Page MenuHomePhabricator

Flaky test Monolog\CeeFormatterTest::testV1
Closed, ResolvedPublicPRODUCTION ERROR

Description

Affecting the merging of mediawiki/core patches into the master branch.

There was 1 failure:
14:47:45 
14:47:45 1) MediaWiki\Logger\Monolog\CeeFormatterTest::testV1
14:47:45 === Logs generated by test case
14:47:45 [PHPUnitCommand] [info] FAILURE in MediaWiki\Logger\Monolog\CeeFormatterTest::testV1: [PHPUnit\Framework\ExpectationFailedException] Failed asserting that two strings are identical. {"private":false}
14:47:45 ===
14:47:45 Failed asserting that two strings are identical.
14:47:45 --- Expected
14:47:45 +++ Actual
14:47:45 @@ @@
14:47:45 -'@cee: {"@timestamp":"2019-03-19T14:47:15+00:00","@version":1,"host":"system","type":"app","url":1,"ctx_url":2}
14:47:45 +'@cee: {"@timestamp":"2019-03-19T14:47:16+00:00","@version":1,"host":"system","type":"app","url":1,"ctx_url":2}
14:47:45 
14:47:45 /workspace/src/tests/phpunit/includes/debug/logger/monolog/CeeFormatterTest.php:15
14:47:45 /workspace/src/maintenance/doMaintenance.php:94
14:47:45

Event Timeline

Change 497516 had a related patch set uploaded (by Krinkle; owner: Krinkle):
[mediawiki/core@master] debug: Disable flaky CeeFormatterTest

https://gerrit.wikimedia.org/r/497516

Change 497516 merged by jenkins-bot:
[mediawiki/core@master] debug: Disable flaky CeeFormatterTest

https://gerrit.wikimedia.org/r/497516

Doh! Indeed the test will be flaky with timestamps, thoughts on how to unflak the test?

Doh! Indeed the test will be flaky with timestamps, thoughts on how to unflak the test?

Where is the code that decides on the timestamp for the actual value? And for the expected value?

Doh! Indeed the test will be flaky with timestamps, thoughts on how to unflak the test?

Where is the code that decides on the timestamp for the actual value? And for the expected value?

The timestamp data is set by Monolog when the log event is generated: https://github.com/Seldaek/monolog/blob/ee26edfd8c5cc49780fa331f16b23fb0acbf59b1/src/Monolog/Logger.php#L301-L309

The formatting into the string representation in the JSON output happens in a long chain of inheritance, but ultimately is done by https://github.com/Seldaek/monolog/blob/790ff7fd1dd832b24d856eb75c24e7b199a1d6b1/src/Monolog/Formatter/NormalizerFormatter.php#L368-L377

The "fix" is probably a diff check that ignores the @timestamp data.

Where is the code that decides on the timestamp for the actual value? And for the expected value?

The timestamp data is set by Monolog when the log event is generated: https://github.com/Seldaek/monolog/blob/ee26edfd8c5cc49780fa331f16b23fb0acbf59b1/src/Monolog/Logger.php#L301-L309

'datetime' => new DateTimeImmutable($this->microsecondTimestamps, $this->timezone),

It seems microsecondTimestamps is a boolean, but DateTimeImmutable::__construct accepts a parsed string (defaulting to "now"). Anyway, assuming that somehow works and actually creates a timestamp. I guess this is indeed where the time is decided and there's no way to override or inject that?

mmodell changed the subtype of this task from "Task" to "Production Error".Aug 28 2019, 11:07 PM
'datetime' => new DateTimeImmutable($this->microsecondTimestamps, $this->timezone),

It seems microsecondTimestamps is a boolean, but DateTimeImmutable::__construct accepts a parsed string (defaulting to "now"). Anyway, assuming that somehow works and actually creates a timestamp. I guess this is indeed where the time is decided and there's no way to override or inject that?

DateTimeImmutable is a class in Monolog/ namespace. It's not passing the $microsecondTimestamps prop to native DateTimeImmutable, which would have resulted in fatal exception

I have checked this while working on T273603 and I think there's an easy way to fix this.

Change 662796 had a related patch set uploaded (by Ammarpad; owner: Ammarpad):
[mediawiki/core@master] Fix broken Monolog\CeeFormatterTest

https://gerrit.wikimedia.org/r/662796

Change 662796 merged by jenkins-bot:
[mediawiki/core@master] logger: Fix broken Monolog\CeeFormatterTest

https://gerrit.wikimedia.org/r/662796

Ammarpad claimed this task.