1391224 - Consider buffering minidump IO operations and then flushing asynchronously

Status: NEW

(Toolkit :: Crash Reporting, enhancement)

Description

[Cervantes Yu [:cyu] [:cervantes]]

We now generate minidumps not only when a process crashes, but also when we detect child hang or when we KillHard() the child process. This creates main-thread disk IO operations. Some minidumps can be generated off the main thread, but some cannot be (e.g. the parent side of the paired mninidumps (bug 1390143)). Ironically, when we detect a browser hang, we hang the browser further by generating minidumps on the main thread.

To fix such performance problems, we used to offload the IO operation from the main thread, but doing this tends to make the code more complicated. And some dumps need to be generated on the main thread to keep the thread stack as in bug 1390143.

We can approach this problem from another perspective: we make the main-thread IO fast so even it doesn't jank the browser. We can do this by not offloading minidump generation methods calls from the main thread, but just offloading the disk IO operations. We can buffer the content in memory and flush to disk later. To do this, we need to generate minidumps out of the main process (bug 587729). Then we can create a pair of pipes instead of a real file on the disk and use the pipe as the FD or HANDLE for breakpad dump method calls. The crash dumper process drains the pipe, buffers the dump content in memory and flushes asynchronously.

Comment 1

[Cervantes Yu [:cyu] [:cervantes]]

To make it clear, there are 2 ways of making minidump disk IO OOP:
1. We still call MinidumpWriteDump() in the parent process, but the performs disk IO in another process. This is easier to implement, but doesn't provide other benefits of OOP dump generation like resistance to memory corruptions.
2. We call MinidumpWriteDump() from another process to generate the dump for the parent process. Even we take this approach, we still can buffer minidump content using pipes to reduce the pause of the parent process while generating the dump.

Comment 2

[Cervantes Yu [:cyu] [:cervantes]]

Attachment: Profiling MinidumpWriteDump

This is a screenshot taken from the profile of MinidumpWriteDump().
From the profile, it can be seen that writing the dump to the disk is *not* the bottleneck of creating minidumps. Getting information of loaded modules makes the function slow.

From the profile, the whole duration of MinidumpWriteDump() call is ~1.6 sec.
[1] WriteDumpData() takes ~47 ms, [2] during which there are 1952 context switches but only 9.3 ms is spent in kernel (9312.089 us). Also from the CPU usage graph it can be seen that during WriteDumpData(), we spent most of time in user space. CPU usage is pretty good.
[3] GenGetProcessInfo() takes ~1537 ms, [4] during which there are 11673 context switches and 1349 ms is spent in kernel. From the CPU usage graph there are many gaps show that it spent lots of time in kernel. Drilling down the stack shows that most of the time spent in kernel are ntoskrnl.exe!KiPageFault called by GenGetDebugRecord(), or other IO operations (not shown in the screenshot) called by Win32LiveSystemProvider::GetImageVersionInfo(), or GenImageNtHeader().

So we actually spent most of time in read operations collecting information of loaded modules. It seems MinidumpWriteDump() already buffers data for later write. Buffering dump data using a pipe is unlikely to have observable performance improvement.

Comment 3

[Cervantes Yu [:cyu] [:cervantes]]

(In reply to Cervantes Yu [:cyu] [:cervantes] from comment #2)
> Created attachment 8898712 [details]
> Profiling MinidumpWriteDump
> 
BTW, this profile is taken after an OS reboot. When taking the minidump, the system is still busy with disk IO, which largely increase the time spent in getting loaded module information. Minidump doesn't usually take so long to generate.