finding IRP detail

Hakim · August 6, 2003, 12:12pm

Hello,

I was running DC2 from HCT 11.2. I got a bugcheck of IRQL not same before and after IoCallDriver. The bugcheck came with a different driver. I know the problem is with my driver and it is most probably with spin locks not released . From the stack I get the IRP address related to my driver from IovCallDriver argument. Then I use !irp to get detail info. My driver is \Driver\CTIBHNPort. I can’t find any way to know the IoControlCode of this IRP, if I know this I can analyse the related code. Any hint or suggestion will be greatly appreciated.

Thanks,
Hablu

ChildEBP RetAddr Args to Child
fa6a2724 805258ca 00000003 fa6a2a54 00000005 nt!RtlpBreakWithStatusInstruction (FPO: [1,0,0])
fa6a2770 80526160 00000003 ffbc5040 806ce014 nt!KiBugCheckDebugBreak+0x19 (FPO: [Non-Fpo])
fa6a2b3c 805266db 000000c9 00000005 ffbc5040 nt!KeBugCheck2+0x46d (FPO: [Non-Fpo])
fa6a2b5c 80647152 000000c9 00000005 ffbc5040 nt!KeBugCheckEx+0x19 (FPO: [Non-Fpo])
fa6a2b94 8064f4de 81148148 8116e040 00000000 nt!IovCallDriver+0xdf (FPO: [Non-Fpo])
fa6a2ba4 804eca36 81148148 8193aed8 806ce014 nt!ViDriverDispatchGeneric+0x27 (FPO: [2,0,3])
fa6a2bb4 80647111 811b90e8 8193aed8 00000000 nt!IopfCallDriver+0x31 (FPO: [0,0,1])
fa6a2bd8 fc95b8ab 811b90e8 8193aed8 8193afd8 nt!IovCallDriver+0x9e (FPO: [Non-Fpo])
fa6a2bec fc95baa2 811b9030 0093aed8 811b9030 serenum!Serenum_DispatchPassThrough+0x63 (FPO: [Non-Fpo])
fa6a2c10 804eca36 811b9030 00000000 806ce014 serenum!Serenum_IoCtl+0x70 (FPO: [Non-Fpo])
fa6a2c20 80647111 ffa65230 806cde40 8193aed8 nt!IopfCallDriver+0x31 (FPO: [0,0,1])
fa6a2c44 8058b076 8193afd8 ffabccc8 8193aed8 nt!IovCallDriver+0x9e (FPO: [Non-Fpo])
fa6a2c58 8058bc62 811b9030 8193aed8 ffabccc8 nt!IopSynchronousServiceTail+0x5e (FPO: [Non-Fpo])
fa6a2d00 805987ec 00000068 00000000 00000000 nt!IopXxxControlFile+0x5ec
fa6a2d34 804da140 00000068 00000000 00000000 nt!NtDeviceIoControlFile+0x28 (FPO: [Non-Fpo])
fa6a2d34 7ffe0304 00000068 00000000 00000000 nt!KiSystemService+0xc4 (FPO: [0,0] TrapFrame @ fa6a2d64)
0006eab0 77f75b1d 01011ff2 00000068 00000000 SharedUserData!SystemCallStub+0x4 (FPO: [0,0,0])
0006eab4 01011ff2 00000068 00000000 00000000 ntdll!ZwDeviceIoControlFile+0xc (FPO: [10,0,0])
WARNING: Stack unwind information not available. Following frames may be wrong.
0006eb70 01013728 0101a070 00264978 00000010 dc2+0x11ff2
0006f3e8 010149da 00000058 002f0508 0101a070 dc2+0x13728

kd> !irp 8193aed8 1
Irp is active with 5 stacks 7 is current (= 00000000)
No Mdl System buffer = ffa01940 Thread ffa65054: Irp is completed.
Flags = 40000070
ThreadListEntry.Flink = ffa65230
ThreadListEntry.Blink = ffa65230
IoStatus.Status = 00000000
IoStatus.Information = 00000004
RequestorMode = 00000001
Cancel = 00
CancelIrql = 0
ApcEnvironment = 00
UserIosb = 0102f288
UserEvent = 00000000
Overlay.AsynchronousParameters.UserApcRoutine = 00000000
Overlay.AsynchronousParameters.UserApcContext = 00000000
Overlay.AllocationSize = 00000000 - 00000000
CancelRoutine = 00000000
UserBuffer = 00280000
&Tail.Overlay.DeviceQueueEntry = 8193af18
Tail.Overlay.Thread = ffa65054
Tail.Overlay.AuxiliaryBuffer = 804f4c48
Tail.Overlay.ListEntry.Flink = 8060188d
Tail.Overlay.ListEntry.Blink = 00000000
Tail.Overlay.CurrentStackLocation = 00000000
Tail.Overlay.OriginalFileObject = ffabccc8
Tail.Apc = 00300012
Tail.CompletionKey = 00300012
cmd flg cl Device File Completion-Context
[0, 0] 0 0 00000000 00000000 00000000-00000000

Args: 00000000 00000000 00000000 00000000
[0, 0] 0 10 00000000 00000000 00000000-00000000

Args: 00000000 00000000 00000000 00000000
[e, 0] 0 10 ffbc5040 00000000 806515f2-8193afb4
\Driver\CTIBHNPort nt!IovpInternalCompletionTrap
Args: 00000000 00000000 00000000 00000000
[e, 0] 0 10 81148148 00000000 806515f2-8193afd8
\DRIVER\VERIFIER nt!IovpInternalCompletionTrap
Args: 00000000 00000000 00000000 00000000
[e, 0] 0 10 811b9030 00000000 00000000-00000000
\Driver\serenum
Args: 00000000 00000000 00000000 00000000

OSR_Community_User · August 6, 2003, 4:22pm

Well, it would be trivial if your CurrentStackLocation pointed to your
driver’s SP. Then you could use “dt IO_STACK_LOCATION” on that address.

So, using dt, I was able to establish that the IRP is 0x70 bytes, and each
stack location is 0x24. So, I think your drivers SP would be at
8193aed8+70+24+24. Try “dt IO_STACK_LOCATION” on that address.

Let me know if this works. I hope my math isn’t off…

Marybeth Croci
Stratus Technologies

-----Original Message-----
From: xxxxx@yahoo.ca [mailto:xxxxx@yahoo.ca]
Sent: Wednesday, August 06, 2003 12:12 PM
To: Kernel Debugging Interest List
Subject: [windbg] finding IRP detail

Hello,

I was running DC2 from HCT 11.2. I got a bugcheck of IRQL not same before
and after IoCallDriver. The bugcheck came with a different driver. I know
the problem is with my driver and it is most probably with spin locks not
released . From the stack I get the IRP address related to my driver from
IovCallDriver argument. Then I use !irp to get detail info. My driver is
\Driver\CTIBHNPort. I can’t find any way to know the IoControlCode of this
IRP, if I know this I can analyse the related code. Any hint or suggestion
will be greatly appreciated.

Thanks,
Hablu

ChildEBP RetAddr Args to Child
fa6a2724 805258ca 00000003 fa6a2a54 00000005
nt!RtlpBreakWithStatusInstruction (FPO: [1,0,0])
fa6a2770 80526160 00000003 ffbc5040 806ce014 nt!KiBugCheckDebugBreak+0x19
(FPO: [Non-Fpo])
fa6a2b3c 805266db 000000c9 00000005 ffbc5040 nt!KeBugCheck2+0x46d (FPO:
[Non-Fpo])
fa6a2b5c 80647152 000000c9 00000005 ffbc5040 nt!KeBugCheckEx+0x19 (FPO:
[Non-Fpo])
fa6a2b94 8064f4de 81148148 8116e040 00000000 nt!IovCallDriver+0xdf (FPO:
[Non-Fpo])
fa6a2ba4 804eca36 81148148 8193aed8 806ce014 nt!ViDriverDispatchGeneric+0x27
(FPO: [2,0,3])
fa6a2bb4 80647111 811b90e8 8193aed8 00000000 nt!IopfCallDriver+0x31 (FPO:
[0,0,1])
fa6a2bd8 fc95b8ab 811b90e8 8193aed8 8193afd8 nt!IovCallDriver+0x9e (FPO:
[Non-Fpo])
fa6a2bec fc95baa2 811b9030 0093aed8 811b9030
serenum!Serenum_DispatchPassThrough+0x63 (FPO: [Non-Fpo])
fa6a2c10 804eca36 811b9030 00000000 806ce014 serenum!Serenum_IoCtl+0x70
(FPO: [Non-Fpo])
fa6a2c20 80647111 ffa65230 806cde40 8193aed8 nt!IopfCallDriver+0x31 (FPO:
[0,0,1])
fa6a2c44 8058b076 8193afd8 ffabccc8 8193aed8 nt!IovCallDriver+0x9e (FPO:
[Non-Fpo])
fa6a2c58 8058bc62 811b9030 8193aed8 ffabccc8
nt!IopSynchronousServiceTail+0x5e (FPO: [Non-Fpo])
fa6a2d00 805987ec 00000068 00000000 00000000 nt!IopXxxControlFile+0x5ec
fa6a2d34 804da140 00000068 00000000 00000000 nt!NtDeviceIoControlFile+0x28
(FPO: [Non-Fpo])
fa6a2d34 7ffe0304 00000068 00000000 00000000 nt!KiSystemService+0xc4 (FPO:
[0,0] TrapFrame @ fa6a2d64)
0006eab0 77f75b1d 01011ff2 00000068 00000000
SharedUserData!SystemCallStub+0x4 (FPO: [0,0,0])
0006eab4 01011ff2 00000068 00000000 00000000 ntdll!ZwDeviceIoControlFile+0xc
(FPO: [10,0,0])
WARNING: Stack unwind information not available. Following frames may be
wrong.
0006eb70 01013728 0101a070 00264978 00000010 dc2+0x11ff2
0006f3e8 010149da 00000058 002f0508 0101a070 dc2+0x13728

kd> !irp 8193aed8 1
Irp is active with 5 stacks 7 is current (= 00000000)
No Mdl System buffer = ffa01940 Thread ffa65054: Irp is completed.
Flags = 40000070
ThreadListEntry.Flink = ffa65230
ThreadListEntry.Blink = ffa65230
IoStatus.Status = 00000000
IoStatus.Information = 00000004
RequestorMode = 00000001
Cancel = 00
CancelIrql = 0
ApcEnvironment = 00
UserIosb = 0102f288
UserEvent = 00000000
Overlay.AsynchronousParameters.UserApcRoutine = 00000000
Overlay.AsynchronousParameters.UserApcContext = 00000000
Overlay.AllocationSize = 00000000 - 00000000
CancelRoutine = 00000000
UserBuffer = 00280000
&Tail.Overlay.DeviceQueueEntry = 8193af18
Tail.Overlay.Thread = ffa65054
Tail.Overlay.AuxiliaryBuffer = 804f4c48
Tail.Overlay.ListEntry.Flink = 8060188d
Tail.Overlay.ListEntry.Blink = 00000000
Tail.Overlay.CurrentStackLocation = 00000000
Tail.Overlay.OriginalFileObject = ffabccc8
Tail.Apc = 00300012
Tail.CompletionKey = 00300012
cmd flg cl Device File Completion-Context
[0, 0] 0 0 00000000 00000000 00000000-00000000

Args: 00000000 00000000 00000000 00000000
[0, 0] 0 10 00000000 00000000 00000000-00000000

Args: 00000000 00000000 00000000 00000000
[e, 0] 0 10 ffbc5040 00000000 806515f2-8193afb4
\Driver\CTIBHNPort nt!IovpInternalCompletionTrap
Args: 00000000 00000000 00000000 00000000
[e, 0] 0 10 81148148 00000000 806515f2-8193afd8
\DRIVER\VERIFIER nt!IovpInternalCompletionTrap
Args: 00000000 00000000 00000000 00000000
[e, 0] 0 10 811b9030 00000000 00000000-00000000
\Driver\serenum
Args: 00000000 00000000 00000000 00000000

You are currently subscribed to windbg as: xxxxx@stratus.com
To unsubscribe send a blank email to xxxxx@lists.osr.com

Hakim · August 7, 2003, 2:35pm

This is excellent! Your math is absolutely correct.
But the IoControlCode is 0 which is wrong, IRP is completed so its field got modified, I found it later by experiment.
I have been able to narrow down the analysis from the Information field of the irp and detected the IOCTL and able to reproduce the problem. Now, I’d like to back trace the stack. Following is the stack right before before IoCompleteRequest:

ChildEBP RetAddr Args to Child
fa6a2b60 804eca36 ffbb1040 8192eed8 806ce014 ctibhnp!CtiIoControl+0x1926 (CONV: stdcall) [c:\projects\bhn\driver\port\1000\ioctl.c @ 2148]
fa6a2b70 80647111 8192efac 8192efd0 8115efc0 nt!IopfCallDriver+0x31 (FPO: [0,0,1])
fa6a2b94 8064f4de 8115ef08 810fa568 00000000 nt!IovCallDriver+0x9e (FPO: [Non-Fpo])
fa6a2ba4 804eca36 8115ef08 8192eed8 806ce014 nt!ViDriverDispatchGeneric+0x27 (FPO: [2,0,3])
fa6a2bb4 80647111 811f6bc8 8192eed8 00000000 nt!IopfCallDriver+0x31 (FPO: [0,0,1])
fa6a2bd8 fc95b8ab 811f6bc8 8192eed8 8192efd8 nt!IovCallDriver+0x9e (FPO: [Non-Fpo])
fa6a2bec fc95baa2 811f6b10 0092eed8 811f6b10 serenum!Serenum_DispatchPassThrough+0x63 (FPO: [Non-Fpo])
fa6a2c10 804eca36 811f6b10 00000000 806ce014 serenum!Serenum_IoCtl+0x70 (FPO: [Non-Fpo])
fa6a2c20 80647111 ffa52230 806cde40 8192eed8 nt!IopfCallDriver+0x31 (FPO: [0,0,1])
fa6a2c44 8058b076 8192efd8 8122b6f0 8192eed8 nt!IovCallDriver+0x9e (FPO: [Non-Fpo])
fa6a2c58 8058bc62 811f6b10 8192eed8 8122b6f0 nt!IopSynchronousServiceTail+0x5e (FPO: [Non-Fpo])
fa6a2d00 805987ec 000007a8 0000079c 00000000 nt!IopXxxControlFile+0x5ec
fa6a2d34 804da140 000007a8 0000079c 00000000 nt!NtDeviceIoControlFile+0x28 (FPO: [Non-Fpo])
fa6a2d34 7ffe0304 000007a8 0000079c 00000000 nt!KiSystemService+0xc4 (FPO: [0,0] TrapFrame @ fa6a2d64)
0012fccc 77f75b1d 77e755d6 000007a8 0000079c SharedUserData!SystemCallStub+0x4 (FPO: [0,0,0])
0012fcd0 77e755d6 000007a8 0000079c 00000000 ntdll!ZwDeviceIoControlFile+0xc (FPO: [10,0,0])
0012fd30 004022a5 000007a8 001b0040 00000000 kernel32!DeviceIoControl+0x78 (FPO: [Non-Fpo])
WARNING: Stack unwind information not available. Following frames may be wrong.
0012fe2c 77d43b37 00401bf0 000300a2 00000111 MTTTY+0x22a5
0012fe94 77d43d91 00000000 00401bf0 000300a2 USER32!UserCallWinProcCheckWow+0x150 (FPO: [Non-Fpo])
0012fef4 77d4438c 0012ff1c 00000001 00401a32 USER32!DispatchMessageWorker+0x306 (FPO: [Non-Fpo])

Following is the call chain for the last frame:

kd> dd fa6a2b58
fa6a2b58 8192ef90 ffbb10f8 fa6a2b94 804eca36
fa6a2b68 ffbb1040 8192eed8 806ce014 80647111
fa6a2b78 8192efac 8192efd0 8115efc0 ffffff00
fa6a2b88 ffffffff ffa35220 8192eed8 fa6a2bd8
fa6a2b98 8064f4de 8115ef08 810fa568 00000000
fa6a2ba8 804eca36 8115ef08 8192eed8 806ce014
fa6a2bb8 80647111 811f6bc8 8192eed8 00000000
fa6a2bc8 ffffff00 ffffffff ffaacf08 8192eed8

Following is the stack right after the return from the function CtiIoControl by single stepping, the control is now in some part of Os’s kernel code

ChildEBP RetAddr Args to Child
fa6a2b70 80647111 8192efac 8192efd0 8115efc0 nt!IopfCallDriver+0x31 (FPO: [0,0,1])
fa6a2b94 8064f4de 8115ef08 810fa568 00000000 nt!IovCallDriver+0x9e (FPO: [Non-Fpo])
fa6a2ba4 804eca36 8115ef08 8192eed8 806ce014 nt!ViDriverDispatchGeneric+0x27 (FPO: [2,0,3])
fa6a2bb4 80647111 811f6bc8 8192eed8 00000000 nt!IopfCallDriver+0x31 (FPO: [0,0,1])
fa6a2bd8 fc95b8ab 811f6bc8 8192eed8 8192efd8 nt!IovCallDriver+0x9e (FPO: [Non-Fpo])
fa6a2bec fc95baa2 811f6b10 0092eed8 811f6b10 serenum!Serenum_DispatchPassThrough+0x63 (FPO: [Non-Fpo])
fa6a2c10 804eca36 811f6b10 00000000 806ce014 serenum!Serenum_IoCtl+0x70 (FPO: [Non-Fpo])
fa6a2c20 80647111 ffa52230 806cde40 8192eed8 nt!IopfCallDriver+0x31 (FPO: [0,0,1])
fa6a2c44 8058b076 8192efd8 8122b6f0 8192eed8 nt!IovCallDriver+0x9e (FPO: [Non-Fpo])
fa6a2c58 8058bc62 811f6b10 8192eed8 8122b6f0 nt!IopSynchronousServiceTail+0x5e (FPO: [Non-Fpo])
fa6a2d00 805987ec 000007a8 0000079c 00000000 nt!IopXxxControlFile+0x5ec
fa6a2d34 804da140 000007a8 0000079c 00000000 nt!NtDeviceIoControlFile+0x28 (FPO: [Non-Fpo])
fa6a2d34 7ffe0304 000007a8 0000079c 00000000 nt!KiSystemService+0xc4 (FPO: [0,0] TrapFrame @ fa6a2d64)
0012fccc 77f75b1d 77e755d6 000007a8 0000079c SharedUserData!SystemCallStub+0x4 (FPO: [0,0,0])
0012fcd0 77e755d6 000007a8 0000079c 00000000 ntdll!ZwDeviceIoControlFile+0xc (FPO: [10,0,0])
0012fd30 004022a5 000007a8 001b0040 00000000 kernel32!DeviceIoControl+0x78 (FPO: [Non-Fpo])
WARNING: Stack unwind information not available. Following frames may be wrong.
0012fe2c 77d43b37 00401bf0 000300a2 00000111 MTTTY+0x22a5
0012fe94 77d43d91 00000000 00401bf0 000300a2 USER32!UserCallWinProcCheckWow+0x150 (FPO: [Non-Fpo])
0012fef4 77d4438c 0012ff1c 00000001 00401a32 USER32!DispatchMessageWorker+0x306 (FPO: [Non-Fpo])
0012ff00 00401a32 0012ff1c 77f517e6 0012ffc0 USER32!DispatchMessageA+0xb (FPO: [1,0,0])

Alas, the function call of my driver vanished from the stack. If I do a dd around the last frame of previous stack I find that EBP is now 0 which makes sense why it is vanished.

kd> dd fa6a2b58
fa6a2b58 8115ef00 fa6a2b94 00000000 804eca36
fa6a2b68 00000008 00000206 806ce014 80647111
fa6a2b78 8192efac 8192efd0 8115efc0 ffffff00
fa6a2b88 ffffffff ffa35220 8192eed8 fa6a2bd8
fa6a2b98 8064f4de 8115ef08 810fa568 00000000
fa6a2ba8 804eca36 8115ef08 8192eed8 806ce014
fa6a2bb8 80647111 811f6bc8 8192eed8 00000000
fa6a2bc8 ffffff00 ffffffff ffaacf08 8192eed8

If I step through more it’ll bugcheck. At this point I’d like to find the frame whcih was:
fa6a2b60 804eca36 ffbb1040 8192eed8 806ce014 ctibhnp!CtiIoControl+0x1926 (CONV: stdcall) [c:\projects\bhn\driver\port\1000\ioctl.c @ 2148]

I have ‘Stacking the Deck’ (The NT Insider, Nov-Dec, 2002) open in front of me, yet if you could give me some quick hints that will be great.

Thanks,
Hablu

Well, it would be trivial if your CurrentStackLocation pointed to your
driver’s SP. Then you could use “dt IO_STACK_LOCATION” on that address.

So, using dt, I was able to establish that the IRP is 0x70 bytes, and each
stack location is 0x24. So, I think your drivers SP would be at
8193aed8+70+24+24. Try “dt IO_STACK_LOCATION” on that address.

Let me know if this works. I hope my math isn’t off…

Marybeth Croci
Stratus Technologies

-----Original Message-----
From: xxxxx@yahoo.ca [mailto:xxxxx@yahoo.ca]
Sent: Wednesday, August 06, 2003 12:12 PM
To: Kernel Debugging Interest List
Subject: [windbg] finding IRP detail

Hello,

I was running DC2 from HCT 11.2. I got a bugcheck of IRQL not same before
and after IoCallDriver. The bugcheck came with a different driver. I know
the problem is with my driver and it is most probably with spin locks not
released . From the stack I get the IRP address related to my driver from
IovCallDriver argument. Then I use !irp to get detail info. My driver is
\Driver\CTIBHNPort. I can’t find any way to know the IoControlCode of this
IRP, if I know this I can analyse the related code. Any hint or suggestion
will be greatly appreciated.

Thanks,
Hablu

OSR_Community_User · August 7, 2003, 2:45pm

Unless I’m missing something, driver verifier is reporting that you exited
your dispatch routine CtiIoControl with IRQL different from when you
entered; so this is a problem in your routine that is, presumably, raising
IRQL and neglecting to lower it again.

/simgr

PS: Marybeths arithmetic was, as always, dead on, but in fact is not
required as the !irp command shows you the parameters in each stack location

it dumps the parameters as 4 longwords, you can then look at ntddk.h to
determine the values relevant to the specific request - in the case of an
IOCTL, the third longword shows the IoControlCode value.

-----Original Message-----
From: xxxxx@yahoo.ca [mailto:xxxxx@yahoo.ca]
Sent: Thursday, August 07, 2003 2:35 PM
To: Kernel Debugging Interest List
Subject: [windbg] RE: finding IRP detail

This is excellent! Your math is absolutely correct.
But the IoControlCode is 0 which is wrong, IRP is completed so its field got
modified, I found it later by experiment.
I have been able to narrow down the analysis from the Information field of
the irp and detected the IOCTL and able to reproduce the problem. Now, I’d
like to back trace the stack. Following is the stack right before before
IoCompleteRequest:

ChildEBP RetAddr Args to Child
fa6a2b60 804eca36 ffbb1040 8192eed8 806ce014 ctibhnp!CtiIoControl+0x1926
(CONV: stdcall) [c:\projects\bhn\driver\port\1000\ioctl.c @ 2148]
fa6a2b70 80647111 8192efac 8192efd0 8115efc0 nt!IopfCallDriver+0x31 (FPO:
[0,0,1])
fa6a2b94 8064f4de 8115ef08 810fa568 00000000 nt!IovCallDriver+0x9e (FPO:
[Non-Fpo])
fa6a2ba4 804eca36 8115ef08 8192eed8 806ce014 nt!ViDriverDispatchGeneric+0x27
(FPO: [2,0,3])
fa6a2bb4 80647111 811f6bc8 8192eed8 00000000 nt!IopfCallDriver+0x31 (FPO:
[0,0,1])
fa6a2bd8 fc95b8ab 811f6bc8 8192eed8 8192efd8 nt!IovCallDriver+0x9e (FPO:
[Non-Fpo])
fa6a2bec fc95baa2 811f6b10 0092eed8 811f6b10
serenum!Serenum_DispatchPassThrough+0x63 (FPO: [Non-Fpo])
fa6a2c10 804eca36 811f6b10 00000000 806ce014 serenum!Serenum_IoCtl+0x70
(FPO: [Non-Fpo])
fa6a2c20 80647111 ffa52230 806cde40 8192eed8 nt!IopfCallDriver+0x31 (FPO:
[0,0,1])
fa6a2c44 8058b076 8192efd8 8122b6f0 8192eed8 nt!IovCallDriver+0x9e (FPO:
[Non-Fpo])
fa6a2c58 8058bc62 811f6b10 8192eed8 8122b6f0
nt!IopSynchronousServiceTail+0x5e (FPO: [Non-Fpo])
fa6a2d00 805987ec 000007a8 0000079c 00000000 nt!IopXxxControlFile+0x5ec
fa6a2d34 804da140 000007a8 0000079c 00000000 nt!NtDeviceIoControlFile+0x28
(FPO: [Non-Fpo])
fa6a2d34 7ffe0304 000007a8 0000079c 00000000 nt!KiSystemService+0xc4 (FPO:
[0,0] TrapFrame @ fa6a2d64)
0012fccc 77f75b1d 77e755d6 000007a8 0000079c
SharedUserData!SystemCallStub+0x4 (FPO: [0,0,0])
0012fcd0 77e755d6 000007a8 0000079c 00000000 ntdll!ZwDeviceIoControlFile+0xc
(FPO: [10,0,0])
0012fd30 004022a5 000007a8 001b0040 00000000 kernel32!DeviceIoControl+0x78
(FPO: [Non-Fpo])
WARNING: Stack unwind information not available. Following frames may be
wrong.
0012fe2c 77d43b37 00401bf0 000300a2 00000111 MTTTY+0x22a5
0012fe94 77d43d91 00000000 00401bf0 000300a2
USER32!UserCallWinProcCheckWow+0x150 (FPO: [Non-Fpo])
0012fef4 77d4438c 0012ff1c 00000001 00401a32
USER32!DispatchMessageWorker+0x306 (FPO: [Non-Fpo])

Following is the call chain for the last frame:

kd> dd fa6a2b58
fa6a2b58 8192ef90 ffbb10f8 fa6a2b94 804eca36
fa6a2b68 ffbb1040 8192eed8 806ce014 80647111
fa6a2b78 8192efac 8192efd0 8115efc0 ffffff00
fa6a2b88 ffffffff ffa35220 8192eed8 fa6a2bd8
fa6a2b98 8064f4de 8115ef08 810fa568 00000000
fa6a2ba8 804eca36 8115ef08 8192eed8 806ce014
fa6a2bb8 80647111 811f6bc8 8192eed8 00000000
fa6a2bc8 ffffff00 ffffffff ffaacf08 8192eed8

Following is the stack right after the return from the function CtiIoControl
by single stepping, the control is now in some part of Os’s kernel code

ChildEBP RetAddr Args to Child
fa6a2b70 80647111 8192efac 8192efd0 8115efc0 nt!IopfCallDriver+0x31 (FPO:
[0,0,1])
fa6a2b94 8064f4de 8115ef08 810fa568 00000000 nt!IovCallDriver+0x9e (FPO:
[Non-Fpo])
fa6a2ba4 804eca36 8115ef08 8192eed8 806ce014 nt!ViDriverDispatchGeneric+0x27
(FPO: [2,0,3])
fa6a2bb4 80647111 811f6bc8 8192eed8 00000000 nt!IopfCallDriver+0x31 (FPO:
[0,0,1])
fa6a2bd8 fc95b8ab 811f6bc8 8192eed8 8192efd8 nt!IovCallDriver+0x9e (FPO:
[Non-Fpo])
fa6a2bec fc95baa2 811f6b10 0092eed8 811f6b10
serenum!Serenum_DispatchPassThrough+0x63 (FPO: [Non-Fpo])
fa6a2c10 804eca36 811f6b10 00000000 806ce014 serenum!Serenum_IoCtl+0x70
(FPO: [Non-Fpo])
fa6a2c20 80647111 ffa52230 806cde40 8192eed8 nt!IopfCallDriver+0x31 (FPO:
[0,0,1])
fa6a2c44 8058b076 8192efd8 8122b6f0 8192eed8 nt!IovCallDriver+0x9e (FPO:
[Non-Fpo])
fa6a2c58 8058bc62 811f6b10 8192eed8 8122b6f0
nt!IopSynchronousServiceTail+0x5e (FPO: [Non-Fpo])
fa6a2d00 805987ec 000007a8 0000079c 00000000 nt!IopXxxControlFile+0x5ec
fa6a2d34 804da140 000007a8 0000079c 00000000 nt!NtDeviceIoControlFile+0x28
(FPO: [Non-Fpo])
fa6a2d34 7ffe0304 000007a8 0000079c 00000000 nt!KiSystemService+0xc4 (FPO:
[0,0] TrapFrame @ fa6a2d64)
0012fccc 77f75b1d 77e755d6 000007a8 0000079c
SharedUserData!SystemCallStub+0x4 (FPO: [0,0,0])
0012fcd0 77e755d6 000007a8 0000079c 00000000 ntdll!ZwDeviceIoControlFile+0xc
(FPO: [10,0,0])
0012fd30 004022a5 000007a8 001b0040 00000000 kernel32!DeviceIoControl+0x78
(FPO: [Non-Fpo])
WARNING: Stack unwind information not available. Following frames may be
wrong.
0012fe2c 77d43b37 00401bf0 000300a2 00000111 MTTTY+0x22a5
0012fe94 77d43d91 00000000 00401bf0 000300a2
USER32!UserCallWinProcCheckWow+0x150 (FPO: [Non-Fpo])
0012fef4 77d4438c 0012ff1c 00000001 00401a32
USER32!DispatchMessageWorker+0x306 (FPO: [Non-Fpo])
0012ff00 00401a32 0012ff1c 77f517e6 0012ffc0 USER32!DispatchMessageA+0xb
(FPO: [1,0,0])

Alas, the function call of my driver vanished from the stack. If I do a dd
around the last frame of previous stack I find that EBP is now 0 which makes
sense why it is vanished.

kd> dd fa6a2b58
fa6a2b58 8115ef00 fa6a2b94 00000000 804eca36
fa6a2b68 00000008 00000206 806ce014 80647111
fa6a2b78 8192efac 8192efd0 8115efc0 ffffff00
fa6a2b88 ffffffff ffa35220 8192eed8 fa6a2bd8
fa6a2b98 8064f4de 8115ef08 810fa568 00000000
fa6a2ba8 804eca36 8115ef08 8192eed8 806ce014
fa6a2bb8 80647111 811f6bc8 8192eed8 00000000
fa6a2bc8 ffffff00 ffffffff ffaacf08 8192eed8

If I step through more it’ll bugcheck. At this point I’d like to find the
frame whcih was:
fa6a2b60 804eca36 ffbb1040 8192eed8 806ce014 ctibhnp!CtiIoControl+0x1926
(CONV: stdcall) [c:\projects\bhn\driver\port\1000\ioctl.c @ 2148]

I have ‘Stacking the Deck’ (The NT Insider, Nov-Dec, 2002) open in front of
me, yet if you could give me some quick hints that will be great.

Thanks,
Hablu

Well, it would be trivial if your CurrentStackLocation pointed to your
driver’s SP. Then you could use “dt IO_STACK_LOCATION” on that address.

So, using dt, I was able to establish that the IRP is 0x70 bytes, and each
stack location is 0x24. So, I think your drivers SP would be at
8193aed8+70+24+24. Try “dt IO_STACK_LOCATION” on that address.

Let me know if this works. I hope my math isn’t off…

Marybeth Croci
Stratus Technologies

-----Original Message-----
From: xxxxx@yahoo.ca [mailto:xxxxx@yahoo.ca]
Sent: Wednesday, August 06, 2003 12:12 PM
To: Kernel Debugging Interest List
Subject: [windbg] finding IRP detail

Hello,

I was running DC2 from HCT 11.2. I got a bugcheck of IRQL not same before
and after IoCallDriver. The bugcheck came with a different driver. I know
the problem is with my driver and it is most probably with spin locks not
released . From the stack I get the IRP address related to my driver from
IovCallDriver argument. Then I use !irp to get detail info. My driver is
\Driver\CTIBHNPort. I can’t find any way to know the IoControlCode of this
IRP, if I know this I can analyse the related code. Any hint or suggestion
will be greatly appreciated.

Thanks,
Hablu

You are currently subscribed to windbg as: xxxxx@stratus.com
To unsubscribe send a blank email to xxxxx@lists.osr.com

OSR_Community_User · August 7, 2003, 2:55pm

The stack frame of your routine “vanished” from the stack because you
returned. I’m not sure what you were hoping to find in the stale stack
frame after returning. If you want to see the values of local variables, do
it while your routine is still running.

Remember, the bug check that you got is indicating that the IRQL changed
during the call to your driver. If this is reproducible and you can single
step through it, you certainly should be able to determined what caused the
IRQL change. Knowing the before and after values of the IRQL might suggest
some hypothesis. What were they?

Marybeth Croci

-----Original Message-----
From: xxxxx@yahoo.ca [mailto:xxxxx@yahoo.ca]
Sent: Thursday, August 07, 2003 2:35 PM
To: Kernel Debugging Interest List
Subject: [windbg] RE: finding IRP detail

This is excellent! Your math is absolutely correct.
But the IoControlCode is 0 which is wrong, IRP is completed so its field got
modified, I found it later by experiment.
I have been able to narrow down the analysis from the Information field of
the irp and detected the IOCTL and able to reproduce the problem. Now, I’d
like to back trace the stack. Following is the stack right before before
IoCompleteRequest:

ChildEBP RetAddr Args to Child
fa6a2b60 804eca36 ffbb1040 8192eed8 806ce014 ctibhnp!CtiIoControl+0x1926
(CONV: stdcall) [c:\projects\bhn\driver\port\1000\ioctl.c @ 2148]
fa6a2b70 80647111 8192efac 8192efd0 8115efc0 nt!IopfCallDriver+0x31 (FPO:
[0,0,1])
fa6a2b94 8064f4de 8115ef08 810fa568 00000000 nt!IovCallDriver+0x9e (FPO:
[Non-Fpo])
fa6a2ba4 804eca36 8115ef08 8192eed8 806ce014 nt!ViDriverDispatchGeneric+0x27
(FPO: [2,0,3])
fa6a2bb4 80647111 811f6bc8 8192eed8 00000000 nt!IopfCallDriver+0x31 (FPO:
[0,0,1])
fa6a2bd8 fc95b8ab 811f6bc8 8192eed8 8192efd8 nt!IovCallDriver+0x9e (FPO:
[Non-Fpo])
fa6a2bec fc95baa2 811f6b10 0092eed8 811f6b10
serenum!Serenum_DispatchPassThrough+0x63 (FPO: [Non-Fpo])
fa6a2c10 804eca36 811f6b10 00000000 806ce014 serenum!Serenum_IoCtl+0x70
(FPO: [Non-Fpo])
fa6a2c20 80647111 ffa52230 806cde40 8192eed8 nt!IopfCallDriver+0x31 (FPO:
[0,0,1])
fa6a2c44 8058b076 8192efd8 8122b6f0 8192eed8 nt!IovCallDriver+0x9e (FPO:
[Non-Fpo])
fa6a2c58 8058bc62 811f6b10 8192eed8 8122b6f0
nt!IopSynchronousServiceTail+0x5e (FPO: [Non-Fpo])
fa6a2d00 805987ec 000007a8 0000079c 00000000 nt!IopXxxControlFile+0x5ec
fa6a2d34 804da140 000007a8 0000079c 00000000 nt!NtDeviceIoControlFile+0x28
(FPO: [Non-Fpo])
fa6a2d34 7ffe0304 000007a8 0000079c 00000000 nt!KiSystemService+0xc4 (FPO:
[0,0] TrapFrame @ fa6a2d64)
0012fccc 77f75b1d 77e755d6 000007a8 0000079c
SharedUserData!SystemCallStub+0x4 (FPO: [0,0,0])
0012fcd0 77e755d6 000007a8 0000079c 00000000 ntdll!ZwDeviceIoControlFile+0xc
(FPO: [10,0,0])
0012fd30 004022a5 000007a8 001b0040 00000000 kernel32!DeviceIoControl+0x78
(FPO: [Non-Fpo])
WARNING: Stack unwind information not available. Following frames may be
wrong.
0012fe2c 77d43b37 00401bf0 000300a2 00000111 MTTTY+0x22a5
0012fe94 77d43d91 00000000 00401bf0 000300a2
USER32!UserCallWinProcCheckWow+0x150 (FPO: [Non-Fpo])
0012fef4 77d4438c 0012ff1c 00000001 00401a32
USER32!DispatchMessageWorker+0x306 (FPO: [Non-Fpo])

Following is the call chain for the last frame:

kd> dd fa6a2b58
fa6a2b58 8192ef90 ffbb10f8 fa6a2b94 804eca36
fa6a2b68 ffbb1040 8192eed8 806ce014 80647111
fa6a2b78 8192efac 8192efd0 8115efc0 ffffff00
fa6a2b88 ffffffff ffa35220 8192eed8 fa6a2bd8
fa6a2b98 8064f4de 8115ef08 810fa568 00000000
fa6a2ba8 804eca36 8115ef08 8192eed8 806ce014
fa6a2bb8 80647111 811f6bc8 8192eed8 00000000
fa6a2bc8 ffffff00 ffffffff ffaacf08 8192eed8

Following is the stack right after the return from the function CtiIoControl
by single stepping, the control is now in some part of Os’s kernel code

ChildEBP RetAddr Args to Child
fa6a2b70 80647111 8192efac 8192efd0 8115efc0 nt!IopfCallDriver+0x31 (FPO:
[0,0,1])
fa6a2b94 8064f4de 8115ef08 810fa568 00000000 nt!IovCallDriver+0x9e (FPO:
[Non-Fpo])
fa6a2ba4 804eca36 8115ef08 8192eed8 806ce014 nt!ViDriverDispatchGeneric+0x27
(FPO: [2,0,3])
fa6a2bb4 80647111 811f6bc8 8192eed8 00000000 nt!IopfCallDriver+0x31 (FPO:
[0,0,1])
fa6a2bd8 fc95b8ab 811f6bc8 8192eed8 8192efd8 nt!IovCallDriver+0x9e (FPO:
[Non-Fpo])
fa6a2bec fc95baa2 811f6b10 0092eed8 811f6b10
serenum!Serenum_DispatchPassThrough+0x63 (FPO: [Non-Fpo])
fa6a2c10 804eca36 811f6b10 00000000 806ce014 serenum!Serenum_IoCtl+0x70
(FPO: [Non-Fpo])
fa6a2c20 80647111 ffa52230 806cde40 8192eed8 nt!IopfCallDriver+0x31 (FPO:
[0,0,1])
fa6a2c44 8058b076 8192efd8 8122b6f0 8192eed8 nt!IovCallDriver+0x9e (FPO:
[Non-Fpo])
fa6a2c58 8058bc62 811f6b10 8192eed8 8122b6f0
nt!IopSynchronousServiceTail+0x5e (FPO: [Non-Fpo])
fa6a2d00 805987ec 000007a8 0000079c 00000000 nt!IopXxxControlFile+0x5ec
fa6a2d34 804da140 000007a8 0000079c 00000000 nt!NtDeviceIoControlFile+0x28
(FPO: [Non-Fpo])
fa6a2d34 7ffe0304 000007a8 0000079c 00000000 nt!KiSystemService+0xc4 (FPO:
[0,0] TrapFrame @ fa6a2d64)
0012fccc 77f75b1d 77e755d6 000007a8 0000079c
SharedUserData!SystemCallStub+0x4 (FPO: [0,0,0])
0012fcd0 77e755d6 000007a8 0000079c 00000000 ntdll!ZwDeviceIoControlFile+0xc
(FPO: [10,0,0])
0012fd30 004022a5 000007a8 001b0040 00000000 kernel32!DeviceIoControl+0x78
(FPO: [Non-Fpo])
WARNING: Stack unwind information not available. Following frames may be
wrong.
0012fe2c 77d43b37 00401bf0 000300a2 00000111 MTTTY+0x22a5
0012fe94 77d43d91 00000000 00401bf0 000300a2
USER32!UserCallWinProcCheckWow+0x150 (FPO: [Non-Fpo])
0012fef4 77d4438c 0012ff1c 00000001 00401a32
USER32!DispatchMessageWorker+0x306 (FPO: [Non-Fpo])
0012ff00 00401a32 0012ff1c 77f517e6 0012ffc0 USER32!DispatchMessageA+0xb
(FPO: [1,0,0])

Alas, the function call of my driver vanished from the stack. If I do a dd
around the last frame of previous stack I find that EBP is now 0 which makes
sense why it is vanished.

kd> dd fa6a2b58
fa6a2b58 8115ef00 fa6a2b94 00000000 804eca36
fa6a2b68 00000008 00000206 806ce014 80647111
fa6a2b78 8192efac 8192efd0 8115efc0 ffffff00
fa6a2b88 ffffffff ffa35220 8192eed8 fa6a2bd8
fa6a2b98 8064f4de 8115ef08 810fa568 00000000
fa6a2ba8 804eca36 8115ef08 8192eed8 806ce014
fa6a2bb8 80647111 811f6bc8 8192eed8 00000000
fa6a2bc8 ffffff00 ffffffff ffaacf08 8192eed8

If I step through more it’ll bugcheck. At this point I’d like to find the
frame whcih was:
fa6a2b60 804eca36 ffbb1040 8192eed8 806ce014 ctibhnp!CtiIoControl+0x1926
(CONV: stdcall) [c:\projects\bhn\driver\port\1000\ioctl.c @ 2148]

I have ‘Stacking the Deck’ (The NT Insider, Nov-Dec, 2002) open in front of
me, yet if you could give me some quick hints that will be great.

Thanks,
Hablu

Well, it would be trivial if your CurrentStackLocation pointed to your
driver’s SP. Then you could use “dt IO_STACK_LOCATION” on that address.

So, using dt, I was able to establish that the IRP is 0x70 bytes, and each
stack location is 0x24. So, I think your drivers SP would be at
8193aed8+70+24+24. Try “dt IO_STACK_LOCATION” on that address.

Let me know if this works. I hope my math isn’t off…

Marybeth Croci
Stratus Technologies

-----Original Message-----
From: xxxxx@yahoo.ca [mailto:xxxxx@yahoo.ca]
Sent: Wednesday, August 06, 2003 12:12 PM
To: Kernel Debugging Interest List
Subject: [windbg] finding IRP detail

Hello,

I was running DC2 from HCT 11.2. I got a bugcheck of IRQL not same before
and after IoCallDriver. The bugcheck came with a different driver. I know
the problem is with my driver and it is most probably with spin locks not
released . From the stack I get the IRP address related to my driver from
IovCallDriver argument. Then I use !irp to get detail info. My driver is
\Driver\CTIBHNPort. I can’t find any way to know the IoControlCode of this
IRP, if I know this I can analyse the related code. Any hint or suggestion
will be greatly appreciated.

Thanks,
Hablu

You are currently subscribed to windbg as: xxxxx@stratus.com
To unsubscribe send a blank email to xxxxx@lists.osr.com

OSR_Community_User · August 7, 2003, 3:00pm

I just responded similarly.

-----Original Message-----
From: Graham, Simon [mailto:xxxxx@stratus.com]
Sent: Thursday, August 07, 2003 2:45 PM
To: Kernel Debugging Interest List
Subject: [windbg] RE: finding IRP detail

Unless I’m missing something, driver verifier is reporting that you exited
your dispatch routine CtiIoControl with IRQL different from when you
entered; so this is a problem in your routine that is, presumably, raising
IRQL and neglecting to lower it again.

/simgr

PS: Marybeths arithmetic was, as always, dead on, but in fact is not
required as the !irp command shows you the parameters in each stack location

it dumps the parameters as 4 longwords, you can then look at ntddk.h to
determine the values relevant to the specific request - in the case of an
IOCTL, the third longword shows the IoControlCode value.

-----Original Message-----
From: xxxxx@yahoo.ca [mailto:xxxxx@yahoo.ca]
Sent: Thursday, August 07, 2003 2:35 PM
To: Kernel Debugging Interest List
Subject: [windbg] RE: finding IRP detail

This is excellent! Your math is absolutely correct.
But the IoControlCode is 0 which is wrong, IRP is completed so its field got
modified, I found it later by experiment.
I have been able to narrow down the analysis from the Information field of
the irp and detected the IOCTL and able to reproduce the problem. Now, I’d
like to back trace the stack. Following is the stack right before before
IoCompleteRequest:

ChildEBP RetAddr Args to Child
fa6a2b60 804eca36 ffbb1040 8192eed8 806ce014 ctibhnp!CtiIoControl+0x1926
(CONV: stdcall) [c:\projects\bhn\driver\port\1000\ioctl.c @ 2148]
fa6a2b70 80647111 8192efac 8192efd0 8115efc0 nt!IopfCallDriver+0x31 (FPO:
[0,0,1])
fa6a2b94 8064f4de 8115ef08 810fa568 00000000 nt!IovCallDriver+0x9e (FPO:
[Non-Fpo])
fa6a2ba4 804eca36 8115ef08 8192eed8 806ce014 nt!ViDriverDispatchGeneric+0x27
(FPO: [2,0,3])
fa6a2bb4 80647111 811f6bc8 8192eed8 00000000 nt!IopfCallDriver+0x31 (FPO:
[0,0,1])
fa6a2bd8 fc95b8ab 811f6bc8 8192eed8 8192efd8 nt!IovCallDriver+0x9e (FPO:
[Non-Fpo])
fa6a2bec fc95baa2 811f6b10 0092eed8 811f6b10
serenum!Serenum_DispatchPassThrough+0x63 (FPO: [Non-Fpo])
fa6a2c10 804eca36 811f6b10 00000000 806ce014 serenum!Serenum_IoCtl+0x70
(FPO: [Non-Fpo])
fa6a2c20 80647111 ffa52230 806cde40 8192eed8 nt!IopfCallDriver+0x31 (FPO:
[0,0,1])
fa6a2c44 8058b076 8192efd8 8122b6f0 8192eed8 nt!IovCallDriver+0x9e (FPO:
[Non-Fpo])
fa6a2c58 8058bc62 811f6b10 8192eed8 8122b6f0
nt!IopSynchronousServiceTail+0x5e (FPO: [Non-Fpo])
fa6a2d00 805987ec 000007a8 0000079c 00000000 nt!IopXxxControlFile+0x5ec
fa6a2d34 804da140 000007a8 0000079c 00000000 nt!NtDeviceIoControlFile+0x28
(FPO: [Non-Fpo])
fa6a2d34 7ffe0304 000007a8 0000079c 00000000 nt!KiSystemService+0xc4 (FPO:
[0,0] TrapFrame @ fa6a2d64)
0012fccc 77f75b1d 77e755d6 000007a8 0000079c
SharedUserData!SystemCallStub+0x4 (FPO: [0,0,0])
0012fcd0 77e755d6 000007a8 0000079c 00000000 ntdll!ZwDeviceIoControlFile+0xc
(FPO: [10,0,0])
0012fd30 004022a5 000007a8 001b0040 00000000 kernel32!DeviceIoControl+0x78
(FPO: [Non-Fpo])
WARNING: Stack unwind information not available. Following frames may be
wrong.
0012fe2c 77d43b37 00401bf0 000300a2 00000111 MTTTY+0x22a5
0012fe94 77d43d91 00000000 00401bf0 000300a2
USER32!UserCallWinProcCheckWow+0x150 (FPO: [Non-Fpo])
0012fef4 77d4438c 0012ff1c 00000001 00401a32
USER32!DispatchMessageWorker+0x306 (FPO: [Non-Fpo])

Following is the call chain for the last frame:

kd> dd fa6a2b58
fa6a2b58 8192ef90 ffbb10f8 fa6a2b94 804eca36
fa6a2b68 ffbb1040 8192eed8 806ce014 80647111
fa6a2b78 8192efac 8192efd0 8115efc0 ffffff00
fa6a2b88 ffffffff ffa35220 8192eed8 fa6a2bd8
fa6a2b98 8064f4de 8115ef08 810fa568 00000000
fa6a2ba8 804eca36 8115ef08 8192eed8 806ce014
fa6a2bb8 80647111 811f6bc8 8192eed8 00000000
fa6a2bc8 ffffff00 ffffffff ffaacf08 8192eed8

Following is the stack right after the return from the function CtiIoControl
by single stepping, the control is now in some part of Os’s kernel code

ChildEBP RetAddr Args to Child
fa6a2b70 80647111 8192efac 8192efd0 8115efc0 nt!IopfCallDriver+0x31 (FPO:
[0,0,1])
fa6a2b94 8064f4de 8115ef08 810fa568 00000000 nt!IovCallDriver+0x9e (FPO:
[Non-Fpo])
fa6a2ba4 804eca36 8115ef08 8192eed8 806ce014 nt!ViDriverDispatchGeneric+0x27
(FPO: [2,0,3])
fa6a2bb4 80647111 811f6bc8 8192eed8 00000000 nt!IopfCallDriver+0x31 (FPO:
[0,0,1])
fa6a2bd8 fc95b8ab 811f6bc8 8192eed8 8192efd8 nt!IovCallDriver+0x9e (FPO:
[Non-Fpo])
fa6a2bec fc95baa2 811f6b10 0092eed8 811f6b10
serenum!Serenum_DispatchPassThrough+0x63 (FPO: [Non-Fpo])
fa6a2c10 804eca36 811f6b10 00000000 806ce014 serenum!Serenum_IoCtl+0x70
(FPO: [Non-Fpo])
fa6a2c20 80647111 ffa52230 806cde40 8192eed8 nt!IopfCallDriver+0x31 (FPO:
[0,0,1])
fa6a2c44 8058b076 8192efd8 8122b6f0 8192eed8 nt!IovCallDriver+0x9e (FPO:
[Non-Fpo])
fa6a2c58 8058bc62 811f6b10 8192eed8 8122b6f0
nt!IopSynchronousServiceTail+0x5e (FPO: [Non-Fpo])
fa6a2d00 805987ec 000007a8 0000079c 00000000 nt!IopXxxControlFile+0x5ec
fa6a2d34 804da140 000007a8 0000079c 00000000 nt!NtDeviceIoControlFile+0x28
(FPO: [Non-Fpo])
fa6a2d34 7ffe0304 000007a8 0000079c 00000000 nt!KiSystemService+0xc4 (FPO:
[0,0] TrapFrame @ fa6a2d64)
0012fccc 77f75b1d 77e755d6 000007a8 0000079c
SharedUserData!SystemCallStub+0x4 (FPO: [0,0,0])
0012fcd0 77e755d6 000007a8 0000079c 00000000 ntdll!ZwDeviceIoControlFile+0xc
(FPO: [10,0,0])
0012fd30 004022a5 000007a8 001b0040 00000000 kernel32!DeviceIoControl+0x78
(FPO: [Non-Fpo])
WARNING: Stack unwind information not available. Following frames may be
wrong.
0012fe2c 77d43b37 00401bf0 000300a2 00000111 MTTTY+0x22a5
0012fe94 77d43d91 00000000 00401bf0 000300a2
USER32!UserCallWinProcCheckWow+0x150 (FPO: [Non-Fpo])
0012fef4 77d4438c 0012ff1c 00000001 00401a32
USER32!DispatchMessageWorker+0x306 (FPO: [Non-Fpo])
0012ff00 00401a32 0012ff1c 77f517e6 0012ffc0 USER32!DispatchMessageA+0xb
(FPO: [1,0,0])

Alas, the function call of my driver vanished from the stack. If I do a dd
around the last frame of previous stack I find that EBP is now 0 which makes
sense why it is vanished.

kd> dd fa6a2b58
fa6a2b58 8115ef00 fa6a2b94 00000000 804eca36
fa6a2b68 00000008 00000206 806ce014 80647111
fa6a2b78 8192efac 8192efd0 8115efc0 ffffff00
fa6a2b88 ffffffff ffa35220 8192eed8 fa6a2bd8
fa6a2b98 8064f4de 8115ef08 810fa568 00000000
fa6a2ba8 804eca36 8115ef08 8192eed8 806ce014
fa6a2bb8 80647111 811f6bc8 8192eed8 00000000
fa6a2bc8 ffffff00 ffffffff ffaacf08 8192eed8

If I step through more it’ll bugcheck. At this point I’d like to find the
frame whcih was:
fa6a2b60 804eca36 ffbb1040 8192eed8 806ce014 ctibhnp!CtiIoControl+0x1926
(CONV: stdcall) [c:\projects\bhn\driver\port\1000\ioctl.c @ 2148]

I have ‘Stacking the Deck’ (The NT Insider, Nov-Dec, 2002) open in front of
me, yet if you could give me some quick hints that will be great.

Thanks,
Hablu

Well, it would be trivial if your CurrentStackLocation pointed to your
driver’s SP. Then you could use “dt IO_STACK_LOCATION” on that address.

So, using dt, I was able to establish that the IRP is 0x70 bytes, and each
stack location is 0x24. So, I think your drivers SP would be at
8193aed8+70+24+24. Try “dt IO_STACK_LOCATION” on that address.

Let me know if this works. I hope my math isn’t off…

Marybeth Croci
Stratus Technologies

-----Original Message-----
From: xxxxx@yahoo.ca [mailto:xxxxx@yahoo.ca]
Sent: Wednesday, August 06, 2003 12:12 PM
To: Kernel Debugging Interest List
Subject: [windbg] finding IRP detail

Hello,

I was running DC2 from HCT 11.2. I got a bugcheck of IRQL not same before
and after IoCallDriver. The bugcheck came with a different driver. I know
the problem is with my driver and it is most probably with spin locks not
released . From the stack I get the IRP address related to my driver from
IovCallDriver argument. Then I use !irp to get detail info. My driver is
\Driver\CTIBHNPort. I can’t find any way to know the IoControlCode of this
IRP, if I know this I can analyse the related code. Any hint or suggestion
will be greatly appreciated.

Thanks,
Hablu

You are currently subscribed to windbg as: xxxxx@stratus.com
To unsubscribe send a blank email to xxxxx@lists.osr.com

Hakim · August 7, 2003, 3:25pm

Earlier I mentioned the reason is being not releasing the spin lock. When serenum passes the IRP to my driver it was in PASSIVE_LEVEL, now my driver during processing this IRP acquires a spin lock which raises the IRQL to DISPATCH_LEVEL and completing the IRP(without releasing the lock) takes control to driver verifier whcih finds the mismatch of IRQL. I know all this and I’m reproducing this to make a better stack that’ll show which of my routine at what place executed before this BSOD. For example the following stack after BSOD does not show that my driver is the culprit:

kd> !analyze -v
*******************************************************************************
* *
* Bugcheck Analysis *
* *
*******************************************************************************

DRIVER_VERIFIER_IOMANAGER_VIOLATION (c9)
The IO manager has caught a misbehaving driver.
Arguments:
Arg1: 00000005, Irql not equal across call to the driver dispatch routine
Arg2: ffbb1040, the device object associated with the offending driver
Arg3: 00000000, the Irql before the call
Arg4: 00000002, the Irql after the call

Debugging Details:

DRIVER_VERIFIER_IO_VIOLATION_TYPE: 5

PREVIOUS_IRQL: 0

CURRENT_IRQL: 2

DEVICE_OBJECT: ffbb1040

DRIVER_OBJECT: 8121aa40

IMAGE_NAME: serenum.sys

DEBUG_FLR_IMAGE_TIMESTAMP: 3b7d8385

MODULE_NAME: serenum

FAULTING_MODULE: 00000000

DEFAULT_BUCKET_ID: DRIVER_FAULT

BUGCHECK_STR: 0xC9

LAST_CONTROL_TRANSFER: from 805258ca to 805103fa

STACK_TEXT:
fa6a2724 805258ca 00000003 fa6a2a54 00000005 nt!RtlpBreakWithStatusInstruction
fa6a2770 80526160 00000003 ffbb1040 806ce014 nt!KiBugCheckDebugBreak+0x19
fa6a2b3c 805266db 000000c9 00000005 ffbb1040 nt!KeBugCheck2+0x46d
fa6a2b5c 80647152 000000c9 00000005 ffbb1040 nt!KeBugCheckEx+0x19
fa6a2b94 8064f4de 8115ef08 810fa568 00000000 nt!IovCallDriver+0xdf
fa6a2ba4 804eca36 8115ef08 8192eed8 806ce014 nt!ViDriverDispatchGeneric+0x27
fa6a2bb4 80647111 811f6bc8 8192eed8 00000000 nt!IopfCallDriver+0x31
fa6a2bd8 fc95b8ab 811f6bc8 8192eed8 8192efd8 nt!IovCallDriver+0x9e
fa6a2bec fc95baa2 811f6b10 0092eed8 811f6b10 serenum!Serenum_DispatchPassThrough+0x63
fa6a2c10 804eca36 811f6b10 00000000 806ce014 serenum!Serenum_IoCtl+0x70
fa6a2c20 80647111 ffa52230 806cde40 8192eed8 nt!IopfCallDriver+0x31
fa6a2c44 8058b076 8192efd8 8122b6f0 8192eed8 nt!IovCallDriver+0x9e
fa6a2c58 8058bc62 811f6b10 8192eed8 8122b6f0 nt!IopSynchronousServiceTail+0x5e
fa6a2d00 805987ec 000007a8 0000079c 00000000 nt!IopXxxControlFile+0x5ec
fa6a2d34 804da140 000007a8 0000079c 00000000 nt!NtDeviceIoControlFile+0x28
fa6a2d34 7ffe0304 000007a8 0000079c 00000000 nt!KiSystemService+0xc4
0012fccc 77f75b1d 77e755d6 000007a8 0000079c SharedUserData!SystemCallStub+0x4
0012fcd0 77e755d6 000007a8 0000079c 00000000 ntdll!ZwDeviceIoControlFile+0xc
0012fd30 004022a5 000007a8 001b0040 00000000 kernel32!DeviceIoControl+0x78
WARNING: Stack unwind information not available. Following frames may be wrong.
0012fe2c 77d43b37 00401bf0 000300a2 00000111 MTTTY+0x22a5
0012fe94 77d43d91 00000000 00401bf0 000300a2 USER32!UserCallWinProcCheckWow+0x150
0012fef4 77d4438c 0012ff1c 00000001 00401a32 USER32!DispatchMessageWorker+0x306
0012ff00 00401a32 0012ff1c 77f517e6 0012ffc0 USER32!DispatchMessageA+0xb
0012ff34 00406f8e 00400000 00000000 00142315 MTTTY+0x1a32
00000105 00000000 00000000 00000000 00000000 MTTTY+0x6f8e

FOLLOWUP_IP:
serenum!Serenum_DispatchPassThrough+63
fc95b8ab 385d0f cmp [ebp+0xf],bl

FOLLOWUP_NAME: MachineOwner

SYMBOL_NAME: serenum!Serenum_DispatchPassThrough+63

STACK_COMMAND: kb

BUCKET_ID: 0xC9_serenum!Serenum_DispatchPassThrough+63

Followup: MachineOwner

This is a different issue than the original post. I have the feeling that it is possible to find which routine of my driver at what place executed last. Could you give me some hints on how to proceed?

Thanks,
Hablu

The stack frame of your routine “vanished” from the stack because you
returned. I’m not sure what you were hoping to find in the stale stack
frame after returning. If you want to see the values of local variables, do
it while your routine is still running.

Remember, the bug check that you got is indicating that the IRQL changed
during the call to your driver. If this is reproducible and you can single
step through it, you certainly should be able to determined what caused the
IRQL change. Knowing the before and after values of the IRQL might suggest
some hypothesis. What were they?

Marybeth Croci

OSR_Community_User · August 7, 2003, 3:32pm

I understand. If it’s reproducible and you can single step it, you should
be able to find the code path that took, but failed to release, the spinlock
(if that’s the cause) by observing what path your code takes, rather than
try to look at the stale stack frame after you’ve already returned.

Marybeth Croci

-----Original Message-----
From: xxxxx@yahoo.ca [mailto:xxxxx@yahoo.ca]
Sent: Thursday, August 07, 2003 3:25 PM
To: Kernel Debugging Interest List
Subject: [windbg] RE: finding IRP detail

Earlier I mentioned the reason is being not releasing the spin lock. When
serenum passes the IRP to my driver it was in PASSIVE_LEVEL, now my driver
during processing this IRP acquires a spin lock which raises the IRQL to
DISPATCH_LEVEL and completing the IRP(without releasing the lock) takes
control to driver verifier whcih finds the mismatch of IRQL. I know all this
and I’m reproducing this to make a better stack that’ll show which of my
routine at what place executed before this BSOD. For example the following
stack after BSOD does not show that my driver is the culprit:

kd> !analyze -v
****************************************************************************
***
*
*
* Bugcheck Analysis
*
*
*
****************************************************************************
***

DRIVER_VERIFIER_IOMANAGER_VIOLATION (c9)
The IO manager has caught a misbehaving driver.
Arguments:
Arg1: 00000005, Irql not equal across call to the driver dispatch routine
Arg2: ffbb1040, the device object associated with the offending driver
Arg3: 00000000, the Irql before the call
Arg4: 00000002, the Irql after the call

Debugging Details:

DRIVER_VERIFIER_IO_VIOLATION_TYPE: 5

PREVIOUS_IRQL: 0

CURRENT_IRQL: 2

DEVICE_OBJECT: ffbb1040

DRIVER_OBJECT: 8121aa40

IMAGE_NAME: serenum.sys

DEBUG_FLR_IMAGE_TIMESTAMP: 3b7d8385

MODULE_NAME: serenum

FAULTING_MODULE: 00000000

DEFAULT_BUCKET_ID: DRIVER_FAULT

BUGCHECK_STR: 0xC9

LAST_CONTROL_TRANSFER: from 805258ca to 805103fa

STACK_TEXT:
fa6a2724 805258ca 00000003 fa6a2a54 00000005
nt!RtlpBreakWithStatusInstruction
fa6a2770 80526160 00000003 ffbb1040 806ce014 nt!KiBugCheckDebugBreak+0x19
fa6a2b3c 805266db 000000c9 00000005 ffbb1040 nt!KeBugCheck2+0x46d
fa6a2b5c 80647152 000000c9 00000005 ffbb1040 nt!KeBugCheckEx+0x19
fa6a2b94 8064f4de 8115ef08 810fa568 00000000 nt!IovCallDriver+0xdf
fa6a2ba4 804eca36 8115ef08 8192eed8 806ce014 nt!ViDriverDispatchGeneric+0x27
fa6a2bb4 80647111 811f6bc8 8192eed8 00000000 nt!IopfCallDriver+0x31
fa6a2bd8 fc95b8ab 811f6bc8 8192eed8 8192efd8 nt!IovCallDriver+0x9e
fa6a2bec fc95baa2 811f6b10 0092eed8 811f6b10
serenum!Serenum_DispatchPassThrough+0x63
fa6a2c10 804eca36 811f6b10 00000000 806ce014 serenum!Serenum_IoCtl+0x70
fa6a2c20 80647111 ffa52230 806cde40 8192eed8 nt!IopfCallDriver+0x31
fa6a2c44 8058b076 8192efd8 8122b6f0 8192eed8 nt!IovCallDriver+0x9e
fa6a2c58 8058bc62 811f6b10 8192eed8 8122b6f0
nt!IopSynchronousServiceTail+0x5e
fa6a2d00 805987ec 000007a8 0000079c 00000000 nt!IopXxxControlFile+0x5ec
fa6a2d34 804da140 000007a8 0000079c 00000000 nt!NtDeviceIoControlFile+0x28
fa6a2d34 7ffe0304 000007a8 0000079c 00000000 nt!KiSystemService+0xc4
0012fccc 77f75b1d 77e755d6 000007a8 0000079c
SharedUserData!SystemCallStub+0x4
0012fcd0 77e755d6 000007a8 0000079c 00000000 ntdll!ZwDeviceIoControlFile+0xc
0012fd30 004022a5 000007a8 001b0040 00000000 kernel32!DeviceIoControl+0x78
WARNING: Stack unwind information not available. Following frames may be
wrong.
0012fe2c 77d43b37 00401bf0 000300a2 00000111 MTTTY+0x22a5
0012fe94 77d43d91 00000000 00401bf0 000300a2
USER32!UserCallWinProcCheckWow+0x150
0012fef4 77d4438c 0012ff1c 00000001 00401a32
USER32!DispatchMessageWorker+0x306
0012ff00 00401a32 0012ff1c 77f517e6 0012ffc0 USER32!DispatchMessageA+0xb
0012ff34 00406f8e 00400000 00000000 00142315 MTTTY+0x1a32
00000105 00000000 00000000 00000000 00000000 MTTTY+0x6f8e

FOLLOWUP_IP:
serenum!Serenum_DispatchPassThrough+63
fc95b8ab 385d0f cmp [ebp+0xf],bl

FOLLOWUP_NAME: MachineOwner

SYMBOL_NAME: serenum!Serenum_DispatchPassThrough+63

STACK_COMMAND: kb

BUCKET_ID: 0xC9_serenum!Serenum_DispatchPassThrough+63

Followup: MachineOwner

This is a different issue than the original post. I have the feeling that it
is possible to find which routine of my driver at what place executed last.
Could you give me some hints on how to proceed?

Thanks,
Hablu

The stack frame of your routine “vanished” from the stack because you
returned. I’m not sure what you were hoping to find in the stale stack
frame after returning. If you want to see the values of local variables,
do
it while your routine is still running.

Remember, the bug check that you got is indicating that the IRQL changed
during the call to your driver. If this is reproducible and you can
single
step through it, you certainly should be able to determined what caused
the
IRQL change. Knowing the before and after values of the IRQL might
suggest
some hypothesis. What were they?

Marybeth Croci

You are currently subscribed to windbg as: xxxxx@stratus.com
To unsubscribe send a blank email to xxxxx@lists.osr.com

OSR_Community_User · August 7, 2003, 3:52pm

Actually, I think this stack DOES show it’s your driver that is the culprit
– SERENUM called into your driver at PASSIVE and this trace which is AFTER
your dispatch routine returns is complaining because you are still at
DISPATCH.

If the bugcheck were happening inside your call to complete the IRP then I
think that would show up on the stack trace

/simgr

-----Original Message-----
From: xxxxx@yahoo.ca [mailto:xxxxx@yahoo.ca]
Sent: Thursday, August 07, 2003 3:25 PM
To: Kernel Debugging Interest List
Subject: [windbg] RE: finding IRP detail

Earlier I mentioned the reason is being not releasing the spin lock. When
serenum passes the IRP to my driver it was in PASSIVE_LEVEL, now my driver
during processing this IRP acquires a spin lock which raises the IRQL to
DISPATCH_LEVEL and completing the IRP(without releasing the lock) takes
control to driver verifier whcih finds the mismatch of IRQL. I know all this
and I’m reproducing this to make a better stack that’ll show which of my
routine at what place executed before this BSOD. For example the following
stack after BSOD does not show that my driver is the culprit:

kd> !analyze -v
****************************************************************************
***
*
*
* Bugcheck Analysis
*
*
*
****************************************************************************
***

DRIVER_VERIFIER_IOMANAGER_VIOLATION (c9)
The IO manager has caught a misbehaving driver.
Arguments:
Arg1: 00000005, Irql not equal across call to the driver dispatch routine
Arg2: ffbb1040, the device object associated with the offending driver
Arg3: 00000000, the Irql before the call
Arg4: 00000002, the Irql after the call

Debugging Details:

DRIVER_VERIFIER_IO_VIOLATION_TYPE: 5

PREVIOUS_IRQL: 0

CURRENT_IRQL: 2

DEVICE_OBJECT: ffbb1040

DRIVER_OBJECT: 8121aa40

IMAGE_NAME: serenum.sys

DEBUG_FLR_IMAGE_TIMESTAMP: 3b7d8385

MODULE_NAME: serenum

FAULTING_MODULE: 00000000

DEFAULT_BUCKET_ID: DRIVER_FAULT

BUGCHECK_STR: 0xC9

LAST_CONTROL_TRANSFER: from 805258ca to 805103fa

STACK_TEXT:
fa6a2724 805258ca 00000003 fa6a2a54 00000005
nt!RtlpBreakWithStatusInstruction
fa6a2770 80526160 00000003 ffbb1040 806ce014 nt!KiBugCheckDebugBreak+0x19
fa6a2b3c 805266db 000000c9 00000005 ffbb1040 nt!KeBugCheck2+0x46d
fa6a2b5c 80647152 000000c9 00000005 ffbb1040 nt!KeBugCheckEx+0x19
fa6a2b94 8064f4de 8115ef08 810fa568 00000000 nt!IovCallDriver+0xdf
fa6a2ba4 804eca36 8115ef08 8192eed8 806ce014 nt!ViDriverDispatchGeneric+0x27
fa6a2bb4 80647111 811f6bc8 8192eed8 00000000 nt!IopfCallDriver+0x31
fa6a2bd8 fc95b8ab 811f6bc8 8192eed8 8192efd8 nt!IovCallDriver+0x9e
fa6a2bec fc95baa2 811f6b10 0092eed8 811f6b10
serenum!Serenum_DispatchPassThrough+0x63
fa6a2c10 804eca36 811f6b10 00000000 806ce014 serenum!Serenum_IoCtl+0x70
fa6a2c20 80647111 ffa52230 806cde40 8192eed8 nt!IopfCallDriver+0x31
fa6a2c44 8058b076 8192efd8 8122b6f0 8192eed8 nt!IovCallDriver+0x9e
fa6a2c58 8058bc62 811f6b10 8192eed8 8122b6f0
nt!IopSynchronousServiceTail+0x5e
fa6a2d00 805987ec 000007a8 0000079c 00000000 nt!IopXxxControlFile+0x5ec
fa6a2d34 804da140 000007a8 0000079c 00000000 nt!NtDeviceIoControlFile+0x28
fa6a2d34 7ffe0304 000007a8 0000079c 00000000 nt!KiSystemService+0xc4
0012fccc 77f75b1d 77e755d6 000007a8 0000079c
SharedUserData!SystemCallStub+0x4
0012fcd0 77e755d6 000007a8 0000079c 00000000 ntdll!ZwDeviceIoControlFile+0xc
0012fd30 004022a5 000007a8 001b0040 00000000 kernel32!DeviceIoControl+0x78
WARNING: Stack unwind information not available. Following frames may be
wrong.
0012fe2c 77d43b37 00401bf0 000300a2 00000111 MTTTY+0x22a5
0012fe94 77d43d91 00000000 00401bf0 000300a2
USER32!UserCallWinProcCheckWow+0x150
0012fef4 77d4438c 0012ff1c 00000001 00401a32
USER32!DispatchMessageWorker+0x306
0012ff00 00401a32 0012ff1c 77f517e6 0012ffc0 USER32!DispatchMessageA+0xb
0012ff34 00406f8e 00400000 00000000 00142315 MTTTY+0x1a32
00000105 00000000 00000000 00000000 00000000 MTTTY+0x6f8e

FOLLOWUP_IP:
serenum!Serenum_DispatchPassThrough+63
fc95b8ab 385d0f cmp [ebp+0xf],bl

FOLLOWUP_NAME: MachineOwner

SYMBOL_NAME: serenum!Serenum_DispatchPassThrough+63

STACK_COMMAND: kb

BUCKET_ID: 0xC9_serenum!Serenum_DispatchPassThrough+63

Followup: MachineOwner

This is a different issue than the original post. I have the feeling that it
is possible to find which routine of my driver at what place executed last.
Could you give me some hints on how to proceed?

Thanks,
Hablu

The stack frame of your routine “vanished” from the stack because you
returned. I’m not sure what you were hoping to find in the stale stack
frame after returning. If you want to see the values of local variables,
do
it while your routine is still running.

Remember, the bug check that you got is indicating that the IRQL changed
during the call to your driver. If this is reproducible and you can
single
step through it, you certainly should be able to determined what caused
the
IRQL change. Knowing the before and after values of the IRQL might
suggest
some hypothesis. What were they?

Marybeth Croci

You are currently subscribed to windbg as: xxxxx@stratus.com
To unsubscribe send a blank email to xxxxx@lists.osr.com

Hakim · August 7, 2003, 3:58pm

I know where I’m not releasing the lock (purposefully). I’m doing this to gain debugging knowledge, thanks to you all for helping me significantly in your busy time.

Stepping through the code is only possible because I’m doing it in a controlled environment. In real life, all I’ll get is memory dump from customer site and going to customer site for live debugging won’t be possible almost always. So, after loading the dump I’ll get the same sort of stack by !analyze -v and that does not show my driver as the culprit. In this context how the analysis should be started? My goal is to find what part of my routine executed last, then I’ll know which IOCTL to look after.

TIA,
Hablu

I understand. If it’s reproducible and you can single step it, you should
be able to find the code path that took, but failed to release, the spinlock
(if that’s the cause) by observing what path your code takes, rather than
try to look at the stale stack frame after you’ve already returned.

Marybeth Croci

-----Original Message-----
From: xxxxx@yahoo.ca [mailto:xxxxx@yahoo.ca]
Sent: Thursday, August 07, 2003 3:25 PM
To: Kernel Debugging Interest List
Subject: [windbg] RE: finding IRP detail

Earlier I mentioned the reason is being not releasing the spin lock. When
serenum passes the IRP to my driver it was in PASSIVE_LEVEL, now my driver
during processing this IRP acquires a spin lock which raises the IRQL to
DISPATCH_LEVEL and completing the IRP(without releasing the lock) takes
control to driver verifier whcih finds the mismatch of IRQL. I know all this
and I’m reproducing this to make a better stack that’ll show which of my
routine at what place executed before this BSOD. For example the following
stack after BSOD does not show that my driver is the culprit:

kd> !analyze -v
****************************************************************************
***
*
*
* Bugcheck Analysis
*
*
*
****************************************************************************
***

DRIVER_VERIFIER_IOMANAGER_VIOLATION (c9)
The IO manager has caught a misbehaving driver.
Arguments:
Arg1: 00000005, Irql not equal across call to the driver dispatch routine
Arg2: ffbb1040, the device object associated with the offending driver
Arg3: 00000000, the Irql before the call
Arg4: 00000002, the Irql after the call

Debugging Details:

DRIVER_VERIFIER_IO_VIOLATION_TYPE: 5

PREVIOUS_IRQL: 0

CURRENT_IRQL: 2

DEVICE_OBJECT: ffbb1040

DRIVER_OBJECT: 8121aa40

IMAGE_NAME: serenum.sys

DEBUG_FLR_IMAGE_TIMESTAMP: 3b7d8385

MODULE_NAME: serenum

FAULTING_MODULE: 00000000

DEFAULT_BUCKET_ID: DRIVER_FAULT

BUGCHECK_STR: 0xC9

LAST_CONTROL_TRANSFER: from 805258ca to 805103fa

STACK_TEXT:
fa6a2724 805258ca 00000003 fa6a2a54 00000005
nt!RtlpBreakWithStatusInstruction
fa6a2770 80526160 00000003 ffbb1040 806ce014 nt!KiBugCheckDebugBreak+0x19
fa6a2b3c 805266db 000000c9 00000005 ffbb1040 nt!KeBugCheck2+0x46d
fa6a2b5c 80647152 000000c9 00000005 ffbb1040 nt!KeBugCheckEx+0x19
fa6a2b94 8064f4de 8115ef08 810fa568 00000000 nt!IovCallDriver+0xdf
fa6a2ba4 804eca36 8115ef08 8192eed8 806ce014 nt!ViDriverDispatchGeneric+0x27
fa6a2bb4 80647111 811f6bc8 8192eed8 00000000 nt!IopfCallDriver+0x31
fa6a2bd8 fc95b8ab 811f6bc8 8192eed8 8192efd8 nt!IovCallDriver+0x9e
fa6a2bec fc95baa2 811f6b10 0092eed8 811f6b10
serenum!Serenum_DispatchPassThrough+0x63
fa6a2c10 804eca36 811f6b10 00000000 806ce014 serenum!Serenum_IoCtl+0x70
fa6a2c20 80647111 ffa52230 806cde40 8192eed8 nt!IopfCallDriver+0x31
fa6a2c44 8058b076 8192efd8 8122b6f0 8192eed8 nt!IovCallDriver+0x9e
fa6a2c58 8058bc62 811f6b10 8192eed8 8122b6f0
nt!IopSynchronousServiceTail+0x5e
fa6a2d00 805987ec 000007a8 0000079c 00000000 nt!IopXxxControlFile+0x5ec
fa6a2d34 804da140 000007a8 0000079c 00000000 nt!NtDeviceIoControlFile+0x28
fa6a2d34 7ffe0304 000007a8 0000079c 00000000 nt!KiSystemService+0xc4
0012fccc 77f75b1d 77e755d6 000007a8 0000079c
SharedUserData!SystemCallStub+0x4
0012fcd0 77e755d6 000007a8 0000079c 00000000 ntdll!ZwDeviceIoControlFile+0xc
0012fd30 004022a5 000007a8 001b0040 00000000 kernel32!DeviceIoControl+0x78
WARNING: Stack unwind information not available. Following frames may be
wrong.
0012fe2c 77d43b37 00401bf0 000300a2 00000111 MTTTY+0x22a5
0012fe94 77d43d91 00000000 00401bf0 000300a2
USER32!UserCallWinProcCheckWow+0x150
0012fef4 77d4438c 0012ff1c 00000001 00401a32
USER32!DispatchMessageWorker+0x306
0012ff00 00401a32 0012ff1c 77f517e6 0012ffc0 USER32!DispatchMessageA+0xb
0012ff34 00406f8e 00400000 00000000 00142315 MTTTY+0x1a32
00000105 00000000 00000000 00000000 00000000 MTTTY+0x6f8e

FOLLOWUP_IP:
serenum!Serenum_DispatchPassThrough+63
fc95b8ab 385d0f cmp [ebp+0xf],bl

FOLLOWUP_NAME: MachineOwner

SYMBOL_NAME: serenum!Serenum_DispatchPassThrough+63

STACK_COMMAND: kb

BUCKET_ID: 0xC9_serenum!Serenum_DispatchPassThrough+63

Followup: MachineOwner

This is a different issue than the original post. I have the feeling that it
is possible to find which routine of my driver at what place executed last.
Could you give me some hints on how to proceed?

Thanks,
Hablu

> The stack frame of your routine “vanished” from the stack because you
> returned. I’m not sure what you were hoping to find in the stale stack
> frame after returning. If you want to see the values of local variables,
do
> it while your routine is still running.
>
> Remember, the bug check that you got is indicating that the IRQL changed
> during the call to your driver. If this is reproducible and you can
single
> step through it, you certainly should be able to determined what caused
the
> IRQL change. Knowing the before and after values of the IRQL might
suggest
> some hypothesis. What were they?
>
> Marybeth Croci
>
>

You are currently subscribed to windbg as: xxxxx@stratus.com
To unsubscribe send a blank email to xxxxx@lists.osr.com

OSR_Community_User · August 7, 2003, 4:56pm

Well, it’s a fact of life that, when you crash, the stack trace often
doesn’t point out, or even hint at, the culprit. In the case that you
contrived, in “real life” you wouldn’t even have crashed as conveniently as
you did. You were running Driver Verifier. Most likely your customer will
not be, at least not in production. So, you would have returned w/o
releasing the spinlock and some time later you would have deadlocked. That
would be even harder to root cause. Furthermore, consider the case of
memory corruption. If your driver writes beyond the end of a buffer, you
could corrupt ANYONE’s memory. The crashing code path will bear no
resemblence to the actual culprit and the crash could occur significantly
later than the corruption.

This is why you need to test your code thoroughly, using driver verifier, in
the environment in which it is easy for you to find root cause by
interactively debugging, having DbgPrints available, etc. If you think that
you will need historical information on what your driver has done in order
to debug customer crashes, you might want to consider implementing some sort
of light weight ring buffer to save the last “n” things you have done. This
might help in cases where you crash “after the fact”.

In the future, it would be helpful to give more information on what you are
trying to do when you post a question. I had no idea that you had planted a
bug on purpose to “practise” debugging. I thought that you had hypothesized
that you had failed to release a spinlock and wanted to know which IOCTL had
done it. We could have gotten here a lot faster had I realized that!

Marybeth Croci

-----Original Message-----
From: xxxxx@yahoo.ca [mailto:xxxxx@yahoo.ca]
Sent: Thursday, August 07, 2003 3:58 PM
To: Kernel Debugging Interest List
Subject: [windbg] RE: finding IRP detail

I know where I’m not releasing the lock (purposefully). I’m doing this to
gain debugging knowledge, thanks to you all for helping me significantly in
your busy time.

Stepping through the code is only possible because I’m doing it in a
controlled environment. In real life, all I’ll get is memory dump from
customer site and going to customer site for live debugging won’t be
possible almost always. So, after loading the dump I’ll get the same sort of
stack by !analyze -v and that does not show my driver as the culprit. In
this context how the analysis should be started? My goal is to find what
part of my routine executed last, then I’ll know which IOCTL to look after.

TIA,
Hablu

I understand. If it’s reproducible and you can single step it, you should
be able to find the code path that took, but failed to release, the
spinlock
(if that’s the cause) by observing what path your code takes, rather than
try to look at the stale stack frame after you’ve already returned.

Marybeth Croci

-----Original Message-----
From: xxxxx@yahoo.ca [mailto:xxxxx@yahoo.ca]
Sent: Thursday, August 07, 2003 3:25 PM
To: Kernel Debugging Interest List
Subject: [windbg] RE: finding IRP detail

Earlier I mentioned the reason is being not releasing the spin lock. When
serenum passes the IRP to my driver it was in PASSIVE_LEVEL, now my driver
during processing this IRP acquires a spin lock which raises the IRQL to
DISPATCH_LEVEL and completing the IRP(without releasing the lock) takes
control to driver verifier whcih finds the mismatch of IRQL. I know all
this
and I’m reproducing this to make a better stack that’ll show which of my
routine at what place executed before this BSOD. For example the following
stack after BSOD does not show that my driver is the culprit:

kd> !analyze -v

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

***
*
*
* Bugcheck Analysis
*
*
*

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

***

DRIVER_VERIFIER_IOMANAGER_VIOLATION (c9)
The IO manager has caught a misbehaving driver.
Arguments:
Arg1: 00000005, Irql not equal across call to the driver dispatch routine
Arg2: ffbb1040, the device object associated with the offending driver
Arg3: 00000000, the Irql before the call
Arg4: 00000002, the Irql after the call

Debugging Details:

DRIVER_VERIFIER_IO_VIOLATION_TYPE: 5

PREVIOUS_IRQL: 0

CURRENT_IRQL: 2

DEVICE_OBJECT: ffbb1040

DRIVER_OBJECT: 8121aa40

IMAGE_NAME: serenum.sys

DEBUG_FLR_IMAGE_TIMESTAMP: 3b7d8385

MODULE_NAME: serenum

FAULTING_MODULE: 00000000

DEFAULT_BUCKET_ID: DRIVER_FAULT

BUGCHECK_STR: 0xC9

LAST_CONTROL_TRANSFER: from 805258ca to 805103fa

STACK_TEXT:
fa6a2724 805258ca 00000003 fa6a2a54 00000005
nt!RtlpBreakWithStatusInstruction
fa6a2770 80526160 00000003 ffbb1040 806ce014 nt!KiBugCheckDebugBreak+0x19
fa6a2b3c 805266db 000000c9 00000005 ffbb1040 nt!KeBugCheck2+0x46d
fa6a2b5c 80647152 000000c9 00000005 ffbb1040 nt!KeBugCheckEx+0x19
fa6a2b94 8064f4de 8115ef08 810fa568 00000000 nt!IovCallDriver+0xdf
fa6a2ba4 804eca36 8115ef08 8192eed8 806ce014
nt!ViDriverDispatchGeneric+0x27
fa6a2bb4 80647111 811f6bc8 8192eed8 00000000 nt!IopfCallDriver+0x31
fa6a2bd8 fc95b8ab 811f6bc8 8192eed8 8192efd8 nt!IovCallDriver+0x9e
fa6a2bec fc95baa2 811f6b10 0092eed8 811f6b10
serenum!Serenum_DispatchPassThrough+0x63
fa6a2c10 804eca36 811f6b10 00000000 806ce014 serenum!Serenum_IoCtl+0x70
fa6a2c20 80647111 ffa52230 806cde40 8192eed8 nt!IopfCallDriver+0x31
fa6a2c44 8058b076 8192efd8 8122b6f0 8192eed8 nt!IovCallDriver+0x9e
fa6a2c58 8058bc62 811f6b10 8192eed8 8122b6f0
nt!IopSynchronousServiceTail+0x5e
fa6a2d00 805987ec 000007a8 0000079c 00000000 nt!IopXxxControlFile+0x5ec
fa6a2d34 804da140 000007a8 0000079c 00000000 nt!NtDeviceIoControlFile+0x28
fa6a2d34 7ffe0304 000007a8 0000079c 00000000 nt!KiSystemService+0xc4
0012fccc 77f75b1d 77e755d6 000007a8 0000079c
SharedUserData!SystemCallStub+0x4
0012fcd0 77e755d6 000007a8 0000079c 00000000
ntdll!ZwDeviceIoControlFile+0xc
0012fd30 004022a5 000007a8 001b0040 00000000 kernel32!DeviceIoControl+0x78
WARNING: Stack unwind information not available. Following frames may be
wrong.
0012fe2c 77d43b37 00401bf0 000300a2 00000111 MTTTY+0x22a5
0012fe94 77d43d91 00000000 00401bf0 000300a2
USER32!UserCallWinProcCheckWow+0x150
0012fef4 77d4438c 0012ff1c 00000001 00401a32
USER32!DispatchMessageWorker+0x306
0012ff00 00401a32 0012ff1c 77f517e6 0012ffc0 USER32!DispatchMessageA+0xb
0012ff34 00406f8e 00400000 00000000 00142315 MTTTY+0x1a32
00000105 00000000 00000000 00000000 00000000 MTTTY+0x6f8e

FOLLOWUP_IP:
serenum!Serenum_DispatchPassThrough+63
fc95b8ab 385d0f cmp [ebp+0xf],bl

FOLLOWUP_NAME: MachineOwner

SYMBOL_NAME: serenum!Serenum_DispatchPassThrough+63

STACK_COMMAND: kb

BUCKET_ID: 0xC9_serenum!Serenum_DispatchPassThrough+63

Followup: MachineOwner

This is a different issue than the original post. I have the feeling that
it
is possible to find which routine of my driver at what place executed
last.
Could you give me some hints on how to proceed?

Thanks,
Hablu

> The stack frame of your routine “vanished” from the stack because you
> returned. I’m not sure what you were hoping to find in the stale stack
> frame after returning. If you want to see the values of local
variables,
do
> it while your routine is still running.
>
> Remember, the bug check that you got is indicating that the IRQL changed
> during the call to your driver. If this is reproducible and you can
single
> step through it, you certainly should be able to determined what caused
the
> IRQL change. Knowing the before and after values of the IRQL might
suggest
> some hypothesis. What were they?
>
> Marybeth Croci
>
>

You are currently subscribed to windbg as: xxxxx@stratus.com
To unsubscribe send a blank email to xxxxx@lists.osr.com

You are currently subscribed to windbg as: xxxxx@stratus.com
To unsubscribe send a blank email to xxxxx@lists.osr.com

Hakim · August 7, 2003, 5:39pm

I’m really sorry about any confusion. I should have made separate thread on separate issues though the second issue came during debugging first issue. The first issue was not practice and I was able to narrow down the analysis using information field of IRP and detect the bug and found my hypothesis correct. In the second issue I wanted to find more info from stack to exactly find the IOCTL by reproducing BSOD.

If you think that
you will need historical information on what your driver has done in order
to debug customer crashes, you might want to consider implementing some sort
of light weight ring buffer to save the last “n” things you have done. This
might help in cases where you crash “after the fact”.

This is something I never thought. Thanks for this excellent tip.

Hablu

Well, it’s a fact of life that, when you crash, the stack trace often
doesn’t point out, or even hint at, the culprit. In the case that you
contrived, in “real life” you wouldn’t even have crashed as conveniently as
you did. You were running Driver Verifier. Most likely your customer will
not be, at least not in production. So, you would have returned w/o
releasing the spinlock and some time later you would have deadlocked. That
would be even harder to root cause. Furthermore, consider the case of
memory corruption. If your driver writes beyond the end of a buffer, you
could corrupt ANYONE’s memory. The crashing code path will bear no
resemblence to the actual culprit and the crash could occur significantly
later than the corruption.

This is why you need to test your code thoroughly, using driver verifier, in
the environment in which it is easy for you to find root cause by
interactively debugging, having DbgPrints available, etc. If you think that
you will need historical information on what your driver has done in order
to debug customer crashes, you might want to consider implementing some sort
of light weight ring buffer to save the last “n” things you have done. This
might help in cases where you crash “after the fact”.

In the future, it would be helpful to give more information on what you are
trying to do when you post a question. I had no idea that you had planted a
bug on purpose to “practise” debugging. I thought that you had hypothesized
that you had failed to release a spinlock and wanted to know which IOCTL had
done it. We could have gotten here a lot faster had I realized that!

Marybeth Croci

-----Original Message-----
From: xxxxx@yahoo.ca [mailto:xxxxx@yahoo.ca]
Sent: Thursday, August 07, 2003 3:58 PM
To: Kernel Debugging Interest List
Subject: [windbg] RE: finding IRP detail

I know where I’m not releasing the lock (purposefully). I’m doing this to
gain debugging knowledge, thanks to you all for helping me significantly in
your busy time.

Stepping through the code is only possible because I’m doing it in a
controlled environment. In real life, all I’ll get is memory dump from
customer site and going to customer site for live debugging won’t be
possible almost always. So, after loading the dump I’ll get the same sort of
stack by !analyze -v and that does not show my driver as the culprit. In
this context how the analysis should be started? My goal is to find what
part of my routine executed last, then I’ll know which IOCTL to look after.

TIA,
Hablu