I have a random crash with the following dump anlaysis. Below the analysis, I dump the stack. Does anything look suspect from the instruction <unloaded_swmidi.sys>+0x6349? When reading the stack insruction call order, do you start at the AutAIO down to KeBugCheck or vice versa?
f8b5acf0 f87d654b AutAIO+0x354b
f8b5acf4 82e89f88
f8b5acf8 f8b5ad24
f8b5acfc 00200246
f8b5ad00 804dc86a nt!KeWaitForSingleObject+0x2e5
f8b5ad04 82f124d8
f8b5ad08 0000bb40
f8b5ad0c f8b5ad2c
f8b5ad10 805339ae nt!KeBugCheckEx+0x1b
Bugcheck Analysis
*** Use !analyze -v to get detailed debugging information.
BugCheck 96, {82f124d8, 80561b7c, 80561b40, 80563e7c}
Probably caused by : ntoskrnl.exe ( nt!IopProcessWorkItem+0 )
Followup: MachineOwner
---------
kd> !analyze -v
Bugcheck Analysis
*
INVALID_WORK_QUEUE_ITEM (96)
This message occurs when KeRemoveQueue removes a queue entry whose flink
or blink field is null. This is almost always called by code misusing
worker thread work items, but any queue misuse can cause this. The rule
is that an entry on a queue may only be inserted on the list once. When an
item is removed from a queue, it’s flink field is set to NULL. This bugcheck
occurs when remove queue attempts to remove an entry, but the flink or blink
field is NULL. In order to debug this problem, you need to know the queue being
referenced.
In an attempt to help identify the guilty driver, this bugcheck assumes the
queue is a worker queue (ExWorkerQueue) and prints the worker routine as
parameter 4 below.
Arguments:
Arg1: 82f124d8, The address of the queue entry whose flink/blink field is NULL
Arg2: 80561b7c, The address of the queue being references. Usually this is one
of the ExWorkerQueues.
Arg3: 80561b40, The base address of the ExWorkerQueue array. This will help determine
if the queue in question is an ExWorkerQueue and if so, the offset from
this parameter will isolate the queue.
Arg4: 80563e7c, If this is an ExWorkerQueue (which it usually is), this is the address
of the worker routine that would have been called if the work item was
valid. This can be used to isolate the driver that is misusing the work
queue.
Debugging Details:
------------------
WORKER_ROUTINE:
nt!IopProcessWorkItem+0
80563e7c 8bff mov edi,edi
FAULTING_IP:
nt!IopProcessWorkItem+0
80563e7c 8bff mov edi,edi
WORK_ITEM: 82f124d8
DEFAULT_BUCKET_ID: DRIVER_FAULT
BUGCHECK_STR: 0x96
PROCESS_NAME: System
LAST_CONTROL_TRANSFER: from 8051d9a8 to 805339ae
STACK_TEXT:
f8b5ad2c 8051d9a8 00000096 82f124d8 80561b7c nt!KeBugCheckEx+0x1b
f8b5ad6c 804e47d0 00000001 00000001 00000000 nt!KeRemoveQueue+0x2e6
f8b5adac 8057dfed 82f124d8 00000000 00000000 nt!ExpWorkerThread+0xd6
f8b5addc 804fa477 804e4729 00000001 00000000 nt!PspSystemThreadStartup+0x34
00000000 00000000 00000000 00000000 00000000 nt!KiThreadStartup+0x16
STACK_COMMAND: .bugcheck ; kb
FOLLOWUP_IP:
nt!IopProcessWorkItem+0
80563e7c 8bff mov edi,edi
SYMBOL_NAME: nt!IopProcessWorkItem+0
FOLLOWUP_NAME: MachineOwner
MODULE_NAME: nt
IMAGE_NAME: ntoskrnl.exe
DEBUG_FLR_IMAGE_TIMESTAMP: 41108004
FAILURE_BUCKET_ID: 0x96_nt!IopProcessWorkItem+0
BUCKET_ID: 0x96_nt!IopProcessWorkItem+0
Followup: MachineOwner
kd> dps esp-3000 esp+3000
.
.
.
f8b5ace0 82e89c80
f8b5ace4 f87d91d8 AutAIO+0x61d8
f8b5ace8 00000000
f8b5acec 00000000
f8b5acf0 f87d654b AutAIO+0x354b
f8b5acf4 82e89f88
f8b5acf8 f8b5ad24
f8b5acfc 00200246
f8b5ad00 804dc86a nt!KeWaitForSingleObject+0x2e5
f8b5ad04 82f124d8
f8b5ad08 0000bb40
f8b5ad0c f8b5ad2c
f8b5ad10 805339ae nt!KeBugCheckEx+0x1b
f8b5ad14 00000096
f8b5ad18 82f124d8
f8b5ad1c 80561b7c nt!ExWorkerQueue+0x3c
f8b5ad20 80561b40 nt!ExWorkerQueue
f8b5ad24 80563e7c nt!IopProcessWorkItem
f8b5ad28 00000000
f8b5ad2c f8b5ad6c
f8b5ad30 8051d9a9 nt!KiInsertQueue+0x81
f8b5ad34 00000096
f8b5ad38 82f124d8
f8b5ad3c 80561b7c nt!ExWorkerQueue+0x3c
f8b5ad40 80561b40 nt!ExWorkerQueue
f8b5ad44 80563e7c nt!IopProcessWorkItem
f8b5ad48 82f124d8
f8b5ad4c 80561b7c nt!ExWorkerQueue+0x3c
f8b5ad50 82fc6640
f8b5ad54 82f124d8
f8b5ad58 82e89c80
f8b5ad5c 82fc6640
f8b5ad60 82e89c80
f8b5ad64 00000000
f8b5ad68 82f124d8
f8b5ad6c f8b5adac
f8b5ad70 804e47d0 nt!ExpWorkerThread+0xd6
f8b5ad74 00000001
f8b5ad78 00000001
f8b5ad7c 00000000
f8b5ad80 00000000
f8b5ad84 82fc6640
f8b5ad88 00000000
f8b5ad8c 00000000
f8b5ad90 00000000
f8b5ad94 00000001
f8b5ad98 80561bb4 nt!ExWorkerQueue+0x74
f8b5ad9c 00000000
f8b5ada0 82fc6640
f8b5ada4 00000000
f8b5ada8 80563e7c nt!IopProcessWorkItem
f8b5adac f8b5addc
f8b5adb0 8057dfed nt!PspSystemThreadStartup+0x34
f8b5adb4 82f124d8
f8b5adb8 00000000
f8b5adbc 00000000
f8b5adc0 00000000
f8b5adc4 f8b5adb8
f8b5adc8 00000000
f8b5adcc ffffffff
f8b5add0 804e2af1 nt!_except_handler3
f8b5add4 804fa640 nt!ObWatchHandles+0x62c
f8b5add8 00000000
f8b5addc 00000000
f8b5ade0 804fa477 nt!KiThreadStartup+0x16
f8b5ade4 804e4729 nt!ExpWorkerThread
f8b5ade8 00000001
f8b5adec 00000000
f8b5adf0 0020027f
f8b5adf4 05d80000
f8b5adf8 ef111349 <unloaded_swmidi.sys>+0x6349
f8b5adfc 00000008
f8b5ae00 f8b5a800
f8b5ae04 00000010
f8b5ae08 00001f80
f8b5ae0c 0000ffff
.
.
.
Thanks</unloaded_swmidi.sys></unloaded_swmidi.sys>
>When reading the stack insruction call order, do you start at the AutAIO down to
KeBugCheck or vice versa?
It must be obvious from the table that you have provided…
The leftmost column shows ESP . Once stack grows downwards (i.e. from the numerically larger address to the smaller one) under Intel architecture and values in the leftmost column are presented in ascending order, it is easy to conclude that the topmost entry in the table represents the top of the call stack…
Anton Bassov
I forgot to paste the stack trace in my original post. Going by teh DDK Help, I used the Walk the Stack portion of Help.
kd> dd esp
f8b5ad14 00000096 82f124d8 80561b7c 80561b40
f8b5ad24 80563e7c 00000000 f8b5ad6c 8051d9a9
f8b5ad34 00000096 82f124d8 80561b7c 80561b40
f8b5ad44 80563e7c 82f124d8 80561b7c 82fc6640
f8b5ad54 82f124d8 82e89c80 82fc6640 82e89c80
f8b5ad64 00000000 82f124d8 f8b5adac 804e47d0
f8b5ad74 00000001 00000001 00000000 00000000
f8b5ad84 82fc6640 00000000 00000000 00000000
Next I tried to find valid functions yielding and unassembled those addresses.
kd> ln 80561b7c
(80561b40) nt!ExWorkerQueue+0x3c | (80561c00) nt!ExpTimeRefreshLock
kd> ln 80561b40
(80561b40) nt!ExWorkerQueue | (80561c00) nt!ExpTimeRefreshLock
Exact matches:
nt!ExWorkerQueue =
kd> ln 80563e7c
(80563e7c) nt!IopProcessWorkItem | (80563ea0) nt!ObpFreeObject
Exact matches:
nt!IopProcessWorkItem =
(804e4641) nt!KiInsertQueue+0x81 | (804e46c0) nt!KeInsertQueue
(804e4729) nt!ExpWorkerThread+0xd6 | (804e4846) nt!KeReadStateQueue
8051d970 6c ins byte ptr es:[edi],dx
8051d971 fc cld
8051d972 ff894d08e92e dec dword ptr [ecx+2EE9084Dh]
8051d973 894d08 mov dword ptr [ebp+8],ecx
8051d974 4d dec ebp
8051d975 08e9 or cl,ch
8051d976 e92e6cfcff jmp nt!KeRemoveQueue+0x10c (804e45a9)
8051d977 2e6c ins byte ptr es:[edi],dx
8051d978 6c ins byte ptr es:[edi],dx
8051d979 fc cld
8051d97a ff807e58010f inc dword ptr [eax+0F01587Eh]
8051d980 835b6cfc sbb dword ptr [ebx+6Ch],0FFFFFFFCh
8051d981 5b pop ebx
8051d982 6c ins byte ptr es:[edi],dx
8051d983 fc cld
8051d984 ff ???
8051d985 ff4318 inc dword ptr [ebx+18h]
8051d988 8a4e58 mov cl,byte ptr [esi+58h]
8051d988 8a4e58 mov cl,byte ptr [esi+58h]
8051d989 4e dec esi
8051d98a 58 pop eax
8051d98b e871e3fbff call nt!KiUnlockDispatcherDatabase (804dbd01)
8051d98c 71e3 jno nt!KeRemoveQueue+0x92 (8051d971)
8051d98d e3fb jecxz nt!KeRemoveQueue+0x182 (8051d98a)
8051d98e fb sti
8051d98f ff ???
8051d990 e92d50fdff jmp nt!KeRemoveQueue+0x235 (804f29c2)
8051d991 2d50fdffff sub eax,0FFFFFD50h
8051d992 50 push eax
8051d993 fd std
8051d994 ff ???
8051d995 ff7008 push dword ptr [eax+8]
8051d998 68401b5680 push offset nt!ExWorkerQueue (80561b40)
8051d99d 53 push ebx
8051d99e 50 push eax
8051d99f 6896000000 push 96h
8051d9a4 e8ea5f0100 call nt!KeBugCheckEx (80533993)
8051d9a9 e9046dfcff jmp nt!KiInsertQueue+0xaa (804e46b2)
8051d9ae e84ee3fbff call nt!KiUnlockDispatcherDatabase (804dbd01)
8051d9b3 68470000c0 push 0C0000047h
8051d9b8 e8ddf1fbff call nt!ExRaiseStatus (804dcb9a)
8051d9bd e9c1c9fcff jmp nt!KeReleaseSemaphore+0x38 (804ea383)
8051d9c2 64a124010000 mov eax,dword ptr fs:[00000124h]
8051d9c8 88485a mov byte ptr [eax+5Ah],cl
8051d9cb 8a4dff mov cl,byte ptr [ebp-1]
8051d9ce 884858 mov byte ptr [eax+58h],cl
8051d9d1 e9cec9fcff jmp nt!KeReleaseSemaphore+0x70 (804ea3a4)
8051d9d6 e9bf50fdff jmp nt!KeAlertThread+0x55 (804f2a9a)
8051d9db ff80a0010000 inc dword ptr [eax+1A0h]
xxxxx@yahoo.com wrote:
I forgot to paste the stack trace in my original post. Going by teh DDK Help, I used the Walk the Stack portion of Help.
The right way to do a stack trace is with the “kb” command, which was in
your original mail. When you dump the stack using “dd esp”, you get a
lot of things that look like addresses but which are just leftovers, or
which are part of temporary stack data pushed by some other kernel object.
–
Tim Roberts, xxxxx@probo.com
Providenza & Boekelheide, Inc.
dps esp
would have also dumped symbols for each address instead of manually trying to find matches
d
-----Original Message-----
From: xxxxx@lists.osr.com [mailto:xxxxx@lists.osr.com] On Behalf Of Tim Roberts
Sent: Tuesday, April 15, 2008 3:07 PM
To: Windows System Software Devs Interest List
Subject: Re: [ntdev] INVALID_WORK_QUEUE_ITEM (96)
xxxxx@yahoo.com wrote:
I forgot to paste the stack trace in my original post. Going by teh DDK Help, I used the Walk the Stack portion of Help.
The right way to do a stack trace is with the “kb” command, which was in
your original mail. When you dump the stack using “dd esp”, you get a
lot of things that look like addresses but which are just leftovers, or
which are part of temporary stack data pushed by some other kernel object.
–
Tim Roberts, xxxxx@probo.com
Providenza & Boekelheide, Inc.
NTDEV is sponsored by OSR
For our schedule of WDF, WDM, debugging and other seminars visit:
http://www.osr.com/seminars
To unsubscribe, visit the List Server section of OSR Online at http://www.osronline.com/page.cfm?name=ListServer
Thanks, Doran. I ran the dps esp in WinDbg with the following stack output.
kd> dps esp
f8b5ad14 00000096
f8b5ad18 82f124d8
f8b5ad1c 80561b7c nt!ExWorkerQueue+0x3c
f8b5ad20 80561b40 nt!ExWorkerQueue
f8b5ad24 80563e7c nt!IopProcessWorkItem
f8b5ad28 00000000
f8b5ad2c f8b5ad6c
f8b5ad30 8051d9a9 nt!KiInsertQueue+0x81
f8b5ad34 00000096
f8b5ad38 82f124d8
f8b5ad3c 80561b7c nt!ExWorkerQueue+0x3c
f8b5ad40 80561b40 nt!ExWorkerQueue
f8b5ad44 80563e7c nt!IopProcessWorkItem
f8b5ad48 82f124d8
f8b5ad4c 80561b7c nt!ExWorkerQueue+0x3c
f8b5ad50 82fc6640
f8b5ad54 82f124d8
f8b5ad58 82e89c80
f8b5ad5c 82fc6640
f8b5ad60 82e89c80
f8b5ad64 00000000
f8b5ad68 82f124d8
f8b5ad6c f8b5adac
f8b5ad70 804e47d0 nt!ExpWorkerThread+0xd6
f8b5ad74 00000001
f8b5ad78 00000001
f8b5ad7c 00000000
f8b5ad80 00000000
f8b5ad84 82fc6640
f8b5ad88 00000000
f8b5ad8c 00000000
f8b5ad90 00000000
The address 80563e7c nt!IopProcessWorkItem is Arg4 in the BugCheck 96, {82f124d8, 80561b7c, 80561b40, 80563e7c} and is the address of the worker routine that would have been called if the work item was valid according to the analyze output. The address above 82f124d8 is Arg1 in the BugCheck that is the queue entry whose flink/blink field is NULL. Does IopProcessWorkItem have the wrong return address ExWorkerQueue instead of ExWorkerQueue+0x3c?
Thanks
xxxxx@yahoo.com wrote:
Thanks, Doran. I ran the dps esp in WinDbg with the following stack output.
kd> dps esp
f8b5ad14 00000096
f8b5ad18 82f124d8
f8b5ad1c 80561b7c nt!ExWorkerQueue+0x3c
f8b5ad20 80561b40 nt!ExWorkerQueue
f8b5ad24 80563e7c nt!IopProcessWorkItem
f8b5ad28 00000000
f8b5ad2c f8b5ad6c
f8b5ad30 8051d9a9 nt!KiInsertQueue+0x81
f8b5ad34 00000096
f8b5ad38 82f124d8
f8b5ad3c 80561b7c nt!ExWorkerQueue+0x3c
f8b5ad40 80561b40 nt!ExWorkerQueue
f8b5ad44 80563e7c nt!IopProcessWorkItem
f8b5ad48 82f124d8
f8b5ad4c 80561b7c nt!ExWorkerQueue+0x3c
f8b5ad50 82fc6640
f8b5ad54 82f124d8
f8b5ad58 82e89c80
f8b5ad5c 82fc6640
f8b5ad60 82e89c80
f8b5ad64 00000000
f8b5ad68 82f124d8
f8b5ad6c f8b5adac
f8b5ad70 804e47d0 nt!ExpWorkerThread+0xd6
f8b5ad74 00000001
f8b5ad78 00000001
f8b5ad7c 00000000
f8b5ad80 00000000
f8b5ad84 82fc6640
f8b5ad88 00000000
f8b5ad8c 00000000
f8b5ad90 00000000The address 80563e7c nt!IopProcessWorkItem is Arg4 in the BugCheck 96, {82f124d8, 80561b7c, 80561b40, 80563e7c} and is the address of the worker routine that would have been called if the work item was valid according to the analyze output. The address above 82f124d8 is Arg1 in the BugCheck that is the queue entry whose flink/blink field is NULL. Does IopProcessWorkItem have the wrong return address ExWorkerQueue instead of ExWorkerQueue+0x3c?
No. This kind of conclusion jumping is exactly why I pointed to “kb”
instead of “dps esp”. There are a lot of things on the stack that are
completely unrelated to function calls and parameters. For example,
it’s quite likely that the entire top half of this dump (and maybe more)
is related to processing the bug check itself. Note the bugcheck
parameters are repeated at f8b5ad34.
–
Tim Roberts, xxxxx@probo.com
Providenza & Boekelheide, Inc.
Thanks, Tim. I am new to driver development / debugging. I appreciate your patience. I ran the kd command line and unassembled the return addresses given. Is there a more methodical approach to analyzing the stack?
kd> kb
ChildEBP RetAddr Args to Child
f8b5ad2c 8051d9a8 00000096 82f124d8 80561b7c nt!KeBugCheckEx+0x1b
f8b5ad6c 804e47d0 00000001 00000001 00000000 nt!KeRemoveQueue+0x2e6
f8b5adac 8057dfed 82f124d8 00000000 00000000 nt!ExpWorkerThread+0xd6
f8b5addc 804fa477 804e4729 00000001 00000000 nt!PspSystemThreadStartup+0x34
00000000 00000000 00000000 00000000 00000000 nt!KiThreadStartup+0x16
kd> u 8051d9a8
nt!KeRemoveQueue+0x2e6:
8051d9a8 00e9 add cl,ch
8051d9aa 046d add al,6Dh
8051d9ac fc cld
8051d9ad ff ???
8051d9ae e84ee3fbff call nt!KiUnlockDispatcherDatabase (804dbd01)
8051d9b3 68470000c0 push 0C0000047h
8051d9b8 e8ddf1fbff call nt!ExRaiseStatus (804dcb9a)
8051d9bd e9c1c9fcff jmp nt!KeReleaseSemaphore+0x38 (804ea383)
kd> u 82f124d8
82f124d8 0000 add byte ptr [eax],al
82f124da 0000 add byte ptr [eax],al
82f124dc 8c1b mov word ptr [ebx],ds
82f124de 56 push esi
82f124df 807c3e5680 cmp byte ptr [esi+edi+56h],80h
82f124e4 d824f1 fsub dword ptr [ecx+esi*8]
82f124e7 82ec5d sub ah,5Dh
82f124ea 7df8 jge 82f124e4
kd> u 80561b7c
nt!ExWorkerQueue+0x3c:
80561b7c 0400 add al,0
80561b7e 0a00 or al,byte ptr [eax]
80561b80 0100 add dword ptr [eax],eax
80561b82 0000 add byte ptr [eax],al
80561b84 3874fc82 cmp byte ptr [esp+edi*8-7Eh],dh
80561b88 2869fc sub byte ptr [ecx-4],ch
80561b8b 82d824 sbb al,24h
80561b8e f1 ???
kd> u 804e47d0
nt!ExpWorkerThread+0xd6:
804e47d0 8bf8 mov edi,eax
804e47d2 81ff02010000 cmp edi,102h
804e47d8 0f84042c0200 je nt!ExpWorkerThread+0x146 (805073e2)
804e47de 8d462c lea eax,[esi+2Ch]
804e47e1 894508 mov dword ptr [ebp+8],eax
804e47e4 b801000000 mov eax,1
804e47e9 8b4d08 mov ecx,dword ptr [ebp+8]
804e47ec 0fc101 xadd dword ptr [ecx],eax
kd> u 8057dfed
nt!PspSystemThreadStartup+0x34:
8057dfed 834dfcff or dword ptr [ebp-4],0FFFFFFFFh
8057dff1 6a00 push 0
8057dff3 56 push esi
8057dff4 e8cc040000 call nt!PspTerminateThreadByPointer (8057e4c5)
8057dff9 e8d44af6ff call nt!_SEH_epilog (804e2ad2)
8057dffe c20800 ret 8
8057e001 894308 mov dword ptr [ebx+8],eax
8057e004 894710 mov dword ptr [edi+10h],eax
kd> u 82f124d8
82f124d8 0000 add byte ptr [eax],al
82f124da 0000 add byte ptr [eax],al
82f124dc 8c1b mov word ptr [ebx],ds
82f124de 56 push esi
82f124df 807c3e5680 cmp byte ptr [esi+edi+56h],80h
82f124e4 d824f1 fsub dword ptr [ecx+esi*8]
82f124e7 82ec5d sub ah,5Dh
82f124ea 7df8 jge 82f124e4
kd> u 804fa477
nt!KiThreadStartup+0x16:
804fa477 59 pop ecx
804fa478 0bc9 or ecx,ecx
804fa47a 7407 je nt!KiThreadStartup+0x22 (804fa483)
804fa47c 8bec mov ebp,esp
804fa47e e9a14dfeff jmp nt!KiServiceExit2 (804df224)
804fa483 6a0e push 0Eh
804fa485 e8e5940300 call nt!KeBugCheck (8053396f)
804fa48a 90 nop
I notice at address 8051d9b3 68470000c0 push 0C0000047h. I found that this is an error for STATUS_SEMAPHORE_LIMIT_EXCEEDED. Is this only a result of the BSOD or the cause?
Any help is appreciated.
Thanks
xxxxx@yahoo.com wrote:
Thanks, Tim. I am new to driver development / debugging. I appreciate your patience. I ran the kd command line and unassembled the return addresses given. Is there a more methodical approach to analyzing the stack?
kd> kb
ChildEBP RetAddr Args to Child
f8b5ad2c 8051d9a8 00000096 82f124d8 80561b7c nt!KeBugCheckEx+0x1b
f8b5ad6c 804e47d0 00000001 00000001 00000000 nt!KeRemoveQueue+0x2e6
f8b5adac 8057dfed 82f124d8 00000000 00000000 nt!ExpWorkerThread+0xd6
f8b5addc 804fa477 804e4729 00000001 00000000 nt!PspSystemThreadStartup+0x34
00000000 00000000 00000000 00000000 00000000 nt!KiThreadStartup+0x16
kd> u 8051d9a8
nt!KeRemoveQueue+0x2e6:
8051d9a8 00e9 add cl,ch
8051d9aa 046d add al,6Dh
8051d9ac fc cld
8051d9ad ff ???
8051d9ae e84ee3fbff call nt!KiUnlockDispatcherDatabase (804dbd01)
8051d9b3 68470000c0 push 0C0000047h
8051d9b8 e8ddf1fbff call nt!ExRaiseStatus (804dcb9a)
8051d9bd e9c1c9fcff jmp nt!KeReleaseSemaphore+0x38 (804ea383)
…
I notice at address 8051d9b3 68470000c0 push 0C0000047h. I found that this is an error for STATUS_SEMAPHORE_LIMIT_EXCEEDED. Is this only a result of the BSOD or the cause?
Neither. That is simply code that has not yet been executed. Remember
that 8051d9a8 is the address where things stopped because of the bug
check occurred. To see what led up to that, you have to look before
that address.
There is something fundamentally wrong here, because that code is not
right. The bytes at 8051d9a9 are a jmp instruction, but not 8051d9a8.
However, I think you are chasing down ratholes here. The problem that
caused the bug check is a bad work queue item. Is your driver using
work queue items? That’s where you need to look. Are you running
driver verifier?
–
Tim Roberts, xxxxx@probo.com
Providenza & Boekelheide, Inc.