1642032 - Perma Windows 10 MinGW TEST-UNEXPECTED-TIMEOUT | automation.py | application timed out after 370 seconds with no output

Status: RESOLVED FIXED

(Firefox Build System :: General, defect, P5)

Description

[Treeherder Bug Filer]

Filed by: ccoroiu [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer.html#?job_id=304330247&repo=mozilla-central
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/fta-7imvQa6ZnUaTWNsN7g/runs/0/artifacts/public/logs/live_backing.log

---

task 2020-05-29T22:23:41.957Z] 22:23:41 INFO - runtests.py | Waiting for browser...
[task 2020-05-29T22:26:41.309Z] 22:26:41 INFO - [6484, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80004005 (NS_ERROR_FAILURE): file /builds/worker/checkouts/gecko/toolkit/components/places/Database.cpp, line 544
[task 2020-05-29T22:26:41.310Z] 22:26:41 INFO - [6484, Main Thread] WARNING: Unable to get a connection to vacuum database: file /builds/worker/checkouts/gecko/storage/VacuumManager.cpp, line 128
[task 2020-05-29T22:26:41.389Z] 22:26:41 INFO - [6484, IPDL Background] WARNING: '!gBasePath', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp, line 3625
[task 2020-05-29T22:26:41.389Z] 22:26:41 INFO - [6484, IPDL Background] WARNING: profile-do-change must precede QuotaManager::GetOrCreate(): file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp, line 3626
[task 2020-05-29T22:26:41.389Z] 22:26:41 INFO - [6484, IPDL Background] WARNING: '!quotaManager', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp, line 8592
[task 2020-05-29T22:26:51.612Z] 22:26:51 INFO - Buffered messages finished
[task 2020-05-29T22:26:51.612Z] 22:26:51 ERROR - TEST-UNEXPECTED-TIMEOUT | automation.py | application timed out after 370 seconds with no output
[task 2020-05-29T22:26:51.612Z] 22:26:51 ERROR - Force-terminating active process(es).
[task 2020-05-29T22:26:51.612Z] 22:26:51 INFO - Determining child pids from psutil...
[task 2020-05-29T22:26:51.622Z] 22:26:51 INFO - [10744]
[task 2020-05-29T22:26:51.622Z] 22:26:51 INFO - Found child pids: set([10744])
[task 2020-05-29T22:26:51.622Z] 22:26:51 INFO - Killing process: 10744
[task 2020-05-29T22:26:51.623Z] 22:26:51 INFO - TEST-INFO | started process screenshot
[task 2020-05-29T22:26:51.729Z] 22:26:51 INFO - TEST-INFO | screenshot: exit 0
[task 2020-05-29T22:26:51.729Z] 22:26:51 INFO - mozcrash Writing a dump to c:\users\task_1590789669\appdata\local\temp\tmpuadnsm.mozrunner\minidumps\2c4c79cb-4b23-4cf8-b6c9-f0fd5149097a.dmp for [10744]
[task 2020-05-29T22:26:51.730Z] 22:26:51 WARNING - mozcrash unable to create minidump file for pid 10744: 3
[task 2020-05-29T22:26:51.757Z] 22:26:51 INFO - psutil found pid 10744 dead
[task 2020-05-29T22:26:51.757Z] 22:26:51 INFO - Killing process: 4832
[task 2020-05-29T22:26:51.758Z] 22:26:51 INFO - Not taking screenshot here: see the one that was previously logged
[task 2020-05-29T22:26:51.758Z] 22:26:51 INFO - mozcrash Writing a dump to c:\users\task_1590789669\appdata\local\temp\tmpuadnsm.mozrunner\minidumps\9c9d2b37-9955-47e2-b379-771a9b9ce2f9.dmp for [4832]
[task 2020-05-29T22:26:51.758Z] 22:26:51 WARNING - mozcrash unable to create minidump file for pid 4832: 3
[task 2020-05-29T22:26:51.759Z] 22:26:51 WARNING - mozcrash kill_pid(): unable to terminate pid 4832: 5
[task 2020-05-29T22:26:51.764Z] 22:26:51 INFO - psutil found pid 4832 dead
[task 2020-05-29T22:26:51.783Z] 22:26:51 INFO - TEST-INFO | Main app process: exit 1
[task 2020-05-29T22:26:51.783Z] 22:26:51 INFO - Buffered messages finished
[task 2020-05-29T22:26:51.784Z] 22:26:51 ERROR - TEST-UNEXPECTED-FAIL | automation.py | application terminated with exit code 1
[task 2020-05-29T22:26:51.785Z] 22:26:51 INFO - runtests.py | Application ran for: 0:06:10.182000
[task 2020-05-29T22:26:51.785Z] 22:26:51 INFO - zombiecheck | Reading PID log: c:\users\task_1590789669\appdata\local\temp\tmpgu65t9pidlog
[task 2020-05-29T22:26:51.785Z] 22:26:51 INFO - Traceback (most recent call last):
[task 2020-05-29T22:26:51.786Z] 22:26:51 INFO - File "Z:\task_1590789669\build\tests\mochitest\runtests.py", line 2927, in doTests
[task 2020-05-29T22:26:51.786Z] 22:26:51 INFO - e10s=options.e10s
[task 2020-05-29T22:26:51.786Z] 22:26:51 INFO - File "Z:\task_1590789669\build\tests\mochitest\runtests.py", line 2428, in runApp
[task 2020-05-29T22:26:51.786Z] 22:26:51 INFO - six.reraise(exc, value, tb)
[task 2020-05-29T22:26:51.787Z] 22:26:51 INFO - File "Z:\task_1590789669\build\tests\mochitest\runtests.py", line 2345, in runApp
[task 2020-05-29T22:26:51.787Z] 22:26:51 INFO - self.marionette.start_session()
[task 2020-05-29T22:26:51.787Z] 22:26:51 INFO - File "Z:\task_1590789669\build\venv\lib\site-packages\marionette_driver\decorators.py", line 36, in _
[task 2020-05-29T22:26:51.788Z] 22:26:51 INFO - m._handle_socket_failure()
[task 2020-05-29T22:26:51.789Z] 22:26:51 INFO - File "Z:\task_1590789669\build\venv\lib\site-packages\marionette_driver\marionette.py", line 654, in _handle_socket_failure
[task 2020-05-29T22:26:51.789Z] 22:26:51 INFO - reraise(exc_cls, exc, tb)
[task 2020-05-29T22:26:51.789Z] 22:26:51 INFO - File "Z:\task_1590789669\build\venv\lib\site-packages\marionette_driver\decorators.py", line 26, in _
[task 2020-05-29T22:26:51.789Z] 22:26:51 INFO - return func(*args, **kwargs)
[task 2020-05-29T22:26:51.790Z] 22:26:51 INFO - File "Z:\task_1590789669\build\venv\lib\site-packages\marionette_driver\marionette.py", line 1112, in start_session
[task 2020-05-29T22:26:51.790Z] 22:26:51 INFO - self.raise_for_port(timeout=timeout)
[task 2020-05-29T22:26:51.790Z] 22:26:51 INFO - File "Z:\task_1590789669\build\venv\lib\site-packages\marionette_driver\marionette.py", line 573, in raise_for_port
[task 2020-05-29T22:26:51.790Z] 22:26:51 INFO - self.host, self.port))
[task 2020-05-29T22:26:51.791Z] 22:26:51 INFO - timeout: Timed out waiting for connection on 127.0.0.1:2828!
[task 2020-05-29T22:26:51.791Z] 22:26:51 ERROR - Automation Error: Received unexpected exception while running application

Comment 1

[Cristina Coroiu [:ccoroiu]]

Nathan, might be from Bug 1641640?

Here are the retriggers:
https://treeherder.mozilla.org/#/jobs?repo=autoland&fromchange=c1820d13f7d232c8e3e1a7c8fe7fe76c61da2924&searchStr=windows%2C10%2Cx64%2Cmingw%2Cdebug%2Cmochitests%2Ctest-windows10-64-mingwclang%2Fdebug-mochitest-webgpu-e10s%2Cm%28webgpu%29&selectedTaskRun=GkMAnwMsRQGHn2Ga7rom0Q-0

There are also failing reftests:
https://treeherder.mozilla.org/#/jobs?repo=autoland&searchStr=windows%2C10%2Cx64%2Cmingw%2Cdebug%2Creftests%2Ctest-windows10-64-mingwclang%2Fdebug-reftest-e10s-1%2Cr%28r1%29&tochange=4a2c49e70cc10a55d840016dcf39b8262e40a125&fromchange=5b828de27b663239abbe1e17a273a313b88d826c&selectedTaskRun=JvhLohATTEqKg4I-SbJ_Lg-0

Can you please take a look? Thank you

Comment 2

[Intermittent Failures Robot]

34 failures in 1051 pushes (0.032 failures/push) were associated with this bug yesterday.

Repository breakdown:

• mozilla-central: 28
• autoland: 6

Platform breakdown:

• windows10-64-mingwclang: 34

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1642032&startday=2020-05-29&endday=2020-05-29&tree=all

Comment 3

[Nathan Froyd [:froydnj]]

Sigh, this is so lame. Bug 1641640 apparently changed this so that the zip file no longer sets the executable mode bit on the file, so something winds up complaining. I guess this is a problem that we've had with other files, like the asan dlls we distribute, and we just didn't dig hard enough to figure this out?

I will look into this very early next week; somewhere in the install manifest code we should be copying mode bits and we are dropping them on the floor instead.

Comment 4

[Nathan Froyd [:froydnj]]

Actually, I take that back: the zip entries are exactly the same for the relevant file before and after the patch, modulo where they live in the archive. So we're still packaging the file and we didn't change anything about the file; why is the test falling over?

Comment 5

[Nathan Froyd [:froydnj]]

tjr, do you know if there is something peculiar with how the d3d compiler dll is handled in mingw?

Comment 6

[Intermittent Failures Robot]

36 failures in 264 pushes (0.136 failures/push) were associated with this bug yesterday.

Repository breakdown:

• autoland: 8
• mozilla-central: 28

Platform breakdown:

• windows10-64-mingwclang: 36

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1642032&startday=2020-05-30&endday=2020-05-30&tree=all

Comment 7

[Intermittent Failures Robot]

116 failures in 5458 pushes (0.021 failures/push) were associated with this bug in the last 7 days.

This is the #4 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:

• mozilla-central: 92
• autoland: 24

Platform breakdown:

• windows10-64-mingwclang: 116

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1642032&startday=2020-05-25&endday=2020-05-31&tree=all

Comment 8

[Intermittent Failures Robot]

67 failures in 722 pushes (0.093 failures/push) were associated with this bug yesterday.

** This test has failed more than 150 times in the last 21 days. It should be disabled until it can be fixed. **

Repository breakdown:

• autoland: 20
• mozilla-central: 46
• mozilla-beta: 1

Platform breakdown:

• windows10-64-mingwclang: 65
• windows10-64-shippable: 1
• linux1804-64-tsan: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1642032&startday=2020-06-01&endday=2020-06-01&tree=all

Comment 10

[Intermittent Failures Robot]

75 failures in 1092 pushes (0.069 failures/push) were associated with this bug yesterday.

Repository breakdown:

• autoland: 21
• mozilla-central: 54

Platform breakdown:

• windows10-64-mingwclang: 73
• windows10-64-shippable: 2

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1642032&startday=2020-06-02&endday=2020-06-02&tree=all

Comment 11

[BugBot [:suhaib / :marco/ :calixte]]

Set release status flags based on info from the regressing bug 1641640

Comment 12

[Tom Ritter [:tjr] (OOTO until 4/30 at least)]

The problem is that d3dcompiler_47.dll is now added to dependentlibs.list. It wasn't before. Once removed from that file, the browser starts again.

Comment 13

[Intermittent Failures Robot]

94 failures in 993 pushes (0.095 failures/push) were associated with this bug yesterday.

Repository breakdown:

• autoland: 15
• mozilla-central: 79

Platform breakdown:

• windows10-64-mingwclang: 94

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1642032&startday=2020-06-03&endday=2020-06-03&tree=all

Comment 14

[Intermittent Failures Robot]

78 failures in 950 pushes (0.082 failures/push) were associated with this bug yesterday.

Repository breakdown:

• autoland: 17
• mozilla-central: 61

Platform breakdown:

• windows10-64-mingwclang: 77
• windows10-64-shippable: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1642032&startday=2020-06-04&endday=2020-06-04&tree=all

Comment 15

[Intermittent Failures Robot]

70 failures in 875 pushes (0.08 failures/push) were associated with this bug yesterday.

** This test has failed more than 150 times in the last 21 days. It should be disabled until it can be fixed. **

Repository breakdown:

• autoland: 15
• mozilla-central: 55

Platform breakdown:

• windows10-64-mingwclang: 69
• windows7-32-mingwclang: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1642032&startday=2020-06-05&endday=2020-06-05&tree=all

Comment 16

[Intermittent Failures Robot]

39 failures in 200 pushes (0.195 failures/push) were associated with this bug yesterday.

** This test has failed more than 150 times in the last 21 days. It should be disabled until it can be fixed. **

Repository breakdown:

• autoland: 10
• mozilla-central: 29

Platform breakdown:

• windows10-64-mingwclang: 39

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1642032&startday=2020-06-06&endday=2020-06-06&tree=all

Comment 17

[Nathan Froyd [:froydnj]]

Attachment: Bug 1642032 - part 1 - factor out install targets for final target files; r=#build

We're going to reuse this machinery in a subsequent patch. I think this
change, by virtue of moving all the output to a single place, also makes
things clearer.

Comment 18

[Nathan Froyd [:froydnj]]

Attachment: Bug 1642032 - part 2 - install non-wildcard absolute FINAL_TARGET_FILES during misc; r=#build

Such files are, at least as of this writing, only libraries, and we can
get by with installing them later. This change will also avoid having
them added to the dependent libraries list.

Depends on D78617

Comment 19

[Intermittent Failures Robot]

464 failures in 4949 pushes (0.094 failures/push) were associated with this bug in the last 7 days.

This is the #1 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: 104
• mozilla-central: 359
• mozilla-beta: 1

Platform breakdown:

• windows10-64-mingwclang: 457
• windows10-64-shippable: 4
• linux1804-64-tsan: 1
• windows7-32-mingwclang: 2

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1642032&startday=2020-06-01&endday=2020-06-07&tree=all

Comment 20

[Intermittent Failures Robot]

68 failures in 890 pushes (0.076 failures/push) were associated with this bug yesterday.

Repository breakdown:

• autoland: 17
• mozilla-central: 51

Platform breakdown:

• windows10-64-mingwclang: 65
• windows10-64-shippable: 2
• windows7-32-mingwclang: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1642032&startday=2020-06-08&endday=2020-06-08&tree=all

Comment 21

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/a9239d026627
part 1 - factor out install targets for final target files; r=nalexander
https://hg.mozilla.org/integration/autoland/rev/c1628d8da86f
part 2 - install non-wildcard absolute FINAL_TARGET_FILES during misc; r=nalexander

Comment 22

[Intermittent Failures Robot]

37 failures in 988 pushes (0.037 failures/push) were associated with this bug yesterday.

Repository breakdown:

• autoland: 20
• mozilla-central: 17

Platform breakdown:

• windows10-64-mingwclang: 37

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1642032&startday=2020-06-09&endday=2020-06-09&tree=all

Comment 23

[Narcis Beleuzu [:NarcisB]]

https://hg.mozilla.org/mozilla-central/rev/a9239d026627
https://hg.mozilla.org/mozilla-central/rev/c1628d8da86f

Comment 24

[Narcis Beleuzu [:NarcisB]]

:froydnj , it`s still failing. Can you please take a look?
https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=305806116&repo=mozilla-central&lineNumber=1149

Comment 25

[Nathan Froyd [:froydnj]]

Attachment: Bug 1642032 - ignore d3dcompiler_47.dll in dependentlibs determination; r=#build

We moved the installation of shared libraries, such as
d3dcompiler_47.dll to the misc tier with the idea of making sure
they weren't taken into account during the computation of the
dependentlibs.list. Unfortunately, dependentlibs.list is itself
computed during misc, so we have an unfortunate race condition where
sometimes libraries might wind up in the list and sometimes they won't.

For this particular case, we can follow what we already do for ICU and
ignore the library, especially since we're dynamically loading the
library anyway.

Comment 26

[Nathan Froyd [:froydnj]]

(In reply to Narcis Beleuzu [:NarcisB] from comment #24)

:froydnj , it`s still failing. Can you please take a look?
https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=305806116&repo=mozilla-central&lineNumber=1149

Sorry, apparently my try push won some races during the build, but our normal builds lost the race. I've posted a new patch.

Comment 27

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/7bc89fd27221
ignore d3dcompiler_47.dll in dependentlibs determination; r=firefox-build-system-reviewers,rstewart

Comment 28

[Bogdan Tara[:bogdan_tara | bogdant]]

https://hg.mozilla.org/mozilla-central/rev/7bc89fd27221

Comment 29

[Intermittent Failures Robot]

74 failures in 1067 pushes (0.069 failures/push) were associated with this bug yesterday.

Repository breakdown:

• autoland: 16
• mozilla-central: 58

Platform breakdown:

• windows10-64-mingwclang: 73
• windows7-32-mingwclang: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1642032&startday=2020-06-10&endday=2020-06-10&tree=all

Comment 30

[Intermittent Failures Robot]

179 failures in 5211 pushes (0.034 failures/push) were associated with this bug in the last 7 days.

This is the #3 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: 53
• mozilla-central: 126

Platform breakdown:

• windows10-64-mingwclang: 175
• windows10-64-shippable: 2
• windows7-32-mingwclang: 2

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1642032&startday=2020-06-08&endday=2020-06-14&tree=all

Comment 31

[Alexandru Ionescu (needinfo me) [:alexandrui]]

== Change summary for alert #26222 (as of Mon, 15 Jun 2020 10:43:24 GMT) ==

Improvements:

3% tp5n main_startup_fileio windows7-32-shippable opt e10s stylo 115,299,781.67 -> 111,603,684.58
3% tp5n main_startup_fileio windows7-32-shippable opt e10s stylo 115,011,309.83 -> 111,537,300.67

For up to date results, see: https://treeherder.mozilla.org/perf.html#/alerts?id=26222

Comment 32

[Ryan VanderMeulen [:RyanVM]]

Do we need to uplift this to Beta for 78 given that it's the next ESR release?

Comment 33

[Nathan Froyd [:froydnj]]

Comment on attachment 9154802 [details]
Bug 1642032 - part 1 - factor out install targets for final target files; r=#build

ESR Uplift Approval Request

• If this is not a sec:{high,crit} bug, please state case for ESR consideration: Fixes some perma-failures on mingw, which seems good for Tor, and also claws back some startup regressions.
• User impact if declined: Slower startup.
• Fix Landed on Version: 79
• Risk to taking this patch: Low
• Why is the change risky/not risky? (and alternatives if risky): These patches are not risky; they tweak only how files are installed and do not generally affect functionality of the browser. We clearly have tests that exercise the functionality of the files installed. =D
• String or UUID changes made by this patch: None

Comment 34

[Ryan VanderMeulen [:RyanVM]]

Comment on attachment 9154802 [details]
Bug 1642032 - part 1 - factor out install targets for final target files; r=#build

Fixes mingw permafails that will affect ESR78. Approved for 78.0b9.

Comment 35

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/releases/mozilla-beta/rev/75f2a5a36aa0
https://hg.mozilla.org/releases/mozilla-beta/rev/d09f4a0ed41c
https://hg.mozilla.org/releases/mozilla-beta/rev/2613fe614a7c

Comment 36

[Intermittent Failures Robot]

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

Repository breakdown:

• mozilla-central: 1

Platform breakdown:

• windows7-32-mingwclang: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1642032&startday=2020-06-15&endday=2020-06-21&tree=all