Windows 7 USB lockup after selective suspend resume

I have a KMDF USB driver for a network device that supports selective suspend 
(this is a two piece driver, as recommended in Doron Holan's blog).  This 
driver passes WHQL for XP and 7.  I am having problems with the x86 (x64 
untested with this scenario) Windows 7/WDF 1009 version of the driver under 
scenarios where a request is received in a power managed queue within 2-3 
milliseconds of the WDF USB driver completing its EvtDeviceD0Exit routine.  
The selective suspend timeout is set to 5 seconds.  The timeline looks 
something like this (per output from DbgView):

119.872   Last read event received
124.866   EvtDeviceSelfManagedIoSuspend routine entered
              - Continuous readers stopped (3 pipes)
              - Read request cancelled        (1 pipe)
124.867  EvtDeviceSelfManagedIoSuspend exited
124.867  EvtDeviceD0Exit entered
124.867  EvtDeviceD0Exit exited

< Driver in selected suspend state at this point>

124.868  Write request sent to power management queue
124.973  Power management write queue handler entered
124.973  Write request forwarded to USB pipe IO target
124.973  Power management write queue handler exited
124.973  EvtDeviceSelfManagedIoRestart entered
124.973  Reader for pipe #1 restarted
124.973  Write completion callback entered with result of 0xc0000001
124.973  Write completion callback completes request
124.973  Write completion callback exited
124.974  Reader for pipe #2 restarted
124.974  Reader for pipe #3 restarted
124.974  Read request posted to pipe #4
124.974  EvtDeviceSelfManagedIoRestart exited

< Driver out of selected suspend state at this point>

124.974  Read completion callback entered with result of 0xc0000001 for pipe 
#4
124.974  Read completion callback exited
124.974  Reader for pipe #1 fail callback entered with error code 0xc0000001.
124.974  Reader for pipe #1 fail callback exited with TRUE to restart reader.
124.974  Reader for pipe #2 fail callback entered with error code 0xc0000001.
124.974  Reader for pipe #2 fail callback exited with TRUE to restart reader.
124.974  Reader for pipe #3 fail callback entered with error code 0xc0000001.
124.974  Reader for pipe #3 fail callback exited with TRUE to restart reader.
129.971   EvtDeviceSelfManagedIoSuspend routine entered
              - Continuous readers stopped (3 pipes)
129.971  EvtDeviceSelfManagedIoSuspend exited
129.971  EvtDeviceD0Exit entered
129.971  EvtDeviceD0Exit exited

< Driver in selected suspend state at this point>

130.381  Write request sent to power management queue
130.518  Power management write queue handler entered
130.518  Request forwarded to USB pipe IO target
130.518  Power management write queue handler exited
130.518  EvtDeviceSelfManagedIoRestart entered
130.518  Reader for pipe #1 restarted
130.519  Reader for pipe #2 restarted
130.519  Reader for pipe #3 restarted
130.519  Read request posted to pipe #4, but returns error of 0xc0000120
130.519  EvtDeviceSelfManagedIoRestart exited

The write that was posted on 130.381 never completes, nor does any 
subsequent write request.  Eventually the driver runs out of transmit 
buffers.  When the device is unplugged, all pending write requests are 
comleted with a status of 0xc0000120.

I connected an Ellisys USB analyzer to confirm that the issue was not with 
my device.  I did notice a bit of an oddity on the USB side which seems to 
correspond with the above failure.  The timestamps here don't match up 
exactly with the above, as I started DbgView a few seconds after the USB 
analyzer:

110.811  Bulk transfer
115.805  SetFeature(RemoteWakeup) sent to device

<15.5 milliseconds of selective suspend>

115.960  ClearFeature(RemoteWakeup) sent to device
115.961  Bulk transfer
.....
126.034  Bulk transfer
131.032  SetFeature(RemoteWakeup) sent to device

<5.5 seconds of selective suspend>

136.684 ClearFeature(RemoteWakeup) sent to device

After the last "ClearFeature", there is no further read or write requests 
made on any endpoint, i.e. the readers are not doing their job and the writes 
are never sent (no NAKs are present).  At this point, the only recovery is to 
unplug the USB device and re-insert the USB device.  A reboot is not 
necessary to recover from this situation.  This scenario is very easy to 
reproduce and is not simply some corner scenario.

The data rate is very low when this occurs, a six packet burst of 30 bytes 
or so every five seconds.  It is a USB 2.0 device and enumerates as such.  If 
I shut off selective suspend, I do not run into any issues.  I have also 
downloaded the latest updates from the Microsoft web site for Windows 7.

What is the problem here?  Is there a solution, short of disabling selective 
suspend?

Thanks,
Michael
0
Utf
12/16/2009 8:35:01 PM
development.device.drivers 941 articles. 0 followers. Follow

11 Replies
1379 Views

Similar Articles

[PageSpeed] 20

Hi Michael,

You can send me a USB ETW trace and I'll see if it shows anything 
interesting.  Instructions here: 
http://blogs.msdn.com/usbcoreblog/archive/2009/12/04/etw-in-the-windows-7-usb-core-stack.aspx
You can also look through the trace yourself using the latter part of 
the instructions.

I'd also be interested to see the DbgView output like below for a 
successful resume from selective suspend for a write and then return to 
selective suspend.

Philip

dhmot wrote:
> I have a KMDF USB driver for a network device that supports selective suspend 
> (this is a two piece driver, as recommended in Doron Holan's blog).  This 
> driver passes WHQL for XP and 7.  I am having problems with the x86 (x64 
> untested with this scenario) Windows 7/WDF 1009 version of the driver under 
> scenarios where a request is received in a power managed queue within 2-3 
> milliseconds of the WDF USB driver completing its EvtDeviceD0Exit routine.  
> The selective suspend timeout is set to 5 seconds.  The timeline looks 
> something like this (per output from DbgView):
> 
> 119.872   Last read event received
> 124.866   EvtDeviceSelfManagedIoSuspend routine entered
>               - Continuous readers stopped (3 pipes)
>               - Read request cancelled        (1 pipe)
> 124.867  EvtDeviceSelfManagedIoSuspend exited
> 124.867  EvtDeviceD0Exit entered
> 124.867  EvtDeviceD0Exit exited
> 
> < Driver in selected suspend state at this point>
> 
> 124.868  Write request sent to power management queue
> 124.973  Power management write queue handler entered
> 124.973  Write request forwarded to USB pipe IO target
> 124.973  Power management write queue handler exited
> 124.973  EvtDeviceSelfManagedIoRestart entered
> 124.973  Reader for pipe #1 restarted
> 124.973  Write completion callback entered with result of 0xc0000001
> 124.973  Write completion callback completes request
> 124.973  Write completion callback exited
> 124.974  Reader for pipe #2 restarted
> 124.974  Reader for pipe #3 restarted
> 124.974  Read request posted to pipe #4
> 124.974  EvtDeviceSelfManagedIoRestart exited
> 
> < Driver out of selected suspend state at this point>
> 
> 124.974  Read completion callback entered with result of 0xc0000001 for pipe 
> #4
> 124.974  Read completion callback exited
> 124.974  Reader for pipe #1 fail callback entered with error code 0xc0000001.
> 124.974  Reader for pipe #1 fail callback exited with TRUE to restart reader.
> 124.974  Reader for pipe #2 fail callback entered with error code 0xc0000001.
> 124.974  Reader for pipe #2 fail callback exited with TRUE to restart reader.
> 124.974  Reader for pipe #3 fail callback entered with error code 0xc0000001.
> 124.974  Reader for pipe #3 fail callback exited with TRUE to restart reader.
> 129.971   EvtDeviceSelfManagedIoSuspend routine entered
>               - Continuous readers stopped (3 pipes)
> 129.971  EvtDeviceSelfManagedIoSuspend exited
> 129.971  EvtDeviceD0Exit entered
> 129.971  EvtDeviceD0Exit exited
> 
> < Driver in selected suspend state at this point>
> 
> 130.381  Write request sent to power management queue
> 130.518  Power management write queue handler entered
> 130.518  Request forwarded to USB pipe IO target
> 130.518  Power management write queue handler exited
> 130.518  EvtDeviceSelfManagedIoRestart entered
> 130.518  Reader for pipe #1 restarted
> 130.519  Reader for pipe #2 restarted
> 130.519  Reader for pipe #3 restarted
> 130.519  Read request posted to pipe #4, but returns error of 0xc0000120
> 130.519  EvtDeviceSelfManagedIoRestart exited
> 
> The write that was posted on 130.381 never completes, nor does any 
> subsequent write request.  Eventually the driver runs out of transmit 
> buffers.  When the device is unplugged, all pending write requests are 
> comleted with a status of 0xc0000120.
> 
> I connected an Ellisys USB analyzer to confirm that the issue was not with 
> my device.  I did notice a bit of an oddity on the USB side which seems to 
> correspond with the above failure.  The timestamps here don't match up 
> exactly with the above, as I started DbgView a few seconds after the USB 
> analyzer:
> 
> 110.811  Bulk transfer
> 115.805  SetFeature(RemoteWakeup) sent to device
> 
> <15.5 milliseconds of selective suspend>
> 
> 115.960  ClearFeature(RemoteWakeup) sent to device
> 115.961  Bulk transfer
> .....
> 126.034  Bulk transfer
> 131.032  SetFeature(RemoteWakeup) sent to device
> 
> <5.5 seconds of selective suspend>
> 
> 136.684 ClearFeature(RemoteWakeup) sent to device
> 
> After the last "ClearFeature", there is no further read or write requests 
> made on any endpoint, i.e. the readers are not doing their job and the writes 
> are never sent (no NAKs are present).  At this point, the only recovery is to 
> unplug the USB device and re-insert the USB device.  A reboot is not 
> necessary to recover from this situation.  This scenario is very easy to 
> reproduce and is not simply some corner scenario.
> 
> The data rate is very low when this occurs, a six packet burst of 30 bytes 
> or so every five seconds.  It is a USB 2.0 device and enumerates as such.  If 
> I shut off selective suspend, I do not run into any issues.  I have also 
> downloaded the latest updates from the Microsoft web site for Windows 7.
> 
> What is the problem here?  Is there a solution, short of disabling selective 
> suspend?
> 
> Thanks,
> Michael
0
Philip
12/18/2009 2:27:19 AM
Philip,

I've emailed you the USB trace.  One odd thing is that I noticed is that 
none of my power management callbacks were invoked this time, or at least 
none showed up in DbgView this time.  But the result is the same - the USB 
driver hangs on the send requests and does not request data from the USB 
device.  However, it does appear from the trace that there was an attempt to 
enter selective suspend at 188.505.

One other point I did not mention, but the driver's execution level 
(ExecutionLevel) is set to WdfExecutionLevelPassive.  I do not know if this 
is pertinent.

Here's the output of a good selective suspend under Windows 7.  FYI, I do 
hand-edit for clarity:
 
------------------------
 5.783  Last read event received
10.783  EvtDeviceSelfManagedIoSuspend routine entered
        - Continuous readers stopped (3 pipes)
        - Read request cancelled (1 pipe) 
10.785  EvtDeviceSelfManagedIoSuspend routine exited
10.785  EvtDeviceD0Exit routine entered
10.785  EvtDeviceD0Exit routine exited

< Driver in selected suspend state at this point>

21.938  Write request sent to power management queue  
22.057  Power management write queue handler entered 
22.057  Write request forwarded to USB pipe IO target
22.057  Power management write queue handler exited 
22.057  EvtDeviceSelfManagedIoRestart routine entered
22.058  Reader for pipe #1 restarted 
22.058  Write completion callback entered with no error
22.058  Write completion callback completes request
22.058  Write completion callback exited
22.058  Reader for pipe #2 restarted
22.058  Reader for pipe #3 restarted
22.058  Read request posted to pipe #4
22.058  EvtDeviceSelfManagedIoRestart routine exited

< Driver out of selected suspend state at this point>

22.153  Read completion callback entered with no error
22.153  Read completion callback exited
23.018  Last read event received
28.018  EvtDeviceSelfManagedIoSuspend routine entered
        - Continuous readers stopped (3 pipes)
        - Read request cancelled (1 pipe)
28.019  EvtDeviceSelfManagedIoSuspend routine exited
28.019  EvtDeviceD0Exit routine entered
28.019  EvtDeviceD0Exit routine exited

< Driver in selected suspend state at this point>
------------------------

Let me know if you want any further information.  Note that I will be on 
vacation starting tomorrow until the end of December or beginning of January.

Thanks,
Michael


"Philip Ries [MSFT]" wrote:

> Hi Michael,
> 
> You can send me a USB ETW trace and I'll see if it shows anything 
> interesting.  Instructions here: 
> http://blogs.msdn.com/usbcoreblog/archive/2009/12/04/etw-in-the-windows-7-usb-core-stack.aspx
> You can also look through the trace yourself using the latter part of 
> the instructions.
> 
> I'd also be interested to see the DbgView output like below for a 
> successful resume from selective suspend for a write and then return to 
> selective suspend.
> 
> Philip
> 
> dhmot wrote:
> > I have a KMDF USB driver for a network device that supports selective suspend 
> > (this is a two piece driver, as recommended in Doron Holan's blog).  This 
> > driver passes WHQL for XP and 7.  I am having problems with the x86 (x64 
> > untested with this scenario) Windows 7/WDF 1009 version of the driver under 
> > scenarios where a request is received in a power managed queue within 2-3 
> > milliseconds of the WDF USB driver completing its EvtDeviceD0Exit routine.  
> > The selective suspend timeout is set to 5 seconds.  The timeline looks 
> > something like this (per output from DbgView):
> > 
> > 119.872   Last read event received
> > 124.866   EvtDeviceSelfManagedIoSuspend routine entered
> >               - Continuous readers stopped (3 pipes)
> >               - Read request cancelled        (1 pipe)
> > 124.867  EvtDeviceSelfManagedIoSuspend exited
> > 124.867  EvtDeviceD0Exit entered
> > 124.867  EvtDeviceD0Exit exited
> > 
> > < Driver in selected suspend state at this point>
> > 
> > 124.868  Write request sent to power management queue
> > 124.973  Power management write queue handler entered
> > 124.973  Write request forwarded to USB pipe IO target
> > 124.973  Power management write queue handler exited
> > 124.973  EvtDeviceSelfManagedIoRestart entered
> > 124.973  Reader for pipe #1 restarted
> > 124.973  Write completion callback entered with result of 0xc0000001
> > 124.973  Write completion callback completes request
> > 124.973  Write completion callback exited
> > 124.974  Reader for pipe #2 restarted
> > 124.974  Reader for pipe #3 restarted
> > 124.974  Read request posted to pipe #4
> > 124.974  EvtDeviceSelfManagedIoRestart exited
> > 
> > < Driver out of selected suspend state at this point>
> > 
> > 124.974  Read completion callback entered with result of 0xc0000001 for pipe 
> > #4
> > 124.974  Read completion callback exited
> > 124.974  Reader for pipe #1 fail callback entered with error code 0xc0000001.
> > 124.974  Reader for pipe #1 fail callback exited with TRUE to restart reader.
> > 124.974  Reader for pipe #2 fail callback entered with error code 0xc0000001.
> > 124.974  Reader for pipe #2 fail callback exited with TRUE to restart reader.
> > 124.974  Reader for pipe #3 fail callback entered with error code 0xc0000001.
> > 124.974  Reader for pipe #3 fail callback exited with TRUE to restart reader.
> > 129.971   EvtDeviceSelfManagedIoSuspend routine entered
> >               - Continuous readers stopped (3 pipes)
> > 129.971  EvtDeviceSelfManagedIoSuspend exited
> > 129.971  EvtDeviceD0Exit entered
> > 129.971  EvtDeviceD0Exit exited
> > 
> > < Driver in selected suspend state at this point>
> > 
> > 130.381  Write request sent to power management queue
> > 130.518  Power management write queue handler entered
> > 130.518  Request forwarded to USB pipe IO target
> > 130.518  Power management write queue handler exited
> > 130.518  EvtDeviceSelfManagedIoRestart entered
> > 130.518  Reader for pipe #1 restarted
> > 130.519  Reader for pipe #2 restarted
> > 130.519  Reader for pipe #3 restarted
> > 130.519  Read request posted to pipe #4, but returns error of 0xc0000120
> > 130.519  EvtDeviceSelfManagedIoRestart exited
> > 
> > The write that was posted on 130.381 never completes, nor does any 
> > subsequent write request.  Eventually the driver runs out of transmit 
> > buffers.  When the device is unplugged, all pending write requests are 
> > comleted with a status of 0xc0000120.
> > 
> > I connected an Ellisys USB analyzer to confirm that the issue was not with 
> > my device.  I did notice a bit of an oddity on the USB side which seems to 
> > correspond with the above failure.  The timestamps here don't match up 
> > exactly with the above, as I started DbgView a few seconds after the USB 
> > analyzer:
> > 
> > 110.811  Bulk transfer
> > 115.805  SetFeature(RemoteWakeup) sent to device
> > 
> > <15.5 milliseconds of selective suspend>
> > 
> > 115.960  ClearFeature(RemoteWakeup) sent to device
> > 115.961  Bulk transfer
> > .....
> > 126.034  Bulk transfer
> > 131.032  SetFeature(RemoteWakeup) sent to device
> > 
> > <5.5 seconds of selective suspend>
> > 
> > 136.684 ClearFeature(RemoteWakeup) sent to device
> > 
> > After the last "ClearFeature", there is no further read or write requests 
> > made on any endpoint, i.e. the readers are not doing their job and the writes 
> > are never sent (no NAKs are present).  At this point, the only recovery is to 
> > unplug the USB device and re-insert the USB device.  A reboot is not 
> > necessary to recover from this situation.  This scenario is very easy to 
> > reproduce and is not simply some corner scenario.
> > 
> > The data rate is very low when this occurs, a six packet burst of 30 bytes 
> > or so every five seconds.  It is a USB 2.0 device and enumerates as such.  If 
> > I shut off selective suspend, I do not run into any issues.  I have also 
> > downloaded the latest updates from the Microsoft web site for Windows 7.
> > 
> > What is the problem here?  Is there a solution, short of disabling selective 
> > suspend?
> > 
> > Thanks,
> > Michael
> .
> 
0
Utf
12/18/2009 9:29:02 PM
The device didn't come out of suspend successfully the third time.  I 
would try to repro with the device behind an external hub.  If you can't 
repro there then it may be a known issue with the EHCI driver.  This 
issue has a QFE (fix) under consideration.

If you'd like to get the QFE as soon as possible, please contact 
Microsoft support (some instructions pasted below).  The KB number for 
this issue will be 978258, you can refer to this number in the support case.

Thanks,
Philip

For more information on how to open a Windows Driver Kit (WDK) service 
request in order to receive USB driver development support, please click 
or copy the below link:

http://support.microsoft.com/select/?LN=en-us&target=assistance&x=13&y=9

In the “Quick product finder” field, type “Windows Driver Kit” as the 
product and select that product

dhmot wrote:
> Philip,
> 
> I've emailed you the USB trace.  One odd thing is that I noticed is that 
> none of my power management callbacks were invoked this time, or at least 
> none showed up in DbgView this time.  But the result is the same - the USB 
> driver hangs on the send requests and does not request data from the USB 
> device.  However, it does appear from the trace that there was an attempt to 
> enter selective suspend at 188.505.
> 
> One other point I did not mention, but the driver's execution level 
> (ExecutionLevel) is set to WdfExecutionLevelPassive.  I do not know if this 
> is pertinent.
> 
> Here's the output of a good selective suspend under Windows 7.  FYI, I do 
> hand-edit for clarity:
>  
> ------------------------
>  5.783  Last read event received
> 10.783  EvtDeviceSelfManagedIoSuspend routine entered
>         - Continuous readers stopped (3 pipes)
>         - Read request cancelled (1 pipe) 
> 10.785  EvtDeviceSelfManagedIoSuspend routine exited
> 10.785  EvtDeviceD0Exit routine entered
> 10.785  EvtDeviceD0Exit routine exited
> 
> < Driver in selected suspend state at this point>
> 
> 21.938  Write request sent to power management queue  
> 22.057  Power management write queue handler entered 
> 22.057  Write request forwarded to USB pipe IO target
> 22.057  Power management write queue handler exited 
> 22.057  EvtDeviceSelfManagedIoRestart routine entered
> 22.058  Reader for pipe #1 restarted 
> 22.058  Write completion callback entered with no error
> 22.058  Write completion callback completes request
> 22.058  Write completion callback exited
> 22.058  Reader for pipe #2 restarted
> 22.058  Reader for pipe #3 restarted
> 22.058  Read request posted to pipe #4
> 22.058  EvtDeviceSelfManagedIoRestart routine exited
> 
> < Driver out of selected suspend state at this point>
> 
> 22.153  Read completion callback entered with no error
> 22.153  Read completion callback exited
> 23.018  Last read event received
> 28.018  EvtDeviceSelfManagedIoSuspend routine entered
>         - Continuous readers stopped (3 pipes)
>         - Read request cancelled (1 pipe)
> 28.019  EvtDeviceSelfManagedIoSuspend routine exited
> 28.019  EvtDeviceD0Exit routine entered
> 28.019  EvtDeviceD0Exit routine exited
> 
> < Driver in selected suspend state at this point>
> ------------------------
> 
> Let me know if you want any further information.  Note that I will be on 
> vacation starting tomorrow until the end of December or beginning of January.
> 
> Thanks,
> Michael
> 
> 
> "Philip Ries [MSFT]" wrote:
> 
>> Hi Michael,
>>
>> You can send me a USB ETW trace and I'll see if it shows anything 
>> interesting.  Instructions here: 
>> http://blogs.msdn.com/usbcoreblog/archive/2009/12/04/etw-in-the-windows-7-usb-core-stack.aspx
>> You can also look through the trace yourself using the latter part of 
>> the instructions.
>>
>> I'd also be interested to see the DbgView output like below for a 
>> successful resume from selective suspend for a write and then return to 
>> selective suspend.
>>
>> Philip
>>
>> dhmot wrote:
>>> I have a KMDF USB driver for a network device that supports selective suspend 
>>> (this is a two piece driver, as recommended in Doron Holan's blog).  This 
>>> driver passes WHQL for XP and 7.  I am having problems with the x86 (x64 
>>> untested with this scenario) Windows 7/WDF 1009 version of the driver under 
>>> scenarios where a request is received in a power managed queue within 2-3 
>>> milliseconds of the WDF USB driver completing its EvtDeviceD0Exit routine.  
>>> The selective suspend timeout is set to 5 seconds.  The timeline looks 
>>> something like this (per output from DbgView):
>>>
>>> 119.872   Last read event received
>>> 124.866   EvtDeviceSelfManagedIoSuspend routine entered
>>>               - Continuous readers stopped (3 pipes)
>>>               - Read request cancelled        (1 pipe)
>>> 124.867  EvtDeviceSelfManagedIoSuspend exited
>>> 124.867  EvtDeviceD0Exit entered
>>> 124.867  EvtDeviceD0Exit exited
>>>
>>> < Driver in selected suspend state at this point>
>>>
>>> 124.868  Write request sent to power management queue
>>> 124.973  Power management write queue handler entered
>>> 124.973  Write request forwarded to USB pipe IO target
>>> 124.973  Power management write queue handler exited
>>> 124.973  EvtDeviceSelfManagedIoRestart entered
>>> 124.973  Reader for pipe #1 restarted
>>> 124.973  Write completion callback entered with result of 0xc0000001
>>> 124.973  Write completion callback completes request
>>> 124.973  Write completion callback exited
>>> 124.974  Reader for pipe #2 restarted
>>> 124.974  Reader for pipe #3 restarted
>>> 124.974  Read request posted to pipe #4
>>> 124.974  EvtDeviceSelfManagedIoRestart exited
>>>
>>> < Driver out of selected suspend state at this point>
>>>
>>> 124.974  Read completion callback entered with result of 0xc0000001 for pipe 
>>> #4
>>> 124.974  Read completion callback exited
>>> 124.974  Reader for pipe #1 fail callback entered with error code 0xc0000001.
>>> 124.974  Reader for pipe #1 fail callback exited with TRUE to restart reader.
>>> 124.974  Reader for pipe #2 fail callback entered with error code 0xc0000001.
>>> 124.974  Reader for pipe #2 fail callback exited with TRUE to restart reader.
>>> 124.974  Reader for pipe #3 fail callback entered with error code 0xc0000001.
>>> 124.974  Reader for pipe #3 fail callback exited with TRUE to restart reader.
>>> 129.971   EvtDeviceSelfManagedIoSuspend routine entered
>>>               - Continuous readers stopped (3 pipes)
>>> 129.971  EvtDeviceSelfManagedIoSuspend exited
>>> 129.971  EvtDeviceD0Exit entered
>>> 129.971  EvtDeviceD0Exit exited
>>>
>>> < Driver in selected suspend state at this point>
>>>
>>> 130.381  Write request sent to power management queue
>>> 130.518  Power management write queue handler entered
>>> 130.518  Request forwarded to USB pipe IO target
>>> 130.518  Power management write queue handler exited
>>> 130.518  EvtDeviceSelfManagedIoRestart entered
>>> 130.518  Reader for pipe #1 restarted
>>> 130.519  Reader for pipe #2 restarted
>>> 130.519  Reader for pipe #3 restarted
>>> 130.519  Read request posted to pipe #4, but returns error of 0xc0000120
>>> 130.519  EvtDeviceSelfManagedIoRestart exited
>>>
>>> The write that was posted on 130.381 never completes, nor does any 
>>> subsequent write request.  Eventually the driver runs out of transmit 
>>> buffers.  When the device is unplugged, all pending write requests are 
>>> comleted with a status of 0xc0000120.
>>>
>>> I connected an Ellisys USB analyzer to confirm that the issue was not with 
>>> my device.  I did notice a bit of an oddity on the USB side which seems to 
>>> correspond with the above failure.  The timestamps here don't match up 
>>> exactly with the above, as I started DbgView a few seconds after the USB 
>>> analyzer:
>>>
>>> 110.811  Bulk transfer
>>> 115.805  SetFeature(RemoteWakeup) sent to device
>>>
>>> <15.5 milliseconds of selective suspend>
>>>
>>> 115.960  ClearFeature(RemoteWakeup) sent to device
>>> 115.961  Bulk transfer
>>> .....
>>> 126.034  Bulk transfer
>>> 131.032  SetFeature(RemoteWakeup) sent to device
>>>
>>> <5.5 seconds of selective suspend>
>>>
>>> 136.684 ClearFeature(RemoteWakeup) sent to device
>>>
>>> After the last "ClearFeature", there is no further read or write requests 
>>> made on any endpoint, i.e. the readers are not doing their job and the writes 
>>> are never sent (no NAKs are present).  At this point, the only recovery is to 
>>> unplug the USB device and re-insert the USB device.  A reboot is not 
>>> necessary to recover from this situation.  This scenario is very easy to 
>>> reproduce and is not simply some corner scenario.
>>>
>>> The data rate is very low when this occurs, a six packet burst of 30 bytes 
>>> or so every five seconds.  It is a USB 2.0 device and enumerates as such.  If 
>>> I shut off selective suspend, I do not run into any issues.  I have also 
>>> downloaded the latest updates from the Microsoft web site for Windows 7.
>>>
>>> What is the problem here?  Is there a solution, short of disabling selective 
>>> suspend?
>>>
>>> Thanks,
>>> Michael
>> .
>>
0
Philip
12/19/2009 2:11:16 AM
Philip,

I was unable to reproduce the problem after placing the device in an 
external, powered USB hub.  It seems then that the problem is related to 
KB978258. I will work through Microsoft support based on your information 
below.

Thanks,
Michael

"Philip Ries [MSFT]" wrote:

> The device didn't come out of suspend successfully the third time.  I 
> would try to repro with the device behind an external hub.  If you can't 
> repro there then it may be a known issue with the EHCI driver.  This 
> issue has a QFE (fix) under consideration.
> 
> If you'd like to get the QFE as soon as possible, please contact 
> Microsoft support (some instructions pasted below).  The KB number for 
> this issue will be 978258, you can refer to this number in the support case.
> 
> Thanks,
> Philip
> 
> For more information on how to open a Windows Driver Kit (WDK) service 
> request in order to receive USB driver development support, please click 
> or copy the below link:
> 
> http://support.microsoft.com/select/?LN=en-us&target=assistance&x=13&y=9
> 
> In the “Quick product finder” field, type “Windows Driver Kit” as the 
> product and select that product
> 
> dhmot wrote:
> > Philip,
> > 
> > I've emailed you the USB trace.  One odd thing is that I noticed is that 
> > none of my power management callbacks were invoked this time, or at least 
> > none showed up in DbgView this time.  But the result is the same - the USB 
> > driver hangs on the send requests and does not request data from the USB 
> > device.  However, it does appear from the trace that there was an attempt to 
> > enter selective suspend at 188.505.
> > 
> > One other point I did not mention, but the driver's execution level 
> > (ExecutionLevel) is set to WdfExecutionLevelPassive.  I do not know if this 
> > is pertinent.
> > 
> > Here's the output of a good selective suspend under Windows 7.  FYI, I do 
> > hand-edit for clarity:
> >  
> > ------------------------
> >  5.783  Last read event received
> > 10.783  EvtDeviceSelfManagedIoSuspend routine entered
> >         - Continuous readers stopped (3 pipes)
> >         - Read request cancelled (1 pipe) 
> > 10.785  EvtDeviceSelfManagedIoSuspend routine exited
> > 10.785  EvtDeviceD0Exit routine entered
> > 10.785  EvtDeviceD0Exit routine exited
> > 
> > < Driver in selected suspend state at this point>
> > 
> > 21.938  Write request sent to power management queue  
> > 22.057  Power management write queue handler entered 
> > 22.057  Write request forwarded to USB pipe IO target
> > 22.057  Power management write queue handler exited 
> > 22.057  EvtDeviceSelfManagedIoRestart routine entered
> > 22.058  Reader for pipe #1 restarted 
> > 22.058  Write completion callback entered with no error
> > 22.058  Write completion callback completes request
> > 22.058  Write completion callback exited
> > 22.058  Reader for pipe #2 restarted
> > 22.058  Reader for pipe #3 restarted
> > 22.058  Read request posted to pipe #4
> > 22.058  EvtDeviceSelfManagedIoRestart routine exited
> > 
> > < Driver out of selected suspend state at this point>
> > 
> > 22.153  Read completion callback entered with no error
> > 22.153  Read completion callback exited
> > 23.018  Last read event received
> > 28.018  EvtDeviceSelfManagedIoSuspend routine entered
> >         - Continuous readers stopped (3 pipes)
> >         - Read request cancelled (1 pipe)
> > 28.019  EvtDeviceSelfManagedIoSuspend routine exited
> > 28.019  EvtDeviceD0Exit routine entered
> > 28.019  EvtDeviceD0Exit routine exited
> > 
> > < Driver in selected suspend state at this point>
> > ------------------------
> > 
> > Let me know if you want any further information.  Note that I will be on 
> > vacation starting tomorrow until the end of December or beginning of January.
> > 
> > Thanks,
> > Michael
> > 
> > 
> > "Philip Ries [MSFT]" wrote:
> > 
> >> Hi Michael,
> >>
> >> You can send me a USB ETW trace and I'll see if it shows anything 
> >> interesting.  Instructions here: 
> >> http://blogs.msdn.com/usbcoreblog/archive/2009/12/04/etw-in-the-windows-7-usb-core-stack.aspx
> >> You can also look through the trace yourself using the latter part of 
> >> the instructions.
> >>
> >> I'd also be interested to see the DbgView output like below for a 
> >> successful resume from selective suspend for a write and then return to 
> >> selective suspend.
> >>
> >> Philip
> >>
> >> dhmot wrote:
> >>> I have a KMDF USB driver for a network device that supports selective suspend 
> >>> (this is a two piece driver, as recommended in Doron Holan's blog).  This 
> >>> driver passes WHQL for XP and 7.  I am having problems with the x86 (x64 
> >>> untested with this scenario) Windows 7/WDF 1009 version of the driver under 
> >>> scenarios where a request is received in a power managed queue within 2-3 
> >>> milliseconds of the WDF USB driver completing its EvtDeviceD0Exit routine.  
> >>> The selective suspend timeout is set to 5 seconds.  The timeline looks 
> >>> something like this (per output from DbgView):
> >>>
> >>> 119.872   Last read event received
> >>> 124.866   EvtDeviceSelfManagedIoSuspend routine entered
> >>>               - Continuous readers stopped (3 pipes)
> >>>               - Read request cancelled        (1 pipe)
> >>> 124.867  EvtDeviceSelfManagedIoSuspend exited
> >>> 124.867  EvtDeviceD0Exit entered
> >>> 124.867  EvtDeviceD0Exit exited
> >>>
> >>> < Driver in selected suspend state at this point>
> >>>
> >>> 124.868  Write request sent to power management queue
> >>> 124.973  Power management write queue handler entered
> >>> 124.973  Write request forwarded to USB pipe IO target
> >>> 124.973  Power management write queue handler exited
> >>> 124.973  EvtDeviceSelfManagedIoRestart entered
> >>> 124.973  Reader for pipe #1 restarted
> >>> 124.973  Write completion callback entered with result of 0xc0000001
> >>> 124.973  Write completion callback completes request
> >>> 124.973  Write completion callback exited
> >>> 124.974  Reader for pipe #2 restarted
> >>> 124.974  Reader for pipe #3 restarted
> >>> 124.974  Read request posted to pipe #4
> >>> 124.974  EvtDeviceSelfManagedIoRestart exited
> >>>
> >>> < Driver out of selected suspend state at this point>
> >>>
> >>> 124.974  Read completion callback entered with result of 0xc0000001 for pipe 
> >>> #4
> >>> 124.974  Read completion callback exited
> >>> 124.974  Reader for pipe #1 fail callback entered with error code 0xc0000001.
> >>> 124.974  Reader for pipe #1 fail callback exited with TRUE to restart reader.
> >>> 124.974  Reader for pipe #2 fail callback entered with error code 0xc0000001.
> >>> 124.974  Reader for pipe #2 fail callback exited with TRUE to restart reader.
> >>> 124.974  Reader for pipe #3 fail callback entered with error code 0xc0000001.
> >>> 124.974  Reader for pipe #3 fail callback exited with TRUE to restart reader.
> >>> 129.971   EvtDeviceSelfManagedIoSuspend routine entered
> >>>               - Continuous readers stopped (3 pipes)
> >>> 129.971  EvtDeviceSelfManagedIoSuspend exited
> >>> 129.971  EvtDeviceD0Exit entered
> >>> 129.971  EvtDeviceD0Exit exited
> >>>
> >>> < Driver in selected suspend state at this point>
> >>>
> >>> 130.381  Write request sent to power management queue
> >>> 130.518  Power management write queue handler entered
> >>> 130.518  Request forwarded to USB pipe IO target
> >>> 130.518  Power management write queue handler exited
> >>> 130.518  EvtDeviceSelfManagedIoRestart entered
> >>> 130.518  Reader for pipe #1 restarted
> >>> 130.519  Reader for pipe #2 restarted
> >>> 130.519  Reader for pipe #3 restarted
> >>> 130.519  Read request posted to pipe #4, but returns error of 0xc0000120
> >>> 130.519  EvtDeviceSelfManagedIoRestart exited
> >>>
> >>> The write that was posted on 130.381 never completes, nor does any 
> >>> subsequent write request.  Eventually the driver runs out of transmit 
> >>> buffers.  When the device is unplugged, all pending write requests are 
> >>> comleted with a status of 0xc0000120.
> >>>
> >>> I connected an Ellisys USB analyzer to confirm that the issue was not with 
> >>> my device.  I did notice a bit of an oddity on the USB side which seems to 
> >>> correspond with the above failure.  The timestamps here don't match up 
> >>> exactly with the above, as I started DbgView a few seconds after the USB 
> >>> analyzer:
> >>>
> >>> 110.811  Bulk transfer
> >>> 115.805  SetFeature(RemoteWakeup) sent to device
> >>>
> >>> <15.5 milliseconds of selective suspend>
> >>>
> >>> 115.960  ClearFeature(RemoteWakeup) sent to device
> >>> 115.961  Bulk transfer
> >>> .....
> >>> 126.034  Bulk transfer
> >>> 131.032  SetFeature(RemoteWakeup) sent to device
> >>>
> >>> <5.5 seconds of selective suspend>
> >>>
> >>> 136.684 ClearFeature(RemoteWakeup) sent to device
> >>>
> >>> After the last "ClearFeature", there is no further read or write requests 
> >>> made on any endpoint, i.e. the readers are not doing their job and the writes 
> >>> are never sent (no NAKs are present).  At this point, the only recovery is to 
> >>> unplug the USB device and re-insert the USB device.  A reboot is not 
> >>> necessary to recover from this situation.  This scenario is very easy to 
> >>> reproduce and is not simply some corner scenario.
> >>>
> >>> The data rate is very low when this occurs, a six packet burst of 30 bytes 
> >>> or so every five seconds.  It is a USB 2.0 device and enumerates as such.  If 
> >>> I shut off selective suspend, I do not run into any issues.  I have also 
> >>> downloaded the latest updates from the Microsoft web site for Windows 7.
> >>>
> >>> What is the problem here?  Is there a solution, short of disabling selective 
> >>> suspend?
> >>>
> >>> Thanks,
> >>> Michael
> >> .
> >>
> .
> 
0
Utf
1/5/2010 8:01:01 PM
Philip,

When I moved the device to a powered external USB hub, the problem no longer 
occurred.  I will attempt to get information on the KB through support.

Thanks,
Michael

"Philip Ries [MSFT]" wrote:

> The device didn't come out of suspend successfully the third time.  I 
> would try to repro with the device behind an external hub.  If you can't 
> repro there then it may be a known issue with the EHCI driver.  This 
> issue has a QFE (fix) under consideration.
> 
> If you'd like to get the QFE as soon as possible, please contact 
> Microsoft support (some instructions pasted below).  The KB number for 
> this issue will be 978258, you can refer to this number in the support case.
> 
> Thanks,
> Philip
> 
> For more information on how to open a Windows Driver Kit (WDK) service 
> request in order to receive USB driver development support, please click 
> or copy the below link:
> 
> http://support.microsoft.com/select/?LN=en-us&target=assistance&x=13&y=9
> 
> In the “Quick product finder” field, type “Windows Driver Kit” as the 
> product and select that product
> 
> dhmot wrote:
> > Philip,
> > 
> > I've emailed you the USB trace.  One odd thing is that I noticed is that 
> > none of my power management callbacks were invoked this time, or at least 
> > none showed up in DbgView this time.  But the result is the same - the USB 
> > driver hangs on the send requests and does not request data from the USB 
> > device.  However, it does appear from the trace that there was an attempt to 
> > enter selective suspend at 188.505.
> > 
> > One other point I did not mention, but the driver's execution level 
> > (ExecutionLevel) is set to WdfExecutionLevelPassive.  I do not know if this 
> > is pertinent.
> > 
> > Here's the output of a good selective suspend under Windows 7.  FYI, I do 
> > hand-edit for clarity:
> >  
> > ------------------------
> >  5.783  Last read event received
> > 10.783  EvtDeviceSelfManagedIoSuspend routine entered
> >         - Continuous readers stopped (3 pipes)
> >         - Read request cancelled (1 pipe) 
> > 10.785  EvtDeviceSelfManagedIoSuspend routine exited
> > 10.785  EvtDeviceD0Exit routine entered
> > 10.785  EvtDeviceD0Exit routine exited
> > 
> > < Driver in selected suspend state at this point>
> > 
> > 21.938  Write request sent to power management queue  
> > 22.057  Power management write queue handler entered 
> > 22.057  Write request forwarded to USB pipe IO target
> > 22.057  Power management write queue handler exited 
> > 22.057  EvtDeviceSelfManagedIoRestart routine entered
> > 22.058  Reader for pipe #1 restarted 
> > 22.058  Write completion callback entered with no error
> > 22.058  Write completion callback completes request
> > 22.058  Write completion callback exited
> > 22.058  Reader for pipe #2 restarted
> > 22.058  Reader for pipe #3 restarted
> > 22.058  Read request posted to pipe #4
> > 22.058  EvtDeviceSelfManagedIoRestart routine exited
> > 
> > < Driver out of selected suspend state at this point>
> > 
> > 22.153  Read completion callback entered with no error
> > 22.153  Read completion callback exited
> > 23.018  Last read event received
> > 28.018  EvtDeviceSelfManagedIoSuspend routine entered
> >         - Continuous readers stopped (3 pipes)
> >         - Read request cancelled (1 pipe)
> > 28.019  EvtDeviceSelfManagedIoSuspend routine exited
> > 28.019  EvtDeviceD0Exit routine entered
> > 28.019  EvtDeviceD0Exit routine exited
> > 
> > < Driver in selected suspend state at this point>
> > ------------------------
> > 
> > Let me know if you want any further information.  Note that I will be on 
> > vacation starting tomorrow until the end of December or beginning of January.
> > 
> > Thanks,
> > Michael
> > 
> > 
> > "Philip Ries [MSFT]" wrote:
> > 
> >> Hi Michael,
> >>
> >> You can send me a USB ETW trace and I'll see if it shows anything 
> >> interesting.  Instructions here: 
> >> http://blogs.msdn.com/usbcoreblog/archive/2009/12/04/etw-in-the-windows-7-usb-core-stack.aspx
> >> You can also look through the trace yourself using the latter part of 
> >> the instructions.
> >>
> >> I'd also be interested to see the DbgView output like below for a 
> >> successful resume from selective suspend for a write and then return to 
> >> selective suspend.
> >>
> >> Philip
> >>
> >> dhmot wrote:
> >>> I have a KMDF USB driver for a network device that supports selective suspend 
> >>> (this is a two piece driver, as recommended in Doron Holan's blog).  This 
> >>> driver passes WHQL for XP and 7.  I am having problems with the x86 (x64 
> >>> untested with this scenario) Windows 7/WDF 1009 version of the driver under 
> >>> scenarios where a request is received in a power managed queue within 2-3 
> >>> milliseconds of the WDF USB driver completing its EvtDeviceD0Exit routine.  
> >>> The selective suspend timeout is set to 5 seconds.  The timeline looks 
> >>> something like this (per output from DbgView):
> >>>
> >>> 119.872   Last read event received
> >>> 124.866   EvtDeviceSelfManagedIoSuspend routine entered
> >>>               - Continuous readers stopped (3 pipes)
> >>>               - Read request cancelled        (1 pipe)
> >>> 124.867  EvtDeviceSelfManagedIoSuspend exited
> >>> 124.867  EvtDeviceD0Exit entered
> >>> 124.867  EvtDeviceD0Exit exited
> >>>
> >>> < Driver in selected suspend state at this point>
> >>>
> >>> 124.868  Write request sent to power management queue
> >>> 124.973  Power management write queue handler entered
> >>> 124.973  Write request forwarded to USB pipe IO target
> >>> 124.973  Power management write queue handler exited
> >>> 124.973  EvtDeviceSelfManagedIoRestart entered
> >>> 124.973  Reader for pipe #1 restarted
> >>> 124.973  Write completion callback entered with result of 0xc0000001
> >>> 124.973  Write completion callback completes request
> >>> 124.973  Write completion callback exited
> >>> 124.974  Reader for pipe #2 restarted
> >>> 124.974  Reader for pipe #3 restarted
> >>> 124.974  Read request posted to pipe #4
> >>> 124.974  EvtDeviceSelfManagedIoRestart exited
> >>>
> >>> < Driver out of selected suspend state at this point>
> >>>
> >>> 124.974  Read completion callback entered with result of 0xc0000001 for pipe 
> >>> #4
> >>> 124.974  Read completion callback exited
> >>> 124.974  Reader for pipe #1 fail callback entered with error code 0xc0000001.
> >>> 124.974  Reader for pipe #1 fail callback exited with TRUE to restart reader.
> >>> 124.974  Reader for pipe #2 fail callback entered with error code 0xc0000001.
> >>> 124.974  Reader for pipe #2 fail callback exited with TRUE to restart reader.
> >>> 124.974  Reader for pipe #3 fail callback entered with error code 0xc0000001.
> >>> 124.974  Reader for pipe #3 fail callback exited with TRUE to restart reader.
> >>> 129.971   EvtDeviceSelfManagedIoSuspend routine entered
> >>>               - Continuous readers stopped (3 pipes)
> >>> 129.971  EvtDeviceSelfManagedIoSuspend exited
> >>> 129.971  EvtDeviceD0Exit entered
> >>> 129.971  EvtDeviceD0Exit exited
> >>>
> >>> < Driver in selected suspend state at this point>
> >>>
> >>> 130.381  Write request sent to power management queue
> >>> 130.518  Power management write queue handler entered
> >>> 130.518  Request forwarded to USB pipe IO target
> >>> 130.518  Power management write queue handler exited
> >>> 130.518  EvtDeviceSelfManagedIoRestart entered
> >>> 130.518  Reader for pipe #1 restarted
> >>> 130.519  Reader for pipe #2 restarted
> >>> 130.519  Reader for pipe #3 restarted
> >>> 130.519  Read request posted to pipe #4, but returns error of 0xc0000120
> >>> 130.519  EvtDeviceSelfManagedIoRestart exited
> >>>
> >>> The write that was posted on 130.381 never completes, nor does any 
> >>> subsequent write request.  Eventually the driver runs out of transmit 
> >>> buffers.  When the device is unplugged, all pending write requests are 
> >>> comleted with a status of 0xc0000120.
> >>>
> >>> I connected an Ellisys USB analyzer to confirm that the issue was not with 
> >>> my device.  I did notice a bit of an oddity on the USB side which seems to 
> >>> correspond with the above failure.  The timestamps here don't match up 
> >>> exactly with the above, as I started DbgView a few seconds after the USB 
> >>> analyzer:
> >>>
> >>> 110.811  Bulk transfer
> >>> 115.805  SetFeature(RemoteWakeup) sent to device
> >>>
> >>> <15.5 milliseconds of selective suspend>
> >>>
> >>> 115.960  ClearFeature(RemoteWakeup) sent to device
> >>> 115.961  Bulk transfer
> >>> .....
> >>> 126.034  Bulk transfer
> >>> 131.032  SetFeature(RemoteWakeup) sent to device
> >>>
> >>> <5.5 seconds of selective suspend>
> >>>
> >>> 136.684 ClearFeature(RemoteWakeup) sent to device
> >>>
> >>> After the last "ClearFeature", there is no further read or write requests 
> >>> made on any endpoint, i.e. the readers are not doing their job and the writes 
> >>> are never sent (no NAKs are present).  At this point, the only recovery is to 
> >>> unplug the USB device and re-insert the USB device.  A reboot is not 
> >>> necessary to recover from this situation.  This scenario is very easy to 
> >>> reproduce and is not simply some corner scenario.
> >>>
> >>> The data rate is very low when this occurs, a six packet burst of 30 bytes 
> >>> or so every five seconds.  It is a USB 2.0 device and enumerates as such.  If 
> >>> I shut off selective suspend, I do not run into any issues.  I have also 
> >>> downloaded the latest updates from the Microsoft web site for Windows 7.
> >>>
> >>> What is the problem here?  Is there a solution, short of disabling selective 
> >>> suspend?
> >>>
> >>> Thanks,
> >>> Michael
> >> .
> >>
> .
> 
0
Utf
1/5/2010 9:54:01 PM
Philip,

Sorry for the duplicate replies earlier.

Following the link you provided requires an access ID and a contract ID.  I 
assume my access ID is the same as my MSDN ID (or one of the numbers 
associated with it).  However, I am unable to get a a contract ID.  Whenever 
I call the 800 number to get a contract ID, I get the runaround when I 
mention the information I'm looking for (details concerning KB 978258).  The 
lady who answered the phone would not provide a contract ID because I was not 
running an official release of Windows 7.

In the end, I was told to return to the forums and ask for further 
information concerning this issue.

Is there some magic phrase I have to use to get a contract number when I 
call?  I should have at least two technical support incidents available to 
me.  Or do I need to restart the whole technical support question series from 
scratch, describing the problem as if I had never heard of KB 978258?

Thanks,
Michael

"Philip Ries [MSFT]" wrote:

> The device didn't come out of suspend successfully the third time.  I 
> would try to repro with the device behind an external hub.  If you can't 
> repro there then it may be a known issue with the EHCI driver.  This 
> issue has a QFE (fix) under consideration.
> 
> If you'd like to get the QFE as soon as possible, please contact 
> Microsoft support (some instructions pasted below).  The KB number for 
> this issue will be 978258, you can refer to this number in the support case.
> 
> Thanks,
> Philip
> 
> For more information on how to open a Windows Driver Kit (WDK) service 
> request in order to receive USB driver development support, please click 
> or copy the below link:
> 
> http://support.microsoft.com/select/?LN=en-us&target=assistance&x=13&y=9
> 
> In the “Quick product finder” field, type “Windows Driver Kit” as the 
> product and select that product
> 
> dhmot wrote:
> > Philip,
> > 
> > I've emailed you the USB trace.  One odd thing is that I noticed is that 
> > none of my power management callbacks were invoked this time, or at least 
> > none showed up in DbgView this time.  But the result is the same - the USB 
> > driver hangs on the send requests and does not request data from the USB 
> > device.  However, it does appear from the trace that there was an attempt to 
> > enter selective suspend at 188.505.
> > 
> > One other point I did not mention, but the driver's execution level 
> > (ExecutionLevel) is set to WdfExecutionLevelPassive.  I do not know if this 
> > is pertinent.
> > 
> > Here's the output of a good selective suspend under Windows 7.  FYI, I do 
> > hand-edit for clarity:
> >  
> > ------------------------
> >  5.783  Last read event received
> > 10.783  EvtDeviceSelfManagedIoSuspend routine entered
> >         - Continuous readers stopped (3 pipes)
> >         - Read request cancelled (1 pipe) 
> > 10.785  EvtDeviceSelfManagedIoSuspend routine exited
> > 10.785  EvtDeviceD0Exit routine entered
> > 10.785  EvtDeviceD0Exit routine exited
> > 
> > < Driver in selected suspend state at this point>
> > 
> > 21.938  Write request sent to power management queue  
> > 22.057  Power management write queue handler entered 
> > 22.057  Write request forwarded to USB pipe IO target
> > 22.057  Power management write queue handler exited 
> > 22.057  EvtDeviceSelfManagedIoRestart routine entered
> > 22.058  Reader for pipe #1 restarted 
> > 22.058  Write completion callback entered with no error
> > 22.058  Write completion callback completes request
> > 22.058  Write completion callback exited
> > 22.058  Reader for pipe #2 restarted
> > 22.058  Reader for pipe #3 restarted
> > 22.058  Read request posted to pipe #4
> > 22.058  EvtDeviceSelfManagedIoRestart routine exited
> > 
> > < Driver out of selected suspend state at this point>
> > 
> > 22.153  Read completion callback entered with no error
> > 22.153  Read completion callback exited
> > 23.018  Last read event received
> > 28.018  EvtDeviceSelfManagedIoSuspend routine entered
> >         - Continuous readers stopped (3 pipes)
> >         - Read request cancelled (1 pipe)
> > 28.019  EvtDeviceSelfManagedIoSuspend routine exited
> > 28.019  EvtDeviceD0Exit routine entered
> > 28.019  EvtDeviceD0Exit routine exited
> > 
> > < Driver in selected suspend state at this point>
> > ------------------------
> > 
> > Let me know if you want any further information.  Note that I will be on 
> > vacation starting tomorrow until the end of December or beginning of January.
> > 
> > Thanks,
> > Michael
> > 
> > 
> > "Philip Ries [MSFT]" wrote:
> > 
> >> Hi Michael,
> >>
> >> You can send me a USB ETW trace and I'll see if it shows anything 
> >> interesting.  Instructions here: 
> >> http://blogs.msdn.com/usbcoreblog/archive/2009/12/04/etw-in-the-windows-7-usb-core-stack.aspx
> >> You can also look through the trace yourself using the latter part of 
> >> the instructions.
> >>
> >> I'd also be interested to see the DbgView output like below for a 
> >> successful resume from selective suspend for a write and then return to 
> >> selective suspend.
> >>
> >> Philip
> >>
> >> dhmot wrote:
> >>> I have a KMDF USB driver for a network device that supports selective suspend 
> >>> (this is a two piece driver, as recommended in Doron Holan's blog).  This 
> >>> driver passes WHQL for XP and 7.  I am having problems with the x86 (x64 
> >>> untested with this scenario) Windows 7/WDF 1009 version of the driver under 
> >>> scenarios where a request is received in a power managed queue within 2-3 
> >>> milliseconds of the WDF USB driver completing its EvtDeviceD0Exit routine.  
> >>> The selective suspend timeout is set to 5 seconds.  The timeline looks 
> >>> something like this (per output from DbgView):
> >>>
> >>> 119.872   Last read event received
> >>> 124.866   EvtDeviceSelfManagedIoSuspend routine entered
> >>>               - Continuous readers stopped (3 pipes)
> >>>               - Read request cancelled        (1 pipe)
> >>> 124.867  EvtDeviceSelfManagedIoSuspend exited
> >>> 124.867  EvtDeviceD0Exit entered
> >>> 124.867  EvtDeviceD0Exit exited
> >>>
> >>> < Driver in selected suspend state at this point>
> >>>
> >>> 124.868  Write request sent to power management queue
> >>> 124.973  Power management write queue handler entered
> >>> 124.973  Write request forwarded to USB pipe IO target
> >>> 124.973  Power management write queue handler exited
> >>> 124.973  EvtDeviceSelfManagedIoRestart entered
> >>> 124.973  Reader for pipe #1 restarted
> >>> 124.973  Write completion callback entered with result of 0xc0000001
> >>> 124.973  Write completion callback completes request
> >>> 124.973  Write completion callback exited
> >>> 124.974  Reader for pipe #2 restarted
> >>> 124.974  Reader for pipe #3 restarted
> >>> 124.974  Read request posted to pipe #4
> >>> 124.974  EvtDeviceSelfManagedIoRestart exited
> >>>
> >>> < Driver out of selected suspend state at this point>
> >>>
> >>> 124.974  Read completion callback entered with result of 0xc0000001 for pipe 
> >>> #4
> >>> 124.974  Read completion callback exited
> >>> 124.974  Reader for pipe #1 fail callback entered with error code 0xc0000001.
> >>> 124.974  Reader for pipe #1 fail callback exited with TRUE to restart reader.
> >>> 124.974  Reader for pipe #2 fail callback entered with error code 0xc0000001.
> >>> 124.974  Reader for pipe #2 fail callback exited with TRUE to restart reader.
> >>> 124.974  Reader for pipe #3 fail callback entered with error code 0xc0000001.
> >>> 124.974  Reader for pipe #3 fail callback exited with TRUE to restart reader.
> >>> 129.971   EvtDeviceSelfManagedIoSuspend routine entered
> >>>               - Continuous readers stopped (3 pipes)
> >>> 129.971  EvtDeviceSelfManagedIoSuspend exited
> >>> 129.971  EvtDeviceD0Exit entered
> >>> 129.971  EvtDeviceD0Exit exited
> >>>
> >>> < Driver in selected suspend state at this point>
> >>>
> >>> 130.381  Write request sent to power management queue
> >>> 130.518  Power management write queue handler entered
> >>> 130.518  Request forwarded to USB pipe IO target
> >>> 130.518  Power management write queue handler exited
> >>> 130.518  EvtDeviceSelfManagedIoRestart entered
> >>> 130.518  Reader for pipe #1 restarted
> >>> 130.519  Reader for pipe #2 restarted
> >>> 130.519  Reader for pipe #3 restarted
> >>> 130.519  Read request posted to pipe #4, but returns error of 0xc0000120
> >>> 130.519  EvtDeviceSelfManagedIoRestart exited
> >>>
> >>> The write that was posted on 130.381 never completes, nor does any 
> >>> subsequent write request.  Eventually the driver runs out of transmit 
> >>> buffers.  When the device is unplugged, all pending write requests are 
> >>> comleted with a status of 0xc0000120.
> >>>
> >>> I connected an Ellisys USB analyzer to confirm that the issue was not with 
> >>> my device.  I did notice a bit of an oddity on the USB side which seems to 
> >>> correspond with the above failure.  The timestamps here don't match up 
> >>> exactly with the above, as I started DbgView a few seconds after the USB 
> >>> analyzer:
> >>>
> >>> 110.811  Bulk transfer
> >>> 115.805  SetFeature(RemoteWakeup) sent to device
> >>>
> >>> <15.5 milliseconds of selective suspend>
> >>>
> >>> 115.960  ClearFeature(RemoteWakeup) sent to device
> >>> 115.961  Bulk transfer
> >>> .....
> >>> 126.034  Bulk transfer
> >>> 131.032  SetFeature(RemoteWakeup) sent to device
> >>>
> >>> <5.5 seconds of selective suspend>
> >>>
> >>> 136.684 ClearFeature(RemoteWakeup) sent to device
> >>>
> >>> After the last "ClearFeature", there is no further read or write requests 
> >>> made on any endpoint, i.e. the readers are not doing their job and the writes 
> >>> are never sent (no NAKs are present).  At this point, the only recovery is to 
> >>> unplug the USB device and re-insert the USB device.  A reboot is not 
> >>> necessary to recover from this situation.  This scenario is very easy to 
> >>> reproduce and is not simply some corner scenario.
> >>>
> >>> The data rate is very low when this occurs, a six packet burst of 30 bytes 
> >>> or so every five seconds.  It is a USB 2.0 device and enumerates as such.  If 
> >>> I shut off selective suspend, I do not run into any issues.  I have also 
> >>> downloaded the latest updates from the Microsoft web site for Windows 7.
> >>>
> >>> What is the problem here?  Is there a solution, short of disabling selective 
> >>> suspend?
> >>>
> >>> Thanks,
> >>> Michael
> >> .
> >>
> .
> 
0
Utf
1/5/2010 10:59:01 PM
> The lady who answered the phone would not provide a contract ID because I was not running an official release of Windows 7. 

You're not running Win7 RTM?

dhmot wrote:
> Philip,
> 
> Sorry for the duplicate replies earlier.
> 
> Following the link you provided requires an access ID and a contract ID.  I 
> assume my access ID is the same as my MSDN ID (or one of the numbers 
> associated with it).  However, I am unable to get a a contract ID.  Whenever 
> I call the 800 number to get a contract ID, I get the runaround when I 
> mention the information I'm looking for (details concerning KB 978258).  The 
> lady who answered the phone would not provide a contract ID because I was not 
> running an official release of Windows 7.
> 
> In the end, I was told to return to the forums and ask for further 
> information concerning this issue.
> 
> Is there some magic phrase I have to use to get a contract number when I 
> call?  I should have at least two technical support incidents available to 
> me.  Or do I need to restart the whole technical support question series from 
> scratch, describing the problem as if I had never heard of KB 978258?
> 
> Thanks,
> Michael
> 
> "Philip Ries [MSFT]" wrote:
> 
>> The device didn't come out of suspend successfully the third time.  I 
>> would try to repro with the device behind an external hub.  If you can't 
>> repro there then it may be a known issue with the EHCI driver.  This 
>> issue has a QFE (fix) under consideration.
>>
>> If you'd like to get the QFE as soon as possible, please contact 
>> Microsoft support (some instructions pasted below).  The KB number for 
>> this issue will be 978258, you can refer to this number in the support case.
>>
>> Thanks,
>> Philip
>>
>> For more information on how to open a Windows Driver Kit (WDK) service 
>> request in order to receive USB driver development support, please click 
>> or copy the below link:
>>
>> http://support.microsoft.com/select/?LN=en-us&target=assistance&x=13&y=9
>>
>> In the “Quick product finder” field, type “Windows Driver Kit” as the 
>> product and select that product
>>
>> dhmot wrote:
>>> Philip,
>>>
>>> I've emailed you the USB trace.  One odd thing is that I noticed is that 
>>> none of my power management callbacks were invoked this time, or at least 
>>> none showed up in DbgView this time.  But the result is the same - the USB 
>>> driver hangs on the send requests and does not request data from the USB 
>>> device.  However, it does appear from the trace that there was an attempt to 
>>> enter selective suspend at 188.505.
>>>
>>> One other point I did not mention, but the driver's execution level 
>>> (ExecutionLevel) is set to WdfExecutionLevelPassive.  I do not know if this 
>>> is pertinent.
>>>
>>> Here's the output of a good selective suspend under Windows 7.  FYI, I do 
>>> hand-edit for clarity:
>>>  
>>> ------------------------
>>>  5.783  Last read event received
>>> 10.783  EvtDeviceSelfManagedIoSuspend routine entered
>>>         - Continuous readers stopped (3 pipes)
>>>         - Read request cancelled (1 pipe) 
>>> 10.785  EvtDeviceSelfManagedIoSuspend routine exited
>>> 10.785  EvtDeviceD0Exit routine entered
>>> 10.785  EvtDeviceD0Exit routine exited
>>>
>>> < Driver in selected suspend state at this point>
>>>
>>> 21.938  Write request sent to power management queue  
>>> 22.057  Power management write queue handler entered 
>>> 22.057  Write request forwarded to USB pipe IO target
>>> 22.057  Power management write queue handler exited 
>>> 22.057  EvtDeviceSelfManagedIoRestart routine entered
>>> 22.058  Reader for pipe #1 restarted 
>>> 22.058  Write completion callback entered with no error
>>> 22.058  Write completion callback completes request
>>> 22.058  Write completion callback exited
>>> 22.058  Reader for pipe #2 restarted
>>> 22.058  Reader for pipe #3 restarted
>>> 22.058  Read request posted to pipe #4
>>> 22.058  EvtDeviceSelfManagedIoRestart routine exited
>>>
>>> < Driver out of selected suspend state at this point>
>>>
>>> 22.153  Read completion callback entered with no error
>>> 22.153  Read completion callback exited
>>> 23.018  Last read event received
>>> 28.018  EvtDeviceSelfManagedIoSuspend routine entered
>>>         - Continuous readers stopped (3 pipes)
>>>         - Read request cancelled (1 pipe)
>>> 28.019  EvtDeviceSelfManagedIoSuspend routine exited
>>> 28.019  EvtDeviceD0Exit routine entered
>>> 28.019  EvtDeviceD0Exit routine exited
>>>
>>> < Driver in selected suspend state at this point>
>>> ------------------------
>>>
>>> Let me know if you want any further information.  Note that I will be on 
>>> vacation starting tomorrow until the end of December or beginning of January.
>>>
>>> Thanks,
>>> Michael
>>>
>>>
>>> "Philip Ries [MSFT]" wrote:
>>>
>>>> Hi Michael,
>>>>
>>>> You can send me a USB ETW trace and I'll see if it shows anything 
>>>> interesting.  Instructions here: 
>>>> http://blogs.msdn.com/usbcoreblog/archive/2009/12/04/etw-in-the-windows-7-usb-core-stack.aspx
>>>> You can also look through the trace yourself using the latter part of 
>>>> the instructions.
>>>>
>>>> I'd also be interested to see the DbgView output like below for a 
>>>> successful resume from selective suspend for a write and then return to 
>>>> selective suspend.
>>>>
>>>> Philip
>>>>
>>>> dhmot wrote:
>>>>> I have a KMDF USB driver for a network device that supports selective suspend 
>>>>> (this is a two piece driver, as recommended in Doron Holan's blog).  This 
>>>>> driver passes WHQL for XP and 7.  I am having problems with the x86 (x64 
>>>>> untested with this scenario) Windows 7/WDF 1009 version of the driver under 
>>>>> scenarios where a request is received in a power managed queue within 2-3 
>>>>> milliseconds of the WDF USB driver completing its EvtDeviceD0Exit routine.  
>>>>> The selective suspend timeout is set to 5 seconds.  The timeline looks 
>>>>> something like this (per output from DbgView):
>>>>>
>>>>> 119.872   Last read event received
>>>>> 124.866   EvtDeviceSelfManagedIoSuspend routine entered
>>>>>               - Continuous readers stopped (3 pipes)
>>>>>               - Read request cancelled        (1 pipe)
>>>>> 124.867  EvtDeviceSelfManagedIoSuspend exited
>>>>> 124.867  EvtDeviceD0Exit entered
>>>>> 124.867  EvtDeviceD0Exit exited
>>>>>
>>>>> < Driver in selected suspend state at this point>
>>>>>
>>>>> 124.868  Write request sent to power management queue
>>>>> 124.973  Power management write queue handler entered
>>>>> 124.973  Write request forwarded to USB pipe IO target
>>>>> 124.973  Power management write queue handler exited
>>>>> 124.973  EvtDeviceSelfManagedIoRestart entered
>>>>> 124.973  Reader for pipe #1 restarted
>>>>> 124.973  Write completion callback entered with result of 0xc0000001
>>>>> 124.973  Write completion callback completes request
>>>>> 124.973  Write completion callback exited
>>>>> 124.974  Reader for pipe #2 restarted
>>>>> 124.974  Reader for pipe #3 restarted
>>>>> 124.974  Read request posted to pipe #4
>>>>> 124.974  EvtDeviceSelfManagedIoRestart exited
>>>>>
>>>>> < Driver out of selected suspend state at this point>
>>>>>
>>>>> 124.974  Read completion callback entered with result of 0xc0000001 for pipe 
>>>>> #4
>>>>> 124.974  Read completion callback exited
>>>>> 124.974  Reader for pipe #1 fail callback entered with error code 0xc0000001.
>>>>> 124.974  Reader for pipe #1 fail callback exited with TRUE to restart reader.
>>>>> 124.974  Reader for pipe #2 fail callback entered with error code 0xc0000001.
>>>>> 124.974  Reader for pipe #2 fail callback exited with TRUE to restart reader.
>>>>> 124.974  Reader for pipe #3 fail callback entered with error code 0xc0000001.
>>>>> 124.974  Reader for pipe #3 fail callback exited with TRUE to restart reader.
>>>>> 129.971   EvtDeviceSelfManagedIoSuspend routine entered
>>>>>               - Continuous readers stopped (3 pipes)
>>>>> 129.971  EvtDeviceSelfManagedIoSuspend exited
>>>>> 129.971  EvtDeviceD0Exit entered
>>>>> 129.971  EvtDeviceD0Exit exited
>>>>>
>>>>> < Driver in selected suspend state at this point>
>>>>>
>>>>> 130.381  Write request sent to power management queue
>>>>> 130.518  Power management write queue handler entered
>>>>> 130.518  Request forwarded to USB pipe IO target
>>>>> 130.518  Power management write queue handler exited
>>>>> 130.518  EvtDeviceSelfManagedIoRestart entered
>>>>> 130.518  Reader for pipe #1 restarted
>>>>> 130.519  Reader for pipe #2 restarted
>>>>> 130.519  Reader for pipe #3 restarted
>>>>> 130.519  Read request posted to pipe #4, but returns error of 0xc0000120
>>>>> 130.519  EvtDeviceSelfManagedIoRestart exited
>>>>>
>>>>> The write that was posted on 130.381 never completes, nor does any 
>>>>> subsequent write request.  Eventually the driver runs out of transmit 
>>>>> buffers.  When the device is unplugged, all pending write requests are 
>>>>> comleted with a status of 0xc0000120.
>>>>>
>>>>> I connected an Ellisys USB analyzer to confirm that the issue was not with 
>>>>> my device.  I did notice a bit of an oddity on the USB side which seems to 
>>>>> correspond with the above failure.  The timestamps here don't match up 
>>>>> exactly with the above, as I started DbgView a few seconds after the USB 
>>>>> analyzer:
>>>>>
>>>>> 110.811  Bulk transfer
>>>>> 115.805  SetFeature(RemoteWakeup) sent to device
>>>>>
>>>>> <15.5 milliseconds of selective suspend>
>>>>>
>>>>> 115.960  ClearFeature(RemoteWakeup) sent to device
>>>>> 115.961  Bulk transfer
>>>>> .....
>>>>> 126.034  Bulk transfer
>>>>> 131.032  SetFeature(RemoteWakeup) sent to device
>>>>>
>>>>> <5.5 seconds of selective suspend>
>>>>>
>>>>> 136.684 ClearFeature(RemoteWakeup) sent to device
>>>>>
>>>>> After the last "ClearFeature", there is no further read or write requests 
>>>>> made on any endpoint, i.e. the readers are not doing their job and the writes 
>>>>> are never sent (no NAKs are present).  At this point, the only recovery is to 
>>>>> unplug the USB device and re-insert the USB device.  A reboot is not 
>>>>> necessary to recover from this situation.  This scenario is very easy to 
>>>>> reproduce and is not simply some corner scenario.
>>>>>
>>>>> The data rate is very low when this occurs, a six packet burst of 30 bytes 
>>>>> or so every five seconds.  It is a USB 2.0 device and enumerates as such.  If 
>>>>> I shut off selective suspend, I do not run into any issues.  I have also 
>>>>> downloaded the latest updates from the Microsoft web site for Windows 7.
>>>>>
>>>>> What is the problem here?  Is there a solution, short of disabling selective 
>>>>> suspend?
>>>>>
>>>>> Thanks,
>>>>> Michael
>>>> .
>>>>
>> .
>>

0
Philip
1/6/2010 7:35:46 PM
"dhmot" <dhmot@discussions.microsoft.com> wrote in message 
news:92D55AAA-E1CA-408F-8A31-7E5FD6CA64A5@microsoft.com...

> lady who answered the phone would not provide a contract ID because I was 
> not
> running an official release of Windows 7.

??? Then test on the official release:
http://technet.microsoft.com/en-us/evalcenter/cc442495.aspx

--pa
 

0
Pavel
1/6/2010 9:52:51 PM
I don't know what "Win7 RTM" is, but yesterday I downloaded Windows 7 
Professional (dated 11/12/09) from the MSDN site.  The problem still occurs 
with that version.

Michael

"Philip Ries [MSFT]" wrote:

> > The lady who answered the phone would not provide a contract ID because I was not running an official release of Windows 7. 
> 
> You're not running Win7 RTM?
> 
> dhmot wrote:
> > Philip,
> > 
> > Sorry for the duplicate replies earlier.
> > 
> > Following the link you provided requires an access ID and a contract ID.  I 
> > assume my access ID is the same as my MSDN ID (or one of the numbers 
> > associated with it).  However, I am unable to get a a contract ID.  Whenever 
> > I call the 800 number to get a contract ID, I get the runaround when I 
> > mention the information I'm looking for (details concerning KB 978258).  The 
> > lady who answered the phone would not provide a contract ID because I was not 
> > running an official release of Windows 7.
> > 
> > In the end, I was told to return to the forums and ask for further 
> > information concerning this issue.
> > 
> > Is there some magic phrase I have to use to get a contract number when I 
> > call?  I should have at least two technical support incidents available to 
> > me.  Or do I need to restart the whole technical support question series from 
> > scratch, describing the problem as if I had never heard of KB 978258?
> > 
> > Thanks,
> > Michael
> > 
> > "Philip Ries [MSFT]" wrote:
> > 
> >> The device didn't come out of suspend successfully the third time.  I 
> >> would try to repro with the device behind an external hub.  If you can't 
> >> repro there then it may be a known issue with the EHCI driver.  This 
> >> issue has a QFE (fix) under consideration.
> >>
> >> If you'd like to get the QFE as soon as possible, please contact 
> >> Microsoft support (some instructions pasted below).  The KB number for 
> >> this issue will be 978258, you can refer to this number in the support case.
> >>
> >> Thanks,
> >> Philip
> >>
> >> For more information on how to open a Windows Driver Kit (WDK) service 
> >> request in order to receive USB driver development support, please click 
> >> or copy the below link:
> >>
> >> http://support.microsoft.com/select/?LN=en-us&target=assistance&x=13&y=9
> >>
> >> In the “Quick product finder” field, type “Windows Driver Kit” as the 
> >> product and select that product
> >>
> >> dhmot wrote:
> >>> Philip,
> >>>
> >>> I've emailed you the USB trace.  One odd thing is that I noticed is that 
> >>> none of my power management callbacks were invoked this time, or at least 
> >>> none showed up in DbgView this time.  But the result is the same - the USB 
> >>> driver hangs on the send requests and does not request data from the USB 
> >>> device.  However, it does appear from the trace that there was an attempt to 
> >>> enter selective suspend at 188.505.
> >>>
> >>> One other point I did not mention, but the driver's execution level 
> >>> (ExecutionLevel) is set to WdfExecutionLevelPassive.  I do not know if this 
> >>> is pertinent.
> >>>
> >>> Here's the output of a good selective suspend under Windows 7.  FYI, I do 
> >>> hand-edit for clarity:
> >>>  
> >>> ------------------------
> >>>  5.783  Last read event received
> >>> 10.783  EvtDeviceSelfManagedIoSuspend routine entered
> >>>         - Continuous readers stopped (3 pipes)
> >>>         - Read request cancelled (1 pipe) 
> >>> 10.785  EvtDeviceSelfManagedIoSuspend routine exited
> >>> 10.785  EvtDeviceD0Exit routine entered
> >>> 10.785  EvtDeviceD0Exit routine exited
> >>>
> >>> < Driver in selected suspend state at this point>
> >>>
> >>> 21.938  Write request sent to power management queue  
> >>> 22.057  Power management write queue handler entered 
> >>> 22.057  Write request forwarded to USB pipe IO target
> >>> 22.057  Power management write queue handler exited 
> >>> 22.057  EvtDeviceSelfManagedIoRestart routine entered
> >>> 22.058  Reader for pipe #1 restarted 
> >>> 22.058  Write completion callback entered with no error
> >>> 22.058  Write completion callback completes request
> >>> 22.058  Write completion callback exited
> >>> 22.058  Reader for pipe #2 restarted
> >>> 22.058  Reader for pipe #3 restarted
> >>> 22.058  Read request posted to pipe #4
> >>> 22.058  EvtDeviceSelfManagedIoRestart routine exited
> >>>
> >>> < Driver out of selected suspend state at this point>
> >>>
> >>> 22.153  Read completion callback entered with no error
> >>> 22.153  Read completion callback exited
> >>> 23.018  Last read event received
> >>> 28.018  EvtDeviceSelfManagedIoSuspend routine entered
> >>>         - Continuous readers stopped (3 pipes)
> >>>         - Read request cancelled (1 pipe)
> >>> 28.019  EvtDeviceSelfManagedIoSuspend routine exited
> >>> 28.019  EvtDeviceD0Exit routine entered
> >>> 28.019  EvtDeviceD0Exit routine exited
> >>>
> >>> < Driver in selected suspend state at this point>
> >>> ------------------------
> >>>
> >>> Let me know if you want any further information.  Note that I will be on 
> >>> vacation starting tomorrow until the end of December or beginning of January.
> >>>
> >>> Thanks,
> >>> Michael
> >>>
> >>>
> >>> "Philip Ries [MSFT]" wrote:
> >>>
> >>>> Hi Michael,
> >>>>
> >>>> You can send me a USB ETW trace and I'll see if it shows anything 
> >>>> interesting.  Instructions here: 
> >>>> http://blogs.msdn.com/usbcoreblog/archive/2009/12/04/etw-in-the-windows-7-usb-core-stack.aspx
> >>>> You can also look through the trace yourself using the latter part of 
> >>>> the instructions.
> >>>>
> >>>> I'd also be interested to see the DbgView output like below for a 
> >>>> successful resume from selective suspend for a write and then return to 
> >>>> selective suspend.
> >>>>
> >>>> Philip
> >>>>
> >>>> dhmot wrote:
> >>>>> I have a KMDF USB driver for a network device that supports selective suspend 
> >>>>> (this is a two piece driver, as recommended in Doron Holan's blog).  This 
> >>>>> driver passes WHQL for XP and 7.  I am having problems with the x86 (x64 
> >>>>> untested with this scenario) Windows 7/WDF 1009 version of the driver under 
> >>>>> scenarios where a request is received in a power managed queue within 2-3 
> >>>>> milliseconds of the WDF USB driver completing its EvtDeviceD0Exit routine.  
> >>>>> The selective suspend timeout is set to 5 seconds.  The timeline looks 
> >>>>> something like this (per output from DbgView):
> >>>>>
> >>>>> 119.872   Last read event received
> >>>>> 124.866   EvtDeviceSelfManagedIoSuspend routine entered
> >>>>>               - Continuous readers stopped (3 pipes)
> >>>>>               - Read request cancelled        (1 pipe)
> >>>>> 124.867  EvtDeviceSelfManagedIoSuspend exited
> >>>>> 124.867  EvtDeviceD0Exit entered
> >>>>> 124.867  EvtDeviceD0Exit exited
> >>>>>
> >>>>> < Driver in selected suspend state at this point>
> >>>>>
> >>>>> 124.868  Write request sent to power management queue
> >>>>> 124.973  Power management write queue handler entered
> >>>>> 124.973  Write request forwarded to USB pipe IO target
> >>>>> 124.973  Power management write queue handler exited
> >>>>> 124.973  EvtDeviceSelfManagedIoRestart entered
> >>>>> 124.973  Reader for pipe #1 restarted
> >>>>> 124.973  Write completion callback entered with result of 0xc0000001
> >>>>> 124.973  Write completion callback completes request
> >>>>> 124.973  Write completion callback exited
> >>>>> 124.974  Reader for pipe #2 restarted
> >>>>> 124.974  Reader for pipe #3 restarted
> >>>>> 124.974  Read request posted to pipe #4
> >>>>> 124.974  EvtDeviceSelfManagedIoRestart exited
> >>>>>
> >>>>> < Driver out of selected suspend state at this point>
> >>>>>
> >>>>> 124.974  Read completion callback entered with result of 0xc0000001 for pipe 
> >>>>> #4
> >>>>> 124.974  Read completion callback exited
> >>>>> 124.974  Reader for pipe #1 fail callback entered with error code 0xc0000001.
> >>>>> 124.974  Reader for pipe #1 fail callback exited with TRUE to restart reader.
> >>>>> 124.974  Reader for pipe #2 fail callback entered with error code 0xc0000001.
> >>>>> 124.974  Reader for pipe #2 fail callback exited with TRUE to restart reader.
> >>>>> 124.974  Reader for pipe #3 fail callback entered with error code 0xc0000001.
> >>>>> 124.974  Reader for pipe #3 fail callback exited with TRUE to restart reader.
> >>>>> 129.971   EvtDeviceSelfManagedIoSuspend routine entered
> >>>>>               - Continuous readers stopped (3 pipes)
> >>>>> 129.971  EvtDeviceSelfManagedIoSuspend exited
> >>>>> 129.971  EvtDeviceD0Exit entered
> >>>>> 129.971  EvtDeviceD0Exit exited
> >>>>>
> >>>>> < Driver in selected suspend state at this point>
> >>>>>
> >>>>> 130.381  Write request sent to power management queue
> >>>>> 130.518  Power management write queue handler entered
> >>>>> 130.518  Request forwarded to USB pipe IO target
> >>>>> 130.518  Power management write queue handler exited
> >>>>> 130.518  EvtDeviceSelfManagedIoRestart entered
> >>>>> 130.518  Reader for pipe #1 restarted
> >>>>> 130.519  Reader for pipe #2 restarted
> >>>>> 130.519  Reader for pipe #3 restarted
> >>>>> 130.519  Read request posted to pipe #4, but returns error of 0xc0000120
> >>>>> 130.519  EvtDeviceSelfManagedIoRestart exited
> >>>>>
> >>>>> The write that was posted on 130.381 never completes, nor does any 
> >>>>> subsequent write request.  Eventually the driver runs out of transmit 
> >>>>> buffers.  When the device is unplugged, all pending write requests are 
> >>>>> comleted with a status of 0xc0000120.
> >>>>>
> >>>>> I connected an Ellisys USB analyzer to confirm that the issue was not with 
> >>>>> my device.  I did notice a bit of an oddity on the USB side which seems to 
> >>>>> correspond with the above failure.  The timestamps here don't match up 
> >>>>> exactly with the above, as I started DbgView a few seconds after the USB 
> >>>>> analyzer:
> >>>>>
> >>>>> 110.811  Bulk transfer
> >>>>> 115.805  SetFeature(RemoteWakeup) sent to device
> >>>>>
> >>>>> <15.5 milliseconds of selective suspend>
> >>>>>
> >>>>> 115.960  ClearFeature(RemoteWakeup) sent to device
> >>>>> 115.961  Bulk transfer
> >>>>> .....
> >>>>> 126.034  Bulk transfer
> >>>>> 131.032  SetFeature(RemoteWakeup) sent to device
> >>>>>
> >>>>> <5.5 seconds of selective suspend>
> >>>>>
> >>>>> 136.684 ClearFeature(RemoteWakeup) sent to device
> >>>>>
> >>>>> After the last "ClearFeature", there is no further read or write requests 
> >>>>> made on any endpoint, i.e. the readers are not doing their job and the writes 
> >>>>> are never sent (no NAKs are present).  At this point, the only recovery is to 
> >>>>> unplug the USB device and re-insert the USB device.  A reboot is not 
> >>>>> necessary to recover from this situation.  This scenario is very easy to 
> >>>>> reproduce and is not simply some corner scenario.
> >>>>>
> >>>>> The data rate is very low when this occurs, a six packet burst of 30 bytes 
> >>>>> or so every five seconds.  It is a USB 2.0 device and enumerates as such.  If 
> >>>>> I shut off selective suspend, I do not run into any issues.  I have also 
> >>>>> downloaded the latest updates from the Microsoft web site for Windows 7.
> >>>>>
> >>>>> What is the problem here?  Is there a solution, short of disabling selective 
> >>>>> suspend?
> >>>>>
> >>>>> Thanks,
> >>>>> Michael
> >>>> .
> >>>>
> >> .
> >>
> 
> .
> 
0
Utf
1/7/2010 3:24:01 PM
Pavel,

Thanks.  I did.  Same results.

Michael

"Pavel A." wrote:

> "dhmot" <dhmot@discussions.microsoft.com> wrote in message 
> news:92D55AAA-E1CA-408F-8A31-7E5FD6CA64A5@microsoft.com...
> 
> > lady who answered the phone would not provide a contract ID because I was 
> > not
> > running an official release of Windows 7.
> 
> ??? Then test on the official release:
> http://technet.microsoft.com/en-us/evalcenter/cc442495.aspx
> 
> --pa
>  
> 
0
Utf
1/7/2010 3:25:01 PM
Pavel,

Actually, I should say I tested with the version on MSDN dated 11/12/09, 
with all the updates downloaded from the Microsoft web site.  Same results.

Michael

"Pavel A." wrote:

> "dhmot" <dhmot@discussions.microsoft.com> wrote in message 
> news:92D55AAA-E1CA-408F-8A31-7E5FD6CA64A5@microsoft.com...
> 
> > lady who answered the phone would not provide a contract ID because I was 
> > not
> > running an official release of Windows 7.
> 
> ??? Then test on the official release:
> http://technet.microsoft.com/en-us/evalcenter/cc442495.aspx
> 
> --pa
>  
> 
0
Utf
1/7/2010 3:26:11 PM
Reply:

Similar Artilces:

Password Protection doesn't interop between Office for Window and Office for Mac 2004
I have an excel file that was created in Office for Windows and certain cells were password protected. When I open that same file with excel for Mac the password protection doesn't work. I tried tools>unprotect> .... I plug in the password and no luck. When I open that same excel file with another windows machine with Office for windows I'm able to access the protected cells after entering the password. Is this a known issue? Is there a fix for office for mac? I'll be forced to buy a windows version of office which would make the mac version useless. I'm currently r...

How to make autostart programs in USB stick memory
Hi. Some said, when USB memory stick putting on PC, it can start autostart programs, like Autorun.inf of CD-R. Does any know how to do it? Thanks, M.M. M.Miura wrote: > Some said, when USB memory stick putting on PC, it can start > autostart programs, like Autorun.inf of CD-R. Does any know > how to do it? Same way. Most systems these days have autorun disabled. ;-) (for good reason.) -- Shenan Stanley MS-MVP -- How To Ask Questions The Smart Way http://www.catb.org/~esr/faqs/smart-questions.html M.Miura wrote: > Hi. > > Some ...

Custom formatting #7
How can I do the following custom formatting – I need trailing dots before the number ……..1,234.00 Thanks for any help Right Click > Format Cells > Select Custom Enter "........ "0.00 "John Knoke" <JohnKnoke@discussions.microsoft.com> wrote in message news:586761E6-32A9-4911-BF50-3790614145B2@microsoft.com... > > How can I do the following custom formatting - > I need trailing dots before the number > ....1,234.00 > > Thanks for any help > > John, Use a custom number format of *.#,###.00 Note the period between the * and the f...

Long delay in opening New Message windows
My Windows mail has recently developed the problem of taking 10 seconds or more just to open a create new message window. How do I fix this? Did you add any 3rd party software into the Add Ins -- Peter Please Reply to Newsgroup for the benefit of others Requests for assistance by email can not and will not be acknowledged. "Jembeaux" <Jembeaux@discussions.microsoft.com> wrote in message news:A58C3591-9431-4BDF-8D32-9ACE1E12D41E@microsoft.com... > My Windows mail has recently developed the problem of taking 10 seconds or > more just to open a create ne...

Windows Live mail not downloaded into Outlook
I have an msn account, Outlook 2007, and Outlook connector installed on a Vista machine. Recently I've had problems downloading mail to Outlook. Outlook Connector shows that Calendar and Contacts are connected, but that there is an error in connecting mail. The error message says: Error in Mail Error with Send/Receive. Look for a log in the Sync Issues folder. Not sure where the Sync issues folder is. This has occurred at least three times in the past month. Once, I deleted my msn profile and started over, but I can't figure out why it occurred or how I was able ...

Mouse scroll not working in Module window
Access97 on HP Laptop on XP Pro Since installing Office 97 on my new (replacement) laptop I find the mouse scroll button does not work in the Module window - works everywhere else in Access ok? Any ideas appreciated. Piri yeah don't use ancient software, kid "Piri" <wiremu.pareiha@hotmail.com> wrote in message news:1178247184.740213.222110@y5g2000hsa.googlegroups.com... > Access97 on HP Laptop on XP Pro > Since installing Office 97 on my new (replacement) laptop I find the > mouse scroll button does not work in the Module window - works > everywhere else i...

Selecting Pics in Explorer, then "Send via e-mail" doesn't work...
I'm sure this has been addressed, but I haven't found it in a search. I'm running Outlook 2007 and it worked fine with XP - since I've upgraded to Windows 7, I can't select *any* files in explorer and send them via e-mail. Nothing happens, then I can't get Outlook to start under any circumstance unless I reboot. I need to create a new e-mail, then select the files...and it works fine, but it's a giant PITA. Any help: Sounds like it is caused by a corruption or an incompatible add-in. Which add-ins do you have installed? Tools-> Trust Center-&g...

Windows Live Video Chat
I have a laptop that has an integrated webcam and microphone. Well I was trying to call a friend over Windows Live Messenger and the webcam works just fine. What doesn't work is the microphone. And I don't know why. Someone help please? Any suggestions? Answers? "Wicked Sin" <WickedSin@discussions.microsoft.com> wrote in message news:B3555EA6-82B4-4831-B70F-1FE3206CB3CD@microsoft.com... > I have a laptop that has an integrated webcam and microphone. > > Well I was trying to call a friend over Windows Live Messenger and the > webcam wor...

Tab Control #7
Hi, I'm using a basic tab control, how to place a bitmap image onto it ? Can a bitmap image be inserted only on the tab strips. (what i mean by tab strips is the part of tab, which holds name for that tab). Also, how to get the 3D effect for the tab ? (Like XP tabs) Hi You can bitblt for each tab clicks. I mean when you change the tab just repaint the dialog with new bitmap. Best regards, Amal Quote raj: Can a bitmap image be inserted only on the tab strips. (what i mean by tab strips is the part of tab, which holds name for that tab). ------------------------------------- Y...

does publisher 2000 run on windows xp?
thanks for helping if you know the answer Yes, all versions of Publisher run on XP, Publisher 1.0 maybe the exception. -- Mary Sauer MSFT MVP http://office.microsoft.com/ http://msauer.mvps.org/ news://msnews.microsoft.com "Baudouin" <Baudouin@discussions.microsoft.com> wrote in message news:6AA35200-15D7-47F2-8471-4E6737171B6A@microsoft.com... > thanks for helping if you know the answer Mary Sauer <gsauer@mycolumbus.rr.com> was very recently heard to utter: > Yes, all versions of Publisher run on XP, Publisher 1.0 maybe the > exception. It runs. Not on...

will RMS 2.0 work with Windows 7
Has anyone tried using RMS 2.0 with Windows 7? What version RMS are you using? Yes 2.0.0126 -- Maurice Gordon Maurice@americanretailsupply.com Sales/Support 1-800-426-5708 XT 1307 "Larry" <Larry@discussions.microsoft.com> wrote in message news:0E0D2035-1FB0-497E-8F73-AF5FDA947E64@microsoft.com... > Has anyone tried using RMS 2.0 with Windows 7? What version RMS are you > using? Hi Larry, RMS 2.0 SP2 working fine with windows 7 Vijay "Larry" wrote: > Has anyone tried using RMS 2.0 with Windows 7? What version RMS ar...

*CANT log into Windows -please help
Hi, I need step by step instructions on how to use my recovery console CD in order to fix a problem. Here is my prob: A virus/malware scan I did probably messed up my logon file. The antivrus program either removed or quaranteined the virus/trojan that was attached to my logon file. Because when AVG prompted me to reboot after this scan, It stopped at the welcome screen logon part. I click on my user name (only one there) and it says its logging on...But then it says saving settings and nothing else happens. My machine does not reboot or anything. It just stays at this logon sc...

Adobe Flash Player and 64 bit Windows 7
I am trying to view the Lulu demonstration but cannot. I am using Windows 7 and IE 64 bit and apparently I need to run the 32 bit to see the demo. I don't know how to. Any help would be appreciated. John, For the time being there is no 64-bit flash player for IE 64-bit. http://kb2.adobe.com/cps/000/6b3af6c9.html You need to install the 32-bit flash plug-in and active-x from here: http://labs.adobe.com/downloads/flashplayer10.html After that you should be able to see your demonstration using IE 32-bit in Windows 7 64-bit. Carlos "John Melchitt" wrote: > ...

Windows Mail spelling control Dutch
Spelling control of my Windows Mail (Version 6.0.6000.16386 / Vista_rtm.061101-2205) is presently limited to English, French, German, Spanish. I want to include spelling control for Dutch. I received below advise, but after donwload and installation of the most recent version of Wlndows Live, no upgrade to below mentioned latest version has happened, nor is there a complement of 37 spell check languages. ********************** Make sure you have the latest version (14.0.8089.0726), and you have to be online to see the full complement of 37 spell check languages. ****************...

Direction of selection in CRichEditCtrl
I believe that CRichEditCtrl::GetSel() does not relay a key piece of information regarding the current selection, namely the direction of the selection. This function always returns the smaller position first, and the larger position second. I would expect this function to return the larger position first and the smaller position second in the case of the user selecting backwards (from right to left). The reason for my expectations is that CRichEditCtrl::SetSel() does support this scheme for relaying the direction of the selection, unlike CRichEditCtrl::GetSel(). I can put the cursor at the e...

How do I stop Excel from deleting the Window's Clipboard Contents
Note: This is with the Office Clipboard turned OFF! For example, If I write the following in 5 cells in Excel. [Hello ][My ][Name ][Is ][Fred ] Then I Copy (CTRL+C) the Cells: [Is ] and [Fred ] to the Clipboard... Then I press [Esc] (there are a dozen other ways to do this, but, this is the simplest) Now, I go to any cell, anywhere in my workbook, and press Paste (CTRL+V)... No Data... If I open up Notepad... Paste (CTRL+V).... No Data... Excel has *decided* for me, that I want to delete the Window's Clipboard Contents. Although I ha...

Struggle in USB Rndis Bootloader wince 5.0.
Hi This is the continuation of the below link : http://groups.google.co.in/group/microsoft.public.windowsce.platbuilder/browse_thread/thread/9a3d0f92deff702a The below code snippet is taken from rndis.c file in RNE_MDD folder. Actually, I got the print statement upto: "***Rndis:: Get MAC address blah,blah,blah". the next print statement is not printed (RNDIS_INITIALIZED SUCCESSFULLY ...). But the RndisMdd.dwDeviceState flag is set to RNDIS_INITIALIZED when i get rndis initialize request. But why this print is not displayed and the below code is also not executed. So,...

Excel 2003
There doesn't seem to be an Office 2003 group, I hope you can help, this is driving me mad! I want to open two different spreadsheets in two different instances of Excel, so I can compare them side by side without switching. Excel XP was OK, but Excel 2003 won't let me, so at the moment I've got one spreadsheet running on a different PC! I've seen a similar question asked many times, but the answer to use: Tools | Options | View Tab | Show| Windows in Taskbar does *not* fix the problem, this just lets you switch windows on the Taskbar; I want two separate windows like in X...

Modifying item lookup window
Is it possible to modify the item lookup window to show Description by default instead of Short Description? I know users can get to the description on that window with an additional click, but when they are doing lookups frequently that's a lot of extra clicks. Thanks. -- Jim@TurboChef Hi Jim, There is a product called SmartFill that will allow you to create the lookup window for an Item anyway you want. It is relatively inexpensive, probably a little more then the cost of customizing the window. But it works with Items, Customers, Vendors, Account Numbers, Employees, etc. it a...

copy data to differences places based on selection
I have a master list of entities name in master name sheets. Let say entity 1 to entitiy 100. If I select Entity 1 to Entity 10, these 1 to 10 entities insert below group1, group2, group 3 in sheet1. It also insert below group4, group5 in sheet2. I don't have preference about how to select the names in master list. Anything like check, or yes is fine to me. I am open to any idea or method. thank you in advance. ...

List Box
I am stumped and need some assistance - PLEASE. New to List Boxes. I have created two unbound list boxes on an unbound form to use as criteria for a report. Both list boxes (lboxCategory and lboxSupplier) have two fields CategoryID and Category and SupplierID and Supplier sorting ascending on latter fields. The Multi-Select property is set to Extended. I have a command button cmdPreview that I would like to use to preview the report after selections are made. I will select two or more choices from each list box at a time. Can anyone get me started with the code I need to make this h...

external usb HDD crashes Windows
It was supposed to be a good external HDD. after not using it for a while i connected it to two different PCs and first it is recognized and then screen goes black. both XP pro, one SP2 and the other SP3. If I leave it connected then the PC attempts to restart and crashes again. both PCs same deal. tried a different PSU and a different USB cable, same. Do not have a another enclosure, but am ordering one. It's a WD 5000AAKS not good timOleary wrote: > It was supposed to be a good external HDD. > after not using it for a while i connected it to two different PCs >...

Error 2203. An internal error has occurred. (C:\Windows\Installer\
Installing Microsoft Outlook 2007 on Windows Vista 32 SP1 products this error. Error 2203. An internal error has occurred. (C:\Windows\Installer\...) Contact Microsoft Product Support Services (PSS) for assistance. ...

Selective backup
Canadian payroll is treated as a Project in GP's. In the good old days we could do a selective backup of only the files in the Project folder. Now, it seems, its all or nothing (GP's 7.5 on Sql). Is there a way to backup/restore only Project, or other module's, files? Thanks I believe Winthrop Development (www.winthropdc.com) has a tool that enables you to back up a portion of a database. "noyb" wrote: > Canadian payroll is treated as a Project in GP's. In the good old days > we could do a selective backup of only the files in the Project folder. > ...

Outlook 2003 Reminder Windows
In previous versions of Outlook, the reminder windows for tasks, meetings, etc. used to come up in separate windows. In 2003 they come up in one box. Is there any way to get the multiple display back? Thanks, - Eric Nope...sorry. -- Jocelyn Fiorello MVP - Outlook *** Messages sent to my e-mail address will NOT be answered -- please reply only to the newsgroup to preserve the message thread. *** In news:176b01c46f43$c2820790$a501280a@phx.gbl, EricS wrote: > In previous versions of Outlook, the reminder windows for > tasks, meetings, etc. used to come up in separate windows. >...