Last modified: 2014-07-11 21:51:04 UTC

Wikimedia Bugzilla is closed!

Wikimedia migrated from Bugzilla to Phabricator. Bug reports are handled in Wikimedia Phabricator.
This static website is read-only and for historical purposes. It is not possible to log in and except for displaying bug reports and their history, links might be broken. See T65579, the corresponding Phabricator task for complete and up-to-date bug report information.
Bug 63579 - QUnit tests for jquery.makeCollapsible and jquery.color failing intermittently on Jenkins
QUnit tests for jquery.makeCollapsible and jquery.color failing intermittentl...
Status: RESOLVED FIXED
Product: MediaWiki
Classification: Unclassified
JavaScript (Other open bugs)
1.23.0
All All
: High major (vote)
: ---
Assigned To: Matthew Flaschen
: code-update-regression
: 63647 (view as bug list)
Depends on:
Blocks:
  Show dependency treegraph
 
Reported: 2014-04-05 18:45 UTC by Bartosz Dziewoński
Modified: 2014-07-11 21:51 UTC (History)
12 users (show)

See Also:
Web browser: ---
Mobile Platform: ---
Assignee Huggle Beta Tester: ---


Attachments

Description Bartosz Dziewoński 2014-04-05 18:45:46 UTC
QUnit tests for jquery.makeCollapsible are often failing on Jenkins. I've seen this at least three times in the last week or so, most recently on https://gerrit.wikimedia.org/r/#/c/124051/ . Every time the failure was within the jquery.makeCollapsible tests (but I'm not entirely sure if on the same exact test).

This might be related to the fake timers being used in them.
Comment 1 Bartosz Dziewoński 2014-04-05 18:50:34 UTC
Another example from today: https://gerrit.wikimedia.org/r/#/c/123804/
Comment 2 Bartosz Dziewoński 2014-04-07 10:32:43 UTC
Again: https://gerrit.wikimedia.org/r/#/c/124302/
Comment 3 Umherirrender 2014-04-07 18:13:10 UTC
Warning: PhantomJS timed out, possibly due to a missing QUnit start() call. Use --force to continue

On https://gerrit.wikimedia.org/r/#/c/124366/ and some more of my changes from last days

Possible regression from Gerrit change #117153

Please have a look into this tests. Thanks.
Comment 4 Krinkle 2014-04-07 19:13:56 UTC
*** Bug 63647 has been marked as a duplicate of this bug. ***
Comment 5 Krinkle 2014-04-07 19:15:45 UTC
This has nothing to do with a time limit of any kind. The qunit tests run quicker than ever and have recently been sped  up a lot further by getting rid of slow animations and http calls to the server etc.

This is failing because for some reason QUnit unexpectedly dies at which point PhantomJS never gets the 'end' event callback and thus times out. It does not time out because the tests are too long or anything.
Comment 6 Bartosz Dziewoński 2014-04-11 13:12:00 UTC
Somewhat interestingly, the job sometimes hangs for real.

From <https://gerrit.wikimedia.org/r/#/c/125370/>: "https://integration.wikimedia.org/ci/job/mediawiki-core-qunit/19052/console : ABORTED in 5h 51m 36s"
Comment 7 Antoine "hashar" Musso (WMF) 2014-04-11 13:24:42 UTC
mediawiki-core-qunit is now sometime stuck. I killed a few jobs earlier today that ran for multiple hours.

Just killed  https://integration.wikimedia.org/ci/job/mediawiki-core-qunit/19068/console which was running for 10 minutes.

Might want to add adjust the timeout of jobs to something more reasonable than the current 360 minutes.
Comment 8 Krinkle 2014-04-11 19:10:50 UTC
The internal time out is 30 seconds.

It hanging for more than 30 seconds is new, that didn't happen until today.

Both that 30s timeout and the 360min timeout should not be triggered because the tests aren't actually taking more than < 10-20 seconds to run. Something is causing it to get stuck or in some kind of loop...
Comment 9 Krinkle 2014-04-17 17:15:31 UTC
This was resolved after the following upgrades were made:


* [jenkins] Update wmfgrunt dependencies to newer upstream versions 
  - grunt-contrib-qunit from v0.2.0 to v0.4.0
  - phantomjs from v1.8.1 to v1.9.7
  https://gerrit.wikimedia.org/r/#/c/125052/

* [mediawiki-core] Update QUnit from v1.11.0 to v1.14.0 
  https://gerrit.wikimedia.org/r/#/c/125533/

The latter is what made the false failures go away, so presumably the changes in those QUnit releases fixed it (possibly the changes in v1.12.0 and v1.14.0 that cache setTimeout and clearTimeout to protect against mocks).
Comment 10 Matthew Flaschen 2014-05-07 01:39:01 UTC
It's recurred.  See https://integration.wikimedia.org/ci/job/mwext-GuidedTour-qunit/220/console .  It's from about 6 hours ago.

It's causing spurious failures in GuidedTour (likely other extensions too).  E.g.:

19:08:11 >> Message: after expanding: contentItem is visible
19:08:11 >> Actual: false
19:08:11 >> Expected: true
Comment 11 Matthew Flaschen 2014-05-22 18:24:43 UTC
Someone really needs to take a look at this.  It is causing major friction in the continuous integration pipeline due to spurious failures.
Comment 12 Greg Grossmeier 2014-05-22 18:33:14 UTC
Krinkle/Antoine: can you take a look please.
Comment 13 Krinkle 2014-05-22 18:41:06 UTC
This is an old report. Been fixed a while ago.
Comment 14 Krinkle 2014-05-22 18:41:46 UTC
Hm.. will give it another look. Although I doubt it's a bug in core.
Comment 15 Matthew Flaschen 2014-06-15 00:26:06 UTC
I'm going to work on this as well, since it's a recurring problem affecting the Growth team.
Comment 16 Bartosz Dziewoński 2014-06-26 14:04:31 UTC
This is really problematic… https://gerrit.wikimedia.org/r/#/c/137837/
Comment 17 Matthew Flaschen 2014-07-01 20:31:08 UTC
Actually, the first failure (at least sometimes, such as 220 mentioned above) is jquery.color.

From the full log (https://integration.wikimedia.org/ci/job/mwext-GuidedTour-qunit/220/consoleFull) (without full it shows the tail):

19:08:06 jquery.color - animate...ERROR
19:08:06 >> Message: Expected 1 assertions, but 0 were run
Comment 18 Gerrit Notification Bot 2014-07-01 21:14:32 UTC
Change 143481 had a related patch set uploaded by Mattflaschen:
Use QUnit.asyncTest even for fake timers, to fix spurious failures

https://gerrit.wikimedia.org/r/143481
Comment 19 Krinkle 2014-07-01 21:31:21 UTC
Considering it is only affecting tests related to asynchronous Date manipulation, I suspect one or more of the extensions the Growth team maintains is interfering with that interface.

That was the case a few months back as well (that time it was an infrastructure library inside Grunt/Jenkins causing it).

I can't reproduce this in MediaWiki core or any of the other extensions I can find. The test for MediaWiki core alone or those run for extensions such as VisualEditor and other projects are all consistently passing.
Comment 20 Matthew Flaschen 2014-07-01 23:42:53 UTC
(In reply to Krinkle from comment #19)
> Considering it is only affecting tests related to asynchronous Date
> manipulation, I suspect one or more of the extensions the Growth team
> maintains is interfering with that interface.

I'm not sure what you mean by "asynchronous Date manipulation".  Sinon's fake timer methods are synchronous, AFAICT, just a simulation where you advance the clock manually.

As far as the actual code (jquery.color.js and jquery.makeCollapsible.js), they are both using .promise (https://api.jquery.com/promise/) to monitor completed actions in the fx queue.

GuidedTour (one of the extensions this bug affects) does not have any asynchronous tests, nor does GettingStarted.  Although we use setTimeout, we certainly don't do anything weird like redefining it.

EventLogging (one of our dependencies) does use asynchronous tests, but we're hardly the only extension to use EventLogging.  (Note, EventLogging is not a Growth extension).  I don't know if any extensions with QUnit tests use EventLogging, but I suspect they do.

If you see a bug (or unexpected interaction) which we can fix in a Growth extension, let us know.

However, practically speaking, we should focus on getting this bug fixed.  My next step (as mentioned on Gerrit) will be to try use PhantomJS's remote debugging to step through and find exactly what's happening.
Comment 21 Matthew Flaschen 2014-07-03 01:20:28 UTC
Doesn't look like we have a GettingStarted example yet, so:

https://integration.wikimedia.org/ci/job/mwext-GettingStarted-qunit/58/consoleFull

(Jul 3, 2014 12:13:51 AM per https://integration.wikimedia.org/ci/job/mwext-GettingStarted-qunit/58/)

Seems to be the same set.  Again, jquery.color is the first error.

If it affects any other extensions, please add.
Comment 22 Krinkle 2014-07-03 13:09:08 UTC
Turning the tests from sync to async in core is the functional equivalent of removing the assertion "test framework works as expected". It's like boldly removing unit tests or parser tests because when executed with a certain extension, they no longer match expected behaviour.

I can reproduce this consistently but only with those extensions installed. With plenty of other extensions installed it works fine. I don't see anything obvious this extension that might cause it, but that wasn't the case earlier this year either and eventually we did find the problem there too.

After static analysis yielded nothing, I turned to removing code locally until you find out what's causing it. Maybe it'll turn out to be a trigger that calls back into mediawiki-core, maybe not. But the surface layer triggering it isn't in core.
Comment 23 Gerrit Notification Bot 2014-07-11 00:52:45 UTC
Change 145479 had a related patch set uploaded by Mattflaschen:
Fix spurious QUnit failures related to fake timers

https://gerrit.wikimedia.org/r/145479
Comment 24 Matthew Flaschen 2014-07-11 00:55:33 UTC
You were right, I didn't need to make it async.

Side note, the SinonJS docs imply that useFakeTimers() uses the current date by default.  Unfortunately (this would have fixed half of my patch), this is not true, so I submitted a patch for those docs at https://github.com/sinonjs/sinon-docs/pull/2 .
Comment 25 Krinkle 2014-07-11 01:47:03 UTC
Also, this really should've been a separate bug. The bug as reported was fixed and affected core. This looks similar (it's something with timers and animations), but a different exception is thrown, different unit tests are failing, and it's only affecting extensions (doesn't mean the bug isn;t in core, but it's a separate bug).

This isn't a "something is wrong with qunit and timers" tracking bug.
Comment 26 Gerrit Notification Bot 2014-07-11 02:16:46 UTC
Change 145487 had a related patch set uploaded by Mattflaschen:
Don't actually show guiders in unit tests

https://gerrit.wikimedia.org/r/145487
Comment 27 Matthew Flaschen 2014-07-11 05:08:50 UTC
(In reply to Krinkle from comment #25)
> Also, this really should've been a separate bug. The bug as reported was
> fixed and affected core.

The original symptoms appeared very close (not just "it's something with timers and animations", but specifically jquery.makeCollapsible).

I didn't dive deeper to figure out the underlying interactions until later.
Comment 28 Gerrit Notification Bot 2014-07-11 13:41:04 UTC
Change 145487 merged by jenkins-bot:
Don't actually show guiders in unit tests

https://gerrit.wikimedia.org/r/145487
Comment 29 Gerrit Notification Bot 2014-07-11 15:07:43 UTC
Change 143481 abandoned by Krinkle:
Use QUnit.asyncTest even for fake timers, to fix spurious failures

Reason:
See Ibada489a58295

https://gerrit.wikimedia.org/r/143481
Comment 30 Matthew Flaschen 2014-07-11 21:45:34 UTC
I disabled the GuidedTour GUI that was triggering this during tests (1e37db808e1f9cc8daffb61e4303ce53d701e25a).  Krinkle's b90c69cdf70ae55a7ae608b074893d140d0a96b6 ("QUnit: Detect unfinished jQuery effects or ajax requests in teardown") has been merged to core, which should detect similar issues in the future.

I will abandon the other patch, since if isolation deficiencies (e.g. running effects queue) are fully detected and error'ed, the runner doesn't need to enforce that isolation.
Comment 31 Gerrit Notification Bot 2014-07-11 21:51:04 UTC
Change 145479 abandoned by Mattflaschen:
Fix spurious QUnit failures related to fake timers

Reason:
I'm okay with throwing an error (which is already merged), rather than having the test runner work to clean it up.  The important thing is the test author/maintainer has a clear indication of the problem, which allows them to easily fix it.

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

Note You need to log in before you can comment on or make changes to this bug.


Navigation
Links