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