From 3328bd9961685bcbb4b6d4af2c6ede86b2d46c64 Mon Sep 17 00:00:00 2001 From: Bryan Davis Date: Fri, 21 Mar 2014 00:57:25 -0600 Subject: [PATCH] Use MWLogger logging for wfLogProfilingData Output structured profiling report data from wfLogProfilingData using MWLogger. Requires Ie667944, I5c82299, and I1e5596d. Change-Id: Iae11e1e4fe970ada74136f0e969dc624c586ce17 --- includes/GlobalFunctions.php | 43 +++++++++--------- includes/debug/logger/legacy/Logger.php | 59 +++++++++++++++++++++---- 2 files changed, 72 insertions(+), 30 deletions(-) diff --git a/includes/GlobalFunctions.php b/includes/GlobalFunctions.php index 379335ab5a..55e6e27b55 100644 --- a/includes/GlobalFunctions.php +++ b/includes/GlobalFunctions.php @@ -1184,53 +1184,54 @@ function wfLogProfilingData() { $profiler->logData(); - // Check whether this should be logged in the debug file. if ( isset( $wgDebugLogGroups['profileoutput'] ) && $wgDebugLogGroups['profileoutput'] === false ) { - // Explicitely disabled - return; - } - if ( !isset( $wgDebugLogGroups['profileoutput'] ) && $wgDebugLogFile == '' ) { - // Logging not enabled; no point going further + // Explicitly disabled return; } if ( !$wgDebugRawPage && wfIsDebugRawPage() ) { return; } - $forward = ''; + $ctx = array( 'elapsed' => $elapsed ); if ( !empty( $_SERVER['HTTP_X_FORWARDED_FOR'] ) ) { - $forward = ' forwarded for ' . $_SERVER['HTTP_X_FORWARDED_FOR']; + $ctx['forwarded_for'] = $_SERVER['HTTP_X_FORWARDED_FOR']; } if ( !empty( $_SERVER['HTTP_CLIENT_IP'] ) ) { - $forward .= ' client IP ' . $_SERVER['HTTP_CLIENT_IP']; + $ctx['client_ip'] = $_SERVER['HTTP_CLIENT_IP']; } if ( !empty( $_SERVER['HTTP_FROM'] ) ) { - $forward .= ' from ' . $_SERVER['HTTP_FROM']; + $ctx['from'] = $_SERVER['HTTP_FROM']; } - if ( $forward ) { - $forward = "\t(proxied via {$_SERVER['REMOTE_ADDR']}{$forward})"; + if ( isset( $ctx['forwarded_for'] ) || + isset( $ctx['client_ip'] ) || + isset( $ctx['from'] ) ) { + $ctx['proxy'] = $_SERVER['REMOTE_ADDR']; } + // Don't load $wgUser at this late stage just for statistics purposes - // @todo FIXME: We can detect some anons even if it is not loaded. See User::getId() + // @todo FIXME: We can detect some anons even if it is not loaded. + // See User::getId() if ( $wgUser->isItemLoaded( 'id' ) && $wgUser->isAnon() ) { - $forward .= ' anon'; + $ctx['anon'] = true; + } else { + $ctx['anon'] = false; } // Command line script uses a FauxRequest object which does not have // any knowledge about an URL and throw an exception instead. try { - $requestUrl = $wgRequest->getRequestURL(); - } catch ( MWException $e ) { - $requestUrl = 'n/a'; + $ctx['url'] = urldecode( $wgRequest->getRequestURL() ); + } catch ( MWException $ignored ) { + // no-op } - $log = sprintf( "%s\t%04.3f\t%s\n", - gmdate( 'YmdHis' ), $elapsed, - urldecode( $requestUrl . $forward ) ); + $ctx['output'] = $profiler->getOutput(); + $ctx['profile'] = $profiler->getRawData(); - wfDebugLog( 'profileoutput', $log . $profiler->getOutput() ); + $log = MWLogger::getInstance( 'profileoutput' ); + $log->info( 'Elapsed: {elapsed}', $ctx ); } /** diff --git a/includes/debug/logger/legacy/Logger.php b/includes/debug/logger/legacy/Logger.php index ff6336bd00..f994da30f7 100644 --- a/includes/debug/logger/legacy/Logger.php +++ b/includes/debug/logger/legacy/Logger.php @@ -134,24 +134,49 @@ class MWLoggerLegacyLogger extends \Psr\Log\AbstractLogger { global $wgDebugLogGroups; if ( $channel === 'wfDebug' ) { - $text = self::formatWfDebug( $channel, $message, $context ); + $text = self::formatAsWfDebug( $channel, $message, $context ); } elseif ( $channel === 'wfLogDBError' ) { - $text = self::formatWfLogDBError( $channel, $message, $context ); + $text = self::formatAsWfLogDBError( $channel, $message, $context ); } elseif ( $channel === 'wfErrorLog' ) { $text = "{$message}\n"; + } elseif ( $channel === 'profileoutput' ) { + // Legacy wfLogProfilingData formatitng + $forward = ''; + if ( isset( $context['forwarded_for'] )) { + $forward = " forwarded for {$context['forwarded_for']}"; + } + if ( isset( $context['client_ip'] ) ) { + $forward .= " client IP {$context['client_ip']}"; + } + if ( isset( $context['from'] ) ) { + $forward .= " from {$context['from']}"; + } + if ( $forward ) { + $forward = "\t(proxied via {$context['proxy']}{$forward})"; + } + if ( $context['anon'] ) { + $forward .= ' anon'; + } + if ( !isset( $context['url'] ) ) { + $context['url'] = 'n/a'; + } + + $log = sprintf( "%s\t%04.3f\t%s%s\n", + gmdate( 'YmdHis' ), $context['elapsed'], $context['url'], $forward ); + + $text = self::formatAsWfDebugLog( + $channel, $log . $context['output'], $context ); + } elseif ( !isset( $wgDebugLogGroups[$channel] ) ) { - $text = self::formatWfDebug( + $text = self::formatAsWfDebug( $channel, "[{$channel}] {$message}", $context ); } else { // Default formatting is wfDebugLog's historic style - $time = wfTimestamp( TS_DB ); - $wiki = wfWikiID(); - $host = wfHostname(); - $text = "{$time} {$host} {$wiki}: {$message}\n"; + $text = self::formatAsWfDebugLog( $channel, $message, $context ); } return $text; } @@ -165,7 +190,7 @@ class MWLoggerLegacyLogger extends \Psr\Log\AbstractLogger { * @param array $context * @return string */ - protected static function formatWfDebug( $channel, $message, $context ) { + protected static function formatAsWfDebug( $channel, $message, $context ) { $text = preg_replace( '![\x00-\x08\x0b\x0c\x0e-\x1f]!', ' ', $message ); if ( isset( $context['prefix'] ) ) { $text = "{$context['prefix']}{$text}"; @@ -182,7 +207,7 @@ class MWLoggerLegacyLogger extends \Psr\Log\AbstractLogger { * @param array $context * @return string */ - protected static function formatWfLogDBError( $channel, $message, $context ) { + protected static function formatAsWfLogDBError( $channel, $message, $context ) { global $wgDBerrorLogTZ; static $cachedTimezone = null; @@ -207,6 +232,22 @@ class MWLoggerLegacyLogger extends \Psr\Log\AbstractLogger { } + /** + * Format a message as `wfDebugLog() would have formatted it. + * + * @param string $channel + * @param string $message + * @param array $context + */ + protected static function formatAsWfDebugLog( $channel, $message, $context ) { + $time = wfTimestamp( TS_DB ); + $wiki = wfWikiID(); + $host = wfHostname(); + $text = "{$time} {$host} {$wiki}: {$message}\n"; + return $text; + } + + /** * Select the appropriate log output destination for the given log event. * -- 2.20.1