1373560 - Intermittent marionette.py | application crashed [@ IPC::Message::`scalar deleting destructor'(unsigned int)]

Status: RESOLVED INCOMPLETE

(Core :: IPC, defect)

Description

[Treeherder Bug Filer]

Filed by: archaeopteryx [at] coole-files.de

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

http://mozilla-releng-blobs.s3.amazonaws.com/blobs/autoland/sha512/31a634d79d2457b43b5e556a194b49beec2330f9d601d05e2c2ae28a7f5035c96aa60d34fe153320ac1bbbb9a7a333ee43ac9b450f1433390719bfd5720718f5

Comment 1

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

Hm, we haven't had this signature for a while now but as far as I can remember it is not the real underlying crash. There is one more listed in the log which should be the one we have to set here. Ted, is this correct?

If yes it will be:
https://treeherder.mozilla.org/logviewer.html#?job_id=107563542&repo=autoland&lineNumber=5602

> PROCESS-CRASH | marionette.py | application crashed [@ RtlImageNtHeaderEx + 0x57]

The first frame of our code is:

> xul.dll!base::MessagePumpForIO::GetIOItem(unsigned long,base::MessagePumpForIO::IOItem *) [message_pump_win.cc:64a2ba65f0d6 : 509 + 0x30]

Could the landed changes on bug 1366072 have been caused this?

Comment 2

[(not currently active) Ted Mielczarek]

This is the content process hanging, and the browser process writing out minidumps for both processes (and then presumably exiting due to MOZ_CRASHREPORTER_SHUTDOWN being set).

Frame 2 of the first minidump's stack has:
2  xul.dll!CrashReporter::CreateMinidumpsAndPair(...)

...which is always a sign that this was intentional. As you correctly pointed out, the second minidump has RtlImageNtHeaderEx as its top frame, which is presumably where the content process was hung.

Comment 3

[Intermittent Failures Robot]

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

Repository breakdown:
* autoland: 1

Platform breakdown:
* windows8-64: 1

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

Comment 4

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

(In reply to Ted Mielczarek [:ted.mielczarek] from comment #2)
> This is the content process hanging, and the browser process writing out
> minidumps for both processes (and then presumably exiting due to
> MOZ_CRASHREPORTER_SHUTDOWN being set).

Hm, shouldn't we wait with the final shutdown until the minidumps have been completely written to disk? We exit normally when MOZ_CRASHREPORTER_SHUTDOWN (bug 1370520) is set, so this is scary to see. 

> Frame 2 of the first minidump's stack has:
> 2  xul.dll!CrashReporter::CreateMinidumpsAndPair(...)
> 
> ...which is always a sign that this was intentional. As you correctly
> pointed out, the second minidump has RtlImageNtHeaderEx as its top frame,
> which is presumably where the content process was hung.

Ok, so the crashing thread here is 0, which should be the main thread. So this cannot be the content process then, right? Or is that the main thread of the content process? Would be at least reasonable.

Here the first 10 stack frames:

22:44:05     INFO -  Crash reason:  EXCEPTION_BREAKPOINT
22:44:05     INFO -  Crash address: 0x7f978caf247
22:44:05     INFO -  Process uptime: 17 seconds
22:44:05     INFO -  Thread 0 (crashed)
22:44:05     INFO -   0  ntdll.dll!RtlImageNtHeaderEx + 0x57
22:44:05     INFO -      rax = 0x0000000000000000   rdx = 0x000000cd29ce0000
22:44:05     INFO -      rcx = 0x0000000000005a4d   rbx = 0x0000000000000000
22:44:05     INFO -      rsi = 0x000000cd2533dd80   rdi = 0x0000000000000001
22:44:05     INFO -      rbp = 0x000000cd1bc54dd0   rsp = 0x000000cd1bc54c80
22:44:05     INFO -       r8 = 0x0000000000000000    r9 = 0x000000cd1bc54d48
22:44:05     INFO -      r10 = 0x0000000000000000   r11 = 0x0000000000000000
22:44:05     INFO -      r12 = 0x0000000000000000   r13 = 0x0000000000000000
22:44:05     INFO -      r14 = 0x000000cd1bc54eb8   r15 = 0x000000cd1bc54ec8
22:44:05     INFO -      rip = 0x000007f978caf247
22:44:05     INFO -      Found by: given as instruction pointer in context
22:44:05     INFO -   1  ntdll.dll!LdrpMapResourceFile + 0x24a
22:44:05     INFO -      rbp = 0x000000cd1bc54dd0   rsp = 0x000000cd1bc54cd0
22:44:05     INFO -      rip = 0x000007f978cc8492
22:44:05     INFO -      Found by: stack scanning
22:44:05     INFO -  Thread 1
22:44:05     INFO -   0  ntdll.dll!ZwRemoveIoCompletion + 0xa
22:44:05     INFO -      rax = 0x000000cd285fbdc0   rdx = 0x000000cd1c07c0d0
22:44:05     INFO -      rcx = 0x000000cd24c48480   rbx = 0x000000cd216bf5a0
22:44:05     INFO -      rsi = 0x0000000000000000   rdi = 0x000000cd216bf5d0
22:44:05     INFO -      rbp = 0x00000000ffffffff   rsp = 0x000000cd216bf4b8
22:44:05     INFO -       r8 = 0x000000cd24038fb8    r9 = 0x0000000000002f60
22:44:05     INFO -      r10 = 0x00000000ffc00000   r11 = 0x0000000000000000
22:44:05     INFO -      r12 = 0x0000000000000000   r13 = 0x0000000000000000
22:44:05     INFO -      r14 = 0x0000000000000000   r15 = 0x0000000000000000
22:44:05     INFO -      rip = 0x000007f978ca2c3a
22:44:05     INFO -      Found by: given as instruction pointer in context
22:44:05     INFO -   1  KERNELBASE.dll!GetQueuedCompletionStatus + 0x3d
22:44:05     INFO -      rsp = 0x000000cd216bf4c0   rip = 0x000007f975d536ad
22:44:05     INFO -      Found by: stack scanning
22:44:05     INFO -   2  xul.dll!IPC::Message::`scalar deleting destructor'(unsigned int) + 0x30
22:44:05     INFO -      rsp = 0x000000cd216bf4e0   rip = 0x000007f956bc5fcc
22:44:05     INFO -      Found by: stack scanning
22:44:05     INFO -   3  0x8dc
22:44:05     INFO -      rsp = 0x000000cd216bf510   rip = 0x00000000000008dc
22:44:05     INFO -      Found by: call frame info
22:44:05     INFO -   4  kernel32.dll!GetQueuedCompletionStatusStub + 0x12
22:44:05     INFO -      rsp = 0x000000cd216bf520   rip = 0x000007f976d21962
22:44:05     INFO -      Found by: stack scanning
22:44:05     INFO -   5  xul.dll!base::MessagePumpForIO::GetIOItem(unsigned long,base::MessagePumpForIO::IOItem *) [message_pump_win.cc:64a2ba65f0d6 : 509 + 0x30]
22:44:05     INFO -      rsp = 0x000000cd216bf560   rip = 0x000007f956bb60be
22:44:05     INFO -      Found by: stack scanning
22:44:05     INFO -   6  xul.dll!base::MessagePumpForIO::WaitForIOCompletion(unsigned long,base::MessagePumpForIO::IOHandler *) [message_pump_win.cc:64a2ba65f0d6 : 481 + 0xf]
22:44:05     INFO -      rsp = 0x000000cd216bf5a0   rip = 0x000007f956bb6618
22:44:05     INFO -      Found by: call frame info
22:44:05     INFO -   7  xul.dll!base::MessagePumpForIO::DoRunLoop() [message_pump_win.cc:64a2ba65f0d6 : 459 + 0x8]
22:44:05     INFO -      rsp = 0x000000cd216bf5f0   rip = 0x000007f956bb5f33
22:44:05     INFO -      Found by: call frame info
22:44:05     INFO -   8  xul.dll!base::MessagePumpWin::RunWithDispatcher(base::MessagePump::Delegate *,base::MessagePumpWin::Dispatcher *) [message_pump_win.cc:64a2ba65f0d6 : 56 + 0x6]
22:44:05     INFO -      rsp = 0x000000cd216bf620   rip = 0x000007f956bb64ea
22:44:05     INFO -      Found by: call frame info
22:44:05     INFO -   9  xul.dll!MessageLoop::RunHandler() [message_loop.cc:64a2ba65f0d6 : 311 + 0xf]
22:44:05     INFO -      rsp = 0x000000cd216bf670   rip = 0x000007f956bc1e93
22:44:05     INFO -      Found by: call frame info
22:44:05     INFO -  10  xul.dll!MessageLoop::Run() [message_loop.cc:64a2ba65f0d6 : 291 + 0x8]
22:44:05     INFO -      rsp = 0x000000cd216bf6a0   rip = 0x000007f956bc1baa
22:44:05     INFO -      Found by: call frame info