Crash in USB stack

OSR_Community_User · September 27, 2005, 1:12pm

I’m hitting a bugcheck in a USB device driver, not really sure why, and
would appreciate any insight. My driver is attempting to reset a pipe on a
USB device, and it is *sometimes* faulting with an attempt to write at
0x00000004.

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

IRQL_NOT_LESS_OR_EQUAL (a)
An attempt was made to access a pageable (or completely invalid) address at
an
interrupt request level (IRQL) that is too high. This is usually
caused by drivers using improper addresses.
If a kernel debugger is available get the stack backtrace.
Arguments:
Arg1: 00000004, memory referenced
Arg2: 00000002, IRQL
Arg3: 00000001, value 0 = read operation, 1 = write operation
Arg4: 804fac9d, address which referenced memory

Debugging Details:

WRITE_ADDRESS: 00000004

CURRENT_IRQL: 2

FAULTING_IP:
nt!KiActivateWaiterQueue+27
804fac9d 897004 mov [eax+0x4],esi

DEFAULT_BUCKET_ID: DRIVER_FAULT

BUGCHECK_STR: 0xA

LAST_CONTROL_TRANSFER: from 804f9996 to 804fac9d

TRAP_FRAME: f6e67a6c – (.trap fffffffff6e67a6c)
ErrCode = 00000002
eax=00000000 ebx=f6e67b34 ecx=8055a1fc edx=858d15cc esi=858d15cc
edi=867c4928
eip=804fac9d esp=f6e67ae0 ebp=f6e67b0c iopl=0 nv up ei pl nz na po
nc
cs=0008 ss=0010 ds=0023 es=0023 fs=0030 gs=0000
efl=00010206
nt!KiActivateWaiterQueue+0x27:
804fac9d 897004 mov [eax+0x4],esi
ds:0023:00000004=???
Resetting default scope

STACK_TEXT:
f6e67ae4 804f9996 866380ec 858d1df0 00000000 nt!KiActivateWaiterQueue+0x27
f6e67b0c f72bf52a 00000000 00000005 00000000 nt!KeWaitForSingleObject+0x19a
f6e67b4c f72b4a9b 74545773 86638028 866380ec
USBPORT!USBPORT_SendCommand+0x20e
f6e67b84 f72b4b76 86638028 860756a8 f6e67cf0
USBPORT!USBPORT_SyncClearStall+0x59
f6e67bbc f72b3d5c 86638028 860756a8 f6e67cf0
USBPORT!USBPORT_SyncResetPipeAndClearStall+0xc6
f6e67be8 f72b8dfe 86647618 86638028 000001e0
USBPORT!USBPORT_ProcessURB+0x3f4
f6e67c08 f72a21e2 86647618 860756a8 860756a8
USBPORT!USBPORT_PdoInternalDeviceControlIrp+0x7e
f6e67c2c 804eddf9 86075760 86647770 f6e67cf0 USBPORT!USBPORT_Dispatch+0x148
f6e67c3c f777c50a f6e67c64 f77802d9 860756a8 nt!IopfCallDriver+0x31
f6e67c44 f77802d9 860756a8 86647618 860756a8 usbhub!USBH_PassIrp+0x18
f6e67c64 f7780afa 8665a0e8 860756a8 f6e67d50 usbhub!USBH_PdoUrbFilter+0xbd
f6e67c80 f777e1d8 f6e67cf0 860756a8 f6e67cd4 usbhub!USBH_PdoDispatch+0x202
f6e67c90 804eddf9 85be1830 860756a8 8055a1fc usbhub!USBH_HubDispatch+0x48
f6e67ca0 b890dae7 00000001 80535010 804da108 nt!IopfCallDriver+0x31
f6e67cd4 b890dbeb 858d1418 f6e67cf0 858d15cc xxx
f6e67d50 b8908a05 858d1418 860929cc 00000001 xxx
f6e67d74 80533dd0 858d1418 00000000 85dd06f0 xxx
f6e67dac 805c4a06 858d1418 00000000 00000000 nt!ExpWorkerThread+0x100
f6e67ddc 80540fa2 80533cd0 80000001 00000000 nt!PspSystemThreadStartup+0x34
00000000 00000000 00000000 00000000 00000000 nt!KiThreadStartup+0x16

Note the first arg to KeWaitForSingleObject, which is NULL. The sequence in
USBPORT_SendCommand just before the call to KeWaitForSingleObject is this:

f72bf51b 53 push ebx
f72bf51c 53 push ebx
f72bf51d 53 push ebx
f72bf51e 6a05 push 0x5
f72bf520 8d45e8 lea eax,[ebp-0x18]
f72bf523 50 push eax
f72bf524 ff15d8d82bf7 call dword ptr [USBPORT!_imp__KeWaitForSingleObject
(f72bd8d8)]

How can “lea eax,[ebp-0x18] ; push eax” lead to a zero being pushed on the
stack? I’m sure I’m doing something wrong, but it certainly isn’t obvious
from this dump. The problem occurs *sometimes* when this code path runs,
not always. The call frame before nt!IopfCallDriver builds a URB of type
USB_FUNCTION_RESET_PIPE, sends it down with
IoBuildDeviceIoControlRequest/IoCallDriver, and waits on the event. This
code has worked before with no problems, so I’m sure I’m doing something
stupid elsewhere.

Any clues are appreciated.

– arlie

OSR_Community_User · September 27, 2005, 1:27pm

Are you calling KeWaitForSingleObject at IRQL=2 with timeout non zero by any chance ?

-----Mensaje original-----
De: xxxxx@lists.osr.com
[mailto:xxxxx@lists.osr.com]En nombre de Arlie Davis
Enviado el: martes, 27 de septiembre de 2005 19:12
Para: Windows System Software Devs Interest List
Asunto: [ntdev] Crash in USB stack

I’m hitting a bugcheck in a USB device driver, not really sure why, and
would appreciate any insight. My driver is attempting to reset a pipe on a
USB device, and it is *sometimes* faulting with an attempt to write at
0x00000004.

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

IRQL_NOT_LESS_OR_EQUAL (a)
An attempt was made to access a pageable (or completely invalid) address at
an
interrupt request level (IRQL) that is too high. This is usually
caused by drivers using improper addresses.
If a kernel debugger is available get the stack backtrace.
Arguments:
Arg1: 00000004, memory referenced
Arg2: 00000002, IRQL
Arg3: 00000001, value 0 = read operation, 1 = write operation
Arg4: 804fac9d, address which referenced memory

Debugging Details:

WRITE_ADDRESS: 00000004

CURRENT_IRQL: 2

FAULTING_IP:
nt!KiActivateWaiterQueue+27
804fac9d 897004 mov [eax+0x4],esi

DEFAULT_BUCKET_ID: DRIVER_FAULT

BUGCHECK_STR: 0xA

LAST_CONTROL_TRANSFER: from 804f9996 to 804fac9d

TRAP_FRAME: f6e67a6c – (.trap fffffffff6e67a6c)
ErrCode = 00000002
eax=00000000 ebx=f6e67b34 ecx=8055a1fc edx=858d15cc esi=858d15cc
edi=867c4928
eip=804fac9d esp=f6e67ae0 ebp=f6e67b0c iopl=0 nv up ei pl nz na po
nc
cs=0008 ss=0010 ds=0023 es=0023 fs=0030 gs=0000
efl=00010206
nt!KiActivateWaiterQueue+0x27:
804fac9d 897004 mov [eax+0x4],esi
ds:0023:00000004=???
Resetting default scope

STACK_TEXT:
f6e67ae4 804f9996 866380ec 858d1df0 00000000 nt!KiActivateWaiterQueue+0x27
f6e67b0c f72bf52a 00000000 00000005 00000000 nt!KeWaitForSingleObject+0x19a
f6e67b4c f72b4a9b 74545773 86638028 866380ec
USBPORT!USBPORT_SendCommand+0x20e
f6e67b84 f72b4b76 86638028 860756a8 f6e67cf0
USBPORT!USBPORT_SyncClearStall+0x59
f6e67bbc f72b3d5c 86638028 860756a8 f6e67cf0
USBPORT!USBPORT_SyncResetPipeAndClearStall+0xc6
f6e67be8 f72b8dfe 86647618 86638028 000001e0
USBPORT!USBPORT_ProcessURB+0x3f4
f6e67c08 f72a21e2 86647618 860756a8 860756a8
USBPORT!USBPORT_PdoInternalDeviceControlIrp+0x7e
f6e67c2c 804eddf9 86075760 86647770 f6e67cf0 USBPORT!USBPORT_Dispatch+0x148
f6e67c3c f777c50a f6e67c64 f77802d9 860756a8 nt!IopfCallDriver+0x31
f6e67c44 f77802d9 860756a8 86647618 860756a8 usbhub!USBH_PassIrp+0x18
f6e67c64 f7780afa 8665a0e8 860756a8 f6e67d50 usbhub!USBH_PdoUrbFilter+0xbd
f6e67c80 f777e1d8 f6e67cf0 860756a8 f6e67cd4 usbhub!USBH_PdoDispatch+0x202
f6e67c90 804eddf9 85be1830 860756a8 8055a1fc usbhub!USBH_HubDispatch+0x48
f6e67ca0 b890dae7 00000001 80535010 804da108 nt!IopfCallDriver+0x31
f6e67cd4 b890dbeb 858d1418 f6e67cf0 858d15cc xxx
f6e67d50 b8908a05 858d1418 860929cc 00000001 xxx
f6e67d74 80533dd0 858d1418 00000000 85dd06f0 xxx
f6e67dac 805c4a06 858d1418 00000000 00000000 nt!ExpWorkerThread+0x100
f6e67ddc 80540fa2 80533cd0 80000001 00000000 nt!PspSystemThreadStartup+0x34
00000000 00000000 00000000 00000000 00000000 nt!KiThreadStartup+0x16

Note the first arg to KeWaitForSingleObject, which is NULL. The sequence in
USBPORT_SendCommand just before the call to KeWaitForSingleObject is this:

f72bf51b 53 push ebx
f72bf51c 53 push ebx
f72bf51d 53 push ebx
f72bf51e 6a05 push 0x5
f72bf520 8d45e8 lea eax,[ebp-0x18]
f72bf523 50 push eax
f72bf524 ff15d8d82bf7 call dword ptr [USBPORT!_imp__KeWaitForSingleObject
(f72bd8d8)]

How can “lea eax,[ebp-0x18] ; push eax” lead to a zero being pushed on the
stack? I’m sure I’m doing something wrong, but it certainly isn’t obvious
from this dump. The problem occurs *sometimes* when this code path runs,
not always. The call frame before nt!IopfCallDriver builds a URB of type
USB_FUNCTION_RESET_PIPE, sends it down with
IoBuildDeviceIoControlRequest/IoCallDriver, and waits on the event. This
code has worked before with no problems, so I’m sure I’m doing something
stupid elsewhere.

Any clues are appreciated.

– arlie

Questions? First check the Kernel Driver FAQ at http://www.osronline.com/article.cfm?id=256

You are currently subscribed to ntdev as: xxxxx@pandasoftware.es
To unsubscribe send a blank email to xxxxx@lists.osr.com

OSR_Community_User · September 27, 2005, 1:35pm

I’m not the one calling KeWaitForSingleObject – USBPORT!USBPORT_SendCommand
is. Once IoCallDriver returns to my driver, I do call
KeWaitForSingleObject, with NULL timeout, at PASSIVE_LEVEL. But my code
never gets to that point – the fault occurs long before control is returned
to my code.

When this call path does succeed, my call to KeWaitForSingleObject works
fine.

– arlie

-----Original Message-----
From: xxxxx@lists.osr.com
[mailto:xxxxx@lists.osr.com] On Behalf Of I?aki Castillo
Sent: Tuesday, September 27, 2005 1:27 PM
To: Windows System Software Devs Interest List
Subject: RE: [ntdev] Crash in USB stack

Are you calling KeWaitForSingleObject at IRQL=2 with timeout non zero by any
chance ?

Michal_Vodicka-2 · September 27, 2005, 2:02pm

> ----------

From: xxxxx@lists.osr.com[SMTP:xxxxx@lists.osr.com] on behalf of Arlie Davis[SMTP:xxxxx@stonestreetone.com]
Reply To: Windows System Software Devs Interest List
Sent: Tuesday, September 27, 2005 7:12 PM
To: Windows System Software Devs Interest List
Subject: [ntdev] Crash in USB stack

f72bf51b 53 push ebx
f72bf51c 53 push ebx
f72bf51d 53 push ebx
f72bf51e 6a05 push 0x5
f72bf520 8d45e8 lea eax,[ebp-0x18]
f72bf523 50 push eax
f72bf524 ff15d8d82bf7 call dword ptr [USBPORT!_imp__KeWaitForSingleObject
(f72bd8d8)]

How can “lea eax,[ebp-0x18] ; push eax” lead to a zero being pushed on the
stack?

Stack values in the dump aren’t necessarily the same as values pushed on the stack before function call. Optimized code can reuse stack parameters and also original C code can. Did this zero cause the crash? You can both disassembly all related code or single step through it to see what really happens with this stack value. I mean although zero seems strange there, it can be quite innocent and there is a different problem.

Best regards,

Michal Vodicka
UPEK, Inc.
[xxxxx@upek.com, http://www.upek.com]

Scott_Noone_OSR · September 27, 2005, 3:05pm

Hi,

Check out this article http://support.microsoft.com/?kbid=818501, seems like
an extremely likely candidate for your crash.

-scott

–
Scott Noone
Software Engineer
OSR Open Systems Resources, Inc.
http://www.osronline.com

“Arlie Davis” wrote in message
news:xxxxx@ntdev…
> I’m hitting a bugcheck in a USB device driver, not really sure why, and
> would appreciate any insight. My driver is attempting to reset a pipe on
> a
> USB device, and it is sometimes faulting with an attempt to write at
> 0x00000004.
>
>
> kd> !analyze -v
> *************************************************************************
>
> *
> *
> * Bugcheck Analysis
> *
> *
> *
> *************************************************************************
>
>
> IRQL_NOT_LESS_OR_EQUAL (a)
> An attempt was made to access a pageable (or completely invalid) address
> at
> an
> interrupt request level (IRQL) that is too high. This is usually
> caused by drivers using improper addresses.
> If a kernel debugger is available get the stack backtrace.
> Arguments:
> Arg1: 00000004, memory referenced
> Arg2: 00000002, IRQL
> Arg3: 00000001, value 0 = read operation, 1 = write operation
> Arg4: 804fac9d, address which referenced memory
>
> Debugging Details:
> ------------------
>
>
> WRITE_ADDRESS: 00000004
>
> CURRENT_IRQL: 2
>
> FAULTING_IP:
> nt!KiActivateWaiterQueue+27
> 804fac9d 897004 mov [eax+0x4],esi
>
> DEFAULT_BUCKET_ID: DRIVER_FAULT
>
> BUGCHECK_STR: 0xA
>
> LAST_CONTROL_TRANSFER: from 804f9996 to 804fac9d
>
> TRAP_FRAME: f6e67a6c – (.trap fffffffff6e67a6c)
> ErrCode = 00000002
> eax=00000000 ebx=f6e67b34 ecx=8055a1fc edx=858d15cc esi=858d15cc
> edi=867c4928
> eip=804fac9d esp=f6e67ae0 ebp=f6e67b0c iopl=0 nv up ei pl nz na po
> nc
> cs=0008 ss=0010 ds=0023 es=0023 fs=0030 gs=0000
> efl=00010206
> nt!KiActivateWaiterQueue+0x27:
> 804fac9d 897004 mov [eax+0x4],esi
> ds:0023:00000004=???
> Resetting default scope
>
> STACK_TEXT:
> f6e67ae4 804f9996 866380ec 858d1df0 00000000 nt!KiActivateWaiterQueue+0x27
> f6e67b0c f72bf52a 00000000 00000005 00000000
> nt!KeWaitForSingleObject+0x19a
> f6e67b4c f72b4a9b 74545773 86638028 866380ec
> USBPORT!USBPORT_SendCommand+0x20e
> f6e67b84 f72b4b76 86638028 860756a8 f6e67cf0
> USBPORT!USBPORT_SyncClearStall+0x59
> f6e67bbc f72b3d5c 86638028 860756a8 f6e67cf0
> USBPORT!USBPORT_SyncResetPipeAndClearStall+0xc6
> f6e67be8 f72b8dfe 86647618 86638028 000001e0
> USBPORT!USBPORT_ProcessURB+0x3f4
> f6e67c08 f72a21e2 86647618 860756a8 860756a8
> USBPORT!USBPORT_PdoInternalDeviceControlIrp+0x7e
> f6e67c2c 804eddf9 86075760 86647770 f6e67cf0
> USBPORT!USBPORT_Dispatch+0x148
> f6e67c3c f777c50a f6e67c64 f77802d9 860756a8 nt!IopfCallDriver+0x31
> f6e67c44 f77802d9 860756a8 86647618 860756a8 usbhub!USBH_PassIrp+0x18
> f6e67c64 f7780afa 8665a0e8 860756a8 f6e67d50 usbhub!USBH_PdoUrbFilter+0xbd
> f6e67c80 f777e1d8 f6e67cf0 860756a8 f6e67cd4 usbhub!USBH_PdoDispatch+0x202
> f6e67c90 804eddf9 85be1830 860756a8 8055a1fc usbhub!USBH_HubDispatch+0x48
> f6e67ca0 b890dae7 00000001 80535010 804da108 nt!IopfCallDriver+0x31
> f6e67cd4 b890dbeb 858d1418 f6e67cf0 858d15cc xxx
> f6e67d50 b8908a05 858d1418 860929cc 00000001 xxx
> f6e67d74 80533dd0 858d1418 00000000 85dd06f0 xxx
> f6e67dac 805c4a06 858d1418 00000000 00000000 nt!ExpWorkerThread+0x100
> f6e67ddc 80540fa2 80533cd0 80000001 00000000
> nt!PspSystemThreadStartup+0x34
> 00000000 00000000 00000000 00000000 00000000 nt!KiThreadStartup+0x16
>
>
>
> Note the first arg to KeWaitForSingleObject, which is NULL. The sequence
> in
> USBPORT_SendCommand just before the call to KeWaitForSingleObject is this:
>
> f72bf51b 53 push ebx
> f72bf51c 53 push ebx
> f72bf51d 53 push ebx
> f72bf51e 6a05 push 0x5
> f72bf520 8d45e8 lea eax,[ebp-0x18]
> f72bf523 50 push eax
> f72bf524 ff15d8d82bf7 call dword ptr [USBPORT!_imp__KeWaitForSingleObject
> (f72bd8d8)]
>
> How can “lea eax,[ebp-0x18] ; push eax” lead to a zero being pushed on the
> stack? I’m sure I’m doing something wrong, but it certainly isn’t obvious
> from this dump. The problem occurs sometimes when this code path runs,
> not always. The call frame before nt!IopfCallDriver builds a URB of type
> USB_FUNCTION_RESET_PIPE, sends it down with
> IoBuildDeviceIoControlRequest/IoCallDriver, and waits on the event. This
> code has worked before with no problems, so I’m sure I’m doing something
> stupid elsewhere.
>
> Any clues are appreciated.
>
> – arlie
>
>
>
>

OSR_Community_User · September 27, 2005, 4:35pm

Ah, right before I read this, I found it. And it was related to the fact
that a work-item was being used. The code was using the older
ExInitializeWorkItem function (now obsolete), and it was not correctly
handling device removal race conditions. So the device was being torn down
in the middle of a USB pipe reset.

Thanks/sorry.

– arlie

-----Original Message-----
From: xxxxx@lists.osr.com
[mailto:xxxxx@lists.osr.com] On Behalf Of Scott Noone
Sent: Tuesday, September 27, 2005 3:05 PM
To: Windows System Software Devs Interest List
Subject: Re:[ntdev] Crash in USB stack

Hi,

Check out this article http://support.microsoft.com/?kbid=818501, seems like
an extremely likely candidate for your crash.

-scott

–
Scott Noone
Software Engineer
OSR Open Systems Resources, Inc.
http://www.osronline.com