LPC CASE2 – When things are not rosy

LPC CASE2 – When things are not rosy

  • Comments 1

Hello, this is Roy again.  In this case we will discuss a scenario where tracing a hung client thread is not possible through LPC data structures and extensions. We would rather use hints from the LPC message sent about the operation that was taking place and other heuristics to arrive at possible reason for the hang.

 

The issue is that whenever an Encrypted File is opened the server locks up. The initial analysis is to determine the reason for the server hang, whether it is low resource condition, deadlock or any other reason. After dumping all the threads and glancing over them I chose to pickup the following thread which looked interestingly abnormal. Below is the thread which is trying to do a CreateFile( ) and is stuck for 4hrs for a LPC reply. The file attempted to be created is an encrypted file. KSecDD.sys is the Kernel Security Device Driver which is used for handling key encryption, decryption tasks. In order to decrypt the file KSecDD makes a LPC request to LsaAuthenticationPort.

 

2: kd> !thread fffffade6c9f1390

THREAD fffffade6c9f1390  Cid 04b4.0790  Teb: 000007fffffd8000 Win32Thread: fffffa8008ed1d80 WAIT: (WrLpcReply) KernelMode Non-Alertable

    fffffade6c9f1710  Semaphore Limit 0x1

Waiting for reply to LPC MessageId 01561d96:

Current LPC port fffffa800380cc40

IRP List:

    fffffade6d389010: (0006,03a0) Flags: 00000884  Mdl: 00000000

    fffffade6bf55c60: (0006,03a0) Flags: 00000884  Mdl: 00000000

Impersonation token:  fffffa8002f5b620 (Level Impersonation)

Owning Process            fffffade6f97c2b0       Image:         svchost.exe

Wait Start TickCount      18281033       Ticks: 26423448 (4:18:41:06.375)

Context Switch Count      11                 LargeStack

UserTime                  00:00:00.015

KernelTime                00:00:00.000

Win32 Start Address 0x0000000003855c60

Start Address 0x0000000078d6b630

Stack Init fffffade56ea1e00 Current fffffade56e9f930

Base fffffade56ea2000 Limit fffffade56e9b000 Call 0

Priority 9 BasePriority 8 PriorityDecrement 0

 

Child-SP          RetAddr           Call Site

fffffade`56e9f970 fffff800`01054df3 nt!KiSwapContext+0x85

fffffade`56e9faf0 fffff800`0105457f nt!KiSwapThread+0x376

fffffade`56e9fb50 fffff800`0125555c nt!KeWaitForSingleObject+0x58e

fffffade`56e9fbd0 fffffade`5b19e471 nt!LpcpRequestWaitReplyPort+0x672

fffffade`56e9fc60 fffffade`5b19f88a KSecDD!EfspDecryptFek+0x131

fffffade`56e9fec0 fffffade`5b0a4f46 KSecDD!EfsDecryptFek+0x2a

fffffade`56e9ff10 fffffade`5b0a4b9d Ntfs!EFSPostCreate+0x323

fffffade`56ea0060 fffffade`5b119d70 Ntfs!EFSFilePostCreate+0x1a5

fffffade`56ea00e0 fffffade`5b1f2daa Ntfs!NtfsFsdCreate+0x425

fffffade`56ea0270 fffffade`59976284 fltMgr!FltpCreate+0x34a

fffffade`56ea0300 fffffade`5997ed4c SomeFSFilter+0x9284

fffffade`56ea0360 fffffade`5997637f SomeFSFilter+0x11d4c

fffffade`56ea0390 fffffade`5b1d759a SomeFSFilter+0x937f

fffffade`56ea0400 fffffade`5b1f2e14 fltMgr!FltpLegacyProcessingAfterPreCallbacksCompleted+0x41a

fffffade`56ea0470 fffff800`01295ede fltMgr!FltpCreate+0x3b4

fffffade`56ea0500 fffff800`0128ea00 nt!IopParseDevice+0x108f

fffffade`56ea06b0 fffff800`012909a7 nt!ObpLookupObjectName+0x923

fffffade`56ea07c0 fffff800`01296a14 nt!ObOpenObjectByName+0x180

fffffade`56ea09b0 fffff800`01296bb7 nt!IopCreateFile+0x630

fffffade`56ea0b40 fffffade`599e2a67 nt!IoCreateFile+0x12f

fffffade`56ea0c20 fffffade`599e3c91 SomeFSFilter+0x47a67

fffffade`56ea0ce0 fffffade`599e62e9 SomeFSFilter+0x48c91

fffffade`56ea0d10 fffffade`599aacd3 SomeFSFilter+0x4b2e9

fffffade`56ea0e00 fffffade`599aad6e SomeFSFilter+0xfcd3

fffffade`56ea0ea0 fffffade`599bea96 SomeFSFilter+0xfd6e

fffffade`56ea0ed0 fffffade`599ae142 SomeFSFilter+0x23a96

fffffade`56ea0f90 fffffade`599ae7f1 SomeFSFilter+0x13142

fffffade`56ea1070 fffffade`5999c0e3 SomeFSFilter+0x137f1

fffffade`56ea10a0 fffffade`599ae848 SomeFSFilter+0x10e3

fffffade`56ea10d0 fffffade`599ae8c3 SomeFSFilter+0x13848

fffffade`56ea1120 fffffade`599a9a96 SomeFSFilter+0x138c3

fffffade`56ea1160 fffffade`599a782f SomeFSFilter+0xea96

fffffade`56ea11a0 fffffade`599a7a02 SomeFSFilter+0xc82f

fffffade`56ea11e0 fffffade`5997d484 SomeFSFilter+0xca02

fffffade`56ea1230 fffffade`599800f4 SomeFSFilter+0x10484

fffffade`56ea1260 fffffade`5998038d SomeFSFilter+0x130f4

fffffade`56ea1290 fffffade`5997ecbc SomeFSFilter+0x1338d

fffffade`56ea12c0 fffffade`5997637f SomeFSFilter+0x11cbc

fffffade`56ea12f0 fffffade`5b1d759a SomeFSFilter+0x937f

fffffade`56ea1360 fffffade`5b1f2e14 fltMgr!FltpLegacyProcessingAfterPreCallbacksCompleted+0x41a

fffffade`56ea13d0 fffff800`01295ede fltMgr!FltpCreate+0x3b4

fffffade`56ea1460 fffff800`0128ea00 nt!IopParseDevice+0x108f

fffffade`56ea1610 fffff800`012909a7 nt!ObpLookupObjectName+0x923

fffffade`56ea1720 fffff800`01296a14 nt!ObOpenObjectByName+0x180

fffffade`56ea1910 fffff800`01296bb7 nt!IopCreateFile+0x630

fffffade`56ea1aa0 fffff800`01298479 nt!IoCreateFile+0x12f

fffffade`56ea1b80 fffff800`0104fce2 nt!NtCreateFile+0x69

fffffade`56ea1c00 00000000`78ef17ba nt!KiSystemServiceCopyEnd+0x3

00000000`00bbf258 00000000`00000000 0x78ef17ba

 

 

Using the message Id mentioned in the “!thread” output we dump the LPC message. The output has two anomalies.

  1. No server thread has been listed which is processing the client request.
  2. The message queue as well as the LpcDataInfoChain is empty.

 

 

Answers to both questions are very specific to LSASS. Most types of client requests received on LsaAuthenticationPort do not have extra data. As mentioned in CASE 1, server threads dequeue the message and chain it to LpcDataInfoChainHead only if the message contains extra information. If the message does not contain any extra data then the server does not need to store the message anywhere. The server would only need to remember the kind of request carried by the message.

 

!lpc message searches the ETHREAD.LpcReceiveMessageId field to determine which server thread is processing the message. The way LSASS handles LPC request is that there is a single thread in LSASS that dequeues all messages from the connection port message queue and enqueues them to an LSASS specific internal queue. LSASS has a pool of worker threads that wait for requests in the internal queue. The worker threads dequeue the request, process it and reply back to the client. Hence the single LPC server thread in LSASS has its LpcReceiveMessageId overwritten by a new one every time it dequeues a message and enqueues it to the internal queue. That is the reason !lpc message fails to find a server thread for the LPC message sent to LsaAuthenticationPort.

 

 

 

 

2: kd> !LPC MESSAGE 01561d96

Searching message 1561d96 in threads ...

Client thread fffffade6c9f1390 waiting a reply from 1561d96                         

Searching thread fffffade6c9f1390 in port rundown queues ...

 

Server communication port 0x033fc660

    Handles: 1   References: 1

    The LpcDataInfoChainHead queue is empty

        Connected port: 0xfffffa800380cc40      Server connection port: 0xfffffa800282ca40

 

Client communication port 0xfffffa800380cc40

    Handles: 0   References: 1

    The LpcDataInfoChainHead queue is empty

 

Server connection port fffffa800282ca40  Name: LsaAuthenticationPort

    Handles: 1   References: 83

    Server process  : fffffade6ead0040 (lsass.exe)

    Queue semaphore : fffffade6e9513c0

    Semaphore state 0 (0x0)

    The message queue is empty

    The LpcDataInfoChainHead queue is empty

Done.  

 

 

 

Then how do you find the server thread that is responsible for replying back to the client and why it isn’t replying? Well there are many ways to do so depending upon the scenario. The way I chose was to look at all threads in LSASS which either have function calls on the stack that relate to the KSecDD request made or other hints. The reason threads only in LSASS were checked is because we knew that the request was sent to LsaAuthenticationPort and will be processed within LSASS. The hint was in the Wait Tick Count of the thread. I found a thread which had exactly the same Wait Tick Count as the client thread that was waiting for a reply. Further investigation of the thread confirmed that it was the one responsible for processing the request from KSecDD.

 

 

 

2: kd> !thread fffffade6fa01460

THREAD fffffade6fa01460  Cid 03a4.0100  Teb: 000007fffff8e000 Win32Thread: 0000000000000000 WAIT: (Executive) KernelMode Non-Alertable

    fffffade6f665820  Semaphore Limit 0x1

    fffffade6f665840  NotificationEvent

IRP List:

    fffffade6bb9a830: (0006,03a0) Flags: 00000884  Mdl: 00000000

Impersonation token:  fffffa80044d11c0 (Level Impersonation)

Owning Process            fffffade6ead0040       Image:         lsass.exe

Wait Start TickCount      18281033       Ticks: 26423448 (4:18:41:06.375)

Context Switch Count      509109            

UserTime                  00:01:54.500

KernelTime                00:00:33.765

Win32 Start Address 0x0000000000c21aa0

Start Address 0x0000000078d6b630

Stack Init fffffade5a894e00 Current fffffade5a893e40

Base fffffade5a895000 Limit fffffade5a88f000 Call 0

Priority 13 BasePriority 9 PriorityDecrement 0

 

Child-SP          RetAddr           Call Site

fffffade`5a893e80 fffff800`01054df3 nt!KiSwapContext+0x85

fffffade`5a894000 fffff800`0105518f nt!KiSwapThread+0x376

fffffade`5a894060 fffffade`599a8b28 nt!KeWaitForMultipleObjects+0x66e

fffffade`5a8940f0 fffffade`599a7808 SomeFSFilter+0xdb28

fffffade`5a8941a0 fffffade`599a7a02 SomeFSFilter+0xc808

fffffade`5a8941e0 fffffade`5997d484 SomeFSFilter+0xca02

fffffade`5a894230 fffffade`599800f4 SomeFSFilter+0x10484

fffffade`5a894260 fffffade`5998038d SomeFSFilter+0x130f4

fffffade`5a894290 fffffade`5997ecbc SomeFSFilter+0x1338d

fffffade`5a8942c0 fffffade`5997637f SomeFSFilter+0x11cbc

fffffade`5a8942f0 fffffade`5b1d759a SomeFSFilter+0x937f

fffffade`5a894360 fffffade`5b1f2e14 fltMgr!FltpLegacyProcessingAfterPreCallbacksCompleted+0x41a

fffffade`5a8943d0 fffff800`01295ede fltMgr!FltpCreate+0x3b4

fffffade`5a894460 fffff800`0128ea00 nt!IopParseDevice+0x108f

fffffade`5a894610 fffff800`012909a7 nt!ObpLookupObjectName+0x923

fffffade`5a894720 fffff800`01296a14 nt!ObOpenObjectByName+0x180

fffffade`5a894910 fffff800`01296bb7 nt!IopCreateFile+0x630

fffffade`5a894aa0 fffff800`01298479 nt!IoCreateFile+0x12f

fffffade`5a894b80 fffff800`0104fce2 nt!NtCreateFile+0x69

fffffade`5a894c00 00000000`78ef17ba nt!KiSystemServiceCopyEnd+0x3

 

 

Having all the facts makes understanding the problem easier. SomeFSFilter.sys is an anti-virus driver that scans every file opened. During the open of an encrypted file it tries to scan the file before it is opened. For doing so it requests KSecDD to decrypt the file. KSecDD sends a LPC request to LsaAuthenticationPort for key decryption. LSASS as part of processing the request tries to open a file which for some reason is blocked by SomeFSFilter.sys. So we have a classic deadlock situation where SomeFSFilter.sys is waiting on LSASS to reply to the LPC message while LSASS is waiting on SomeFSFilter.sys for opening a file.

 

In this scenario we could only use minimal help from the LPC debugger extension because of the way LPC requests were handled by LSASS. In such situations other heuristics are required to debug the problem.

 

Finally, our journey through the world of LPC comes to an end. LPC has been the backbone of local inter-process communication since the NT4.0 days but as everything has a shell life, so did LPC. LPC has been replaced by ALPC (Asynchronous LPC) in Vista and Server 2008. The LPC APIs are now implemented over the new ALPC APIs to maintain compatibility. Although the LPC APIs are not exported, neither is there a requirement to call them directly, nevertheless having an understanding of the API helps in debugging as we have seen in the posts.

Hope this information helps. Happy debugging!!!

 

Leave a Comment
  • Please add 6 and 8 and type the answer here:
  • Post
  • hi, i was looking for some debugging books and google leads me to your site, this is a very great site full of excellent techniques that I would like to learn. As I'm just a newbie on trying to learn using windbg, a lot of things are fun to me, although most of the article I still have trouble in reading even after several years using VC. Hope I'll soon learn the trick of this.  Just leave a message to thank you for having such a great site!!

    It's very informative and useful.

Page 1 of 1 (1 items)