Open Bug 1237030 Opened 8 years ago Updated 2 years ago

browser_938980_navbar_collapsed.js/browser_970511_undo_restore_default.js times out all the time in single core docker containers and doesn't in multi core

Categories

(Firefox :: Toolbars and Customization, defect)

defect

Tracking

()

People

(Reporter: jmaher, Unassigned)

References

(Blocks 1 open bug)

Details

in comparing a single core vs multi core docker container for running tests, we find a few tests which have different behaviors (bug 1237024).  In this case I care about:
INFO TEST-UNEXPECTED-FAIL | browser/components/customizableui/test/browser_938980_navbar_collapsed.js | This test exceeded the timeout
https://public-artifacts.taskcluster.net/aaVY9liWQV-JRj2a2uwY2w/0/public/logs/live_backing.log

here is a clip from the above log:
21:28:40     INFO -  86 INFO TEST-START | browser/components/customizableui/test/browser_938980_navbar_collapsed.js
21:28:40     INFO -  ++DOMWINDOW == 62 (0x7f85d650ec00) [pid = 942] [serial = 377] [outer = 0x7f85db4de800]
21:28:40     INFO -  [942] WARNING: attempt to modify an immutable nsStandardURL: file /home/worker/workspace/build/src/netwerk/base/nsStandardURL.cpp, line 1302
21:28:47     INFO -  --DOCSHELL 0x7f85cf86f800 == 20 [pid = 942] [id = 123]
21:28:47     INFO -  --DOCSHELL 0x7f85d587b000 == 19 [pid = 942] [id = 125]
21:28:47     INFO -  --DOCSHELL 0x7f85d5e2d000 == 18 [pid = 942] [id = 124]
21:28:47     INFO -  --DOCSHELL 0x7f85d6490000 == 17 [pid = 942] [id = 127]
21:28:47     INFO -  --DOMWINDOW == 61 (0x7f85d7796400) [pid = 942] [serial = 312] [outer = (nil)] [url = about:customizing]
21:28:47     INFO -  --DOMWINDOW == 60 (0x7f85db3cbc00) [pid = 942] [serial = 317] [outer = (nil)] [url = about:customizing]
21:28:50     INFO -  ++DOCSHELL 0x7f85cf862800 == 18 [pid = 942] [id = 135]
21:28:50     INFO -  ++DOMWINDOW == 61 (0x7f85d5e73400) [pid = 942] [serial = 378] [outer = (nil)]
21:28:50     INFO -  ++DOMWINDOW == 62 (0x7f85d6251400) [pid = 942] [serial = 379] [outer = 0x7f85d5e73400]
21:28:51     INFO -  ++DOMWINDOW == 63 (0x7f85d64fa400) [pid = 942] [serial = 380] [outer = 0x7f85d5e73400]
21:28:52     INFO -  --DOMWINDOW == 62 (0x7f85dccaf000) [pid = 942] [serial = 353] [outer = (nil)] [url = about:blank]
21:28:52     INFO -  --DOMWINDOW == 61 (0x7f85d77c2c00) [pid = 942] [serial = 346] [outer = (nil)] [url = about:blank]
21:28:52     INFO -  --DOMWINDOW == 60 (0x7f85dccb5c00) [pid = 942] [serial = 351] [outer = (nil)] [url = about:blank]
21:28:52     INFO -  --DOMWINDOW == 59 (0x7f85d6df5800) [pid = 942] [serial = 342] [outer = (nil)] [url = about:blank]
21:28:52     INFO -  --DOMWINDOW == 58 (0x7f85d624c400) [pid = 942] [serial = 339] [outer = (nil)] [url = about:blank]
21:28:52     INFO -  --DOMWINDOW == 57 (0x7f85d5e76800) [pid = 942] [serial = 360] [outer = (nil)] [url = about:blank]
21:28:52     INFO -  --DOMWINDOW == 56 (0x7f85cef43c00) [pid = 942] [serial = 358] [outer = (nil)] [url = about:blank]
21:28:52     INFO -  --DOMWINDOW == 55 (0x7f85db4e6400) [pid = 942] [serial = 349] [outer = (nil)] [url = about:blank]
21:28:52     INFO -  --DOMWINDOW == 54 (0x7f85de5eec00) [pid = 942] [serial = 356] [outer = (nil)] [url = about:blank]
21:28:52     INFO -  ++DOMWINDOW == 55 (0x7f85d6deac00) [pid = 942] [serial = 381] [outer = 0x7f85d5f1d000]
21:28:52     INFO -  ++DOMWINDOW == 56 (0x7f85cec93400) [pid = 942] [serial = 382] [outer = 0x7f85d5f1d000]
21:28:53     INFO -  [942] WARNING: attempt to modify an immutable nsStandardURL: file /home/worker/workspace/build/src/netwerk/base/nsStandardURL.cpp, line 1302
21:29:03     INFO -  ++DOCSHELL 0x7f85d5b5c000 == 19 [pid = 942] [id = 136]
21:29:03     INFO -  ++DOMWINDOW == 57 (0x7f85d7584800) [pid = 942] [serial = 383] [outer = (nil)]
21:29:03     INFO -  ++DOMWINDOW == 58 (0x7f85d77c1000) [pid = 942] [serial = 384] [outer = 0x7f85d7584800]
21:29:03     INFO -  [942] WARNING: NS_ENSURE_TRUE(!mParent || mParent == docLoaderService) failed: file /home/worker/workspace/build/src/docshell/base/nsDocShell.cpp, line 3190
21:29:03     INFO -  [942] WARNING: NS_ENSURE_TRUE(!mParent || mParent == docLoaderService) failed: file /home/worker/workspace/build/src/docshell/base/nsDocShell.cpp, line 3190
21:29:03     INFO -  JavaScript error: resource://app/modules/ReaderParent.jsm, line 108: TypeError: win.gBrowser is undefined
21:29:04     INFO -  [942] WARNING: attempt to modify an immutable nsStandardURL: file /home/worker/workspace/build/src/netwerk/base/nsStandardURL.cpp, line 1302
21:29:04     INFO -  ++DOCSHELL 0x7f85ceb4a800 == 20 [pid = 942] [id = 137]
21:29:04     INFO -  ++DOMWINDOW == 59 (0x7f85d6251c00) [pid = 942] [serial = 385] [outer = (nil)]
21:29:04     INFO -  ++DOMWINDOW == 60 (0x7f85daaee000) [pid = 942] [serial = 386] [outer = 0x7f85d6251c00]
21:29:05     INFO -  ++DOMWINDOW == 61 (0x7f85daafb000) [pid = 942] [serial = 387] [outer = 0x7f85d6251c00]
21:29:15     INFO -  ++DOCSHELL 0x7f85d656d000 == 21 [pid = 942] [id = 138]
21:29:15     INFO -  ++DOMWINDOW == 62 (0x7f85ceb6fc00) [pid = 942] [serial = 388] [outer = (nil)]
21:29:15     INFO -  ++DOMWINDOW == 63 (0x7f85db3d4000) [pid = 942] [serial = 389] [outer = 0x7f85ceb6fc00]
21:29:15     INFO -  [942] WARNING: NS_ENSURE_TRUE(!mParent || mParent == docLoaderService) failed: file /home/worker/workspace/build/src/docshell/base/nsDocShell.cpp, line 3190
21:29:15     INFO -  [942] WARNING: NS_ENSURE_TRUE(!mParent || mParent == docLoaderService) failed: file /home/worker/workspace/build/src/docshell/base/nsDocShell.cpp, line 3190
21:29:15     INFO -  JavaScript error: resource://app/modules/ReaderParent.jsm, line 108: TypeError: win.gBrowser is undefined
21:29:15     INFO -  [942] WARNING: attempt to modify an immutable nsStandardURL: file /home/worker/workspace/build/src/netwerk/base/nsStandardURL.cpp, line 1302
21:29:16     INFO -  ++DOCSHELL 0x7f85d6e17000 == 22 [pid = 942] [id = 139]
21:29:16     INFO -  ++DOMWINDOW == 64 (0x7f85db98d000) [pid = 942] [serial = 390] [outer = (nil)]
21:29:16     INFO -  ++DOMWINDOW == 65 (0x7f85dbaf9000) [pid = 942] [serial = 391] [outer = 0x7f85db98d000]
21:29:16     INFO -  ++DOMWINDOW == 66 (0x7f85dbc5e000) [pid = 942] [serial = 392] [outer = 0x7f85db98d000]
21:29:19     INFO -  --DOCSHELL 0x7f85d5b66000 == 21 [pid = 942] [id = 131]
21:29:19     INFO -  --DOCSHELL 0x7f85d5f2c000 == 20 [pid = 942] [id = 132]
21:29:19     INFO -  --DOCSHELL 0x7f85ceb27800 == 19 [pid = 942] [id = 133]
21:29:19     INFO -  --DOCSHELL 0x7f85d715b000 == 18 [pid = 942] [id = 134]
21:29:19     INFO -  --DOCSHELL 0x7f85cee9f800 == 17 [pid = 942] [id = 129]
21:29:19     INFO -  --DOCSHELL 0x7f85d5b5c000 == 16 [pid = 942] [id = 136]
21:29:19     INFO -  --DOCSHELL 0x7f85da958000 == 15 [pid = 942] [id = 126]
21:29:19     INFO -  --DOCSHELL 0x7f85dba5c800 == 14 [pid = 942] [id = 128]
21:29:20     INFO -  --DOCSHELL 0x7f85d656d000 == 13 [pid = 942] [id = 138]
21:29:20     INFO -  --DOCSHELL 0x7f85d716f800 == 12 [pid = 942] [id = 116]
21:29:20     INFO -  --DOMWINDOW == 65 (0x7f85d6244800) [pid = 942] [serial = 333] [outer = (nil)] [url = about:customizing]
21:29:20     INFO -  --DOMWINDOW == 64 (0x7f85e8604c00) [pid = 942] [serial = 300] [outer = (nil)] [url = about:newtab]
21:29:20     INFO -  --DOMWINDOW == 63 (0x7f85d6516c00) [pid = 942] [serial = 336] [outer = (nil)] [url = about:newtab]
21:29:24     INFO -  --DOMWINDOW == 62 (0x7f85db4de800) [pid = 942] [serial = 375] [outer = (nil)] [url = about:customizing]
21:29:24     INFO -  --DOMWINDOW == 61 (0x7f85daaef400) [pid = 942] [serial = 348] [outer = (nil)] [url = about:blank]
21:29:24     INFO -  --DOMWINDOW == 60 (0x7f85d77c4400) [pid = 942] [serial = 355] [outer = (nil)] [url = about:blank]
21:29:24     INFO -  --DOMWINDOW == 59 (0x7f85d6df3800) [pid = 942] [serial = 368] [outer = (nil)] [url = about:mozilla]
21:29:24     INFO -  --DOMWINDOW == 58 (0x7f85d72cc800) [pid = 942] [serial = 371] [outer = (nil)] [url = about:robots]
21:29:24     INFO -  --DOMWINDOW == 57 (0x7f85d5e79000) [pid = 942] [serial = 341] [outer = (nil)] [url = about:blank]
21:29:24     INFO -  --DOMWINDOW == 56 (0x7f85d64f3400) [pid = 942] [serial = 366] [outer = (nil)] [url = about:blank]
21:29:24     INFO -  --DOMWINDOW == 55 (0x7f85d758dc00) [pid = 942] [serial = 352] [outer = (nil)] [url = about:customizing]
21:29:24     INFO -  --DOMWINDOW == 54 (0x7f85d5977800) [pid = 942] [serial = 359] [outer = (nil)] [url = about:customizing]
21:29:24     INFO -  --DOMWINDOW == 53 (0x7f85d6dec400) [pid = 942] [serial = 345] [outer = (nil)] [url = about:customizing]
21:29:24     INFO -  --DOMWINDOW == 52 (0x7f85d5f23400) [pid = 942] [serial = 338] [outer = (nil)] [url = about:customizing]
21:29:24     INFO -  --DOMWINDOW == 51 (0x7f85db3d0400) [pid = 942] [serial = 320] [outer = (nil)] [url = about:customizing]
21:29:24     INFO -  --DOMWINDOW == 50 (0x7f85db995400) [pid = 942] [serial = 376] [outer = (nil)] [url = about:blank]
21:29:24     INFO -  --DOMWINDOW == 49 (0x7f85d6245c00) [pid = 942] [serial = 365] [outer = (nil)] [url = about:blank]
21:29:24     INFO -  --DOMWINDOW == 48 (0x7f85d778c000) [pid = 942] [serial = 372] [outer = (nil)] [url = about:blank]
21:29:24     INFO -  --DOMWINDOW == 47 (0x7f85d68c0000) [pid = 942] [serial = 367] [outer = (nil)] [url = about:blank]
21:29:24     INFO -  --DOMWINDOW == 46 (0x7f85d6df8000) [pid = 942] [serial = 369] [outer = (nil)] [url = about:blank]
21:29:24     INFO -  --DOMWINDOW == 45 (0x7f85d624e800) [pid = 942] [serial = 363] [outer = (nil)] [url = about:blank]
21:29:24     INFO -  --DOMWINDOW == 44 (0x7f85d6251400) [pid = 942] [serial = 379] [outer = (nil)] [url = about:blank]
21:29:25     INFO -  --DOMWINDOW == 43 (0x7f85d725f400) [pid = 942] [serial = 373] [outer = (nil)] [url = about:robots]
21:29:25     INFO -  --DOMWINDOW == 42 (0x7f85de580c00) [pid = 942] [serial = 354] [outer = (nil)] [url = about:customizing]
21:29:25     INFO -  --DOMWINDOW == 41 (0x7f85d5f23000) [pid = 942] [serial = 361] [outer = (nil)] [url = about:customizing]
21:29:25     INFO -  --DOMWINDOW == 40 (0x7f85d77ecc00) [pid = 942] [serial = 347] [outer = (nil)] [url = about:customizing]
21:29:25     INFO -  --DOMWINDOW == 39 (0x7f85d5f20800) [pid = 942] [serial = 340] [outer = (nil)] [url = about:customizing]
21:29:27     INFO -  TEST-INFO | started process screentopng
21:29:27     INFO -  TEST-INFO | screentopng: exit 0
21:29:27     INFO -  87 INFO checking window state
21:29:27     INFO -  88 INFO Console message: [JavaScript Error: "TelemetryStopwatch: requesting elapsed time for nonexisting stopwatch. Histogram: "FX_PAGE_LOAD_MS", key: "null"" {file: "resource://gre/modules/TelemetryStopwatch.jsm" line: 297}]
21:29:27     INFO -  89 INFO Entering test
21:29:27     INFO -  90 INFO TEST-PASS | browser/components/customizableui/test/browser_938980_navbar_collapsed.js | Test should start with navbar visible -
21:29:27     INFO -  91 INFO TEST-PASS | browser/components/customizableui/test/browser_938980_navbar_collapsed.js | navbar should be hidden now -
21:29:27     INFO -  92 INFO TEST-PASS | browser/components/customizableui/test/browser_938980_navbar_collapsed.js | Customization reset should restore visibility to the navbar -
21:29:27     INFO -  93 INFO Leaving test
21:29:27     INFO -  94 INFO Entering test
21:29:27     INFO -  95 INFO TEST-PASS | browser/components/customizableui/test/browser_938980_navbar_collapsed.js | Everything should be in its default state -
21:29:27     INFO -  96 INFO TEST-PASS | browser/components/customizableui/test/browser_938980_navbar_collapsed.js | Test should start with bookmarks toolbar collapsed -
21:29:27     INFO -  97 INFO TEST-PASS | browser/components/customizableui/test/browser_938980_navbar_collapsed.js | bookmarksToolbar should be collapsed -
21:29:27     INFO -  98 INFO TEST-PASS | browser/components/customizableui/test/browser_938980_navbar_collapsed.js | TabsToolbar should not be collapsed -
21:29:27     INFO -  99 INFO TEST-PASS | browser/components/customizableui/test/browser_938980_navbar_collapsed.js | The nav-bar should be shown by default -
21:29:27     INFO -  100 INFO TEST-PASS | browser/components/customizableui/test/browser_938980_navbar_collapsed.js | bookmarksToolbar should be visible now -
21:29:27     INFO -  101 INFO TEST-PASS | browser/components/customizableui/test/browser_938980_navbar_collapsed.js | navbar should be collapsed -
21:29:27     INFO -  102 INFO TEST-PASS | browser/components/customizableui/test/browser_938980_navbar_collapsed.js | Should no longer be in default state -
21:29:27     INFO -  103 INFO TEST-PASS | browser/components/customizableui/test/browser_938980_navbar_collapsed.js | Customization reset should restore collapsed-state to the bookmarks toolbar -
21:29:27     INFO -  104 INFO TEST-PASS | browser/components/customizableui/test/browser_938980_navbar_collapsed.js | TabsToolbar should not be collapsed -
21:29:27     INFO -  105 INFO TEST-PASS | browser/components/customizableui/test/browser_938980_navbar_collapsed.js | The bookmarksToolbar should be collapsed after reset -
21:29:27     INFO -  106 INFO TEST-PASS | browser/components/customizableui/test/browser_938980_navbar_collapsed.js | Everything should be back to default state -
21:29:27     INFO -  107 INFO Leaving test
21:29:27     INFO -  108 INFO Entering test
21:29:27     INFO -  109 INFO TEST-PASS | browser/components/customizableui/test/browser_938980_navbar_collapsed.js | Everything should be in its default state -
21:29:27     INFO -  110 INFO TEST-PASS | browser/components/customizableui/test/browser_938980_navbar_collapsed.js | menubar should be hidden by default -
21:29:27     INFO -  111 INFO TEST-PASS | browser/components/customizableui/test/browser_938980_navbar_collapsed.js | menubar should be visible now -
21:29:27     INFO -  112 INFO TEST-PASS | browser/components/customizableui/test/browser_938980_navbar_collapsed.js | The menubar should have autohide=true after reset in customization mode -
21:29:27     INFO -  113 INFO TEST-PASS | browser/components/customizableui/test/browser_938980_navbar_collapsed.js | The menubar should have height=0 after reset in customization mode -
21:29:27     INFO -  114 INFO TEST-PASS | browser/components/customizableui/test/browser_938980_navbar_collapsed.js | The menubar should have autohide=true after reset -
21:29:27     INFO -  115 INFO TEST-PASS | browser/components/customizableui/test/browser_938980_navbar_collapsed.js | The menubar should have height=0 after reset -
21:29:27     INFO -  116 INFO Leaving test
21:29:27     INFO -  117 INFO Entering test
21:29:27     INFO -  118 INFO TEST-PASS | browser/components/customizableui/test/browser_938980_navbar_collapsed.js | Everything should be in its default state -
21:29:27     INFO -  119 INFO TEST-PASS | browser/components/customizableui/test/browser_938980_navbar_collapsed.js | bookmarksToolbar should be collapsed -
21:29:27     INFO -  120 INFO TEST-PASS | browser/components/customizableui/test/browser_938980_navbar_collapsed.js | TabsToolbar should not be collapsed -
21:29:27     INFO -  121 INFO TEST-PASS | browser/components/customizableui/test/browser_938980_navbar_collapsed.js | bookmarksToolbar should be visible now -
21:29:27     INFO -  122 INFO TEST-PASS | browser/components/customizableui/test/browser_938980_navbar_collapsed.js | Should no longer be in default state -
21:29:27     INFO -  123 INFO Console message: [JavaScript Error: "TypeError: win.gBrowser is undefined" {file: "resource://app/modules/ReaderParent.jsm" line: 108}]
21:29:27     INFO -  124 INFO TEST-PASS | browser/components/customizableui/test/browser_938980_navbar_collapsed.js | The bookmarksToolbar should be visible before reset -
21:29:27     INFO -  125 INFO TEST-PASS | browser/components/customizableui/test/browser_938980_navbar_collapsed.js | The navbar should be visible before reset -
21:29:27     INFO -  126 INFO TEST-PASS | browser/components/customizableui/test/browser_938980_navbar_collapsed.js | TabsToolbar should not be collapsed -
21:29:27     INFO -  127 INFO TEST-PASS | browser/components/customizableui/test/browser_938980_navbar_collapsed.js | The bookmarksToolbar should be collapsed after reset -
21:29:27     INFO -  128 INFO TEST-PASS | browser/components/customizableui/test/browser_938980_navbar_collapsed.js | TabsToolbar should not be collapsed -
21:29:27     INFO -  129 INFO TEST-PASS | browser/components/customizableui/test/browser_938980_navbar_collapsed.js | The navbar should still be visible after reset -
21:29:27     INFO -  130 INFO TEST-PASS | browser/components/customizableui/test/browser_938980_navbar_collapsed.js | Everything should be back to default state -
21:29:27     INFO -  131 INFO Leaving test
21:29:27     INFO -  132 INFO Entering test
21:29:27     INFO -  133 INFO TEST-PASS | browser/components/customizableui/test/browser_938980_navbar_collapsed.js | Everything should be in its default state -
21:29:27     INFO -  134 INFO Console message: [JavaScript Error: "TypeError: win.gBrowser is undefined" {file: "resource://app/modules/ReaderParent.jsm" line: 108}]
21:29:27     INFO -  135 INFO TEST-PASS | browser/components/customizableui/test/browser_938980_navbar_collapsed.js | The reset button should be disabled when in default state -
21:29:27     INFO -  136 INFO TEST-PASS | browser/components/customizableui/test/browser_938980_navbar_collapsed.js | The reset button should be enabled when not in default state -
21:29:27     INFO -  137 INFO TEST-PASS | browser/components/customizableui/test/browser_938980_navbar_collapsed.js | No longer in default state when the menubar is shown -
21:29:27     INFO -  138 INFO TEST-PASS | browser/components/customizableui/test/browser_938980_navbar_collapsed.js | The reset button should be disabled when in default state -
21:29:27     INFO -  139 INFO TEST-PASS | browser/components/customizableui/test/browser_938980_navbar_collapsed.js | Everything should be in its default state -
21:29:27     INFO -  140 INFO Leaving test
21:29:27     INFO -  141 INFO TEST-UNEXPECTED-FAIL | browser/components/customizableui/test/browser_938980_navbar_collapsed.js | This test exceeded the timeout threshold. It should be rewritten or split up. If that's not possible, use requestLongerTimeout(N), but only as a last resort. -
21:29:27     INFO -  MEMORY STAT | vsize 1307MB | residentFast 326MB | heapAllocated 89MB
21:29:27     INFO -  142 INFO TEST-OK | browser/components/customizableui/test/browser_938980_navbar_collapsed.js | took 46973ms
21:29:27     INFO -  ++DOCSHELL 0x7f85cee83800 == 13 [pid = 942] [id = 140]
21:29:27     INFO -  ++DOMWINDOW == 40 (0x7f85d5971c00) [pid = 942] [serial = 393] [outer = (nil)]
21:29:27     INFO -  ++DOMWINDOW == 41 (0x7f85d5e7f800) [pid = 942] [serial = 394] [outer = 0x7f85d5971c00]


in the same log you can see the failure for browser_970511_undo_restore_default.js.

I am filing this bug because it seems that this test is using 100% cpu and exceeding the time limit.  I am not sure if we can rewrite the test or split it up to be smaller.
Ugh, I hate the logging changes that mean timestamps are now utterly useless.

Why do you think the test is exceeding the time limit, rather than just waiting for something that never happens? It seems from the log that the test completes all the tasks in the test correctly (all the way down to "leaving test" for the last task). So have you checked if the test framework is hung or something? We assert something right before the end of the last task in the test, and the timeout should run from that point onwards. It doesn't make sense to split the test up because it doesn't seem to be the test that is "stuck" here.
Flags: needinfo?(jmaher)
the timestamps are frustrating and reproducing this locally is hard as I run on a multi-core system.  Spending more time looking at the output yields the same conclusion- we finish the test, but we time out.  I wonder if a single core system takes longer and there is some screensaver or other popup which is taking longer.  Say if it is time based or related to something else system wide crashing due to the high cpu load.

This test failure is <10 minutes into the test run, I doubt it would be screensaver related despite attempts to turn the screensaver off.

Looking at passing jobs in the land of multi-core, I see that we finish in ~25 seconds, which is much less than the 45 seconds allocated for the timeout.  Knowing on average we had a 20% slowdown on single core, that would still have us finish in <45 seconds, probably <35 seconds.

If there is nothing of concern with this test, we might not have anything specific to do here.
Flags: needinfo?(jmaher)
(In reply to Joel Maher (:jmaher) from comment #2)
> the timestamps are frustrating and reproducing this locally is hard as I run
> on a multi-core system.  Spending more time looking at the output yields the
> same conclusion- we finish the test, but we time out.  I wonder if a single
> core system takes longer and there is some screensaver or other popup which
> is taking longer.  Say if it is time based or related to something else
> system wide crashing due to the high cpu load.
> 
> This test failure is <10 minutes into the test run, I doubt it would be
> screensaver related despite attempts to turn the screensaver off.
> 
> Looking at passing jobs in the land of multi-core, I see that we finish in
> ~25 seconds, which is much less than the 45 seconds allocated for the
> timeout.  Knowing on average we had a 20% slowdown on single core, that
> would still have us finish in <45 seconds, probably <35 seconds.
> 
> If there is nothing of concern with this test, we might not have anything
> specific to do here.

Well, you said we're going to be switching to the single core docker image, so does that mean we're going to have to disable this test or live with it being orange lots of the time? That doesn't sound good...

Is there a simple way to trypush this or something? Can we just add logging to the browser-test.js harness to see what's going on in more detail? That might be a good idea generally...
Flags: needinfo?(jmaher)
yes, we will be using single core (as that is what we are doing with the non docker tests).  We have found that running on different instance types in amazon yield different results.  This is what we are testing now.  I know that means this is undeterministic in that we cannot reliably reproduce the problem locally (the great promise of docker is now not there).

We can add logging and push to try, there are a series of patches which are needed for this- I will probably be pushing some debugging in the near future, if you want to suggest some areas to start with to see if this helps.
Flags: needinfo?(jmaher)
Severity: normal → S3
You need to log in before you can comment on or make changes to this bug.