Crash Dump Analysis Patterns (Part 130a)

This part starts the block of patterns called Semantic Structures. These structures are fragments of memory which have meaning helping us in troubleshooting and debugging. The first pattern in this block deals with PID.TID structures of the form DWORD : DWORD or QWORD : QWORD. Such memory fragments are useful for wait chain analysis, for example, by looking at the excution residue left on a raw stack to find a target or an origin of RPC or (A)LPC calls. RPC target example can be found in the post: In Search of Lost CID. Here we look at another example, this time to find the originator of an ALPC call.

A ServiceA was executing some undesired functionality and a breakpoint was set on ModuleA code to trigger it under unreproducible conditions. Then a complete memory dump was saved for offline analysis. There we see an ALPC server thread that triggered the breakpoint but don’t see the message information in the output of WinDbg !thread command that can help us finding an ALPC client thread easily:

THREAD fffffa8005e6b060  Cid 0cc0.1838  Teb: 000007fffff8e000 Win32Thread: 0000000000000000 WAIT: (Executive) KernelMode Non-Alertable
SuspendCount 1
    fffff880094ad0a0  SynchronizationEvent
Not impersonating
DeviceMap                 fffff8a001aba3c0
Owning Process            fffffa8004803b30       Image:         ServiceA.exe
Attached Process          N/A            Image:         N/A
Wait Start TickCount      1441562        Ticks: 106618 (0:00:27:43.251)
Context Switch Count      414            
UserTime                  00:00:00.000
KernelTime                00:00:00.031
Win32 Start Address ntdll!TppWorkerThread (0×0000000077c88f00)
Stack Init fffff880094addb0 Current fffff880094acdb0
Base fffff880094ae000 Limit fffff880094a8000 Call 0
Priority 12 BasePriority 10 UnusualBoost 0 ForegroundBoost 0 IoPriority 2 PagePriority 5
Child-SP          RetAddr           Call Site
fffff880`094acdf0 fffff800`01678992 nt!KiSwapContext+0×7a
fffff880`094acf30 fffff800`0167acff nt!KiCommitThreadWait+0×1d2
fffff880`094acfc0 fffff800`01a150e8 nt!KeWaitForSingleObject+0×19f
fffff880`094ad060 fffff800`01a1546c nt!DbgkpQueueMessage+0×2a8
fffff880`094ad230 fffff800`019b9116 nt!DbgkpSendApiMessage+0×5c
fffff880`094ad270 fffff800`016abb96 nt! ?? ::NNGAKEGL::`string’+0×3463d
fffff880`094ad3b0 fffff800`01670d82 nt!KiDispatchException+0×316
fffff880`094ada40 fffff800`0166ebb4 nt!KiExceptionDispatch+0xc2
fffff880`094adc20 000007fe`f79365d1 nt!KiBreakpointTrap+0xf4 (TrapFrame @ fffff880`094adc20)
00000000`035ee568 000007fe`f80670b5 ModuleA+0×38611
[…]
00000000`035ee5d0 000007fe`ff4bc7f5 ModuleB!Start+0×6e1
00000000`035ee770 000007fe`ff56b62e RPCRT4!Invoke+0×65
00000000`035ee7c0 000007fe`ff4bf1f6 RPCRT4!Ndr64StubWorker+0×61b
00000000`035eed80 000007fe`ffedf223 RPCRT4!NdrStubCall3+0xb5
00000000`035eede0 000007fe`ffedfc0d ole32!CStdStubBuffer_Invoke+0×5b
00000000`035eee10 000007fe`ffedfb83 ole32!SyncStubInvoke+0×5d
00000000`035eee80 000007fe`ffd7fd60 ole32!StubInvoke+0xdb
00000000`035eef30 000007fe`ffedfa22 ole32!CCtxComChnl::ContextInvoke+0×190
00000000`035ef0c0 000007fe`ffedf76b ole32!AppInvoke+0xc2
00000000`035ef130 000007fe`ffeded6d ole32!ComInvokeWithLockAndIPID+0×52b
00000000`035ef2c0 000007fe`ff4b9c24 ole32!ThreadInvoke+0×30d
00000000`035ef360 000007fe`ff4b9d86 RPCRT4!DispatchToStubInCNoAvrf+0×14
00000000`035ef390 000007fe`ff4bc44b RPCRT4!RPC_INTERFACE::DispatchToStubWorker+0×146
00000000`035ef4b0 000007fe`ff4bc38b RPCRT4!RPC_INTERFACE::DispatchToStub+0×9b
00000000`035ef4f0 000007fe`ff4bc322 RPCRT4!RPC_INTERFACE::DispatchToStubWithObject+0×5b
00000000`035ef570 000007fe`ff4ba11d RPCRT4!LRPC_SCALL::DispatchRequest+0×422
00000000`035ef650 000007fe`ff4c7ddf RPCRT4!LRPC_SCALL::HandleRequest+0×20d
00000000`035ef780 000007fe`ff4c7995 RPCRT4!LRPC_ADDRESS::ProcessIO+0×3bf
00000000`035ef8c0 00000000`77c8b43b RPCRT4!LrpcIoComplete+0xa5
00000000`035ef950 00000000`77c8923f ntdll!TppAlpcpExecuteCallback+0×26b
00000000`035ef9e0 00000000`77a6f56d ntdll!TppWorkerThread+0×3f8
00000000`035efce0 00000000`77ca3281 kernel32!BaseThreadInitThunk+0xd
00000000`035efd10 00000000`00000000 ntdll!RtlUserThreadStart+0×1d

We inspect the raw stack starting from the first top Child-SP value for RPCRT4 subtrace and find NNN:NNN data there resembling PID:TID pair:

1: kd> dpp 00000000`035ef360 l100
[...]
00000000`035ef698  00000000`00000000
00000000`035ef6a0  00000000`00000001
00000000`035ef6a8  00000000`00000000
00000000`035ef6b0  00000000`00000000
00000000`035ef6b8  00000000`00000118
00000000`035ef6c0  00000000`0000048c
00000000`035ef6c8  00000000`00495e50 000007fe`ff57d920 RPCRT4!LRPC_ADDRESS::`vftable’
00000000`035ef6d0  00000000`00000000
[…]

We find such CID in the stack trace collection and see a wait for an ALPC message reply:

THREAD fffffa8003d49b60  Cid 0118.048c  Teb: 000007fffffaa000 Win32Thread: fffff900c01e4c30 WAIT: (WrLpcReply) UserMode Non-Alertable
    fffffa8003d49f20  Semaphore Limit 0×1
Waiting for reply to ALPC Message fffff8a000bdb6c0 : queued at port fffffa80042f8090 : owned by process fffffa8004803b30
Not impersonating
DeviceMap                 fffff8a000008600
Owning Process            fffffa8003cf15d0       Image:         ServiceB.exe
Attached Process          N/A            Image:         N/A
Wait Start TickCount      1441554        Ticks: 106626 (0:00:27:43.376)
Context Switch Count      23180                 LargeStack
UserTime                  00:00:00.468
KernelTime                00:00:03.057
Win32 Start Address ntdll!TppWorkerThread (0×0000000077c88f00)
Stack Init fffff88004ffcdb0 Current fffff88004ffc620
Base fffff88004ffd000 Limit fffff88004ff7000 Call 0
Priority 6 BasePriority 6 UnusualBoost 0 ForegroundBoost 0 IoPriority 2 PagePriority 5
Kernel stack not resident.
Child-SP          RetAddr           Call Site
fffff880`04ffc660 fffff800`01678992 nt!KiSwapContext+0×7a
fffff880`04ffc7a0 fffff800`0167acff nt!KiCommitThreadWait+0×1d2
fffff880`04ffc830 fffff800`0168fd1f nt!KeWaitForSingleObject+0×19f
fffff880`04ffc8d0 fffff800`01977ac6 nt!AlpcpSignalAndWait+0×8f
fffff880`04ffc980 fffff800`01975a50 nt!AlpcpReceiveSynchronousReply+0×46
fffff880`04ffc9e0 fffff800`01972fcb nt!AlpcpProcessSynchronousRequest+0×33d
fffff880`04ffcb00 fffff800`01670993 nt!NtAlpcSendWaitReceivePort+0×1ab
fffff880`04ffcbb0 00000000`77cc070a nt!KiSystemServiceCopyEnd+0×13 (TrapFrame @ fffff880`04ffcc20)
00000000`018ce308 000007fe`ff4caa76 ntdll!ZwAlpcSendWaitReceivePort+0xa
00000000`018ce310 000007fe`ff4bf802 RPCRT4!LRPC_CCALL::SendReceive+0×156
00000000`018ce3d0 000007fe`ffee0900 RPCRT4!I_RpcSendReceive+0×42
00000000`018ce400 000007fe`ffee05ef ole32!ThreadSendReceive+0×40
00000000`018ce450 000007fe`ffee041b ole32!CRpcChannelBuffer::SwitchAptAndDispatchCall+0xa3
00000000`018ce4f0 000007fe`ffd819c6 ole32!CRpcChannelBuffer::SendReceive2+0×11b
00000000`018ce6b0 000007fe`ffd81928 ole32!CAptRpcChnl::SendReceive+0×52
00000000`018ce780 000007fe`ffedfcf5 ole32!CCtxComChnl::SendReceive+0×68
00000000`018ce830 000007fe`ff56ba3b ole32!NdrExtpProxySendReceive+0×45
00000000`018ce860 000007fe`ffee02d0 RPCRT4!NdrpClientCall3+0×2e2
00000000`018ceb20 000007fe`ffd818a2 ole32!ObjectStublessClient+0×11d
00000000`018ceeb0 00000000`ff5afe64 ole32!ObjectStubless+0×42
[…]
00000000`018cf7a0 00000000`77c8f8eb ServiceB!Worker+0×366
00000000`018cf800 00000000`77c89d9f ntdll!RtlpTpWorkCallback+0×16b
00000000`018cf8e0 00000000`77a6f56d ntdll!TppWorkerThread+0×5ff
00000000`018cfbe0 00000000`77ca3281 kernel32!BaseThreadInitThunk+0xd
00000000`018cfc10 00000000`00000000 ntdll!RtlUserThreadStart+0×1d

Inspection of that message shows that it was directed to our server thread that triggered the breakpoint:

1: kd> !alpc /m fffff8a000bdb6c0

Message @ fffff8a000bdb6c0
  MessageID             : 0x0600 (1536)
  CallbackID            : 0x2D910D (2986253)
  SequenceNumber        : 0x0002CB50 (183120)
  Type                  : LPC_REQUEST
  DataLength            : 0x0068 (104)
  TotalLength           : 0x0090 (144)
  Canceled              : No
  Release               : No
  ReplyWaitReply        : No
  Continuation          : Yes
  OwnerPort             : fffffa8004823a80 [ALPC_CLIENT_COMMUNICATION_PORT]
  WaitingThread         : fffffa8003d49b60
  QueueType             : ALPC_MSGQUEUE_PENDING
  QueuePort             : fffffa80042f8090 [ALPC_CONNECTION_PORT]
  QueuePortOwnerProcess : fffffa8004803b30 (ServiceA.exe)
  ServerThread          : fffffa8005e6b060
  QuotaCharged          : No
  CancelQueuePort       : 0000000000000000
  CancelSequencePort    : 0000000000000000
  CancelSequenceNumber  : 0×00000000 (0)
  ClientContext         : 000000000020f0c0
  ServerContext         : 0000000000000000
  PortContext           : 0000000000416990
  CancelPortContext     : 0000000000000000
  SecurityData          : 0000000000000000
  View                  : 0000000000000000

- Dmitry Vostokov @ DumpAnalysis.org + TraceAnalysis.org -

One Response to “Crash Dump Analysis Patterns (Part 130a)”

  1. Dmitry Vostokov Says:

    Another example is 2 blocked COM threads where the second one has PID.TID packed in a qword on its raw stack that clearly shows a dependency.

Leave a Reply