Page Menu
Home
Phabricator
Search
Configure Global Search
Log In
Files
F14781096
D13956.id33689.diff
No One
Temporary
Actions
View File
Edit File
Delete File
View Transforms
Subscribe
Mute Notifications
Award Token
Flag For Later
Size
11 KB
Referenced Files
None
Subscribers
None
D13956.id33689.diff
View Options
diff --git a/src/__phutil_library_map__.php b/src/__phutil_library_map__.php
--- a/src/__phutil_library_map__.php
+++ b/src/__phutil_library_map__.php
@@ -286,6 +286,7 @@
'DarkConsolePlugin' => 'applications/console/plugin/DarkConsolePlugin.php',
'DarkConsoleRequestPlugin' => 'applications/console/plugin/DarkConsoleRequestPlugin.php',
'DarkConsoleServicesPlugin' => 'applications/console/plugin/DarkConsoleServicesPlugin.php',
+ 'DarkConsoleStartupPlugin' => 'applications/console/plugin/DarkConsoleStartupPlugin.php',
'DarkConsoleXHProfPlugin' => 'applications/console/plugin/DarkConsoleXHProfPlugin.php',
'DarkConsoleXHProfPluginAPI' => 'applications/console/plugin/xhprof/DarkConsoleXHProfPluginAPI.php',
'DatabaseConfigurationProvider' => 'infrastructure/storage/configuration/DatabaseConfigurationProvider.php',
@@ -3912,6 +3913,7 @@
'DarkConsolePlugin' => 'Phobject',
'DarkConsoleRequestPlugin' => 'DarkConsolePlugin',
'DarkConsoleServicesPlugin' => 'DarkConsolePlugin',
+ 'DarkConsoleStartupPlugin' => 'DarkConsolePlugin',
'DarkConsoleXHProfPlugin' => 'DarkConsolePlugin',
'DarkConsoleXHProfPluginAPI' => 'Phobject',
'DefaultDatabaseConfigurationProvider' => array(
diff --git a/src/aphront/configuration/AphrontApplicationConfiguration.php b/src/aphront/configuration/AphrontApplicationConfiguration.php
--- a/src/aphront/configuration/AphrontApplicationConfiguration.php
+++ b/src/aphront/configuration/AphrontApplicationConfiguration.php
@@ -58,6 +58,7 @@
* @phutil-external-symbol class PhabricatorStartup
*/
public static function runHTTPRequest(AphrontHTTPSink $sink) {
+ PhabricatorStartup::beginStartupPhase('multimeter');
$multimeter = MultimeterControl::newInstance();
$multimeter->setEventContext('<http-init>');
$multimeter->setEventViewer('<none>');
@@ -67,6 +68,7 @@
// request object first.
$write_guard = new AphrontWriteGuard('id');
+ PhabricatorStartup::beginStartupPhase('env.init');
PhabricatorEnv::initializeWebEnvironment();
$multimeter->setSampleRate(
@@ -78,6 +80,7 @@
}
// This is the earliest we can get away with this, we need env config first.
+ PhabricatorStartup::beginStartupPhase('log.access');
PhabricatorAccessLog::init();
$access_log = PhabricatorAccessLog::getLog();
PhabricatorStartup::setAccessLog($access_log);
@@ -89,6 +92,11 @@
));
DarkConsoleXHProfPluginAPI::hookProfiler();
+
+ // We just activated the profiler, so we don't need to keep track of
+ // startup phases anymore: it can take over from here.
+ PhabricatorStartup::beginStartupPhase('startup.done');
+
DarkConsoleErrorLogPluginAPI::registerErrorHandler();
$response = PhabricatorSetupCheck::willProcessRequest();
diff --git a/src/applications/console/plugin/DarkConsoleStartupPlugin.php b/src/applications/console/plugin/DarkConsoleStartupPlugin.php
new file mode 100644
--- /dev/null
+++ b/src/applications/console/plugin/DarkConsoleStartupPlugin.php
@@ -0,0 +1,84 @@
+<?php
+
+final class DarkConsoleStartupPlugin extends DarkConsolePlugin {
+
+ public function getName() {
+ return pht('Startup');
+ }
+
+ public function getDescription() {
+ return pht('Timing information about the startup sequence.');
+ }
+
+ /**
+ * @phutil-external-symbol class PhabricatorStartup
+ */
+ public function generateData() {
+ return PhabricatorStartup::getPhases();
+ }
+
+ public function renderPanel() {
+ $data = $this->getData();
+
+ // Compute the time offset and duration of each startup phase.
+ $prev_key = null;
+ $init = null;
+ $phases = array();
+ foreach ($data as $key => $value) {
+ if ($init === null) {
+ $init = $value;
+ }
+
+ $offset = (int)floor(1000 * ($value - $init));
+
+ $phases[$key] = array(
+ 'time' => $value,
+ 'offset' => $value - $init,
+ );
+
+
+ if ($prev_key !== null) {
+ $phases[$prev_key]['duration'] = $value - $phases[$prev_key]['time'];
+ }
+ $prev_key = $key;
+ }
+
+ // Render the phases.
+ $rows = array();
+ foreach ($phases as $key => $phase) {
+ $offset_ms = (int)floor(1000 * $phase['offset']);
+
+ if (isset($phase['duration'])) {
+ $duration_us = (int)floor(1000000 * $phase['duration']);
+ } else {
+ $duration_us = null;
+ }
+
+ $rows[] = array(
+ $key,
+ pht('+%s ms', new PhutilNumber($offset_ms)),
+ ($duration_us === null)
+ ? pht('-')
+ : pht('%s us', new PhutilNumber($duration_us)),
+ null,
+ );
+ }
+
+ return id(new AphrontTableView($rows))
+ ->setHeaders(
+ array(
+ pht('Phase'),
+ pht('Offset'),
+ pht('Duration'),
+ null,
+ ))
+ ->setColumnClasses(
+ array(
+ '',
+ 'n right',
+ 'n right',
+ 'wide',
+ ));
+ }
+
+}
diff --git a/src/applications/console/plugin/xhprof/DarkConsoleXHProfPluginAPI.php b/src/applications/console/plugin/xhprof/DarkConsoleXHProfPluginAPI.php
--- a/src/applications/console/plugin/xhprof/DarkConsoleXHProfPluginAPI.php
+++ b/src/applications/console/plugin/xhprof/DarkConsoleXHProfPluginAPI.php
@@ -124,7 +124,13 @@
self::startProfiler();
}
+
+ /**
+ * @phutil-external-symbol class PhabricatorStartup
+ */
private static function startProfiler() {
+ PhabricatorStartup::beginStartupPhase('profiler.init');
+
self::includeXHProfLib();
xhprof_enable();
@@ -132,15 +138,23 @@
self::$profilerRunning = true;
}
+
+ /**
+ * @phutil-external-symbol class PhabricatorStartup
+ */
public static function getProfileFilePHID() {
+ if (!self::isProfilerRunning()) {
+ return;
+ }
+
+ PhabricatorStartup::beginStartupPhase('profiler.stop');
self::stopProfiler();
+ PhabricatorStartup::beginStartupPhase('profiler.done');
+
return self::$profileFilePHID;
}
private static function stopProfiler() {
- if (!self::isProfilerRunning()) {
- return;
- }
$data = xhprof_disable();
$data = @json_encode($data);
diff --git a/src/docs/user/field/darkconsole.diviner b/src/docs/user/field/darkconsole.diviner
--- a/src/docs/user/field/darkconsole.diviner
+++ b/src/docs/user/field/darkconsole.diviner
@@ -138,6 +138,25 @@
tool to understand problems in PHP is XHProf.
+Plugin: Startup
+===============
+
+The "Startup" plugin shows information about startup phases. This information
+can provide insight about performance problems which occur before the profiler
+can start.
+
+Normally, the profiler is the best tool for understanding runtime performance,
+but some work is performed before the profiler starts (for example, loading
+libraries and configuration). If there is a substantial difference between the
+wall time reported by the profiler and the "Entire Page" cost reported by the
+Services tab, the Startup tab can help account for that time.
+
+It is normal for starting the profiler to increase the cost of the page
+somewhat: the profiler itself adds overhead while it is running, and the page
+must do some work after the profiler is stopped to save the profile and
+complete other shutdown operations.
+
+
Plugin: XHProf
==============
diff --git a/support/PhabricatorStartup.php b/support/PhabricatorStartup.php
--- a/support/PhabricatorStartup.php
+++ b/support/PhabricatorStartup.php
@@ -34,6 +34,7 @@
* @task apocalypse In Case Of Apocalypse
* @task validation Validation
* @task ratelimit Rate Limiting
+ * @task phases Startup Phase Timers
*/
final class PhabricatorStartup {
@@ -43,6 +44,7 @@
private static $capturingOutput;
private static $rawInput;
private static $oldMemoryLimit;
+ private static $phases;
// TODO: For now, disable rate limiting entirely by default. We need to
// iterate on it a bit for Conduit, some of the specific score levels, and
@@ -89,10 +91,14 @@
/**
+ * @param float Request start time, from `microtime(true)`.
* @task hook
*/
- public static function didStartup() {
- self::$startTime = microtime(true);
+ public static function didStartup($start_time) {
+ self::$startTime = $start_time;
+
+ self::$phases = array();
+
self::$accessLog = null;
static $registered;
@@ -854,4 +860,58 @@
exit(1);
}
+
+/* -( Startup Timers )----------------------------------------------------- */
+
+
+ /**
+ * Record the beginning of a new startup phase.
+ *
+ * For phases which occur before @{class:PhabricatorStartup} loads, save the
+ * time and record it with @{method:recordStartupPhase} after the class is
+ * available.
+ *
+ * @param string Phase name.
+ * @task phases
+ */
+ public static function beginStartupPhase($phase) {
+ self::recordStartupPhase($phase, microtime(true));
+ }
+
+
+ /**
+ * Record the start time of a previously executed startup phase.
+ *
+ * For startup phases which occur after @{class:PhabricatorStartup} loads,
+ * use @{method:beginStartupPhase} instead. This method can be used to
+ * record a time before the class loads, then hand it over once the class
+ * becomes available.
+ *
+ * @param string Phase name.
+ * @param float Phase start time, from `microtime(true)`.
+ * @task phases
+ */
+ public static function recordStartupPhase($phase, $time) {
+ self::$phases[$phase] = $time;
+ }
+
+
+ /**
+ * Get information about startup phase timings.
+ *
+ * Sometimes, performance problems can occur before we start the profiler.
+ * Since the profiler can't examine these phases, it isn't useful in
+ * understanding their performance costs.
+ *
+ * Instead, the startup process marks when it enters various phases using
+ * @{method:beginStartupPhase}. A later call to this method can retrieve this
+ * information, which can be examined to gain greater insight into where
+ * time was spent. The output is still crude, but better than nothing.
+ *
+ * @task phases
+ */
+ public static function getPhases() {
+ return self::$phases;
+ }
+
}
diff --git a/webroot/index.php b/webroot/index.php
--- a/webroot/index.php
+++ b/webroot/index.php
@@ -1,23 +1,19 @@
<?php
-$phabricator_root = dirname(dirname(__FILE__));
-require_once $phabricator_root.'/support/PhabricatorStartup.php';
-
-// If the preamble script exists, load it.
-$preamble_path = $phabricator_root.'/support/preamble.php';
-if (file_exists($preamble_path)) {
- require_once $preamble_path;
-}
-
-PhabricatorStartup::didStartup();
+phabricator_startup();
try {
+ PhabricatorStartup::beginStartupPhase('libraries');
PhabricatorStartup::loadCoreLibraries();
+
+ PhabricatorStartup::beginStartupPhase('purge');
PhabricatorCaches::destroyRequestCache();
+ PhabricatorStartup::beginStartupPhase('sink');
$sink = new AphrontPHPHTTPSink();
try {
+ PhabricatorStartup::beginStartupPhase('run');
AphrontApplicationConfiguration::runHTTPRequest($sink);
} catch (Exception $ex) {
try {
@@ -36,3 +32,24 @@
} catch (Exception $ex) {
PhabricatorStartup::didEncounterFatalException('Core Exception', $ex, false);
}
+
+function phabricator_startup() {
+ // Load the PhabricatorStartup class itself.
+ $t_startup = microtime(true);
+ $root = dirname(dirname(__FILE__));
+ require_once $root.'/support/PhabricatorStartup.php';
+
+ // If the preamble script exists, load it.
+ $t_preamble = microtime(true);
+ $preamble_path = $root.'/support/preamble.php';
+ if (file_exists($preamble_path)) {
+ require_once $preamble_path;
+ }
+
+ $t_hook = microtime(true);
+ PhabricatorStartup::didStartup($t_startup);
+
+ PhabricatorStartup::recordStartupPhase('startup.init', $t_startup);
+ PhabricatorStartup::recordStartupPhase('preamble', $t_preamble);
+ PhabricatorStartup::recordStartupPhase('hook', $t_hook);
+}
File Metadata
Details
Attached
Mime Type
text/plain
Expires
Sat, Jan 25, 8:22 AM (9 h, 11 m)
Storage Engine
blob
Storage Format
Encrypted (AES-256-CBC)
Storage Handle
7048657
Default Alt Text
D13956.id33689.diff (11 KB)
Attached To
Mode
D13956: Add a "Startup" to DarkConsole
Attached
Detach File
Event Timeline
Log In to Comment