1615449 - Intermittent TEST-UNEXPECTED-TIMEOUT | toolkit/mozapps/extensions/test/xpinstall/browser_doorhanger_installs.js | application timed out after 370 seconds with no output

Status: NEW

(Toolkit :: Add-ons Manager, defect, P2)

Description

[Treeherder Bug Filer]

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

---

task 2020-02-13T21:21:06.830Z] 21:21:06 INFO - TEST-PASS | toolkit/mozapps/extensions/test/xpinstall/browser_doorhanger_installs.js | Should have seen the progress notification -
[task 2020-02-13T21:21:06.830Z] 21:21:06 INFO - Buffered messages finished
[task 2020-02-13T21:21:06.830Z] 21:21:06 ERROR - TEST-UNEXPECTED-TIMEOUT | toolkit/mozapps/extensions/test/xpinstall/browser_doorhanger_installs.js | application timed out after 370 seconds with no output
[task 2020-02-13T21:21:06.830Z] 21:21:06 ERROR - Force-terminating active process(es).
[task 2020-02-13T21:21:06.831Z] 21:21:06 INFO - Determining child pids from psutil...
[task 2020-02-13T21:21:06.831Z] 21:21:06 INFO - [716]
[task 2020-02-13T21:21:06.831Z] 21:21:06 INFO - ==> process 716 launched child process 5520 ("Z:\task_1581627030\build\application\firefox\firefox.exe" -contentproc --channel="716.0.176927398\882473448" -parentBuildID 20200213183716 -prefsHandle 2284 -prefMapHandle 2276 -prefsLen 1 -prefMapSize 227708 -greomni "Z:\task_1581627030\build\application\firefox\omni.ja" -appomni "Z:\task_1581627030\build\application\firefox\browser\omni.ja" -appdir "Z:\task_1581627030\build\application\firefox\browser" - 716 "\.\pipe\gecko-crash-server-pipe.716" 2336 gpu)
[task 2020-02-13T21:21:06.831Z] 21:21:06 INFO - ==> process 716 launched child process 6364 ("Z:\task_1581627030\build\application\firefox\firefox.exe" -contentproc --channel="716.6.1480287346\714531778" -childID 1 -isForBrowser -prefsHandle 2916 -prefMapHandle 2912 -prefsLen 1391 -prefMapSize 227708 -parentBuildID 20200213183716 -greomni "Z:\task_1581627030\build\application\firefox\omni.ja" -appomni "Z:\task_1581627030\build\application\firefox\browser\omni.ja" -appdir "Z:\task_1581627030\build\application\firefox\browser" - 716 "\.\pipe\gecko-crash-server-pipe.716" 2224 tab)
[task 2020-02-13T21:21:06.831Z] 21:21:06 INFO - ==> process 716 launched child process 4288 ("Z:\task_1581627030\build\application\firefox\firefox.exe" -contentproc --channel="716.13.899960570\1055194389" -childID 2 -isForBrowser -prefsHandle 3136 -prefMapHandle 3128 -prefsLen 1857 -prefMapSize 227708 -parentBuildID 20200213183716 -greomni "Z:\task_1581627030\build\application\firefox\omni.ja" -appomni "Z:\task_1581627030\build\application\firefox\browser\omni.ja" -appdir "Z:\task_1581627030\build\application\firefox\browser" - 716 "\.\pipe\gecko-crash-server-pipe.716" 3156 tab)
[task 2020-02-13T21:21:06.831Z] 21:21:06 INFO - ==> process 716 launched child process 9608 ("Z:\task_1581627030\build\application\firefox\firefox.exe" -contentproc --channel="716.20.823239547\1607177642" -childID 3 -isForBrowser -prefsHandle 3376 -prefMapHandle 3364 -prefsLen 1918 -prefMapSize 227708 -parentBuildID 20200213183716 -greomni "Z:\task_1581627030\build\application\firefox\omni.ja" -appomni "Z:\task_1581627030\build\application\firefox\browser\omni.ja" -appdir "Z:\task_1581627030\build\application\firefox\browser" - 716 "\.\pipe\gecko-crash-server-pipe.716" 3396 tab)
[task 2020-02-13T21:21:06.831Z] 21:21:06 INFO - ==> process 716 launched child process 8520 ("Z:\task_1581627030\build\application\firefox\firefox.exe" -contentproc --channel="716.27.1194950409\554775864" -childID 4 -isForBrowser -prefsHandle 4504 -prefMapHandle 4500 -prefsLen 11739 -prefMapSize 227708 -parentBuildID 20200213183716 -greomni "Z:\task_1581627030\build\application\firefox\omni.ja" -appomni "Z:\task_1581627030\build\application\firefox\browser\omni.ja" -appdir "Z:\task_1581627030\build\application\firefox\browser" - 716 "\.\pipe\gecko-crash-server-pipe.716" 3732 tab)
[task 2020-02-13T21:21:06.831Z] 21:21:06 INFO - ==> process 716 launched child process 4936 ("Z:\task_1581627030\build\application\firefox\firefox.exe" -contentproc --channel="716.34.810976452\1912921664" -childID 5 -isForBrowser -prefsHandle 4900 -prefMapHandle 4896 -prefsLen 11762 -prefMapSize 227708 -parentBuildID 20200213183716 -greomni "Z:\task_1581627030\build\application\firefox\omni.ja" -appomni "Z:\task_1581627030\build\application\firefox\browser\omni.ja" -appdir "Z:\task_1581627030\build\application\firefox\browser" - 716 "\.\pipe\gecko-crash-server-pipe.716" 4920 tab)
[task 2020-02-13T21:21:06.832Z] 21:21:06 INFO - ==> process 716 launched child process 7116 ("Z:\task_1581627030\build\application\firefox\firefox.exe" -contentproc --channel="716.41.775638556\895456110" -childID 6 -isForBrowser -prefsHandle 4928 -prefMapHandle 4500 -prefsLen 11812 -prefMapSize 227708 -parentBuildID 20200213183716 -greomni "Z:\task_1581627030\build\application\firefox\omni.ja" -appomni "Z:\task_1581627030\build\application\firefox\browser\omni.ja" -appdir "Z:\task_1581627030\build\application\firefox\browser" - 716 "\.\pipe\gecko-crash-server-pipe.716" 5112 tab)
[task 2020-02-13T21:21:06.832Z] 21:21:06 INFO - ==> process 716 launched child process 6812 ("Z:\task_1581627030\build\application\firefox\firefox.exe" -contentproc --channel="716.48.266853285\1922913297" -childID 7 -isForBrowser -prefsHandle 5408 -prefMapHandle 5404 -prefsLen 11812 -prefMapSize 227708 -parentBuildID 20200213183716 -greomni "Z:\task_1581627030\build\application\firefox\omni.ja" -appomni "Z:\task_1581627030\build\application\firefox\browser\omni.ja" -appdir "Z:\task_1581627030\build\application\firefox\browser" - 716 "\.\pipe\gecko-crash-server-pipe.716" 5368 tab)
[task 2020-02-13T21:21:06.832Z] 21:21:06 INFO - ==> process 716 launched child process 356 ("Z:\task_1581627030\build\application\firefox\firefox.exe" -contentproc --channel="716.55.632996653\1892032754" -childID 8 -isForBrowser -prefsHandle 4772 -prefMapHandle 5196 -prefsLen 11812 -prefMapSize 227708 -parentBuildID 20200213183716 -greomni "Z:\task_1581627030\build\application\firefox\omni.ja" -appomni "Z:\task_1581627030\build\application\firefox\browser\omni.ja" -appdir "Z:\task_1581627030\build\application\firefox\browser" - 716 "\.\pipe\gecko-crash-server-pipe.716" 5588 tab)
[task 2020-02-13T21:21:06.832Z] 21:21:06 INFO - ==> process 716 launched child process 3372 ("Z:\task_1581627030\build\application\firefox\firefox.exe" -contentproc --channel="716.62.100271287\1930528877" -childID 9 -isForBrowser -prefsHandle 4888 -prefMapHandle 5180 -prefsLen 11762 -prefMapSize 227708 -parentBuildID 20200213183716 -greomni "Z:\task_1581627030\build\application\firefox\omni.ja" -appomni "Z:\task_1581627030\build\application\firefox\browser\omni.ja" -appdir "Z:\task_1581627030\build\application\firefox\browser" - 716 "\.\pipe\gecko-crash-server-pipe.716" 5268 tab)
[task 2020-02-13T21:21:06.832Z] 21:21:06 INFO - Found child pids: set([4288, 6812, 356, 9608, 7116, 716, 5520, 8520, 4936, 3372, 6364])
[task 2020-02-13T21:21:06.832Z] 21:21:06 INFO - Killing process: 4288

Comment 1

[Intermittent Failures Robot]

16 failures in 739 pushes (0.022 failures/push) were associated with this bug yesterday.

Repository breakdown:

• autoland: 12
• try: 4

Platform breakdown:

• windows10-64-shippable: 5
• windows10-64: 1
• windows10-64-shippable-qr: 6
• windows10-64-devedition: 2
• windows10-64-qr: 2

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

Comment 2

[Intermittent Failures Robot]

15 failures in 220 pushes (0.068 failures/push) were associated with this bug yesterday.

Repository breakdown:

• autoland: 11
• mozilla-central: 3
• try: 1

Platform breakdown:

• windows10-64-shippable-qr: 6
• windows10-64: 5
• windows10-64-shippable: 3
• windows10-64-qr: 1

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

Comment 3

[Oana Pop-Rus]

I did some retriggers and the failures seems to start since Bug 1604412 was landed.

Treeherder link: https://treeherder.mozilla.org/#/jobs?repo=autoland&searchStr=windows%2C10%2Cx64%2Cshippable%2Copt%2Cmochitests%2Ctest-windows10-64-shippable%2Fopt-mochitest-browser-chrome-e10s-2%2Cm%28bc2%29&tochange=dea3ec096b735035303e3830ef8bbfe19b8c675f&fromchange=b61bb41f31d147a3fd1ba875bbf73abb56286e67&selectedJob=289130128

There are 28 failures since this bug was created, all on windows platforms: https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?startday=2020-01-17&endday=2020-02-16&tree=trunk&bug=1615449

Chris, could you please take a look?

Thank you.

Comment 4

[Intermittent Failures Robot]

46 failures in 4690 pushes (0.01 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 30 times this week! Resolving this bug is a high priority. **

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

Repository breakdown:

• autoland: 34
• try: 6
• mozilla-central: 6

Platform breakdown:

• windows10-64-shippable: 10
• windows10-64: 7
• windows10-64-shippable-qr: 22
• windows10-64-devedition: 3
• windows10-64-qr: 3
• windows10-64-ccov: 1

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

Comment 5

[Andreea Pavel [:apavel]]

Chris there are 74 total failures in the last 4 days. This will soon reach disable-recommended queue, please take a look.

Comment 6

[Intermittent Failures Robot]

32 failures in 441 pushes (0.073 failures/push) were associated with this bug yesterday.

Repository breakdown:

• autoland: 9
• try: 14
• mozilla-central: 9

Platform breakdown:

• windows10-64-shippable-qr: 8
• windows10-64: 9
• linux64: 2
• macosx1014-64: 2
• windows10-64-qr: 3
• linux1804-64: 2
• windows10-64-devedition: 2
• windows10-64-shippable: 3
• windows10-64-ccov: 1

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

Comment 7

[Chris Martin [:cmartin]]

:apavel Since this patch is also currently responsible for bug 1616000, if I can't solve that quickly I may have to back this patch out and fix it offline.

I will advise in the next few hours if I think I can solve it quickly. If not, it will likely be backed out and the intermittent failures will go away.

Comment 8

[Chris Martin [:cmartin]]

Hi Andreea,

I believe I will be able to fix bug 1616000 tomorrow, and there's a reasonable chance that fixing that bug will also fix these intermittent test failures.

Is it okay to wait a big longer before disabling this test or backing anything out?

Comment 9

[Oana Pop-Rus]

Hi Chris, thanks for updates.
We can wait until tomorrow and hopefully the fix will work for this bug too.

Comment 10

[Chris Martin [:cmartin]]

Hi there,

I was able to fix bug 1616000, but it looks like the fix will not stop these intermittent test failures from happening.

Furthermore, the test failures are not happening on my own machine, so I will have to spend some time to figure out why these intermittent failures are happening.

Comment 11

[Intermittent Failures Robot]

27 failures in 767 pushes (0.035 failures/push) were associated with this bug yesterday.

Repository breakdown:

• mozilla-central: 7
• autoland: 18
• try: 2

Platform breakdown:

• windows10-64-qr: 5
• windows10-64: 8
• windows10-64-shippable: 9
• windows10-64-shippable-qr: 5

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

Comment 12

[Andreea Pavel [:apavel]]

Chris, do you know how long that will take? Should we disable the test until you have the fix?

Comment 13

[Intermittent Failures Robot]

24 failures in 882 pushes (0.027 failures/push) were associated with this bug yesterday.

Repository breakdown:

• autoland: 12
• mozilla-central: 8
• try: 4

Platform breakdown:

• windows10-64-shippable: 4
• windows10-64: 5
• windows10-64-qr: 3
• windows10-64-shippable-qr: 7
• windows10-64-devedition: 2
• windows10-64-ccov: 3

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

Comment 14

[Chris Martin [:cmartin]]

Hi Andreea,

I think it's fine to disable the test until I have a fix. I don't want everyone to have to deal with it in the meantime, and I suspect that it's not worth backing the change out until we get closer to the branch date.

I will update the ticket when I have the fix and we can re-enable the test.

Thanks and have a good weekend!

Comment 15

[Andreea Pavel [:apavel]]

Attachment: Bug 1615449 - disabled browser_doorhanger_installs.js on win10 64bits r=cmartin

Comment 16

[Andreea Pavel [:apavel]]

Sure, thanks, have a nice weekend too!

Comment 17

[Intermittent Failures Robot]

24 failures in 836 pushes (0.029 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: 13
• try: 1

Platform breakdown:

• windows10-64-qr: 4
• windows10-64-shippable-qr: 7
• windows10-64-shippable: 3
• windows10-64: 10

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

Comment 18

[Intermittent Failures Robot]

23 failures in 196 pushes (0.117 failures/push) were associated with this bug yesterday.

Repository breakdown:

• autoland: 9
• mozilla-central: 4
• try: 10

Platform breakdown:

• windows10-64: 2
• windows10-64-qr: 2
• windows10-64-shippable-qr: 7
• windows10-64-shippable: 5
• windows10-64-devedition: 6
• windows10-64-ccov: 1

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

Comment 19

[Intermittent Failures Robot]

155 failures in 4045 pushes (0.038 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: 70
• try: 35
• mozilla-central: 50

Platform breakdown:

• windows10-64-shippable-qr: 41
• windows10-64: 39
• linux64: 2
• macosx1014-64: 2
• windows10-64-qr: 22
• linux1804-64: 2
• windows10-64-devedition: 12
• windows10-64-shippable: 28
• windows10-64-ccov: 7

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

Comment 20

[Intermittent Failures Robot]

42 failures in 646 pushes (0.065 failures/push) were associated with this bug yesterday.

Repository breakdown:

• autoland: 27
• mozilla-central: 12
• try: 3

Platform breakdown:

• windows10-64-shippable: 21
• windows10-64-qr: 3
• windows10-64: 9
• windows10-64-ccov: 1
• windows10-64-shippable-qr: 7
• windows10-64-devedition: 1

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

Comment 21

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/fa13c4a426e7
disabled browser_doorhanger_installs.js on win10 64bits r=aryx

Comment 22

[Natalia Csoregi [:nataliaCs]]

https://hg.mozilla.org/mozilla-central/rev/fa13c4a426e7

Comment 23

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

The priority flag is not set for this bug.
:mixedpuppy, could you have a look please?

For more information, please visit auto_nag documentation.

Comment 24

[Intermittent Failures Robot]

54 failures in 5233 pushes (0.01 failures/push) were associated with this bug in the last 7 days.

This is the #16 most frequent failure this week.

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

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

Repository breakdown:

• autoland: 30
• mozilla-central: 17
• try: 7

Platform breakdown:

• windows10-64-shippable: 24
• windows10-64-qr: 5
• windows10-64: 12
• windows10-64-ccov: 1
• windows10-64-shippable-qr: 11
• windows10-64-devedition: 1

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

Comment 25

[Intermittent Failures Robot]

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

Repository breakdown:

• autoland: 6

Platform breakdown:

• macosx1014-64-shippable: 5
• macosx1014-64: 1

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

Comment 26

[Intermittent Failures Robot]

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

Repository breakdown:

• autoland: 6

Platform breakdown:

• macosx1014-64: 1
• macosx1014-64-shippable: 5

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

Comment 27

[Intermittent Failures Robot]

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

Repository breakdown:

• autoland: 1

Platform breakdown:

• windows7-32: 1

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

Comment 28

[Dianna Smith [:diannaS]]

Is this still an S2 now that it is disabled?