Crash Dump Analysis Patterns (Part 42e)

Now its time to write about wait chains involving LPC calls. These chains are easily identified by searching for “Waiting for reply to LPC MessageId” in the output of !process 0 ff command or if we know that some specific process is hanging and see that message in its thread information output. For example, in one kernel memory dump taken when AppA was hanging we see this example of Blocked Thread pattern:

7: kd> !process 88556778  ff
PROCESS 88556778  SessionId: 0  Cid: 1f88    Peb: 7ffdc000  ParentCid: 0f74
DirBase: 96460000  ObjectTable: e65a5348  HandleCount:  80.
Image: AppA.exe
VadRoot 870d2208 Vads 54 Clone 0 Private 234. Modified 0. Locked 0.
DeviceMap e22ba7c0
Token                             e5e47cf0
ElapsedTime                       00:04:44.017
UserTime                          00:00:00.000
KernelTime                        00:00:00.000
QuotaPoolUsage[PagedPool]         20092
QuotaPoolUsage[NonPagedPool]      2160
Working Set Sizes (now,min,max)  (748, 50, 345) (2992KB, 200KB, 1380KB)
PeakWorkingSetSize                748
VirtualSize                       16 Mb
PeakVirtualSize                   16 Mb
PageFaultCount                    810
MemoryPriority                    BACKGROUND
BasePriority                      8
CommitCharge                      252

    PEB NULL...                       

THREAD 8861aab8  Cid 1f88.1bd4  Teb: 7ffdf000 Win32Thread: bc161ea8 WAIT: (Unknown) UserMode Non-Alertable
    8861aca4  Semaphore Limit 0x1
Waiting for reply to LPC MessageId 00037bb2:
Current LPC port e625bbd0
Not impersonating
DeviceMap                 e22ba7c0
Owning Process            88556778       Image:         AppA.exe
Wait Start TickCount      426549         Ticks: 18176 (0:00:04:44.000)
Context Switch Count      76                 LargeStack
UserTime                  00:00:00.000
KernelTime                00:00:00.000
Win32 Start Address 0×010043ab
Start Address 0×77e617f8
Stack Init bab4b000 Current bab4ac08 Base bab4b000 Limit bab47000 Call 0
Priority 11 BasePriority 8 PriorityDecrement 2
Kernel stack not resident.
ChildEBP RetAddr 
bab4ac20 8083d5b1 nt!KiSwapContext+0×26
bab4ac4c 8083df9e nt!KiSwapThread+0×2e5
bab4ac94 8093eda1 nt!KeWaitForSingleObject+0×346
bab4ad50 80833bef nt!NtRequestWaitReplyPort+0×776
bab4ad50 7c8285ec nt!KiFastCallEntry+0xfc

Now we look for a server thread processing the message 00037bb2:

7: kd> !lpc message 00037bb2
Searching message 37bb2 in threads ...
    Server thread 89815db0 is working on message 37bb2
Client thread 8861aab8 waiting a reply from 37bb2                         
Searching thread 8861aab8 in port rundown queues …

Server communication port 0xe1216be8
    Handles: 1   References: 1
    The LpcDataInfoChainHead queue is empty
        Connected port: 0xe625bbd0      Server connection port: 0xe1323f68

Client communication port 0xe625bbd0
    Handles: 1   References: 2
    The LpcDataInfoChainHead queue is empty

Server connection port e1323f68  Name: ApiABC
    Handles: 1   References: 43
    Server process  : 887d32d0 (svchost.exe)
    Queue semaphore : 884df210
    Semaphore state 0 (0x0)
    The message queue is empty

    Messages in LpcDataInfoChainHead:
        0000 e6067418 - Busy  Id=00020695  From: 0224.134c  Context=80050003  [e1323fe8 . e65fa5a8]
                   Length=0044002c  Type=00380001 (LPC_REQUEST)
                   Data: 00000001 00050242 00000000 00000000 00000000 00000000
        0000 e65fa5a8 - Busy  Id=0002e1dd  From: 0fd8.0fe0  Context=80110002  [e6067418 . e5f6a360]
                   Length=0044002c  Type=00380001 (LPC_REQUEST)
                   Data: 00000001 00050242 c03007fc c01fff7c 00000000 80a84456
        0000 e5f6a360 - Busy  Id=00037bb2  From: 1f88.1bd4  Context=8017000f  [e65fa5a8 . e1323fe8]
                   Length=0044002c  Type=00380001 (LPC_REQUEST)
                   Data: 00000001 00050242 88572278 88572290 8a386990 000015e7
    The LpcDataInfoChainHead queue contains 3 messages
    Threads in RunDown queue :     0xe6067258    0xe65fa3e8    0xe5f6a1a0
Done.           

7: kd> !thread  89815db0
THREAD 89815db0  Cid 1218.0c00  Teb: 7ff8f000 Win32Thread: 00000000 WAIT: (Unknown) UserMode Non-Alertable
    88603e40  Mutant - owning thread 884d7db0
Not impersonating
DeviceMap                 e10018b8
Owning Process            887d32d0       Image:         svchost.exe
Wait Start TickCount      426549         Ticks: 18176 (0:00:04:44.000)
Context Switch Count      42            
UserTime                  00:00:00.000
KernelTime                00:00:00.000
Win32 Start Address 0×00037bb2
LPC Server thread working on message Id 37bb2
Start Address 0×77e617ec
Stack Init f60e0000 Current f60dfc60 Base f60e0000 Limit f60dd000 Call 0
Priority 9 BasePriority 8 PriorityDecrement 0
Kernel stack not resident.
ChildEBP RetAddr  Args to Child             
f60dfc78 8083d5b1 89815db0 89815e58 00000006 nt!KiSwapContext+0×26
f60dfca4 8083df9e 00000000 00000000 00000000 nt!KiSwapThread+0×2e5
f60dfcec 8092ae57 88603e40 00000006 00000001 nt!KeWaitForSingleObject+0×346
f60dfd50 80833bef 000004fc 00000000 00000000 nt!NtWaitForSingleObject+0×9a
f60dfd50 7c8285ec 000004fc 00000000 00000000 nt!KiFastCallEntry+0xfc

We see that it is blocked waiting for a synchronization object (mutant, shown in magenta above) and we check the thread 884d7db0 that owns it:

7: kd> !thread 884d7db0
THREAD 884d7db0  Cid 1218.12ec  Teb: 7ffdd000 Win32Thread: 00000000 WAIT: (Unknown) UserMode Non-Alertable
    884d7f9c  Semaphore Limit 0x1
Waiting for reply to LPC MessageId 0000fa9e:
Current LPC port e121fdb8
Not impersonating
DeviceMap                 e10018b8
Owning Process            887d32d0       Image:         svchost.exe
Wait Start TickCount      11800          Ticks: 432925 (0:01:52:44.453)
Context Switch Count      111            
UserTime                  00:00:00.000
KernelTime                00:00:00.000
Win32 Start Address 0×0000fa9b
LPC Server thread working on message Id fa9b
Start Address 0×77e617ec
Stack Init f4598000 Current f4597c08 Base f4598000 Limit f4595000 Call 0
Priority 9 BasePriority 8 PriorityDecrement 0
Kernel stack not resident.
ChildEBP RetAddr  Args to Child             
f4597c20 8083d5b1 884d7db0 884d7e58 00000007 nt!KiSwapContext+0×26
f4597c4c 8083df9e 884d7f9c 884d7f70 884d7db0 nt!KiSwapThread+0×2e5
f4597c94 8093eda1 884d7f9c 00000011 80930901 nt!KeWaitForSingleObject+0×346
f4597d50 80833bef 00000560 000ebfe0 000ebfe0 nt!NtRequestWaitReplyPort+0×776
f4597d50 7c8285ec 00000560 000ebfe0 000ebfe0 nt!KiFastCallEntry+0xfc

The thread is waiting for the LPC message 0000fa9e and we look for a server thread processing it:

7: kd> !thread 898c6db0
THREAD 898c6db0  Cid 0b38.188c  Teb: 7ff4d000 Win32Thread: 00000000 WAIT: (Unknown) UserMode Non-Alertable
    884362c8  SynchronizationEvent
Not impersonating
DeviceMap                 e11399e8
Owning Process            88340758       Image:         AppB.exe
Wait Start TickCount      11801          Ticks: 432924 (0:01:52:44.437)
Context Switch Count      7            
UserTime                  00:00:00.000
KernelTime                00:00:00.000
Win32 Start Address 0x0000fa9e
LPC Server thread working on message Id fa9e
Start Address 0x77e617ec
Stack Init f5138000 Current f5137c60 Base f5138000 Limit f5135000 Call 0
Priority 9 BasePriority 8 PriorityDecrement 0
Kernel stack not resident.
ChildEBP RetAddr  Args to Child             
f5137c78 8083d5b1 898c6db0 898c6e58 00000006 nt!KiSwapContext+0x26
f5137ca4 8083df9e 00000000 00000000 00000000 nt!KiSwapThread+0x2e5
f5137cec 8092ae57 884362c8 00000006 00000001 nt!KeWaitForSingleObject+0x346
f5137d50 80833bef 0000056c 00000000 00000000 nt!NtWaitForSingleObject+0x9a
f5137d50 7c8285ec 0000056c 00000000 00000000 nt!KiFastCallEntry+0xfc

We also see that the thread 884d7db0 was working on message fa9b (shown in blue above) and therefore we can find its client thread:

7: kd> !lpc message fa9b
Searching message fa9b in threads ...
    Server thread 884d7db0 is working on message fa9b                        
Client thread 871ab9a0 waiting a reply from fa9b                         
Searching thread 871ab9a0 in port rundown queues …

Server communication port 0xe23f68b8
    Handles: 1   References: 1
    The LpcDataInfoChainHead queue is empty
        Connected port: 0xe1325c10      Server connection port: 0xe1323f68

Client communication port 0xe1325c10
    Handles: 1   References: 2
    The LpcDataInfoChainHead queue is empty

Server connection port e1323f68  Name: ApiABC
    Handles: 1   References: 43
    Server process  : 887d32d0 (svchost.exe)
    Queue semaphore : 884df210
    Semaphore state 0 (0x0)
    The message queue is empty

    Messages in LpcDataInfoChainHead:
        0000 e6067418 - Busy  Id=00020695  From: 0224.134c  Context=80050003  [e1323fe8 . e65fa5a8]
                   Length=0044002c  Type=00380001 (LPC_REQUEST)
                   Data: 00000001 00050242 00000000 00000000 00000000 00000000
        0000 e65fa5a8 - Busy  Id=0002e1dd  From: 0fd8.0fe0  Context=80110002  [e6067418 . e5f6a360]
                   Length=0044002c  Type=00380001 (LPC_REQUEST)
                   Data: 00000001 00050242 c03007fc c01fff7c 00000000 80a84456
        0000 e5f6a360 - Busy  Id=00037bb2  From: 1f88.1bd4  Context=8017000f  [e65fa5a8 . e1323fe8]
                   Length=0044002c  Type=00380001 (LPC_REQUEST)
                   Data: 00000001 00050242 88572278 88572290 8a386990 000015e7
    The LpcDataInfoChainHead queue contains 3 messages
    Threads in RunDown queue :     0xe6067258    0xe65fa3e8    0xe5f6a1a0
Done.

7: kd> !thread 871ab9a0
THREAD 871ab9a0  Cid 180c.1810  Teb: 7ffdf000 Win32Thread: bc011008 WAIT: (Unknown) UserMode Non-Alertable
    871abb8c  Semaphore Limit 0x1
Waiting for reply to LPC MessageId 0000fa9b:
Current LPC port e1325c10
Not impersonating
DeviceMap                 e10018b8
Owning Process            8963c388       Image:         AppC.exe
Wait Start TickCount      11796          Ticks: 432929 (0:01:52:44.515)
Context Switch Count      540                 LargeStack
UserTime                  00:00:00.046
KernelTime                00:00:00.062
Start Address 0x0103e1b0
Stack Init f68a4000 Current f68a3c08 Base f68a4000 Limit f689f000 Call 0
Priority 15 BasePriority 15 PriorityDecrement 0
Kernel stack not resident.
ChildEBP RetAddr  Args to Child             
f68a3c20 8083d5b1 871ab9a0 871aba48 00000004 nt!KiSwapContext+0x26
f68a3c4c 8083df9e 871abb8c 871abb60 871ab9a0 nt!KiSwapThread+0x2e5
f68a3c94 8093eda1 871abb8c 00000011 e24f0401 nt!KeWaitForSingleObject+0x346
f68a3d50 80833bef 00000150 0007fc70 0007fc70 nt!NtRequestWaitReplyPort+0x776
f68a3d50 7c8285ec 00000150 0007fc70 0007fc70 nt!KiFastCallEntry+0xfc

Finally we can draw this wait chain diagram where LPC calls are shown as red arrows:

 

- Dmitry Vostokov @ DumpAnalysis.org -

15 Responses to “Crash Dump Analysis Patterns (Part 42e)”

  1. Crash Dump Analysis » Blog Archive » Blocked GUI thread, wait chain and virtualized process: pattern cooperation Says:

    […] 2009 (0×7D9) - The Year of DebuggingIn one system even Task Manager was hanging and forced complete memory dump reveals a blocked GUI dialog thread waiting for an LPC reply: […]

  2. Crash Dump Analysis » Blog Archive » Inconsistent dump, blocked threads, wait chains, incorrect stack trace and process factory: pattern cooperation Says:

    […] that ServiceA is crucial for our system functions we examine LPC wait chains. All “Waiting for reply to LPC MessageId <…>” threads depend on another […]

  3. Crash Dump Analysis » Blog Archive » Stack trace collection, suspended threads, not my version, special process, main thread and blocked LPC chain threads: pattern cooperation Says:

    […] follow LPC chain to csrss.exe to find out another blocked thread […]

  4. Crash Dump Analysis » Blog Archive » Truncated dump, stack trace collection, waiting thread time and wait chains: pattern cooperation Says:

    […] kernel and user space stack traces not present in the output. ServiceA has many threads waiting for LPC requests during last 5 minutes (the bugcheck was forced after 3 - 4 minutes the issue manifested […]

  5. Dmitry Vostokov Says:

    The pattern has been renamed to Wait Chains (LPC/ALPC)

  6. Crash Dump Analysis » Blog Archive » Statement current, coupled processes, wait chain, spiking thread, hidden exception, message box and not my version: memory dump and trace analysis pattern cooperation Says:

    […] The thread 2484 (9B4) corresponds to thread #22 in ServiceA and it is blocked waiting for an LPC reply: […]

  7. Crash Dump Analysis » Blog Archive » Insufficient memory, handle leak, wait chain, deadlock, inconsistent dump and overaged system: pattern cooperation Says:

    […] Now we follow LPC wait chain: […]

  8. Crash Dump Analysis » Blog Archive » Crash Dump Analysis Patterns (Part 42f) Says:

    […] Here we show an example of a wait chain involving process objects. This Wait Chain pattern variation is similar to threads waiting for thread objects. When looking at stack trace collection from a complete memory dump file we see several threads in a set of processes are blocked in ALPC wait chain: […]

  9. Crash Dump Analysis » Blog Archive » Inconsistent dump, stack trace collection, LPC, thread, process, executive resource wait chains, missing threads and waiting thread time: pattern cooperation Says:

    […] from a frozen system is inconsistent, saved by LiveKd. Stack trace collection shows many threads waiting for LPC […]

  10. Crash Dump Analysis » Blog Archive » Coupled processes, wait chains, message box, waiting thread time, paged out data, incorrect stack trace, hidden exception, unknown component and execution residue: pattern cooperation Says:

    […] an LPC wait chain and see a thread blocked by a message […]

  11. Crash Dump Analysis » Blog Archive » ALPC wait chain, waiting thread time and semantic process coupling: pattern cooperation Says:

    […] link: Memory Dump Analysis ServicesIn a complete memory dump we could see ALPC wait chains leading to ServiceA.exe process with a queue of 372 messages. Additionally we could also […]

  12. Crash Dump Analysis » Blog Archive » Crash Dump Analysis Patterns (Part 42g) Says:

    […] Experts Magazine Online In addition to LPC / ALPC wait chains we can also see RPC chains in complete memory dumps and even mixed (A)LPC / RPC chains. How to […]

  13. Crash Dump Analysis » Blog Archive » Icons for Memory Dump Analysis Patterns (Part 72) Says:

    […] Experts Magazine Online Today we introduce an icon for Wait Chain (LPC/ALPC) […]

  14. Crash Dump Analysis » Blog Archive » Wait Chain Patterns Says:

    […] Wait Chain (LPC/ALPC) […]

  15. Crash Dump Analysis » Blog Archive » Crash Dump Analysis Patterns (Part 115a) Says:

    […] new pattern is called Blocked Queue and we provide an example of an ALPC port here. If we see an LPC/ALPC wait chain endpoint or just have a message address (and optionally a port address) we can check the port […]

Leave a Reply