Closed Bug 958075 Opened 6 years ago Closed 6 years ago

B2G: Permaorange with test_extra_inherit_initial.html | Test timed out.

Categories

(Core :: CSS Parsing and Computation, defect)

ARM
Gonk (Firefox OS)
defect
Not set

Tracking

()

RESOLVED FIXED
mozilla29

People

(Reporter: gwagner, Unassigned)

References

Details

Probably caused by bug 940229?
This happens on debug-emulator builds running mochitests.
For example: https://tbpl.mozilla.org/php/getParsedLog.php?id=32748915&tree=Pine&full=1

These tests are only enabled on pine but we want to enable them on all trees once they are green. This new regression is currently the only remaining orange.
We just need to increase the value in the test's call to "requestLongerTimeout", presumably.

gwagner, can you see if editing the test to use "requestLongerTimeout(4)" fixes it?
Nice, looks like that fixes it, based on the green M(15) in this run (next to "B2G ICS Emulator Debug"):
 https://tbpl.mozilla.org/?tree=Pine&rev=85108acaac38

gwagner, do you want to push a version of that tweak to inbound? (I'm happy to do it, if you'd rather)
For the record: quoting that successful M15 log:
 INFO TEST-END | /tests/layout/style/test/test_extra_inherit_initial.html | finished in 879226ms

So, this test took just under 900 seconds (15 minutes) to run. IIRC, the standard timeout is 300 seconds (5 minutes). So, if Gregor had used requestLongerTimeout(3), it would *barely* have given it enough time to complete (and would be cutting it a little close -- only 20 seconds of leeway. Which we'll chip away at as we add more properties / property-values.)

Hence, requestLongerTimeout(4) seems like it's the smallest multiplier we can safely use here.
(In reply to Daniel Holbert [:dholbert] from comment #2)
> gwagner, do you want to push a version of that tweak to inbound? (I'm happy
> to do it, if you'd rather)

on IRC, gwagner asked me to proceed, so I pushed a requestLongerTimeout(4) tweak to inbound:
  https://hg.mozilla.org/integration/mozilla-inbound/rev/d46aa338c518
Flags: in-testsuite-
(In reply to Daniel Holbert [:dholbert] from comment #3)
> For the record: quoting that successful M15 log:
>  INFO TEST-END | /tests/layout/style/test/test_extra_inherit_initial.html |
> finished in 879226ms
> 
> So, this test took just under 900 seconds (15 minutes) to run.

RyanVM and bz both (justifiably) thought this duration seemed a little nuts, so I dug in a bit further.

On Android Debug (running on Cedar), this test only takes 39 seconds:
INFO TEST-END | /tests/layout/style/test/test_extra_inherit_initial.html | finished in 39307ms
https://tbpl.mozilla.org/php/getParsedLog.php?id=32786952&full=1&branch=cedar
Android 4.0 Panda cedar debug test mochitest-8 on 2014-01-09 15:25:08 PST for push af91b088d34d

So it seems like somethings going a bit crazy on B2G debug to make it take this long...
Actually, per bug 940229 comment 8, this is taking a long time on B2G debug, too (> 3 min, which was the reason we had requestLongerTimeout(2) in the first place).  Given that, it's unsurprising that B2G debug takes ~twice as long and required a doubled requestLongerTimeout.

The question is, why is B2G taking so long (> 10x the time) as compared to Android.
Here are some Try runs, experimenting with ways to speed things up (with B2G opt builds, which are already running on TBPL and are slow, per previous comment).

Unmodified mozilla-central:
  https://tbpl.mozilla.org/?tree=Try&rev=c41fd4b3814a
Tweaked test to disable CSS error reporting:
  https://tbpl.mozilla.org/?tree=Try&rev=dff0a6e9fdcb
Tweaked test to do larger batches of properties per executeSoon() call:
 https://tbpl.mozilla.org/?tree=Try&rev=414cd8f7c500

We'll see if either of those tweaks have much effect on the test runtime...
Whiteboard: [leave open]
Version: unspecified → Trunk
It is running in an arm emulator with a --enable-debug gecko. This is definitely the slowest environment we have.
(In reply to Daniel Holbert [:dholbert] from comment #7)
> Unmodified mozilla-central:
>   https://tbpl.mozilla.org/?tree=Try&rev=c41fd4b3814a
test_extra_inherit_initial.html | finished in 362811ms

> Tweaked test to disable CSS error reporting:
>   https://tbpl.mozilla.org/?tree=Try&rev=dff0a6e9fdcb
test_extra_inherit_initial.html | finished in 235086ms

> Tweaked test to do larger batches of properties per executeSoon() call:
>  https://tbpl.mozilla.org/?tree=Try&rev=414cd8f7c500
test_extra_inherit_initial.html | finished in 329240ms

If those measurements are reliable (and I'm triggering another run of each to see), then disabling CSS error reporting shaves off about 35% of the time, and (separately) batching shaves off about 10% of the time. Seems like both are worth doing.
Flags: needinfo?(dholbert)
Second sample on each of those Try runs was similar (though the batching showed more of an improvement for some reason this time around, perhaps just due to more fortuitous GC timing or something):
> Unmodified mozilla-central:
test_extra_inherit_initial.html | finished in 340532ms

> Tweaked test to disable CSS error reporting:
test_extra_inherit_initial.html | finished in 237924ms

> Tweaked test to do larger batches of properties per executeSoon() call:
test_extra_inherit_initial.html | finished in 218459ms
Flags: needinfo?(dholbert)
For good measure, I did a Try run with both optimizations applied:
 https://tbpl.mozilla.org/?tree=Try&rev=7fd338193fcf
test_extra_inherit_initial.html | finished in 198842ms
Since I already landed a patch with this bug number (comment 4), I filed a new bug to cover the test-optimization patches discussed in comment 7 - comment 11 here. That new bug is bug 958802.
Whiteboard: [leave open]
https://hg.mozilla.org/mozilla-central/rev/d46aa338c518
Status: NEW → RESOLVED
Closed: 6 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla29
You need to log in before you can comment on or make changes to this bug.