From cde1416446f66d64d9d334e90a2d12bb9a55230f Mon Sep 17 00:00:00 2001 From: epriestley Date: Tue, 2 Apr 2013 09:53:56 -0700 Subject: [PATCH] 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 | 3 +- .../xhprof/DarkConsoleXHProfPluginAPI.php | 21 +++---- .../PhabricatorAccessLogConfigOptions.php | 3 +- src/infrastructure/PhabricatorAccessLog.php | 6 +- support/PhabricatorStartup.php | 26 +++++--- webroot/index.php | 61 ++++++++----------- 6 files changed, 56 insertions(+), 64 deletions(-) diff --git a/conf/default.conf.php b/conf/default.conf.php index 83d140241d..0a5a000a4d 100644 --- a/conf/default.conf.php +++ b/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. // diff --git a/src/aphront/console/plugin/xhprof/DarkConsoleXHProfPluginAPI.php b/src/aphront/console/plugin/xhprof/DarkConsoleXHProfPluginAPI.php index afad7f1b8e..3821e54b00 100644 --- a/src/aphront/console/plugin/xhprof/DarkConsoleXHProfPluginAPI.php +++ b/src/aphront/console/plugin/xhprof/DarkConsoleXHProfPluginAPI.php @@ -68,9 +68,7 @@ final class DarkConsoleXHProfPluginAPI { } - public static function saveProfilerSample( - AphrontRequest $request, - $access_log) { + public static function saveProfilerSample(PhutilDeferredLog $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); - - if ($access_log) { - $profile_sample - ->setUsTotal($access_log->getData('T')) - ->setHostname($access_log->getData('h')) - ->setRequestPath($access_log->getData('U')) - ->setController($access_log->getData('C')) - ->setUserPHID($request->getUser()->getPHID()); - } + $profile_sample + ->setSampleRate($sample_rate) + ->setUsTotal($access_log->getData('T')) + ->setHostname($access_log->getData('h')) + ->setRequestPath($access_log->getData('U')) + ->setController($access_log->getData('C')) + ->setUserPHID($access_log->getData('P')); $profile_sample->save(); } diff --git a/src/applications/config/option/PhabricatorAccessLogConfigOptions.php b/src/applications/config/option/PhabricatorAccessLogConfigOptions.php index 3e5cabd156..5503b66870 100644 --- a/src/applications/config/option/PhabricatorAccessLogConfigOptions.php +++ b/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."), ); diff --git a/src/infrastructure/PhabricatorAccessLog.php b/src/infrastructure/PhabricatorAccessLog.php index f70f110477..937bf3dfb1 100644 --- a/src/infrastructure/PhabricatorAccessLog.php +++ b/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) { - return null; - } + // NOTE: Path may be null. We still create the log, it just won't write + // anywhere. + $path = null; $log = new PhutilDeferredLog($path, $format); $log->setData( diff --git a/support/PhabricatorStartup.php b/support/PhabricatorStartup.php index cf4b0d09d3..8ee7de26bd 100644 --- a/support/PhabricatorStartup.php +++ b/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 { - $access_log->setData( - array( - 'c' => 500, - )); - $access_log->write(); - } catch (Exception $ex) { - $message .= "\n(Moreover, unable to write to access log.)"; - } + try { + $access_log->setData( + array( + 'c' => 500, + )); + $access_log->write(); + } catch (Exception $ex) { + $message .= "\n(Moreover, unable to write to access log.)"; } header( diff --git a/webroot/index.php b/webroot/index.php index 7221ded949..ff3e15ce71 100644 --- a/webroot/index.php +++ b/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); - $access_log->setData( - array( - 'R' => AphrontRequest::getHTTPHeader('Referer', '-'), - 'r' => idx($_SERVER, 'REMOTE_ADDR', '-'), - 'M' => idx($_SERVER, 'REQUEST_METHOD', '-'), - )); - } + PhabricatorStartup::setGlobal('log.access', $access_log); + $access_log->setData( + array( + 'R' => AphrontRequest::getHTTPHeader('Referer', '-'), + 'r' => idx($_SERVER, 'REMOTE_ADDR', '-'), + '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( - array( - 'U' => (string)$request->getRequestURI()->getPath(), - 'C' => get_class($controller), - )); - } + $access_log->setData( + array( + 'U' => (string)$request->getRequestURI()->getPath(), + '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()) { - $access_log->setData( - array( - 'u' => $request->getUser()->getUserName(), - )); - } + if ($request->getUser() && $request->getUser()->getPHID()) { + $access_log->setData( + array( + '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) { - $request_start = PhabricatorStartup::getStartTime(); - $access_log->setData( - array( - 'c' => $response->getHTTPResponseCode(), - 'T' => (int)(1000000 * (microtime(true) - $request_start)), - )); - $access_log->write(); - } + $access_log->setData( + array( + 'c' => $response->getHTTPResponseCode(), + 'T' => PhabricatorStartup::getMicrosecondsSinceStart(), + )); - DarkConsoleXHProfPluginAPI::saveProfilerSample($request, $access_log); + DarkConsoleXHProfPluginAPI::saveProfilerSample($access_log); } catch (Exception $ex) { PhabricatorStartup::didFatal("[Exception] ".$ex->getMessage());