Closed Bug 1371490 Opened 7 years ago Closed 5 years ago

Intermittent devtools/shared/tests/unit/test_console_filtering.js | application crashed [@ mozilla::ipc::MessageChannel::Close()]

Categories

(Core :: Gecko Profiler, defect, P3)

defect

Tracking

()

RESOLVED FIXED
mozilla69
Tracking Status
firefox-esr60 --- wontfix
firefox67 --- wontfix
firefox68 --- fixed
firefox69 --- fixed

People

(Reporter: intermittent-bug-filer, Assigned: jld)

References

Details

(Keywords: crash, intermittent-failure)

Crash Data

Andrea, I can't tell from the log what is going on here.  I see:

> 03:37:40     INFO -  TEST-START | devtools/shared/tests/unit/test_console_filtering.js

Then later:

> 03:37:53     INFO -  TEST-PASS | devtools/shared/tests/unit/test_console_filtering.js | took 13341ms

Then finally during a bunch of indexeddb tests:

> 03:38:52  WARNING -  PROCESS-CRASH | devtools/shared/tests/unit/test_console_filtering.js | application crashed

Can you tell if this is originating from the console?
Flags: needinfo?(amarchesini)
Priority: -- → P3
Suspect the crash is not related to the Console API, but a wrong shutdown procedure of IPC:

ipc/glue/MessageChannel.cpp: 2671
            MOZ_CRASH("Close() called on closed channel!");
Flags: needinfo?(amarchesini) → needinfo?(wmccloskey)
Can you please take a look at this Markus? It looks like an issue with the new profiler IPC code.
Component: Developer Tools → Gecko Profiler
Flags: needinfo?(wmccloskey) → needinfo?(mstange)
Product: Firefox → Core
http://searchfox.org/mozilla-central/source/tools/profiler/gecko/ProfilerChild.cpp#89

ProfilerChild::Destroy only calls Close() if ActorDestroy hasn't been called. Is there a way that the channel could be closed without ActorDestroy having been called?
Flags: needinfo?(mstange) → needinfo?(wmccloskey)
ActorDestroy is called asynchronously. Could Destroy get called twice? Maybe if some variant of ChildProfilerController::Shutdown is called twice?

It might make sense to set mDestroyed in Destroy().
Flags: needinfo?(wmccloskey)
I don't think it can get called twice, because the only caller nulls out its pointer to the object after calling Destroy():
http://searchfox.org/mozilla-central/source/tools/profiler/gecko/ChildProfilerController.cpp#98
Bulk priority update of open intermittent test failure bugs. 

P3 => P5

https://bugzilla.mozilla.org/show_bug.cgi?id=1381960
Priority: P3 → P5
https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
Status: NEW → RESOLVED
Closed: 6 years ago
Resolution: --- → INCOMPLETE
Status: REOPENED → RESOLVED
Closed: 6 years ago5 years ago
Resolution: --- → INCOMPLETE

Recent failure log: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=231380360&repo=mozilla-central&lineNumber=3174

23:54:19 INFO - TEST-START | xpcshell-parent-process.ini:dom/indexedDB/test/unit/test_transaction_lifetimes_nested.js
23:54:19 INFO - mozcrash Saved minidump as Z:\task_1551483959\build\blobber_upload_dir\82ccdc7d-dc19-4ec2-8b10-42132b1ebc12.dmp
23:54:19 INFO - mozcrash Saved app info as Z:\task_1551483959\build\blobber_upload_dir\82ccdc7d-dc19-4ec2-8b10-42132b1ebc12.extra
23:54:19 WARNING - PROCESS-CRASH | devtools/shared/tests/unit/test_console_filtering.js | application crashed [@ mozilla::ipc::MessageChannel::Close()]
23:54:19 INFO - Crash dump filename: c:\users\task_1551483959\appdata\local\temp\xpc-other-j7iojd\82ccdc7d-dc19-4ec2-8b10-42132b1ebc12.dmp
23:54:19 INFO - Operating system: Windows NT
23:54:19 INFO - 10.0.17134
23:54:19 INFO - CPU: amd64
23:54:19 INFO - family 6 model 85 stepping 3
23:54:19 INFO - 8 CPUs
23:54:19 INFO - GPU: UNKNOWN
23:54:19 INFO - Crash reason: EXCEPTION_BREAKPOINT
23:54:19 INFO - Crash address: 0x7ffab6a0c515
23:54:19 INFO - Assertion: Unknown assertion type 0x00000000
23:54:19 INFO - Process uptime: 1 seconds
23:54:19 INFO - Thread 5 (crashed)
23:54:19 INFO - 0 xul.dll!mozilla::ipc::MessageChannel::Close() [MessageChannel.cpp:e3762382f7906a9389f3dd890b07a2bfbad17227 : 2693 + 0x0]
23:54:19 INFO - rax = 0x00007ffabd77b537 rdx = 0x00007ffafcb5a640
23:54:19 INFO - rcx = 0x00007ffae7eefae0 rbx = 0x0000000000000003
23:54:19 INFO - rsi = 0x000001c8966a6948 rdi = 0x000001c896608340
23:54:19 INFO - rbp = 0x0000000000000001 rsp = 0x00000043d5b6f3e0
23:54:19 INFO - r8 = 0x00000043d5b69538 r9 = 0x00000043d5b6ab50
23:54:19 INFO - r10 = 0x0000000000000000 r11 = 0x00000043d5b6aa60
23:54:19 INFO - r12 = 0x000001c89661af00 r13 = 0x0000000000000001
23:54:19 INFO - r14 = 0x00000000ffffffff r15 = 0x00000043d5b6fa4f
23:54:19 INFO - rip = 0x00007ffab6a0c515
23:54:19 INFO - Found by: given as instruction pointer in context
23:54:19 INFO - 1 xul.dll!mozilla::ChildProfilerController::ShutdownProfilerChild(nsTString<char> *) [ChildProfilerController.cpp:e3762382f7906a9389f3dd890b07a2bfbad17227 : 95 + 0x8]
23:54:19 INFO - rbx = 0x0000000000000003 rbp = 0x0000000000000001
23:54:19 INFO - rsp = 0x00000043d5b6f440 r12 = 0x000001c89661af00
23:54:19 INFO - r13 = 0x0000000000000001 r14 = 0x00000000ffffffff
23:54:19 INFO - r15 = 0x00000043d5b6fa4f rip = 0x00007ffabb54d169
23:54:19 INFO - Found by: call frame info
23:54:19 INFO - 2 xul.dll!nsresult mozilla::detail::RunnableMethodImpl<mozilla::ChildProfilerController ,void (mozilla::ChildProfilerController::)(nsTString<char> *),1,mozilla::RunnableKind::Standard,nsTString<char> *>::Run() [nsThreadUtils.h:e3762382f7906a9389f3dd890b07a2bfbad17227 : 1174 + 0x7]
23:54:19 INFO - rbx = 0x0000000000000003 rbp = 0x0000000000000001
23:54:19 INFO - rsp = 0x00000043d5b6f4a0 r12 = 0x000001c89661af00
23:54:19 INFO - r13 = 0x0000000000000001 r14 = 0x00000000ffffffff
23:54:19 INFO - r15 = 0x00000043d5b6fa4f rip = 0x00007ffabb55eda7
23:54:19 INFO - Found by: call frame info
23:54:19 INFO - 3 xul.dll!nsThread::ProcessNextEvent(bool,bool *) [nsThread.cpp:e3762382f7906a9389f3dd890b07a2bfbad17227 : 1166 + 0x6]
23:54:19 INFO - rbx = 0x0000000000000003 rbp = 0x0000000000000001
23:54:19 INFO - rsp = 0x00000043d5b6f4d0 r12 = 0x000001c89661af00
23:54:19 INFO - r13 = 0x0000000000000001 r14 = 0x00000000ffffffff
23:54:19 INFO - r15 = 0x00000043d5b6fa4f rip = 0x00007ffab62f6c59
23:54:19 INFO - Found by: call frame info
23:54:19 INFO - 4 xul.dll!NS_ProcessNextEvent(nsIThread *,bool) [nsThreadUtils.cpp:e3762382f7906a9389f3dd890b07a2bfbad17227 : 482 + 0xd]
23:54:19 INFO - rbx = 0x0000000000000003 rbp = 0x0000000000000001
23:54:19 INFO - rsp = 0x00000043d5b6fa20 r12 = 0x000001c89661af00
23:54:19 INFO - r13 = 0x0000000000000001 r14 = 0x00000000ffffffff
23:54:19 INFO - r15 = 0x00000043d5b6fa4f rip = 0x00007ffab62fa336
23:54:19 INFO - Found by: call frame info
23:54:19 INFO - 5 xul.dll!mozilla::ipc::MessagePumpForNonMainThreads::Run(base::MessagePump::Delegate *) [MessagePump.cpp:e3762382f7906a9389f3dd890b07a2bfbad17227 : 333 + 0xa]
23:54:19 INFO - rbx = 0x0000000000000003 rbp = 0x0000000000000001
23:54:19 INFO - rsp = 0x00000043d5b6fa70 r12 = 0x000001c89661af00
23:54:19 INFO - r13 = 0x0000000000000001 r14 = 0x00000000ffffffff
23:54:19 INFO - r15 = 0x00000043d5b6fa4f rip = 0x00007ffab6a0ec4a
23:54:19 INFO - Found by: call frame info
23:54:19 INFO - 6 xul.dll!MessageLoop::RunHandler() [message_loop.cc:e3762382f7906a9389f3dd890b07a2bfbad17227 : 308 + 0x8]
23:54:19 INFO - rbx = 0x0000000000000003 rbp = 0x0000000000000001
23:54:19 INFO - rsp = 0x00000043d5b6fae0 r12 = 0x000001c89661af00
23:54:19 INFO - r13 = 0x0000000000000001 r14 = 0x00000000ffffffff
23:54:19 INFO - r15 = 0x00000043d5b6fa4f rip = 0x00007ffab69b73e2
23:54:19 INFO - Found by: call frame info
23:54:19 INFO - 7 xul.dll!MessageLoop::Run() [message_loop.cc:e3762382f7906a9389f3dd890b07a2bfbad17227 : 290 + 0x5]
23:54:19 INFO - rbx = 0x0000000000000003 rbp = 0x0000000000000001
23:54:19 INFO - rsp = 0x00000043d5b6fb30 r12 = 0x000001c89661af00
23:54:19 INFO - r13 = 0x0000000000000001 r14 = 0x00000000ffffffff
23:54:19 INFO - r15 = 0x00000043d5b6fa4f rip = 0x00007ffab69b72a1
23:54:19 INFO - Found by: call frame info
23:54:19 INFO - 8 xul.dll!nsThread::ThreadFunc(void *) [nsThread.cpp:e3762382f7906a9389f3dd890b07a2bfbad17227 : 453 + 0x8]
23:54:19 INFO - rbx = 0x0000000000000003 rbp = 0x0000000000000001
23:54:19 INFO - rsp = 0x00000043d5b6fb80 r12 = 0x000001c89661af00
23:54:19 INFO - r13 = 0x0000000000000001 r14 = 0x00000000ffffffff
23:54:19 INFO - r15 = 0x00000043d5b6fa4f rip = 0x00007ffab62f33c3
23:54:19 INFO - Found by: call frame info
23:54:19 INFO - 9 nss3.dll!PR_NativeRunThread [pruthr.c:e3762382f7906a9389f3dd890b07a2bfbad17227 : 397 + 0x7]
23:54:19 INFO - rbx = 0x0000000000000003 rbp = 0x0000000000000001
23:54:19 INFO - rsp = 0x00000043d5b6fbf0 r12 = 0x000001c89661af00
23:54:19 INFO - r13 = 0x0000000000000001 r14 = 0x00000000ffffffff
23:54:19 INFO - r15 = 0x00000043d5b6fa4f rip = 0x00007ffae7c44826
23:54:19 INFO - Found by: call frame info
23:54:19 INFO - 10 nss3.dll!static unsigned int pr_root(void *) [w95thred.c:e3762382f7906a9389f3dd890b07a2bfbad17227 : 137 + 0x6]
23:54:19 INFO - rbx = 0x0000000000000003 rbp = 0x0000000000000001
23:54:19 INFO - rsp = 0x00000043d5b6fc90 r12 = 0x000001c89661af00
23:54:19 INFO - r13 = 0x0000000000000001 r14 = 0x00000000ffffffff
23:54:19 INFO - r15 = 0x00000043d5b6fa4f rip = 0x00007ffae7c3250a
23:54:19 INFO - Found by: call frame info
23:54:19 INFO - 11 ucrtbase.dll!guard_dispatch_icall_nop + 0x11b5e
23:54:19 INFO - rbx = 0x0000000000000003 rbp = 0x0000000000000001
23:54:19 INFO - rsp = 0x00000043d5b6fcc0 r12 = 0x000001c89661af00
23:54:19 INFO - r13 = 0x0000000000000001 r14 = 0x00000000ffffffff
23:54:19 INFO - r15 = 0x00000043d5b6fa4f rip = 0x00007ffafca8c4be
23:54:19 INFO - Found by: call frame info
23:54:19 INFO - 12 ucrtbase.dll!guard_dispatch_icall_nop + 0x11b20
23:54:19 INFO - rsp = 0x00000043d5b6fcd0 rip = 0x00007ffafca8c480
23:54:19 INFO - Found by: stack scanning
23:54:19 INFO - 13 ucrtbase.dll!guard_dispatch_icall_nop + 0x11b20
23:54:19 INFO - rsp = 0x00000043d5b6fce8 rip = 0x00007ffafca8c480
23:54:19 INFO - Found by: stack scanning
23:54:19 INFO - 14 kernel32.dll!guard_dispatch_icall_nop + 0x86d4
23:54:19 INFO - rsp = 0x00000043d5b6fcf0 rip = 0x00007ffaff0b3034
23:54:19 INFO - Found by: stack scanning
23:54:19 INFO - 15 ucrtbase.dll!guard_dispatch_icall_nop + 0x11b20
23:54:19 INFO - rsp = 0x00000043d5b6fd18 rip = 0x00007ffafca8c480
23:54:19 INFO - Found by: stack scanning
23:54:19 INFO - 16 mozglue.dll!static void patched_BaseThreadInitThunk(int, void *, void *) [WindowsDllBlocklist.cpp:e3762382f7906a9389f3dd890b07a2bfbad17227 : 735 + 0xe]
23:54:19 INFO - rsp = 0x00000043d5b6fd20 rip = 0x00007ffae7e87fdb
23:54:19 INFO - Found by: stack scanning
23:54:19 INFO - 17 ntdll.dll!guard_dispatch_icall_nop + 0x66b01
23:54:19 INFO - rsp = 0x00000043d5b6fda0 rip = 0x00007ffaffa21461
23:54:19 INFO - Found by: call frame info
23:54:19 INFO - 18 KERNELBASE.dll!guard_dispatch_icall_nop + 0xe15b0
23:54:19 INFO - rsp = 0x00000043d5b6fdd0 rip = 0x00007ffafc8dbf10
23:54:19 INFO - Found by: stack scanning
23:54:19 INFO - Thread 0
23:54:19 INFO - 0 win32u.dll!NtUserMsgWaitForMultipleObjectsEx + 0x14
23:54:19 INFO - rax = 0x0000000000001436 rdx = 0x0000000000000000
23:54:19 INFO - rcx = 0x0000000000000000 rbx = 0x0000000000000000
23:54:19 INFO - rsi = 0x00000000ffffffff rdi = 0x000000000006ccd8
23:54:19 INFO - rbp = 0x00007ffaff180200 rsp = 0x00000043d65fe818
23:54:19 INFO - r8 = 0x00007ffabd5b8f0a r9 = 0x000001c8966066a0
23:54:19 INFO - r10 = 0x0000000000000000 r11 = 0x000001c8966bc840
23:54:19 INFO - r12 = 0x00007ffaff0b3d50 r13 = 0x00000043d65fe890
23:54:19 INFO - r14 = 0x00007ffaff180b40 r15 = 0x000001c8966b8110
23:54:19 INFO - rip = 0x00007ffafc5996e4
23:54:19 INFO - Found by: given as instruction pointer in context
23:54:19 INFO - 1 user32.dll!guard_dispatch_icall_nop + 0x1593d
23:54:19 INFO - rbx = 0x0000000000000000 rbp = 0x00007ffaff180200
23:54:19 INFO - rsp = 0x00000043d65fe820 r12 = 0x00007ffaff0b3d50
23:54:19 INFO - r13 = 0x00000043d65fe890 r14 = 0x00007ffaff180b40
23:54:19 INFO - r15 = 0x000001c8966b8110 rip = 0x00007ffaff18029d
23:54:19 INFO - Found by: call frame info
23:54:19 INFO - 2 nss3.dll + 0x142ed0
23:54:19 INFO - rbp = 0x00007ffaff180200 rsp = 0x00000043d65fe828
23:54:19 INFO - rip = 0x00007ffae7c32ed0
23:54:19 INFO - Found by: stack scanning
23:54:19 INFO - 3 xul.dll!mozilla::BlockingResourceBase::CheckAcquire() [BlockingResourceBase.cpp:e3762382f7906a9389f3dd890b07a2bfbad17227 : 284 + 0x10]
23:54:19 INFO - rbp = 0x00007ffaff180200 rsp = 0x00000043d65fe830
23:54:19 INFO - rip = 0x00007ffab62d597b
23:54:19 INFO - Found by: stack scanning

Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
Status: REOPENED → RESOLVED
Closed: 5 years ago5 years ago
Resolution: --- → INCOMPLETE

Don't mark intermittent crashes as P5s. We want them to go to triage owners.

Priority: P5 → --

Fixed by bug 1554244.

Status: REOPENED → RESOLVED
Closed: 5 years ago5 years ago
Resolution: --- → FIXED
Assignee: nobody → jld
Target Milestone: --- → mozilla69

Mass-editing the bug 1554244 duplicates to set qe-verify -: they're intermittents with no reliable STR, so if we stop seeing them on CI then it's safe to say they're fixed.

Flags: qe-verify-
You need to log in before you can comment on or make changes to this bug.