10 Common Mistakes in Memory Analysis (Part 1)
Tuesday, May 27th, 2008Mistake #1 - Not looking at full stack traces
By default WinDbg cuts off stack traces after 20th line and an analyst misses essential information when looking at Stack Trace or Stack Trace Collection. Consider this thread stack trace taken from a user process dump where runaway information was not saved but customers reported CPU spikes:
0:000> ~3kvL
ChildEBP RetAddr
0290f864 773976f2 user32!_SEH_prolog+0xb
0290f86c 0047f9ec user32!EnableMenuItem+0xf
0290f884 00488f6d Application!Close+0x142c
0290f8a4 0047a9c6 Application!EnableMenu+0x5d
0290f8b8 0048890d Application!EnableWindows+0x106
0290f8d0 0048cc2b Application!SetHourGlass+0xbd
0290f8fc 0046327a Application!WriteDataStream+0x24b
0290f924 0048d8f9 Application!WriteDataStream+0x21a
0290fa68 00479811 Application!WriteDataStream+0xcb9
0290fadc 5b5e976c Application!OnWrite+0x3c1
0290fb70 5b60e0b0 mfc71!CWnd::OnWndMsg+0x4f2
0290fb90 5b60e14f mfc71!CWnd::WindowProc+0x22
0290fbf0 5b60e1b8 mfc71!AfxCallWndProc+0x91
0290fc10 00516454 mfc71!AfxWndProc+0x46
0290fc3c 7739c3b7 Application!ExitCheck+0x28f34
0290fc68 7739c484 user32!InternalCallWinProc+0x28
0290fce0 77395563 user32!UserCallWinProcCheckWow+0x151
0290fd10 773ad03f user32!CallWindowProcAorW+0x98
0290fd30 0047a59a user32!CallWindowProcA+0x1b
We can see that it uses MFC libraries and window messaging API but was it caught accidentally? Is it a typical message loop like idle message loops in Passive Thread pattern using GetMessage or it is an active GUI message pump using PeekMessage? If we expand stack trace we would see that the thread is actually MFC GUI thread that spins according to MFC source code:
int CWinThread::Run()
{
for (;;)
{
while (bIdle &&
!::PeekMessage(&(pState->m_msgCur),
NULL, NULL, NULL, PM_NOREMOVE))
{
0:000> ~3kvL 100
ChildEBP RetAddr
0290f864 773976f2 user32!_SEH_prolog+0xb
0290f86c 0047f9ec user32!EnableMenuItem+0xf
0290f884 00488f6d Application!Close+0x142c
0290f8a4 0047a9c6 Application!EnableMenu+0x5d
0290f8b8 0048890d Application!EnableWindows+0x106
0290f8d0 0048cc2b Application!SetHourGlass+0xbd
0290f8fc 0046327a Application!WriteDataStream+0x24b
0290f924 0048d8f9 Application!WriteDataStream+0x21a
0290fa68 00479811 Application!WriteDataStream+0xcb9
0290fadc 5b5e976c Application!OnWrite+0x3c1
0290fb70 5b60e0b0 mfc71!CWnd::OnWndMsg+0x4f2
0290fb90 5b60e14f mfc71!CWnd::WindowProc+0x22
0290fbf0 5b60e1b8 mfc71!AfxCallWndProc+0x91
0290fc10 00516454 mfc71!AfxWndProc+0x46
0290fc3c 7739c3b7 Application!ExitCheck+0x28f34
0290fc68 7739c484 user32!InternalCallWinProc+0x28
0290fce0 77395563 user32!UserCallWinProcCheckWow+0x151
0290fd10 773ad03f user32!CallWindowProcAorW+0x98
0290fd30 0047a59a user32!CallWindowProcA+0x1b
0290fdb0 7739c3b7 Application!OnOK+0x77a
0290fddc 7739c484 user32!InternalCallWinProc+0x28
0290fe54 7739c73c user32!UserCallWinProcCheckWow+0x151
0290febc 7738e406 user32!DispatchMessageWorker+0x327
0290fecc 5b609076 user32!DispatchMessageA+0xf
0290fedc 5b60913e mfc71!AfxInternalPumpMessage+0x3e
0290fef8 004ba7cf mfc71!CWinThread::Run+0×54
0290ff04 5b61b30c Application!CMyThread::Run+0xf
0290ff84 5b869565 mfc71!_AfxThreadEntry+0×100
0290ffb8 77e66063 msvcr71!_endthreadex+0xa0
0290ffec 00000000 kernel32!BaseThreadStart+0×34
There is also WinDbg .kframes meta-command that can change default stack trace depth:
2: kd> .kframes 0n100
Default stack trace depth is 0n100 frames
- Dmitry Vostokov @ DumpAnalysis.org -
