* $wgDebugRawPage - if false, 'action=raw' hits will not result in debug output.
* $wgDebugComments - if on, some debug items may appear in comments in the HTML output.
*
+ * @since 1.25 support for additional context data
+ *
* @param string $text
* @param string|bool $dest Destination of the message:
* - 'all': both to the log and HTML (debug toolbar or HTML comments)
* For backward compatibility, it can also take a boolean:
* - true: same as 'all'
* - false: same as 'log'
+ * @param array $context Additional logging context data
*/
-function wfDebug( $text, $dest = 'all' ) {
+function wfDebug( $text, $dest = 'all', array $context = array() ) {
global $wgDebugRawPage, $wgDebugLogPrefix;
+ global $wgDebugTimestamps, $wgRequestTime;
if ( !$wgDebugRawPage && wfIsDebugRawPage() ) {
return;
$dest = 'log';
}
- $timer = wfDebugTimer();
- if ( $timer !== '' ) {
- // Prepend elapsed request time and real memory usage to each line
- $text = preg_replace( '/[^\n]/', $timer . '\0', $text, 1 );
+ $text = trim( $text );
+
+ // Inline logic from deprecated wfDebugTimer()
+ if ( $wgDebugTimestamps ) {
+ $context['seconds_elapsed'] = sprintf(
+ '%6.4f',
+ microtime( true ) - $wgRequestTime
+ );
+ $context['memory_used'] = sprintf(
+ '%5.1fM',
+ ( memory_get_usage( true ) / ( 1024 * 1024 ) )
+ );
}
if ( $dest === 'all' ) {
- MWDebug::debugMsg( $text );
+ $prefix = '';
+ if ( $wgDebugTimestamps ) {
+ // Prepend elapsed request time and real memory usage with two
+ // trailing spaces.
+ $prefix = "{$context['seconds_elapsed']} {$context['memory_used']} ";
+ }
+ MWDebug::debugMsg( "{$prefix}{$text}" );
}
- $ctx = array();
if ( $wgDebugLogPrefix !== '' ) {
- $ctx['prefix'] = $wgDebugLogPrefix;
+ $context['prefix'] = $wgDebugLogPrefix;
}
$logger = MWLogger::getInstance( 'wfDebug' );
- $logger->debug( rtrim( $text, "\n" ), $ctx );
+ $logger->debug( $text, $context );
}
/**
/**
* Get microsecond timestamps for debug logs
*
+ * @deprecated since 1.25
* @return string
*/
function wfDebugTimer() {
global $wgDebugTimestamps, $wgRequestTime;
+ wfDeprecated( __METHOD__, '1.25' );
+
if ( !$wgDebugTimestamps ) {
return '';
}
* a sampling factor.
*
* @since 1.23 support for sampling log messages via $wgDebugLogGroups.
+ * @since 1.25 support for additional context data
*
* @param string $logGroup
* @param string $text
* For backward compatibility, it can also take a boolean:
* - true: same as 'all'
* - false: same as 'private'
+ * @param array $context Additional logging context data
*/
-function wfDebugLog( $logGroup, $text, $dest = 'all' ) {
+function wfDebugLog(
+ $logGroup, $text, $dest = 'all', array $context = array()
+) {
// Turn $dest into a string if it's a boolean (for b/c)
if ( $dest === true ) {
$dest = 'all';
}
$logger = MWLogger::getInstance( $logGroup );
- $logger->debug( $text, array(
- 'private' => ( $dest === 'private' ),
- ) );
+ $context['private'] = ( $dest === 'private' );
+ $logger->debug( $text, $context );
}
/**
* Log for database errors
*
+ * @since 1.25 support for additional context data
+ *
* @param string $text Database error message.
+ * @param array $context Additional logging context data
*/
-function wfLogDBError( $text ) {
+function wfLogDBError( $text, array $context = array() ) {
$logger = MWLogger::getInstance( 'wfLogDBError' );
- $logger->error( trim( $text ) );
+ $logger->error( trim( $text ), $context );
}
/**
*
* Can also log to TCP or UDP with the syntax udp://host:port/prefix. This will
* send lines to the specified port, prefixed by the specified prefix and a space.
+ * @since 1.25 support for additional context data
*
* @param string $text
* @param string $file Filename
+ * @param array $context Additional logging context data
* @throws MWException
*/
-function wfErrorLog( $text, $file ) {
+function wfErrorLog( $text, $file, array $context = array() ) {
$logger = MWLogger::getInstance( 'wfErrorLog' );
- $logger->info( trim( $text ), array(
- 'destination' => $file,
- ) );
+ $context['destination'] = $file;
+ $logger->info( trim( $text ), $context );
}
/**
$this->mPHPError = $errstr;
}
+ /**
+ * Create a log context to pass to wfLogDBError or other logging functions.
+ *
+ * @param array $extras Additional data to add to context
+ * @return array
+ */
+ protected function getLogContext( array $extras = array() ) {
+ return array_merge(
+ array(
+ 'db_server' => $this->mServer,
+ 'db_name' => $this->mDBname,
+ 'db_user' => $this->mUser,
+ ),
+ $extras
+ );
+ }
+
/**
* Closes a database connection.
* if it is open : commits any open transactions
$elapsed = round( microtime( true ) - $wgRequestTime, 3 );
if ( $elapsed < 300 ) {
# Not a database error to lose a transaction after a minute or two
- wfLogDBError( "Connection lost and reconnected after {$elapsed}s, query: $sqlx" );
+ wfLogDBError(
+ "Connection lost and reconnected after {$elapsed}s, query: $sqlx",
+ $this->getLogContext( array(
+ 'method' => __METHOD__,
+ 'query' => $sqlx,
+ ) )
+ );
}
if ( $hadTrx ) {
# Leave $ret as false and let an error be reported.
$this->ignoreErrors( $ignore );
} else {
$sql1line = mb_substr( str_replace( "\n", "\\n", $sql ), 0, 5 * 1024 );
- wfLogDBError( "$fname\t{$this->mServer}\t$errno\t$error\t$sql1line" );
+ wfLogDBError(
+ "{fname}\t{db_server}\t{errno}\t{error}\t{sql1line}",
+ $this->getLogContext( array(
+ 'method' => __METHOD__,
+ 'errno' => $errno,
+ 'error' => $error,
+ 'sql1line' => $sql1line,
+ 'fname' => $fname,
+ ) )
+ );
wfDebug( "SQL ERROR: " . $error . "\n" );
throw new DBQueryError( $this, $error, $errno, $sql, $fname );
}
$msg = "$fname: Transaction already in progress (from {$this->mTrxFname}), " .
" performing implicit commit!";
wfWarn( $msg );
- wfLogDBError( $msg );
+ wfLogDBError( $msg,
+ $this->getLogContext( array(
+ 'method' => __METHOD__,
+ 'fname' => $fname,
+ ) )
+ );
} else {
// if the transaction was automatic and has done write operations,
// log it if $wgDebugDBTransactions is enabled.
if ( !$error ) {
$error = $this->lastError();
}
- wfLogDBError( "Error connecting to {$this->mServer}: $error" );
+ wfLogDBError(
+ "Error connecting to {db_server}: {error}",
+ $this->getLogContext( array(
+ 'method' => __METHOD__,
+ 'error' => $error,
+ ) )
+ );
wfDebug( "DB connection error\n" .
"Server: $server, User: $user, Password: " .
substr( $password, 0, 3 ) . "..., error: " . $error . "\n" );
$success = $this->selectDB( $dbName );
wfRestoreWarnings();
if ( !$success ) {
- wfLogDBError( "Error selecting database $dbName on server {$this->mServer}" );
+ wfLogDBError(
+ "Error selecting database {db_name} on server {db_server}",
+ $this->getLogContext( array(
+ 'method' => __METHOD__,
+ ) )
+ );
wfDebug( "Error selecting database $dbName on server {$this->mServer} " .
"from client host " . wfHostname() . "\n" );
// Use doQuery() to avoid opening implicit transactions (DBO_TRX)
$success = $this->doQuery( "SET sql_mode = $mode", __METHOD__ );
if ( !$success ) {
- wfLogDBError( "Error setting sql_mode to $mode on server {$this->mServer}" );
+ wfLogDBError(
+ "Error setting sql_mode to $mode on server {db_server}",
+ $this->getLogContext( array(
+ 'method' => __METHOD__,
+ ) )
+ );
wfProfileOut( __METHOD__ );
$this->reportConnectionError( "Error setting sql_mode to $mode" );
}
*/
private function reportConnectionError() {
$conn = $this->mErrorConnection; // The connection which caused the error
+ $context = array(
+ 'method' => __METHOD__,
+ 'last_error' => $this->mLastError,
+ );
if ( !is_object( $conn ) ) {
// No last connection, probably due to all servers being too busy
- wfLogDBError( "LB failure with no last connection. Connection error: {$this->mLastError}" );
+ wfLogDBError(
+ "LB failure with no last connection. Connection error: {last_error}",
+ $context
+ );
// If all servers were busy, mLastError will contain something sensible
throw new DBConnectionError( null, $this->mLastError );
} else {
- $server = $conn->getProperty( 'mServer' );
- wfLogDBError( "Connection error: {$this->mLastError} ({$server})" );
- $conn->reportConnectionError( "{$this->mLastError} ({$server})" ); // throws DBConnectionError
+ $context['db_server'] = $conn->getProperty( 'mServer' );
+ wfLogDBError(
+ "Connection error: {last_error} ({db_server})",
+ $context
+ );
+ $conn->reportConnectionError( "{$this->mLastError} ({$context['db_server']})" ); // throws DBConnectionError
}
return false; /* not reached */
// Default formatting is wfDebugLog's historic style
$text = self::formatAsWfDebugLog( $channel, $message, $context );
}
- return $text;
+
+ return self::interpolate( $text, $context );
}
*/
protected static function formatAsWfDebug( $channel, $message, $context ) {
$text = preg_replace( '![\x00-\x08\x0b\x0c\x0e-\x1f]!', ' ', $message );
+ if ( isset( $context['seconds_elapsed'] ) ) {
+ // Prepend elapsed request time and real memory usage with two
+ // trailing spaces.
+ $text = "{$context['seconds_elapsed']} {$context['memory_used']} {$text}";
+ }
if ( isset( $context['prefix'] ) ) {
$text = "{$context['prefix']}{$text}";
}
}
+ /**
+ * Interpolate placeholders in logging message.
+ *
+ * @param string $message
+ * @param array $context
+ */
+ public static function interpolate( $message, array $context ) {
+ if ( strpos( $message, '{' ) !== false ) {
+ $replace = array();
+ foreach ( $context as $key => $val ) {
+ $replace['{' . $key . '}'] = $val;
+ }
+ $message = strtr( $message, $replace );
+ }
+ return $message;
+ }
+
+
/**
* Select the appropriate log output destination for the given log event.
*
--- /dev/null
+<?php
+/**
+ * @section LICENSE
+ * This program is free software; you can redistribute it and/or modify
+ * it under the terms of the GNU General Public License as published by
+ * the Free Software Foundation; either version 2 of the License, or
+ * (at your option) any later version.
+ *
+ * This program is distributed in the hope that it will be useful,
+ * but WITHOUT ANY WARRANTY; without even the implied warranty of
+ * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
+ * GNU General Public License for more details.
+ *
+ * You should have received a copy of the GNU General Public License along
+ * with this program; if not, write to the Free Software Foundation, Inc.,
+ * 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301, USA.
+ * http://www.gnu.org/copyleft/gpl.html
+ *
+ * @file
+ */
+
+class MWLoggerLegacyLoggerTest extends MediaWikiTestCase {
+
+ /**
+ * @covers MWLoggerLegacyLogger::interpolate
+ * @dataProvider provideInterpolate
+ */
+ public function testInterpolate( $message, $context, $expect ) {
+ $this->assertEquals(
+ $expect, MWLoggerLegacyLogger::interpolate( $message, $context ) );
+ }
+
+ public function provideInterpolate() {
+ return array(
+ array(
+ 'no-op',
+ array(),
+ 'no-op',
+ ),
+ array(
+ 'Hello {world}!',
+ array(
+ 'world' => 'World',
+ ),
+ 'Hello World!',
+ ),
+ array(
+ '{greeting} {user}',
+ array(
+ 'greeting' => 'Goodnight',
+ 'user' => 'Moon',
+ ),
+ 'Goodnight Moon',
+ ),
+ array(
+ 'Oops {key_not_set}',
+ array(),
+ 'Oops {key_not_set}',
+ ),
+ array(
+ '{ not interpolated }',
+ array(
+ 'not interpolated' => 'This should NOT show up in the message',
+ ),
+ '{ not interpolated }',
+ ),
+ );
+ }
+
+}