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