Intermittent browser_animation_actors_03.js | PlayState is correct - Got pending, expected running

RESOLVED FIXED in Firefox 37

Status

RESOLVED FIXED
4 years ago
2 months ago

People

(Reporter: RyanVM, Assigned: pbro)

Tracking

({intermittent-failure})

unspecified
Firefox 37
x86_64
Mac OS X
intermittent-failure
Bug Flags:
in-testsuite +

Firefox Tracking Flags

(firefox35 unaffected, firefox36 unaffected, firefox37 fixed, firefox-esr31 unaffected)

Details

Attachments

(2 attachments)

(Reporter)

Description

4 years ago
19:46:49 INFO - 5447 INFO TEST-START | toolkit/devtools/server/tests/browser/browser_animation_actors_03.js
19:46:49 INFO - -*-*- UserCustomizations (parent): document created: http://test1.example.org/browser/toolkit/devtools/server/tests/browser/animation.html
19:46:49 INFO - -*-*- UserCustomizations (parent): _injectInWindow
19:46:49 INFO - -*-*- UserCustomizations (parent): principal status: 0
19:46:49 INFO - 5448 INFO checking window state
19:46:49 INFO - 5449 INFO Entering test
19:46:49 INFO - 5450 INFO Adding a new tab with URL: 'http://test1.example.org/browser/toolkit/devtools/server/tests/browser/animation.html'
19:46:49 INFO - 5451 INFO Waiting for event: 'load' on [object XULElement].
19:46:49 INFO - 5452 INFO Console message: [JavaScript Error: "The character encoding of the HTML document was not declared. The document will render with garbled text in some browser configurations if the document contains characters from outside the US-ASCII range. The character encoding of the page must be declared in the document or in the transfer protocol." {file: "http://test1.example.org/browser/toolkit/devtools/server/tests/browser/animation.html" line: 0}]
19:46:49 INFO - 5453 INFO Got event: 'load' on [object XULElement].
19:46:49 INFO - 5454 INFO URL 'http://test1.example.org/browser/toolkit/devtools/server/tests/browser/animation.html' loading complete
19:46:49 INFO - 5455 INFO TEST-PASS | toolkit/devtools/server/tests/browser/browser_animation_actors_03.js | The player front has an initial state
19:46:49 INFO - 5456 INFO TEST-PASS | toolkit/devtools/server/tests/browser/browser_animation_actors_03.js | Player's state has startTime
19:46:49 INFO - 5457 INFO TEST-PASS | toolkit/devtools/server/tests/browser/browser_animation_actors_03.js | Player's state has currentTime
19:46:49 INFO - 5458 INFO TEST-PASS | toolkit/devtools/server/tests/browser/browser_animation_actors_03.js | Player's state has playState
19:46:49 INFO - 5459 INFO TEST-PASS | toolkit/devtools/server/tests/browser/browser_animation_actors_03.js | Player's state has name
19:46:49 INFO - 5460 INFO TEST-PASS | toolkit/devtools/server/tests/browser/browser_animation_actors_03.js | Player's state has duration
19:46:49 INFO - 5461 INFO TEST-PASS | toolkit/devtools/server/tests/browser/browser_animation_actors_03.js | Player's state has iterationCount
19:46:49 INFO - 5462 INFO TEST-PASS | toolkit/devtools/server/tests/browser/browser_animation_actors_03.js | Player's state has isRunningOnCompositor
19:46:49 INFO - 5463 INFO Checking the state of the simple animation
19:46:49 INFO - 5464 INFO TEST-PASS | toolkit/devtools/server/tests/browser/browser_animation_actors_03.js | Name is correct
19:46:49 INFO - 5465 INFO TEST-PASS | toolkit/devtools/server/tests/browser/browser_animation_actors_03.js | Duration is correct
19:46:49 INFO - 5466 INFO TEST-PASS | toolkit/devtools/server/tests/browser/browser_animation_actors_03.js | Iteration count is correct
19:46:49 INFO - 5467 INFO TEST-UNEXPECTED-FAIL | toolkit/devtools/server/tests/browser/browser_animation_actors_03.js | PlayState is correct - Got pending, expected running
19:46:49 INFO - Stack trace:
19:46:49 INFO - chrome://mochikit/content/browser-test.js:test_is:851
19:46:49 INFO - chrome://mochitests/content/browser/toolkit/devtools/server/tests/browser/browser_animation_actors_03.js:playerStateIsCorrect:54
19:46:49 INFO - self-hosted:InterpretGeneratorResume:659
19:46:49 INFO - self-hosted:next:585
19:46:49 INFO - Handler.prototype.process@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:870:23
19:46:49 INFO - this.PromiseWalker.walkerLoop@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:749:7
19:46:49 INFO - this.PromiseWalker.scheduleWalkerLoop/<@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:691:37
19:46:49 INFO - 5468 INFO Checking the state of the transition 
19:46:49 INFO - 5469 INFO TEST-PASS | toolkit/devtools/server/tests/browser/browser_animation_actors_03.js | Transition has no name
19:46:49 INFO - 5470 INFO TEST-PASS | toolkit/devtools/server/tests/browser/browser_animation_actors_03.js | Transition duration is correct
19:46:49 INFO - 5471 INFO TEST-PASS | toolkit/devtools/server/tests/browser/browser_animation_actors_03.js | Transition iteration count is correct
19:46:49 INFO - 5472 INFO TEST-PASS | toolkit/devtools/server/tests/browser/browser_animation_actors_03.js | Transition playState is correct
19:46:49 INFO - 5473 INFO Checking the state of one of multiple animations on a node
19:46:49 INFO - 5474 INFO TEST-PASS | toolkit/devtools/server/tests/browser/browser_animation_actors_03.js | The 2nd animation's name is correct
19:46:49 INFO - 5475 INFO TEST-PASS | toolkit/devtools/server/tests/browser/browser_animation_actors_03.js | The 2nd animation's duration is correct
19:46:49 INFO - 5476 INFO TEST-PASS | toolkit/devtools/server/tests/browser/browser_animation_actors_03.js | The 2nd animation's iteration count is correct
19:46:49 INFO - 5477 INFO TEST-PASS | toolkit/devtools/server/tests/browser/browser_animation_actors_03.js | The 2nd animation's playState is correct
19:46:49 INFO - 5478 INFO Leaving test
19:46:49 INFO - 5479 INFO MEMORY STAT vsize after test: 4110974976
19:46:49 INFO - 5480 INFO MEMORY STAT residentFast after test: 880885760
19:46:49 INFO - 5481 INFO MEMORY STAT heapAllocated after test: 352724032
19:46:49 INFO - 5482 INFO TEST-OK | toolkit/devtools/server/tests/browser/browser_animation_actors_03.js | took 245ms
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
I will get to this bug shortly.
The test is now failing due to bug 927349 which makes animations pass by a pending state before starting. The failing test assumes the animation is running from the start.
The good news is that since bug 1113091, it's an easy one line fix. Before checking for the running state, the test should wait until the player.ready promise resolves.
Assignee: nobody → pbrosset
Created attachment 8547071 [details] [diff] [review]
bug1120100-intermittent-actor-test v1.patch

Pending try build: https://treeherder.mozilla.org/ui/#/jobs?repo=try&revision=1e9381e3b508
Let's retrigger many dt jobs to see if this fixes the issue.
Also, if this doesn't get in before the release on monday (and I don't think it will), I'll request uplift.
(Reporter)

Comment 6

4 years ago
It's a test-only change, so we can just uplift it to Aurora whenever it's ready (if it misses the uplift).
status-firefox35: --- → unaffected
status-firefox36: --- → unaffected
status-firefox37: --- → affected
status-firefox-esr31: --- → unaffected
Comment on attachment 8547071 [details] [diff] [review]
bug1120100-intermittent-actor-test v1.patch

Alright, try is pretty green after many retriggers, so that confirms my suspicion.
It would be good to have this land in this release (even if as RyanVM said, it's easy to uplift).
So flagging Panos for review.

Panos, I know this code is a bit mysterious cause it's related to the animation inspector, and noone in devtools has worked on this apart from me so far. But hopefully the code changes are small and obvious enough to not have to know about the animations actors to review this.

The idea is that the AnimationPlayerActor exposes a |ready| method which is really just a wrapper around the underlying AnimationPlayer ready promise and is very useful to call when an animation starts, to make sure it's not in its pending state anymore.
Attachment #8547071 - Flags: review?(past)
Comment on attachment 8547071 [details] [diff] [review]
bug1120100-intermittent-actor-test v1.patch

Review of attachment 8547071 [details] [diff] [review]:
-----------------------------------------------------------------

Indeed, I haven't looked at the animation backend yet, but this change seems straightforward.
Attachment #8547071 - Flags: review?(past) → review+
Thanks Panos for the review and landing it on fx-team.
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
This isn't fixed unfortunately, my last change makes sense, we need to wait on the ready promise, *but* the test still reads the state from the initialState property, which isn't updated. So the test fails intermittently as often as before.

I'll upload a new patch that will correct this by calling getState after the ready promise resolves.
Created attachment 8547493 [details] [diff] [review]
bug1120100-2-intermittent-actor-test v1.patch

As explained in my previous comment, this requests the current state of the animation player object before checking it.
Attachment #8547493 - Flags: review?(past)
Comment on attachment 8547493 [details] [diff] [review]
bug1120100-2-intermittent-actor-test v1.patch

Review of attachment 8547493 [details] [diff] [review]:
-----------------------------------------------------------------

Looks good.
Attachment #8547493 - Flags: review?(past) → review+
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
(Reporter)

Comment 27

4 years ago
https://hg.mozilla.org/mozilla-central/rev/4e343b8494f9
https://hg.mozilla.org/mozilla-central/rev/4c52eac505cf

Looks like there's still been at least one instance since part 2 landed :(
Flags: in-testsuite+
I looked at the fx-team failure since part 2 landed, and, if I'm not mistaken, the cset didn't contain my fix yet. Could it be a late result to a build that started before part 2 landed?
(Reporter)

Comment 29

4 years ago
You're right, the last one was from the push before, not after.
Status: NEW → RESOLVED
Last Resolved: 4 years ago
status-firefox37: affected → fixed
Resolution: --- → FIXED
Target Milestone: --- → Firefox 37
Comment hidden (Treeherder Robot)

Updated

2 months ago
Product: Firefox → DevTools
You need to log in before you can comment on or make changes to this bug.