From: Gergő Tisza Date: Wed, 23 Nov 2016 01:01:07 +0000 (+0000) Subject: Rewrite logstash key conflict warning from I6677dbf6 X-Git-Tag: 1.31.0-rc.0~3984^2~1 X-Git-Url: http://git.cyclocoop.org/?a=commitdiff_plain;h=98f143e0f48cd024c02d40083951c5b26d7ee7dc;p=lhc%2Fweb%2Fwiklou.git Rewrite logstash key conflict warning from I6677dbf6 * do not warn if something is overwritten with an identical value (happens a lot with 'ip') * move to LogstashFormatter so we can check for the value * instead of spamming errors, just add a flag to the logstash data Bug: T145133 Change-Id: I31caee865cd60c785126478ac75c9aefce78eaaf --- diff --git a/autoload.php b/autoload.php index 30ef985be0..f0bbe92e27 100644 --- a/autoload.php +++ b/autoload.php @@ -875,6 +875,7 @@ $wgAutoloadLocalClasses = [ 'MediaWiki\\Logger\\Monolog\\LegacyFormatter' => __DIR__ . '/includes/debug/logger/monolog/LegacyFormatter.php', 'MediaWiki\\Logger\\Monolog\\LegacyHandler' => __DIR__ . '/includes/debug/logger/monolog/LegacyHandler.php', 'MediaWiki\\Logger\\Monolog\\LineFormatter' => __DIR__ . '/includes/debug/logger/monolog/LineFormatter.php', + 'MediaWiki\\Logger\\Monolog\\LogstashFormatter' => __DIR__ . '/includes/debug/logger/monolog/LogstashFormatter.php', 'MediaWiki\\Logger\\Monolog\\SyslogHandler' => __DIR__ . '/includes/debug/logger/monolog/SyslogHandler.php', 'MediaWiki\\Logger\\Monolog\\WikiProcessor' => __DIR__ . '/includes/debug/logger/monolog/WikiProcessor.php', 'MediaWiki\\Logger\\NullSpi' => __DIR__ . '/includes/debug/logger/NullSpi.php', diff --git a/includes/debug/logger/monolog/LogstashFormatter.php b/includes/debug/logger/monolog/LogstashFormatter.php new file mode 100644 index 0000000000..553cbf61c4 --- /dev/null +++ b/includes/debug/logger/monolog/LogstashFormatter.php @@ -0,0 +1,83 @@ +contextPrefix ) { + return parent::formatV0( $record ); + } + + $context = !empty( $record['context'] ) ? $record['context'] : []; + $record['context'] = []; + $formatted = parent::formatV0( $record ); + + $formatted['@fields'] = $this->fixKeyConflicts( $formatted['@fields'], $context ); + return $formatted; + } + + /** + * Prevent key conflicts + * @param array $record + * @return array + */ + protected function formatV1( array $record ) { + if ( $this->contextPrefix ) { + return parent::formatV1( $record ); + } + + $context = !empty( $record['context'] ) ? $record['context'] : []; + $record['context'] = []; + $formatted = parent::formatV1( $record ); + + $formatted = $this->fixKeyConflicts( $formatted, $context ); + return $formatted; + } + + /** + * Check whether some context field would overwrite another message key. If so, rename + * and flag. + * @param array $fields Fields to be sent to logstash + * @param array $context Copy of the original $record['context'] + * @return array Updated version of $fields + */ + protected function fixKeyConflicts( array $fields, array $context ) { + foreach ( $context as $key => $val ) { + if ( + in_array( $key, $this->reservedKeys, true ) && + isset( $fields[$key] ) && $fields[$key] !== $val + ) { + $fields['logstash_formatter_key_conflict'][] = $key; + $key = 'c_' . $key; + } + $fields[$key] = $val; + } + return $fields; + } +} diff --git a/includes/debug/logger/monolog/WikiProcessor.php b/includes/debug/logger/monolog/WikiProcessor.php index 81e1e14763..ad939a0932 100644 --- a/includes/debug/logger/monolog/WikiProcessor.php +++ b/includes/debug/logger/monolog/WikiProcessor.php @@ -29,17 +29,6 @@ namespace MediaWiki\Logger\Monolog; * @copyright © 2013 Bryan Davis and Wikimedia Foundation. */ class WikiProcessor { - /** @var array Keys which should not be used in log context */ - protected $reservedKeys = [ - // from monolog:src/Monolog/Formatter/LogstashFormatter.php#L71-L88 - 'message', 'channel', 'level', 'type', - // from WebProcessor - 'url', 'ip', 'http_method', 'server', 'referrer', - // from WikiProcessor - 'host', 'wiki', 'reqId', 'mwversion', - // from config magic - 'normalized_message', - ]; /** * @param array $record @@ -47,15 +36,6 @@ class WikiProcessor { */ public function __invoke( array $record ) { global $wgVersion; - - // some log aggregators such as Logstash will merge the log context into the main - // metadata and end up overwriting the data coming from processors - foreach ( $this->reservedKeys as $key ) { - if ( isset( $record['context'][$key] ) ) { - wfLogWarning( __METHOD__ . ": '$key' key overwritten in log context." ); - } - } - $record['extra'] = array_merge( $record['extra'], [ @@ -67,4 +47,5 @@ class WikiProcessor { ); return $record; } + } diff --git a/tests/phpunit/includes/debug/logger/monolog/LogstashFormatterTest.php b/tests/phpunit/includes/debug/logger/monolog/LogstashFormatterTest.php new file mode 100644 index 0000000000..8086b4bf23 --- /dev/null +++ b/tests/phpunit/includes/debug/logger/monolog/LogstashFormatterTest.php @@ -0,0 +1,55 @@ +format( $record ), true ); + foreach ( $expected as $key => $value ) { + $this->assertArrayHasKey( $key, $formatted ); + $this->assertSame( $value, $formatted[$key] ); + } + foreach ( $notExpected as $key ) { + $this->assertArrayNotHasKey( $key, $formatted ); + } + } + + public function provideV1() { + return [ + [ + [ 'extra' => [ 'foo' => 1 ], 'context' => [ 'bar' => 2 ] ], + [ 'foo' => 1, 'bar' => 2 ], + [ 'logstash_formatter_key_conflict' ], + ], + [ + [ 'extra' => [ 'url' => 1 ], 'context' => [ 'url' => 2 ] ], + [ 'url' => 1, 'c_url' => 2, 'logstash_formatter_key_conflict' => [ 'url' ] ], + [], + ], + [ + [ 'channel' => 'x', 'context' => [ 'channel' => 'y' ] ], + [ 'channel' => 'x', 'c_channel' => 'y', + 'logstash_formatter_key_conflict' => [ 'channel' ] ], + [], + ], + ]; + } + + public function testV1WithPrefix() { + $formatter = new LogstashFormatter( 'app', 'system', null, 'ctx_', LogstashFormatter::V1 ); + $record = [ 'extra' => [ 'url' => 1 ], 'context' => [ 'url' => 2 ] ]; + $formatted = json_decode( $formatter->format( $record ), true ); + $this->assertArrayHasKey( 'url', $formatted ); + $this->assertSame( 1, $formatted['url'] ); + $this->assertArrayHasKey( 'ctx_url', $formatted ); + $this->assertSame( 2, $formatted['ctx_url'] ); + $this->assertArrayNotHasKey( 'c_url', $formatted ); + } +}