OSRLogo
OSRLogoOSRLogoOSRLogo x Subscribe to The NT Insider
OSRLogo
x

Everything Windows Driver Development

x
x
x
GoToHomePage xLoginx
 
 

    Sat, 01 Nov 2014     105067 members

   Login
   Join


 
 
Contents
  About This Site
What's New?
OSR Dev Blog
The NT Insider
The Basics
File Systems
Downloads
ListServer / Forum
Driver Jobs
Store
  Express Links
  · The NT Insider Digital Edition - Sept-Oct 2014 Now Available!
  · Sept-Oct Issue of The NT Insider Released!
  · Writing WDF Drivers: Advanced Implementation Techniques
  · OSR Seminar Schedule
  · Windows 8.1 Update: VS Express Now Supported

Stacking the Deck -- Finding Your Way Through the Stack


One of the frustrating aspects of debugging on the x86 system is when you cannot make further progress because you are missing symbols needed by the debugger to walk back up the stack.  In this article we describe a technique for finding a stack frame earlier in the call sequence so that you can actually reconstruct more of the stack.

 

To manage limitations with respect to the x86 instruction set, compilers have developed a number of techniques for optimizing the calling sequence in order to both minimize the number of operations as well as “free up” an additional register that may be used for data access.

 

The key to decoding a call stack frame on the x86 is to understand the basic calling convention assumed by the debugger – that the “base pointer” actually points to the base of the current function’s stack frame.  Because stack addresses grow down (so that subsequent values are written at lower memory addresses), addresses at positive offsets are in earlier frames, while addresses at negative offsets are in the current frame.

 

When walking the stack, the debugger knows the number of parameters passed to the function, the number of saved registers (because they are used within the function) and the number of local variables. Given the base pointer for the current stack frame, the “unoptimized” frame would look like the above figure.

 

The EBP (“extended base pointer”) actually refers to the memory location on the stack that in turn refers to the previous base pointer on the stack.  By following these base pointers back through multiple calls, the debugger can actually reconstruct the call chain, not even requiring any symbol information.  The challenge arises when the base pointer is eliminated.  In this case, the compiler generates code that does not use a base pointer.  Thus, from our previous illustration we see the only thing missing is the base pointer:

 

However, now if the kernel debugger were to use the EBP information, it would miss the call frame.  To resolve this problem, the debugger requires symbolic information emitted by the compiler.  In the absence of such information, the debugger will emit a warning message when attempting to display the stack:

 

WARNING: Stack unwind information not available. Following frames may be wrong.

 

This is an indication that the debugger is relying upon the EBP call-chain mechanism to walk back up the stack.  The risk here is that individual frames may be missing from the overall call stack.

 

The more egregious case is when the compiler uses the EBP pointer within the function as a general purpose register.  While this can optimize register utilization, it makes it virtually impossible for the kernel debugger to reliably reconstruct the stack trace if symbols are not available.  In this case the call frame is as it was before, but now the EBP points to some arbitrary location in memory.  Thus, the debugger will not be able to unwind any additional information from the stack.

 

However, it is possible to manually attempt to identify a new stack frame location and continue the stack trace from that point.  This is achieved by looking for the three things the debugger must have in order to perform this task: the instruction pointer, the stack pointer, and the base pointer, where the stack pointer and base pointer must correspond to their values at the time the instruction pointer was executed.

 

In doing so, we exploit our knowledge of how canonical stack frames are constructed, notably that the return address from a function call is placed on the stack and is followed by the previous base pointer value.  So, if we can identify the instruction that was the call, then we can identify where the stack was (the address above the return address on the stack) and the child base pointer (the address after the return address).  Of course, in doing so, we need to keep in mind that the previous base pointer is not always recorded on the stack.  Thus, this technique requires analyzing the base pointer to ensure that it “makes sense” with respect to the stack frame.  If it does, then it probably can be used for decoding the stack.  Of course, if it does not, the debugger is unlikely to make much additional progress.

 

It is possible to “manually” walk through the stack and find information further along.  For example, a recent crash dump contributed to OSR for analysis had a popular anti-virus product installed.  Crash dumps with such products installed often are difficult to debug because of the absence of symbols for a highly optimized driver.

 

For example, in the crash we analyzed for this article, we saw the following stack (Figure 1 below).

 

3: kd> kv

ChildEBP RetAddr  Args to Child             

bdec6690 8046bb4d 85517708 00000000 eb8532ad nt!ExFreePoolWithTag+0x19b (FPO: [Non-Fpo])

bdec669c eb8532ad 85517708 86aeb1c8 85517718 nt!ExFreePool+0xb (FPO: [1,0,0])

bdec66b0 eb85667d 86aeb1c8 85517718 86aeb030 CLASSPNP!FreeDictionaryEntry+0x3f (FPO: [2,0,3])

bdec66e4 eb8565c5 86aeb030 00000000 86aeb030 CLASSPNP!ClasspCreateClose+0x9f (FPO: [Non-Fpo])

bdec6700 8041d915 86aeb0e8 84761208 84761218 CLASSPNP!ClassCreateClose+0x5d (FPO: [Non-Fpo])

bdec6714 80428412 00000000 8583c6a4 804282ce nt!IopfCallDriver+0x35 (FPO: [0,0,2])

bdec6748 804d71b0 8583c600 8583c690 86c03b40 nt!IopDeleteFile+0x144 (FPO: [Non-Fpo])

bdec6764 8044f10d 8583c6a8 00000000 00000000 nt!ObpRemoveObjectRoutine+0xd6 (FPO: [Non-Fpo])

bdec6788 be57d0d2 bdec68c8 bdec68c8 86267bd0 nt!ObfDereferenceObject+0x157 (FPO: [Non-Fpo])

WARNING: Stack unwind information not available. Following frames may be wrong.

bdec6890 be57f4a8 868f5020 86267c00 bdec68e8 SYMEVENT+0x20d2

bdec68c9 60845d3b d0845d3c e886267b 0086b6f3 SYMEVENT!SYMEvent_Operation+0x2ed

a8804600 00000000 00000000 00000000 00000000 0x60845d3b

 

Figure 1

 

 

Note that the debugger provides us with the “standard” warning about the stack unwinding being suspect.  Rather than just “give up” at this point, however, it is possible to track farther up the stack, although it requires some manual analysis.  We started by looking at the raw contents of the stack, beginning with the frame prior to the suspect frame (Figure 2):

 

3: kd> dd bdec6780

bdec6780  00000000 00ec6870 bdec6890 be57d0d2

bdec6790  bdec68c8 bdec68c8 86267bd0 0044005c

bdec67a0  00760065 00630069 005c0065 00640043

bdec67b0  006f0052 0030006d 006b0073 006d0044

bdec67c0  006f0056 0075006c 0065006d 005c0073

bdec67d0  00790044 0070006e 00720061 00440074

bdec67e0  00300067 0056005c 006c006f 006d0075

bdec67f0  00380065 845d0037 c0000034 868f5020

 

 

Figure 2 

What we are looking for is a sequence of values that might represent a calling frame that we can use for further analysis.  Such a frame would probably contain an EBP pointer (an address higher in memory, and hence lower in the stack) and a return address.  Once we find one, we can manually restart the stack trace from that point.  For example, the last stack frame the debugger could unravel was at bdec6788.  Note that the address after that (at bdec678c) is be57d0d2 (See Figure 3):

 

3: kd> u be57d0d2

SYMEVENT+20d2:

be57d0d2 837de400         cmp     dword ptr [ebp-0x1c],0x0

be57d0d6 7524             jnz     SYMEVENT+0x20fc (be57d0fc)

be57d0d8 66ff45a4         inc     word ptr [ebp-0x5c]

be57d0dc 66837da45a       cmp     word ptr [ebp-0x5c],0x5a

be57d0e1 0f8667feffff     jbe     SYMEVENT+0x1f4e (be57cf4e)

be57d0e7 32c0             xor     al,al

be57d0e9 8b4df0           mov     ecx,[ebp-0x10]

be57d0ec 5f               pop     edi

 

Figure 3

 

And that is exactly the same “address” shown in the debugger’s listing of the stack trace.  But the return address stored on the stack (in the case of a procedure call) is the instruction after the call.  So, if we disassemble the previous instruction, we can see the call (Figure 4  below).

 

SYMEVENT+20cc:

be57d0cc ff15506f58be call dword ptr [SYMEVENT!SYMEvent_GetSubTask+0x2f65 (be586f50)]

be57d0d2 837de400         cmp     dword ptr [ebp-0x1c],0x0

be57d0d6 7524             jnz     SYMEVENT+0x20fc (be57d0fc)

be57d0d8 66ff45a4         inc     word ptr [ebp-0x5c]

be57d0dc 66837da45a       cmp     word ptr [ebp-0x5c],0x5a

be57d0e1 0f8667feffff     jbe     SYMEVENT+0x1f4e (be57cf4e)

be57d0e7 32c0             xor     al,al

be57d0e9 8b4df0           mov     ecx,[ebp-0x10]

 

Figure 4 

And we can see the actual function called by looking into the table we see in the disassembly (Figure 5):

 

3: kd> dd be586f50 l1

be586f50  8044efb6

3: kd> u @$p

nt!ObfDereferenceObject:

8044efb6 55               push    ebp

8044efb7 8bec             mov     ebp,esp

 

Figure 5 

And this matches the information on the stack that the debugger showed us.  Using this same technique, we can try to analyze the first of the two mystery calls.  First, we note that the return address displayed by the debugger (be57f4a8) should be preceded by a call operation (Figure 6):

 

3: kd> u be57f4a3

SYMEVENT!SYMEvent_Operation+2e8:

be57f4a3 e858daffff       call    SYMEVENT+0x1f00 (be57cf00)

be57f4a8 84c0             test    al,al

 

Figure 6 

This then suggests to us that the beginning of this function call is at be57cf00. We can thus disassemble from this point, to the point of the return address (Figure 7):

 

3: kd> u be57cf00 be57d0d2

SYMEVENT+1f00:

be57cf00 64a100000000     mov     eax,fs:[00000000]

be57cf06 55               push    ebp

be57cf07 8bec             mov     ebp,esp

be57cf09 6aff             push    0xff

be57cf0b 6850b457be       push    0xbe57b450

be57cf10 68446458be       push    0xbe586444

be57cf15 50               push    eax

be57cf16 64892500000000   mov     fs:[00000000],esp

be57cf1d 81ece4000000     sub     esp,0xe4

be57cf23 8d458c           lea     eax,[ebp-0x74]

be57cf26 53               push    ebx

be57cf27 56               push    esi

be57cf28 57               push    edi

be57cf29 8965e8           mov     [ebp-0x18],esp

 

Figure 7 

We have omitted the entire listing here, since it is fairly long.  But we started by analyzing the preamble here and noting that this is actually a fairly standard call frame.  It is storing the EBP on the stack and resetting the base pointer.  The other operations here, where it is moving values onto the stack and manipulating fs:[00000000] is how the compiler and OS set up an exception handler (using __try and __except.)  The fs selector always represents the KPCR (kernel processor control region) for the given CPU.  Since each CPU has its own private fs selector, on a per CPU basis the same code will reference a different data structure.

 

From that point we analyzed the balance of the disassembly looking for something that would suggest the end of this function (e.g. a call from one function to another with frame pointer optimization enabled).  We found only a single “suspicious” frame just before the return address the debugger showed us on the stack (Figure 8 below).

 

be57d0ac 85c0             test    eax,eax

be57d0ae 75eb             jnz     SYMEVENT+0x209b (be57d09b)

be57d0b0 eb10             jmp     SYMEVENT+0x20c2 (be57d0c2)

be57d0b2 b801000000       mov     eax,0x1

be57d0b7 c3               ret

be57d0b8 8b65e8           mov     esp,[ebp-0x18]

be57d0bb c745e400000000   mov     dword ptr [ebp-0x1c],0x0

be57d0c2 c745fcffffffff   mov     dword ptr [ebp-0x4],0xffffffff

be57d0c9 8b4de0           mov     ecx,[ebp-0x20]

be57d0cc ff15506f58be call dword ptr [SYMEVENT!SYMEvent_GetSubTask+0x2f65 (be586f50)]

 

Figure 8 

That “ret” instruction is mildly suspicious (it often is at the end of a function) but in this case we believe that this is an error return – that is, the value 0x1 is loaded into EAX (the return register) and the function terminates.  The jmp in front of it strongly suggests this is a terminal branch, and certainly not part of the main code flow – in fact, that jmp is probably why we ended up executing the call to ObfDereferenceObject.

 

This then brings us up to the previous call frame – the last one the debugger was able to unravel, presumably due to frame pointer optimization.  We found this whole sequence a bit “suspicious” since we’ve yet to see a valid stack where the return address was on an odd byte boundary. So, we tried to analyze back “earlier” in the stack by starting with be57f1bb because it is the nearest function boundary identified by the debugger.  This gave us a long listing of what appeared to be small functions.  For example, the first one from this region (Figure 9 below).

 

SYMEVENT!SYMEvent_Operation:

be57f1bb 8b4c2408         mov     ecx,[esp+0x8]

be57f1bf 85c9             test    ecx,ecx

be57f1c1 8d41f8           lea     eax,[ecx-0x8]

be57f1c4 7502             jnz     SYMEVENT!SYMEvent_Operation+0xd (be57f1c8)

be57f1c6 33c0             xor     eax,eax

be57f1c8 85c9             test    ecx,ecx

be57f1ca 7405             jz      SYMEVENT!SYMEvent_Operation+0x16 (be57f1d1)

be57f1cc 83e908           sub     ecx,0x8

be57f1cf eb02             jmp     SYMEVENT!SYMEvent_Operation+0x18 (be57f1d3)

be57f1d1 33c9             xor     ecx,ecx

be57f1d3 8b00             mov     eax,[eax]

be57f1d5 ff742404         push    dword ptr [esp+0x4]

be57f1d9 ff5004           call    dword ptr [eax+0x4]

be57f1dc c20800           ret     0x8

 

Figure 9 

We decided that this was most likely a single function because all call sequences led to the final return – suggesting that this was a small, self-contained function and not part of a much larger function.  In fact, there were many of these small functions, with the last one in the range of interest being (Figure 10 below).

 

be57f461 53               push    ebx

be57f462 56               push    esi

be57f463 57               push    edi

be57f464 8bd9             mov     ebx,ecx

be57f466 8b7c2410         mov     edi,[esp+0x10]

be57f46a 55               push    ebp

be57f46b 33c9             xor     ecx,ecx

be57f46d 884f1c           mov     [edi+0x1c],cl

be57f470 390d306758be cmp [SYMEVENT!SYMEvent_GetSubTask+0x2745 (be586730)],ecx

be57f476 0f8420010000     je     SYMEVENT!SYMEvent_Operation+0x3e1 (be57f59c)

be57f47c 8d6f01           lea     ebp,[edi+0x1]

be57f47f 8a4500           mov     al,[ebp]

be57f482 3c1b             cmp     al,0x1b

be57f484 0f8712010000     jnbe   SYMEVENT!SYMEvent_Operation+0x3e1 (be57f59c)

be57f48a 384b40           cmp     [ebx+0x40],cl

be57f48d 7421             jz     SYMEVENT!SYMEvent_Operation+0x2f5 (be57f4b0)

be57f48f 8d5330           lea     edx,[ebx+0x30]

be57f492 66390a           cmp     [edx],cx

be57f495 7519             jnz    SYMEVENT!SYMEvent_Operation+0x2f5 (be57f4b0)

be57f497 84c0             test    al,al

be57f499 0f85fd000000     jne    SYMEVENT!SYMEvent_Operation+0x3e1 (be57f59c)

be57f49f 52               push    edx

be57f4a0 ff7328           push    dword ptr [ebx+0x28]

be57f4a3 e858daffff       call    SYMEVENT+0x1f00 (be57cf00)

 

Figure 10 

Immediately preceding this had been what looked like a call frame unwinding sequence (Figure 11):

 

be57f458 5f               pop     edi

be57f459 5e               pop     esi

be57f45a 5b               pop     ebx

be57f45b c3               ret

be57f45c e9f5efffff       jmp     SYMEVENT+0x3456 (be57e456)

 

Figure 11 

Note that it is restoring register state and executing that return.  Thus, we believe that the beginning of our function is at be57f461.  Returning to our stack, we need to find a return address that calls this function.  We do this by slowly walking back up the stack analyzing each DWORD value to see if it looks like a valid return address.  For example (Figure 12):

 

3: kd> u 86267c00

86267c00 0000             add     [eax],al

86267c02 3a00             cmp     al,[eax]

86267c04 0000             add     [eax],al

86267c06 2e32f4           xor     dh,cs:ah

86267c09 b557             mov     ch,0x57

86267c0b bea87e2686       mov     esi,0x86267ea8

86267c10 017063           add     [eax+0x63],

 

Figure 12 

Does not look like a terribly likely candidate.  This is a time-consuming process but eventually starts to yield potential candidates, such as be57c05d which disassembles to (Figure 13):

 

SYMEVENT+105d:

be57c05d 894618           mov     [esi+0x18],eax

be57c060 807e1e00         cmp     byte ptr [esi+0x1e],0x0

be57c064 7528             jnz     SYMEVENT+0x108e (be57c08e)

be57c066 8b4618           mov     eax,[esi+0x18]

be57c069 8b5604           mov     edx,[esi+0x4]

be57c06c 894218           mov     [edx+0x18],eax

be57c06f 807e1c00         cmp     byte ptr [esi+0x1c],0x0

be57c073 740d             jz      SYMEVENT+0x1082 (be57c082)

 

Figure 13 

Having identified a potential return address, we need to see if there is a call preceding the potential return address (Figure 14):

 

3: kd> u be57c055

SYMEVENT+1055:

be57c055 8b0f             mov     ecx,[edi]

be57c057 56               push    esi

be57c058 8b01             mov     eax,[ecx]

be57c05a ff5008           call    dword ptr [eax+0x8]

be57c05d 894618           mov     [esi+0x18],eax

be57c060 807e1e00         cmp     byte ptr [esi+0x1e],0x0

be57c064 7528             jnz     SYMEVENT+0x108e (be57c08e)

be57c066 8b4618           mov     eax,[esi+0x18]

 

Figure 14 

The call here doesn’t directly tell us what function was called because the EAX register is not saved across function calls.  However, we theorize that this code sequence is calling to our function at be57f461. If this is the case, we migh be able to prove it from the information on the stack.  This is because the EAX register had been loaded from a value stored in the ECX register, and the ECX register was loaded from a value in the EDI register.  The code at be57f461 saved the contents of the EDI register (although not the contents of ECX or EAX).  Thus, we should be able to find the contents of the EDI register at the time this stack frame was called because it will be on the stack just after the return address. Note that the code at be57f461 actually saved the EBX, ESI, and EDI registers in that order.  Thus, if we go back and look at the stack where we found the return address (Figure 15):

 

3: kd> dd bdec6890

bdec6890  bdec68c9 be57f4a8 868f5020 86267c00

bdec68a0  bdec68e8 bdec68d4 bdec68c8 bdec6c98

bdec68b0  be57c05d bdec68c8 86267ac0 845d3ba8

bdec68c0  be57c012 845d3ba8 80460001 845d3ba8

bdec68d0  845d3c60 86267bd0 86b6f3e8 00000000

bdec68e0  00000000 00000100 bdec6a7c 8041d915

bdec68f0  86267ac0 845d3ba8 845d3bb8 845d3ba8

bdec6900  804c13b2 8455d0e8 bdec6c98 bdec6c1c

 

Figure 15 

Recall the return address candidate was be57c05d.  If this is correct, then EBX was bdec6c98, ESI was bdec68c8 and EDI was bdec68d4.  Now, we can begin to unravel the value of the mystery function pointer.  First, the value in EDI was used to load the value into ECX:

 

be57c055 8b0f             mov     ecx,[edi]

 

This means that the value in EDI was used as a pointer, and the CPU loaded the value at the address stored in EDI into ECX.  We can use the debugger to display this information:

 

3: kd> dd bdec68d4 l1

bdec68d4  86267bd0

 

The push did not have any impact on the register state for our analysis.  The next interesting instruction:

 

be57c058 8b01             mov     eax,[ecx]

 

Loads the value at the address stored in ECX into the EAX register.  Continuing from our previous debugger operation (and using some short-hand that relies upon that last dd command):

 

3: kd> dd @$p l1

86267bd0  be57b5f8

 

This is now the value loaded into the EAX register.  The function called requires one last memory indirection:

 

be57c05a ff5008           call    dword ptr [eax+0x8]

 

And one more incantation of the debugger, again using the results from the previous dd command:

 

 3: kd> dd @$p+8 l1

be57b600  be57f461

 

This is the function we theorized it might be – so we’ve now managed to find this part of the call sequence, and one that the debugger did not find.   Unfortunately, this new call does not have a “standard” call frame, so we cannot get the debugger to do more work for us yet. Instead, we must persevere and unravel the next call in the stack.

 

Thus, we repeat this process, attempting to find the beginning of the function that issued the call at be57c05d.  We found what appeared to be a function preamble a bit earlier at be57c034 (Figure 16):

 

be57c034 56               push    esi

be57c035 57               push    edi

be57c036 8d790c           lea     edi,[ecx+0xc]

be57c039 8bf1             mov     esi,ecx

be57c03b 6a00             push    0x0

be57c03d 8b0f             mov     ecx,[edi]

be57c03f e80a050000       call    SYMEVENT+0x154e (be57c54e)

be57c044 84c0             test    al,al

 

Figure 16 

Once again, we went back to the stack to see if we could find a function that called be57c034.  We found the next potential return address fairly quickly - be57c012.  This yielded the following disassembly:

 

be57c00d e822000000       call    SYMEVENT+0x1034 (be57c034)

be57c012 ff75e0           push    dword ptr [ebp-0x20]

 

And be57c034 is the function we found in analyzing the last stack frame.  Looking backwards a bit in the disassembly, we were able to identify the beginning of the function (Figure 17 below).

 

3: kd> u be57bfda be57c012

SYMEVENT+fda:

be57bfda 55               push    ebp

be57bfdb b9b06c58be       mov     ecx,0xbe586cb0

be57bfe0 8bec             mov     ebp,esp

be57bfe2 83ec20           sub     esp,0x20

be57bfe5 56               push    esi

be57bfe6 e883a30000       call SYMEVENT!SYMEvent_GetSubTask+0x2383 (be58636e)

be57bfeb ff7508           push    dword ptr [ebp+0x8]

be57bfee ff750c           push    dword ptr [ebp+0xc]

be57bff1 8d4de0           lea     ecx,[ebp-0x20]

be57bff4 e802ffffff       call    SYMEVENT+0xefb (be57befb)

be57bff9 ff15246f58be call dword ptr [SYMEVENT!SYMEvent_GetSubTask+0x2f39 (be586f24)]

be57bfff 6a00             push    0x0

be57c001 ff15206f58be call dword ptr [SYMEVENT!SYMEvent_GetSubTask+0x2f35 (be586f20)]

be57c007 8d4de0           lea     ecx,[ebp-0x20]

be57c00a 8845e0           mov     [ebp-0x20],al

be57c00d e822000000       call    SYMEVENT+0x1034 (be57c034)

 

Figure 17 

The observation that this time the program pushed the EBP pointer is encouraging – since that is what the debugger needs in order to continue its stack walk.  Thus, we only need to find the frame that called this routine and we can restart the stack walk.  The next interesting return address we found was at bdec68e0 on the stack.  The address (8041d915) there gave us the following disassembly (Figure 18):

 

3: kd> u 8041d915

nt!IopfCallDriver+35:

8041d915 5f               pop     edi

8041d916 5e               pop     esi

8041d917 c3               ret

 

Figure 18 

But since we have now returned back to code within the operating system, finding the beginning of the function was quite easy (Figure 19):

 

3: kd> u IopfCallDriver 8041d917

nt!IopfCallDriver:

8041d8e0 56               push    esi

8041d8e1 8bf2             mov     esi,edx

8041d8e3 57               push    edi

8041d8e4 8bf9             mov     edi,ecx

8041d8e6 fe4e23           dec     byte ptr [esi+0x23]

8041d8e9 8a4623           mov     al,[esi+0x23]

8041d8ec 33c9             xor     ecx,ecx

8041d8ee 3ac1             cmp     al,cl

8041d8f0 7f0b             jg      nt!IopfCallDriver+0x1d (8041d8fd)

8041d8f2 51               push    ecx

8041d8f3 51               push    ecx

8041d8f4 51               push    ecx

8041d8f5 56               push    esi

8041d8f6 6a35             push    0x35

8041d8f8 e8a1cd0000       call    nt!KeBugCheckEx (8042a69e)

8041d8fd 8b4660           mov     eax,[esi+0x60]

8041d900 56               push    esi

8041d901 83e824           sub     eax,0x24

8041d904 57               push    edi

8041d905 894660           mov     [esi+0x60],eax

8041d908 897814           mov     [eax+0x14],edi

8041d90b 8b4f08           mov     ecx,[edi+0x8]

8041d90e 0fb600           movzx   eax,byte ptr [eax]

8041d911 ff548138         call    dword ptr [ecx+eax*4+0x38]

8041d915 5f               pop     edi

8041d916 5e               pop     esi

 

Figure 19 

This is the entire disassembly of this function.  Knowing this, we can now exploit some of our information about how drivers work, since we know that the two parameters passed by IopfCallDriver are the DeviceObject and Irp for a driver.  These are clearly on the stack, immediately above the return address (Figure 20):

 

3: kd> !devobj 86267ac0

Device object (86267ac0) is for:

  \Driver\SymEvent DriverObject 86450eb0

Current Irp 00000000 RefCount 0 Type 00000008 Flags 00000040

DevExt 86267b78 DevObjExt 86267b80

ExtensionFlags (0000000000) 

AttachedTo (Lower) 868f5020 \FileSystem\Ntfs

Device queue is not busy.

 

Figure 20 

And (Figure 21 below).

 

3: kd> !irp 845d3ba8

Irp is active with 3 stacks 3 is current (= 0x845d3c60)

 No Mdl Thread 84386320:  Irp stack trace. 

     cmd  flg cl Device   File     Completion-Context

 [  0, 0]   0  0 00000000 00000000 00000000-00000000   

 

 Args: 00000000 00000000 00000000 00000000

 [  0, 0]   0  0 00000000 00000000 00000000-00000000   

 

 Args: 00000000 00000000 00000000 00000000

>[  0, 0]   0  0 86267ac0 86b6f3e8 00000000-00000000   

              \Driver\SymEvent

Args: bdec6a50 01000021 00030000 00000000

 

Figure 21 

If we look in the driver object, we can see the address of the function that was called (Figure 22):

 

3: kd> dd 86450eb0

86450eb0  00a80004 86266d20 00000012 be57b000

86450ec0  0000db60 863487c8 86450f58 00200020

86450ed0  e3087128 8053dd98 8692c01c be5878a0

86450ee0  00000000 00000000 be57bfda be57bfda

86450ef0  be57bfda be57bf7b be57bfda be57bfda

86450f00  be57bfda be57bfda be57bfda be57bfda

86450f10  be57bfda be57bfda be57bfda be57bfda

86450f20  be57bfda be57bfda be57bfda be57bfda

 

Figure 22 

Since the driver function table starts at offset 0x38 from the beginning of the driver object (note the call earlier used 0x38 as its offset value.  ECX contained the address of the driver object and EAX was the major function being called within the driver).  This gives us enough information to restart the debugger’s stack walk.  We do this by using the kv command, but this time specifying the optional arguments of the base pointer (which is the address on the stack one memory location below the return address), the stack pointer (which is the address of the stack before the return address was pushed onto it) and the instruction pointer (which is the address of the call instruction).  This is shown in Figure 23 below.

 

3: kd> kv =bdec6a7c bdec68f0  8041d911

ChildEBP RetAddr  Args to Child             

bdec68fc 804c13b2 8455d0e8 bdec6c98 bdec6c1c nt!IopfCallDriver+0x31 (FPO: [0,0,2])

bdec6a7c 804c18e4 86267ac0 00000000 bdec6b60 nt!IopParseDevice+0x9fc (FPO: [Non-Fpo])

bdec6ab4 804509b1 8455d0e8 00000000 bdec6b60 nt!IopParseFile+0x44 (FPO: [Non-Fpo])

bdec6b20 804d6db7 00000078 bdec6c1c 00000040 nt!ObpLookupObjectName+0xe3 (FPO: [Non-Fpo])

bdec6c30 804a1b4e 00000000 00000000 00000001 nt!ObOpenObjectByName+0xc5 (FPO: [Non-Fpo])

bdec6d04 804aa227 0006f068 00100001 0006f00c nt!IoCreateFile+0x3ec (FPO: [Non-Fpo])

bdec6d44 80465679 0006f068 00100001 0006f00c nt!NtOpenFile+0x25 (FPO: [Non-Fpo])

bdec6d44 77f8971d 0006f068 00100001 0006f00c nt!KiSystemService+0xc9 (FPO: [0,0] TrapFrame @ bdec6d64)

0006ed78 77e8c2f5 0006f068 00100001 0006f00c ntdll!ZwOpenFile+0xb (FPO: [6,0,0])

0006f05c 77ea0d28 7ffdec00 00000000 0006f088 KERNEL32!FindFirstFileExW+0x131 (FPO: [Non-Fpo])

*** ERROR: Symbol file could not be found.  Defaulted to export symbols for msvcrt.dll -

0006f2ec 78015e7d 0006f5f4 0006f304 00000015 KERNEL32!FindFirstFileA+0x31 (FPO: [Non-Fpo])

*** ERROR: Module load completed but symbols could not be loaded for nmake.exe

WARNING: Stack unwind information not available. Following frames may be wrong.

0006f444 0100bb94 0006f5f4 0006f4a4 00000011 msvcrt!findfirst+0x1b

0006f484 0100a145 0006f5f4 0027b0b0 0027b0c1 nmake+0xbb94

0006f5c0 010036bc 0027b0d8 0006f5f4 3c17ec9b nmake+0xa145

0006f848 01002eda 3c17ec9b 00000002 0006facc nmake+0x36bc

0006f86c 01003377 0027aeb0 00000002 0006facc nmake+0x2eda

0006fae8 01002eda 00000000 3c17ec62 0006fd6c nmake+0x3377

0006fb0c 01003377 002647a0 00000002 0006fd6c nmake+0x2eda

0006fd88 01002eda 00000000 3c1816e6 0006ff10 nmake+0x3377

0006fdac 010031c3 00285e68 00000002 0006ff10 nmake+0x2eda

 

Figure 23

 

Thus, even when the debugger cannot unravel the stack, it is possible to do so.  While it is certainly hard work, for some stack traces, this extra information can help analyzing a crash dump.  Alas, for the sample we used, it didn’t help, as the base analysis really told us everything we needed to know (see Figure 24 below.

 

3: kd> !analyze -v

*******************************************************************************

*                                                                             *

*                        Bugcheck Analysis                                    *

*                                                                             *

*******************************************************************************

 

 BAD_POOL_CALLER (c2)

The current thread is making a bad pool request.  Typically this is at a bad IRQL level or double freeing the same allocation, etc.

Arguments:

Arg1: 00000007, Attempt to free pool which was already freed

Arg2: 00000b8a, (reserved)

Arg3: 85517700, Memory contents of the pool block

Arg4: 85517708, Pointer to pool header

 

 Debugging Details:

------------------

 

 *85517700 size:   40 previous size:   40 Debugger SolutionDb Connection::Open failed 80004005

 

 

 FREED_POOL_TAG:  ScLF

 

 BUGCHECK_STR:  0xc2_7_ScLF

 

 DEFAULT_BUCKET_ID:  DRIVER_FAULT

Figure 24 

Happy Debugging!

 

 

User Comments
Rate this article and give us feedback. Do you find anything missing? Share your opinion with the community!
Post Your Comment

"Have no doubt"
The point is that the frame in figure 2 is the region that - in figure 1 - was skipped over by the debugger. If you look, you can see the address falls within the range the debugger did not unwind.

Rating:
09-Aug-08, Tony Mason


"A doubt"
Hi,

I am trying to understand the logic of manually walking the stack and i am stuck at the starting point - In fig 2 we have seen the dump for the frame pointer bdec6780, but it does not exist on the stack shown in fig 1. Should we be starting with bdec68c9??

Please help me clarify.

Thanks, Amol

Rating:
23-May-07, AJ


Post Your Comments.
Print this article.
Email this article.

Developing File Systems for Windows
Seattle, WA
4-7 Nov 2014

Kernel Debugging and Crash Analysis
LAB

Boston/Waltham, MA
10-14 Nov 2014

Writing WDF Drivers: Core Concepts
LAB

Palo Alto, CA
12-16 Jan 2015

Windows Internals and SW Drivers
LAB

Seattle, WA
16-20 Feb 2015

Writing WDF Drivers: Advanced Implementation Techniques
LAB

Palo Alto, CA
10-13 Mar 2015

 
 

Windows Debugger

Checked Build Downloads
29-Apr-10

Debugging Symbols

WDK Documentation

Windows WDK

 
 
x
LetUsHelp
 

Need to develop a Windows file system solution?

We've got a kit for that.

Need Windows internals or kernel driver expertise?

Bring us your most challenging project - we can help!

System hangs/crashes?

We've got a special diagnostic team that's standing by.

Visit the OSR Corporate Web site for more information about how OSR can help!

 
bottom nav links