Open Bug 1611555 Opened 5 years ago Updated 3 years ago

Perma PROCESS-CRASH | damp | application crashed [@ AslHashFree + 0x35028]

Categories

(Core :: Gecko Profiler, defect, P2)

Product:
Core
Component:
Gecko Profiler
Type:
defect

Tracking

()

People

(Reporter: intermittent-bug-filer, Unassigned)

References

Details

(Keywords: crash)

Crash Data

Filed by: nbeleuzu [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer.html#?job_id=286434336&repo=mozilla-central
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/Irlr0HnQTG2zNbMvLAsuJg/runs/0/artifacts/public/logs/live_backing.log

[task 2020-01-25T00:21:32.672Z] 00:21:32 INFO - TEST-INFO | 4516: exit 0
[task 2020-01-25T00:21:32.674Z] 00:21:32 INFO - mozcrash Downloading symbols from: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/bzHPdRYcT-md6Q_NhG8x0A/artifacts/public/build/target.crashreporter-symbols.zip
[task 2020-01-25T00:21:35.121Z] 00:21:35 INFO - mozcrash Copy/paste: C:\Users\task_1579907993\build\win32-minidump_stackwalk.exe c:\users\task_1579907993\appdata\local\temp\tmpfzvnqh\profile\minidumps\19e11e21-9855-4d6f-8941-713a8801bb60-browser.dmp c:\users\task_1579907993\appdata\local\temp\tmpzz06am
[task 2020-01-25T00:21:40.412Z] 00:21:40 INFO - mozcrash Saved minidump as C:\Users\task_1579907993\build\blobber_upload_dir\19e11e21-9855-4d6f-8941-713a8801bb60-browser.dmp
[task 2020-01-25T00:21:40.414Z] 00:21:40 INFO - PROCESS-CRASH | damp | application crashed [@ static google_breakpad::ExceptionHandler::WriteMinidump(std::basic_string<wchar_t,std::char_traits<wchar_t>,std::allocator<wchar_t> > const&, bool ()(wchar_t const, wchar_t const*, void*, _EXCEPTION_POINTERS*, MDRawAssertionInfo*, mozilla::phc::AddrInfo const*, bool), void*, _MINIDUMP_TYPE)]
[task 2020-01-25T00:21:40.414Z] 00:21:40 INFO - Crash dump filename: c:\users\task_1579907993\appdata\local\temp\tmpfzvnqh\profile\minidumps\19e11e21-9855-4d6f-8941-713a8801bb60-browser.dmp
[task 2020-01-25T00:21:40.415Z] 00:21:40 INFO - Operating system: Windows NT
[task 2020-01-25T00:21:40.415Z] 00:21:40 INFO - 10.0.15063
[task 2020-01-25T00:21:40.415Z] 00:21:40 INFO - CPU: amd64
[task 2020-01-25T00:21:40.416Z] 00:21:40 INFO - family 6 model 94 stepping 3
[task 2020-01-25T00:21:40.416Z] 00:21:40 INFO - 8 CPUs
[task 2020-01-25T00:21:40.416Z] 00:21:40 INFO - GPU: UNKNOWN
[task 2020-01-25T00:21:40.416Z] 00:21:40 INFO - Crash reason: EXCEPTION_NONCONTINUABLE_EXCEPTION
[task 2020-01-25T00:21:40.416Z] 00:21:40 INFO - Crash address: 0x0
[task 2020-01-25T00:21:40.417Z] 00:21:40 INFO - Process uptime: 53 seconds
[task 2020-01-25T00:21:40.417Z] 00:21:40 INFO - Thread 0 (crashed)
[task 2020-01-25T00:21:40.417Z] 00:21:40 INFO - 0 xul.dll!static google_breakpad::ExceptionHandler::WriteMinidump(std::basic_string<wchar_t,std::char_traits<wchar_t>,std::allocator<wchar_t> > const&, bool ()(wchar_t const, wchar_t const*, void*, _EXCEPTION_POINTERS*, MDRawAssertionInfo*, mozilla::phc::AddrInfo const*, bool), void*, _MINIDUMP_TYPE) [exception_handler.cc:6f6e201853c8f5053d6f8837acf89e76f5a334c5 : 775 + 0x8a]
[task 2020-01-25T00:21:40.417Z] 00:21:40 INFO - rax = 0x00000042129fe440 rdx = 0x00000042129fdf70
[task 2020-01-25T00:21:40.417Z] 00:21:40 INFO - rcx = 0x00000042129fdf70 rbx = 0x0000000000001498
[task 2020-01-25T00:21:40.418Z] 00:21:40 INFO - rsi = 0x00000042129fde10 rdi = 0x00000042129fdf70
[task 2020-01-25T00:21:40.418Z] 00:21:40 INFO - rbp = 0x0000000000001388 rsp = 0x00000042129fddd0
[task 2020-01-25T00:21:40.418Z] 00:21:40 INFO - r8 = 0x00000000000004d0 r9 = 0x0000000000000000
[task 2020-01-25T00:21:40.418Z] 00:21:40 INFO - r10 = 0x00000042129fda60 r11 = 0x00000042129fdf70
[task 2020-01-25T00:21:40.418Z] 00:21:40 INFO - r12 = 0x00000042129fe560 r13 = 0x00000042129fef5f
[task 2020-01-25T00:21:40.419Z] 00:21:40 INFO - r14 = 0x00000042129fe670 r15 = 0x00000042129fe540
[task 2020-01-25T00:21:40.419Z] 00:21:40 INFO - rip = 0x00007ffd99576954
[task 2020-01-25T00:21:40.419Z] 00:21:40 INFO - Found by: given as instruction pointer in context
[task 2020-01-25T00:21:40.419Z] 00:21:40 INFO - 1 xul.dll!CrashReporter::CreateMinidumpsAndPair(void*, unsigned long, nsTSubstring<char> const&, nsIFile*, mozilla::EnumeratedArray<CrashReporter::Annotation,CrashReporter::Annotation::Count,nsTString<char> >&, nsIFile**) [nsExceptionHandler.cpp:6f6e201853c8f5053d6f8837acf89e76f5a334c5 : 3862 + 0x1e]
[task 2020-01-25T00:21:40.419Z] 00:21:40 INFO - rbx = 0x0000000000001498 rbp = 0x0000000000001388
[task 2020-01-25T00:21:40.419Z] 00:21:40 INFO - rsp = 0x00000042129fe500 r12 = 0x00000042129fe560
[task 2020-01-25T00:21:40.420Z] 00:21:40 INFO - r13 = 0x00000042129fef5f r14 = 0x00000042129fe670
[task 2020-01-25T00:21:40.420Z] 00:21:40 INFO - r15 = 0x00000042129fe540 rip = 0x00007ffd99570304
[task 2020-01-25T00:21:40.420Z] 00:21:40 INFO - Found by: call frame info
[task 2020-01-25T00:21:40.420Z] 00:21:40 INFO - 2 xul.dll!mozilla::ipc::CrashReporterHost::GenerateMinidumpAndPair<mozilla::dom::ContentParent>(mozilla::dom::ContentParent*, nsIFile*, nsTSubstring<char> const&) [CrashReporterHost.h:6f6e201853c8f5053d6f8837acf89e76f5a334c5 : 74 + 0x28]
[task 2020-01-25T00:21:40.420Z] 00:21:40 INFO - rbx = 0x0000000000001498 rbp = 0x0000000000001388
[task 2020-01-25T00:21:40.421Z] 00:21:40 INFO - rsp = 0x00000042129fe5e0 r12 = 0x00000042129fe560
[task 2020-01-25T00:21:40.421Z] 00:21:40 INFO - r13 = 0x00000042129fef5f r14 = 0x00000042129fe670
[task 2020-01-25T00:21:40.421Z] 00:21:40 INFO - r15 = 0x00000042129fe540 rip = 0x00007ffd9849fcd0
[task 2020-01-25T00:21:40.421Z] 00:21:40 INFO - Found by: call frame info
[task 2020-01-25T00:21:40.421Z] 00:21:40 INFO - 3 xul.dll!mozilla::dom::ContentParent::GeneratePairedMinidump(char const*) [ContentParent.cpp:6f6e201853c8f5053d6f8837acf89e76f5a334c5 : 3588 + 0x8]
[task 2020-01-25T00:21:40.421Z] 00:21:40 INFO - rbx = 0x0000000000001498 rbp = 0x0000000000001388
[task 2020-01-25T00:21:40.422Z] 00:21:40 INFO - rsp = 0x00000042129fe650 r12 = 0x00000042129fe560

This is a content process shutdown hang. It seems that a content process is stuck here for more than a minute during shutdown. It's possible that it's not really stuck but just being slow, I'll investigate on Monday.

As per comment 1, the content process seems to be waiting (or stuck?) somewhere while trying to grab a profile.

Component: Crash Reporting → Gecko Profiler
Product: Toolkit → Core

Maybe the same issue as bug 1613798?

Priority: -- → P2

They're similar issues but the stacks are different. In this case it seems like the child process has not received the shutdown IPC message at all.

Isn't that just a dupe of bug 1538088? Gabriele, as we talked about recently we shouldn't classify failures like that but actually use the first crash report as listed. So this bug should cover the following crash, right?

[task 2020-01-25T00:21:45.260Z] 00:21:45     INFO -  Crash address: 0x7ffdc03b8be4
[task 2020-01-25T00:21:45.260Z] 00:21:45     INFO -  Process uptime: 7 seconds
[task 2020-01-25T00:21:45.260Z] 00:21:45     INFO -  Thread 0 (crashed)
[task 2020-01-25T00:21:45.261Z] 00:21:45     INFO -   0  ntdll.dll!AslHashFree + 0x35028
[task 2020-01-25T00:21:45.261Z] 00:21:45     INFO -      rax = 0x0000000000000003   rdx = 0x0000000000000000
[task 2020-01-25T00:21:45.261Z] 00:21:45     INFO -      rcx = 0x000000000000011b   rbx = 0x0000000000000000
[task 2020-01-25T00:21:45.261Z] 00:21:45     INFO -      rsi = 0x0000018412237230   rdi = 0x0000000000000000
[task 2020-01-25T00:21:45.261Z] 00:21:45     INFO -      rbp = 0x0000004ae77fd100   rsp = 0x0000004ae77fd0a8
[task 2020-01-25T00:21:45.261Z] 00:21:45     INFO -       r8 = 0x0000000000000000    r9 = 0x0000000000000000
[task 2020-01-25T00:21:45.262Z] 00:21:45     INFO -      r10 = 0x0000018412237230   r11 = 0x0000018412237268
[task 2020-01-25T00:21:45.262Z] 00:21:45     INFO -      r12 = 0x0000000000000000   r13 = 0x0000000000000000
[task 2020-01-25T00:21:45.262Z] 00:21:45     INFO -      r14 = 0x0000000000000000   r15 = 0x0000018412237268
[task 2020-01-25T00:21:45.262Z] 00:21:45     INFO -      rip = 0x00007ffdc03b8be4
[task 2020-01-25T00:21:45.262Z] 00:21:45     INFO -      Found by: given as instruction pointer in context
[task 2020-01-25T00:21:45.263Z] 00:21:45     INFO -   1  ntdll.dll!SdbResolveDatabase + 0x8d
[task 2020-01-25T00:21:45.263Z] 00:21:45     INFO -      rbp = 0x0000004ae77fd100   rsp = 0x0000004ae77fd0b0
[task 2020-01-25T00:21:45.263Z] 00:21:45     INFO -      rip = 0x00007ffdc0380009
[task 2020-01-25T00:21:45.263Z] 00:21:45     INFO -      Found by: stack scanning
[task 2020-01-25T00:21:45.263Z] 00:21:45     INFO -   2  mozglue.dll!mozilla::detail::ConditionVariableImpl::wait(mozilla::detail::MutexImpl&) [ConditionVariable_windows.cpp:6f6e201853c8f5053d6f8837acf89e76f5a334c5 : 50 + 0xf]
[task 2020-01-25T00:21:45.263Z] 00:21:45     INFO -      rbp = 0x0000004ae77fd100   rsp = 0x0000004ae77fd170
[task 2020-01-25T00:21:45.264Z] 00:21:45     INFO -      rip = 0x00007ffdb338c9d3
[task 2020-01-25T00:21:45.264Z] 00:21:45     INFO -      Found by: call frame info
[task 2020-01-25T00:21:45.264Z] 00:21:45     INFO -   3  xul.dll!mozilla::ThreadEventQueue<mozilla::PrioritizedEventQueue>::GetEvent(bool, mozilla::EventQueuePriority*, mozilla::BaseTimeDuration<mozilla::TimeDurationValueCalculator>*) [ThreadEventQueue.cpp:6f6e201853c8f5053d6f8837acf89e76f5a334c5 : 208 + 0x43]
[task 2020-01-25T00:21:45.264Z] 00:21:45     INFO -      rbp = 0x0000004ae77fd100   rsp = 0x0000004ae77fd1a0
[task 2020-01-25T00:21:45.264Z] 00:21:45     INFO -      rip = 0x00007ffd9666724e
[task 2020-01-25T00:21:45.265Z] 00:21:45     INFO -      Found by: call frame info
[task 2020-01-25T00:21:45.265Z] 00:21:45     INFO -   4  xul.dll!nsThread::ProcessNextEvent(bool, bool*) [nsThread.cpp:6f6e201853c8f5053d6f8837acf89e76f5a334c5 : 1140 + 0x2d]
[task 2020-01-25T00:21:45.265Z] 00:21:45     INFO -      rbp = 0x0000004ae77fd100   rsp = 0x0000004ae77fd280
[task 2020-01-25T00:21:45.265Z] 00:21:45     INFO -      rip = 0x00007ffd95e8ac18
[task 2020-01-25T00:21:45.265Z] 00:21:45     INFO -      Found by: call frame info
Flags: needinfo?(gsvelto)

Yes, that's the one that matters.

Flags: needinfo?(gsvelto)

Ok, so lets get the summary of the bug updated to prevent false classifications of other unrelated crashes.

Summary: Perma PROCESS-CRASH | damp | application crashed [@ static google_breakpad::ExceptionHandler::WriteMinidump(std::basic_string<wchar_t,std::char_traits<wchar_t>,std::allocator<wchar_t> > const&, bool (*)(wchar_t const*, wchar_t const*, void*, _EXCEP → Perma PROCESS-CRASH | damp | application crashed [@ AslHashFree + 0x35028]

Oh, I assume we can even dupe it to bug 1396112 (and reopen the other bug with an updated summary).

Crash Signature: [@ static google_breakpad::ExceptionHandler::WriteMinidump(std::basic_string<wchar_t,std::char_traits<wchar_t>,std::allocator<wchar_t> > const&, bool (*)(wchar_t const*, wchar_t const*, void*, _EXCEPTION_POINTERS*, MDRawAssertionInfo*, mozilla::phc::AddrI… → [@ AslHashFree + 0x35028]
Severity: normal → S3
You need to log in before you can comment on or make changes to this bug.