Code Coverage
 
Lines
Functions and Methods
Classes and Traits
Total
51.57% covered (warning)
51.57%
82 / 159
7.69% covered (danger)
7.69%
1 / 13
CRAP
0.00% covered (danger)
0.00%
0 / 1
LegacyLogger
51.57% covered (warning)
51.57%
82 / 159
7.69% covered (danger)
7.69%
1 / 13
905.58
0.00% covered (danger)
0.00%
0 / 1
 __construct
0.00% covered (danger)
0.00%
0 / 14
0.00% covered (danger)
0.00%
0 / 1
156
 setMinimumForTest
0.00% covered (danger)
0.00%
0 / 5
0.00% covered (danger)
0.00%
0 / 1
6
 log
64.00% covered (warning)
64.00%
16 / 25
0.00% covered (danger)
0.00%
0 / 1
18.72
 shouldEmit
73.68% covered (warning)
73.68%
14 / 19
0.00% covered (danger)
0.00%
0 / 1
11.82
 format
36.84% covered (danger)
36.84%
7 / 19
0.00% covered (danger)
0.00%
0 / 1
35.19
 formatAsWfDebug
66.67% covered (warning)
66.67%
4 / 6
0.00% covered (danger)
0.00%
0 / 1
3.33
 formatAsWfLogDBError
0.00% covered (danger)
0.00%
0 / 9
0.00% covered (danger)
0.00%
0 / 1
6
 formatAsWfDebugLog
0.00% covered (danger)
0.00%
0 / 5
0.00% covered (danger)
0.00%
0 / 1
2
 interpolate
100.00% covered (success)
100.00%
6 / 6
100.00% covered (success)
100.00%
1 / 1
3
 flatten
78.57% covered (warning)
78.57%
22 / 28
0.00% covered (danger)
0.00%
0 / 1
18.52
 destination
46.15% covered (danger)
46.15%
6 / 13
0.00% covered (danger)
0.00%
0 / 1
11.62
 emit
75.00% covered (warning)
75.00%
6 / 8
0.00% covered (danger)
0.00%
0 / 1
6.56
 maybeLogToStderr
50.00% covered (danger)
50.00%
1 / 2
0.00% covered (danger)
0.00%
0 / 1
2.50
1<?php
2/**
3 * @license GPL-2.0-or-later
4 * @file
5 */
6
7namespace MediaWiki\Logger;
8
9use DateTimeZone;
10use Error;
11use LogicException;
12use MediaWiki\Debug\MWDebug;
13use MediaWiki\Exception\MWExceptionHandler;
14use MediaWiki\WikiMap\WikiMap;
15use Monolog\LogRecord;
16use Psr\Log\AbstractLogger;
17use Psr\Log\LogLevel;
18use Throwable;
19use Wikimedia\Timestamp\ConvertibleTimestamp;
20use Wikimedia\Timestamp\TimestampFormat as TS;
21use Wikimedia\UDPTransport;
22
23/**
24 * PSR-3 logger that mimics the historic implementation of MediaWiki's former
25 * wfErrorLog logging implementation.
26 *
27 * This logger is configured by the following global configuration variables:
28 * - `$wgDebugLogFile`
29 * - `$wgDebugLogGroups`
30 * - `$wgDBerrorLog`
31 * - `$wgDBerrorLogTZ`
32 *
33 * See docs/Configuration.md for detailed explanations of these settings.
34 *
35 * @see \MediaWiki\Logger\LoggerFactory
36 * @since 1.25
37 * @ingroup Debug
38 * @copyright © 2014 Wikimedia Foundation and contributors
39 */
40class LegacyLogger extends AbstractLogger {
41
42    /**
43     * @var string
44     */
45    protected $channel;
46
47    private const LEVEL_DEBUG = 100;
48    private const LEVEL_INFO = 200;
49    private const LEVEL_NOTICE = 250;
50    private const LEVEL_WARNING = 300;
51    private const LEVEL_ERROR = 400;
52    private const LEVEL_CRITICAL = 500;
53    private const LEVEL_ALERT = 550;
54    private const LEVEL_EMERGENCY = 600;
55    private const LEVEL_INFINITY = 999;
56
57    /**
58     * Convert \Psr\Log\LogLevel constants into int for sensible comparisons
59     * These are the same values that Monolog uses
60     *
61     * @var array
62     */
63    protected static $levelMapping = [
64        LogLevel::DEBUG => self::LEVEL_DEBUG,
65        LogLevel::INFO => self::LEVEL_INFO,
66        LogLevel::NOTICE => self::LEVEL_NOTICE,
67        LogLevel::WARNING => self::LEVEL_WARNING,
68        LogLevel::ERROR => self::LEVEL_ERROR,
69        LogLevel::CRITICAL => self::LEVEL_CRITICAL,
70        LogLevel::ALERT => self::LEVEL_ALERT,
71        LogLevel::EMERGENCY => self::LEVEL_EMERGENCY,
72    ];
73
74    /**
75     * Minimum level. This is just to allow faster discard of debugging
76     * messages. Not all messages meeting the level will be logged.
77     *
78     * @var int
79     */
80    private $minimumLevel;
81
82    /**
83     * Whether the channel is a DB channel
84     *
85     * @var bool
86     */
87    private $isDB;
88
89    /**
90     * @param string $channel
91     */
92    public function __construct( $channel ) {
93        global $wgDebugLogFile, $wgDBerrorLog, $wgDebugLogGroups, $wgDebugToolbar, $wgDebugRawPage, $wgShowDebug;
94
95        $this->channel = $channel;
96        $this->isDB = ( $channel === 'rdbms' );
97
98        // Calculate minimum level, duplicating some of the logic from log() and shouldEmit()
99        if ( !$wgDebugRawPage && wfIsDebugRawPage() ) {
100            $this->minimumLevel = self::LEVEL_WARNING;
101        } elseif ( $wgDebugLogFile != '' || $wgShowDebug || $wgDebugToolbar ) {
102            // Log all messages if there is a debug log file or debug toolbar
103            $this->minimumLevel = self::LEVEL_DEBUG;
104        } elseif ( isset( $wgDebugLogGroups[$channel] ) ) {
105            $logConfig = $wgDebugLogGroups[$channel];
106            // Log messages if the config is set, according to the configured level
107            if ( is_array( $logConfig ) && isset( $logConfig['level'] ) ) {
108                $this->minimumLevel = self::$levelMapping[$logConfig['level']];
109            } else {
110                $this->minimumLevel = self::LEVEL_DEBUG;
111            }
112        } else {
113            // No other case hit: discard all messages
114            $this->minimumLevel = self::LEVEL_INFINITY;
115        }
116
117        if ( $this->isDB && $wgDBerrorLog && $this->minimumLevel > self::LEVEL_ERROR ) {
118            // Log DB errors if there is a DB error log
119            $this->minimumLevel = self::LEVEL_ERROR;
120        }
121    }
122
123    /**
124     * Change an existing Logger singleton to act like NullLogger.
125     *
126     * @internal For use by MediaWikiIntegrationTestCase::setNullLogger
127     * @param null|int $level
128     * @return int
129     */
130    public function setMinimumForTest( ?int $level ) {
131        if ( !defined( 'MW_PHPUNIT_TEST' ) ) {
132            throw new LogicException( 'Not allowed outside tests' );
133        }
134        // Set LEVEL_INFINITY if given null, or restore the original level.
135        $original = $this->minimumLevel;
136        $this->minimumLevel = $level ?? self::LEVEL_INFINITY;
137        return $original;
138    }
139
140    /**
141     * Logs with an arbitrary level.
142     *
143     * @param string|int $level
144     * @param string $message
145     * @param array $context
146     */
147    public function log( $level, $message, array $context = [] ): void {
148        if ( is_string( $level ) ) {
149            $level = self::$levelMapping[$level];
150        }
151        if ( $level < $this->minimumLevel ) {
152            return;
153        }
154
155        $context += LoggerFactory::getContext()->get();
156
157        if ( $this->isDB
158            && $level === self::LEVEL_DEBUG
159            && isset( $context['sql'] )
160        ) {
161            // Also give the query information to the MWDebug tools
162            MWDebug::query(
163                $context['sql'],
164                $context['method'],
165                $context['runtime_ms'] / 1000,
166                $context['db_server'],
167                $context['rows'],
168            );
169        }
170
171        // If this is a DB-related error, and the site has $wgDBerrorLog
172        // configured, rewrite the channel as wfLogDBError instead.
173        // Likewise, if the site does not use  $wgDBerrorLog, it should
174        // configurable like any other channel via $wgDebugLogGroups
175        // or $wgMWLoggerDefaultSpi.
176        global $wgDBerrorLog;
177        if ( $this->isDB && $level >= self::LEVEL_ERROR && $wgDBerrorLog ) {
178            // Format and write DB errors to the legacy locations
179            $effectiveChannel = 'wfLogDBError';
180        } else {
181            $effectiveChannel = $this->channel;
182        }
183
184        if ( self::shouldEmit( $effectiveChannel, $message, $level, $context ) ) {
185            $text = self::format( $effectiveChannel, $message, $context );
186            $destination = self::destination( $effectiveChannel, $message, $context );
187            $this->maybeLogToStderr( $text );
188            self::emit( $text, $destination );
189        }
190        if ( !isset( $context['private'] ) || !$context['private'] ) {
191            // Add to debug toolbar if not marked as "private"
192            MWDebug::debugMsg( $message, [ 'channel' => $this->channel ] + $context );
193        }
194    }
195
196    /**
197     * Determine if the given message should be emitted or not.
198     *
199     * @param string $channel
200     * @param string $message
201     * @param string|int $level \Psr\Log\LogEvent constant or Monolog level int
202     * @param array|LogRecord $context
203     * @return bool True if message should be sent to disk/network, false
204     * otherwise
205     */
206    public static function shouldEmit( $channel, $message, $level, $context ) {
207        global $wgDebugLogFile, $wgDBerrorLog, $wgDebugLogGroups;
208
209        if ( is_string( $level ) ) {
210            $level = self::$levelMapping[$level];
211        }
212
213        if ( $channel === 'wfLogDBError' ) {
214            // wfLogDBError messages are emitted if a database log location is
215            // specified.
216            $shouldEmit = (bool)$wgDBerrorLog;
217
218        } elseif ( $channel === 'wfDebug' ) {
219            // wfDebug messages are emitted if a catch all logging file has
220            // been specified. Checked explicitly so that 'private' flagged
221            // messages are not discarded by unset $wgDebugLogGroups channel
222            // handling below.
223            $shouldEmit = $wgDebugLogFile != '';
224
225        } elseif ( isset( $wgDebugLogGroups[$channel] ) ) {
226            $logConfig = $wgDebugLogGroups[$channel];
227
228            if ( is_array( $logConfig ) ) {
229                $shouldEmit = true;
230                if ( isset( $logConfig['sample'] ) ) {
231                    // Emit randomly with a 1 in 'sample' chance for each message.
232                    $shouldEmit = mt_rand( 1, $logConfig['sample'] ) === 1;
233                }
234
235                if ( isset( $logConfig['level'] ) ) {
236                    $shouldEmit = $level >= self::$levelMapping[$logConfig['level']];
237                }
238            } else {
239                // Emit unless the config value is explicitly false.
240                $shouldEmit = $logConfig !== false;
241            }
242
243        } elseif ( isset( $context['private'] ) && $context['private'] ) {
244            // Don't emit if the message didn't match previous checks based on
245            // the channel and the event is marked as private. This check
246            // discards messages sent via wfDebugLog() with dest == 'private'
247            // and no explicit wgDebugLogGroups configuration.
248            $shouldEmit = false;
249        } else {
250            // Default return value is the same as the historic wfDebug
251            // method: emit if $wgDebugLogFile has been set.
252            $shouldEmit = $wgDebugLogFile != '';
253        }
254
255        return $shouldEmit;
256    }
257
258    /**
259     * Format a message.
260     *
261     * Messages to the 'wfDebug' and 'wfLogDBError' channels receive special formatting to mimic the
262     * historic output of the functions of the same name. All other channel values are formatted
263     * based on the historic output of the `wfDebugLog()` global function.
264     *
265     * @param string $channel
266     * @param string $message
267     * @param array $context
268     * @return string
269     */
270    public static function format( $channel, $message, $context ) {
271        global $wgDebugLogGroups, $wgLogExceptionBacktrace;
272
273        if ( $channel === 'wfDebug' ) {
274            $text = self::formatAsWfDebug( $channel, $message, $context );
275
276        } elseif ( $channel === 'wfLogDBError' ) {
277            $text = self::formatAsWfLogDBError( $channel, $message, $context );
278
279        } elseif ( !isset( $wgDebugLogGroups[$channel] ) ) {
280            $text = self::formatAsWfDebug(
281                $channel, "[{$channel}] {$message}", $context );
282
283        } else {
284            // Default formatting is wfDebugLog's historic style
285            $text = self::formatAsWfDebugLog( $channel, $message, $context );
286        }
287
288        // Append stacktrace of throwable if available
289        if ( $wgLogExceptionBacktrace && isset( $context['exception'] ) ) {
290            $e = $context['exception'];
291            $backtrace = false;
292
293            if ( $e instanceof Throwable ) {
294                $backtrace = MWExceptionHandler::getRedactedTrace( $e );
295
296            } elseif ( is_array( $e ) && isset( $e['trace'] ) ) {
297                // Throwable has already been unpacked as structured data
298                $backtrace = $e['trace'];
299            }
300
301            if ( $backtrace ) {
302                $text .= MWExceptionHandler::prettyPrintTrace( $backtrace ) .
303                    "\n";
304            }
305        }
306
307        return self::interpolate( $text, $context );
308    }
309
310    /**
311     * Format a message as `wfDebug()` would have formatted it.
312     *
313     * @param string $channel
314     * @param string $message
315     * @param array $context
316     * @return string
317     */
318    protected static function formatAsWfDebug( $channel, $message, $context ) {
319        $text = preg_replace( '![\x00-\x08\x0b\x0c\x0e-\x1f]!', ' ', $message );
320        if ( isset( $context['seconds_elapsed'] ) ) {
321            // Prepend elapsed request time and real memory usage with two
322            // trailing spaces.
323            $text = "{$context['seconds_elapsed']} {$context['memory_used']}  {$text}";
324        }
325        if ( isset( $context['prefix'] ) ) {
326            $text = "{$context['prefix']}{$text}";
327        }
328        return "{$text}\n";
329    }
330
331    /**
332     * Format a message as `wfLogDBError()` would have formatted it.
333     *
334     * @param string $channel
335     * @param string $message
336     * @param array $context
337     * @return string
338     */
339    protected static function formatAsWfLogDBError( $channel, $message, $context ) {
340        global $wgDBerrorLogTZ;
341        static $cachedTimezone = null;
342
343        if ( !$cachedTimezone ) {
344            $cachedTimezone = new DateTimeZone( $wgDBerrorLogTZ );
345        }
346
347        $d = date_create( 'now', $cachedTimezone );
348        $date = $d->format( 'D M j G:i:s T Y' );
349
350        $host = wfHostname();
351        $wiki = WikiMap::getCurrentWikiId();
352
353        $text = "{$date}\t{$host}\t{$wiki}\t{$message}\n";
354        return $text;
355    }
356
357    /**
358     * Format a message as `wfDebugLog() would have formatted it.
359     *
360     * @param string $channel
361     * @param string $message
362     * @param array $context
363     * @return string
364     */
365    protected static function formatAsWfDebugLog( $channel, $message, $context ) {
366        $time = ConvertibleTimestamp::now( TS::DB );
367        $wiki = WikiMap::getCurrentWikiId();
368        $host = wfHostname();
369        $text = "{$time} {$host} {$wiki}: {$message}\n";
370        return $text;
371    }
372
373    /**
374     * Interpolate placeholders in logging message.
375     *
376     * @param string $message
377     * @param array $context
378     * @return string Interpolated message
379     */
380    public static function interpolate( $message, array $context ) {
381        if ( str_contains( $message, '{' ) ) {
382            $replace = [];
383            foreach ( $context as $key => $val ) {
384                $replace['{' . $key . '}'] = self::flatten( $val );
385            }
386            $message = strtr( $message, $replace );
387        }
388        return $message;
389    }
390
391    /**
392     * Convert a logging context element to a string suitable for
393     * interpolation.
394     *
395     * @param mixed $item
396     * @return string
397     */
398    protected static function flatten( $item ) {
399        if ( $item === null ) {
400            return '[Null]';
401        }
402
403        if ( is_bool( $item ) ) {
404            return $item ? 'true' : 'false';
405        }
406
407        if ( is_float( $item ) ) {
408            if ( is_infinite( $item ) ) {
409                return ( $item > 0 ? '' : '-' ) . 'INF';
410            }
411            if ( is_nan( $item ) ) {
412                return 'NaN';
413            }
414            return (string)$item;
415        }
416
417        if ( is_scalar( $item ) ) {
418            return (string)$item;
419        }
420
421        if ( is_array( $item ) ) {
422            return '[Array(' . count( $item ) . ')]';
423        }
424
425        if ( $item instanceof \DateTime ) {
426            return $item->format( 'c' );
427        }
428
429        if ( $item instanceof Throwable ) {
430            $which = $item instanceof Error ? 'Error' : 'Exception';
431            return '[' . $which . ' ' . get_class( $item ) . '( ' .
432                $item->getFile() . ':' . $item->getLine() . ') ' .
433                $item->getMessage() . ']';
434        }
435
436        if ( is_object( $item ) ) {
437            if ( method_exists( $item, '__toString' ) ) {
438                return (string)$item;
439            }
440
441            return '[Object ' . get_class( $item ) . ']';
442        }
443
444        // phpcs:ignore MediaWiki.Usage.ForbiddenFunctions.is_resource
445        if ( is_resource( $item ) ) {
446            return '[Resource ' . get_resource_type( $item ) . ']';
447        }
448
449        return '[Unknown ' . get_debug_type( $item ) . ']';
450    }
451
452    /**
453     * Select the appropriate log output destination for the given log event.
454     *
455     * If the event context contains 'destination'
456     *
457     * @param string $channel
458     * @param string $message
459     * @param array $context
460     * @return string
461     */
462    protected static function destination( $channel, $message, $context ) {
463        global $wgDebugLogFile, $wgDBerrorLog, $wgDebugLogGroups;
464
465        // Default destination is the debug log file as historically used by
466        // the wfDebug function.
467        $destination = $wgDebugLogFile;
468
469        if ( isset( $context['destination'] ) ) {
470            // Use destination explicitly provided in context
471            $destination = $context['destination'];
472
473        } elseif ( $channel === 'wfDebug' ) {
474            $destination = $wgDebugLogFile;
475
476        } elseif ( $channel === 'wfLogDBError' ) {
477            $destination = $wgDBerrorLog;
478
479        } elseif ( isset( $wgDebugLogGroups[$channel] ) ) {
480            $logConfig = $wgDebugLogGroups[$channel];
481
482            if ( is_array( $logConfig ) ) {
483                $destination = $logConfig['destination'];
484            } else {
485                $destination = strval( $logConfig );
486            }
487        }
488
489        return $destination;
490    }
491
492    /**
493     * Log to a file without getting "file size exceeded" signals.
494     *
495     * Can also log to UDP with the syntax udp://host:port/prefix. This will send
496     * lines to the specified port, prefixed by the specified prefix and a space.
497     *
498     * @param string $text
499     * @param string $file Filename
500     */
501    public static function emit( $text, $file ) {
502        if ( str_starts_with( $file, 'udp:' ) ) {
503            $transport = UDPTransport::newFromString( $file );
504            $transport->emit( $text );
505        } else {
506            // phpcs:ignore Generic.PHP.NoSilencedErrors.Discouraged
507            $exists = @file_exists( $file );
508            // phpcs:ignore Generic.PHP.NoSilencedErrors.Discouraged
509            $size = $exists ? @filesize( $file ) : false;
510            if ( !$exists ||
511                ( $size !== false && $size + strlen( $text ) < 0x7fffffff )
512            ) {
513                // phpcs:ignore Generic.PHP.NoSilencedErrors.Discouraged
514                @file_put_contents( $file, $text, FILE_APPEND );
515            }
516        }
517    }
518
519    /**
520     * If MW_LOG_STDERR is set (used currently in `composer serve`) then also
521     * emit to stderr using error_log().
522     *
523     * @param string $text
524     * @return void
525     */
526    private function maybeLogToStderr( string $text ): void {
527        if ( getenv( 'MW_LOG_STDERR' ) ) {
528            error_log( trim( $text ) );
529        }
530    }
531
532}