Heap and spike: pattern cooperation

This is another case study showing how different patterns interact. It was reported that the service was spiking CPU (see Spiking Thread pattern) and other processes couldn’t communicate with it (see Coupled Processes pattern). The dump was saved using userdump.exe and !runaway command showed that the thread #18 was consuming CPU mostly in user mode:

0:018> !runaway 0y11
 User Mode Time
  Thread       Time
  18:6080      0 days 20:46:57.156
   3:2838      0 days 0:00:00.203
   5:53a0      0 days 0:00:00.093
  16:44a8      0 days 0:00:00.078
  17:2ad8      0 days 0:00:00.046
  19:5834      0 days 0:00:00.015
[…]
   0:57d4      0 days 0:00:00.000
 Kernel Mode Time
  Thread       Time
   5:53a0      0 days 0:00:03.328
   3:2838      0 days 0:00:01.046
  16:44a8      0 days 0:00:00.937
  18:6080      0 days 0:00:00.765
  17:2ad8      0 days 0:00:00.531
  19:5834      0 days 0:00:00.171
  20:3174      0 days 0:00:00.140
[…]

Its thread stack revealed runtime heap manipulation function on top of it:

0:018> ~18kL
ChildEBP RetAddr 
0207f748 77e673ca ntdll!RtlFreeHeap+0×4a5
0207f7b0 77e67690 kernel32!BasepComputeProcessPath+0×395
0207f7b0 77e67690 kernel32!BaseComputeProcessDllPath+0xe3
0207f7f0 77e41b95 kernel32!BaseComputeProcessDllPath+0xe3
0207f850 710f43d9 kernel32!LoadLibraryExW+0×14e
[…]

The parameters to RtlFreeHeap call are described in the following MSDN article:

http://msdn.microsoft.com/en-us/library/ms796710.aspx

We see that the code was freeing the heap block with the address 0×02f88278 and it was located in the first heap 0×00090000:

0:018> ~18kv
ChildEBP RetAddr  Args to Child             
0207f748 77e673ca 00090000 00000000 02f88278 ntdll!RtlFreeHeap+0×4a5
[…]

0:018> !heap
Index   Address  Name      Debugging options enabled
  1:   00090000               
  2:   00190000               
  3:   003b0000               
  4:   00340000               
  5:   00380000               
  6:   007d0000               
  7:   008e0000               
  8:   00a40000               
  9:   00ae0000               
 10:   00c60000               
 11:   00cf0000               
 12:   00d30000               
 13:   00d40000               
 14:   00ed0000               
 15:   01010000               
 16:   01090000               
 17:   00a20000               
 18:   00c90000               
 19:   00fd0000               
 20:   01690000               
 21:   01b30000               
 22:   01b50000               
 23:   01c20000               
 24:   01e50000               
 25:   01f20000               
 26:   01f30000               
 27:   01f40000
               

Could it be the case that the heap was corrupt? We can validate it:

0:018> !heap -s 00090000
Walking the heap 00090000 .HEAP 00090000 (Seg 00090640) At 00184998 Error: invalid block size

.List corrupted: (Blink->Flink = 00000000) != (Block = 02f88278)
HEAP 00090000 (Seg 02f80000) At 02f88270 Error: block list entry corrupted

[...]

The output shows our block 0×02f88278 too but this could also be the effect of False Positive Corruption, the fact that the heap control structures had not been updated yet: the thread is inside heap manipulation function. 

When looking at critical sections and other threads we also see several wait chains (see Wait Chain pattern): 

0:000> !locks

CritSec ntdll!LdrpLoaderLock+0 at 7c889d94
WaiterWoken        No
LockCount          18
RecursionCount     1
OwningThread       2300
EntryCount         0
ContentionCount    141
*** Locked

CritSec ntdll!FastPebLock+0 at 7c889d40
WaiterWoken        No
LockCount          1
RecursionCount     1
OwningThread       2904
EntryCount         0
ContentionCount    2
*** Locked

CritSec +90608 at 00090608
WaiterWoken        No
LockCount          7
RecursionCount     1
OwningThread       6080
EntryCount         0
ContentionCount    7
*** Locked

CritSec serviceA!ServiceSection+0 at 7617c340
WaiterWoken        No
LockCount          5
RecursionCount     1
OwningThread       2838
EntryCount         0
ContentionCount    1e3
*** Locked

0:000> ~*kv

[...]

3 Id: da4.2838 Suspend: 1 Teb: 7ffdc000 Unfrozen
ChildEBP RetAddr Args to Child
00c4f164 7c822124 7c83970f 00000688 00000000 ntdll!KiFastSystemCallRet
00c4f168 7c83970f 00000688 00000000 00000000 ntdll!NtWaitForSingleObject+0xc
00c4f1a4 7c839620 00000000 00000004 00090000 ntdll!RtlpWaitOnCriticalSection+0x19c
00c4f1c4 7c82fe72 00090608 000995b8 00000008 ntdll!RtlEnterCriticalSection+0xa8
00c4f3ec 7c81f4d5 00090000 00800000 000000f8 ntdll!RtlAllocateHeap+0×313
00c4f434 7c81f073 000995b8 00000000 00090000 ntdll!RtlpAllocateUserBlock+0×91
00c4f4f8 7c81ff83 00000bbe 00000000 00000001 ntdll!RtlpLowFragHeapAlloc+0×862
00c4f71c 7c820b23 00090000 00000000 0000000c ntdll!RtlAllocateHeap+0×80
00c4f734 77f6599e 00c4f7b8 00000001 00000002 ntdll!RtlAllocateAndInitializeSid+0×35
00c4f768 74062bfd 00c4f7b8 00000001 00000002 advapi32!AllocateAndInitializeSid+0×2c
[…]

[...]

18 Id: da4.6080 Suspend: 1 Teb: 7ffa8000 Unfrozen
[This is our spiking thread]
[...]

[...]

32 Id: da4.2904 Suspend: 1 Teb: 7ff9a000 Unfrozen
ChildEBP RetAddr Args to Child
0356fbfc 7c822124 7c83970f 00000688 00000000 ntdll!KiFastSystemCallRet
0356fc00 7c83970f 00000688 00000000 00000000 ntdll!NtWaitForSingleObject+0xc
0356fc3c 7c839620 00000000 00000004 00090000 ntdll!RtlpWaitOnCriticalSection+0x19c
0356fc5c 7c82fe72 00090608 7c8329a4 0000008e ntdll!RtlEnterCriticalSection+0xa8
0356fe84 77e67319 00090000 00000000 0000056a ntdll!RtlAllocateHeap+0×313
0356fee8 77e67690 77e676bc 00020a50 00000000 kernel32!BasepComputeProcessPath+0xc2
0356ff28 77e41b95 00000000 00000000 7c82f337 kernel32!BaseComputeProcessDllPath+0xe3
0356ff88 77e67b77 74066908 00000000 00000000 kernel32!LoadLibraryExW+0×14e
0356ff9c 74071b74 74066908 74075320 74071c1c kernel32!LoadLibraryW+0×11
[…]

  33  Id: da4.2300 Suspend: 1 Teb: 7ff99000 Unfrozen
ChildEBP RetAddr  Args to Child             
035afb40 7c822124 7c83970f 00000164 00000000 ntdll!KiFastSystemCallRet
035afb44 7c83970f 00000164 00000000 00000000 ntdll!NtWaitForSingleObject+0xc
035afb80 7c839620 00000000 00000004 00000000 ntdll!RtlpWaitOnCriticalSection+0x19c
035afba0 7c83288c 7c889d40 77e630b8 00000000 ntdll!RtlEnterCriticalSection+0xa8
035afba8 77e630b8 00000000 007e5860 00000001 ntdll!RtlAcquirePebLock+0×11
[…]

[...]

18 threads -> TID#2300 -> TID#2904 -> TID#6080

5 threads -> TID#2838 -> TID#6080

So it looks like our spiking thread was the main problem and preventing other threads from running.

- Dmitry Vostokov @ DumpAnalysis.org -

Leave a Reply

You must be logged in to post a comment.