Bug 1622931 Comment 8 Edit History

Note: The actual edited comment in the bug view page will always show the original commenter’s name and original timestamp.

Summarizing what I know so far:
- there are two related crashes under this signature, one in the server's "AudioIPC Callback RPC" thread and one in the client's "AudioIPC Client RPC" thread
- both crashes are the same `expect("unexpected execution error")` inside tokio under spawn_thread's call to [Runtime::block_on](https://searchfox.org/mozilla-central/rev/54f965e51e4f77866bec42737978d40d4c1fdfc5/media/audioipc/audioipc/src/core.rs#66), caused by an unknown internal error
   - current suspect is a failing `GetQueuedCompletionStatusEx` call in [miow](https://github.com/yoshuawuyts/miow/blob/38faaa697e6c7867be628b361800415c664fdaf8/src/iocp.rs#L155)
- "available page file" is < 42MB for every crash with this signature in the last month
  - most are < 10MB

For crash [4fe6d133-db30-477f-bd10-b3c8f0200430](https://crash-stats.mozilla.org/report/index/4fe6d133-db30-477f-bd10-b3c8f0200430), the complete stack is:
```
 # ChildEBP RetAddr  
00 (Inline) -------- xul!MOZ_Crash+0xb [/builds/worker/workspace/obj-build/dist/include/mozilla/Assertions.h @ 332] 
01 17aff56c 59e28512 xul!RustMozCrash+0x11 [/builds/worker/checkouts/gecko/mozglue/static/rust/wrappers.cpp @ 16] 
02 17aff998 59e2848a xul!mozglue_static::panic_hook+0x82 [/builds/worker/checkouts/gecko/mozglue/static/rust/lib.rs @ 71] 
03 17aff9a0 59f11eaf xul!core::ops::function::Fn::call<fn(core::panic::PanicInfo*),(core::panic::PanicInfo*)>+0xa [/rustc/f3e1a954d2ead4e2fc197c7da7d71e6c61bad196\src\libcore\ops\function.rs @ 72] 
04 17affa50 59f16bcc xul!std::panicking::rust_panic_with_hook+0x14f [/rustc/f3e1a954d2ead4e2fc197c7da7d71e6c61bad196\/src\libstd\panicking.rs @ 475] 
05 17affa98 59c57e50 xul!std::panicking::begin_panic_handler+0x4c [/rustc/f3e1a954d2ead4e2fc197c7da7d71e6c61bad196\/src\libstd\panicking.rs @ 375] 
06 17affaac 59c5d4ed xul!core::panicking::panic_fmt+0x20 [/rustc/f3e1a954d2ead4e2fc197c7da7d71e6c61bad196\/src\libcore\panicking.rs @ 84] 
07 17affad8 59bd3a94 xul!core::option::expect_failed+0x4d [/rustc/f3e1a954d2ead4e2fc197c7da7d71e6c61bad196\/src\libcore\option.rs @ 1188] 
08 17affe3c 59bd1615 xul!audioipc::core::spawn_thread::{{closure}}<str*,closure-1,closure-2>+0x2474 [/builds/worker/checkouts/gecko/media/audioipc/audioipc/src/core.rs @ 69] 
09 17affe64 59bd159b xul!std::sys_common::backtrace::__rust_begin_short_backtrace<closure-0,()>+0x35 [/rustc/f3e1a954d2ead4e2fc197c7da7d71e6c61bad196\src\libstd\sys_common\backtrace.rs @ 137] 
0a (Inline) -------- xul!std::thread::{{impl}}::spawn_unchecked::{{closure}}::{{closure}}+0x30 [/rustc/f3e1a954d2ead4e2fc197c7da7d71e6c61bad196\src\libstd\thread\mod.rs @ 469] 
0b (Inline) -------- xul!std::panic::{{impl}}::call_once+0x30 [/rustc/f3e1a954d2ead4e2fc197c7da7d71e6c61bad196\src\libstd\panic.rs @ 318] 
0c (Inline) -------- xul!std::panicking::try::do_call+0x30 [/rustc/f3e1a954d2ead4e2fc197c7da7d71e6c61bad196\src\libstd\panicking.rs @ 292] 
0d (Inline) -------- xul!panic_abort::__rust_maybe_catch_panic+0x30 [/rustc/f3e1a954d2ead4e2fc197c7da7d71e6c61bad196\/src\libpanic_abort\lib.rs @ 28] 
0e (Inline) -------- xul!std::panicking::try+0x30 [/rustc/f3e1a954d2ead4e2fc197c7da7d71e6c61bad196\src\libstd\panicking.rs @ 270] 
0f (Inline) -------- xul!std::panic::catch_unwind+0x30 [/rustc/f3e1a954d2ead4e2fc197c7da7d71e6c61bad196\src\libstd\panic.rs @ 394] 
10 (Inline) -------- xul!std::thread::{{impl}}::spawn_unchecked::{{closure}}+0x50 [/rustc/f3e1a954d2ead4e2fc197c7da7d71e6c61bad196\src\libstd\thread\mod.rs @ 468] 
11 17affe94 59f1f04b xul!core::ops::function::FnOnce::call_once<closure-0,()>+0x5b [/rustc/f3e1a954d2ead4e2fc197c7da7d71e6c61bad196\src\libcore\ops\function.rs @ 232] 
12 17affefc 59f20d75 xul!alloc::boxed::{{impl}}::call_once<(),FnOnce<()>>+0x3b [/rustc/f3e1a954d2ead4e2fc197c7da7d71e6c61bad196\src\liballoc\boxed.rs @ 1022] 
13 (Inline) -------- xul!alloc::boxed::{{impl}}::call_once+0xe [/rustc/f3e1a954d2ead4e2fc197c7da7d71e6c61bad196\src\liballoc\boxed.rs @ 1022] 
14 (Inline) -------- xul!std::sys_common::thread::start_thread+0x53 [/rustc/f3e1a954d2ead4e2fc197c7da7d71e6c61bad196\/src\libstd\sys_common\thread.rs @ 13] 
15 17afff08 748d38f4 xul!std::sys::windows::thread::{{impl}}::new::thread_start+0x55 [/rustc/f3e1a954d2ead4e2fc197c7da7d71e6c61bad196\/src\libstd\sys\windows\thread.rs @ 51] 
16 17afff1c 772b5de3 kernel32!BaseThreadInitThunk+0x24
17 17afff64 772b5dae ntdll!__RtlUserThreadStart+0x2f
18 17afff74 00000000 ntdll!_RtlUserThreadStart+0x1b
```

Frame 8 is the frame of interest, but it's fairly difficult to make sense of in minidumps as it's an ~11kB compiled function with an 868 byte stack frame.  As far as I can tell (trusting Ghidra's control flow analysis), `expect_failed` was preceded by a call to `tokio_reactor::Reactor::turn`.  Internally, `turn` may call `mio::Poll::poll`, which eventually makes the assumed-to-be failing `GetQueuedCompletionStatusEx` reachable via a call to `miow::CompletionPort::get_many`.

Currently trying to reproduce locally with in a VM with low page file, and continuing analysis of dumps.  Also looking into locally forking miow to add additional debugging around GetQueuedCompletionStatusEx.
Summarizing what I know so far:
- there are two related crashes under this signature, one in the server's "AudioIPC Callback RPC" thread and one in the client's "AudioIPC Client RPC" thread
- both crashes are the same `expect("unexpected execution error")` inside tokio under spawn_thread's call to [Runtime::block_on](https://searchfox.org/mozilla-central/rev/54f965e51e4f77866bec42737978d40d4c1fdfc5/media/audioipc/audioipc/src/core.rs#66), caused by an unknown internal error
   - current suspect is a failing `GetQueuedCompletionStatusEx` call in [miow](https://github.com/yoshuawuyts/miow/blob/38faaa697e6c7867be628b361800415c664fdaf8/src/iocp.rs#L155)
- "available page file" is < 42MB for every crash with this signature in the last month
  - most are < 10MB

For crash [4fe6d133-db30-477f-bd10-b3c8f0200430](https://crash-stats.mozilla.org/report/index/4fe6d133-db30-477f-bd10-b3c8f0200430), the complete stack is:
```
 # ChildEBP RetAddr  
00 (Inline) -------- xul!MOZ_Crash+0xb [/builds/worker/workspace/obj-build/dist/include/mozilla/Assertions.h @ 332] 
01 17aff56c 59e28512 xul!RustMozCrash+0x11 [/builds/worker/checkouts/gecko/mozglue/static/rust/wrappers.cpp @ 16] 
02 17aff998 59e2848a xul!mozglue_static::panic_hook+0x82 [/builds/worker/checkouts/gecko/mozglue/static/rust/lib.rs @ 71] 
03 17aff9a0 59f11eaf xul!core::ops::function::Fn::call<fn(core::panic::PanicInfo*),(core::panic::PanicInfo*)>+0xa [/rustc/f3e1a954d2ead4e2fc197c7da7d71e6c61bad196\src\libcore\ops\function.rs @ 72] 
04 17affa50 59f16bcc xul!std::panicking::rust_panic_with_hook+0x14f [/rustc/f3e1a954d2ead4e2fc197c7da7d71e6c61bad196\/src\libstd\panicking.rs @ 475] 
05 17affa98 59c57e50 xul!std::panicking::begin_panic_handler+0x4c [/rustc/f3e1a954d2ead4e2fc197c7da7d71e6c61bad196\/src\libstd\panicking.rs @ 375] 
06 17affaac 59c5d4ed xul!core::panicking::panic_fmt+0x20 [/rustc/f3e1a954d2ead4e2fc197c7da7d71e6c61bad196\/src\libcore\panicking.rs @ 84] 
07 17affad8 59bd3a94 xul!core::option::expect_failed+0x4d [/rustc/f3e1a954d2ead4e2fc197c7da7d71e6c61bad196\/src\libcore\option.rs @ 1188] 
08 17affe3c 59bd1615 xul!audioipc::core::spawn_thread::{{closure}}<str*,closure-1,closure-2>+0x2474 [/builds/worker/checkouts/gecko/media/audioipc/audioipc/src/core.rs @ 69] 
09 17affe64 59bd159b xul!std::sys_common::backtrace::__rust_begin_short_backtrace<closure-0,()>+0x35 [/rustc/f3e1a954d2ead4e2fc197c7da7d71e6c61bad196\src\libstd\sys_common\backtrace.rs @ 137] 
0a (Inline) -------- xul!std::thread::{{impl}}::spawn_unchecked::{{closure}}::{{closure}}+0x30 [/rustc/f3e1a954d2ead4e2fc197c7da7d71e6c61bad196\src\libstd\thread\mod.rs @ 469] 
0b (Inline) -------- xul!std::panic::{{impl}}::call_once+0x30 [/rustc/f3e1a954d2ead4e2fc197c7da7d71e6c61bad196\src\libstd\panic.rs @ 318] 
0c (Inline) -------- xul!std::panicking::try::do_call+0x30 [/rustc/f3e1a954d2ead4e2fc197c7da7d71e6c61bad196\src\libstd\panicking.rs @ 292] 
0d (Inline) -------- xul!panic_abort::__rust_maybe_catch_panic+0x30 [/rustc/f3e1a954d2ead4e2fc197c7da7d71e6c61bad196\/src\libpanic_abort\lib.rs @ 28] 
0e (Inline) -------- xul!std::panicking::try+0x30 [/rustc/f3e1a954d2ead4e2fc197c7da7d71e6c61bad196\src\libstd\panicking.rs @ 270] 
0f (Inline) -------- xul!std::panic::catch_unwind+0x30 [/rustc/f3e1a954d2ead4e2fc197c7da7d71e6c61bad196\src\libstd\panic.rs @ 394] 
10 (Inline) -------- xul!std::thread::{{impl}}::spawn_unchecked::{{closure}}+0x50 [/rustc/f3e1a954d2ead4e2fc197c7da7d71e6c61bad196\src\libstd\thread\mod.rs @ 468] 
11 17affe94 59f1f04b xul!core::ops::function::FnOnce::call_once<closure-0,()>+0x5b [/rustc/f3e1a954d2ead4e2fc197c7da7d71e6c61bad196\src\libcore\ops\function.rs @ 232] 
12 17affefc 59f20d75 xul!alloc::boxed::{{impl}}::call_once<(),FnOnce<()>>+0x3b [/rustc/f3e1a954d2ead4e2fc197c7da7d71e6c61bad196\src\liballoc\boxed.rs @ 1022] 
13 (Inline) -------- xul!alloc::boxed::{{impl}}::call_once+0xe [/rustc/f3e1a954d2ead4e2fc197c7da7d71e6c61bad196\src\liballoc\boxed.rs @ 1022] 
14 (Inline) -------- xul!std::sys_common::thread::start_thread+0x53 [/rustc/f3e1a954d2ead4e2fc197c7da7d71e6c61bad196\/src\libstd\sys_common\thread.rs @ 13] 
15 17afff08 748d38f4 xul!std::sys::windows::thread::{{impl}}::new::thread_start+0x55 [/rustc/f3e1a954d2ead4e2fc197c7da7d71e6c61bad196\/src\libstd\sys\windows\thread.rs @ 51] 
16 17afff1c 772b5de3 kernel32!BaseThreadInitThunk+0x24
17 17afff64 772b5dae ntdll!__RtlUserThreadStart+0x2f
18 17afff74 00000000 ntdll!_RtlUserThreadStart+0x1b
```

Frame 8 is the frame of interest, but it's fairly difficult to make sense of in minidumps as it's an ~11kB compiled function with an 868 byte stack frame.  As far as I can tell (trusting Ghidra's control flow analysis), `expect_failed` was preceded by a call to `tokio_reactor::Reactor::turn`.  Internally, `turn` may call `mio::Poll::poll`, which eventually makes the assumed-to-be failing `GetQueuedCompletionStatusEx` reachable via a call to `miow::CompletionPort::get_many`, e.g. (captured from a [unrelated](https://crash-stats.mozilla.org/report/index/1f38d39a-9084-4377-b8b4-8ee180200505#allthreads) crash report):
```
Frame 	Module 	Signature 	Source
0 	ntdll.dll 	KiFastSystemCallRet 	
1 	ntdll.dll 	NtRemoveIoCompletionEx 	
2 	KERNELBASE.dll 	GetQueuedCompletionStatusEx 	
3 	xul.dll 	miow::iocp::CompletionPort::get_many(mut slice<miow::iocp::CompletionStatus>*, core::option::Option<core::time::Duration>) 	third_party/rust/miow-0.2.1/src/iocp.rs:146
4 	xul.dll 	mio::poll::Poll::poll1(mio::poll::Events*, core::option::Option<core::time::Duration>, bool) 	third_party/rust/mio/src/poll.rs:1139
5 	xul.dll 	tokio_reactor::Reactor::turn(core::option::Option<core::time::Duration>) 	third_party/rust/tokio-reactor/src/lib.rs:327
6 	xul.dll 	tokio::runtime::current_thread::runtime::Runtime::block_on<futures::sync::oneshot::Receiver<()>>(futures::sync::oneshot::Receiver<()>) 	third_party/rust/tokio-0.1.11/src/runtime/current_thread/runtime.rs:182
7 	xul.dll 	std::sys_common::backtrace::__rust_begin_short_backtrace<closure-0, ()>(audioipc::core::spawn_thread::closure-0) 	../f3e1a954d2ead4e2fc197c7da7d71e6c61bad196/src/libstd/sys_common/backtrace.rs:136
8 	xul.dll 	core::ops::function::FnOnce::call_once<closure-0, ()>(std::thread::{{impl}}::spawn_unchecked::closure-0*) 	../f3e1a954d2ead4e2fc197c7da7d71e6c61bad196/src/libcore/ops/function.rs:232
9 	xul.dll 	alloc::boxed::{{impl}}::call_once<(), FnOnce<()>>() 	../f3e1a954d2ead4e2fc197c7da7d71e6c61bad196/src/liballoc/boxed.rs:1022
10 	xul.dll 	std::sys::windows::thread::{{impl}}::new::thread_start() 	../f3e1a954d2ead4e2fc197c7da7d71e6c61bad196//src/libstd/sys/windows/thread.rs:51
11 	kernel32.dll 	BaseThreadInitThunk 	
12 	ntdll.dll 	__RtlUserThreadStart 	
13 	ntdll.dll 	_RtlUserThreadStart 	
```

Currently trying to reproduce locally with in a VM with low page file, and continuing analysis of dumps.  Also looking into locally forking miow to add additional debugging around GetQueuedCompletionStatusEx.

Back to Bug 1622931 Comment 8