Closed Bug 1693794 Opened 5 years ago Closed 3 years ago

Intermittent js/src/tests/test262/language/white-space/string-vertical-tab.js (finished) | application crashed [@ mozilla::nsTerminator::StartWatchdog + 0x7d2]

Categories

(Core :: XPCOM, defect)

Product:
Core
Component:
XPCOM
Type:
defect

Tracking

()

Status:
RESOLVED WORKSFORME

People

(Reporter: intermittent-bug-filer, Unassigned)

Details

(Keywords: crash, intermittent-failure)

Crash Data

Filed by: abutkovits [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=330512127&repo=mozilla-central
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/cyu__k-FSYO8DfnpvcJBFw/runs/0/artifacts/public/logs/live_backing.log
Reftest URL: https://hg.mozilla.org/mozilla-central/raw-file/tip/layout/tools/reftest/reftest-analyzer.xhtml#logurl=https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/cyu__k-FSYO8DfnpvcJBFw/runs/0/artifacts/public/logs/live_backing.log&only_show_unexpected=1

[task 2021-02-19T12:32:46.724Z] 12:32:46     INFO - REFTEST TEST-PASS | js/src/tests/test262/language/white-space/string-vertical-tab.js |   item 1
[task 2021-02-19T12:32:46.724Z] 12:32:46     INFO - REFTEST TEST-END | js/src/tests/test262/language/white-space/string-vertical-tab.js
[task 2021-02-19T12:32:46.743Z] 12:32:46     INFO - JavaScript error: resource://specialpowers/AppTestDelegateParent.jsm, line 10: NS_ERROR_NOT_AVAILABLE:
[task 2021-02-19T12:32:46.743Z] 12:32:46     INFO - JavaScript error: resource://specialpowers/AppTestDelegateParent.jsm, line 10: NS_ERROR_NOT_AVAILABLE:
[task 2021-02-19T12:32:46.743Z] 12:32:46     INFO - REFTEST INFO | Result summary:
[task 2021-02-19T12:32:46.743Z] 12:32:46     INFO - REFTEST INFO | Successful: 7729 (7729 pass, 0 load only)
[task 2021-02-19T12:32:46.744Z] 12:32:46     INFO - REFTEST INFO | Unexpected: 0 (0 unexpected fail, 0 unexpected pass, 0 unexpected asserts, 0 failed load, 0 exception)
[task 2021-02-19T12:32:46.744Z] 12:32:46     INFO - REFTEST INFO | Known problems: 2459 (1 known fail, 0 known asserts, 0 random, 2458 skipped, 0 slow)
[task 2021-02-19T12:32:46.744Z] 12:32:46     INFO - REFTEST SUITE-END | Shutdown
[task 2021-02-19T12:32:46.746Z] 12:32:46     INFO - REFTEST INFO | Slowest test took 5133ms (file:///C:/Users/task_1613735722/build/tests/jsreftest/tests/js/src/tests/jsreftest.html?test=test262/language/literals/regexp/S7.8.5_A2.1_T2.js)
[task 2021-02-19T12:32:46.746Z] 12:32:46     INFO - REFTEST INFO | Total canvas count = 0
[task 2021-02-19T12:32:46.893Z] 12:32:46  WARNING - REFTEST WARNING | Failed to find the test-plugin.
[task 2021-02-19T12:32:46.893Z] 12:32:46  WARNING - REFTEST WARNING | Failed to find the test-plugin.
[task 2021-02-19T12:32:46.893Z] 12:32:46  WARNING - REFTEST WARNING | Failed to get test plugin tags.
[task 2021-02-19T12:32:46.923Z] 12:32:46     INFO - ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2021-02-19T12:32:46.923Z] 12:32:46     INFO - ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2021-02-19T12:32:47.308Z] 12:32:47     INFO - ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2021-02-19T12:32:47.308Z] 12:32:47     INFO - ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2021-02-19T12:32:47.308Z] 12:32:47     INFO - ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2021-02-19T12:32:48.568Z] 12:32:48     INFO - 1613737968563	Marionette	TRACE	Received observer notification xpcom-will-shutdown
[task 2021-02-19T12:32:48.568Z] 12:32:48     INFO - 1613737968564	Marionette	INFO	Stopped listening on port 2828
[task 2021-02-19T12:32:48.568Z] 12:32:48     INFO - 1613737968564	Marionette	DEBUG	Marionette stopped listening
[task 2021-02-19T12:32:48.578Z] 12:32:48     INFO - ###!!! [Child][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2021-02-19T12:34:39.855Z] 12:34:39    ERROR - TEST-UNEXPECTED-FAIL | js/src/tests/test262/language/white-space/string-vertical-tab.js (finished) | application terminated with exit code 1
[task 2021-02-19T12:34:39.855Z] 12:34:39     INFO - REFTEST INFO | Downloading symbols from: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/SV3RU5IBRy2eeIRuHrGKHA/artifacts/public/build/target.crashreporter-symbols.zip
[task 2021-02-19T12:34:45.316Z] 12:34:45     INFO - REFTEST INFO | Copy/paste: C:/Users/task_1613735722/fetches\minidump_stackwalk\minidump_stackwalk.exe c:\users\task_1613735722\appdata\local\temp\tmpm0povz.mozrunner\minidumps\00184243-9cdc-48c0-9285-c4cb89ded59d.dmp c:\users\task_1613735722\appdata\local\temp\tmpyavgdb
[task 2021-02-19T12:34:48.251Z] 12:34:48     INFO - REFTEST INFO | Saved minidump as C:\Users\task_1613735722\build\blobber_upload_dir\00184243-9cdc-48c0-9285-c4cb89ded59d.dmp
[task 2021-02-19T12:34:48.251Z] 12:34:48     INFO - REFTEST INFO | Saved app info as C:\Users\task_1613735722\build\blobber_upload_dir\00184243-9cdc-48c0-9285-c4cb89ded59d.extra
[task 2021-02-19T12:34:48.261Z] 12:34:48     INFO - REFTEST PROCESS-CRASH | js/src/tests/test262/language/white-space/string-vertical-tab.js (finished) | application crashed [@ mozilla::nsTerminator::StartWatchdog + 0x7d2]
[task 2021-02-19T12:34:48.261Z] 12:34:48     INFO - Mozilla crash reason: MOZ_CRASH(Shutdown hanging after all known phases and workers finished.)
[task 2021-02-19T12:34:48.261Z] 12:34:48     INFO - Crash dump filename: c:\users\task_1613735722\appdata\local\temp\tmpm0povz.mozrunner\minidumps\00184243-9cdc-48c0-9285-c4cb89ded59d.dmp
[task 2021-02-19T12:34:48.261Z] 12:34:48     INFO - Operating system: Windows NT
[task 2021-02-19T12:34:48.261Z] 12:34:48     INFO -                   10.0.17134 
[task 2021-02-19T12:34:48.262Z] 12:34:48     INFO - CPU: amd64
[task 2021-02-19T12:34:48.262Z] 12:34:48     INFO -      family 6 model 94 stepping 3
[task 2021-02-19T12:34:48.262Z] 12:34:48     INFO -      8 CPUs
[task 2021-02-19T12:34:48.262Z] 12:34:48     INFO - 
[task 2021-02-19T12:34:48.262Z] 12:34:48     INFO - GPU: UNKNOWN
[task 2021-02-19T12:34:48.262Z] 12:34:48     INFO - 
[task 2021-02-19T12:34:48.262Z] 12:34:48     INFO - Crash reason:  EXCEPTION_BREAKPOINT
[task 2021-02-19T12:34:48.262Z] 12:34:48     INFO - Crash address: 0x6ca42cb2
[task 2021-02-19T12:34:48.262Z] 12:34:48     INFO - Process uptime: 948 seconds
[task 2021-02-19T12:34:48.262Z] 12:34:48     INFO - 
[task 2021-02-19T12:34:48.262Z] 12:34:48     INFO - Thread 11 (crashed)
[task 2021-02-19T12:34:48.262Z] 12:34:48     INFO -  0  xul.dll!void mozilla::nsTerminator::StartWatchdog + 0x7d2
[task 2021-02-19T12:34:48.262Z] 12:34:48     INFO -     rax = 0x00007fff9444ad50   rdx = 0x0000000000000000
[task 2021-02-19T12:34:48.262Z] 12:34:48     INFO -     rcx = 0x00007fff75573a49   rbx = 0x00007fff79a0c7e8
[task 2021-02-19T12:34:48.262Z] 12:34:48     INFO -     rsi = 0x000000000000003f   rdi = 0x00007fffb3d23ca0
[task 2021-02-19T12:34:48.262Z] 12:34:48     INFO -     rbp = 0x000000e8f1350000   rsp = 0x000000e8f134fda0
[task 2021-02-19T12:34:48.263Z] 12:34:48     INFO -      r8 = 0x0000000000000008    r9 = 0x00007fffb3ab0cec
[task 2021-02-19T12:34:48.263Z] 12:34:48     INFO -     r10 = 0x00000ffff65bcbe7   r11 = 0x0022008000000002
[task 2021-02-19T12:34:48.263Z] 12:34:48     INFO -     r12 = 0x00007fffb67982c0   r13 = 0x00007fff93621c58
[task 2021-02-19T12:34:48.263Z] 12:34:48     INFO -     r14 = 0x00000209af66ee00   r15 = 0x00000209af6a4c50
[task 2021-02-19T12:34:48.263Z] 12:34:48     INFO -     rip = 0x00007fff6ca42cb2
[task 2021-02-19T12:34:48.263Z] 12:34:48     INFO -     Found by: given as instruction pointer in context
[task 2021-02-19T12:34:48.263Z] 12:34:48     INFO -  1  nss3.dll!PR_NativeRunThread + 0x20d
[task 2021-02-19T12:34:48.263Z] 12:34:48     INFO -     rbx = 0x00007fff79a0c7e8   rbp = 0x000000e8f1350000
[task 2021-02-19T12:34:48.263Z] 12:34:48     INFO -     rsp = 0x000000e8f134fe10   r12 = 0x00007fffb67982c0
[task 2021-02-19T12:34:48.263Z] 12:34:48     INFO -     r13 = 0x00007fff93621c58   r14 = 0x00000209af66ee00
[task 2021-02-19T12:34:48.263Z] 12:34:48     INFO -     r15 = 0x00000209af6a4c50   rip = 0x00007fff9335d68d
[task 2021-02-19T12:34:48.263Z] 12:34:48     INFO -     Found by: call frame info
[task 2021-02-19T12:34:48.263Z] 12:34:48     INFO -  2  nss3.dll!PR_MD_CREATE_THREAD + 0x129
[task 2021-02-19T12:34:48.264Z] 12:34:48     INFO -     rbx = 0x00007fff79a0c7e8   rbp = 0x000000e8f1350000
[task 2021-02-19T12:34:48.264Z] 12:34:48     INFO -     rsp = 0x000000e8f134feb0   r12 = 0x00007fffb67982c0
[task 2021-02-19T12:34:48.264Z] 12:34:48     INFO -     r13 = 0x00007fff93621c58   r14 = 0x00000209af66ee00
[task 2021-02-19T12:34:48.264Z] 12:34:48     INFO -     r15 = 0x00000209af6a4c50   rip = 0x00007fff9333ebc9
[task 2021-02-19T12:34:48.264Z] 12:34:48     INFO -     Found by: call frame info
[task 2021-02-19T12:34:48.264Z] 12:34:48     INFO -  3  ucrtbase.dll!RtlpHpSegPageRangeShrink + 0xda
[task 2021-02-19T12:34:48.264Z] 12:34:48     INFO -     rbx = 0x00007fff79a0c7e8   rbp = 0x000000e8f1350000
[task 2021-02-19T12:34:48.264Z] 12:34:48     INFO -     rsp = 0x000000e8f134fee0   r12 = 0x00007fffb67982c0
[task 2021-02-19T12:34:48.264Z] 12:34:48     INFO -     r13 = 0x00007fff93621c58   r14 = 0x00000209af66ee00
[task 2021-02-19T12:34:48.264Z] 12:34:48     INFO -     r15 = 0x00000209af6a4c50   rip = 0x00007fffb3a8c4be
[task 2021-02-19T12:34:48.264Z] 12:34:48     INFO -     Found by: call frame info```

Atila, the message (finished) after a test filename means the test finished running before the crash.

When you see this message, it's better to select a Component based on the crash location, not the test filename.

In this case:

[task 2021-02-19T12:34:48.262Z] 12:34:48     INFO - Thread 11 (crashed)
[task 2021-02-19T12:34:48.262Z] 12:34:48     INFO -  0  xul.dll!void mozilla::nsTerminator::StartWatchdog + 0x7d2

I searched searchfox for mozilla::nsTerminator::StartWatchdog and looked at the bugs that recently touched that file. It looks like there are many possible Components, so I had to guess.

Component: JavaScript Engine → DOM: Content Processes
Flags: needinfo?(abutkovits)

Jason, thank you for the advice. I will do so in the future.

Flags: needinfo?(abutkovits)

The watch dog crash just indicates that the main thread was hanging, so this is unlikely to be a problem with the watchdog per se.

Thread 0 is this:

ntdll.dll!NtWaitForSingleObject + 0x14
KERNELBASE.dll!RtlpComputeLangListCheckSum + 0x132
xul.dll!virtual void * mozilla::ipc::BrowserProcessSubThread::`scalar deleting destructor'(unsigned int) + 0x18
xul.dll!enum nsresult mozilla::ShutdownXPCOM(class nsIServiceManager *) + 0xd2b
xul.dll! ScopedXPCOMStartup::~ScopedXPCOMStartup + 0x381

It looks like we're hanging during XPCOM shutdown.

Maybe this is ~BrowserProcessSubThread trying to acquire sLock? I looked through the other threads and there wasn't anything that looked obviously to me like something interesting was happening that might be holding this lock.

Component: DOM: Content Processes → XPCOM

This specific report is moot now for 2 years (I am sure we still see other flavors of shutdown hangs, of course).

Status: NEW → RESOLVED
Closed: 3 years ago
Resolution: --- → WORKSFORME
You need to log in before you can comment on or make changes to this bug.