Intermittent TEST-UNEXPECTED-TIMEOUT | toolkit/content/tests/chrome/test_bug331215.xhtml | application timed out after 370 seconds with no output
Categories
(Toolkit :: Find Toolbar, defect, P5)
Tracking
()
People
(Reporter: intermittent-bug-filer, Unassigned)
References
(Regression)
Details
(Keywords: intermittent-failure, regression, Whiteboard: [stockwell disabled])
Attachments
(1 file)
Filed by: csabou [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer.html#?job_id=267343567&repo=autoland
Full log: https://queue.taskcluster.net/v1/task/fPZQbuTkTiydoOnnf_cr1A/runs/0/artifacts/public/logs/live_backing.log
[task 2019-09-18T23:52:26.605Z] 23:52:26 INFO - TEST-PASS | toolkit/content/tests/chrome/test_bug331215.xul | Findfield status attribute should not have been 'notfound' after entering latest
[task 2019-09-18T23:52:26.605Z] 23:52:26 INFO - Starting test with browser 'content-remote'
[task 2019-09-18T23:52:26.605Z] 23:52:26 INFO - Buffered messages finished
[task 2019-09-18T23:52:26.605Z] 23:52:26 ERROR - TEST-UNEXPECTED-TIMEOUT | toolkit/content/tests/chrome/test_bug331215.xul | application timed out after 370 seconds with no output
[task 2019-09-18T23:52:26.605Z] 23:52:26 ERROR - Force-terminating active process(es).
[task 2019-09-18T23:52:26.605Z] 23:52:26 INFO - Determining child pids from psutil...
[task 2019-09-18T23:52:26.605Z] 23:52:26 INFO - [2068, 2071]
[task 2019-09-18T23:52:26.606Z] 23:52:26 INFO - ==> process 2067 launched child process 2068
[task 2019-09-18T23:52:26.606Z] 23:52:26 INFO - ==> process 2067 launched child process 2069
[task 2019-09-18T23:52:26.611Z] 23:52:26 INFO - ==> process 2067 launched child process 2070
[task 2019-09-18T23:52:26.611Z] 23:52:26 INFO - ==> process 2067 launched child process 2071
[task 2019-09-18T23:52:26.612Z] 23:52:26 INFO - Found child pids: set([2068, 2069, 2070, 2071])
[task 2019-09-18T23:52:26.612Z] 23:52:26 INFO - Failed to get child procs
[task 2019-09-18T23:52:26.612Z] 23:52:26 INFO - Killing process: 2068
[task 2019-09-18T23:52:26.612Z] 23:52:26 INFO - TEST-INFO | started process screencapture
[task 2019-09-18T23:52:26.731Z] 23:52:26 INFO - TEST-INFO | screencapture: exit 0
[task 2019-09-18T23:52:26.731Z] 23:52:26 INFO - Killing process: 2069
[task 2019-09-18T23:52:26.731Z] 23:52:26 INFO - Not taking screenshot here: see the one that was previously logged
[task 2019-09-18T23:52:26.731Z] 23:52:26 INFO - Can't trigger Breakpad, process no longer exists
[task 2019-09-18T23:52:26.731Z] 23:52:26 INFO - Killing process: 2070
[task 2019-09-18T23:52:26.731Z] 23:52:26 INFO - Not taking screenshot here: see the one that was previously logged
[task 2019-09-18T23:52:26.731Z] 23:52:26 INFO - Can't trigger Breakpad, process no longer exists
[task 2019-09-18T23:52:26.731Z] 23:52:26 INFO - Killing process: 2071
[task 2019-09-18T23:52:26.731Z] 23:52:26 INFO - Not taking screenshot here: see the one that was previously logged
[task 2019-09-18T23:52:26.733Z] 23:52:26 INFO - Killing process: 2067
[task 2019-09-18T23:52:26.733Z] 23:52:26 INFO - Not taking screenshot here: see the one that was previously logged
[task 2019-09-18T23:52:27.108Z] 23:52:27 INFO - psutil found pid 2067 dead
[task 2019-09-18T23:52:27.173Z] 23:52:27 WARNING - runtests.py | Failed to get app exit code - running/crashed?
[task 2019-09-18T23:52:27.173Z] 23:52:27 INFO - TEST-INFO | Main app process: exit 0
[task 2019-09-18T23:52:27.173Z] 23:52:27 INFO - runtests.py | Application ran for: 0:07:07.980306
[task 2019-09-18T23:52:27.174Z] 23:52:27 INFO - zombiecheck | Reading PID log: /var/folders/4z/gmjb5mfn7m15rdy406rr641h000017/T/tmp8s2BJgpidlog
[task 2019-09-18T23:52:27.174Z] 23:52:27 INFO - ==> process 2067 launched child process 2068
[task 2019-09-18T23:52:27.174Z] 23:52:27 INFO - ==> process 2067 launched child process 2069
[task 2019-09-18T23:52:27.175Z] 23:52:27 INFO - ==> process 2067 launched child process 2070
[task 2019-09-18T23:52:27.175Z] 23:52:27 INFO - ==> process 2067 launched child process 2071
[task 2019-09-18T23:52:27.175Z] 23:52:27 INFO - zombiecheck | Checking for orphan process with PID: 2068
[task 2019-09-18T23:52:27.175Z] 23:52:27 INFO - zombiecheck | Checking for orphan process with PID: 2069
[task 2019-09-18T23:52:27.175Z] 23:52:27 INFO - zombiecheck | Checking for orphan process with PID: 2070
[task 2019-09-18T23:52:27.175Z] 23:52:27 INFO - zombiecheck | Checking for orphan process with PID: 2071
[task 2019-09-18T23:52:27.175Z] 23:52:27 INFO - mozcrash Copy/paste: /Users/cltbld/tasks/task_1568849388/build/macosx64-minidump_stackwalk /var/folders/4z/gmjb5mfn7m15rdy406rr641h000017/T/tmp7n4CGX.mozrunner/minidumps/26570C0C-38D2-4712-AA4B-02E707302944.dmp /Users/cltbld/tasks/task_1568849388/build/symbols
[task 2019-09-18T23:52:27.180Z] 23:52:27 INFO - mozcrash Saved minidump as /Users/cltbld/tasks/task_1568849388/build/blobber_upload_dir/26570C0C-38D2-4712-AA4B-02E707302944.dmp
[task 2019-09-18T23:52:27.181Z] 23:52:27 INFO - PROCESS-CRASH | Main app process exited normally | application crashed [None]
Comment 1•5 years ago
|
||
Masayuki, could you please take a look over this? Started to fail with this push: https://treeherder.mozilla.org/#/jobs?repo=autoland&group_state=expanded&resultStatus=success%2Cpending%2Crunning%2Ctestfailed%2Cbusted%2Cexception&searchStr=os%2Cx%2C10.14%2Cdebug%2Cmochitests%2Cwithout%2Ce10s%2Ctest-macosx1014-64%2Fdebug-mochitest-chrome-1proc-2%2Cm-1proc%28c2%29&revision=bcaada0fa740bf6d07b95df1e1da820e12f990a9&selectedJob=267363018
Comment 2•5 years ago
|
||
Sure, but it seems that the test itself may be unstable. It's also disabled if webrender is enabled or debug build on Windows...
Comment 3•5 years ago
•
|
||
It starts from part 10 of bug 1540029. It stops allocating TextEditRules
and HTMLEditRules
. Some methods check whether they were allocated, but the patch makes them check whether the initialization which they did instead. If we hit the difference (whether initialization succeeded or not) is, it should be in the log as warning message. However, it's not recorded so that I'm thinking that the patch changes timing of something since the test looks like really complicated async test. I'll try to investigate which await
causes the timeout.
Comment 4•5 years ago
|
||
https://treeherder.mozilla.org/#/jobs?repo=try&revision=7062585c0840ac10cba880ce6d0a924f6ffe40f3
Log is here:
[task 2019-09-20T06:34:45.800Z] 06:34:45 INFO - TEST-PASS | toolkit/content/tests/chrome/test_bug331215.xul | startTestWithBrowser(content)...
[task 2019-09-20T06:34:45.800Z] 06:34:45 INFO - Starting test with browser 'content'
[task 2019-09-20T06:34:45.800Z] 06:34:45 INFO - TEST-PASS | toolkit/content/tests/chrome/test_bug331215.xul | BrowserTestUtils.browserLoaded(gBrowser)...
[task 2019-09-20T06:34:45.801Z] 06:34:45 INFO - TEST-PASS | toolkit/content/tests/chrome/test_bug331215.xul | Got BrowserTestUtils.browserLoaded(gBrowser)
[task 2019-09-20T06:34:45.801Z] 06:34:45 INFO - TEST-PASS | toolkit/content/tests/chrome/test_bug331215.xul | onDocumentLoaded...
[task 2019-09-20T06:34:45.801Z] 06:34:45 INFO - TEST-PASS | toolkit/content/tests/chrome/test_bug331215.xul | promiseEnterStringIntoFindField("test")...
[task 2019-09-20T06:34:45.801Z] 06:34:45 INFO - TEST-PASS | toolkit/content/tests/chrome/test_bug331215.xul | Got promiseEnterStringIntoFindField("test")
[task 2019-09-20T06:34:45.801Z] 06:34:45 INFO - TEST-PASS | toolkit/content/tests/chrome/test_bug331215.xul | promiseEnterStringIntoFindField("l")...
[task 2019-09-20T06:34:45.801Z] 06:34:45 INFO - TEST-PASS | toolkit/content/tests/chrome/test_bug331215.xul | Got promiseEnterStringIntoFindField("l")
[task 2019-09-20T06:34:45.801Z] 06:34:45 INFO - TEST-PASS | toolkit/content/tests/chrome/test_bug331215.xul | Findfield status attribute should have been 'notfound' after entering test
[task 2019-09-20T06:34:45.801Z] 06:34:45 INFO - TEST-PASS | toolkit/content/tests/chrome/test_bug331215.xul | promiseEnterStringIntoFindField("a")...
[task 2019-09-20T06:34:45.802Z] 06:34:45 INFO - TEST-PASS | toolkit/content/tests/chrome/test_bug331215.xul | Got promiseEnterStringIntoFindField("a")
[task 2019-09-20T06:34:45.802Z] 06:34:45 INFO - TEST-PASS | toolkit/content/tests/chrome/test_bug331215.xul | Findfield status attribute should not have been 'notfound' after entering latest
[task 2019-09-20T06:34:45.802Z] 06:34:45 INFO - TEST-PASS | toolkit/content/tests/chrome/test_bug331215.xul | Got onDocumentLoaded
[task 2019-09-20T06:34:45.802Z] 06:34:45 INFO - TEST-PASS | toolkit/content/tests/chrome/test_bug331215.xul | Got startTestWithBrowser(content)
[task 2019-09-20T06:34:45.802Z] 06:34:45 INFO - TEST-PASS | toolkit/content/tests/chrome/test_bug331215.xul | startTestWithBrowser(content-remote)...
[task 2019-09-20T06:34:45.802Z] 06:34:45 INFO - Starting test with browser 'content-remote'
[task 2019-09-20T06:34:45.803Z] 06:34:45 INFO - TEST-PASS | toolkit/content/tests/chrome/test_bug331215.xul | BrowserTestUtils.browserLoaded(gBrowser)...
[task 2019-09-20T06:34:45.803Z] 06:34:45 INFO - TEST-PASS | toolkit/content/tests/chrome/test_bug331215.xul | Got BrowserTestUtils.browserLoaded(gBrowser)
[task 2019-09-20T06:34:45.803Z] 06:34:45 INFO - TEST-PASS | toolkit/content/tests/chrome/test_bug331215.xul | onDocumentLoaded...
[task 2019-09-20T06:34:45.803Z] 06:34:45 INFO - TEST-PASS | toolkit/content/tests/chrome/test_bug331215.xul | promiseEnterStringIntoFindField("test")...
[task 2019-09-20T06:34:45.803Z] 06:34:45 INFO - Buffered messages finished
[task 2019-09-20T06:34:45.803Z] 06:34:45 ERROR - TEST-UNEXPECTED-TIMEOUT | toolkit/content/tests/chrome/test_bug331215.xul | application timed out after 370 seconds with no output
[task 2019-09-20T06:34:45.803Z] 06:34:45 ERROR - Force-terminating active process(es).
So, when startTestWithBrowser()
is called with "content-remote"
, promiseEnterStringIntoFindField("test")
may not receive expected onFindResult
from the findbar.
mikedeboer: You struggled with similar timeout of this test in bug 1261233, do you have some ideas?
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment 8•5 years ago
|
||
There are 24 total failures in the last 7 days: https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?startday=2019-10-06&endday=2019-10-13&tree=trunk&bug=1582327.
Recent failure log: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=271051097&repo=autoland&lineNumber=21510
Mike, could you assign this to someone?
Comment hidden (Intermittent Failures Robot) |
Updated•5 years ago
|
Comment 10•5 years ago
|
||
Comment 11•5 years ago
|
||
Updated•5 years ago
|
Comment hidden (Intermittent Failures Robot) |
Comment 13•5 years ago
|
||
bugherder |
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) |
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•4 years 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 hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Updated•3 years ago
|
Updated•2 years ago
|
Comment 51•2 years ago
|
||
Clear a needinfo that is pending on an inactive user.
Inactive users most likely will not respond; if the missing information is essential and cannot be collected another way, the bug maybe should be closed as INCOMPLETE
.
For more information, please visit BugBot documentation.
Comment 52•2 years ago
|
||
It seems that this is not reproducible in this 2 years. So, I guess that we can enable this test on macOS and close this bug.
Comment 53•2 years ago
|
||
Looks like it would still fail on mac debug - try push.
Comment 54•4 months ago
|
||
https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit BugBot documentation.
Updated•4 months ago
|
Description
•