Page MenuHomePhabricator

Echo qunit test has a time based race condition ( ext.echo.dm - mw.echo.dm.NotificationItem Constructing items FAILED )
Closed, ResolvedPublic

Description

This is the second time this has occurred recently: Jekins has failed because the timestamp generated by the code is one second off from the expected value, most likely because the code takes some time to run and the seconds hand of the clock might tick once in the mean time. example

A QUnit test for Echo has a race condition with a timestamp. The expected time and function results have a one second resolution and can divert:

Chrome 53.0.2785 (Linux 0.0.0) ext.echo.dm - mw.echo.dm.NotificationItem Constructing items FAILED
Empty data (getTimestamp)
Expected: "2016-12-15T13:54:41Z"
Actual: "2016-12-15T13:54:42Z"

Event Timeline

Huji created this task.Dec 27 2016, 5:30 PM
Restricted Application added a subscriber: Aklapper. · View Herald TranscriptDec 27 2016, 5:30 PM
hashar renamed this task from Jenkins should tolerate a one second delay to Echo qunit test has a time based race condition ( ext.echo.dm - mw.echo.dm.NotificationItem Constructing items FAILED ).Dec 28 2016, 11:26 AM
hashar updated the task description. (Show Details)

Tests added by Moriel. The race is the expected timestamp is forged first, then a notification object created which get a timestamp independently and can thus be different.

Change 321793 had a related patch set uploaded (by Catrope):
Fix 'getTimestamp' default check in NotificationItem unit test

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

hashar assigned this task to Catrope.Jan 3 2017, 7:42 PM

Thank you for taking care of that. Race conditions are nasty :]

Catrope reassigned this task from Catrope to Mooeypoo.Jan 3 2017, 8:54 PM
Catrope added a subscriber: Catrope.

(That was actually Moriel's patch, not mine. It predates this task, so all I did was tag it.)

Catrope reassigned this task from Mooeypoo to SBisson.Jan 3 2017, 9:44 PM
Catrope added a subscriber: Mooeypoo.

Reassigning to Stephane because Moriel's busy and he isn't.

Change 330480 had a related patch set uploaded (by Sbisson):
Use fake timer in Echo unit tests

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

Change 321793 abandoned by Sbisson:
Fix 'getTimestamp' default check in NotificationItem unit test

Reason:
Should be fixed by I6b0c8ae06360e6da016d97361cc2ccdeaf2e4343

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

Change 330480 merged by jenkins-bot:
Use fake timer in Echo unit tests

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

@SBisson The most recent failure was in https://integration.wikimedia.org/ci/job/mediawiki-extensions-qunit-jessie/21081/console (Build #21081 (Jan 11, 2017 6:42:25 PM)):

18:45:39 Chrome 55.0.2883 (Linux 0.0.0) ext.echo.dm - mw.echo.dm.NotificationItem Constructing items FAILED
18:45:39 	Empty data (getTimestamp)
18:45:39 	Expected: "2017-01-11T18:45:37Z"
18:45:39 	Actual: "2017-01-11T18:45:38Z"

After that up to the Build #21142 (Jan 11, 2017 11:47:38 PM), mediawiki-extensions-qunit-jessie is marked with SUCCESS.

That January 11th failure was for a patch made against the REL1_28 branch.

So I guess we could backport https://gerrit.wikimedia.org/r/#/c/330480/ ?

Change 331927 had a related patch set (by Paladox) published:
Use fake timer in Echo unit tests

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

Change 332335 had a related patch set uploaded (by Paladox):
Use fake timer in Echo unit tests

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

Change 331927 abandoned by Paladox:
Use fake timer in Echo unit tests

Reason:
Done here https://gerrit.wikimedia.org/r/332335

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

Etonkovidova added a comment.EditedJan 17 2017, 9:14 PM

Checked - no more "Empty data (getTimestamp)" errors for mediawiki-extensions-qunit-jessie tests. There are some failures (e.g. the most recent #21343), but with a different error.

QA recommendation: Resolve.

jmatazzoni closed this task as Resolved.Jan 17 2017, 10:39 PM

Change 332335 abandoned by Reedy:
Use fake timer in Echo unit tests

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