includes/debug/logger/LegacyLogger.php

   1 <?php
   2 /**
   3  * This program is free software; you can redistribute it and/or modify
   4  * it under the terms of the GNU General Public License as published by
   5  * the Free Software Foundation; either version 2 of the License, or
   6  * (at your option) any later version.
   7  *
   8  * This program is distributed in the hope that it will be useful,
   9  * but WITHOUT ANY WARRANTY; without even the implied warranty of
  10  * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
  11  * GNU General Public License for more details.
  12  *
  13  * You should have received a copy of the GNU General Public License along
  14  * with this program; if not, write to the Free Software Foundation, Inc.,
  15  * 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301, USA.
  16  * http://www.gnu.org/copyleft/gpl.html
  17  *
  18  * @file
  19  */
  20
  21 namespace MediaWiki\Logger;
  22
  23 use DateTimeZone;
  24 use Exception;
  25 use MWDebug;
  26 use MWExceptionHandler;
  27 use Psr\Log\AbstractLogger;
  28 use Psr\Log\LogLevel;
  29 use UDPTransport;
  30
  31 /**
  32  * PSR-3 logger that mimics the historic implementation of MediaWiki's
  33  * wfErrorLog logging implementation.
  34  *
  35  * This logger is configured by the following global configuration variables:
  36  * - `$wgDebugLogFile`
  37  * - `$wgDebugLogGroups`
  38  * - `$wgDBerrorLog`
  39  * - `$wgDBerrorLogTZ`
  40  *
  41  * See documentation in DefaultSettings.php for detailed explanations of each
  42  * variable.
  43  *
  44  * @see \\MediaWiki\\Logger\\LoggerFactory
  45  * @since 1.25
  46  * @author Bryan Davis <bd808@wikimedia.org>
  47  * @copyright © 2014 Bryan Davis and Wikimedia Foundation.
  48  */
  49 class LegacyLogger extends AbstractLogger {
  50
  51         /**
  52          * @var string $channel
  53          */
  54         protected $channel;
  55
  56         /**
  57          * Convert Psr\\Log\\LogLevel constants into int for sane comparisons
  58          * These are the same values that Monlog uses
  59          *
  60          * @var array $levelMapping
  61          */
  62         protected static $levelMapping = array(
  63                 LogLevel::DEBUG => 100,
  64                 LogLevel::INFO => 200,
  65                 LogLevel::NOTICE => 250,
  66                 LogLevel::WARNING => 300,
  67                 LogLevel::ERROR => 400,
  68                 LogLevel::CRITICAL => 500,
  69                 LogLevel::ALERT => 550,
  70                 LogLevel::EMERGENCY => 600,
  71         );
  72
  73
  74         /**
  75          * @param string $channel
  76          */
  77         public function __construct( $channel ) {
  78                 $this->channel = $channel;
  79         }
  80
  81         /**
  82          * Logs with an arbitrary level.
  83          *
  84          * @param string|int $level
  85          * @param string $message
  86          * @param array $context
  87          */
  88         public function log( $level, $message, array $context = array() ) {
  89                 if ( self::shouldEmit( $this->channel, $message, $level, $context ) ) {
  90                         $text = self::format( $this->channel, $message, $context );
  91                         $destination = self::destination( $this->channel, $message, $context );
  92                         self::emit( $text, $destination );
  93                 }
  94                 // Add to debug toolbar
  95                 MWDebug::debugMsg( $message, array( 'channel' => $this->channel ) + $context );
  96         }
  97
  98
  99         /**
 100          * Determine if the given message should be emitted or not.
 101          *
 102          * @param string $channel
 103          * @param string $message
 104          * @param string|int $level Psr\\Log\\LogEvent constant or Monlog level int
 105          * @param array $context
 106          * @return bool True if message should be sent to disk/network, false
 107          * otherwise
 108          */
 109         public static function shouldEmit( $channel, $message, $level, $context ) {
 110                 global $wgDebugLogFile, $wgDBerrorLog, $wgDebugLogGroups;
 111
 112                 if ( $channel === 'wfLogDBError' ) {
 113                         // wfLogDBError messages are emitted if a database log location is
 114                         // specfied.
 115                         $shouldEmit = (bool)$wgDBerrorLog;
 116
 117                 } elseif ( $channel === 'wfErrorLog' ) {
 118                         // All messages on the wfErrorLog channel should be emitted.
 119                         $shouldEmit = true;
 120
 121                 } elseif ( isset( $wgDebugLogGroups[$channel] ) ) {
 122                         $logConfig = $wgDebugLogGroups[$channel];
 123
 124                         if ( is_array( $logConfig ) ) {
 125                                 $shouldEmit = true;
 126                                 if ( isset( $logConfig['sample'] ) ) {
 127                                         // Emit randomly with a 1 in 'sample' chance for each message.
 128                                         $shouldEmit = mt_rand( 1, $logConfig['sample'] ) === 1;
 129                                 }
 130
 131                                 if ( isset( $logConfig['level'] ) ) {
 132                                         if ( is_string( $level ) ) {
 133                                                 $level = self::$levelMapping[$level];
 134                                         }
 135                                         $shouldEmit = $level >= self::$levelMapping[$logConfig['level']];
 136                                 }
 137                         } else {
 138                                 // Emit unless the config value is explictly false.
 139                                 $shouldEmit = $logConfig !== false;
 140                         }
 141
 142                 } elseif ( isset( $context['private'] ) && $context['private'] ) {
 143                         // Don't emit if the message didn't match previous checks based on
 144                         // the channel and the event is marked as private. This check
 145                         // discards messages sent via wfDebugLog() with dest == 'private'
 146                         // and no explicit wgDebugLogGroups configuration.
 147                         $shouldEmit = false;
 148                 } else {
 149                         // Default return value is the same as the historic wfDebug
 150                         // method: emit if $wgDebugLogFile has been set.
 151                         $shouldEmit = $wgDebugLogFile != '';
 152                 }
 153
 154                 return $shouldEmit;
 155         }
 156
 157
 158         /**
 159          * Format a message.
 160          *
 161          * Messages to the 'wfDebug', 'wfLogDBError' and 'wfErrorLog' channels
 162          * receive special fomatting to mimic the historic output of the functions
 163          * of the same name. All other channel values are formatted based on the
 164          * historic output of the `wfDebugLog()` global function.
 165          *
 166          * @param string $channel
 167          * @param string $message
 168          * @param array $context
 169          * @return string
 170          */
 171         public static function format( $channel, $message, $context ) {
 172                 global $wgDebugLogGroups, $wgLogExceptionBacktrace;
 173
 174                 if ( $channel === 'wfDebug' ) {
 175                         $text = self::formatAsWfDebug( $channel, $message, $context );
 176
 177                 } elseif ( $channel === 'wfLogDBError' ) {
 178                         $text = self::formatAsWfLogDBError( $channel, $message, $context );
 179
 180                 } elseif ( $channel === 'wfErrorLog' ) {
 181                         $text = "{$message}\n";
 182
 183                 } elseif ( $channel === 'profileoutput' ) {
 184                         // Legacy wfLogProfilingData formatitng
 185                         $forward = '';
 186                         if ( isset( $context['forwarded_for'] ) ) {
 187                                 $forward = " forwarded for {$context['forwarded_for']}";
 188                         }
 189                         if ( isset( $context['client_ip'] ) ) {
 190                                 $forward .= " client IP {$context['client_ip']}";
 191                         }
 192                         if ( isset( $context['from'] ) ) {
 193                                 $forward .= " from {$context['from']}";
 194                         }
 195                         if ( $forward ) {
 196                                 $forward = "\t(proxied via {$context['proxy']}{$forward})";
 197                         }
 198                         if ( $context['anon'] ) {
 199                                 $forward .= ' anon';
 200                         }
 201                         if ( !isset( $context['url'] ) ) {
 202                                 $context['url'] = 'n/a';
 203                         }
 204
 205                         $log = sprintf( "%s\t%04.3f\t%s%s\n",
 206                                 gmdate( 'YmdHis' ), $context['elapsed'], $context['url'], $forward );
 207
 208                         $text = self::formatAsWfDebugLog(
 209                                 $channel, $log . $context['output'], $context );
 210
 211                 } elseif ( !isset( $wgDebugLogGroups[$channel] ) ) {
 212                         $text = self::formatAsWfDebug(
 213                                 $channel, "[{$channel}] {$message}", $context );
 214
 215                 } else {
 216                         // Default formatting is wfDebugLog's historic style
 217                         $text = self::formatAsWfDebugLog( $channel, $message, $context );
 218                 }
 219
 220                 // Append stacktrace of exception if available
 221                 if ( $wgLogExceptionBacktrace && isset( $context['exception'] ) ) {
 222                         $e = $context['exception'];
 223                         $backtrace = false;
 224
 225                         if ( $e instanceof Exception ) {
 226                                 $backtrace = MWExceptionHandler::getRedactedTrace( $e );
 227
 228                         } elseif ( is_array( $e ) && isset( $e['trace'] ) ) {
 229                                 // Exception has already been unpacked as structured data
 230                                 $backtrace = $e['trace'];
 231                         }
 232
 233                         if ( $backtrace ) {
 234                                 $text .= MWExceptionHandler::prettyPrintTrace( $backtrace ) .
 235                                         "\n";
 236                         }
 237                 }
 238
 239                 return self::interpolate( $text, $context );
 240         }
 241
 242
 243         /**
 244          * Format a message as `wfDebug()` would have formatted it.
 245          *
 246          * @param string $channel
 247          * @param string $message
 248          * @param array $context
 249          * @return string
 250          */
 251         protected static function formatAsWfDebug( $channel, $message, $context ) {
 252                 $text = preg_replace( '![\x00-\x08\x0b\x0c\x0e-\x1f]!', ' ', $message );
 253                 if ( isset( $context['seconds_elapsed'] ) ) {
 254                         // Prepend elapsed request time and real memory usage with two
 255                         // trailing spaces.
 256                         $text = "{$context['seconds_elapsed']} {$context['memory_used']}  {$text}";
 257                 }
 258                 if ( isset( $context['prefix'] ) ) {
 259                         $text = "{$context['prefix']}{$text}";
 260                 }
 261                 return "{$text}\n";
 262         }
 263
 264
 265         /**
 266          * Format a message as `wfLogDBError()` would have formatted it.
 267          *
 268          * @param string $channel
 269          * @param string $message
 270          * @param array $context
 271          * @return string
 272          */
 273         protected static function formatAsWfLogDBError( $channel, $message, $context ) {
 274                 global $wgDBerrorLogTZ;
 275                 static $cachedTimezone = null;
 276
 277                 if ( !$cachedTimezone ) {
 278                         $cachedTimezone = new DateTimeZone( $wgDBerrorLogTZ );
 279                 }
 280
 281                 // Workaround for https://bugs.php.net/bug.php?id=52063
 282                 // Can be removed when min PHP > 5.3.6
 283                 if ( $cachedTimezone === null ) {
 284                         $d = date_create( 'now' );
 285                 } else {
 286                         $d = date_create( 'now', $cachedTimezone );
 287                 }
 288                 $date = $d->format( 'D M j G:i:s T Y' );
 289
 290                 $host = wfHostname();
 291                 $wiki = wfWikiID();
 292
 293                 $text = "{$date}\t{$host}\t{$wiki}\t{$message}\n";
 294                 return $text;
 295         }
 296
 297
 298         /**
 299          * Format a message as `wfDebugLog() would have formatted it.
 300          *
 301          * @param string $channel
 302          * @param string $message
 303          * @param array $context
 304          */
 305         protected static function formatAsWfDebugLog( $channel, $message, $context ) {
 306                 $time = wfTimestamp( TS_DB );
 307                 $wiki = wfWikiID();
 308                 $host = wfHostname();
 309                 $text = "{$time} {$host} {$wiki}: {$message}\n";
 310                 return $text;
 311         }
 312
 313
 314         /**
 315          * Interpolate placeholders in logging message.
 316          *
 317          * @param string $message
 318          * @param array $context
 319          * @return string Interpolated message
 320          */
 321         public static function interpolate( $message, array $context ) {
 322                 if ( strpos( $message, '{' ) !== false ) {
 323                         $replace = array();
 324                         foreach ( $context as $key => $val ) {
 325                                 $replace['{' . $key . '}'] = self::flatten( $val );
 326                         }
 327                         $message = strtr( $message, $replace );
 328                 }
 329                 return $message;
 330         }
 331
 332
 333         /**
 334          * Convert a logging context element to a string suitable for
 335          * interpolation.
 336          *
 337          * @param mixed $item
 338          * @return string
 339          */
 340         protected static function flatten( $item ) {
 341                 if ( null === $item ) {
 342                         return '[Null]';
 343                 }
 344
 345                 if ( is_bool( $item ) ) {
 346                         return $item ? 'true' : 'false';
 347                 }
 348
 349                 if ( is_float( $item ) ) {
 350                         if ( is_infinite( $item ) ) {
 351                                 return ( $item > 0 ? '' : '-' ) . 'INF';
 352                         }
 353                         if ( is_nan( $item ) ) {
 354                                 return 'NaN';
 355                         }
 356                         return $item;
 357                 }
 358
 359                 if ( is_scalar( $item ) ) {
 360                         return (string) $item;
 361                 }
 362
 363                 if ( is_array( $item ) ) {
 364                         return '[Array(' . count( $item ) . ')]';
 365                 }
 366
 367                 if ( $item instanceof \DateTime ) {
 368                         return $item->format( 'c' );
 369                 }
 370
 371                 if ( $item instanceof Exception ) {
 372                         return '[Exception ' . get_class( $item ) . '( ' .
 373                                 $item->getFile() . ':' . $item->getLine() . ') ' .
 374                                 $item->getMessage() . ']';
 375                 }
 376
 377                 if ( is_object( $item ) ) {
 378                         if ( method_exists( $item, '__toString' ) ) {
 379                                 return (string) $item;
 380                         }
 381
 382                         return '[Object ' . get_class( $item ) . ']';
 383                 }
 384
 385                 if ( is_resource( $item ) ) {
 386                         return '[Resource ' . get_resource_type( $item ) . ']';
 387                 }
 388
 389                 return '[Unknown ' . gettype( $item ) . ']';
 390         }
 391
 392
 393         /**
 394          * Select the appropriate log output destination for the given log event.
 395          *
 396          * If the event context contains 'destination'
 397          *
 398          * @param string $channel
 399          * @param string $message
 400          * @param array $context
 401          * @return string
 402          */
 403         protected static function destination( $channel, $message, $context ) {
 404                 global $wgDebugLogFile, $wgDBerrorLog, $wgDebugLogGroups;
 405
 406                 // Default destination is the debug log file as historically used by
 407                 // the wfDebug function.
 408                 $destination = $wgDebugLogFile;
 409
 410                 if ( isset( $context['destination'] ) ) {
 411                         // Use destination explicitly provided in context
 412                         $destination = $context['destination'];
 413
 414                 } elseif ( $channel === 'wfDebug' ) {
 415                         $destination = $wgDebugLogFile;
 416
 417                 } elseif ( $channel === 'wfLogDBError' ) {
 418                         $destination = $wgDBerrorLog;
 419
 420                 } elseif ( isset( $wgDebugLogGroups[$channel] ) ) {
 421                         $logConfig = $wgDebugLogGroups[$channel];
 422
 423                         if ( is_array( $logConfig ) ) {
 424                                 $destination = $logConfig['destination'];
 425                         } else {
 426                                 $destination = strval( $logConfig );
 427                         }
 428                 }
 429
 430                 return $destination;
 431         }
 432
 433
 434         /**
 435         * Log to a file without getting "file size exceeded" signals.
 436         *
 437         * Can also log to UDP with the syntax udp://host:port/prefix. This will send
 438         * lines to the specified port, prefixed by the specified prefix and a space.
 439         *
 440         * @param string $text
 441         * @param string $file Filename
 442         * @throws MWException
 443         */
 444         public static function emit( $text, $file ) {
 445                 if ( substr( $file, 0, 4 ) == 'udp:' ) {
 446                         $transport = UDPTransport::newFromString( $file );
 447                         $transport->emit( $text );
 448                 } else {
 449                         \MediaWiki\suppressWarnings();
 450                         $exists = file_exists( $file );
 451                         $size = $exists ? filesize( $file ) : false;
 452                         if ( !$exists ||
 453                                 ( $size !== false && $size + strlen( $text ) < 0x7fffffff )
 454                         ) {
 455                                 file_put_contents( $file, $text, FILE_APPEND );
 456                         }
 457                         \MediaWiki\restoreWarnings();
 458                 }
 459         }
 460
 461 }