Intermittent TV automation.py | application timed out after 740.0 seconds with no output | single tracking bug
Categories
(Testing :: General, defect, P5)
Tracking
(firefox-esr115 unaffected, firefox120 unaffected, firefox121 unaffected, firefox122 affected, firefox123 affected)
| Tracking | Status | |
|---|---|---|
| firefox-esr115 | --- | unaffected |
| firefox120 | --- | unaffected |
| firefox121 | --- | unaffected |
| firefox122 | --- | affected |
| firefox123 | --- | affected |
People
(Reporter: intermittent-bug-filer, Unassigned)
References
Details
(Keywords: intermittent-failure, regression, test-verify-fail)
Filed by: imoraru [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=439220639&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/d0J9AcHnRbSdfQM668_kHg/runs/0/artifacts/public/logs/live_backing.log
Reftest URL: https://hg.mozilla.org/mozilla-central/raw-file/tip/layout/tools/reftest/reftest-analyzer.xhtml#logurl=https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/d0J9AcHnRbSdfQM668_kHg/runs/0/artifacts/public/logs/live_backing.log&only_show_unexpected=1
[task 2023-12-07T16:25:54.545Z] 16:25:54 INFO - TEST-START | browser/extensions/formautofill/test/browser/creditCard/browser_creditCard_capture_form_removal.js
[task 2023-12-07T16:25:58.631Z] 16:25:58 INFO - GECKO(6245) | MEMORY STAT vsizeMaxContiguous not supported in this build configuration.
[task 2023-12-07T16:25:58.634Z] 16:25:58 INFO - GECKO(6245) | MEMORY STAT | vsize 11517MB | residentFast 465MB | heapAllocated 249MB
[task 2023-12-07T16:25:58.634Z] 16:25:58 INFO - TEST-OK | browser/extensions/formautofill/test/browser/creditCard/browser_creditCard_capture_form_removal.js | took 4088ms
[task 2023-12-07T16:25:58.706Z] 16:25:58 INFO - checking window state
[task 2023-12-07T16:25:58.798Z] 16:25:58 INFO - GECKO(6245) | Completed ShutdownLeaks collections in process 6245
[task 2023-12-07T16:25:58.798Z] 16:25:58 INFO - TEST-START | Shutdown
[task 2023-12-07T16:25:58.798Z] 16:25:58 INFO - Browser Chrome Test Summary
[task 2023-12-07T16:25:58.798Z] 16:25:58 INFO - Passed: 7
[task 2023-12-07T16:25:58.798Z] 16:25:58 INFO - Failed: 0
[task 2023-12-07T16:25:58.798Z] 16:25:58 INFO - Todo: 0
[task 2023-12-07T16:25:58.798Z] 16:25:58 INFO - Mode: e10s
[task 2023-12-07T16:25:58.799Z] 16:25:58 INFO - *** End BrowserChrome Test Results ***
[task 2023-12-07T16:25:58.836Z] 16:25:58 INFO - GECKO(6245) | Exiting due to channel error.
[task 2023-12-07T16:25:58.836Z] 16:25:58 INFO - GECKO(6245) | Exiting due to channel error.
[task 2023-12-07T16:25:58.837Z] 16:25:58 INFO - GECKO(6245) | Exiting due to channel error.
[task 2023-12-07T16:25:58.837Z] 16:25:58 INFO - GECKO(6245) | Exiting due to channel error.
[task 2023-12-07T16:25:58.837Z] 16:25:58 INFO - GECKO(6245) | Exiting due to channel error.
[task 2023-12-07T16:25:58.838Z] 16:25:58 INFO - GECKO(6245) | Exiting due to channel error.
[task 2023-12-07T16:25:58.838Z] 16:25:58 INFO - GECKO(6245) | Exiting due to channel error.
[task 2023-12-07T16:25:58.899Z] 16:25:58 INFO - TEST-INFO | Main app process: exit 0
[task 2023-12-07T16:25:58.899Z] 16:25:58 INFO - runtests.py | Application ran for: 0:08:50.843136
[task 2023-12-07T16:25:58.899Z] 16:25:58 INFO - zombiecheck | Reading PID log: /tmp/tmph4e3lft_pidlog
<...>
[task 2023-12-07T16:25:59.373Z] 16:25:59 INFO - runtests.py | Running tests: start.
[task 2023-12-07T16:25:59.374Z] 16:25:59 INFO -
[task 2023-12-07T16:25:59.402Z] 16:25:59 INFO - Application command: /builds/worker/workspace/build/application/firefox/firefox -marionette -foreground -profile /tmp/tmpc_pn2b7y.mozrunner
[task 2023-12-07T16:25:59.412Z] 16:25:59 INFO - runtests.py | Application pid: 6687
[task 2023-12-07T16:25:59.413Z] 16:25:59 INFO - TEST-INFO | started process GECKO(6687)
[task 2023-12-07T16:25:59.440Z] 16:25:59 INFO - GECKO(6687) | *** You are running in chaos test mode. See ChaosMode.h. ***
[task 2023-12-07T16:26:00.396Z] 16:26:00 INFO - GECKO(6687) | ATTENTION: default value of option mesa_glthread overridden by environment.
[task 2023-12-07T16:26:00.429Z] 16:26:00 INFO - GECKO(6687) | 1701966360428 Marionette INFO Marionette enabled
[task 2023-12-07T16:26:00.432Z] 16:26:00 INFO - GECKO(6687) | 1701966360431 Marionette TRACE Received observer notification final-ui-startup
[task 2023-12-07T16:26:00.489Z] 16:26:00 INFO - GECKO(6687) | console.error: "Warning: unrecognized command line flag" "-foreground"
[task 2023-12-07T16:26:00.498Z] 16:26:00 INFO - GECKO(6687) | ATTENTION: default value of option mesa_glthread overridden by environment.
[task 2023-12-07T16:26:00.531Z] 16:26:00 INFO - GECKO(6687) | 1701966360530 RemoteAgent WARN PollPromise timed out after 5000 ms
[task 2023-12-07T16:26:00.537Z] 16:26:00 INFO - GECKO(6687) | 1701966360536 Marionette INFO Listening on port 2828
[task 2023-12-07T16:26:00.540Z] 16:26:00 INFO - GECKO(6687) | 1701966360539 Marionette DEBUG Marionette is listening
[task 2023-12-07T16:26:00.584Z] 16:26:00 INFO - GECKO(6687) | 1701966360582 Marionette DEBUG Accepted connection 0 from 127.0.0.1:59156
[task 2023-12-07T16:26:00.657Z] 16:26:00 INFO - GECKO(6687) | 1701966360655 Marionette DEBUG Accepted connection 1 from 127.0.0.1:59160
[task 2023-12-07T16:26:00.665Z] 16:26:00 INFO - GECKO(6687) | 1701966360664 Marionette DEBUG Closed connection 0
[task 2023-12-07T16:26:01.032Z] 16:26:01 INFO - GECKO(6687) | 1701966361031 Marionette DEBUG 1 -> [0,1,"WebDriver:NewSession",{"strictFileInteractability":true}]
[task 2023-12-07T16:26:01.038Z] 16:26:01 INFO - GECKO(6687) | 1701966361037 Marionette DEBUG Waiting for initial application window
[task 2023-12-07T16:26:05.972Z] 16:26:05 INFO - GECKO(6687) | console.error: ({})
[task 2023-12-07T16:26:09.868Z] 16:26:09 INFO - GECKO(6687) | 1701966369867 Marionette TRACE Received observer notification browser-idle-startup-tasks-finished
[task 2023-12-07T16:26:09.917Z] 16:26:09 INFO - GECKO(6687) | 1701966369915 RemoteAgent TRACE [9] ProgressListener Start: expectNavigation=false resolveWhenStarted=false unloadTimeout=5000 waitForExplicitStart=false
[task 2023-12-07T16:26:09.919Z] 16:26:09 INFO - GECKO(6687) | 1701966369918 RemoteAgent TRACE [9] ProgressListener Setting unload timer (5000ms)
[task 2023-12-07T16:26:09.922Z] 16:26:09 INFO - GECKO(6687) | 1701966369921 RemoteAgent TRACE [9] Document already finished loading: about:blank
[task 2023-12-07T16:26:09.927Z] 16:26:09 INFO - GECKO(6687) | 1701966369923 RemoteAgent TRACE [9] ProgressListener Stop: has error=false
[task 2023-12-07T16:26:09.960Z] 16:26:09 INFO - GECKO(6687) | 1701966369957 Marionette DEBUG 1 <- [1,1,null,{"sessionId":"4ff0fab7-7b0d-4fac-8703-0d9eb6cb7308","capabilities":{"browserName":"firefox","browserVersion":"122.0a1","platformName":"linux","acceptInsecureCerts":false,"pageLoadStrategy":"normal","setWindowRect":true,"timeouts":{"implicit":0,"pageLoad":300000,"script":30000},"strictFileInteractability":true,"unhandledPromptBehavior":"dismiss and notify","moz:accessibilityChecks":false,"moz:buildID":"20231207152911","moz:headless":false,"moz:platformVersion":"4.4.0-1014-aws","moz:processID":6687,"moz:profile":"/tmp/tmpc_pn2b7y.mozrunner","moz:shutdownTimeout":60000,"moz:webdriverClick":true,"moz:windowless":false,"proxy":{}}}]
[task 2023-12-07T16:26:10.009Z] 16:26:10 INFO - GECKO(6687) | 1701966370008 Marionette DEBUG 1 -> [0,2,"Addon:Install",{"path":"/tmp/tmpupss0eod.zip","temporary":false}]
[task 2023-12-07T16:26:11.408Z] 16:26:11 INFO - GECKO(6687) | JavaScript error: resource://gre/modules/XULStore.sys.mjs, line 60: Error: Can't find profile directory.
[task 2023-12-07T16:26:11.410Z] 16:26:11 INFO - GECKO(6687) | JavaScript error: resource://gre/modules/XULStore.sys.mjs, line 60: Error: Can't find profile directory.
[task 2023-12-07T16:26:11.415Z] 16:26:11 INFO - GECKO(6687) | JavaScript error: resource://gre/modules/XULStore.sys.mjs, line 60: Error: Can't find profile directory.
[task 2023-12-07T16:26:11.436Z] 16:26:11 INFO - GECKO(6687) | JavaScript error: resource://gre/modules/XULStore.sys.mjs, line 60: Error: Can't find profile directory.
[task 2023-12-07T16:26:11.438Z] 16:26:11 INFO - GECKO(6687) | JavaScript error: resource://gre/modules/XULStore.sys.mjs, line 60: Error: Can't find profile directory.
[task 2023-12-07T16:26:11.441Z] 16:26:11 INFO - GECKO(6687) | JavaScript error: resource://gre/modules/XULStore.sys.mjs, line 60: Error: Can't find profile directory.
[task 2023-12-07T16:26:11.443Z] 16:26:11 INFO - GECKO(6687) | 1701966371442 Marionette DEBUG 1 <- [1,2,null,{"value":"special-powers@mozilla.org"}]
[task 2023-12-07T16:26:11.446Z] 16:26:11 INFO - GECKO(6687) | JavaScript error: resource://gre/modules/XULStore.sys.mjs, line 60: Error: Can't find profile directory.
[task 2023-12-07T16:26:11.547Z] 16:26:11 INFO - GECKO(6687) | 1701966371544 Marionette DEBUG 1 -> [0,3,"Addon:Install",{"path":"/tmp/tmpke7ftsx6.zip","temporary":false}]
[task 2023-12-07T16:32:11.553Z] 16:32:11 INFO - runtests.py | Waiting for browser...
[task 2023-12-07T16:33:57.150Z] 16:33:57 INFO - GECKO(6687) | 1701966837149 Marionette DEBUG 1 <- [1,3,null,{"value":"mochikit@mozilla.org"}]
[task 2023-12-07T16:33:57.182Z] 16:33:57 INFO - GECKO(6687) | 1701966837181 Marionette DEBUG Closed connection 1
[task 2023-12-07T16:46:17.196Z] 16:46:17 INFO - TEST-UNEXPECTED-TIMEOUT | automation.py | application timed out after 740 seconds with no output
[task 2023-12-07T16:46:17.196Z] 16:46:17 INFO - TEST-INFO
[task 2023-12-07T16:46:17.196Z] 16:46:17 INFO - Buffered messages finished
[task 2023-12-07T16:46:17.196Z] 16:46:17 WARNING - Force-terminating active process(es).
[task 2023-12-07T16:46:17.196Z] 16:46:17 INFO - Determining child pids from psutil...
[task 2023-12-07T16:46:17.206Z] 16:46:17 INFO - [6765, 6798, 6836, 6862, 6864, 6865, 6898]
Comment 1•2 years ago
|
||
Hi Janika! Can you please take a look at this? The reason for the need info and marking Bug 1865876 as the culprit, is that I saw the last test start before the timeout TEST-START | browser/extensions/formautofill/test/browser/creditCard/browser_creditCard_capture_form_removal.js which is added in that bug.
Thank you!
Hi Geoff! Can you also take a look at this please?
Thank you!
There seems to be a hang here:
[task 2023-12-07T16:26:11.547Z] 16:26:11 INFO - GECKO(6687) | 1701966371544 Marionette DEBUG 1 -> [0,3,"Addon:Install",{"path":"/tmp/tmpke7ftsx6.zip","temporary":false}]
[task 2023-12-07T16:32:11.553Z] 16:32:11 INFO - runtests.py | Waiting for browser...
[task 2023-12-07T16:33:57.150Z] 16:33:57 INFO - GECKO(6687) | 1701966837149 Marionette DEBUG 1 <- [1,3,null,{"value":"mochikit@mozilla.org"}]
[task 2023-12-07T16:33:57.182Z] 16:33:57 INFO - GECKO(6687) | 1701966837181 Marionette DEBUG Closed connection 1
[task 2023-12-07T16:46:17.196Z] 16:46:17 INFO - TEST-UNEXPECTED-TIMEOUT | automation.py | application timed out after 740 seconds with no output
[task 2023-12-07T16:46:17.196Z] 16:46:17 INFO - TEST-INFO
[task 2023-12-07T16:46:17.196Z] 16:46:17 INFO - Buffered messages finished
Updated•2 years ago
|
Comment 2•2 years ago
|
||
Set release status flags based on info from the regressing bug 1865876
| Comment hidden (Intermittent Failures Robot) |
Comment 5•2 years ago
|
||
Set release status flags based on info from the regressing bug 1865876
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
Updated•1 year ago
|
Comment 21•1 year ago
|
||
Hm, afaict we aren't running TV on Wayland yet:
https://searchfox.org/mozilla-central/source/taskcluster/kinds/test/misc.yml#72
Updated•1 year ago
|
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
Comment 34•11 months ago
|
||
Hi Joel , could you take a look at this failure? It's racking 59 failures this week
Thanks.
Recent failure log -> https://treeherder.mozilla.org/logviewer?job_id=508869737&repo=autoland&lineNumber=4900
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
Comment 37•11 months ago
|
||
this is macosx 14.70/debug only. I suspect this is similar to what we see for webdriver tests in bug 1960740.
I would rather revisit this after bug 1960740 is resolved. If this is still a problem or we want to do something faster, I am happy to not schedule test-verify on macosx/debug.
Comment 38•11 months ago
|
||
Well, for recent failures at least I can see the following log entries:
https://treeherder.mozilla.org/logviewer?job_id=509217630&repo=autoland&lineNumber=15451-15453
task 2025-05-20T11:55:51.579Z] 11:55:51 INFO - GECKO(2633) | ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to /var/folders/8h/42m81v7x53xc8ycgyw2nl0vw0000jb/T/tmphcvisqvp.mozrunner/runtests_leaks_tab_pid2641.log
[task 2025-05-20T11:55:51.787Z] 11:55:51 INFO - GECKO(2633) | Couldn't convert chrome URL: chrome://branding/locale/brand.properties
[task 2025-05-20T11:55:51.788Z] 11:55:51 INFO - GECKO(2633) | [Child 2641, Main Thread] WARNING: Could not get the program name for a cubeb stream.: 'NS_SUCCEEDED(rv)', file /builds/worker/checkouts/gecko/dom/media/CubebUtils.cpp:476
[task 2025-05-20T12:07:51.164Z] 12:07:51 INFO - runtests.py | Waiting for browser...
If there is a problem with chrome://branding/locale/brand.properties it most likely is a broken build? I have seen things like that only when updating a local checkout and failing to build before starting Firefox. Here we clearly hang and also cannot get a connection to Marionette to install the mochijar and specialpowers addons.
Note that this line is only printed in debug builds and as per list only those builds are failing here. IMHO this is a different issue than bug 1960740.
Gijs, do you have an idea/
Comment 39•11 months ago
|
||
(In reply to Henrik Skupin [:whimboo][⌚️UTC+2] from comment #38)
Well, for recent failures at least I can see the following log entries:
https://treeherder.mozilla.org/logviewer?job_id=509217630&repo=autoland&lineNumber=15451-15453task 2025-05-20T11:55:51.579Z] 11:55:51 INFO - GECKO(2633) | ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to /var/folders/8h/42m81v7x53xc8ycgyw2nl0vw0000jb/T/tmphcvisqvp.mozrunner/runtests_leaks_tab_pid2641.log [task 2025-05-20T11:55:51.787Z] 11:55:51 INFO - GECKO(2633) | Couldn't convert chrome URL: chrome://branding/locale/brand.properties [task 2025-05-20T11:55:51.788Z] 11:55:51 INFO - GECKO(2633) | [Child 2641, Main Thread] WARNING: Could not get the program name for a cubeb stream.: 'NS_SUCCEEDED(rv)', file /builds/worker/checkouts/gecko/dom/media/CubebUtils.cpp:476 [task 2025-05-20T12:07:51.164Z] 12:07:51 INFO - runtests.py | Waiting for browser...Gijs, do you have an idea/
The screenshot from this is super weird. Joel, are we expecting raritan hardware connected to our thing? Can we dismiss this prompt? Is this issue specific to particular (virtual) machines?
If there is a problem with
chrome://branding/locale/brand.propertiesit most likely is a broken build? I have seen things like that only when updating a local checkout and failing to build before starting Firefox. Here we clearly hang and also cannot get a connection to Marionette to install the mochijar and specialpowers addons.Note that this line is only printed in debug builds and as per list only those builds are failing here. IMHO this is a different issue than bug 1960740.
I don't understand what "as per list" means. Do other, working debug build tests report this same error? Have you tried downloading the artifacts that are being run and do they run locally? Any evidence that things are getting lost when moving content out of dmgs and such?
Comment 40•11 months ago
|
||
These lines in the log about not killing things are also weird: https://treeherder.mozilla.org/logviewer?job_id=509217630&repo=autoland&lineNumber=15385-15390
Comment 41•11 months ago
|
||
thanks for pointing that out :gijs, the raritan is what we use for pdu/kvm, but we need to dismiss this dialog properly and it shouldn't be popping up in general, maybe setup had some issues.
:rcurran, can you look at the kvm setup and ensure all "devices" are properly setup on the 14.7.5 machines (per screenshot)?
Comment 42•11 months ago
|
||
(In reply to :Gijs (he/him) from comment #39)
I don't understand what "as per list" means. Do other, working debug build tests report this same error? Have you tried downloading the artifacts that are being run and do they run locally? Any evidence that things are getting lost when moving content out of dmgs and such?
I meant the intermittent failures list. Sorry when it was not that clear.
These kind of hang also happens when this Raritan dialog is not open. It looks like Firefox doesn't open any window, and the last notification that we receive in Marionette is final-ui-startup.
I now downloaded such a DMG and run it locally after installing with mozinstall. I didn't observe an issue.
Comment 43•11 months ago
|
||
Note that those failures started on May 13th. Joel and Ryan, was it the time when we started to upgrade from 14.7.1 to 14.7.5?
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
Comment 46•11 months ago
•
|
||
We started that rollout on May 6th, completed it on May 8th, re-puppetized the workers on May 9th (so that the gw config would update reflecting the correct OS version), and updated Safari on May 12th.
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
Comment 50•11 months ago
|
||
Recent failures still have the same dialog popping up: https://firefoxci.taskcluster-artifacts.net/AzpAHKtFTfutFuIRkXmsGw/0/public/test_info/mozilla-test-fail-screenshot_d9ufdv9p.png
Renewing this needinfo for that bit in case it is interfering with Firefox in some way:
(In reply to Joel Maher ( :jmaher ) (UTC -8) from comment #41)
thanks for pointing that out :gijs, the raritan is what we use for pdu/kvm, but we need to dismiss this dialog properly and it shouldn't be popping up in general, maybe setup had some issues.
:rcurran, can you look at the kvm setup and ensure all "devices" are properly setup on the 14.7.5 machines (per screenshot)?
Comment 51•11 months ago
|
||
(In reply to :Gijs (he/him) from comment #50)
Recent failures still have the same dialog popping up: https://firefoxci.taskcluster-artifacts.net/AzpAHKtFTfutFuIRkXmsGw/0/public/test_info/mozilla-test-fail-screenshot_d9ufdv9p.png
Note that not all of these failures actually show this dialog, but still a lot of notifications for firefox and xyz: https://firefoxci.taskcluster-artifacts.net/DHVZwPDCTK6TOaxzY87T2Q/0/public/test_info/mozilla-test-fail-screenshot_r3ig06b1.png.
But there is probably some other factor which is causing this issue.
| Comment hidden (Intermittent Failures Robot) |
Comment 53•11 months ago
|
||
:Gijs Is the needinfo a request to suppress the kvm keyboard prompt? Or something else? Thank you
| Comment hidden (Intermittent Failures Robot) |
Comment 55•11 months ago
|
||
(In reply to Ryan Curran from comment #53)
:Gijs Is the needinfo a request to suppress the kvm keyboard prompt? Or something else? Thank you
Yes - I quoted comment #41 where my read of Joel's comment was that hopefully we could get rid of the dialog. Even if it isn't itself interfering with the test, as long as it's there other people with intermittent failures will probably wonder about whether it is a cause (and/or may occlude what the actual app is doing), so it seems better to make sure it's not present.
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
Comment 59•10 months ago
|
||
(In reply to :Gijs (he/him) from comment #55)
(In reply to Ryan Curran from comment #53)
:Gijs Is the needinfo a request to suppress the kvm keyboard prompt? Or something else? Thank you
Yes - I quoted comment #41 where my read of Joel's comment was that hopefully we could get rid of the dialog. Even if it isn't itself interfering with the test, as long as it's there other people with intermittent failures will probably wonder about whether it is a cause (and/or may occlude what the actual app is doing), so it seems better to make sure it's not present.
Thank you. I have created a work item for this issue https://mozilla-hub.atlassian.net/browse/RELOPS-1601
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
Updated•7 months ago
|
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
Comment 77•6 months ago
|
||
Note that I was able to see the exact problem locally on my MBP. I filed bug 1997841 with a Gecko profile attached. Lets hope it's useful and we can figure out why it's happening. this is a high frequent failure - whereby the underlying reason in the mochitest harness is the same as bug 1414495.
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
Comment 84•4 months ago
|
||
As it looks like the infra changes as pushed to macOS workers on bug 2004631 has fixed the timeouts completely for that platform. Lets revisit later this week if we can close this bug now given that only macOS was affected by it over the last 30 days.
Comment 85•4 months ago
|
||
(In reply to Henrik Skupin [:whimboo][⌚️UTC+1] from comment #84)
As it looks like the infra changes as pushed to macOS workers on bug 2004631 has fixed the timeouts completely for that platform. Lets revisit later this week if we can close this bug now given that only macOS was affected by it over the last 30 days.
Actually macOS machines need to be provisioned again. The whole process will take a bit longer. So no improvements will be seen immediately.
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
Comment 90•3 months ago
|
||
With the fix on bug 2004631 most of the failures are gone now.
But what I wonder why we are waiting twice that long (740s) on macOS instead of the 360s on other platforms. I'm asking because this bug is basically all the same as bug 1414495, which is about Waiting for browser....
From the logs it looks like that only verify mode is actually affected and I can see those lines:
[task 2026-01-06T01:21:12.194+00:00] 01:21:12 INFO - Increasing default timeout to 90 seconds (asan or debug)
[task 2026-01-06T01:21:12.194+00:00] 01:21:12 INFO - Increasing default timeout to 180 seconds (MOZ_CHAOSMODE)
But still there is a factor of 4 still missing which might get applied at some other point and that is not listed anywhere in the logs.
Andrew, do you have an idea where this could be done and especially why we need that? I don't see an actual reason for it.
Comment 91•3 months ago
|
||
Sorry, I'm not sure. There could be some logic in one of the transforms under taskcluster/gecko_taskgraph/transforms/test (try grepping for max-run-time), or sometimes test manifests can increase the timeoutfactor as well, e.g:
https://searchfox.org/firefox-main/source/browser/components/backup/tests/xpcshell/xpcshell.toml#35
Comment 92•3 months ago
|
||
(In reply to Andrew Halberstadt [:ahal] from comment #91)
Sorry, I'm not sure. There could be some logic in one of the transforms under
taskcluster/gecko_taskgraph/transforms/test(try grepping formax-run-time), or sometimes test manifests can increase the timeoutfactor as well, e.g:
https://searchfox.org/firefox-main/source/browser/components/backup/tests/xpcshell/xpcshell.toml#35
But that should as well be reflected in the log output as shown above. When I query the log viewer for Increasing default timeout nothing is listed which would explain an increase of the default timeout. The maximum is still set to 180s like for this job:
https://treeherder.mozilla.org/logviewer?job_id=542468879&repo=autoland&lineNumber=14584
If we silently applying other multiplicators we should as well log that and not doing it silently.
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
Comment 102•1 month ago
|
||
It looks like that the increase of this failure on macOS might be related to the Keyboard Setup Assistent dialog which pops-up for all the affected tests.
But not sure if that is actually the real underlying reason why the Firefox window doesn't open at all.
@Ryan are you aware of this dialog? Is that something new or do you already have a bug for it?
| Comment hidden (Intermittent Failures Robot) |
Comment 104•1 month ago
|
||
hi :whimboo
we landed a change with a potential fix for this about a month ago. are the keyboard prompts still showing up since then?
thank you
Comment 105•1 month ago
|
||
Yes it does. Here a failing job from Saturday with the associated screenshot:
https://treeherder.mozilla.org/logviewer?job_id=554874271&repo=autoland&lineNumber=6556
https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/HmFo3kbaSUeJrnyMAIY0BQ/runs/0/artifacts/public/test_info/mozilla-test-fail-screenshot_0wck_6ic.png
Comment 106•1 month ago
|
||
thank you. i have a new approach im going to test https://github.com/mozilla-platform-ops/ronin_puppet/pull/1141
Updated•1 month ago
|
Comment 107•1 month ago
|
||
merged the pr. the change should land on all the mac14/15 workers in an hour or so. keep me posted :whimboo if you still see the issue after that time. thanks
Comment 108•1 month ago
|
||
Great! Let it bake some days given that sometimes new failures appear days after. I'll check back on Monday with the regular triage work if the situation has been improved, and if that keyboard dialog was the reason for the failures at all.
| Comment hidden (Intermittent Failures Robot) |
Comment 110•1 month ago
|
||
(In reply to Ryan Curran from comment #107)
merged the pr. the change should land on all the mac14/15 workers in an hour or so. keep me posted :whimboo if you still see the issue after that time. thanks
Since the patch landed on all the workers I haven't seen this dialog in a screenshot anymore. Thanks Ryan!
Nevertheless this bug is still not done given that the Firefox window doesn't come up correctly. Marionette is blocked as well with waiting for the initial application window. Maybe some more details logging could help to identify the underlying problem. But lets wait until more failures happen.
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
Description
•