Closed Bug 1273876 Opened 4 years ago Closed 1 year ago

Intermittent test_transitions_events.html | unexpected event on SPAN element with id 'five' elapsedTime=0.5 propertyName='color'

Categories

(Core :: Layout, defect, P3)

defect

Tracking

()

RESOLVED FIXED
mozilla67
Tracking Status
firefox66 --- fixed
firefox67 --- fixed

People

(Reporter: aryx, Assigned: hiro)

References

Details

(Keywords: intermittent-failure, Whiteboard: [retriggered][stockwell unknown])

Attachments

(2 files)

https://treeherder.mozilla.org/logviewer.html#?job_id=28100932&repo=mozilla-inbound

23:19:26     INFO -  529 INFO TEST-PASS | layout/style/test/test_transitions_events.html | computed style of outline-color for transitionend on one
23:19:26     INFO -  530 INFO TEST-PASS | layout/style/test/test_transitions_events.html | transitionend on one on target (text-decoration-color)
23:19:26     INFO -  531 INFO TEST-PASS | layout/style/test/test_transitions_events.html | elapsedTime for transitionend on one
23:19:26     INFO -  532 INFO TEST-PASS | layout/style/test/test_transitions_events.html | computed style of text-decoration-color for transitionend on one
23:19:26     INFO -  533 INFO TEST-UNEXPECTED-FAIL | layout/style/test/test_transitions_events.html | unexpected event on SPAN element with id 'five' elapsedTime=0.5 propertyName='color'
23:19:26     INFO -      @layout/style/test/test_transitions_events.html:140:7
23:19:26     INFO -      EventListener.handleEvent*@layout/style/test/test_transitions_events.html:88:1
23:19:26     INFO -  Not taking screenshot here: see the one that was previously logged
23:19:26     INFO -  534 INFO TEST-UNEXPECTED-FAIL | layout/style/test/test_transitions_events.html | unexpected event on SPAN element with id 'six' elapsedTime=0.5 propertyName='color'
Bulk assigning P3 to all open intermittent bugs without a priority set in Firefox components per bug 1298978.
Priority: -- → P3
I faced this failure when implement transitioncancel event.
I think that transition finished before checking the timeout.[1]

[1] https://dxr.mozilla.org/mozilla-central/rev/57a8cde3f08ca9d60bcd8bdd698ceec687f0aed2/layout/style/test/test_transitions_events.html#127
Yes.  Now we have 'transitionstart' event so that we can detect the transition has been started without setTimeout.
Hmm, also actually it's not related to this bug, it seems to me that the condition when we set did_stops is not correct.

https://dxr.mozilla.org/mozilla-central/rev/47f42f21541b9b98ad7db82edb996b29065debd0/layout/style/test/test_transitions_events.html#238-241

The transition is from rgb(0, 0, 255) to rgb(0, 255, 0), so the condition should be 'cs("five") == "rgb(0, 255, 0)'.
(In reply to Hiroyuki Ikezoe (:hiro) from comment #8)
> https://treeherder.mozilla.org/#/
> jobs?repo=try&revision=f2fe9c51cb6c9f8afba514e578c78dd6172dbb3f

I did an overkill against #four element there.  We reverse the transition on the #four once the first transition has been stated, but with below code sometimes the reverse transition does not start because the style color is still "blue" in the callback of transitionstart. As a result, transitionend event for the #four is not fired.

+$("four").addEventListener("transitionstart", function startTransition() {
+  // The forward transition has started.
+  $("four").style.color = "blue";
+  $("four").removeEventListener("transitionstart", startTransition, false);
+}, false);

I will drop this part.

It seems to start failing frequently in these days. (I notice it on the one of my tries)

Probably this is a timing-sensitive test (in a bad way), thus the intermittent before.

I'l try to contact whomever is responsible for the test. Android emulator is FAR more sensitive to this sort of problem to begin with... thus why so many tests are disabled on android.

Flags: needinfo?(rjesup)

heycam - can you look at this? layout/style/test/test_transitions_events.html
The patch that made this near-permafail moves setTimeout execution to occur after pageload finishes (unless we have Idle time before then, which I presume in this case we don't). So timings can change... This was apparently on the edge of failing before (thus the intermittent)

Flags: needinfo?(cam)

Birtles / Hiro may know more about the timing dependency here.

Flags: needinfo?(hikezoe)
Flags: needinfo?(bbirtles)

Though I don't recall what I tried in comment 9, we should/could rewrite this test case without setTimeout calls. I can try it again.

Assignee: nobody → hikezoe
Status: NEW → ASSIGNED
Flags: needinfo?(hikezoe)
Flags: needinfo?(cam)

For what it's worth this is one of my least favorite tests. I would love to see it rewritten, especially if the rewrite involved moving it to wpt. Hiro, let me know if you need help. I've been meaning to finish tidying up the transitions tests in WPT so I can include it in that work.

Flags: needinfo?(bbirtles)

There are 62 total failures in the last 7 days on android-em-4-3-armv7-api16 debug, opt

Recent failure log: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=224570799&repo=autoland&lineNumber=1588

[task 2019-01-28T23:59:51.212Z] 23:59:51 INFO - 121 INFO TEST-START | layout/style/test/test_transitions_events.html
[task 2019-01-28T23:59:51.213Z] 23:59:51 INFO - Buffered messages logged at 23:59:13
[task 2019-01-28T23:59:51.214Z] 23:59:51 INFO - 122 INFO TEST-PASS | layout/style/test/test_transitions_events.html | A valid string reason is expected
[task 2019-01-28T23:59:51.215Z] 23:59:51 INFO - 123 INFO TEST-PASS | layout/style/test/test_transitions_events.html | Reason cannot be empty
[task 2019-01-28T23:59:51.216Z] 23:59:51 INFO - Buffered messages logged at 23:59:14
[task 2019-01-28T23:59:51.218Z] 23:59:51 INFO - 124 INFO TEST-FAIL | layout/style/test/test_transitions_events.html | The author of the test has indicated that flaky timeouts are expected. Reason: untriaged
[task 2019-01-28T23:59:51.221Z] 23:59:51 INFO - 125 INFO TEST-FAIL | layout/style/test/test_transitions_events.html | The author of the test has indicated that flaky timeouts are expected. Reason: untriaged
[task 2019-01-28T23:59:51.222Z] 23:59:51 INFO - 126 INFO TEST-PASS | layout/style/test/test_transitions_events.html | undefined assertion name
[task 2019-01-28T23:59:51.223Z] 23:59:51 INFO - 127 INFO TEST-PASS | layout/style/test/test_transitions_events.html | undefined assertion name
[task 2019-01-28T23:59:51.223Z] 23:59:51 INFO - 128 INFO TEST-PASS | layout/style/test/test_transitions_events.html | undefined assertion name
[task 2019-01-28T23:59:51.224Z] 23:59:51 INFO - 129 INFO TEST-PASS | layout/style/test/test_transitions_events.html | undefined assertion name
[task 2019-01-28T23:59:51.224Z] 23:59:51 INFO - 130 INFO TEST-PASS | layout/style/test/test_transitions_events.html | undefined assertion name
[task 2019-01-28T23:59:51.225Z] 23:59:51 INFO - 131 INFO TEST-PASS | layout/style/test/test_transitions_events.html | undefined assertion name
[task 2019-01-28T23:59:51.226Z] 23:59:51 INFO - 132 INFO TEST-PASS | layout/style/test/test_transitions_events.html | transitionend on body on root
[task 2019-01-28T23:59:51.227Z] 23:59:51 INFO - 133 INFO TEST-PASS | layout/style/test/test_transitions_events.html | propertyName for transitionend on body
[task 2019-01-28T23:59:51.227Z] 23:59:51 INFO - 134 INFO TEST-PASS | layout/style/test/test_transitions_events.html | elapsedTime for transitionend on body
[task 2019-01-28T23:59:51.228Z] 23:59:51 INFO - Buffered messages logged at 23:59:15
[task 2019-01-28T23:59:51.229Z] 23:59:51 INFO - 135 INFO TEST-PASS | layout/style/test/test_transitions_events.html | undefined assertion name
[task 2019-01-28T23:59:51.231Z] 23:59:51 INFO - 136 INFO TEST-PASS | layout/style/test/test_transitions_events.html | undefined assertion name
[task 2019-01-28T23:59:51.232Z] 23:59:51 INFO - 137 INFO TEST-PASS | layout/style/test/test_transitions_events.html | undefined assertion name
[task 2019-01-28T23:59:51.234Z] 23:59:51 INFO - 138 INFO TEST-PASS | layout/style/test/test_transitions_events.html | transitionend on #seven::after
[task 2019-01-28T23:59:51.235Z] 23:59:51 INFO - 139 INFO TEST-PASS | layout/style/test/test_transitions_events.html | undefined assertion name
[task 2019-01-28T23:59:51.236Z] 23:59:51 INFO - 140 INFO TEST-PASS | layout/style/test/test_transitions_events.html | undefined assertion name
[task 2019-01-28T23:59:51.238Z] 23:59:51 INFO - 141 INFO TEST-PASS | layout/style/test/test_transitions_events.html | undefined assertion name
[task 2019-01-28T23:59:51.238Z] 23:59:51 INFO - 142 INFO TEST-PASS | layout/style/test/test_transitions_events.html | unexpected property name for transitionend on one on target
[task 2019-01-28T23:59:51.238Z] 23:59:51 INFO - 143 INFO TEST-PASS | layout/style/test/test_transitions_events.html | transitionend on one on target (color)
[task 2019-01-28T23:59:51.239Z] 23:59:51 INFO - 144 INFO TEST-PASS | layout/style/test/test_transitions_events.html | elapsedTime for transitionend on one
[task 2019-01-28T23:59:51.239Z] 23:59:51 INFO - 145 INFO TEST-PASS | layout/style/test/test_transitions_events.html | computed style of color for transitionend on one
[task 2019-01-28T23:59:51.240Z] 23:59:51 INFO - Buffered messages finished
[task 2019-01-28T23:59:51.240Z] 23:59:51 INFO - 146 INFO TEST-UNEXPECTED-FAIL | layout/style/test/test_transitions_events.html | unexpected event on SPAN element with id 'five' elapsedTime=0.5 propertyName='color'
[task 2019-01-28T23:59:51.241Z] 23:59:51 INFO - SimpleTest.ok@SimpleTest/SimpleTest.js:275:7
[task 2019-01-28T23:59:51.241Z] 23:59:51 INFO - @layout/style/test/test_transitions_events.html:133:7
[task 2019-01-28T23:59:51.242Z] 23:59:51 INFO - 147 INFO TEST-UNEXPECTED-FAIL | layout/style/test/test_transitions_events.html | unexpected event on SPAN element with id 'six' elapsedTime=0.5 propertyName='color'
[task 2019-01-28T23:59:51.242Z] 23:59:51 INFO - SimpleTest.ok@SimpleTest/SimpleTest.js:275:7
[task 2019-01-28T23:59:51.242Z] 23:59:51 INFO - @layout/style/test/test_transitions_events.html:133:7
[task 2019-01-28T23:59:51.243Z] 23:59:51 INFO - 148 INFO TEST-PASS | layout/style/test/test_transitions_events.html | should only get margin-bottom once
[task 2019-01-28T23:59:51.243Z] 23:59:51 INFO - 149 INFO TEST-PASS | layout/style/test/test_transitions_events.html | elapsedTime for transitionend on three
[task 2019-01-28T23:59:51.244Z] 23:59:51 INFO - 150 INFO TEST-PASS | layout/style/test/test_transitions_events.html | computed style for transitionend on three

Whiteboard: [retriggered] → [retriggered][stockwell needswork:owner]

https://treeherder.mozilla.org/#/jobs?repo=try&revision=51f51b447413bbcfc263ec7be5a17935920fe295
Looks orangy but all failures are not related to this. :)

There is still definitely room to improvement, but I don't want to spent more time on this. :)

And stop the transitions inside the event callbacks. Also in this commit,
did_stop flag was split into two dedicated flags for five' andsix` elements
respectively to avoid success accidentally. And flip the flag usage, e.g.
true if the transition finished at the same time of the transitionstart event.

MozReview-Commit-ID: DttQ2nLVYWU

Depends on D17911

Pushed by hikezoe@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/4ae308f1f64b
Check the computed style _color_. r=birtles
https://hg.mozilla.org/integration/autoland/rev/6ff72e58273b
Use 'transitionstart' event to detect the target transition has been started instead of using setTimeout. r=birtles
Status: ASSIGNED → RESOLVED
Closed: 1 year ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla67

Probably this should be uplifted (This just changed a mochitest)?

Flags: needinfo?(ryanvm)
Flags: needinfo?(ryanvm)
You need to log in before you can comment on or make changes to this bug.