• Ntdebugging Blog

    NonPagedPool Depletion

    • 1 Comments

    I recently was engaged on an issue where a server was depleting NonPagedPool over a period of a few days.  Ordinarily, we would just use a tool like PoolMon to identify the offending pool tag and then find the driver that uses that pool tag using the method in this article

     

    However, what made this case interesting was the pool tag and that we were unable to identify the driver using the normal methodology.  You’ll see what I mean in a moment.  The engineer supplied me with a kernel dump of the server while it was in-state and this is what I found.

     

    Let’s start by taking a look at the virtual memory usage:

     

    2: kd> !vm

     

    *** Virtual Memory Usage ***

           Physical Memory:      851420 (   3405680 Kb)

           Page File: \??\C:\pagefile.sys

             Current:   3584000 Kb  Free Space:   3568552 Kb

             Minimum:   3584000 Kb  Maximum:      3584000 Kb

           Available Pages:      573277 (   2293108 Kb)

           ResAvail Pages:       800628 (   3202512 Kb)

           Locked IO Pages:        1067 (      4268 Kb)

           Free System PTEs:      25102 (    100408 Kb)

           Free NP PTEs:            335 (      1340 Kb)

           Free Special NP:           0 (         0 Kb)

           Modified Pages:           22 (        88 Kb)

           Modified PF Pages:        22 (        88 Kb)

           NonPagedPool Usage:    31369 (    125476 Kb)    ß Very high

           NonPagedPool Max:      31986 (    127944 Kb)

           ********** Excessive NonPaged Pool Usage *****

           PagedPool 0 Usage:     19071 (     76284 Kb)

           PagedPool 1 Usage:       735 (      2940 Kb)

           PagedPool 2 Usage:       747 (      2988 Kb)

           PagedPool 3 Usage:       720 (      2880 Kb)

           PagedPool 4 Usage:       746 (      2984 Kb)

           PagedPool Usage:       22019 (     88076 Kb)

           PagedPool Maximum:     38912 (    155648 Kb)

     

           ********** 3 pool allocations have failed **********

     

    So we can see that NPP usage is very high given the server is using the /3GB switch which limits NPP to 128MB by default.  We need to identify what pool tag is associated with the high NPP usage:

     

    2: kd> !poolused /t2 2

       Sorting by  NonPaged Pool Consumed

     

      Pool Used:

                NonPaged            Paged

     Tag    Allocs     Used    Allocs     Used

     None   246479 50827424         0        0      call to ExAllocatePool

     MmCm     1198 18462512         0        0      Calls made to MmAllocateContiguousMemory , Binary: nt!mm

     

    Interesting, so the offending tag is “None”.  This means that these allocations were made by calling the function ExAllocatePool instead of ExAllocatePoolWithTag.  ExAllocatePool is obsolete and should no longer be used. 

     

    Now, I need to find out which driver is calling this function.  First, I need to know where ExAllocatePool lives:

     

    2: kd> x nt!ExAllocatePool

    e0894d1f nt!ExAllocatePool

     

    Next, I need to search all the drivers to see which one is importing this function:

     

    2: kd> !for_each_module s-d @#Base @#End e0894d1f

    f50b8058  e0894d1f e0828e04 e089b708 e084011b  .M..............

     

    Hmm, looks suspiciously like an import table, let’s see:

     

    2: kd> dps f50b8058

    f50b8058  e0894d1f nt!ExAllocatePool

    f50b805c  e0828e04 nt!_wcsnicmp

    f50b8060  e089b708 nt!ExFreePoolWithTag

    f50b8064  e083e30a nt!KeInitializeEvent

    <SNIP>

     

    Yep, that’s an import table.  You can also verify that this is the import table of a particular module by checking the header (!dh on the module’s base address and look for “Import Address Table Directory”).

     

    As you can see, we have only one driver that imports ExAllocatePool.  Let’s see which driver this is:

     

    2: kd> !lmi f50b8058

    Loaded Module Info: [f50b8058]

             Module: {XXXXXXXX-XXXX-XXXX-XXXX-XXXXXXXXXXXX}

       Base Address: f50b3000

         Image Name: {XXXXXXXX-XXXX-XXXX-XXXX-XXXXXXXXXXXX}.sys

           <SNIP>

     

    I’ve removed the incriminating identifiers from module information displayed above to protect the guilty.  It is interesting to note that the driver name was a GUID and that this driver did not exist on the disk.  This was because the driver is dynamically created when its parent program loads.  

     

    The software package was removed and the server was happy again. 

     

    -         David

  • Ntdebugging Blog

    The Case of the Low Hanging Filter Driver Fruit

    • 1 Comments

     

    Written By Jeff Dailey:

     

    Not all our cases are crashes, leaks, or high CPU.  Sometimes the problems we are faced with are purely a question of why a given application runs slow on a particular version of Windows versus another version of windows.  In other cases an application may just start running slow for no reason.   OK, not likely.  There is ALWAYS SOME RESASON.  Something changed!  In this case, the customer reported that an application started running slow when booted into “Normal Mode”, but when the OS was booted in safe mode, the application would run fast.  In this particular case the customer reported that a given operation went from taking just a few seconds (safe mode) to several minutes (normal mode).   Further research found that the problem was related to accessing the registry and registry performance in general.  At this point I’m already thinking, “Registry Access?” and “Safe Mode”.  What could affect registry access that does not run in safe mode?  Well lots of services DO NOT start in safe mode.  What kind of services could affect registry calls?  Antivirus?  Maybe…  Let’s look deeper.

     

    One of the first things I typically do in such cases is to ask for a kernrate log of the slow and fast scenario. http://download.microsoft.com/download/8/e/c/8ec3a7d8-05b4-440a-a71e-ca3ee25fe057/rktools.exe  Kernrate is a sampling profiler.   It basically checks the location of the instruction pointer at regular intervals and stores the results in a hash table.   We can then get a breakdown of the %time spent in each module that is executing.    Even better you can zoon in to each module.  Zooming in shows utilization at a function level within the module and requires symbols to be present in a flat symbol directory on the machine being profiled.  I recommend downloading the symbol pack for this (http://www.microsoft.com/whdc/devtools/debugging/symbolpkg.mspx) or use symchk.exe (included in the debugging tools) to download the symbols.  We’ll talk more about symbols and symchk.exe in an upcoming post.

     

    In a lot of cases kernrate data is only a starting point.   We will find some code that is running a lot longer in one case verses another and that in turn requires a follow up code review and multiple debugs to further isolate the problem.  This case however was different.  The following is output from beyond compare that shows a comparison between the module execution time in kernel.   The slow test run is on the right, and the fast test run is on the left.  Keeping in mind that I was looking for something different between safe mode and normal mode, I simply started by looking at the modules listed on the slow side (Right) there were not on the fast side (Left).   What was loaded during the normal run that was not a factor during the safe mode run.  Right away FILTERDRVXYZ just above the HAL jumped off the page.  (Some names were changed to protect the innocent. J)  I did a http://www.live.com search to find out what this driver was.  It was a file system filter driver for an antivirus program.

     

    To understand why a filter driver can slow things down you need to understand that a filter driver basically installs itself between the application and the underlying file system and intercepts nearly every call being made to the underlying I/O subsystem.   Most of the time filter drivers are just fine and run with no problems at all.   However, what do they do?  An antivirus filter driver may have several tasks that it needs to do for each I/O.  This may involve looking up information about a process or file when it’s being accessed.   If the data source associated with this information changes it can change the amount of time that these operations take.   The interesting thing is that the timing change may only be a hundred or so extra milliseconds per call to the registry or file system.  Under most cases a user would not even notice this.  If however you have some aspect of your application needs to make many thousands of calls and they each take 250+ milliseconds vs. 10 milliseconds, all of a sudden the problem compounds.  The classic example of this is a VIRUS PROFILE gets uploaded or pushed to servers and all of a sudden the customer starts seeing performance problems because the data set or comparison for the filter driver changes.   In this case I simply recommended that the customer remove the suspect filter driver to see if it was the root of the problem.  IT WAS…  They contacted the product vendor to get an update and the case was resolved.

     

    Good luck and happy debugging….

  • Ntdebugging Blog

    Disassemble the MBR

    • 1 Comments

     

    UPDATE:  This is why we *LOVE* our readers!  After posting a 32-bit disassembly of 16-bit MBR code, I was gently informed of my misstep by three sharp-eyed readers.  I’ve corrected the original post below.  Thanks go out to Ramon Sola, Jeroen Frijters and 'pedantic gnome' for keeping us honest.  Thanks guys!

     

     

    Hi Everyone,

     

    One of our readers, Pete, asked a very interesting question about disassembling the MBR and I'd like to take a moment to show you the quick & dirty way to do this.

     

    First, dump the MBR to a file using a low-level sector editor such as the Microsoft Resource Kit utility DiskProbe.  Once you've saved the file, launch a program (like Notepad) and attach to it using Windbg (the Windows Debugger). 

     

    Next, find a valid, but unoccupied range of memory (the default heap is a good candidate).  The memory range needs to be at least 512 (0x200) bytes.  For example, here's where I found mine:

     

    000120a0  00000000 00000000 00000000 00000000

    000120b0  00000000 00000000 00000000 00000000

    000120c0  00000000 00000000 00000000 00000000

    000120d0  00000000 00000000 00000000 00000000

    000120e0  00000000 00000000 00000000 00000000

    000120f0  00000000 00000000 00000000 00000000

    00012100  00000000 00000000 00000000 00000000

    00012110  00000000 00000000 00000000 00000000

    00012120  00000000 00000000 00000000 00000000

    <snip>...

     

    Once you've found a good memory range in your process, read the file contents into that memory location using the following command:

     

    0:001> .readmem c:\<<path>>\sector00.bin 120a0 120a0+0x1ff

     

    Tada!  You now have the MBR in memory and it is fully examinable just like any other assembly code. 

     

    0:001> db 000120a0 

    000120a0  33 c0 8e d0 bc 00 7c 8e-c0 8e d8 be 00 7c bf 00  3.....|......|..

    000120b0  06 b9 00 02 fc f3 a4 50-68 1c 06 cb fb b9 04 00  .......Ph.......

    000120c0  bd be 07 80 7e 00 00 7c-0b 0f 85 10 01 83 c5 10  ....~..|........

    000120d0  e2 f1 cd 18 88 56 00 55-c6 46 11 05 c6 46 10 00  .....V.U.F...F..

    000120e0  b4 41 bb aa 55 cd 13 5d-72 0f 81 fb 55 aa 75 09  .A..U..]r...U.u.

    000120f0  f7 c1 01 00 74 03 fe 46-10 66 60 80 7e 10 00 74  ....t..F.f`.~..t

    00012100  26 66 68 00 00 00 00 66-ff 76 08 68 00 00 68 00  &fh....f.v.h..h.

    00012110  7c 68 01 00 68 10 00 b4-42 8a 56 00 8b f4 cd 13  |h..h...B.V.....

     

    Since this is 16-bit assembly, you can unassemble using ‘ur’:

    0:001> ur 120a0
    000120a0 33c0            xor     ax,ax
    000120a2 8ed0            mov     ss,ax
    000120a4 bc007c          mov     sp,7C00h
    000120a7 8ec0            mov     es,ax
    000120a9 8ed8            mov     ds,ax
    000120ab be007c          mov     si,7C00h
    000120ae bf0006          mov     di,600h
    000120b1 b90002          mov     cx,200h
    <snip>...

     

    Have fun Pete!

     

    DiskProbe:       http://technet.microsoft.com/en-us/library/bb457122.aspx

    WinDbg:           http://www.microsoft.com/whdc/devtools/debugging/default.mspx

     

      - David

  • Ntdebugging Blog

    How to Find the Owner of a Named Pipe

    • 1 Comments

    This is a follow-up on the LPC hang blog. The same hang troubleshooting techniques apply to this, but when a named pipe is involved you’ll have to use a slightly different method to following the chain from a client application to the server application. For the purpose of this exercise I’ll use the named pipe server (http://msdn2.microsoft.com/en-us/library/aa365588.aspx) and client (http://msdn2.microsoft.com/en-us/library/aa365592.aspx) given by MSDN.

     

     

    Here is a diagram of our scenario.

    named_pipes

     

    Here we have the client application that is waiting on a read operation to a named pipe. We need to determine what process will be putting data into the named pipe which will let the client application move forward.

    Here is the thread in the client application.

     

     

    THREAD 81e70858  Cid 06bc.06c0  Teb: 7ffdf000 Win32Thread: 00000000 WAIT: (Executive) UserMode Non-Alertable

        81baaf7c  NotificationEvent

    Not impersonating

    DeviceMap                 e25176b8

    Owning Process            81b3a020       Image:         client.exe

    Attached Process          N/A            Image:         N/A

    Wait Start TickCount      73194          Ticks: 1599 (0:00:00:24.984)

    Context Switch Count      21            

    UserTime                  00:00:00.000

    KernelTime                00:00:00.000

    Win32 Start Address client (0x00401376)

    Start Address kernel32!BaseProcessStartThunk (0x77e617f8)

    Stack Init f7450000 Current f744fc04 Base f7450000 Limit f744d000 Call 0

    Priority 10 BasePriority 8 PriorityDecrement 2

    ChildEBP RetAddr  Args to Child             

    f744fc1c 808202b6 81e70858 81e70900 00000700 nt!KiSwapContext+0x25 (FPO: [Uses EBP] [0,0,4])

    f744fc34 8081fb6e 8207dac0 00000000 81baaf20 nt!KiSwapThread+0x83 (FPO: [Non-Fpo])

    f744fc78 8092deb3 81baaf7c 00000000 81f93601 nt!KeWaitForSingleObject+0x2e0 (FPO: [Non-Fpo])

    f744fca0 80924ca9 81f936e0 00000103 81baaf20 nt!IopSynchronousServiceTail+0x180 (FPO: [Non-Fpo])

    f744fd38 8082350b 00000024 00000000 00000000 nt!NtReadFile+0x5d5 (FPO: [Non-Fpo])

    f744fd38 7c8285ec 00000024 00000000 00000000 nt!KiFastCallEntry+0xf8 (FPO: [0,0] TrapFrame @ f744fd64)

    0012eed4 7c82776b 77e418b2 00000024 00000000 ntdll!KiFastSystemCallRet (FPO: [0,0,0])

    0012eed8 77e418b2 00000024 00000000 00000000 ntdll!NtReadFile+0xc (FPO: [9,0,0])

    0012ef40 004010ab 00000024 0012ef60 00001000 kernel32!ReadFile+0x16c (FPO: [Non-Fpo])

    0012ff78 0040131f 00000001 00323038 00323078 client+0x10ab

    0012ffc0 77e6f23b 00000000 00000000 7ffd8000 client+0x131f

    0012fff0 00000000 00401376 00000000 78746341 kernel32!BaseProcessStart+0x23 (FPO: [Non-Fpo])

     

    We have highlighted the first parameter to the ReadFile function. This parameter is the handle to the file we are trying to read.

    Knowing this we can use the !handle extension to display details on this handle. The !handle extension takes three parameters: 1. The handle to get details on, 2: a flag controlling the level of verbosity the extension will display (f being the most verbose level), and 3: the process address.

     

    kd> !handle 00000024 f 81b3a020

    processor number 0, process 81b3a020

    PROCESS 81b3a020  SessionId: 0  Cid: 06bc    Peb: 7ffd8000  ParentCid: 0f2c

        DirBase: 1d486000  ObjectTable: e252bbc8  HandleCount:  10.

        Image: client.exe

    Handle table at e2845000 with 10 Entries in use

    0024: Object: 81baaf20  GrantedAccess: 0012019f Entry: e2845048

    Object: 81baaf20  Type: (823ceca0) File

        ObjectHeader: 81baaf08 (old version)

            HandleCount: 1  PointerCount: 3

            Directory Object: 00000000  Name: \mynamedpipe {NamedPipe}

    We have highlighted the object address (yellow) and the type of the object (green) above. The object is of type file which is defined by the FILE_OBJECT structure. So we can examine that using the dt (Display Type) command. The dt command can take 3 parameters: 1. The structure you want to cast the data as, 2: the address of the object, and 3: the field in the structure to be displayed.

     

    kd> dt nt!_FILE_OBJECT 81baaf20 FsContext2

       +0x010 FsContext2       : 0x81b5cc90

     

    The FsContext2 field points to an NPFS CCB structure. The importance of this structure is that it is charged to the server process which created it. The !pool extension can be used to display information about the ownership of the memory the file object is stored in.

     

    kd> !pool 0x81b5cc90  2

    Pool page 81b5cc90 region is Nonpaged pool

    *81b5cc88 size:   50 previous size:  140  (Allocated) *NpFc Process: 81be0d88

                  Pooltag NpFc : CCB, client control block, Binary : npfs.sys

    PROCESS 81be0d88  SessionId: 0  Cid: 07b4    Peb: 7ffd4000  ParentCid: 0160

        DirBase: 02b6f000  ObjectTable: e234a530  HandleCount:  10.

        Image: server.exe

     

     

    Now you have the established the link from the client application and the server application. Now you will be able to move forward in your debugging and figure out why the server process isn’t writing data back to the client.

     

    - Bryan

  • Ntdebugging Blog

    WE ARE HIRING

    • 1 Comments

    Want to debug the most difficult problems against the largest, most complex piece of software ever written? Are you fluent in C and assembly? Do you carry a spare debugger cable in your bag? Can you represent Microsoft in critical, time sensitive solution delivery? Writing code is easy, finding bugs in someone else’s code you’ve never seen before is a real challenge.

     

    Want to hear more?

     

    http://blogs.msdn.com/jobsblog/archive/2007/01/26/jobcast-life-as-an-escalation-engineer.aspx

     

    http://blogs.msdn.com/jobsblog/archive/2007/11/21/life-as-an-escalation-engineer-part-ii.aspx

     

     

    Candidate must be a strong critical thinker, and enjoy solving very difficult problems (often involving code level analysis).  Escalation Engineers within GES are frequently involved with the highest profile issues, and therefore must be able to handle both pressure and complex situations. Candidates must also have strong customer service, accurate logical problem solving and communication skills, and the ability to work in a team environment. Programming and debugging skills are required, preferably in C or C++.  Also, the ability to read and analyze network traces and solid protocol analysis is a plus. The ideal candidate may have a four year degree in C.S. or Engineering and a minimum of four years product support experience or the equivalent in work experience. Prior knowledge of the product to be supported, and other networking products and/or networking operating systems is required. If you enjoy being the problem-solver in the spotlight of critical problems, then this position will excite and challenge you.

     

     

    Applicants that possess the experience, and desire will be considered and are encouraged to apply using the below link. After applying, please submit a copy of your resume to benjammc@microsoft.com

     

    Job Details - Microsoft Careers job code is 209923 and can be found on the Microsoft Career page.

     

     

  • Ntdebugging Blog

    LPC part 2 Kernel Debugger Extensions

    • 1 Comments

    Hello my name is Roy, I’m an EE on the Microsoft global escalation services / CPR team.   This blog is a follow on to my first LPC blog.  We will be discussing debugger extensions that allow you to look at LPC related issues.

     

    Disclaimer: The purpose of this blog is to illustrate debugging techniques with LPC. Please do not rely on this information as documentation for the APIs when writing your own code. As always, this is subject to change in the future.  

     

    LPC Kernel Debugger Extensions

     

     

    Command

    Description

    !lpc                    

    Display the list and description of all the !lpc commands

    !lpc message [MessageId]

    Display the message with a given ID and all related information by attempting to match the given Message ID to the EHTREAD->LpcReceivedMessageId and to the ETHREAD->LpcReplyMessageId of all threads in the system.

    If the MessageId parameter is omitted then it attempts to display all the outstanding messages in the system by searching for the tag ‘LpcM’ in the pools.

    !lpc port [PortAddress] 

    Displays port information. If a server connection port address is specified then only information about that port is displayed. If either a client or server communication port is specified it prints information about the specified communication port, the peer communication port and the server connection port.

    If the PortAddress parameter is omitted then it attempts to walk the list of all objects of type “Port” and “WaitablePort” and display them. Note that for this feature to work the GFlags option “+otl” i.e. “Maintain a list of objects for each type” must be enabled.

    !lpc scan PortAddress   

    Displays port information. It attempts to walk the list of all objects of type “Port” and “WaitablePort” and display the one matching the specified port address. Note that for this feature to work the GFlags option “+otl” i.e. “Maintain a list of objects for each type” must be enabled.

    !lpc thread [ThreadAddr]

    If  ThreadAddr is specified it walks the list of threads in the ETHREAD-> LpcReplyChain to locate the list head i.e. a “Port” or “WaitablePort” object on which the thread is waiting for a reply.

    If the ThreadAddr parameter is omitted then it attempts to find all LPC server threads by looking for threads with a non-NULL EHTREAD->LpcReceivedMessageId and all client threads by looking for threads with a non-NULL ETHREAD->LpcReplyMessageId and displays them.

    !lpc PoolSearch

    Toggles a setting that controls whether the “lpc message” command will search for LPC message tag (‘LpcM’) in the kernel pools or not.

     

     

     

    LPC Kernel Debugger Extension Usage

     

     

    LPC Connection Port information from call stack

     

    On the call stack of any client or server threads blocked on LPC data transfer or LPC connection there will be a frame containing either one of the functions  NtRequestWaitReplyPort() or NtReplyWaitReceivePortEx() . The first parameter to either one of these functions is the handle to the port they are blocked on.

     

    kd> !thread 810de2a8 

    THREAD 810de2a8  Cid 01dc.01f4  Teb: 7ffde000 Win32Thread: 00000000 WAIT: (WrLpcReceive) UserMode Non-Alertable

        81131188  Semaphore Limit 0x7fffffff

        810de398  NotificationTimer

    Not impersonating

    DeviceMap                 e196c460

    Owning Process            810ddda0       Image:         rpclpcs.exe

    Wait Start TickCount      64555          Ticks: 402 (0:00:00:04.025)

    Context Switch Count      2            

    UserTime                  00:00:00.000

    KernelTime                00:00:00.000

    Win32 Start Address 0x77e76bf0

    Start Address 0x7c810856

    Stack Init f8e28000 Current f8e27c4c Base f8e28000 Limit f8e25000 Call 0

    Priority 8 BasePriority 8 PriorityDecrement 0 DecrementCount 0

    ChildEBP RetAddr  Args to Child             

    f8e27c64 804dc6a6 810de318 810de2a8 804dc6f2 nt!KiSwapContext+0x2e (FPO: [Uses EBP] [0,0,4])

    f8e27c70 804dc6f2 e1084108 8055a540 e1084108 nt!KiSwapThread+0x46 (FPO: [0,0,0])

    f8e27c98 8056a50a 00000001 00000010 00000001 nt!KeWaitForSingleObject+0x1c2 (FPO: [Non-Fpo])

    f8e27d48 804df06b 000007c4 002bff70 00000000 nt!NtReplyWaitReceivePortEx+0x3dc (FPO: [Non-Fpo])

    f8e27d48 7c90eb94 000007c4 002bff70 00000000 nt!KiFastCallEntry+0xf8 (FPO: [0,0] TrapFrame @ f8e27d64)

    002bff80 00000000 00000000 00000000 00000000 ntdll!KiFastSystemCallRet (FPO: [0,0,0])

     

    kd> !handle 7c4 3 810ddda0       

    processor number 0, process 810ddda0

    PROCESS 810ddda0  SessionId: 0  Cid: 01dc    Peb: 7ffd9000  ParentCid: 01b4

        DirBase: 058cd000  ObjectTable: e1a13278  HandleCount:  18.

        Image: rpclpcs.exe

     

    Handle table at e107d000 with 18 Entries in use

    07c4: Object: e1084108  GrantedAccess: 001f0001 Entry: e107df88

    Object: e1084108  Type: (812b5c80) Port

        ObjectHeader: e10840f0 (old version)

            HandleCount: 1  PointerCount: 4

            Directory Object: e14c72c8  Name: rpclpc

     

    kd> !lpc port e1084108

     

    Server connection port e1084108  Name: rpclpc

        Handles: 1   References: 4

        Server process  : 810ddda0 (rpclpcs.exe)

        Queue semaphore : 81131188

        Semaphore state 0 (0x0)

        The message queue is empty

        The LpcDataInfoChainHead queue is empty

     

     

    LPC Messages that are waiting to be picked up by the server thread

     

    When a message is queued to the server connection port and the server thread has not yet not been signaled to pull out the message the ‘!lpc port <Port>” displays the following output that includes the message.

     

    kd> !lpc port e10d8388

     

    Client communication port 0xe10d8388

        Handles: 1   References: 2

        The LpcDataInfoChainHead queue is empty

            Connected port: 0xe106dc00      Server connection port: 0xe15512e0

     

    Server communication port 0xe106dc00

        Handles: 1   References: 1

        The LpcDataInfoChainHead queue is empty

     

    Server connection port e15512e0  Name: rpclpc

        Handles: 1   References: 9

        Server process  : ffbbebe8 (rpclpcs.exe)

        Queue semaphore : 81250848

        Semaphore state 0 (0x0)

            Messages in queue:

            0000 e10513f8 - Busy  Id=000048d8  From: 05f4.0108  Context=80020000  [e15512f0 . e15512f0]

                       Length=0054003c  Type=00000001 (LPC_REQUEST)

                       Data: 00000001 00000241 00000000 00000000 f877bc04 804ec10e

        The message queue contains 1 messages

        The LpcDataInfoChainHead queue is empty

     

     

    LPC Messages being processed by the server

     

    When an LPC message has been queued by the client, dequeued by the sever and being worked upon by the server both the client and the server thread have the message ID associated with them

     

    kd> !lpc message 16fa

    Searching message 16fa in threads ...

        Server thread 810de2a8 is working on message 16fa                        

    Client thread 810dc930 waiting a reply from 16fa                         

    Searching thread 810dc930 in port rundown queues ...

     

    Server connection port e1084108  Name: rpclpc

        Handles: 1   References: 3

        Server process  : 810ddda0 (rpclpcs.exe)

        Queue semaphore : 81131188

        Semaphore state 0 (0x0)

        The message queue is empty

        The LpcDataInfoChainHead queue is empty

    Done.                                             

     

    kd> !thread 810de2a8

    THREAD 810de2a8  Cid 01dc.01f4  Teb: 7ffde000 Win32Thread: 00000000 RUNNING on processor 0

    Not impersonating

    DeviceMap                 e196c460

    Owning Process            810ddda0       Image:         rpclpcs.exe

    Wait Start TickCount      65732          Ticks: 10 (0:00:00:00.100)

    Context Switch Count      4            

    UserTime                  00:00:00.000

    KernelTime                00:00:00.010

    Win32 Start Address 0x000016fa

    LPC Server thread working on message Id 16fa

    Start Address kernel32!BaseThreadStartThunk (0x7c810856)

    Stack Init f8e28000 Current f8e27728 Base f8e28000 Limit f8e25000 Call 0

    Priority 9 BasePriority 8 PriorityDecrement 0 DecrementCount 0

    ChildEBP RetAddr  Args to Child             

    f8e27d64 7c90eb94 badb0d00 002bfe24 00000000 nt!KiFastCallEntry+0xf8 (FPO: [0,0] TrapFrame @ f8e27d64)

    002bfe18 7c90e399 77e76703 000007c4 002bff70 ntdll!KiFastSystemCallRet (FPO: [0,0,0])

    002bfe1c 77e76703 000007c4 002bff70 00000000 ntdll!NtReplyWaitReceivePortEx+0xc (FPO: [5,0,0])

    002bff80 77e76c22 002bffa8 77e76a3b 00084540 RPCRT4!LRPC_ADDRESS::ReceiveLotsaCalls+0xf4 (FPO: [Non-Fpo])

    002bff88 77e76a3b 00084540 7c90ee18 0006fb10 RPCRT4!RecvLotsaCallsWrapper+0xd (FPO: [Non-Fpo])

    002bffa8 77e76c0a 00083f20 002bffec 7c80b50b RPCRT4!BaseCachedThreadRoutine+0x79 (FPO: [Non-Fpo])

    002bffb4 7c80b50b 00084718 7c90ee18 0006fb10 RPCRT4!ThreadStartRoutine+0x1a (FPO: [Non-Fpo])

    002bffec 00000000 77e76bf0 00084718 00000000 kernel32!BaseThreadStart+0x37 (FPO: [Non-Fpo])

     

    kd> !thread 810dc930

    THREAD 810dc930  Cid 01e4.01ec  Teb: 7ffde000 Win32Thread: 00000000 READY

    Waiting for reply to LPC MessageId 000016fa:

    Pending LPC Reply Message:

        e16b8538: [e16b8538,e16b8538]

    Not impersonating

    DeviceMap                 e196c460

    Owning Process            810e9860       Image:         rpclpcc.exe

    Wait Start TickCount      65731          Ticks: 11 (0:00:00:00.110)

    Context Switch Count      26            

    UserTime                  00:00:00.000

    KernelTime                00:00:00.020

    Win32 Start Address rpclpcs!pre_c_init (0x01001a91)

    Start Address kernel32!BaseProcessStartThunk (0x7c810867)

    Stack Init fbe0e000 Current fbe0dc28 Base fbe0e000 Limit fbe0b000 Call 0

    Priority 8 BasePriority 8 PriorityDecrement 0 DecrementCount 16

    ChildEBP RetAddr  Args to Child             

    fbe0dc40 804ea3a4 00000000 810dc930 e107f388 nt!KiUnlockDispatcherDatabase+0x77 (FPO: [Uses EBP] [0,0,4])

    fbe0dc58 80586255 81131188 00000001 00000001 nt!KeReleaseSemaphore+0x70 (FPO: [Non-Fpo])

    fbe0dd10 80598c58 000847b0 0006f8c0 0006f8c8 nt!NtSecureConnectPort+0x635 (FPO: [Non-Fpo])

    fbe0dd3c 804df06b 000847b0 0006f8c0 0006f8c8 nt!NtConnectPort+0x24 (FPO: [Non-Fpo])

    fbe0dd3c 7c90eb94 000847b0 0006f8c0 0006f8c8 nt!KiFastCallEntry+0xf8 (FPO: [0,0] TrapFrame @ fbe0dd64)

    0006f8d0 7c93040b ffffffff 00000000 7c859e48 ntdll!KiFastSystemCallRet (FPO: [0,0,0])

    0006f9b0 7c8107fd 00000000 00084718 7c90e642 ntdll!DbgPrint+0x1b (FPO: [Non-Fpo])

    0006fe68 77ea11a8 00000022 00084540 00000000 kernel32!CreateRemoteThread+0x284 (FPO: [Non-Fpo])

    000847a8 00000000 00000001 00000000 00000000 RPCRT4!LRPC_ADDRESS::CompleteListen+0x84 (FPO: [Non-Fpo])

     

     

    Finding all threads in the system involved in LPC communication

     

    To get a consolidated list of all client threads in the system waiting on LPC replies and a list of server threads working on received LPC requests use the “!lpc threads” command without any parameters

     

    0: kd> !lpc thread

    Searching message 0 in threads ...

    Client thread 89a4cdb0 waiting a reply from 15f6                         

        Server thread 898c6a50 is working on message 63f09                        

        Server thread 89671020 is working on message 63f75                        

        Server thread 89904a48 is working on message 63f10                        

        Server thread 88d6bdb0 is working on message 3d6b1                        

        Server thread 89973db0 is working on message 63f32                         

        Server thread 896d32b8 is working on message 3454                        

        Server thread 8995d020 is working on message 63f76                        

        Server thread 8960f020 is working on message 63f77                         

        Server thread 898cd350 is working on message 61bd9                        

        Server thread 8900edb0 is working on message 3832f                        

        Server thread 8900fbf0 is working on message 33c2e                        

        Server thread 88d539a8 is working on message 3343f                        

    Client thread 89be4020 waiting a reply from 6077e                         

    Client thread 89012990 waiting a reply from 39239                         

        Server thread 89012990 is working on message 39232                        

    Client thread 89531020 waiting a reply from 3923d                         

        Server thread 89531020 is working on message 39236                        

    Client thread 88d13b40 waiting a reply from 3c96e                            

     

     

     

    Quick Tips

     

    8 No thread in the system is doing a NtListenPort( ) does that mean no LPC connection  port is open for connections?

     

    !stacks 2 NtListenPort does not return any thread because NtListenPort( ) calls NtRequestWaitReplyPort( ) to wait for an incoming LPC_CONNECTION_REQUEST message. Instead of calling NtListenPort( ) for listening for incoming connections most LPC connection threads directly call NtRequestWaitReplyPort( ).

     

    8 !lpc message does not show any message?

     

    !poolfind LpcM 1 should do the trick.

     

     

    0: kd> !lpc message

     

    Scanning large pool allocation table for Tag: LpcM (8974e000 : 8976e000)

     

    Searching Paged pool (e1000000 : f7000000) for Tag: LpcM

     

     

    0: kd> !poolfind LpcM 1

     

    Scanning large pool allocation table for Tag: LpcM (8974e000 : 8976e000)

     

     

    Searching Paged pool (e1000000 : f7000000) for Tag: LpcM

     

    e1061000 size:  168 previous size:    0  (Allocated) LpcM

    e1090758 size:  168 previous size:    8  (Allocated) LpcM

    e10a7a40 size:  168 previous size:    8  (Allocated) LpcM

    e1188468 size:    8 previous size:   20  (Free)      LpcM

    e1261000 size:  168 previous size:    0  (Allocated) LpcM

    e1297428 size:  168 previous size:    8  (Allocated) LpcM

     

    Once you have the pool blocks listed with the “LpcM” tag dump the ones that are “Allocated”. On a 32-bit machine add 8bytes to the pool address listed on the left most column. On a 64-bit machine add 16bytes i.e. 0x10. Dump the message as below to retrieve the message id.

     

    0: kd> dt nt!_LPCP_MESSAGE e1061000+8

       +0x000 Entry            : _LIST_ENTRY [ 0xe295fa80 - 0xe29279e8 ]

       +0x000 FreeEntry        : _SINGLE_LIST_ENTRY

       +0x004 Reserved0        : 0xe29279e8

       +0x008 SenderPort       : 0xe2327020

       +0x00c RepliedToThread  : (null)

       +0x010 PortContext      : 0x8021000d

       +0x018 Request          : _PORT_MESSAGE

     

    0: kd> dt nt!_LPCP_MESSAGE e1061000+8 Request.

       +0x018 Request  :

          +0x000 u1       : __unnamed

          +0x004 u2       : __unnamed

          +0x008 ClientId : _CLIENT_ID

          +0x008 DoNotUseThisField : 9.8460604703041575e-311

          +0x010 MessageId : 0x4617f

          +0x014 ClientViewSize : 0

          +0x014 CallbackId : 0

     

    0: kd> !lpc message 0x4617f

    Searching message 4617f in threads ...

        Server thread 88f91c08 is working on message 4617f                        

    Client thread 88f0f5f8 waiting a reply from 4617f                         

    Searching thread 88f0f5f8 in port rundown queues ...

     

    Server communication port 0xe2300a38

        Handles: 1   References: 1

        The LpcDataInfoChainHead queue is empty

            Connected port: 0xe2327020      Server connection port: 0xe13734b0

     

    Client communication port 0xe2327020

        Handles: 1   References: 9

        The LpcDataInfoChainHead queue is empty

     

    Server connection port e13734b0  Name: epmapper

        Handles: 1   References: 93

        Server process  : 896e1450 (svchost1.exe)

        Queue semaphore : 8995ac10

        Semaphore state 0 (0x0)

        The message queue is empty

     

     

    8   The number of server threads shown by !lpc thread processing requests is much more than the number of client threads waiting for reply.

     

    !lpc thread interprets stale data in ETHREAD structure as valid LPC information. An indication of the stale data is the ETHREAD.LpcExitThreadCalled will be set. This field is only set when the thread is exiting.

     

    0: kd> !lpc thread

    Searching message 0 in threads ...

    Client thread 89a4cdb0 waiting a reply from 15f6                         

        Server thread 898c6a50 is working on message 63f09                        

        Server thread 89671020 is working on message 63f75                         

        Server thread 89904a48 is working on message 63f10                        

        Server thread 88d6bdb0 is working on message 3d6b1                        

        Server thread 89973db0 is working on message 63f32                        

        Server thread 896d32b8 is working on message 3454                        

        Server thread 8995d020 is working on message 63f76                        

        Server thread 8960f020 is working on message 63f77                        

        Server thread 898cd350 is working on message 61bd9                        

        Server thread 8900edb0 is working on message 3832f                        

        Server thread 8900fbf0 is working on message 33c2e                        

        Server thread 88d539a8 is working on message 3343f     

     

    0: kd> !lpc message 3454

    Searching message 3454 in threads ...

        Server thread 896d32b8 is working on message 3454                        

    Done. 

     

     

    0: kd> dt nt!_ETHREAD 896d32b8 Lpc.

       +0x1c0 LpcReplyChain :  [ 0x896d3478 - 0x896d3478 ]

          +0x000 Flink : 0x896d3478 _LIST_ENTRY [ 0x896d3478 - 0x896d3478 ]

          +0x004 Blink : 0x896d3478 _LIST_ENTRY [ 0x896d3478 - 0x896d3478 ]

       +0x1ec LpcReplySemaphore :

          +0x000 Header : _DISPATCHER_HEADER

          +0x010 Limit : 1

       +0x200 LpcReplyMessage :

       +0x200 LpcWaitingOnPort :

       +0x220 LpcReceivedMessageId : 0x3454

       +0x234 LpcReplyMessageId : 0

       +0x248 LpcReceivedMsgIdValid : 0x1 ''

       +0x248 LpcExitThreadCalled : 0x1 ''

     

    8 Finding all client threads in the system waiting for LPC reply.

     

    !lpc thread

  • Ntdebugging Blog

    Join us on Facebook

    • 0 Comments

    We’ve set up a new Facebook group named “Windows Debugging” as a community for Windows Debugging industry experts.  If Windows debugging is an interest of yours, please consider joining the group!  Many of the regular contributors to this blog will be there as well.  Just login to Facebook and search for “Windows Debugging” to find us, or go here:

    http://www.facebook.com/n/?group.php&gid=23775552268.

  • Ntdebugging Blog

    Windows NT Debugging Blog Live Chat 2

    • 0 Comments

    Windows NT Debugging Blog Live Chat

    Microsoft Platform Global Escalation Services is hosting our second live group debug chat session for the debugging community on March 17, 2009 at 11 AM Pacific Time.  We will be focusing on debugging techniques and any questions you may have about anything we’ve previously blogged about. 

    Details about the “PGES-Windows NT Debugging Blog Live Chat” can be found here: http://www.microsoft.com/communities/chats/default.mspx

  • Ntdebugging Blog

    Next Week: Windows NT Debugging Blog Live Chat

    • 0 Comments

    Windows NT Debugging Blog Live Chat

    Microsoft Platform Global Escalation Services is hosting our second live group debug chat session for the debugging community on March 17, 2009 at 11 AM Pacific Time.  We will be focusing on debugging techniques and any questions you may have about anything we’ve previously blogged about. 

    Details about the “PGES-Windows NT Debugging Blog Live Chat” can be found here: http://www.microsoft.com/communities/chats/default.mspx

    Share this post :
  • Ntdebugging Blog

    Case Study - Software Restriction Policies and Large EXE Files

    • 0 Comments

    Recently I received a debugging request for a customer having problems running large executables. On their systems, they could run most EXEs without any problems, but they had two programs that were over 1.8 GB which, when run, would display the following error:

    clip_image002

    If they tried to run them in a command prompt, they received the message “Access is denied.” Both attempts were made with an administrator account and in neither case were the processes created. Through testing, they found that the programs worked if they were scheduled to run as System and also worked when run in safe mode as an administrator.

    When the case was brought to my attention, it was noted that when the failing executables were run, the following appeared in process monitor logs:

    clip_image004

    The engineer did not see this when one of the problematic EXEs was run (successfully) on his test machine. The customer provided a VM image of their system which we set up in HyperV with a named pipe kernel debugger. I then started kernel debugging to find the cause of the INVALID PARAMETER error, hoping that resolving it would fix the issue.

    To start, I looked at the call stack within process monitor for the invalid parameter:

    clip_image005

    The problem is this isn’t exactly where we return invalid parameter. Looking at the source code for Fltmgr, it doesn’t return invalid parameter – this was just where the error was caught in procmon. This call stack did provide some ideas for good starting places to debug, however. First, I looked up the hex value for STATUS_INVALID_PARAMETER in ntstatus.h – 0xC000000D. Knowing this, I decided to set a breakpoint on nt!IofCallDriver and ran the program. Once the debugger broke in, I planned to use wt -oR. This will trace through the calls displaying the return values next to each call. From there, I would just need to find 0xC000000D on the return column. Unfortunately, what I had forgotten was wt does not display return codes in kernel debugging, only when debugging user mode.

    With wt not an option, I decided to use a combination of debugger commands to approximate the output of wt. I knew the return value I was looking for, and I was also confident that I would find that code in the EAX register after the problem occurred. As such, I needed to write a loop that would walk through the instructions until it found 0xC000000D in EAX. The debugger provides two main options for walking instructions: p and t. p (Step) will execute a single instruction and display the register values. If the instruction is a call, it will not enter that function, but just display the results after that subroutine has been executed. t (Trace) also executes a single instruction, but it will enter into the function and will display each instruction.

    In this case I wanted trace so I could see which function was returning the invalid parameter status. Tracing though that many instructions/functions would take a long time, but there are some variations on t (and p) that can help. tc (or pc)will execute instructions until a call statement is reached, where it will break and show the register values. tt (or pt) will execute instructions until a return instruction is reached. tct (or pct) will run until either a call or return is reached. In this case, I opted for tct.

    Knowing that I would use tct, I had to find a way to execute tct statements until EAX was the value I was looking for. This can be accomplished with the z (While) debugger command. The syntax is pretty easy, it’s just z(expression) and it works just like a do-while loop. Putting it all together, I used this command in the debugger:

    tct; z(eax!=0xc000000d)

    I then waited for the debugger to break in so I could see where this status was being thrown. Regrettably, the code called ended up going in to some recursion which made my while loop take way too long. To resolve this, I set a new breakpoint just before we entered the recursion, reran the program, used p to step past the call then ran the tct loop.

    This time I was quickly brought to the code I was looking for. As soon as it broke in, I ran k to view the callstack:

    kd> k

    ChildEBP RetAddr
    b9541a3c f7b7fab9 Ntfs!NtfsCommonDeviceControl+0x40
    b9541aa0 f7b8b02f Ntfs!NtfsFsdDispatchSwitch+0xe4
    b9541bbc 8081df85 Ntfs!NtfsFsdDispatchWait+0x1c
    b9541bd0 f7876d28 nt!IofCallDriver+0x45
    b9541bfc 8081df85 fltmgr!FltpDispatch+0x152
    b9541c10 f7876d28 nt!IofCallDriver+0x45
    b9541c3c 8081df85 fltmgr!FltpDispatch+0x152
    b9541c50 808f5437 nt!IofCallDriver+0x45
    b9541c64 808f61bf nt!IopSynchronousServiceTail+0x10b
    b9541d00 808eed08 nt!IopXxxControlFile+0x5e5
    b9541d34 808897bc nt!NtDeviceIoControlFile+0x2a
    b9541d34 7c82860c nt!KiFastCallEntry+0xfc
    0012e960 7c826fe9 ntdll!KiFastSystemCallRet
    0012e964 77e416f9 ntdll!NtDeviceIoControlFile+0xc
    0012e9c8 77e6738d kernel32!DeviceIoControl+0x137
    0012ec44 77e67032 kernel32!GetVolumeNameForRoot+0x16d
    0012ec68 77e67782 kernel32!BasepGetVolumeNameForVolumeMountPoint+0x73
    0012ecd0 7d20b01d kernel32!GetVolumePathNameW+0x1c7
    0012ef18 7d20ae2c ADVAPI32!CodeAuthzFullyQualifyFilename+0xbc
    0012eff8 7d20b33f ADVAPI32!__CodeAuthzpIdentifyOneCodeAuthzLevel+0x19f
    0012f07c 77e6df9e ADVAPI32!SaferIdentifyLevel+0x163
    0012f278 77e6ce03 kernel32!BasepCheckWinSaferRestrictions+0x60c
    0012fa90 77e424b0 kernel32!CreateProcessInternalW+0xc0e
    0012fac8 4ad0256f kernel32!CreateProcessW+0x2c
    0012fc24 4ad01a2b cmd!ExecPgm+0x221
    0012fc58 4ad019b3 cmd!ECWork+0x84
    0012fc70 4ad03c58 cmd!ExtCom+0x40
    0012fe9c 4ad01447 cmd!FindFixAndRun+0xa9
    0012fee0 4ad0c30b cmd!Dispatch+0x137
    0012ff44 4ad07786 cmd!main+0x216
    0012ffc0 77e6f23b cmd!mainCRTStartup+0x12f
    0012fff0 00000000 kernel32!BaseProcessStart+0x23

    If we look at the assembly around Ntfs!NtfsCommonDeviceControl+0x40, we see that only if our return from NtfsDecodeFileObject is not equal to 4 it would move 0xC000000D in to esi, and then move esi to eax, :

    f7b7faf9 e8e904fdff call Ntfs!NtfsDecodeFileObject (f7b4ffe7)
    f7b7fafe 83f804 cmp eax,4
    f7b7fb01 0f848873ffff je Ntfs!NtfsCommonDeviceControl+0x54 (f7b76e8f)

    Ntfs!NtfsCommonDeviceControl+0x40:
    f7b7fafe 83f804 cmp eax,4
    f7b7fb01 0f848873ffff je Ntfs!NtfsCommonDeviceControl+0x54 (f7b76e8f)
    f7b7fb07 be0d0000c0 mov esi,0C000000Dh
    f7b7fb0c 56 push esi
    f7b7fb0d 53 push ebx
    f7b7fb0e 57 push edi
    f7b7fb0f e83506fdff call Ntfs!NtfsCompleteRequest (f7b50149)
    f7b7fb14 8bc6 mov eax,esi

    I looked at the source code for these functions, and it didn’t make sense that a failure here would cause the problems we were seeing; especially specific to large executables. Out of curiosity I ran notepad on the VM again with procmon and found that it too displayed INVALID PARAMETER, but the program started and ran correctly:

    clip_image007

    Since this wasn’t the problem, I stopped reviewing the code and decided on a new approach. We knew that when running the EXE in a command prompt we received an “Access is denied message”. At that point it made sense to switch to user mode debugging and take a look at the cmd.exe process that was trying to launch install.exe

    Doing user mode debugging in a VM can be a bit of a challenge, especially if you are trying to minimize changes to the VM (and in my case, avoid putting any symbols on the customer’s VM image). Since I already had a kernel debugger attached, one option would be to run ntsd.exe (debugger provided in the Debugging Tools for Windows) on the VM with the -p switch specifying the PID of the cmd.exe process I wanted to debug and -d switch which forwards the i/o of ntsd to the kernel debugger. The problem with this approach is the kernel debugger just becomes a front end for issuing commands and seeing the output from ntsd. That means all symbol resolution is still done on the target system running ntsd.

    I didn’t want to give the customer VM Internet or corporate network access, so I instead opted to run dbgsrv.exe on the VM. Running “dbgsrv -t tcp:port=9999” tells the debug server to listen on TCP port 9999 for debugger connections. Then, on the HyperV server computer I could just run windbg -premote tcp:server=(IP of VM),port=9999 -p (PID of cmd on VM) to debug it.

    I suspected that we may be calling CreateProcess but it was failing, so I set a breakpoint on kernel32!CreateProcessW. Sure enough, it hit when I tried to run install.exe in the command prompt:

    0:000> k
    ChildEBP RetAddr
    0012fac8 4ad0256f kernel32!CreateProcessW
    0012fc24 4ad01a2b cmd!ExecPgm+0x221
    0012fc58 4ad019b3 cmd!ECWork+0x84
    0012fc70 4ad03c58 cmd!ExtCom+0x40
    0012fe9c 4ad01447 cmd!FindFixAndRun+0xa9
    0012fee0 4ad0c30b cmd!Dispatch+0x137
    0012ff44 4ad07786 cmd!main+0x216
    0012ffc0 77e6f23b cmd!mainCRTStartup+0x12f
    0012fff0 00000000 kernel32!BaseProcessStart+0x23

    This time I could use wt -oR since this was a usermode debug. Looking in ntstatus.h again, the code for STATUS_ACCESS_DENIED is 0xC0000022. Running wt can take a very long time, so I used the -l switch, which limits the number of levels deep it will display. This would be something like using tct as I did above until you were a few calls deep then using pct. Using wt -l 3 -oR gave me the following:


    575      291       [ 1] kernel32!CreateProcessInternalW
    35        0           [ 2] kernel32!BasepCheckWinSaferRestrictions
    25        0           [ 3] ntdll!RtlEnterCriticalSection eax = 0
    48        25         [ 2] kernel32!BasepCheckWinSaferRestrictions
    1          0           [ 3] ntdll!NtOpenThreadToken
    3          0           [ 3] ntdll!ZwOpenThreadToken eax = ffffffff`c000007c
    57        29         [ 2] kernel32!BasepCheckWinSaferRestrictions
    1          0           [ 3] ntdll!ZwOpenProcessToken
    3          0           [ 3] ntdll!NtOpenProcessToken eax = 0
    116      33         [ 2] kernel32!BasepCheckWinSaferRestrictions
    113      0           [ 3] ADVAPI32!SaferIdentifyLevel eax = 0
    130      146       [ 2] kernel32!BasepCheckWinSaferRestrictions
    4           0          [ 3] ntdll!ZwClose eax = 0
    132      150       [ 2] kernel32!BasepCheckWinSaferRestrictions
    22        0           [ 3] ntdll!RtlLeaveCriticalSection eax = 0
    138      172       [ 2] kernel32!BasepCheckWinSaferRestrictions
    5           0          [ 3] kernel32!__security_check_cookie eax = ffffffff`c0000022

     Now we are getting close! I set a new breakpoint for kernel32!BasepCheckWinSaferRestrictions and reran the test. This gave me the following line:

    63 0 [ 3] ADVAPI32!__CodeAuthzpCheckIdentityHashRules eax = ffffffff`c0000022

    One last run with a new breakpoint at ADVAPI32!__CodeAuthzpCheckIdentityHashRules and I found what I was looking for:

    58 218 [ 1] ADVAPI32!__CodeAuthzpEnsureMapped eax = ffffffff`c0000022

    The depth is shown in brackets. As this call was 1 deep from __CodeAuthzpCheckIdentityHashRules and I was using 3 as my maximum depth in wt, I knew this is where the STATUS_ACCESS_DENIED was coming from. I reviewed the source code and found that this is the code that performs Software Restriction Policy checking. Specifically, we are attempting to map the executable into memory to perform hash checking on it. Since there isn’t 1.8 GB of contiguous available memory, it failed. Looking at the VM, I discovered that the customer had implemented a number of software restriction policies. As a test, I removed their restrictions on the VM, and the programs ran successfully. A search of the KB revealed that a hotfix was published for this problem: 973825. Installing the hotfix in the article also resolved the issue with their policies intact.

    -Matt Burrough

Page 21 of 24 (238 items) «1920212223»