Closed Bug 1275718 Opened 4 years ago Closed 4 years ago

Intermittent test_transitions_replacement_on_busy_frame.html | 1,0,0,0,0,1,0,0,0,0,1,0,75.2551,0,0,1 should be advanced ahead of 1,0,0,0,0,1,0,0,0,0,1,0,74.7237,0,0,1

Categories

(Core :: Layout, defect)

49 Branch
defect
Not set

Tracking

()

RESOLVED FIXED
mozilla50
Tracking Status
firefox49 --- fixed
firefox50 --- fixed

People

(Reporter: KWierso, Unassigned)

References

Details

(Keywords: intermittent-failure)

Attachments

(2 files)

Blocks: 1167519
Flags: needinfo?(hiikezoe)
It's hard to believe there are some cases that the latter value is greater than the former.

17:46:17 INFO - 72 INFO TEST-UNEXPECTED-FAIL | layout/style/test/test_transitions_replacement_on_busy_frame.html | 1,0,0,0,0,1,0,0,0,0,1,0,16.9868,0,0,1 should be advanced ahead of 1,0,0,0,0,1,0,0,0,0,1,0,19.293,0,0,1 

This fact implies that the recent refresh time of the refresh driver was greater than TimeStamp::Now()?
Ah, I am now suspecting that taking a snapshot for thumbnails might causes this weird situation.
Flags: needinfo?(hiikezoe)
Depends on: 1276170
(In reply to Hiroyuki Ikezoe (:hiro) from comment #1)
> It's hard to believe there are some cases that the latter value is greater
> than the former.
> 
> 17:46:17 INFO - 72 INFO TEST-UNEXPECTED-FAIL |
> layout/style/test/test_transitions_replacement_on_busy_frame.html |
> 1,0,0,0,0,1,0,0,0,0,1,0,16.9868,0,0,1 should be advanced ahead of
> 1,0,0,0,0,1,0,0,0,0,1,0,19.293,0,0,1 
> 
> This fact implies that the recent refresh time of the refresh driver was
> greater than TimeStamp::Now()?

I think I am getting to close to the root cause of this weird situation.
In this test we wait for being new transition painted[1].
If the main-thread gets busy while this wait, the transition goes back closer to 0px in the meantime.
Creating thumbnail process is the one of reasons causing main-thread busy, but there are another possibility to cause such busyness.  I will figure out how to solve this situation.

[1] https://dxr.mozilla.org/mozilla-central/rev/4d63dde701b47b8661ab7990f197b6b60e543839/layout/style/test/file_transitions_replacement_on_busy_frame.html#71
I've decided to skip the test if it takes over 300ms to receive the paint callback.
https://treeherder.mozilla.org/#/jobs?repo=try&revision=ef345f448680
Ideally it does not take long time but on Android it sometimes takes long,
in a worse case it took 20000ms.  In such cases, the new transition on the
compositor goes back to 0px while the main-thread busy.  If it takes 300ms,
the transition is approximately positioned at the same place just before
setting the new transition. Once we fall into such situations, we have no
way to check results reliably.
Unfortunely we will not notice it if the sisuations happened frequently but
other tests will definitely fail by that time.

Review commit: https://reviewboard.mozilla.org/r/57814/diff/#index_header
See other reviews: https://reviewboard.mozilla.org/r/57814/
Attachment #8760097 - Flags: review?(bbirtles) → review+
Comment on attachment 8760097 [details]
Bug 1275718 - Part 1: Use ok instead of info in case of no OMTA since mochitest fails there is no checks.

https://reviewboard.mozilla.org/r/57812/#review54642
(In reply to Hiroyuki Ikezoe (:hiro) from comment #9)
> Created attachment 8760098 [details]
> Bug 1275718 - Part 2: Skip test when the main-thread takes over 300ms
> between paint process and its callback because we can't check results
> reliably in such cases.
> 
> Ideally it does not take long time but on Android it sometimes takes long,
> in a worse case it took 20000ms.  In such cases, the new transition on the
> compositor goes back to 0px while the main-thread busy.

I guess that is because it is recognized as a reverse transition and so it uses the expired duration of the first transition, right?

What if we make the end point of the second transition some other value, like translateX(-100px)? Would that work?
(In reply to Brian Birtles (:birtles) from comment #11)
> (In reply to Hiroyuki Ikezoe (:hiro) from comment #9)
> > Created attachment 8760098 [details]
> > Bug 1275718 - Part 2: Skip test when the main-thread takes over 300ms
> > between paint process and its callback because we can't check results
> > reliably in such cases.
> > 
> > Ideally it does not take long time but on Android it sometimes takes long,
> > in a worse case it took 20000ms.  In such cases, the new transition on the
> > compositor goes back to 0px while the main-thread busy.
> 
> I guess that is because it is recognized as a reverse transition and so it
> uses the expired duration of the first transition, right?

Maybe not.  I had been observing this kind of failures without creating thumbnails (i.e. without style/paint fluses). 

> What if we make the end point of the second transition some other value,
> like translateX(-100px)? Would that work?

I did try it now, and did not help.
(In reply to Hiroyuki Ikezoe (:hiro) from comment #12)
> (In reply to Brian Birtles (:birtles) from comment #11)
> > (In reply to Hiroyuki Ikezoe (:hiro) from comment #9)
> > > Created attachment 8760098 [details]
> > > Bug 1275718 - Part 2: Skip test when the main-thread takes over 300ms
> > > between paint process and its callback because we can't check results
> > > reliably in such cases.
> > > 
> > > Ideally it does not take long time but on Android it sometimes takes long,
> > > in a worse case it took 20000ms.  In such cases, the new transition on the
> > > compositor goes back to 0px while the main-thread busy.
> > 
> > I guess that is because it is recognized as a reverse transition and so it
> > uses the expired duration of the first transition, right?
> 
> Maybe not.  I had been observing this kind of failures without creating
> thumbnails (i.e. without style/paint fluses). 

So then why does the second transition finish after only 300ms? It should take 100s, right? We must be reversing it.

So long as we are using the Web Animations API in this test, can't we just look up the keyframe values to see if they are correct?

My concern is that at the moment the comment, "something went wrong", isn't helpful. If anyone else has to debug this test in the future they'll have a hard time so either we should simplify the test or write a clear explanation of what is happening.
(In reply to Brian Birtles (:birtles) from comment #14)
> (In reply to Hiroyuki Ikezoe (:hiro) from comment #12)
> > (In reply to Brian Birtles (:birtles) from comment #11)
> > > (In reply to Hiroyuki Ikezoe (:hiro) from comment #9)
> > > > Created attachment 8760098 [details]
> > > > Bug 1275718 - Part 2: Skip test when the main-thread takes over 300ms
> > > > between paint process and its callback because we can't check results
> > > > reliably in such cases.
> > > > 
> > > > Ideally it does not take long time but on Android it sometimes takes long,
> > > > in a worse case it took 20000ms.  In such cases, the new transition on the
> > > > compositor goes back to 0px while the main-thread busy.
> > > 
> > > I guess that is because it is recognized as a reverse transition and so it
> > > uses the expired duration of the first transition, right?
> > 
> > Maybe not.  I had been observing this kind of failures without creating
> > thumbnails (i.e. without style/paint fluses). 
> 
> So then why does the second transition finish after only 300ms? It should
> take 100s, right? We must be reversing it.

The second transition is not finished in failure cases just positioned at closer to 0px.

> So long as we are using the Web Animations API in this test, can't we just
> look up the keyframe values to see if they are correct?
>
> My concern is that at the moment the comment, "something went wrong", isn't
> helpful. If anyone else has to debug this test in the future they'll have a
> hard time so either we should simplify the test or write a clear explanation
> of what is happening.

Yeah, "something" is actually not a good word. One reason I know is creating thumbnails. Others I've been seeing also come from Android browser's codes.  I can't catch what the others actually do.  I think we should run mochitest-plain without browser-chrome to prevent main-thead busyness caused by browser's processes eventually.  I am convinced we should do so, but it's another big deal...
Comment on attachment 8760098 [details]
Bug 1275718 - Part 2: Check the new transition position with KeyframeEffectReadOnly.getProperties().

Clearing review request since the calculation of expected position is wrong.
Attachment #8760098 - Flags: review?(bbirtles)
(In reply to Brian Birtles (:birtles) from comment #14)
> So long as we are using the Web Animations API in this test, can't we just
> look up the keyframe values to see if they are correct?

Thank you, Brian!  Actually keyframe values can not be used there since we don't update keyframes, we just update mProperties of KeyframeEffectReadonly. Yes! we can use KeyframeEffectReadOnly.getProperties() instead.  What a nice API!
(In reply to Hiroyuki Ikezoe (:hiro) from comment #17)
> Thank you, Brian!  Actually keyframe values can not be used there since we
> don't update keyframes, we just update mProperties of
> KeyframeEffectReadonly. Yes! we can use
> KeyframeEffectReadOnly.getProperties() instead.  What a nice API!

Oh, I'm surprised we don't update the keyframes. The properties can be overwritten at any time so it seems like we should be updating the keyframes?
(In reply to Brian Birtles (:birtles) from comment #18)
> (In reply to Hiroyuki Ikezoe (:hiro) from comment #17)
> > Thank you, Brian!  Actually keyframe values can not be used there since we
> > don't update keyframes, we just update mProperties of
> > KeyframeEffectReadonly. Yes! we can use
> > KeyframeEffectReadOnly.getProperties() instead.  What a nice API!
> 
> Oh, I'm surprised we don't update the keyframes. The properties can be
> overwritten at any time so it seems like we should be updating the keyframes?

Filed. Bug 1278430.
Comment on attachment 8760098 [details]
Bug 1275718 - Part 2: Check the new transition position with KeyframeEffectReadOnly.getProperties().

Review request updated; see interdiff: https://reviewboard.mozilla.org/r/57814/diff/1-2/
Attachment #8760098 - Attachment description: Bug 1275718 - Part 2: Skip test when the main-thread takes over 300ms between paint process and its callback because we can't check results reliably in such cases. → Bug 1275718 - Part 2: Check the new transition position with KeyframeEffectReadOnly.getProperties().
Attachment #8760098 - Flags: review?(bbirtles)
A try run not finished yet, but I did confirm the new patch works with --repeat=50 locally.
https://treeherder.mozilla.org/#/jobs?repo=try&revision=46a9a7079669&selectedJob=22076567
Note that test test fails if UpdateStartValueFromReplacedTransition in AddAnimationForProperty()[1] is dropped.

[1] https://dxr.mozilla.org/mozilla-central/rev/3e8ee3599a67edd971770af4982ad4b0fe77f073/layout/base/nsDisplayList.cpp#412
Comment on attachment 8760098 [details]
Bug 1275718 - Part 2: Check the new transition position with KeyframeEffectReadOnly.getProperties().

https://reviewboard.mozilla.org/r/57814/#review55000

::: layout/style/test/file_transitions_replacement_on_busy_frame.html:78
(Diff revision 2)
> -        // Wait for being animated style updated by animation.pause().
> -        anim.ready.then(function() {
> +              "We surely update from value of the transition after the busy " +
> +              "in rAF callback");

"From value of transition is updated since the moment when it was generated"
Attachment #8760098 - Flags: review?(bbirtles) → review+
Comment on attachment 8760098 [details]
Bug 1275718 - Part 2: Check the new transition position with KeyframeEffectReadOnly.getProperties().

Review request updated; see interdiff: https://reviewboard.mozilla.org/r/57814/diff/2-3/
Pushed by hiikezoe@mozilla-japan.org:
https://hg.mozilla.org/integration/mozilla-inbound/rev/fed8fa38d29d
Part 1: Use ok instead of info in case of no OMTA since mochitest fails there is no checks. r=birtles
https://hg.mozilla.org/integration/mozilla-inbound/rev/38a91ae89a41
Part 2: Check the new transition position with KeyframeEffectReadOnly.getProperties(). r=birtles
https://hg.mozilla.org/mozilla-central/rev/fed8fa38d29d
https://hg.mozilla.org/mozilla-central/rev/38a91ae89a41
Status: NEW → RESOLVED
Closed: 4 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla50
You need to log in before you can comment on or make changes to this bug.