jenkins-bot has submitted this change and it was merged. Change subject: Rewrite logstash key conflict warning from I6677dbf6 ......................................................................
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 --- M autoload.php A includes/debug/logger/monolog/LogstashFormatter.php M includes/debug/logger/monolog/WikiProcessor.php A tests/phpunit/includes/debug/logger/monolog/LogstashFormatterTest.php 4 files changed, 140 insertions(+), 20 deletions(-) Approvals: Chad: Looks good to me, approved jenkins-bot: Verified diff --git a/autoload.php b/autoload.php index 30ef985..f0bbe92 100644 --- a/autoload.php +++ b/autoload.php @@ -875,6 +875,7 @@ '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 0000000..553cbf6 --- /dev/null +++ b/includes/debug/logger/monolog/LogstashFormatter.php @@ -0,0 +1,83 @@ +<?php + +namespace MediaWiki\Logger\Monolog; + +/** + * LogstashFormatter squashes the base message array and the context and extras subarrays into one. + * This can result in unfortunately named context fields overwriting other data (T145133). + * This class modifies the standard LogstashFormatter to rename such fields and flag the message. + * + * Compatible with Monolog 1.x only. + * + * @since 1.29 + */ +class LogstashFormatter extends \Monolog\Formatter\LogstashFormatter { + /** @var array Keys which should not be used in log context */ + protected $reservedKeys = [ + // from LogstashFormatter + 'message', 'channel', 'level', 'type', + // from WebProcessor + 'url', 'ip', 'http_method', 'server', 'referrer', + // from WikiProcessor + 'host', 'wiki', 'reqId', 'mwversion', + // from config magic + 'normalized_message', + ]; + + /** + * Prevent key conflicts + * @param array $record + * @return array + */ + protected function formatV0( array $record ) { + if ( $this->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 81e1e14..ad939a0 100644 --- a/includes/debug/logger/monolog/WikiProcessor.php +++ b/includes/debug/logger/monolog/WikiProcessor.php @@ -29,17 +29,6 @@ * @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 @@ */ 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 @@ ); 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 0000000..8086b4b --- /dev/null +++ b/tests/phpunit/includes/debug/logger/monolog/LogstashFormatterTest.php @@ -0,0 +1,55 @@ +<?php + +namespace MediaWiki\Logger\Monolog; + +class LogstashFormatterTest extends \PHPUnit_Framework_TestCase { + /** + * @dataProvider provideV1 + * @param array $record The input record. + * @param array $expected Associative array of expected keys and their values. + * @param array $notExpected List of keys that should not exist. + */ + public function testV1( array $record, array $expected, array $notExpected ) { + $formatter = new LogstashFormatter( 'app', 'system', null, null, LogstashFormatter::V1 ); + $formatted = json_decode( $formatter->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 ); + } +} -- To view, visit https://gerrit.wikimedia.org/r/323099 To unsubscribe, visit https://gerrit.wikimedia.org/r/settings Gerrit-MessageType: merged Gerrit-Change-Id: I31caee865cd60c785126478ac75c9aefce78eaaf Gerrit-PatchSet: 4 Gerrit-Project: mediawiki/core Gerrit-Branch: master Gerrit-Owner: Gergő Tisza <gti...@wikimedia.org> Gerrit-Reviewer: BryanDavis <bda...@wikimedia.org> Gerrit-Reviewer: Chad <ch...@wikimedia.org> Gerrit-Reviewer: Gergő Tisza <gti...@wikimedia.org> Gerrit-Reviewer: jenkins-bot <> _______________________________________________ MediaWiki-commits mailing list MediaWiki-commits@lists.wikimedia.org https://lists.wikimedia.org/mailman/listinfo/mediawiki-commits