USB 3 Crash

Tim_Roberts · May 27, 2011, 1:36pm

I have a USB video camera driver (AVStream) that has been in the wild
for about 4 years. Thousands of the cameras are in real-world use.
We've run tens of thousands of plug/unplug tests over the years. We've
passed the WHQL unclassified suite many times. I'm pretty confident of
my PnP handling.

This week, we had a client report a bugcheck 0xFE on a Win 7 64-bit
system after an unplug and replug while our viewer application is
running. The bugcheck parameters are (8,6,6,x), which indicates a
timeout in the USB hub driver trying to suspend a port. They sent me a
full kernel dump (analysis below). My driver is not in the crash stack
-- it's only usbhub.sys, trying to disable a port. I've never seen this
before. I don't know whether usbhub is complaining that the hardware
didn't respond in time, or if my driver is somehow blocking the
transition. There are no outstanding IRPs for my driver.

There are two things in this dump that I find suspicious. The most
interesting thing is that we are plugged in to a USB 3 host controller.
There are 4 processors; one of them triggered the crash, one is idle,
and the other two are inside NEC's USB 3 host controller driver
(nusb3xhc.sys).

The other suspicious thing is that there is a filter driver sitting
above me -- CtClsFlt.sys, which is a video class upper filter from
Creative Technology of unknown purpose.

Has anybody with USB 3 experience seen unusual crashes? My gut
suspicion is that there are PnP corner cases that the NEC host
controller and/or hub driver are not handling, or that it is making some
assumptions that are not universally valid, but I'm not sure I know how
to validate that.

Loading Dump File [C:\tmp\MEMORY.DMP]
Kernel Summary Dump File: Only kernel address space is available

Symbol search path is:
srv*c:\ddk\symbols*Symbol information
Executable search path is:
Windows 7 Kernel Version 7600 MP (4 procs) Free x64
Product: WinNt, suite: TerminalServer SingleUserTS Personal
Built by: 7600.16792.amd64fre.win7_gdr.110408-1633
Machine Name:
Kernel base = 0xfffff8000365a000 PsLoadedModuleList = 0xfffff80003897e50
Debug session time: Thu May 26 06:16:39.472 2011 (GMT-7)
System Uptime: 0 days 1:39:22.033
Loading Kernel Symbols
...............................................................
................................................................
............................................
Loading User Symbols

Loading unloaded module list
..........
*******************************************************************************
*
*
* Bugcheck Analysis
*
*
*
*******************************************************************************

Use !analyze -v to get detailed debugging information.

BugCheck FE, {8, 6, 6, fffffa8008a27000}

Probably caused by : usbhub.sys ( usbhub!UsbhWaitEventWithTimeoutEx+3aa )

Followup: MachineOwner

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

BUGCODE_USB_DRIVER (fe)
USB Driver bugcheck, first parameter is USB bugcheck code.
Arguments:
Arg1: 0000000000000008, USBBUGCODE_RESERVED_USBHUB
Arg2: 0000000000000006, USBHUB_TRAP_FATAL_TIMEOUT
Arg3: 0000000000000006, TimeoutCode: Timeout_PCE_Disable_Action -
PortData->PortChangeListDone - Timeout trying to set Disable bit
Arg4: fffffa8008a27000, TimeoutContext - PortData

Debugging Details:

DEFAULT_BUCKET_ID: VISTA_DRIVER_FAULT

BUGCHECK_STR: 0xFE

PROCESS_NAME: System

CURRENT_IRQL: 0

LAST_CONTROL_TRANSFER: from fffff880044017fa to fffff800036ca700

STACK_TEXT:
fffff880033a1888 fffff880044017fa : 00000000000000fe 0000000000000008 0000000000000006 0000000000000006 : nt!KeBugCheckEx
fffff880033a1890 fffff8800440c5c1 : fffffa8008a27000 fffffa8008a271d8 fffffa8008a27000 fffffa8008a23050 :
usbhub!UsbhWaitEventWithTimeoutEx+0x3aa
fffff880033a1940 fffff8800440bbdc : 0000000000000000 fffffa8050447100 fffffa8008a27000 0000000000080000 :
usbhub!Usbh_PCE_Disable_Action+0x4f1
fffff880033a19a0 fffff88004410ff0 : fffffa8008a23050 0000000000000001 0000000000000001 fffffa8008a239c8 :
usbhub!UsbhDispatch_PortChangeQueueEventEx+0x110
fffff880033a19e0 fffff88004409744 : fffffa8008a23050 fffffa8008a27000 fffffa8008a27000 0000000000000000 :
usbhub!UsbhPCE_Disable+0xb4
fffff880033a1a30 fffff88004408a3c : 0000000000000007 0000000000000003 fffffa8008a23050 fffffa8008a239c8 :
usbhub!UsbhBusPause_Action+0x184
fffff880033a1a80 fffff88004408eb6 : fffffa8008a231a0 0000000000000007 fffffa8008a23050 fffff8800441ac00 :
usbhub!Usbh_BS_BusRun+0x94
fffff880033a1ac0 fffff8800440992b : 0000000000000002 fffffa8008a23ec8 fffffa8008a23050 fffffa8008a20000 :
usbhub!UsbhDispatch_BusEvent+0x20e
fffff880033a1b10 fffff8800443a738 : fffffa8008a23050 fffffa8008a239c8 0000000000000000 0000000000000000 :
usbhub!UsbhSyncBusPause+0x4f
fffff880033a1b50 fffff880044395ab : 0000000000000000 0000000000000001 fffff80000000003 fffffa8008a23050 :
usbhub!UsbhSshSuspendHub+0xcc
fffff880033a1bb0 fffff88004439447 : 0000000000000001 0000000000000001 fffffa8008a23050 fffff800036d52b1 :
usbhub!Usbh_SSH_HubActive+0x13f
fffff880033a1be0 fffff8800443a311 : fffffa8008a231a0 fffff8000386f5f8 fffffa8008a23050 fffffa8008a239c8 :
usbhub!Usbh_SSH_Event+0x147
fffff880033a1c10 fffff8800440673f : fffffa8008a231a0 fffffa8008a23050 0000000000000000 0000000000000001 :
usbhub!UsbhHubSSH_Worker+0x2d
fffff880033a1c40 fffff800039c5843 : fffffa8008a23050 fffffa80041ac040 0000000000000000 fffffa80041ac040 :
usbhub!UsbhHubWorker+0x63
fffff880033a1c80 fffff800036d7961 : fffff800039bc400 fffff800039bc4c8 fffffa80041ac040 0000000000000000 :
nt!IopProcessWorkItem+0x23
fffff880033a1cb0 fffff8000396dbc6 : 6300650030003100 fffffa80041ac040 0000000000000080 fffffa80041975f0 :
nt!ExpWorkerThread+0x111
fffff880033a1d40 fffff800036a8bc6 : fffff880031d3180 fffffa80041ac040 fffff880031ddfc0 0034003200440049 :
nt!PspSystemThreadStartup+0x5a
fffff880033a1d80 0000000000000000 : fffff880033a2000 fffff8800339c000 fffff880033a13d0 0000000000000000 :
nt!KiStartSystemThread+0x16

STACK_COMMAND: kb

FOLLOWUP_IP:
usbhub!UsbhWaitEventWithTimeoutEx+3aa
fffff880`044017fa cc int 3

SYMBOL_STACK_INDEX: 1

SYMBOL_NAME: usbhub!UsbhWaitEventWithTimeoutEx+3aa

FOLLOWUP_NAME: MachineOwner

MODULE_NAME: usbhub

IMAGE_NAME: usbhub.sys

DEBUG_FLR_IMAGE_TIMESTAMP: 4d9152dc

FAILURE_BUCKET_ID: X64_0xFE_usbhub!UsbhWaitEventWithTimeoutEx+3aa

BUCKET_ID: X64_0xFE_usbhub!UsbhWaitEventWithTimeoutEx+3aa

Followup: MachineOwner

0: kd> 0kb
RetAddr : Args to Child
: Call Site
fffff88006609b74 : fffffa800cba2430 fffffa8007af6390 fffffa8007955000 0000000000000080 : nusb3xhc+0x93e3 fffff88006609f73 : 0000000000000102 0000000000000080
fffffa8007955000 fffffa8007af6300 : nusb3xhc+0x9b74
fffff88006628bdc : ffffffffffb3b4c0 fffffa80083be970 fffffa8007a995e0 fffffa80041975f0 : nusb3xhc+0x9f73 fffff8000396dbc6 : 00000000026bc0d9 fffff880031d3180
fffff880030d3db0 fffffa800840d160 : nusb3xhc+0x28bdc
fffff800036a8bc6 : fffff880031d3180 fffffa800840d160 fffff880031ddfc0 fffff88001411810 : nt!PspSystemThreadStartup+0x5a 0000000000000000 : fffff880030d4000 0000000000000000
0000000000000000 0000000000000000 : nt!KiStartSystemThread+0x16
0: kd> 1kb
RetAddr : Args to Child
: Call Site
fffff800036d824a : 000000000025a7f8 fffffa8004fe24f8 0000000000000000 0000000000000000 : intelppm+0x2c61 fffff800036d2ebc : fffff880009e8180 fffff88000000002
0000000000000002 fffff88000000000 : nt!PoIdle+0x53a
0000000000000000 : fffff8800311c000 fffff88003116000 fffff8800311bd40 0000000000000000 : nt!KiIdleLoop+0x2c 0: kd\> 2kb RetAddr : Args to Child : Call Site fffff880044017fa : 00000000000000fe 0000000000000008
0000000000000006 0000000000000006 : nt!KeBugCheckEx
fffff8800440c5c1 : fffffa8008a27000 fffffa8008a271d8 fffffa8008a27000 fffffa8008a23050 : usbhub!UsbhWaitEventWithTimeoutEx+0x3aa fffff8800440bbdc : 0000000000000000 fffffa8050447100
fffffa8008a27000 0000000000080000 : usbhub!Usbh_PCE_Disable_Action+0x4f1
fffff88004410ff0 : fffffa8008a23050 0000000000000001 0000000000000001 fffffa8008a239c8 : usbhub!UsbhDispatch_PortChangeQueueEventEx+0x110 fffff88004409744 : fffffa8008a23050 fffffa8008a27000
fffffa8008a27000 0000000000000000 : usbhub!UsbhPCE_Disable+0xb4
fffff88004408a3c : 0000000000000007 0000000000000003 fffffa8008a23050 fffffa8008a239c8 : usbhub!UsbhBusPause_Action+0x184 fffff88004408eb6 : fffffa8008a231a0 0000000000000007
fffffa8008a23050 fffff8800441ac00 : usbhub!Usbh_BS_BusRun+0x94
fffff8800440992b : 0000000000000002 fffffa8008a23ec8 fffffa8008a23050 fffffa8008a20000 : usbhub!UsbhDispatch_BusEvent+0x20e fffff8800443a738 : fffffa8008a23050 fffffa8008a239c8
0000000000000000 0000000000000000 : usbhub!UsbhSyncBusPause+0x4f
fffff880044395ab : 0000000000000000 0000000000000001 fffff80000000003 fffffa8008a23050 : usbhub!UsbhSshSuspendHub+0xcc fffff88004439447 : 0000000000000001 0000000000000001
fffffa8008a23050 fffff800036d52b1 : usbhub!Usbh_SSH_HubActive+0x13f
fffff8800443a311 : fffffa8008a231a0 fffff8000386f5f8 fffffa8008a23050 fffffa8008a239c8 : usbhub!Usbh_SSH_Event+0x147 fffff8800440673f : fffffa8008a231a0 fffffa8008a23050
0000000000000000 0000000000000001 : usbhub!UsbhHubSSH_Worker+0x2d
fffff800039c5843 : fffffa8008a23050 fffffa80041ac040 0000000000000000 fffffa80041ac040 : usbhub!UsbhHubWorker+0x63 fffff800036d7961 : fffff800039bc400 fffff800039bc4c8
fffffa80041ac040 0000000000000000 : nt!IopProcessWorkItem+0x23
fffff8000396dbc6 : 6300650030003100 fffffa80041ac040 0000000000000080 fffffa80041975f0 : nt!ExpWorkerThread+0x111 fffff800036a8bc6 : fffff880031d3180 fffffa80041ac040
fffff880031ddfc0 0034003200440049 : nt!PspSystemThreadStartup+0x5a
0000000000000000 : fffff880033a2000 fffff8800339c000 fffff880033a13d0 0000000000000000 : nt!KiStartSystemThread+0x16 0: kd\> 3kb RetAddr : Args to Child : Call Site fffff88006617555 : 000000000000008a 0000000000000000
0000000000000002 0000000000000000 : nt!MmUnlockPages+0x39d
fffff880066175bb : fffffa800a914d10 fffffa800a914d10 fffffa80089c5460 fffffa800897ede0 : nusb3xhc+0x17555 fffff88006611a03 : fffffa800897ede0 fffffa8007955000
fffffa800a914d10 fffffa80089c5460 : nusb3xhc+0x175bb
fffff8800660e26d : fffffa8007a977b0 fffff880031d3102 fffffa80089c5460 fffffa800897ede0 : nusb3xhc+0x11a03 fffff800036d5c0c : fffff880031d3180 fffffa8007955000
fffffa800897ef90 0000000000000000 : nusb3xhc+0xe26d
fffff800036d2eea : fffff880031d3180 fffff880031ddfc0 0000000000000000 fffff8800660e180 : nt!KiRetireDpcList+0x1bc 0000000000000000 : fffff880031fc000 fffff880031f6000
fffff880031fbd40 0000000000000000 : nt!KiIdleLoop+0x5a
0: kd> 4kb
^ Range error in '4kb'

--
Tim Roberts, xxxxx@probo.com
Providenza & Boekelheide, Inc.

Christopher_Koschack · May 27, 2011, 1:59pm

Just to provide a warning.

CtClsFlt.sys is not stable.
We could trace some crashes with our USB video capture devices, back to
this driver.
(This doesn’t mean that this time, it is the culprit …)

–

Christopher Koschack

On 27.05.2011 19:35, Tim Roberts wrote:

I have a USB video camera driver (AVStream) that has been in the wild
for about 4 years. Thousands of the cameras are in real-world use.
We’ve run tens of thousands of plug/unplug tests over the years. We’ve
passed the WHQL unclassified suite many times. I’m pretty confident of
my PnP handling.

This week, we had a client report a bugcheck 0xFE on a Win 7 64-bit
system after an unplug and replug while our viewer application is
running. The bugcheck parameters are (8,6,6,x), which indicates a
timeout in the USB hub driver trying to suspend a port. They sent me a
full kernel dump (analysis below). My driver is not in the crash stack
– it’s only usbhub.sys, trying to disable a port. I’ve never seen this
before. I don’t know whether usbhub is complaining that the hardware
didn’t respond in time, or if my driver is somehow blocking the
transition. There are no outstanding IRPs for my driver.

There are two things in this dump that I find suspicious. The most
interesting thing is that we are plugged in to a USB 3 host controller.
There are 4 processors; one of them triggered the crash, one is idle,
and the other two are inside NEC’s USB 3 host controller driver
(nusb3xhc.sys).

The other suspicious thing is that there is a filter driver sitting
above me – CtClsFlt.sys, which is a video class upper filter from
Creative Technology of unknown purpose.

Has anybody with USB 3 experience seen unusual crashes? My gut
suspicion is that there are PnP corner cases that the NEC host
controller and/or hub driver are not handling, or that it is making some
assumptions that are not universally valid, but I’m not sure I know how
to validate that.

Pavel_A1 · May 27, 2011, 9:36pm

“Tim Roberts” wrote in message news:xxxxx@ntdev…
> . The bugcheck parameters are (8,6,6,x), which indicates a
> timeout in the USB hub driver trying to suspend a port.

A side note: is some problem with an USB hub a good reason for a bugcheck?
Would event log record be enough?

–pa

OSR_Community_User · May 27, 2011, 10:58pm

Of course not. We had this discussion in the past when this great feature was introduced in Vista. Apparently, a good debugging feature crept somewhat to release version and nobody was able to stop developers from doing it. In turn, from time to time I have to solve a case of bugcheck related to our USB fingerprint sensor. For me, as a developer, it is easier to analyze BSOD and say something as “race conditions in OS drivers” but I have really bad feeling if an user loses data just because s/he uses our device. Which isn’t vitally important for the rest of OS and there is no reason to destroy all the unsaved work just because it can’t be suspended for example.

@Tim: I had several reports about problems with USB3 hw and I’d bet it was the same driver as in your case (nusb3xhc.sys). Not BSOD but USB malfunction. In all cases problem was solved when USB3 driver was updated, sometimes several times. Child illnesses, I’d say. This case is also malfunction and BSOD is artificially generated because usbhub.sys didn’t receive an expected event (port status change?) in timely manner.

Michal

-----Original Message-----
From: xxxxx@lists.osr.com [mailto:bounce-456277-
xxxxx@lists.osr.com] On Behalf Of Pavel A.
Sent: Saturday, May 28, 2011 3:36 AM
To: Windows System Software Devs Interest List
Subject: Re:[ntdev] USB 3 Crash

“Tim Roberts” wrote in message news:xxxxx@ntdev…
> > . The bugcheck parameters are (8,6,6,x), which indicates a
> > timeout in the USB hub driver trying to suspend a port.
>
> A side note: is some problem with an USB hub a good reason for a bugcheck?
> Would event log record be enough?
>
> --pa
>
>
> —
> 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

NOTE: The information in this message is intended for the personal and confidential use of the designated recipient(s) named above. To the extent the recipient(s) is/are bound by a non-disclosure agreement, or other agreement that contains an obligation of confidentiality, with AuthenTec, then this message and/or any attachments shall be considered confidential information and subject to the confidentiality terms of that agreement. If the reader of this message is not the intended recipient named above, you are notified that you have received this document in error, and any review, dissemination, distribution or copying of this message is strictly prohibited. If you have received this document in error, please delete the original message and notify the sender immediately.
Thank You!
AuthenTec, Inc. http://www.authentec.com/