1405357 - Intermittent TEST-UNEXPECTED-TIMEOUT | automation.py | application timed out after 330 seconds with no output

Status: RESOLVED DUPLICATE of bug 1397201

(Testing :: General, defect, P5)

Description

[Treeherder Bug Filer]

Filed by: rvandermeulen [at] mozilla.com

https://treeherder.mozilla.org/logviewer.html#?job_id=134649897&repo=mozilla-beta

https://queue.taskcluster.net/v1/task/OPeYts1aQG6ZFIIjcI7K2w/runs/0/artifacts/public/logs/live_backing.log

Startup hang :(

Comment 1

[Intermittent Failures Robot]

1 failures in 824 pushes (0.001 failures/push) were associated with this bug in the last 7 days.    

Repository breakdown:
* mozilla-beta: 1

Platform breakdown:
* linux32: 1

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1405357&startday=2017-10-02&endday=2017-10-08&tree=all

Comment 2

[Intermittent Failures Robot]

15 failures in 947 pushes (0.016 failures/push) were associated with this bug in the last 7 days.    

Repository breakdown:
* try: 11
* mozilla-inbound: 2
* autoland: 2

Platform breakdown:
* windows10-64: 15

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1405357&startday=2017-10-09&endday=2017-10-15&tree=all

Comment 3

[Intermittent Failures Robot]

21 failures in 864 pushes (0.024 failures/push) were associated with this bug in the last 7 days.    

Repository breakdown:
* autoland: 7
* mozilla-inbound: 5
* mozilla-central: 5
* try: 4

Platform breakdown:
* windows10-64: 12
* windows10-64-stylo-disabled: 9

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1405357&startday=2017-10-16&endday=2017-10-22&tree=all

Comment 4

[Henrietta Maior [:henrietta_maior]]

There have been 31 failures in the last 7 days, all of them on Windows 10 and it occurs only on opt & debug.

Here is an example of a recent log:
https://treeherder.mozilla.org/logviewer.html#?repo=mozilla-inbound&job_id=139876484&lineNumber=1760

And a snippet of the log where the timeout occurs:
14:35:51     INFO -  Running manifest: js\xpconnect\tests\chrome\chrome.ini
1747
14:35:51     INFO -  Z:\task_1509028429\build\tests\bin\pk12util.exe: PKCS12 IMPORT SUCCESSFUL
1748
14:35:51     INFO -  MochitestServer : launching [u'Z:\\task_1509028429\\build\\tests\\bin\\xpcshell.exe', '-g', 'Z:\\task_1509028429\\build\\application\\firefox', '-v', '170', '-f', 'Z:\\task_1509028429\\build\\tests\\bin\\components\\httpd.js', '-e', "const _PROFILE_PATH = 'c:\\\\users\\\\genericworker\\\\appdata\\\\local\\\\temp\\\\tmpj6mmw0.mozrunner'; const _SERVER_PORT = '8888'; const _SERVER_ADDR = '127.0.0.1'; const _TEST_PREFIX = undefined; const _DISPLAY_RESULTS = false;", '-f', 'Z:\\task_1509028429\\build\\tests\\mochitest\\server.js']
1749
14:35:51     INFO -  runtests.py | Server pid: 3300
1750
14:35:51     INFO -  runtests.py | Websocket server pid: 8868
1751
14:35:51     INFO -  runtests.py | SSL tunnel pid: 4492
1752
14:35:51     INFO -  runtests.py | Running with e10s: False
1753
14:35:51     INFO -  runtests.py | Running tests: start.
1754
14:35:51     INFO -  Application command: Z:\task_1509028429\build\application\firefox\firefox.exe -marionette -foreground -profile c:\users\genericworker\appdata\local\temp\tmpj6mmw0.mozrunner
1755
14:35:51     INFO -  runtests.py | Application pid: 5192
1756
14:35:51     INFO -  TEST-INFO | started process GECKO(5192)
1757
14:35:52     INFO -  GECKO(5192) | 1509028552412	Marionette	INFO	Enabled via --marionette
1758
14:35:53     INFO -  GECKO(5192) | 1509028553619	Marionette	INFO	Listening on port 2828
1759
14:41:23     INFO -  Buffered messages finished
1760
14:41:23  WARNING -  TEST-UNEXPECTED-TIMEOUT | automation.py | application timed out after 330 seconds with no output
1761
14:41:23     INFO -  0 ERROR Force-terminating active process(es).
1762
14:41:23     INFO -  Determining child pids from psutil
1763
14:41:23     INFO -  Found child pids: []
1764
14:41:23     INFO -  Killing process: 5192
1765
14:41:23     INFO -  TEST-INFO | started process screenshot
1766
14:41:23     INFO -  TEST-INFO | screenshot: exit 0
1767
14:41:23     INFO -  mozcrash Using Z:\task_1509028429\build\tests\bin\minidumpwriter.exe to write a dump to c:\users\genericworker\appdata\local\temp\tmpj6mmw0.mozrunner\minidumps\74df2a33-e9ad-41f6-8dfe-b208ddabb99f.dmp for [5192]
1768
14:47:51     INFO -  TEST-INFO | Main app process: exit 1
1769
14:47:51     INFO -  Buffered messages finished
1770
14:47:51    ERROR -  1 ERROR TEST-UNEXPECTED-FAIL | automation.py | application terminated with exit code 1


:jonco, could you please take a look?

Comment 5

[Intermittent Failures Robot]

49 failures in 196 pushes (0.25 failures/push) were associated with this bug yesterday.    

Repository breakdown:
* autoland: 47
* try: 1
* mozilla-inbound: 1

Platform breakdown:
* windows10-64: 35
* windows10-64-stylo-disabled: 14

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1405357&startday=2017-10-26&endday=2017-10-26&tree=all

Comment 6

[Jon Coppeard (:jonco)]

I looked at all the failure reports and only the first one is at GetGCThingMarkWordAndMask.  Most of the timeouts happen at NtWaitForMultipleObjects with some at AslHashFree and a few others.  Therefore I'm moving this out of the GC component and removing that signature from the title.  I don't know what's causing this but it seems to have spiked in the last day or two.

Comment 7

[Geoff Brown [:gbrown]]

Should we dup this to bug 1397201?

Comment 8

[Intermittent Failures Robot]

24 failures in 151 pushes (0.159 failures/push) were associated with this bug yesterday.    

Repository breakdown:
* mozilla-inbound: 10
* mozilla-central: 8
* autoland: 4
* try: 2

Platform breakdown:
* windows10-64: 14
* windows10-64-stylo-disabled: 9
* linux32-stylo-disabled: 1

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1405357&startday=2017-10-27&endday=2017-10-27&tree=all

Comment 9

[Intermittent Failures Robot]

101 failures in 912 pushes (0.111 failures/push) were associated with this bug in the last 7 days. 

This is the #9 most frequent failure this week. 

** This failure happened more than 75 times this week! Resolving this bug is a very high priority. **

** Try to resolve this bug as soon as possible. If unresolved for 1 week, the affected test(s) may be disabled. **   

Repository breakdown:
* autoland: 65
* mozilla-inbound: 17
* mozilla-central: 15
* try: 4

Platform breakdown:
* windows10-64: 70
* windows10-64-stylo-disabled: 29
* linux32-stylo-disabled: 1
* linux32: 1

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1405357&startday=2017-10-23&endday=2017-10-29&tree=all

Comment 10

[Henrik Skupin [:whimboo][⌚️UTC+2]]

(In reply to Geoff Brown [:gbrown] from comment #7)
> Should we dup this to bug 1397201?

Yes, looks like the right type of action to do here.

Comment 11

[Intermittent Failures Robot]

3 failures in 857 pushes (0.004 failures/push) were associated with this bug in the last 7 days.    

Repository breakdown:
* autoland: 2
* mozilla-central: 1

Platform breakdown:
* windows10-64: 3

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1405357&startday=2017-10-30&endday=2017-11-05&tree=all

Comment 12

[Intermittent Failures Robot]

1 failures in 462 pushes (0.002 failures/push) were associated with this bug in the last 7 days.    

Repository breakdown:
* mozilla-release: 1

Platform breakdown:
* linux32-stylo-disabled: 1

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1405357&startday=2018-01-01&endday=2018-01-07&tree=all