Inconsistent dump, blocked threads, wait chains, incorrect stack trace and process factory: pattern cooperation
The more busy the system is, the more inconsistent are complete memory dumps produced by external physical memory dumpers. On the contrary, quiet systems, with idle existent users and when no one can connect, are more consistent than usual. Here is one example:
Loading Dump File [complete_dump.dmp]
Kernel Complete Dump File: Full address space is available
[...]
WARNING: Process directory table base 00039000 doesn't match CR3 CB759000
[...]
BugCheck 0, {0, 0, 0, 0}
Probably caused by : LiveKdD.SYS ( LiveKdD+12d1 )
In such cases I often dump all processes and threads to look for anomalies and indeed we find plenty of blocked threads in several services. For example, ServiceA.exe has blocked threads waiting for critical sections and LPC requests:
0: kd> !process 0 ff
**** NT ACTIVE PROCESS DUMP ****
[...]
THREAD 86f21118 Cid 07d4.2914 Teb: 7ffa5000 Win32Thread: 00000000 WAIT: (Unknown) UserMode Non-Alertable
86f21304 Semaphore Limit 0x1
Waiting for reply to LPC MessageId 00f2b546:
Current LPC port d79c6e00
Impersonation token: db621028 (Level Impersonation)
DeviceMap dca24d50
Owning Process 88948d88 Image: ServiceA.exe
Attached Process N/A Image: N/A
Wait Start TickCount 14788708 Ticks: 3643121 (0:15:48:43.765)
Context Switch Count 52
UserTime 00:00:00.000
KernelTime 00:00:00.000
Win32 Start Address ServiceA!EventWorkerThread (0×0042e2f8)
Start Address kernel32!BaseThreadStartThunk (0×77e617ec)
Stack Init b2246000 Current b2245c08 Base b2246000 Limit b2243000 Call 0
Priority 12 BasePriority 10 PriorityDecrement 0
Kernel stack not resident.
ChildEBP RetAddr
b2245c10 00000000 0×149c3
[…]
THREAD 8736fdb0 Cid 07d4.3cc4 Teb: 7ff9c000 Win32Thread: 00000000 WAIT: (Unknown) UserMode Non-Alertable
8736ff9c Semaphore Limit 0x1
Waiting for reply to LPC MessageId 00f2b518:
Current LPC port d79c6e00
Impersonation token: da1b51a8 (Level Impersonation)
DeviceMap d9f9e368
Owning Process 88948d88 Image: ServiceA.exe
Attached Process N/A Image: N/A
Wait Start TickCount 14788707 Ticks: 3643122 (0:15:48:43.781)
Context Switch Count 44
UserTime 00:00:00.000
KernelTime 00:00:00.000
Win32 Start Address ServiceA!EventWorkerThread (0×0042e2f8)
Start Address kernel32!BaseThreadStartThunk (0×77e617ec)
Stack Init ae5d3000 Current ae5d2c08 Base ae5d3000 Limit ae5d0000 Call 0
Priority 12 BasePriority 10 PriorityDecrement 0
Kernel stack not resident.
ChildEBP RetAddr
WARNING: Frame IP not in any known module. Following frames may be wrong.
ae5d2c10 3fe63bfa 0×73e40763
[…]
THREAD 85e89c80 Cid 07d4.5648 Teb: 7ff6a000 Win32Thread: 00000000 WAIT: (Unknown) UserMode Non-Alertable
871d6e80 SynchronizationEvent
Impersonation token: d7a1c028 (Level Impersonation)
DeviceMap d66ef860
Owning Process 88948d88 Image: ServiceA.exe
Attached Process N/A Image: N/A
Wait Start TickCount 14320472 Ticks: 4111357 (0:17:50:39.953)
Context Switch Count 28
UserTime 00:00:00.000
KernelTime 00:00:00.000
Win32 Start Address 0x00ebebcc
LPC Server thread working on message Id ebebcc
Start Address kernel32!BaseThreadStartThunk (0x77e617ec)
Stack Init a536b000 Current a536ac60 Base a536b000 Limit a5368000 Call 0
Priority 11 BasePriority 10 PriorityDecrement 0
Kernel stack not resident.
ChildEBP RetAddr
a536ac78 8083d5b1 nt!KiSwapContext+0x26
a536aca4 8083df9e nt!KiSwapThread+0x2e5
a536acec 8092ae57 nt!KeWaitForSingleObject+0x346
a536ad50 80833bdf nt!NtWaitForSingleObject+0x9a
a536ad50 7c8285ec nt!KiFastCallEntry+0xfc
05b6f7d0 7c827d0b ntdll!KiFastSystemCallRet
05b6f7d4 7c83d236 ntdll!NtWaitForSingleObject+0xc
05b6f810 7c83d281 ntdll!RtlpWaitOnCriticalSection+0×1a3
05b6f830 0040bb5b ntdll!RtlEnterCriticalSection+0xa8
05b6f874 00415889 ServiceA!OnRequest+0×23
[…]
05b6f8b4 77ce33e1 RPCRT4!Invoke+0×30
05b6fcb4 77ce35c4 RPCRT4!NdrStubCall2+0×299
05b6fcd0 77c7ff7a RPCRT4!NdrServerCall2+0×19
05b6fd04 77c8042d RPCRT4!DispatchToStubInCNoAvrf+0×38
05b6fd58 77c80353 RPCRT4!RPC_INTERFACE::DispatchToStubWorker+0×11f
05b6fd7c 77c7e0d4 RPCRT4!RPC_INTERFACE::DispatchToStub+0xa3
05b6fdbc 77c7e080 RPCRT4!RPC_INTERFACE::DispatchToStubWithObject+0xc0
05b6fdfc 77c812f0 RPCRT4!LRPC_SCALL::DealWithRequestMessage+0×41e
05b6fe20 77c88678 RPCRT4!LRPC_ADDRESS::DealWithLRPCRequest+0×127
05b6ff84 77c88792 RPCRT4!LRPC_ADDRESS::ReceiveLotsaCalls+0×430
05b6ff8c 77c8872d RPCRT4!RecvLotsaCallsWrapper+0xd
05b6ffac 77c7b110 RPCRT4!BaseCachedThreadRoutine+0×9d
05b6ffb8 77e64829 RPCRT4!ThreadStartRoutine+0×1b
05b6ffec 00000000 kernel32!BaseThreadStart+0×34
Knowing that ServiceA is crucial for our system functions we examine LPC wait chains. All “Waiting for reply to LPC MessageId <…>” threads depend on another service:
0: kd> !lpc message 00f2b546
Searching message f2b546 in threads ...
Client thread 86f21118 waiting a reply from f2b546
Server thread 860cc9e0 is working on message f2b546
[…]
Server process : 87d21698 (svchost.exe)
[…]
We find this thread in svchost.exe hosting ServiceB:
0: kd> !thread 860cc9e0 1f
THREAD 860cc9e0 Cid 1310.4ad8 Teb: 7ff88000 Win32Thread: 00000000 WAIT: (Unknown) UserMode Non-Alertable
871d47d0 Mutant - owning thread 867322e0
Not impersonating
DeviceMap d64008f8
Owning Process 87d21698 Image: svchost.exe
Attached Process N/A Image: N/A
Wait Start TickCount 14788708 Ticks: 3643121 (0:15:48:43.765)
Context Switch Count 1791
UserTime 00:00:00.031
KernelTime 00:00:00.046
Win32 Start Address 0×00f2b546
LPC Server thread working on message Id f2b546
Start Address kernel32!BaseThreadStartThunk (0×77e617ec)
Stack Init b055e000 Current b055dc60 Base b055e000 Limit b055b000 Call 0
Priority 12 BasePriority 10 PriorityDecrement 0
Kernel stack not resident.
ChildEBP RetAddr
b055dc78 8083d5b1 nt!KiSwapContext+0×26
b055dca4 8083df9e nt!KiSwapThread+0×2e5
b055dcec 8092ae57 nt!KeWaitForSingleObject+0×346
b055dd50 80833bdf nt!NtWaitForSingleObject+0×9a
b055dd50 7c8285ec nt!KiFastCallEntry+0xfc
0400f718 7c827d0b ntdll!KiFastSystemCallRet
0400f71c 7654bf59 ntdll!NtWaitForSingleObject+0xc
0400f73c 7654c694 ServiceB!Lock+0×42
0400f754 76558b17 ServiceB!FindObjectById+0×39
0400f8ac 7654fa50 ServiceB!QueryInformation+0×3e
0400f8c8 77c80193 ServiceB!RpcQueryInformation+0×49
0400f8f8 77ce33e1 RPCRT4!Invoke+0×30
0400fcf8 77ce35c4 RPCRT4!NdrStubCall2+0×299
0400fd14 77c7ff7a RPCRT4!NdrServerCall2+0×19
0400fd48 77c8042d RPCRT4!DispatchToStubInCNoAvrf+0×38
0400fd9c 77c80353 RPCRT4!RPC_INTERFACE::DispatchToStubWorker+0×11f
0400fdc0 77c811dc RPCRT4!RPC_INTERFACE::DispatchToStub+0xa3
0400fdfc 77c812f0 RPCRT4!LRPC_SCALL::DealWithRequestMessage+0×42c
0400fe20 77c88678 RPCRT4!LRPC_ADDRESS::DealWithLRPCRequest+0×127
0400ff84 77c88792 RPCRT4!LRPC_ADDRESS::ReceiveLotsaCalls+0×430
0400ff8c 77c8872d RPCRT4!RecvLotsaCallsWrapper+0xd
0400ffac 77c7b110 RPCRT4!BaseCachedThreadRoutine+0×9d
0400ffb8 77e64829 RPCRT4!ThreadStartRoutine+0×1b
0400ffec 00000000 kernel32!BaseThreadStart+0×34
We notice that about 45 threads are waiting for the mutant 871d47d0 owned by thread 867322e0, like this one with incorrect stack trace because of inconsistent dump file data:
0: kd> !thread 86cad210 1f
THREAD 86cad210 Cid 1310.31a4 Teb: 7ff15000 Win32Thread: 00000000 WAIT: (Unknown) UserMode Non-Alertable
871d47d0 Mutant - owning thread 867322e0
Not impersonating
DeviceMap d64008f8
Owning Process 87d21698 Image: svchost.exe
Attached Process N/A Image: N/A
Wait Start TickCount 18020896 Ticks: 410933 (0:01:47:00.828)
Context Switch Count 43
UserTime 00:00:00.000
KernelTime 00:00:00.000
Win32 Start Address RPCRT4!ThreadStartRoutine (0×77c7b0f5)
Start Address kernel32!BaseThreadStartThunk (0×77e617ec)
Stack Init abb1b000 Current abb1ac60 Base abb1b000 Limit abb18000 Call 0
Priority 11 BasePriority 10 PriorityDecrement 0
Kernel stack not resident.
ChildEBP RetAddr
WARNING: Frame IP not in any known module. Following frames may be wrong.
abb1ac68 60203020 0×84
[…]
We inspect the thread 867322e0:
0: kd> !thread 867322e0 1f
THREAD 867322e0 Cid 1310.26dc Teb: 7ff56000 Win32Thread: 00000000 WAIT: (Unknown) UserMode Non-Alertable
869d4020 ProcessObject
86732358 NotificationTimer
Not impersonating
DeviceMap d64008f8
Owning Process 87d21698 Image: svchost.exe
Attached Process N/A Image: N/A
Wait Start TickCount 18454684
Context Switch Count 5172
UserTime 00:00:00.000
KernelTime 00:00:00.031
Win32 Start Address 0×0083fd5d
LPC Server thread working on message Id 83fd5d
Start Address kernel32!BaseThreadStartThunk (0×77e617ec)
Stack Init ad350000 Current ad34fc60 Base ad350000 Limit ad34d000 Call 0
Priority 10 BasePriority 10 PriorityDecrement 0
ChildEBP RetAddr
ad34fc78 8083d5b1 nt!KiSwapContext+0×26
ad34fca4 8083df9e nt!KiSwapThread+0×2e5
ad34fcec 8092ae57 nt!KeWaitForSingleObject+0×346
ad34fd50 80833bdf nt!NtWaitForSingleObject+0×9a
ad34fd50 7c8285ec nt!KiFastCallEntry+0xfc
04f5fbec 7c827d0b ntdll!KiFastSystemCallRet
04f5fbf0 76548721 ntdll!NtWaitForSingleObject+0xc
04f5fc0c 7654c596 ServiceB!WaitForProcess+0×4a
04f5ffb8 77e64829 ServiceB!LpcThread+0×14e
04f5ffec 00000000 kernel32!BaseThreadStart+0×34
We see that it is waiting for the process 869d4020 and we find the latter one with a single thread blocked by DriverA:
0: kd> !process 869d4020 ff
PROCESS 869d4020 SessionId: 18 Cid: 56b8 Peb: 7ffde000 ParentCid: 3608
DirBase: 758b3000 ObjectTable: dd7083c0 HandleCount: 79.
Image: rundll32.exe
VadRoot 869d5228 Vads 107 Clone 0 Private 330. Modified 1706. Locked 0.
DeviceMap d8d260a8
Token dfa8f028
ElapsedTime 1 Day 23:52:06.918
UserTime 00:00:00.312
KernelTime 00:00:01.484
QuotaPoolUsage[PagedPool] 34784
QuotaPoolUsage[NonPagedPool] 5016
Working Set Sizes (now,min,max) (810, 50, 345) (3240KB, 200KB, 1380KB)
PeakWorkingSetSize 2088
VirtualSize 37 Mb
PeakVirtualSize 47 Mb
PageFaultCount 34473
MemoryPriority BACKGROUND
BasePriority 10
CommitCharge 707
[..]
CommandLine: ‘rundll32 C:\WINDOWS\system32\DllA.dll,CheckData /name”PropertyA”‘
[…]
THREAD 86bac020 Cid 56b8.4904 Teb: 7ffdb000 Win32Thread: 00000000 WAIT: (Unknown) KernelMode Non-Alertable
8774a930 NotificationEvent
Not impersonating
DeviceMap d8d260a8
Owning Process 869d4020 Image: rundll32.exe
Attached Process N/A Image: N/A
Wait Start TickCount 10113815 Ticks: 8318014 (1:12:06:08.968)
Context Switch Count 188
UserTime 00:00:00.000
KernelTime 00:00:00.000
Win32 Start Address 0x2b169ecb
Start Address kernel32!BaseThreadStartThunk (0x77e617ec)
Stack Init af12b000 Current af12ac34 Base af12b000 Limit af128000 Call 0
Priority 12 BasePriority 10 PriorityDecrement 0
ChildEBP RetAddr
af12ac4c 8083d5b1 nt!KiSwapContext+0x26
af12ac78 8083df9e nt!KiSwapThread+0x2e5
af12acc0 b5075a82 nt!KeWaitForSingleObject+0x346
WARNING: Stack unwind information not available. Following frames may be wrong.
af12acf4 b507f989 DriverA+0×3a82
[…]
We also check virtual memory consumption and instantly see hundreds of rundll32.exe processes like in a process factory pattern:
0: kd> !vm
[...]
57f4 rundll32.exe 586 ( 2344 Kb)
57d0 rundll32.exe 586 ( 2344 Kb)
57b4 rundll32.exe 586 ( 2344 Kb)
578c rundll32.exe 586 ( 2344 Kb)
5780 rundll32.exe 586 ( 2344 Kb)
577c rundll32.exe 586 ( 2344 Kb)
5744 rundll32.exe 586 ( 2344 Kb)
572c rundll32.exe 586 ( 2344 Kb)
5724 rundll32.exe 586 ( 2344 Kb)
5708 rundll32.exe 586 ( 2344 Kb)
56d4 rundll32.exe 586 ( 2344 Kb)
56a4 rundll32.exe 586 ( 2344 Kb)
564c rundll32.exe 586 ( 2344 Kb)
5630 rundll32.exe 586 ( 2344 Kb)
55e0 rundll32.exe 586 ( 2344 Kb)
55b8 rundll32.exe 586 ( 2344 Kb)
55ac rundll32.exe 586 ( 2344 Kb)
558c rundll32.exe 586 ( 2344 Kb)
550c rundll32.exe 586 ( 2344 Kb)
546c rundll32.exe 586 ( 2344 Kb)
5428 rundll32.exe 586 ( 2344 Kb)
5418 rundll32.exe 586 ( 2344 Kb)
53d0 rundll32.exe 586 ( 2344 Kb)
53bc rundll32.exe 586 ( 2344 Kb)
53b0 rundll32.exe 586 ( 2344 Kb)
53a8 rundll32.exe 586 ( 2344 Kb)
530c rundll32.exe 586 ( 2344 Kb)
5300 rundll32.exe 586 ( 2344 Kb)
52e8 rundll32.exe 586 ( 2344 Kb)
52a4 rundll32.exe 586 ( 2344 Kb)
5294 rundll32.exe 586 ( 2344 Kb)
5228 rundll32.exe 586 ( 2344 Kb)
5118 rundll32.exe 586 ( 2344 Kb)
50bc rundll32.exe 586 ( 2344 Kb)
50a8 rundll32.exe 586 ( 2344 Kb)
5080 rundll32.exe 586 ( 2344 Kb)
5030 rundll32.exe 586 ( 2344 Kb)
4fc8 rundll32.exe 586 ( 2344 Kb)
4f88 rundll32.exe 586 ( 2344 Kb)
4ef0 rundll32.exe 586 ( 2344 Kb)
4e84 rundll32.exe 586 ( 2344 Kb)
4e70 rundll32.exe 586 ( 2344 Kb)
4e68 rundll32.exe 586 ( 2344 Kb)
4e4c rundll32.exe 586 ( 2344 Kb)
4e38 rundll32.exe 586 ( 2344 Kb)
4df8 rundll32.exe 586 ( 2344 Kb)
4df4 rundll32.exe 586 ( 2344 Kb)
4d2c rundll32.exe 586 ( 2344 Kb)
4d00 rundll32.exe 586 ( 2344 Kb)
4cd4 rundll32.exe 586 ( 2344 Kb)
4cbc rundll32.exe 586 ( 2344 Kb)
4c90 rundll32.exe 586 ( 2344 Kb)
4c80 rundll32.exe 586 ( 2344 Kb)
4c68 rundll32.exe 586 ( 2344 Kb)
4c40 rundll32.exe 586 ( 2344 Kb)
[...]
By switching the current process context to 869d4020 (.process /r /p command) and using lmv command we check vendors for DllA and DriverA. It seems that they are different. We also see that DllA module is no longer loaded (not seen in the module list) by the time DriverA is waiting for a notification event. All rundll32.exe processes are waiting for that DriverA kernel module. We therefore decide to contact its vendor.
- Dmitry Vostokov @ DumpAnalysis.org -