1441580 - Intermittent windows10 reftest,jsreftest,crashtest REFTEST ERROR | None | application timed out after 370 seconds with no output | pid: None | application crashed [@ CrashingThread(void *)]

Status: RESOLVED WORKSFORME

(Testing :: Reftest, defect, P5)

Description

[Treeherder Bug Filer]

Filed by: aiakab [at] mozilla.com

https://treeherder.mozilla.org/logviewer.html#?job_id=164587615&repo=autoland

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

https://hg.mozilla.org/mozilla-central/raw-file/tip/layout/tools/reftest/reftest-analyzer.xhtml#logurl=https://queue.taskcluster.net/v1/task/J1E7Ld6yRkyiJP1o3Ks-0g/runs/0/artifacts/public/logs/live_backing.log&only_show_unexpected=1

Comment 1

[Cristina Coroiu [:ccoroiu]]

Since this bug was created, 5 days ago, there have been 30 failures. 
Starting with 2nd March we have an increase: https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1441580

The failures are on windows10-64 and windows10-64-ccov platform.
Affected build types: debug and opt.

An example of a recent log file:
https://treeherder.mozilla.org/logviewer.html#?repo=mozilla-central&job_id=165835047&lineNumber=1776

And the relevant part of the log:
11:40:31     INFO -  --DOMWINDOW == 4 (00000124F5006400) [pid = 3416] [serial = 1] [outer = 0000000000000000] [url = chrome://gfxsanity/content/sanitytest.html]
11:40:34     INFO -  --DOMWINDOW == 3 (00000124F528D800) [pid = 3416] [serial = 3] [outer = 0000000000000000] [url = chrome://gfxsanity/content/sanitytest.html]
11:40:36     INFO -  --DOMWINDOW == 2 (000002178D136800) [pid = 4092] [serial = 2] [outer = 0000000000000000] [url = about:blank]
11:41:33     INFO -  --DOMWINDOW == 2 (00000124F507C000) [pid = 3416] [serial = 5] [outer = 0000000000000000] [url = about:blank]
11:47:43     INFO -  REFTEST ERROR | None | application timed out after 370 seconds with no output
11:47:43     INFO -  REFTEST ERROR | Force-terminating active process(es).
11:47:43     INFO -  REFTEST TEST-INFO | started process screenshot
11:47:45     INFO -  REFTEST TEST-INFO | screenshot: exit 0
11:47:45     INFO -  TEST-INFO | crashinject: exit 0
11:47:46  WARNING -  TEST-UNEXPECTED-FAIL | None | application terminated with exit code 1
11:47:46     INFO -  REFTEST INFO | Copy/paste: Z:\task_1520163497\build\win32-minidump_stackwalk.exe c:\users\genericworker\appdata\local\temp\tmpnkgmhq.mozrunner\minidumps\aac2d0b6-624f-4b8c-bb2a-5f6a37d76edf.dmp Z:\task_1520163497\build\symbols
11:47:56     INFO -  REFTEST INFO | Saved minidump as Z:\task_1520163497\build\blobber_upload_dir\aac2d0b6-624f-4b8c-bb2a-5f6a37d76edf.dmp
11:47:56     INFO -  REFTEST INFO | Saved app info as Z:\task_1520163497\build\blobber_upload_dir\aac2d0b6-624f-4b8c-bb2a-5f6a37d76edf.extra
11:47:56    ERROR -  REFTEST PROCESS-CRASH | pid: None | application crashed [@ CrashingThread(void *)]
11:47:56     INFO -  Crash dump filename: c:\users\genericworker\appdata\local\temp\tmpnkgmhq.mozrunner\minidumps\aac2d0b6-624f-4b8c-bb2a-5f6a37d76edf.dmp
11:47:56     INFO -  Operating system: Windows NT
11:47:56     INFO -                    10.0.15063
11:47:56     INFO -  CPU: amd64
11:47:56     INFO -       family 6 model 63 stepping 2
11:47:56     INFO -       8 CPUs
11:47:56     INFO -  GPU: UNKNOWN
11:47:56     INFO -  Crash reason:  EXCEPTION_ACCESS_VIOLATION_WRITE
11:47:56     INFO -  Crash address: 0x0
11:47:56     INFO -  Process uptime: 458 seconds
11:47:56     INFO -  Thread 53 (crashed)
11:47:56     INFO -   0  crashinjectdll.dll!CrashingThread(void *) [crashinjectdll.cpp:21f7f94a2c18dc8010ac2f300a36cc4ddd16081c : 17 + 0x0]
11:47:56     INFO -      rax = 0x00007fffc3991000   rdx = 0x00007fffc3991000
11:47:56     INFO -      rcx = 0x0000000000000000   rbx = 0x0000000000000000
11:47:56     INFO -      rsi = 0x00007fffc3991000   rdi = 0x00007fffcae9fab0
11:47:56     INFO -      rbp = 0x0000000000000000   rsp = 0x0000002f03dff8a8
11:47:56     INFO -       r8 = 0x0000000000000000    r9 = 0x0000000000000000
11:47:56     INFO -      r10 = 0x0000000000000000   r11 = 0x0000000000000246
11:47:56     INFO -      r12 = 0x0000000000000000   r13 = 0x0000000000000000
11:47:56     INFO -      r14 = 0x0000000000000000   r15 = 0x0000000000000000
11:47:56     INFO -      rip = 0x00007fffc3991018
11:47:56     INFO -      Found by: given as instruction pointer in context
11:47:56     INFO -   1  kernel32.dll!LdrpLoadResourceFromAlternativeModule + 0x27c
11:47:56     INFO -      rsp = 0x0000002f03dff8b0   rip = 0x00007fffe9782774
11:47:56     INFO -      Found by: stack scanning

:ahal could you please take a look?

Comment 2

[Andreea Pavel [:apavel]]

Failure classification for this issue specifies: 

Logs not fully parsed, please wait 

However, the logs are parsed:
 
https://treeherder.mozilla.org/logviewer.html#?job_id=165741192&repo=autoland&lineNumber=1638

https://taskcluster-artifacts.net/YIpGfHBmQEyFJPuC2N9cVg/0/public/logs/live_backing.log

Comment 3

[Intermittent Failures Robot]

45 failures in 831 pushes (0.054 failures/push) were associated with this bug in the last 7 days. 

This is the #34 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:
* mozilla-central: 19
* try: 9
* mozilla-inbound: 9
* autoland: 7
* mozilla-beta: 1

Platform breakdown:
* windows10-64: 27
* windows10-64-ccov: 18

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1441580&startday=2018-02-26&endday=2018-03-04&tree=all

Comment 4

[Joel Maher ( :jmaher ) (UTC -8)]

:gbrown, do you think this is related to the other reftest startup timeout issues?

Comment 5

[Geoff Brown [:gbrown]]

Most of the recent jsreftest failures here appear to be browser startup hangs, with logs similar to those seen in bug 1414495 (for mochitest) and bug 1418575 (for reftests, but recently closed since we stopped getting failures reported there -- maybe because they shifted here?). So they are related in that way. In terms of root cause, it's harder to say, since we've found several causes of browser startup hangs, none of which leaves a clear signature.

It is possibly worth noting that I see "Unable to read VR Path Registry" in a lot of these logs; see https://bugzilla.mozilla.org/show_bug.cgi?id=1414495#c68.

Comment 6

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

Please note that in a lot or maybe even all cases we have again multiple processes of Firefox running as it looks like:

https://taskcluster-artifacts.net/b6BKzNgaRVunvlp8FtIWEA/0/public/test_info/mozilla-test-fail-screenshot_ux4v9o.png

Comment 7

[Intermittent Failures Robot]

44 failures in 747 pushes (0.059 failures/push) were associated with this bug in the last 7 days. 

This is the #23 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:
* mozilla-central: 17
* mozilla-inbound: 11
* autoland: 10
* try: 5
* mozilla-beta: 1

Platform breakdown:
* windows10-64: 33
* windows10-64-ccov: 7
* windows10-64-nightly: 4

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1441580&startday=2018-03-05&endday=2018-03-11&tree=all

Comment 8

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

Those all look like content crashes. Geoff, I assume we need bug 1440719 first before you want to add the crash environment variable for reftests too?

(In reply to Geoff Brown [:gbrown] from comment #5)
> Most of the recent jsreftest failures here appear to be browser startup
> hangs, with logs similar to those seen in bug 1414495 (for mochitest) and

Actually Marionette is initialized and installed the required extensions. The hang as I think caused by a content crash happens afterward. Having the env variable set we might get better information where it crashes.

Comment 9

[Geoff Brown [:gbrown]]

Yes, bug 1440719 will set MOZ_CRASHREPORTER_SHUTDOWN for mochitests and reftests; browser-chrome mochitest might be handled in a separate bug. I hope to work on that more this week.

How can you tell these are content crashes?

Comment 10

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

There are lots of pipe errors from the ipc component which from experience with content crashes in Marionette tests could indicate that there are content crashes happening. 

https://treeherder.mozilla.org/logviewer.html#?repo=mozilla-inbound&job_id=167201353&lineNumber=1708-1715

Given that the harness hangs the reftest tab should have been crashed. Sadly it's not visible because the command window overlays Firefox:

https://taskcluster-artifacts.net/AwGg84RrQvGEC7eI9yLY8A/0/public/test_info/mozilla-test-fail-screenshot_tur6yn.png

Comment 11

[Andrew Halberstadt [:ahal]]

This was filed around when reftest run-by-manifest was landed. If there was a previously existing startup crash/hang, then it would make sense that it is now a lot more frequent (since we start Firefox N times per job instead of 1). So my guess is this could be a previously existing issue that is now magnified by run-by-manifest.

Interestingly, it looks like all jobs in orange factor are either crashtest or jsreftest jobs. I wonder if there are configuration differences that could explain this.

Comment 12

[Joel Maher ( :jmaher ) (UTC -8)]

win10 reftests run on buildbot (ix hardware + buildbot worker), crashtest and jsreftest are on VM machines and use a taskcluster worker.

Comment 13

[Intermittent Failures Robot]

31 failures in 814 pushes (0.038 failures/push) were associated with this bug in the last 7 days.   

** 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:
* try: 13
* mozilla-central: 8
* autoland: 7
* mozilla-inbound: 3

Platform breakdown:
* windows10-64: 24
* windows10-64-ccov: 4
* windows10-64-nightly: 3

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1441580&startday=2018-03-12&endday=2018-03-18&tree=all

Comment 14

[Intermittent Failures Robot]

43 failures in 822 pushes (0.052 failures/push) were associated with this bug in the last 7 days. 

This is the #33 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:
* mozilla-central: 15
* autoland: 12
* mozilla-inbound: 9
* try: 7

Platform breakdown:
* windows10-64: 32
* windows10-64-ccov: 9
* windows10-64-devedition: 1
* android-4-3-armv7-api16: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1441580&startday=2018-03-20&endday=2018-03-26&tree=trunk

Comment 15

[Noemi Erli[:noemi_erli]]

There are 34 failures in the past 7 days.
Platforms: 
- windows10-64 opt, debug and pgo
- windows10-64-ccov debug
- android-4-3-armv7-api16 debug
Recent log failure: https://treeherder.mozilla.org/logviewer.html#?repo=mozilla-inbound&job_id=170601870&lineNumber=1635
Relevant part of the log: 
16:51:16     INFO -  REFTEST ERROR | None | application timed out after 370 seconds with no output
16:51:16     INFO -  REFTEST ERROR | Force-terminating active process(es).
16:51:16     INFO -  REFTEST TEST-INFO | started process screenshot
16:51:16     INFO -  REFTEST TEST-INFO | screenshot: exit 0
16:51:16     INFO -  TEST-INFO | crashinject: exit 0
17:07:56     INFO - Automation Error: mozprocess timed out after 1000 seconds running ['Z:\\task_1522168990\\build\\venv\\Scripts\\python', '-u', 'Z:\\task_1522168990\\build\\tests\\reftest\\runreftest.py', '--total-chunks', '2', '--this-chunk', '1', '--appname=Z:\\task_1522168990\\build\\application\\firefox\\firefox.exe', '--utility-path=tests/bin', '--extra-profile-file=tests/bin/plugins', '--symbols-path=https://queue.taskcluster.net/v1/task/JtWmTP07Rwy2zJwexL6gZA/artifacts/public/build/target.crashreporter-symbols.zip', '--log-raw=Z:\\task_1522168990\\build\\blobber_upload_dir\\jsreftest_raw.log', '--log-errorsummary=Z:\\task_1522168990\\build\\blobber_upload_dir\\jsreftest_errorsummary.log', '--cleanup-crashes', '--marionette-startup-timeout=180', '--extra-profile-file=tests/jsreftest/tests/user.js', '--suite=jstestbrowser', '--', 'tests/jsreftest/tests/jstests.list']
[taskcluster 2018-03-27T17:43:13.169Z]   Exit Code: 0
[taskcluster 2018-03-27T17:43:13.169Z]   User Time: 15.625ms
[taskcluster 2018-03-27T17:43:13.169Z] Kernel Time: 0s
[taskcluster 2018-03-27T17:43:13.169Z]   Wall Time: 59m57.205979s
[taskcluster 2018-03-27T17:43:13.169Z] Peak Memory: 5918720
[taskcluster 2018-03-27T17:43:13.169Z]      Result: IDLENESS_LIMIT_EXCEEDED
[taskcluster 2018-03-27T17:43:13.169Z] === Task Finished ===
[taskcluster 2018-03-27T17:43:13.169Z] Task Duration: 59m57.210049s
:ahal Can you please take a look here?

Comment 16

[Noemi Erli[:noemi_erli]]

Reftest analyzer: https://hg.mozilla.org/mozilla-central/raw-file/tip/layout/tools/reftest/reftest-analyzer.xhtml#logurl=https://queue.taskcluster.net/v1/task/egyAGMj3Sj2oLpbY06-1NQ/runs/0/artifacts/public/logs/live_backing.log&only_show_unexpected=1

Comment 17

[Geoff Brown [:gbrown]]

Most of these likely have a common cause with bug 1414495, although the subsequent mozprocess timeout and the lack of crash report is odd and unfortunate.

Comment 18

[Andrew Halberstadt [:ahal]]

I filed bug 1449576 to figure out why were not getting crash stacks on timeout anymore. I'll poke into that a bit to see if I can figure out why. I don't have any ideas for this bug though :/

Comment 19

[Intermittent Failures Robot]

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

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

Platform breakdown:
* windows10-64: 15
* windows10-64-ccov: 4
* linux64-ccov: 1
* android-4-3-armv7-api16: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1441580&startday=2018-03-26&endday=2018-04-01&tree=trunk

Comment 20

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

In each of the cases the Firefox window is still in the background and a command line window is pushed to foreground. I know that for a couple of tests we wait until the Firefox window has focus. So maybe this hits us here?

https://queue.taskcluster.net/v1/task/I3ADGO9cToyq9fNgHCNI2g/runs/0/artifacts/public/test_info/mozilla-test-fail-screenshot_l5vwzt.png

Pete or Rob, can we run the Notepad command in a minimized command line window?

Comment 21

[Rob Thijssen [:grenade (EET/UTC+0300)]]

Yes. The command to create the cmd window is created by the generic worker install command so a patch to gw to add a /B (background process) flag should mean that the cmd window won't show up in the test UI. I'll let Pete weigh in because I suspect this is already patched on the 10.x gw installs which are due to roll out any day now.

Comment 22

[Pete Moore [:pmoore][:pete]]

Thanks Rob.

Yes indeed, we have a major Windows upgrade going on today - let's see if this is still needed after the upgrade.

Details: https://groups.google.com/forum/#!topic/mozilla.tools.taskcluster/UHeTl1ZMEy8

Comment 23

[Geoff Brown [:gbrown]]

(In reply to Henrik Skupin (:whimboo) from comment #20)
> In each of the cases the Firefox window is still in the background and a
> command line window is pushed to foreground. I know that for a couple of
> tests we wait until the Firefox window has focus. So maybe this hits us here?

I think it may make sense that the Firefox window is not displayed: The hangs we have identified from crash reports in bug 1414495 are fairly early in Firefox startup -- perhaps before we have tried to display a window?

Comment 24

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

No, the Firefox windows are visible but hidden by the command window. So there is no way to see what is actually been displayed. See the screenshot from comment 20.

Comment 25

[Intermittent Failures Robot]

9 failures in 765 pushes (0.012 failures/push) were associated with this bug in the last 7 days.    

Repository breakdown:
* mozilla-central: 4
* mozilla-inbound: 2
* autoland: 2
* mozilla-beta: 1

Platform breakdown:
* windows10-64: 6
* windows10-64-ccov: 2
* windows10-64-nightly: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1441580&startday=2018-04-02&endday=2018-04-08&tree=trunk

Comment 26

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

Something interesting happened here on a ccov job:
https://treeherder.mozilla.org/logviewer.html#?job_id=172327879&repo=mozilla-central&lineNumber=1795

Why are all those applications and windows open which cause Firefox to be in the background, and maybe the harness to hang?

https://queue.taskcluster.net/v1/task/T9kkWXaDRkaH8SrF6XlTug/runs/0/artifacts/public/test_info/mozilla-test-fail-screenshot_nqpwq6.png

Good news is at least that since we are on the new generic worker the amount of failures has been drastically dropped. So I assume that the problem here was the shown command window which executed the Notepad command.

Comment 27

[Rob Thijssen [:grenade (EET/UTC+0300)]]

this screenshot appears to be from a hardware instance (T-W1064-MS-021).
on hardware the generic worker version is still 8. hardware was not included in the upgrade to 10.
i suspect someone was on the instance doing some debugging work because the event viewer shown in the screenshot is unlikely to have been opened by something in automation. much more likely to be a human being doing some debug work.

Comment 28

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

Greg, can you please check comment 26 and comment 27? Did you operate on that machine while it was running the ccov tests?

Comment 29

[Joel Maher ( :jmaher ) (UTC -8)]

I am pretty sure neither Greg or Marco have had a loaner, this could have been stuck around since setting up the hardware, or maybe there was an odd bit of hardware someone from relops was looking into.  The standard method for putting a loaner back into production is at the very least to reboot it, I thought it was to reimage the machine.

I agree that this looks fully resolved with the new worker- I imagine there will always be an odd case where the specific hardware machine is quirky or there is human error intervening.

Comment 30

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

(In reply to Joel Maher ( :jmaher) (UTC-5) from comment #29)
> been stuck around since setting up the hardware, or maybe there was an odd
> bit of hardware someone from relops was looking into.  The standard method
> for putting a loaner back into production is at the very least to reboot it,
> I thought it was to reimage the machine.

Should someone check that machine to be sure that all is back to normal? I doubt it will be re-imaged automatically, or does it?

> I agree that this looks fully resolved with the new worker- I imagine there
> will always be an odd case where the specific hardware machine is quirky or
> there is human error intervening.

Ok, then lets close this bug as fixed by the generic worker upgrade. Thanks a ton Pete! \o/

Comment 31

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

Please note that I can perfectly replicate this problem with a Unicode character in the profile string. See the following try push:

https://treeherder.mozilla.org/logviewer.html#?job_id=172807698&repo=try&lineNumber=1824

It hangs in the same line as usual (directly after Marionette installed the extensions):

> [task 2018-04-10T05:47:41.148Z] 05:47:41     INFO - 1523339261141	Marionette	TRACE	1 <- [1,2,null,{"value":"[e-mail]"}]
> [task 2018-04-10T05:47:41.399Z] 05:47:41     INFO - 1523339261393	Marionette	TRACE	1 -> [0,3,"deleteSession",{}]
> [task 2018-04-10T05:47:41.400Z] 05:47:41     INFO - 1523339261395	Marionette	TRACE	1 <- [1,3,null,{}]
> [task 2018-04-10T05:47:41.416Z] 05:47:41     INFO - 1523339261412	Marionette	DEBUG	Closed connection 1
> [task 2018-04-10T05:53:51.729Z] 05:53:51    ERROR - REFTEST ERROR | None | application timed out after 370 seconds with no output

I will track this separately via bug 918097 because that's a new feature which might break certain code in reftest. But it may be related.

Comment 32

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

Well, I think that we should reopen for now given that I found some cases which are not only related to Unicode characters in the profile path, but wrong Promise handling which cause a hang in reftests. I will file as separate bug in a moment.

Comment 33

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

Geoff, I have another case (from yesterday) for you here:

https://treeherder.mozilla.org/logviewer.html#?job_id=172985412&repo=autoland&lineNumber=7372-7374

As the screenshot shows there is a problem with loading XPCOM:
https://taskcluster-artifacts.net/AiJoPQdSRqakMIHuhLUSLQ/0/public/test_info/mozilla-test-fail-screenshot_n1mdgg.png

Looks like the reftest harness waits forever and always assumes that Marionette will install the reftest extension, and executes the tests. Maybe we can catch this with another kind of timeout?

Comment 34

[Geoff Brown [:gbrown]]

Thanks - I haven't seen that screenshot before.

I think the 370 s no-output application timeout is appropriate. I'm not sure what else we can do in the harness.

I suppose GetBootstrap() failed here:

https://dxr.mozilla.org/mozilla-central/rev/0528a414c2a86dad0623779abde5301d37337934/browser/app/nsBrowserApp.cpp#243-247

And it looks like that Output() call pops up a message box in Windows/debug builds:

https://dxr.mozilla.org/mozilla-central/rev/0528a414c2a86dad0623779abde5301d37337934/browser/app/nsBrowserApp.cpp#120-127

Maybe using a message box here is not a good idea?


In the log I also notice:

23:39:32     INFO -  [Parent 4988, Main Thread] WARNING: NS_ENSURE_TRUE(mHiddenWindow) failed: file z:/build/build/src/xpfe/appshell/nsAppShellService.cpp, line 805
23:39:32     INFO -  JavaScript error: jar:file:///C:/Users/task_1523403112/build/application/firefox/browser/omni.ja!/components/nsBrowserGlue.js, line 1019: NS_ERROR_FAILURE: Component returned failure code: 0x80004005 (NS_ERROR_FAILURE) [nsIAppShellService.hiddenDOMWindow]
23:39:32     INFO -  [Parent 4988, StreamTrans #26] WARNING: 'NS_FAILED(rv)', file z:/build/build/src/modules/libjar/nsJARChannel.cpp, line 428
23:40:17     INFO -  Hit MOZ_CRASH(Shutdown hanging before starting.) at z:/build/build/src/toolkit/components/terminator/nsTerminator.cpp:206
23:40:17     INFO -  #01: PR_NativeRunThread [nsprpub/pr/src/threads/combined/pruthr.c:406]
23:40:17     INFO -  #02: static unsigned int pr_root(void *) [nsprpub/pr/src/md/windows/w95thred.c:138]
23:40:17     INFO -  #03: ucrtbase.dll + 0x20369
23:40:17     INFO -  #04: KERNEL32.DLL + 0x12774
23:40:17     INFO -  #05: ntdll.dll + 0x70d61
23:40:20     INFO -  [GPU 6368, Main Thread] WARNING: Shutting down GPU process early due to a crash!: file z:/build/build/src/gfx/ipc/GPUParent.cpp, line 466

...but I do not know what went wrong first.

Comment 35

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

(In reply to Geoff Brown [:gbrown] from comment #34)
> 23:39:32     INFO -  [Parent 4988, Main Thread] WARNING:
> NS_ENSURE_TRUE(mHiddenWindow) failed: file
> z:/build/build/src/xpfe/appshell/nsAppShellService.cpp, line 805
> 23:39:32     INFO -  JavaScript error:
> jar:file:///C:/Users/task_1523403112/build/application/firefox/browser/omni.
> ja!/components/nsBrowserGlue.js, line 1019: NS_ERROR_FAILURE: Component
> returned failure code: 0x80004005 (NS_ERROR_FAILURE)
> [nsIAppShellService.hiddenDOMWindow]

So we report first that something maybe went wrong in creating the hidden window, and then we fail with a JavaScript failure in Media Telemetry code trying to access the hidden window:

https://dxr.mozilla.org/mozilla-central/rev/cfe6399e142c71966ef58a16cfd52c0b46dc6b1e/browser/components/nsBrowserGlue.js#1018-1021

I would say that we should file a separate bug for that, or get at least some info from Felipe first who implemented this code in bug 1397232.

Also shouldn't Telemetry be disabled for reftests? Why are we running into this code?

> 23:39:32     INFO -  [Parent 4988, StreamTrans #26] WARNING:
> 'NS_FAILED(rv)', file z:/build/build/src/modules/libjar/nsJARChannel.cpp,
> line 428
> 23:40:17     INFO -  Hit MOZ_CRASH(Shutdown hanging before starting.) at
> z:/build/build/src/toolkit/components/terminator/nsTerminator.cpp:206

I wonder why we hang here, and do not see a shutdown of the process. Is that the messagebox which is blocking it? For automation this doesn't look ideal. Jim, could you help us here? Also see comment 33 and comment 34. Thanks.

Comment 36

[Intermittent Failures Robot]

2 failures in 792 pushes (0.003 failures/push) were associated with this bug in the last 7 days.    

Repository breakdown:
* autoland: 2

Platform breakdown:
* windows10-64-qr: 1
* linux32: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1441580&startday=2018-04-09&endday=2018-04-15&tree=trunk

Comment 37

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

(In reply to OrangeFactor Robot from comment #36)
> * windows10-64-qr: 1

I cannot find anything for that listed in the intermittent failures list. Maybe it was mis-starred and got fixed.

> * linux32: 1

Interesting here is that it takes about 4:30 minutes until this instance of Firefox (debug) has been started:
https://treeherder.mozilla.org/logviewer.html#?job_id=173652170&repo=autoland&lineNumber=1766-1802

Comment 38

[Andreea Pavel [:apavel]]

(In reply to Henrik Skupin (:whimboo) from comment #37)
> (In reply to OrangeFactor Robot from comment #36)
> > * windows10-64-qr: 1
> 
> I cannot find anything for that listed in the intermittent failures list.
> Maybe it was mis-starred and got fixed.

When and if we find miss-classified failures we usually correct them, so that's likely the case here.

Comment 39

[Jim Mathies [:jimm]]

(In reply to Geoff Brown [:gbrown] from comment #34)
> Thanks - I haven't seen that screenshot before.
> 
> I think the 370 s no-output application timeout is appropriate. I'm not sure
> what else we can do in the harness.
> 
> I suppose GetBootstrap() failed here:
> 
> https://dxr.mozilla.org/mozilla-central/rev/
> 0528a414c2a86dad0623779abde5301d37337934/browser/app/nsBrowserApp.cpp#243-247
> 
> And it looks like that Output() call pops up a message box in Windows/debug
> builds:
> 
> https://dxr.mozilla.org/mozilla-central/rev/
> 0528a414c2a86dad0623779abde5301d37337934/browser/app/nsBrowserApp.cpp#120-127
> 
> Maybe using a message box here is not a good idea?
> 
> 
> In the log I also notice:
> 
> 23:39:32     INFO -  [Parent 4988, Main Thread] WARNING:
> NS_ENSURE_TRUE(mHiddenWindow) failed: file
> z:/build/build/src/xpfe/appshell/nsAppShellService.cpp, line 805
> 23:39:32     INFO -  JavaScript error:
> jar:file:///C:/Users/task_1523403112/build/application/firefox/browser/omni.
> ja!/components/nsBrowserGlue.js, line 1019: NS_ERROR_FAILURE: Component
> returned failure code: 0x80004005 (NS_ERROR_FAILURE)
> [nsIAppShellService.hiddenDOMWindow]
> 23:39:32     INFO -  [Parent 4988, StreamTrans #26] WARNING:
> 'NS_FAILED(rv)', file z:/build/build/src/modules/libjar/nsJARChannel.cpp,
> line 428
> 23:40:17     INFO -  Hit MOZ_CRASH(Shutdown hanging before starting.) at
> z:/build/build/src/toolkit/components/terminator/nsTerminator.cpp:206
> 23:40:17     INFO -  #01: PR_NativeRunThread
> [nsprpub/pr/src/threads/combined/pruthr.c:406]
> 23:40:17     INFO -  #02: static unsigned int pr_root(void *)
> [nsprpub/pr/src/md/windows/w95thred.c:138]
> 23:40:17     INFO -  #03: ucrtbase.dll + 0x20369
> 23:40:17     INFO -  #04: KERNEL32.DLL + 0x12774
> 23:40:17     INFO -  #05: ntdll.dll + 0x70d61
> 23:40:20     INFO -  [GPU 6368, Main Thread] WARNING: Shutting down GPU
> process early due to a crash!: file
> z:/build/build/src/gfx/ipc/GPUParent.cpp, line 466
> 
> ...but I do not know what went wrong first.

I don't see how any of this can happen with an XPCOM lib that failed to load. These issues are usually related to flawed installs or corrupt binaries.

Comment 40

[Intermittent Failures Robot]

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

Repository breakdown:
* mozilla-central: 1

Platform breakdown:
* osx-10-10: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1441580&startday=2018-05-21&endday=2018-05-27&tree=trunk

Comment 41

[Intermittent Failures Robot]

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

Repository breakdown:
* mozilla-central: 1

Platform breakdown:
* windows10-64-ccov: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1441580&startday=2018-06-04&endday=2018-06-10&tree=trunk

Comment 42

[Intermittent Failures Robot]

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

Repository breakdown:
* autoland: 1

Platform breakdown:
* linux64: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1441580&startday=2018-06-11&endday=2018-06-17&tree=trunk

Comment 43

[Intermittent Failures Robot]

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

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

Platform breakdown:
* linux64: 2
* windows10-64-qr: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1441580&startday=2018-06-18&endday=2018-06-24&tree=trunk

Comment 44

[Intermittent Failures Robot]

2 failures in 718 pushes (0.003 failures/push) were associated with this bug in the last 7 days.    

Repository breakdown:
* mozilla-inbound: 2

Platform breakdown:
* windows10-64: 2

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

Comment 45

[Intermittent Failures Robot]

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

Repository breakdown:
* mozilla-central: 1

Platform breakdown:
* linux64: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1441580&startday=2018-07-02&endday=2018-07-08&tree=trunk

Comment 46

[Intermittent Failures Robot]

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

Repository breakdown:
* try: 1

Platform breakdown:
* linux64: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1441580&startday=2018-07-09&endday=2018-07-15&tree=trunk

Comment 47

[Intermittent Failures Robot]

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

Repository breakdown:
* autoland: 1

Platform breakdown:
* windows10-64: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1441580&startday=2018-07-16&endday=2018-07-22&tree=trunk

Comment 48

[Intermittent Failures Robot]

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

Repository breakdown:
* mozilla-inbound: 1

Platform breakdown:
* linux64-qr: 1

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

Comment 49

[Intermittent Failures Robot]

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

Repository breakdown:
* mozilla-beta: 1

Platform breakdown:
* windows10-64-qr: 1

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

Comment 50

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

As it looks like we no longer getting those failures classified.

Sebastian, could you please check if we can mark this bug as WFM, or if we incorrectly classify failures?

Comment 51

[Sebastian Hengst [:aryx] (needinfo me if it's about an intermittent or backout)]

The last match for "[@ CrashingThread(void *)]" on a normal branch is from 2018-12-13.