Guarantee the existence of the Phabricator access log

Summary:
We have a fair number of conditionals on the existence of the access log. Instead, always build it and just don't write it if the user doesn't want a version on disk.

Also, formalize logged-in user PHID (avoids object existence juggling) in the access log and move microseconds-since-startup to PhabricatorStartup (simplifies index.php).

Depends on D5532. Fixes T2860. Ref T2870.

Test Plan: Disabled access log, verified XHProf writes occurred correctly.

Reviewers: btrahan, chad

Reviewed By: btrahan

CC: aran

Maniphest Tasks: T2860, T2870

Differential Revision: https://secure.phabricator.com/D5533

conf/default.conf.php

@@ -113,7 +113,8 @@ return array(
   //  - %r The remote IP.
   //  - %T The request duration, in microseconds.
   //  - %U The request path.
-  //  - %u The logged-in user, if one is logged in.
+  //  - %u The logged-in username, if one is logged in.
+  //  - %P The logged-in user PHID, if one is logged in.
   //  - %M The HTTP method.
   //  - %m For conduit, the Conduit method which was invoked.
   //

src/aphront/console/plugin/xhprof/DarkConsoleXHProfPluginAPI.php

@@ -68,9 +68,7 @@ final class DarkConsoleXHProfPluginAPI {
   }
 
 
-  public static function saveProfilerSample(
+  public static function saveProfilerSample(PhutilDeferredLog $access_log) {
-    AphrontRequest $request,
-    $access_log) {
 
     if (!self::isProfilerStarted()) {
       return;
@@ -86,16 +84,13 @@ final class DarkConsoleXHProfPluginAPI {
       $sample_rate = PhabricatorEnv::getEnvConfig('debug.profile-rate');
     }
 
-    $profile_sample->setSampleRate($sample_rate);
+    $profile_sample
-
+      ->setSampleRate($sample_rate)
-    if ($access_log) {
+      ->setUsTotal($access_log->getData('T'))
-      $profile_sample
+      ->setHostname($access_log->getData('h'))
-        ->setUsTotal($access_log->getData('T'))
+      ->setRequestPath($access_log->getData('U'))
-        ->setHostname($access_log->getData('h'))
+      ->setController($access_log->getData('C'))
-        ->setRequestPath($access_log->getData('U'))
+      ->setUserPHID($access_log->getData('P'));
-        ->setController($access_log->getData('C'))
-        ->setUserPHID($request->getUser()->getPHID());
-    }
 
     $profile_sample->save();
   }

src/applications/config/option/PhabricatorAccessLogConfigOptions.php

@@ -23,7 +23,8 @@ final class PhabricatorAccessLogConfigOptions
       'r' => pht("The remote IP."),
       'T' => pht("The request duration, in microseconds."),
       'U' => pht("The request path."),
-      'u' => pht("The logged-in user, if one is logged in."),
+      'u' => pht("The logged-in username, if one is logged in."),
+      'P' => pht("The logged-in user PHID, if one is logged in."),
       'M' => pht("The HTTP method."),
       'm' => pht("For conduit, the Conduit method which was invoked."),
     );

src/infrastructure/PhabricatorAccessLog.php

@@ -19,9 +19,9 @@ final class PhabricatorAccessLog {
         $format,
         "[%D]\t%p\t%h\t%r\t%u\t%C\t%m\t%U\t%R\t%c\t%T");
 
-      if (!$path) {
+      // NOTE: Path may be null. We still create the log, it just won't write
-        return null;
+      // anywhere.
-      }
+      $path = null;
 
       $log = new PhutilDeferredLog($path, $format);
       $log->setData(

support/PhabricatorStartup.php

@@ -31,6 +31,14 @@ final class PhabricatorStartup {
   }
 
 
+  /**
+   * @task info
+   */
+  public static function getMicrosecondsSinceStart() {
+    return (int)(1000000 * (microtime(true) - self::getStartTime()));
+  }
+
+
   /**
    * @task info
    */
@@ -183,16 +191,14 @@ final class PhabricatorStartup {
     self::endOutputCapture();
     $access_log = self::getGlobal('log.access');
 
-    if ($access_log) {
+    try {
-      try {
+      $access_log->setData(
-        $access_log->setData(
+        array(
-          array(
+          'c' => 500,
-            'c' => 500,
+        ));
-          ));
+      $access_log->write();
-        $access_log->write();
+    } catch (Exception $ex) {
-      } catch (Exception $ex) {
+      $message .= "\n(Moreover, unable to write to access log.)";
-        $message .= "\n(Moreover, unable to write to access log.)";
-      }
     }
 
     header(

webroot/index.php

@@ -11,15 +11,13 @@ try {
   // This is the earliest we can get away with this, we need env config first.
   PhabricatorAccessLog::init();
   $access_log = PhabricatorAccessLog::getLog();
-  if ($access_log) {
+  PhabricatorStartup::setGlobal('log.access', $access_log);
-    PhabricatorStartup::setGlobal('log.access', $access_log);
+  $access_log->setData(
-    $access_log->setData(
+    array(
-      array(
+      'R' => AphrontRequest::getHTTPHeader('Referer', '-'),
-        'R' => AphrontRequest::getHTTPHeader('Referer', '-'),
+      'r' => idx($_SERVER, 'REMOTE_ADDR', '-'),
-        'r' => idx($_SERVER, 'REMOTE_ADDR', '-'),
+      'M' => idx($_SERVER, 'REQUEST_METHOD', '-'),
-        'M' => idx($_SERVER, 'REQUEST_METHOD', '-'),
+    ));
-      ));
-  }
 
   DarkConsoleXHProfPluginAPI::hookProfiler();
 
@@ -62,13 +60,11 @@ try {
   $application->setRequest($request);
   list($controller, $uri_data) = $application->buildController();
 
-  if ($access_log) {
+  $access_log->setData(
-    $access_log->setData(
+    array(
-      array(
+      'U' => (string)$request->getRequestURI()->getPath(),
-        'U' => (string)$request->getRequestURI()->getPath(),
+      'C' => get_class($controller),
-        'C' => get_class($controller),
+    ));
-      ));
-  }
 
   // If execution throws an exception and then trying to render that exception
   // throws another exception, we want to show the original exception, as it is
@@ -77,13 +73,12 @@ try {
   try {
     $response = $controller->willBeginExecution();
 
-    if ($access_log) {
+    if ($request->getUser() && $request->getUser()->getPHID()) {
-      if ($request->getUser() && $request->getUser()->getPHID()) {
+      $access_log->setData(
-        $access_log->setData(
+        array(
-          array(
+          'u' => $request->getUser()->getUserName(),
-            'u' => $request->getUser()->getUserName(),
+          'P' => $request->getUser()->getPHID(),
-          ));
+        ));
-      }
     }
 
     if (!$response) {
@@ -120,9 +115,7 @@ try {
     $sink->writeResponse($response);
   } catch (Exception $ex) {
     $write_guard->dispose();
-    if ($access_log) {
+    $access_log->write();
-      $access_log->write();
-    }
     if ($original_exception) {
       $ex = new PhutilAggregateException(
         "Multiple exceptions during processing and rendering.",
@@ -136,17 +129,13 @@ try {
 
   $write_guard->dispose();
 
-  if ($access_log) {
+  $access_log->setData(
-    $request_start = PhabricatorStartup::getStartTime();
+    array(
-    $access_log->setData(
+      'c' => $response->getHTTPResponseCode(),
-      array(
+      'T' => PhabricatorStartup::getMicrosecondsSinceStart(),
-        'c' => $response->getHTTPResponseCode(),
+    ));
-        'T' => (int)(1000000 * (microtime(true) - $request_start)),
-      ));
-    $access_log->write();
-  }
 
-  DarkConsoleXHProfPluginAPI::saveProfilerSample($request, $access_log);
+  DarkConsoleXHProfPluginAPI::saveProfilerSample($access_log);
 
 } catch (Exception $ex) {
   PhabricatorStartup::didFatal("[Exception] ".$ex->getMessage());