From: dhmot on
I'm quite positive that the device supports selective suspend, and this
morning re-confirmed that it does with an Ellisys USB analyzer on both XP SP3
and Vista SP2. A "SetFeature(RemoteWakeup)" is sent out, the device enters
selective suspend. Upon wake, a "Clear Feature(RemoteWakeup)" is sent out.
Both transactions were successful and returned an "ACK" packet.

The power management tab of both XP and Vista have a check box checked that
says "Allow the computer to turn off this device to save power".

Concerning the sequence, I was basing my statement off of the KMDF & Kernel
Mode Driver Architecture documents provided on-line at MSDN (I do not own the
book you refer to, but it's now on my "Buy Real Soon" list). Under "Windows
Driver Kit -> Kernel-Mode Driver Architecture -> Design Guide -> Writing WDM
Drivers -> Implementing Power Management -> Managing Power for Individual
Devices -> Device Power States", the final paragraph says:

"Like the system, a device can transition from the working state (D0) to any
sleeping state (D1-D3) and from any sleeping state to the working state."

Under "Windows Driver Kit -> Windows Driver Foundation -> Kernel-Mode Driver
Framework -> Design Guide -> PnP and Power Management in Framework-Based
Drivers -> PnP and Power Management Scenarios -> A Device Enters a Low-Power
State", there's no mention of a call to the "IO Flush" callback. In the
collected logs, the "IO Flush" callback takes place about 12 seconds -after-
the "D0 Exit to D2 (Selective Suspend)" callback completes, so I don't think
it's part of the entry into selective suspend. The only time I see the "IO
Flush" callback mentioned is under the "A User Unplugs a Device" scenario.
And in order to hit that scenario, the driver must be brought back to D0 per
the section I mentioned in the preceding paragraph. This seems to have
changed in Vista versus XP. XP brings the driver back to D0 first, then
takes it to D3. Vista just does a D2 to D3 transition (if a bus powered
device is removed, it's certainly no longer in D2).

However, my driver works regardless of whether or not it returned to D0
first. Under WHQL testing, ithe driver is not handling any traffic, so has
no cleanup to perform. Also, since the device went from D2 to D3 directly,
the driver does not perform a reset of the device (i.e. the device will not
re-enumerate). When told to perform an "IO Flush", the driver assumes that
the device is physically gone.

Here's a DbgView output snippet starting from when the "IO Suspend" is
received by my driver. My driver has a prefix of "CtbUsb":

--------------------
00000226 64.85100555 Ctb:--> pwrIoSuspend
00000227 64.85101318 Ctb:--> CtbReaderStop
00000228 64.85102081 Ctb:<-- CtbReaderStop (not started)
00000229 64.85102081 Ctb:<-- pwrIoSuspend
00000230 64.85131073 PNPFILTR: List has 0 entries
00000231 64.85131836 PNPFILTR: Processed 0 IRPs
00000232 64.85133362 PNPFILTR: List has 0 entries
00000233 64.85133362 PNPFILTR: Processed 0 IRPs
00000234 64.85134125 Ctb:--> pwrD0Exit (3)
00000235 64.85134888 Ctb:<-- pwrD0Exit (in DFU mode/target state
not 5)
00000236 66.62499237 PNPFILTR: Received IRP_MN_QUERY_CAPABILITIES
which I am simply passing down
00000237 66.64597321 PNPFILTR: Received IRP_MN_QUERY_CAPABILITIES
which I am simply passing down
00000238 66.65718079 PNPFILTR: Received IRP_MN_QUERY_INTERFACE
which I am simply passing down
00000239 76.08638763 PNPFILTR: Received IOCTL_QUERY_DEVICE_COUNT
00000240 76.08644867 PNPFILTR: Received
IOCTL_QUERY_HARDWARE_ID_SIZE for PDO 0x9DF3D030
00000241 76.08652496 PNPFILTR: Received IOCTL_QUERY_HARDWARE_ID
for PDO 0x9DF3D030
00000242 76.08661652 PNPFILTR: Received
IOCTL_SURPRISE_REMOVE_DEVICE for PDO 0x9DF3D030
00000243 76.08661652 PNPFILTR: Calling IoInvalidateDeviceState to
start rebalance on PDO 9DF3D030
00000244 76.08663177 PNPFILTR: Received
IRP_MN_QUERY_PNP_DEVICE_STATE for stack with PDO 0x9DF3D030
00000245 76.08679962 PNPFILTR: Recieved Query Result
00000246 76.08680725 PNPFILTR: Waiting for test to be completed -
will wait for 50 seconds
00000247 76.08682251 PNPFILTR: FilterCompletionRoutine Completed,
event set.
00000248 76.08683014 PNPFILTR: Completing
IRP_MN_QUERY_PNP_DEVICE_STATE for PDO 0x9DF3D030 with status 0x00000000 and
information 0x00000004
00000249 76.08685303 PNPFILTR: Received
IRP_MN_QUERY_DEVICE_RELATIONS which I am simply passing down
00000250 76.08687592 PNPFILTR: Received IRP_MN_SURPRISE_REMOVAL
for stack with PDO 0x9DF3D030
00000251 76.08901215 Ctb:--> pwrIoFlush
00000252 76.08901978 Ctb:--> CtbReaderFlush
00000253 76.08902740 Ctb:<-- CtbReaderFlush
00000254 76.08902740 Ctb:--> pmdtStopPmdt
00000255 76.08902740 Ctb:<-- pmdtStopPmdt
00000256 76.08903503 Ctb:<-- pwrIoFlush
00000257 76.08925629 PNPFILTR: FilterSurpriseRemove returning
0x00000103 for stack with PDO 0x9DF3D030
00000258 76.11583710 PNPFILTR: Received IRP_MN_REMOVE_DEVICE for
stack with PDO 0x9DF3D030
00000259 76.11583710 PNPFILTR: Setting the test completed event
00000260 76.11584473 PNPFILTR: Waiting for result to be stored
00000261 76.11585236 PNPFILTR: Query Result Wait Satisfied... 4
00000262 76.11585236 PNPFILTR: Number of IRPs Stored... 4
00000263 76.11586761 PNPFILTR: Query Result - Releasing the remove
00000264 76.11587524 PNPFILTR: Remove Wait completed... now
deleting
00000265 76.11587524 PNPFILTR: List has 0 entries
00000266 76.11588287 PNPFILTR: Processed 0 IRPs
00000267 76.11589813 PNPFILTR: Query Result -Result Stored Event
set
00000268 76.13028717 PNPFILTR: Deleting the global control object
00000269 76.13031006 PNPFILTR: FilterRemove returning 0x00000000
for stack with PDO 0x9DF3D030
--------------------

Is there some new Vista requirement for D2 -> D3 support that's needed?
I've removed the device while it was in selective suspend, and that operation
works fine in both Vista and XP. Likewise, I've issued a "Disable" request
from the device manager, and under that scenario Vista acts like XP. The
only remaining issue seems to be with this PnP test.

Thanks,
Michael

"Egidio [MSFT]" wrote:

> The sequence below seems correct and consistent with the flow you can find
> in pages 181 to 189 of Windows Driver Foundation book. It may be possible
> that in XP the device doesn't support selective suspend. Please check the
> device characteristics of your node (device manager). Do you see the
> PowerManager tab in XP? like you see in Vista.
> What are the info you see in Details->Power Data in both XP and Vista for
> this device?
> Is it possible that this device doesn't support selective suspend?
>
> Thx,
> Egi.
>
> "dhmot" <dhmot(a)discussions.microsoft.com> wrote in message
> news:1A229197-B74F-4822-9CC4-FAEE1510B4E9(a)microsoft.com...
> > To answer your questions (#5 is probably the most important):
> >
> > 1) As far as I can tell, the test runs - I see the PnP window appear for
> > a
> > short period, maybe a few seconds, at least twice during the PnP test. At
> > the end of my response, I've included the log file (uuencoded zip file).
> >
> > 2) I do nothing special for a surprise remove that I do for any other
> > condition that causes the device to enter D3; it's the same code that's
> > used
> > if someone right-clicks on the device in device manager and "Disable"s it.
> >
> > 3) I re-ran the test with the selective suspend time-out cranked down to
> > one second on Windows XP. This should cause the driver and device to
> > enter
> > selective suspend. The test still passed on Windows XP.
> >
> > 4) As far as I'm aware, my driver is not a child of USBCCGP. I assume
> > this
> > is something I'd have to call out explicitly. If not, please tell me how
> > I'd
> > know.
> >
> > 5) I performed a log comparison and found one major difference just prior
> > to
> > the second driver re-load (initial driver load on boot-up, first driver
> > re-load after start of test, then second driver re-load). On XP, the
> > callback sequence after the first driver re-load was as follows:
> >
> > DriverEntry
> > Device Add
> > Prepare Hardware
> > IO Init
> > IO Suspend
> > D0 Exit to D3
> > IO Flush
> >
> > The above is what I would normally expect. However, Vista threw the
> > following at my driver:
> >
> > DriverEntry
> > Device Add
> > Prepare Hardware
> > IO Init
> > IO Suspend
> > D0 Exit to D2 (selective suspend)
> > IO Flush
> >
> > I would have expected it to have called my IO Restart callback after the
> > D0
> > Exit to D2, then IO Suspend, then D0 Exit to D3, and THEN IO Flush.
> > Turning
> > on WDF Verifier did not affect this. After this occurs, Vista re-loads my
> > driver and stops testing while XP continues testing.
> >
> > 6) I did not have WDF Verifier enabled for either Vista or XP. Once I
> > discovered #5, I re-ran the test on Vista with WDF Verifier enabled for
> > the
> > USB driver (I'm not sure how to enable it for WDF01000). There was no
> > change
> > in the test results.
> >
> > 7) I have no Windows 7 machines available to me at the moment.
> >
> > Any ideas why #5 is happening?
> >
> > Thanks,
> > Michael
> >
> > PnP result log:
> >
> >
>
>
>
> >
> >
> > "Egidio [MSFT]" wrote:
> >
> >> Just to understand more about this error.
> >> does the surprise remove test run? or doesnâ?Tt even run because the
> >> device is
> >> not initializing correctly, i.e., the previous test left the device in a
> >> strange state?
> >> Do you do anything in your driver when you receiving surprise remove?
> >> When XP works, is the device in selective suspend? I.e., is it possible
> >> that in the XP case you don't see a problem b/c the device never enters
> >> the
> >> selective suspend state?
> >> Is your client driver a child of USBCCGP?
> >> Do you see the same callbacks from your driver point of view in both the
> >> XP
> >> and Vista cases?
> >> Did you make sure to enable device verifier and wdf verifier on your
> >> driver
> >> and wdf01000?
> >> Since Win7 is available, do you see any problem in Win7? Win7 has better
> >> logging for USB.
> >>
> >> Egi.
> >>
> >> "dhmot" <dhmot(a)discussions.microsoft.com> wrote in message
> >> news:5E3C4F23-83C8-4BFF-8AE7-3243860E4C2A(a)microsoft.com...
> >> > The same hardware series is used (Dell Precision 380), although not
> >> > exactly
> >> > the same machine. The failure occurs with three different devices on
> >> > Vista
> >> > (all that are available to me), and at least one of those passes on XP.
> >> > WDF
> >> > Framework 1.7 is used for both, not 1.9. I can't say if it's exactly
> >> > the
> >> > same PnP test, as one is run on Vista and the other on XP. I do have
> >> > the
> >> > latest filters and have installed QFE011 & QFE002.
> >> >
> >> > So as far as I can tell, the only difference is the OS.
> >> >
> >> > If you think there's some benefit, I can try swapping hard drives
> >> > between
> >> > the XP and Vista machines to see if that makes a difference. Let me
> >> > know.
> >> >
> >> > Michael
> >> >
> >> > "Egidio [MSFT]" wrote:
> >> >
> >> >> Just to clarify, what is different in your environment from Vista and
> >> >> XP?
> >> >> Only the OS? Is everything else is the same? system h/w, device h/w,
> >> >> WDF
> >> >> framework 1.9, PnP tests?
> >> >> Otherwise can you try re-running the tests on the h/w that works?
> >> >>
> >> >> Egi.
> >> >>
> >> >> "dhmot" <dhmot(a)discussions.microsoft.com> wrote in message
> >> >> news:B3EA455C-E94A-4A4F-A145-B8E5C14ADDBF(a)microsoft.com...
> >> >> > All,
> >> >> >
> >> >> > I'm sure you're all tired of hearing of my WHQL trials and
> >> >> > tribulations
> >> >> > :),
> >> >> > but I've got another question. I have a KMDF driver for a USB
> >> >> > device.
> >> >> > The
> >> >> > device and driver support selective suspend, and have a default
> >> >> > selective
> >> >> > suspend time-out of five seconds. If I run the PnP Driver Test on
> >> >> > an
> >> >> > x86
> >> >> > Vista + SP2 Dell Precision 380, the test fails unless I disable
> >> >> > selective
> >> >> > suspend first. The surprise removal test is the test that fails
> >> >> > with
> >> >> > an
> >> >> > error of "Device node status not ok: problem code 10". I've
> >> >> > confirmed
> >> >> > that
> >> >> > my driver is not returning any errors nor is it hitting any code I
> >> >> > would
> >> >> > not
> >> >> > expect it to hit. Likewise, I see nothing wayward in the debug
> >> >> > output
> >> >> > from
> >> >> > the PNP filter captured via Dbgview.
> >> >> >
> >> >> > If I disable selective suspend, all "PnP Driver Test" tests pass
> >> >> > under
> >> >> > x86
> >> >> > Vista. Likewise, all "PnP Driver Test" tests pass under XP (x86 and
> >> >> > x64)
> >> >> > with selective suspend enabled.
> >> >> >
> >> >> > What's the proper solution for this?
> >> >> >
> >> >> > Thanks,
> >> >> > Michael
> >> >>
> >> >>
> >>
>
From: Egidio [MSFT] on
WDF does not bring the device in D0 after receiving surprise_remove if the
device is already suspended, the device goes into a special D3 state. Since
you are using the same WDF 1.7 in both platforms (XP and Vista) and I assume
the same driver, (and the same test? If not, try using the same test too),
the only diff is the USB layer. USB layer has changed a lot from XP to
Vista and from Vista to Win7. Thus this diff in behavior can be indeed
attributed to the USB layer. But this doesn't explain why the test fails.

Is your device a high speed device? Can you disable the EHCI drivers on your
machine via device manager for your USB ports? This will allow your device
to use UHCI or OHCI. Re-run again the same test and let me know if the test
works.

And what exactly does it fail on the next start? Is the driver called at
all?

Please also take a look at http://support.microsoft.com/kb/314743 for more
info on how to get USB stack trace info.
(For Vista, the debug symbol in USBCCGP is dbgLevel. USBHUB debug output is
via WPP only).

Thx,
Egi.

Note about the EvtDeviceSelfManagedIoFlush callback function from MSDN: the
framework calls it after the device has been removed. The driver should
flush (that is, remove) I/O requests that are associated with the device's
self-managed I/O operations.
http://msdn.microsoft.com/en-us/library/aa491132.aspx

"dhmot" <dhmot(a)discussions.microsoft.com> wrote in message
news:948B0825-EE66-4CA5-A1CE-79FD944B5717(a)microsoft.com...
> I'm quite positive that the device supports selective suspend, and this
> morning re-confirmed that it does with an Ellisys USB analyzer on both XP
> SP3
> and Vista SP2. A "SetFeature(RemoteWakeup)" is sent out, the device
> enters
> selective suspend. Upon wake, a "Clear Feature(RemoteWakeup)" is sent
> out.
> Both transactions were successful and returned an "ACK" packet.
>
> The power management tab of both XP and Vista have a check box checked
> that
> says "Allow the computer to turn off this device to save power".
>
> Concerning the sequence, I was basing my statement off of the KMDF &
> Kernel
> Mode Driver Architecture documents provided on-line at MSDN (I do not own
> the
> book you refer to, but it's now on my "Buy Real Soon" list). Under
> "Windows
> Driver Kit -> Kernel-Mode Driver Architecture -> Design Guide -> Writing
> WDM
> Drivers -> Implementing Power Management -> Managing Power for Individual
> Devices -> Device Power States", the final paragraph says:
>
> "Like the system, a device can transition from the working state (D0) to
> any
> sleeping state (D1-D3) and from any sleeping state to the working state."
>
> Under "Windows Driver Kit -> Windows Driver Foundation -> Kernel-Mode
> Driver
> Framework -> Design Guide -> PnP and Power Management in Framework-Based
> Drivers -> PnP and Power Management Scenarios -> A Device Enters a
> Low-Power
> State", there's no mention of a call to the "IO Flush" callback. In the
> collected logs, the "IO Flush" callback takes place about 12
> seconds -after-
> the "D0 Exit to D2 (Selective Suspend)" callback completes, so I don't
> think
> it's part of the entry into selective suspend. The only time I see the
> "IO
> Flush" callback mentioned is under the "A User Unplugs a Device" scenario.
> And in order to hit that scenario, the driver must be brought back to D0
> per
> the section I mentioned in the preceding paragraph. This seems to have
> changed in Vista versus XP. XP brings the driver back to D0 first, then
> takes it to D3. Vista just does a D2 to D3 transition (if a bus powered
> device is removed, it's certainly no longer in D2).
>
> However, my driver works regardless of whether or not it returned to D0
> first. Under WHQL testing, ithe driver is not handling any traffic, so
> has
> no cleanup to perform. Also, since the device went from D2 to D3
> directly,
> the driver does not perform a reset of the device (i.e. the device will
> not
> re-enumerate). When told to perform an "IO Flush", the driver assumes
> that
> the device is physically gone.
>
> Here's a DbgView output snippet starting from when the "IO Suspend" is
> received by my driver. My driver has a prefix of "CtbUsb":
>
> --------------------
> 00000226 64.85100555 Ctb:--> pwrIoSuspend
> 00000227 64.85101318 Ctb:--> CtbReaderStop
> 00000228 64.85102081 Ctb:<-- CtbReaderStop (not started)
> 00000229 64.85102081 Ctb:<-- pwrIoSuspend
> 00000230 64.85131073 PNPFILTR: List has 0 entries
> 00000231 64.85131836 PNPFILTR: Processed 0 IRPs
> 00000232 64.85133362 PNPFILTR: List has 0 entries
> 00000233 64.85133362 PNPFILTR: Processed 0 IRPs
> 00000234 64.85134125 Ctb:--> pwrD0Exit (3)
> 00000235 64.85134888 Ctb:<-- pwrD0Exit (in DFU mode/target
> state
> not 5)
> 00000236 66.62499237 PNPFILTR: Received
> IRP_MN_QUERY_CAPABILITIES
> which I am simply passing down
> 00000237 66.64597321 PNPFILTR: Received
> IRP_MN_QUERY_CAPABILITIES
> which I am simply passing down
> 00000238 66.65718079 PNPFILTR: Received IRP_MN_QUERY_INTERFACE
> which I am simply passing down
> 00000239 76.08638763 PNPFILTR: Received
> IOCTL_QUERY_DEVICE_COUNT
> 00000240 76.08644867 PNPFILTR: Received
> IOCTL_QUERY_HARDWARE_ID_SIZE for PDO 0x9DF3D030
> 00000241 76.08652496 PNPFILTR: Received IOCTL_QUERY_HARDWARE_ID
> for PDO 0x9DF3D030
> 00000242 76.08661652 PNPFILTR: Received
> IOCTL_SURPRISE_REMOVE_DEVICE for PDO 0x9DF3D030
> 00000243 76.08661652 PNPFILTR: Calling IoInvalidateDeviceState
> to
> start rebalance on PDO 9DF3D030
> 00000244 76.08663177 PNPFILTR: Received
> IRP_MN_QUERY_PNP_DEVICE_STATE for stack with PDO 0x9DF3D030
> 00000245 76.08679962 PNPFILTR: Recieved Query Result
> 00000246 76.08680725 PNPFILTR: Waiting for test to be
> completed -
> will wait for 50 seconds
> 00000247 76.08682251 PNPFILTR: FilterCompletionRoutine
> Completed,
> event set.
> 00000248 76.08683014 PNPFILTR: Completing
> IRP_MN_QUERY_PNP_DEVICE_STATE for PDO 0x9DF3D030 with status 0x00000000
> and
> information 0x00000004
> 00000249 76.08685303 PNPFILTR: Received
> IRP_MN_QUERY_DEVICE_RELATIONS which I am simply passing down
> 00000250 76.08687592 PNPFILTR: Received IRP_MN_SURPRISE_REMOVAL
> for stack with PDO 0x9DF3D030
> 00000251 76.08901215 Ctb:--> pwrIoFlush
> 00000252 76.08901978 Ctb:--> CtbReaderFlush
> 00000253 76.08902740 Ctb:<-- CtbReaderFlush
> 00000254 76.08902740 Ctb:--> pmdtStopPmdt
> 00000255 76.08902740 Ctb:<-- pmdtStopPmdt
> 00000256 76.08903503 Ctb:<-- pwrIoFlush
> 00000257 76.08925629 PNPFILTR: FilterSurpriseRemove returning
> 0x00000103 for stack with PDO 0x9DF3D030
> 00000258 76.11583710 PNPFILTR: Received IRP_MN_REMOVE_DEVICE
> for
> stack with PDO 0x9DF3D030
> 00000259 76.11583710 PNPFILTR: Setting the test completed event
> 00000260 76.11584473 PNPFILTR: Waiting for result to be stored
> 00000261 76.11585236 PNPFILTR: Query Result Wait Satisfied...
> 4
> 00000262 76.11585236 PNPFILTR: Number of IRPs Stored... 4
> 00000263 76.11586761 PNPFILTR: Query Result - Releasing the
> remove
> 00000264 76.11587524 PNPFILTR: Remove Wait completed... now
> deleting
> 00000265 76.11587524 PNPFILTR: List has 0 entries
> 00000266 76.11588287 PNPFILTR: Processed 0 IRPs
> 00000267 76.11589813 PNPFILTR: Query Result -Result Stored
> Event
> set
> 00000268 76.13028717 PNPFILTR: Deleting the global control
> object
> 00000269 76.13031006 PNPFILTR: FilterRemove returning
> 0x00000000
> for stack with PDO 0x9DF3D030
> --------------------
>
> Is there some new Vista requirement for D2 -> D3 support that's needed?
> I've removed the device while it was in selective suspend, and that
> operation
> works fine in both Vista and XP. Likewise, I've issued a "Disable"
> request
> from the device manager, and under that scenario Vista acts like XP. The
> only remaining issue seems to be with this PnP test.
>
> Thanks,
> Michael
>
> "Egidio [MSFT]" wrote:
>
>> The sequence below seems correct and consistent with the flow you can
>> find
>> in pages 181 to 189 of Windows Driver Foundation book. It may be possible
>> that in XP the device doesn't support selective suspend. Please check
>> the
>> device characteristics of your node (device manager). Do you see the
>> PowerManager tab in XP? like you see in Vista.
>> What are the info you see in Details->Power Data in both XP and Vista for
>> this device?
>> Is it possible that this device doesn't support selective suspend?
>>
>> Thx,
>> Egi.
>>
>> "dhmot" <dhmot(a)discussions.microsoft.com> wrote in message
>> news:1A229197-B74F-4822-9CC4-FAEE1510B4E9(a)microsoft.com...
>> > To answer your questions (#5 is probably the most important):
>> >
>> > 1) As far as I can tell, the test runs - I see the PnP window appear
>> > for
>> > a
>> > short period, maybe a few seconds, at least twice during the PnP test.
>> > At
>> > the end of my response, I've included the log file (uuencoded zip
>> > file).
>> >
>> > 2) I do nothing special for a surprise remove that I do for any other
>> > condition that causes the device to enter D3; it's the same code that's
>> > used
>> > if someone right-clicks on the device in device manager and "Disable"s
>> > it.
>> >
>> > 3) I re-ran the test with the selective suspend time-out cranked down
>> > to
>> > one second on Windows XP. This should cause the driver and device to
>> > enter
>> > selective suspend. The test still passed on Windows XP.
>> >
>> > 4) As far as I'm aware, my driver is not a child of USBCCGP. I assume
>> > this
>> > is something I'd have to call out explicitly. If not, please tell me
>> > how
>> > I'd
>> > know.
>> >
>> > 5) I performed a log comparison and found one major difference just
>> > prior
>> > to
>> > the second driver re-load (initial driver load on boot-up, first driver
>> > re-load after start of test, then second driver re-load). On XP, the
>> > callback sequence after the first driver re-load was as follows:
>> >
>> > DriverEntry
>> > Device Add
>> > Prepare Hardware
>> > IO Init
>> > IO Suspend
>> > D0 Exit to D3
>> > IO Flush
>> >
>> > The above is what I would normally expect. However, Vista threw the
>> > following at my driver:
>> >
>> > DriverEntry
>> > Device Add
>> > Prepare Hardware
>> > IO Init
>> > IO Suspend
>> > D0 Exit to D2 (selective suspend)
>> > IO Flush
>> >
>> > I would have expected it to have called my IO Restart callback after
>> > the
>> > D0
>> > Exit to D2, then IO Suspend, then D0 Exit to D3, and THEN IO Flush.
>> > Turning
>> > on WDF Verifier did not affect this. After this occurs, Vista re-loads
>> > my
>> > driver and stops testing while XP continues testing.
>> >
>> > 6) I did not have WDF Verifier enabled for either Vista or XP. Once I
>> > discovered #5, I re-ran the test on Vista with WDF Verifier enabled for
>> > the
>> > USB driver (I'm not sure how to enable it for WDF01000). There was no
>> > change
>> > in the test results.
>> >
>> > 7) I have no Windows 7 machines available to me at the moment.
>> >
>> > Any ideas why #5 is happening?
>> >
>> > Thanks,
>> > Michael
>> >
>> > PnP result log:
>> >
>> >
>>
>>
>>
>> >
>> >
>> > "Egidio [MSFT]" wrote:
>> >
>> >> Just to understand more about this error.
>> >> does the surprise remove test run? or doesnâ?Tt even run because the
>> >> device is
>> >> not initializing correctly, i.e., the previous test left the device in
>> >> a
>> >> strange state?
>> >> Do you do anything in your driver when you receiving surprise remove?
>> >> When XP works, is the device in selective suspend? I.e., is it
>> >> possible
>> >> that in the XP case you don't see a problem b/c the device never
>> >> enters
>> >> the
>> >> selective suspend state?
>> >> Is your client driver a child of USBCCGP?
>> >> Do you see the same callbacks from your driver point of view in both
>> >> the
>> >> XP
>> >> and Vista cases?
>> >> Did you make sure to enable device verifier and wdf verifier on your
>> >> driver
>> >> and wdf01000?
>> >> Since Win7 is available, do you see any problem in Win7? Win7 has
>> >> better
>> >> logging for USB.
>> >>
>> >> Egi.
>> >>
>> >> "dhmot" <dhmot(a)discussions.microsoft.com> wrote in message
>> >> news:5E3C4F23-83C8-4BFF-8AE7-3243860E4C2A(a)microsoft.com...
>> >> > The same hardware series is used (Dell Precision 380), although not
>> >> > exactly
>> >> > the same machine. The failure occurs with three different devices
>> >> > on
>> >> > Vista
>> >> > (all that are available to me), and at least one of those passes on
>> >> > XP.
>> >> > WDF
>> >> > Framework 1.7 is used for both, not 1.9. I can't say if it's
>> >> > exactly
>> >> > the
>> >> > same PnP test, as one is run on Vista and the other on XP. I do
>> >> > have
>> >> > the
>> >> > latest filters and have installed QFE011 & QFE002.
>> >> >
>> >> > So as far as I can tell, the only difference is the OS.
>> >> >
>> >> > If you think there's some benefit, I can try swapping hard drives
>> >> > between
>> >> > the XP and Vista machines to see if that makes a difference. Let me
>> >> > know.
>> >> >
>> >> > Michael
>> >> >
>> >> > "Egidio [MSFT]" wrote:
>> >> >
>> >> >> Just to clarify, what is different in your environment from Vista
>> >> >> and
>> >> >> XP?
>> >> >> Only the OS? Is everything else is the same? system h/w, device
>> >> >> h/w,
>> >> >> WDF
>> >> >> framework 1.9, PnP tests?
>> >> >> Otherwise can you try re-running the tests on the h/w that works?
>> >> >>
>> >> >> Egi.
>> >> >>
>> >> >> "dhmot" <dhmot(a)discussions.microsoft.com> wrote in message
>> >> >> news:B3EA455C-E94A-4A4F-A145-B8E5C14ADDBF(a)microsoft.com...
>> >> >> > All,
>> >> >> >
>> >> >> > I'm sure you're all tired of hearing of my WHQL trials and
>> >> >> > tribulations
>> >> >> > :),
>> >> >> > but I've got another question. I have a KMDF driver for a USB
>> >> >> > device.
>> >> >> > The
>> >> >> > device and driver support selective suspend, and have a default
>> >> >> > selective
>> >> >> > suspend time-out of five seconds. If I run the PnP Driver Test
>> >> >> > on
>> >> >> > an
>> >> >> > x86
>> >> >> > Vista + SP2 Dell Precision 380, the test fails unless I disable
>> >> >> > selective
>> >> >> > suspend first. The surprise removal test is the test that fails
>> >> >> > with
>> >> >> > an
>> >> >> > error of "Device node status not ok: problem code 10". I've
>> >> >> > confirmed
>> >> >> > that
>> >> >> > my driver is not returning any errors nor is it hitting any code
>> >> >> > I
>> >> >> > would
>> >> >> > not
>> >> >> > expect it to hit. Likewise, I see nothing wayward in the debug
>> >> >> > output
>> >> >> > from
>> >> >> > the PNP filter captured via Dbgview.
>> >> >> >
>> >> >> > If I disable selective suspend, all "PnP Driver Test" tests pass
>> >> >> > under
>> >> >> > x86
>> >> >> > Vista. Likewise, all "PnP Driver Test" tests pass under XP (x86
>> >> >> > and

From: dhmot on
My device is a high speed device. I disabled the EHCI, which caused the
device to enumerate at full speed. When I run the PnP test under this
condition, I get the same results, and the log file looks very similar.

I'm selecting the same PnP DTM test on both XP and Vista. However, I do not
know what DTM is doing behind the scenes. DTM is aware that the OS is not
the same; I do not know if DTM is configuruing the PnP test slightly
different for XP versus Vista.

I'm not quite sure why there is a failure, at least from the log file.
After the surprise removal test completes, my driver is reloaded. Here's the
output from from the driver re-load to the end of the DbgView log file
(kernel output only captured):

00000311 60.73113251 Ctb:--> DriverEntry built Aug 31 2009 12:38:03
00000312 60.73143005 Ctb:<-- DriverEntry (0x0)
00000313 60.73184204 Ctb:CtbRegGetDword: Found DebugFlags = 6
00000314 60.73185349 Ctb:<-- CtbRegGetDword (DebugFlags)
00000315 60.73185730 Ctb:CtbDeviceAdd: handle 0x61f39878, Debug: 6
00000316 60.73186111 Ctb:--> CtbRegGetDword (D3Flag)
00000317 60.73195648 Ctb:CtbRegGetDword: Found D3Flag = 1
00000318 60.73196030 Ctb:<-- CtbRegGetDword (D3Flag)
00000319 60.73196411 Ctb:CtbDeviceAdd: D3Flag: 1
00000320 60.75346756 Ctb:<-- CtbDeviceAdd
00000321 60.75364685 PNPFILTR: Events being initialized
00000322 60.75368881 PNPFILTR: Received
IRP_MN_QUERY_LEGACY_BUS_INFORMATION which I am simply passing down
00000323 60.75377655 PNPFILTR: Received
IRP_MN_QUERY_RESOURCE_REQUIREMENTS which I am simply passing down
00000324 60.75382233 PNPFILTR: Received
IRP_MN_FILTER_RESOURCE_REQUIREMENT for stack with PDO 0x85921030
00000325 60.75382996 PNPFILTR: FilterCompletionRoutine Completed,
event set.
00000326 60.75383377 PNPFILTR: FilterFilterResourceRequirement
returning 0x00000000 for stack with PDO 0x85921030
00000327 60.75416946 PNPFILTR: Received IRP_MN_START_DEVICE for
stack with PDO 0x85921030
00000328 60.75426865 PNPFILTR: FilterCompletionRoutine Completed,
event set.
00000329 60.75428391 PNPFILTR: Time taken for IRP_MN_START_DEVICE
to get processed for the PDO 85921030 is 0 miliseconds
00000330 60.75429153 PNPFILTR: Completing Start request with
status == 0xC000000E PDO = 0x85921030
00000331 60.83396530 PNPFILTR: Received IRP_MN_REMOVE_DEVICE for
stack with PDO 0x85921030
00000332 60.83398819 PNPFILTR: List has 0 entries
00000333 60.83399582 PNPFILTR: Processed 0 IRPs
00000334 60.88864517 PNPFILTR: Deleting the global control object
00000335 60.88867188 PNPFILTR: FilterRemove returning 0x00000000
for stack with PDO 0x85921030

Line 00000330 seems to be the error. However, my driver's callback was
never invoked (all my routines have entry and exit traces). Specifically,
after other entries like line 00000327 in this log file, I see my prepare
hardware callback being invoked.

The link http://support.microsoft.com/kb/314743 is for XP and earlier. Is
there a similar page for Vista (Google couldn't find one)? If not, which
..sys files should I debug, what is the debug flag name, and what values are
valid?

Thanks,
Michael

"Egidio [MSFT]" wrote:

> WDF does not bring the device in D0 after receiving surprise_remove if the
> device is already suspended, the device goes into a special D3 state. Since
> you are using the same WDF 1.7 in both platforms (XP and Vista) and I assume
> the same driver, (and the same test? If not, try using the same test too),
> the only diff is the USB layer. USB layer has changed a lot from XP to
> Vista and from Vista to Win7. Thus this diff in behavior can be indeed
> attributed to the USB layer. But this doesn't explain why the test fails.
>
> Is your device a high speed device? Can you disable the EHCI drivers on your
> machine via device manager for your USB ports? This will allow your device
> to use UHCI or OHCI. Re-run again the same test and let me know if the test
> works.
>
> And what exactly does it fail on the next start? Is the driver called at
> all?
>
> Please also take a look at http://support.microsoft.com/kb/314743 for more
> info on how to get USB stack trace info.
> (For Vista, the debug symbol in USBCCGP is dbgLevel. USBHUB debug output is
> via WPP only).
>
> Thx,
> Egi.
>
> Note about the EvtDeviceSelfManagedIoFlush callback function from MSDN: the
> framework calls it after the device has been removed. The driver should
> flush (that is, remove) I/O requests that are associated with the device's
> self-managed I/O operations.
> http://msdn.microsoft.com/en-us/library/aa491132.aspx
>
> "dhmot" <dhmot(a)discussions.microsoft.com> wrote in message
> news:948B0825-EE66-4CA5-A1CE-79FD944B5717(a)microsoft.com...
> > I'm quite positive that the device supports selective suspend, and this
> > morning re-confirmed that it does with an Ellisys USB analyzer on both XP
> > SP3
> > and Vista SP2. A "SetFeature(RemoteWakeup)" is sent out, the device
> > enters
> > selective suspend. Upon wake, a "Clear Feature(RemoteWakeup)" is sent
> > out.
> > Both transactions were successful and returned an "ACK" packet.
> >
> > The power management tab of both XP and Vista have a check box checked
> > that
> > says "Allow the computer to turn off this device to save power".
> >
> > Concerning the sequence, I was basing my statement off of the KMDF &
> > Kernel
> > Mode Driver Architecture documents provided on-line at MSDN (I do not own
> > the
> > book you refer to, but it's now on my "Buy Real Soon" list). Under
> > "Windows
> > Driver Kit -> Kernel-Mode Driver Architecture -> Design Guide -> Writing
> > WDM
> > Drivers -> Implementing Power Management -> Managing Power for Individual
> > Devices -> Device Power States", the final paragraph says:
> >
> > "Like the system, a device can transition from the working state (D0) to
> > any
> > sleeping state (D1-D3) and from any sleeping state to the working state."
> >
> > Under "Windows Driver Kit -> Windows Driver Foundation -> Kernel-Mode
> > Driver
> > Framework -> Design Guide -> PnP and Power Management in Framework-Based
> > Drivers -> PnP and Power Management Scenarios -> A Device Enters a
> > Low-Power
> > State", there's no mention of a call to the "IO Flush" callback. In the
> > collected logs, the "IO Flush" callback takes place about 12
> > seconds -after-
> > the "D0 Exit to D2 (Selective Suspend)" callback completes, so I don't
> > think
> > it's part of the entry into selective suspend. The only time I see the
> > "IO
> > Flush" callback mentioned is under the "A User Unplugs a Device" scenario.
> > And in order to hit that scenario, the driver must be brought back to D0
> > per
> > the section I mentioned in the preceding paragraph. This seems to have
> > changed in Vista versus XP. XP brings the driver back to D0 first, then
> > takes it to D3. Vista just does a D2 to D3 transition (if a bus powered
> > device is removed, it's certainly no longer in D2).
> >
> > However, my driver works regardless of whether or not it returned to D0
> > first. Under WHQL testing, ithe driver is not handling any traffic, so
> > has
> > no cleanup to perform. Also, since the device went from D2 to D3
> > directly,
> > the driver does not perform a reset of the device (i.e. the device will
> > not
> > re-enumerate). When told to perform an "IO Flush", the driver assumes
> > that
> > the device is physically gone.
> >
> > Here's a DbgView output snippet starting from when the "IO Suspend" is
> > received by my driver. My driver has a prefix of "CtbUsb":
> >
> > --------------------
> > 00000226 64.85100555 Ctb:--> pwrIoSuspend
> > 00000227 64.85101318 Ctb:--> CtbReaderStop
> > 00000228 64.85102081 Ctb:<-- CtbReaderStop (not started)
> > 00000229 64.85102081 Ctb:<-- pwrIoSuspend
> > 00000230 64.85131073 PNPFILTR: List has 0 entries
> > 00000231 64.85131836 PNPFILTR: Processed 0 IRPs
> > 00000232 64.85133362 PNPFILTR: List has 0 entries
> > 00000233 64.85133362 PNPFILTR: Processed 0 IRPs
> > 00000234 64.85134125 Ctb:--> pwrD0Exit (3)
> > 00000235 64.85134888 Ctb:<-- pwrD0Exit (in DFU mode/target
> > state
> > not 5)
> > 00000236 66.62499237 PNPFILTR: Received
> > IRP_MN_QUERY_CAPABILITIES
> > which I am simply passing down
> > 00000237 66.64597321 PNPFILTR: Received
> > IRP_MN_QUERY_CAPABILITIES
> > which I am simply passing down
> > 00000238 66.65718079 PNPFILTR: Received IRP_MN_QUERY_INTERFACE
> > which I am simply passing down
> > 00000239 76.08638763 PNPFILTR: Received
> > IOCTL_QUERY_DEVICE_COUNT
> > 00000240 76.08644867 PNPFILTR: Received
> > IOCTL_QUERY_HARDWARE_ID_SIZE for PDO 0x9DF3D030
> > 00000241 76.08652496 PNPFILTR: Received IOCTL_QUERY_HARDWARE_ID
> > for PDO 0x9DF3D030
> > 00000242 76.08661652 PNPFILTR: Received
> > IOCTL_SURPRISE_REMOVE_DEVICE for PDO 0x9DF3D030
> > 00000243 76.08661652 PNPFILTR: Calling IoInvalidateDeviceState
> > to
> > start rebalance on PDO 9DF3D030
> > 00000244 76.08663177 PNPFILTR: Received
> > IRP_MN_QUERY_PNP_DEVICE_STATE for stack with PDO 0x9DF3D030
> > 00000245 76.08679962 PNPFILTR: Recieved Query Result
> > 00000246 76.08680725 PNPFILTR: Waiting for test to be
> > completed -
> > will wait for 50 seconds
> > 00000247 76.08682251 PNPFILTR: FilterCompletionRoutine
> > Completed,
> > event set.
> > 00000248 76.08683014 PNPFILTR: Completing
> > IRP_MN_QUERY_PNP_DEVICE_STATE for PDO 0x9DF3D030 with status 0x00000000
> > and
> > information 0x00000004
> > 00000249 76.08685303 PNPFILTR: Received
> > IRP_MN_QUERY_DEVICE_RELATIONS which I am simply passing down
> > 00000250 76.08687592 PNPFILTR: Received IRP_MN_SURPRISE_REMOVAL
> > for stack with PDO 0x9DF3D030
> > 00000251 76.08901215 Ctb:--> pwrIoFlush
> > 00000252 76.08901978 Ctb:--> CtbReaderFlush
> > 00000253 76.08902740 Ctb:<-- CtbReaderFlush
> > 00000254 76.08902740 Ctb:--> pmdtStopPmdt
> > 00000255 76.08902740 Ctb:<-- pmdtStopPmdt
> > 00000256 76.08903503 Ctb:<-- pwrIoFlush
> > 00000257 76.08925629 PNPFILTR: FilterSurpriseRemove returning
> > 0x00000103 for stack with PDO 0x9DF3D030
> > 00000258 76.11583710 PNPFILTR: Received IRP_MN_REMOVE_DEVICE
> > for
> > stack with PDO 0x9DF3D030
> > 00000259 76.11583710 PNPFILTR: Setting the test completed event
> > 00000260 76.11584473 PNPFILTR: Waiting for result to be stored
> > 00000261 76.11585236 PNPFILTR: Query Result Wait Satisfied...
> > 4
> > 00000262 76.11585236 PNPFILTR: Number of IRPs Stored... 4
> > 00000263 76.11586761 PNPFILTR: Query Result - Releasing the
> > remove
> > 00000264 76.11587524 PNPFILTR: Remove Wait completed... now
> > deleting
> > 00000265 76.11587524 PNPFILTR: List has 0 entries
> > 00000266 76.11588287 PNPFILTR: Processed 0 IRPs
> > 00000267 76.11589813 PNPFILTR: Query Result -Result Stored
> > Event
> > set
> > 00000268 76.13028717 PNPFILTR: Deleting the global control
> > object
> > 00000269 76.13031006 PNPFILTR: FilterRemove returning
> > 0x00000000
> > for stack with PDO 0x9DF3D030
> > --------------------
> >
> > Is there some new Vista requirement for D2 -> D3 support that's needed?
> > I've removed the device while it was in selective suspend, and that
> > operation
> > works fine in both Vista and XP. Likewise, I've issued a "Disable"
> > request
> > from the device manager, and under that scenario Vista acts like XP. The
> > only remaining issue seems to be with this PnP test.
> >
> > Thanks,
> > Michael
> >
> > "Egidio [MSFT]" wrote:
> >
> >> The sequence below seems correct and consistent with the flow you can
> >> find
> >> in pages 181 to 189 of Windows Driver Foundation book. It may be possible
> >> that in XP the device doesn't support selective suspend. Please check
> >> the
> >> device characteristics of your node (device manager). Do you see the
> >> PowerManager tab in XP? like you see in Vista.
> >> What are the info you see in Details->Power Data in both XP and Vista for
> >> this device?
> >> Is it possible that this device doesn't support selective suspend?
> >>
> >> Thx,
> >> Egi.
> >>
> >> "dhmot" <dhmot(a)discussions.microsoft.com> wrote in message
> >> news:1A229197-B74F-4822-9CC4-FAEE1510B4E9(a)microsoft.com...
> >> > To answer your questions (#5 is probably the most important):
> >> >
> >> > 1) As far as I can tell, the test runs - I see the PnP window appear
> >> > for
> >> > a
> >> > short period, maybe a few seconds, at least twice during the PnP test.
> >> > At
> >> > the end of my response, I've included the log file (uuencoded zip
> >> > file).
> >> >
> >> > 2) I do nothing special for a surprise remove that I do for any other
> >> > condition that causes the device to enter D3; it's the same code that's
> >> > used
> >> > if someone right-clicks on the device in device manager and "Disable"s
> >> > it.
> >> >
> >> > 3) I re-ran the test with the selective suspend time-out cranked down
> >> > to
> >> > one second on Windows XP. This should cause the driver and device to
> >> > enter
> >> > selective suspend. The test still passed on Windows XP.
> >> >
> >> > 4) As far as I'm aware, my driver is not a child of USBCCGP. I assume
> >> > this
> >> > is something I'd have to call out explicitly. If not, please tell me
> >> > how
> >> > I'd
> >> > know.
> >> >
> >> > 5) I performed a log comparison and found one major difference just
> >> > prior
> >> > to
> >> > the second driver re-load (initial driver load on boot-up, first driver
> >> > re-load after start of test, then second driver re-load). On XP, the
> >> > callback sequence after the first driver re-load was as follows:
> >> >
> >> > DriverEntry
> >> > Device Add
> >> > Prepare Hardware
> >> > IO Init
> >> > IO Suspend
> >> > D0 Exit to D3
> >> > IO Flush
> >> >
> >> > The above is what I would normally expect. However, Vista threw the
> >> > following at my driver:
> >> >
> >> > DriverEntry
> >> > Device Add
> >> > Prepare Hardware
> >> > IO Init
> >> > IO Suspend
> >> > D0 Exit to D2 (selective suspend)
> >> > IO Flush
> >> >
> >> > I would have expected it to have called my IO Restart callback after
> >> > the
> >> > D0
> >> > Exit to D2, then IO Suspend, then D0 Exit to D3, and THEN IO Flush.
> >> > Turning
> >> > on WDF Verifier did not affect this. After this occurs, Vista re-loads
> >> > my
> >> > driver and stops testing while XP continues testing.
> >> >
> >> > 6) I did not have WDF Verifier enabled for either Vista or XP. Once I
> >> > discovered #5, I re-ran the test on Vista with WDF Verifier enabled for
> >> > the
> >> > USB driver (I'm not sure how to enable it for WDF01000). There was no
> >> > change
> >> > in the test results.
> >> >
> >> > 7) I have no Windows 7 machines available to me at the moment.
> >> >
> >> > Any ideas why #5 is happening?
> >> >
> >> > Thanks,
> >> > Michael
> >> >
> >> > PnP result log:
> >> >
> >> >
> >>
> >>
> >>
> >> >
> >> >
> >> > "Egidio [MSFT]" wrote:
> >> >
> >> >> Just to understand more about this error.
> >> >> does the surprise remove test run? or doesnâ?Tt even run because the
> >> >> device is
> >> >> not initializing correctly, i.e., the previous test left the device in
> >> >> a
> >> >> strange state?
> >> >> Do you do anything in your driver when you receiving surprise remove?
> >> >> When XP works, is the device in selective suspend? I.e., is it
From: Egidio [MSFT] on
- Yes, log line 330 with error 0xC000000E means: a device which does not
exist was specified.

- Can you send also your WDF driver log after the failure? !load wdfkd.dll,
!wdflogdump <your_driver_name>
Of course you need to run the above dbg commands before the driver is
removed from the system.

- Do you call WdfDeviceSuspendIdle/ResumeIdle in your driver? If so, make
sure they are called correctly and in pairs, for example don't call
WdfDeviceResumeIdle if you didn't call WdfDeviceSuspendIdle. Remember also
that these calls are counted.

- Try the following code in the surprise removal callback, to make sure the
device is in D0 and run the test again.
VOID
EvtDeviceSurpriseRemoval (
__in WDFDEVICE Device
)
{
NTSTATUS status;

status = WdfDeviceStopIdle(Device, TRUE);
if (NT_SUCCESS(status)) {
resumeIdle = TRUE;
}
}

Plus add the following in the DoExit callback:
if (resumeIdle) {
WdfDeviceResumeIdle(Device);
}

- Yes, http://support.microsoft.com/kb/314743 is for XP and before, in Vista
you have the following changes:
For Vista, the debug symbol in USBCCGP is dbgLevel. USBHUB debug output
is via WPP only.
Before starting to enable these traces let's see the results for above
tests.

Thx,
Egi

"dhmot" <dhmot(a)discussions.microsoft.com> wrote in message
news:584EDD97-651D-41C3-BE14-D3C211686141(a)microsoft.com...
> My device is a high speed device. I disabled the EHCI, which caused the
> device to enumerate at full speed. When I run the PnP test under this
> condition, I get the same results, and the log file looks very similar.
>
> I'm selecting the same PnP DTM test on both XP and Vista. However, I do
> not
> know what DTM is doing behind the scenes. DTM is aware that the OS is not
> the same; I do not know if DTM is configuruing the PnP test slightly
> different for XP versus Vista.
>
> I'm not quite sure why there is a failure, at least from the log file.
> After the surprise removal test completes, my driver is reloaded. Here's
> the
> output from from the driver re-load to the end of the DbgView log file
> (kernel output only captured):
>
> 00000311 60.73113251 Ctb:--> DriverEntry built Aug 31 2009
> 12:38:03
> 00000312 60.73143005 Ctb:<-- DriverEntry (0x0)
> 00000313 60.73184204 Ctb:CtbRegGetDword: Found DebugFlags = 6
> 00000314 60.73185349 Ctb:<-- CtbRegGetDword (DebugFlags)
> 00000315 60.73185730 Ctb:CtbDeviceAdd: handle 0x61f39878,
> Debug: 6
> 00000316 60.73186111 Ctb:--> CtbRegGetDword (D3Flag)
> 00000317 60.73195648 Ctb:CtbRegGetDword: Found D3Flag = 1
> 00000318 60.73196030 Ctb:<-- CtbRegGetDword (D3Flag)
> 00000319 60.73196411 Ctb:CtbDeviceAdd: D3Flag: 1
> 00000320 60.75346756 Ctb:<-- CtbDeviceAdd
> 00000321 60.75364685 PNPFILTR: Events being initialized
> 00000322 60.75368881 PNPFILTR: Received
> IRP_MN_QUERY_LEGACY_BUS_INFORMATION which I am simply passing down
> 00000323 60.75377655 PNPFILTR: Received
> IRP_MN_QUERY_RESOURCE_REQUIREMENTS which I am simply passing down
> 00000324 60.75382233 PNPFILTR: Received
> IRP_MN_FILTER_RESOURCE_REQUIREMENT for stack with PDO 0x85921030
> 00000325 60.75382996 PNPFILTR: FilterCompletionRoutine
> Completed,
> event set.
> 00000326 60.75383377 PNPFILTR: FilterFilterResourceRequirement
> returning 0x00000000 for stack with PDO 0x85921030
> 00000327 60.75416946 PNPFILTR: Received IRP_MN_START_DEVICE for
> stack with PDO 0x85921030
> 00000328 60.75426865 PNPFILTR: FilterCompletionRoutine
> Completed,
> event set.
> 00000329 60.75428391 PNPFILTR: Time taken for
> IRP_MN_START_DEVICE
> to get processed for the PDO 85921030 is 0 miliseconds
> 00000330 60.75429153 PNPFILTR: Completing Start request with
> status == 0xC000000E PDO = 0x85921030
> 00000331 60.83396530 PNPFILTR: Received IRP_MN_REMOVE_DEVICE
> for
> stack with PDO 0x85921030
> 00000332 60.83398819 PNPFILTR: List has 0 entries
> 00000333 60.83399582 PNPFILTR: Processed 0 IRPs
> 00000334 60.88864517 PNPFILTR: Deleting the global control
> object
> 00000335 60.88867188 PNPFILTR: FilterRemove returning
> 0x00000000
> for stack with PDO 0x85921030
>
> Line 00000330 seems to be the error. However, my driver's callback was
> never invoked (all my routines have entry and exit traces). Specifically,
> after other entries like line 00000327 in this log file, I see my prepare
> hardware callback being invoked.
>
> The link http://support.microsoft.com/kb/314743 is for XP and earlier. Is
> there a similar page for Vista (Google couldn't find one)? If not, which
> .sys files should I debug, what is the debug flag name, and what values
> are
> valid?
>
> Thanks,
> Michael
>
> "Egidio [MSFT]" wrote:
>
>> WDF does not bring the device in D0 after receiving surprise_remove if
>> the
>> device is already suspended, the device goes into a special D3 state.
>> Since
>> you are using the same WDF 1.7 in both platforms (XP and Vista) and I
>> assume
>> the same driver, (and the same test? If not, try using the same test
>> too),
>> the only diff is the USB layer. USB layer has changed a lot from XP to
>> Vista and from Vista to Win7. Thus this diff in behavior can be indeed
>> attributed to the USB layer. But this doesn't explain why the test
>> fails.
>>
>> Is your device a high speed device? Can you disable the EHCI drivers on
>> your
>> machine via device manager for your USB ports? This will allow your
>> device
>> to use UHCI or OHCI. Re-run again the same test and let me know if the
>> test
>> works.
>>
>> And what exactly does it fail on the next start? Is the driver called at
>> all?
>>
>> Please also take a look at http://support.microsoft.com/kb/314743 for
>> more
>> info on how to get USB stack trace info.
>> (For Vista, the debug symbol in USBCCGP is dbgLevel. USBHUB debug output
>> is
>> via WPP only).
>>
>> Thx,
>> Egi.
>>
>> Note about the EvtDeviceSelfManagedIoFlush callback function from MSDN:
>> the
>> framework calls it after the device has been removed. The driver should
>> flush (that is, remove) I/O requests that are associated with the
>> device's
>> self-managed I/O operations.
>> http://msdn.microsoft.com/en-us/library/aa491132.aspx
>>
>> "dhmot" <dhmot(a)discussions.microsoft.com> wrote in message
>> news:948B0825-EE66-4CA5-A1CE-79FD944B5717(a)microsoft.com...
>> > I'm quite positive that the device supports selective suspend, and this
>> > morning re-confirmed that it does with an Ellisys USB analyzer on both
>> > XP
>> > SP3
>> > and Vista SP2. A "SetFeature(RemoteWakeup)" is sent out, the device
>> > enters
>> > selective suspend. Upon wake, a "Clear Feature(RemoteWakeup)" is sent
>> > out.
>> > Both transactions were successful and returned an "ACK" packet.
>> >
>> > The power management tab of both XP and Vista have a check box checked
>> > that
>> > says "Allow the computer to turn off this device to save power".
>> >
>> > Concerning the sequence, I was basing my statement off of the KMDF &
>> > Kernel
>> > Mode Driver Architecture documents provided on-line at MSDN (I do not
>> > own
>> > the
>> > book you refer to, but it's now on my "Buy Real Soon" list). Under
>> > "Windows
>> > Driver Kit -> Kernel-Mode Driver Architecture -> Design Guide ->
>> > Writing
>> > WDM
>> > Drivers -> Implementing Power Management -> Managing Power for
>> > Individual
>> > Devices -> Device Power States", the final paragraph says:
>> >
>> > "Like the system, a device can transition from the working state (D0)
>> > to
>> > any
>> > sleeping state (D1-D3) and from any sleeping state to the working
>> > state."
>> >
>> > Under "Windows Driver Kit -> Windows Driver Foundation -> Kernel-Mode
>> > Driver
>> > Framework -> Design Guide -> PnP and Power Management in
>> > Framework-Based
>> > Drivers -> PnP and Power Management Scenarios -> A Device Enters a
>> > Low-Power
>> > State", there's no mention of a call to the "IO Flush" callback. In
>> > the
>> > collected logs, the "IO Flush" callback takes place about 12
>> > seconds -after-
>> > the "D0 Exit to D2 (Selective Suspend)" callback completes, so I don't
>> > think
>> > it's part of the entry into selective suspend. The only time I see the
>> > "IO
>> > Flush" callback mentioned is under the "A User Unplugs a Device"
>> > scenario.
>> > And in order to hit that scenario, the driver must be brought back to
>> > D0
>> > per
>> > the section I mentioned in the preceding paragraph. This seems to have
>> > changed in Vista versus XP. XP brings the driver back to D0 first,
>> > then
>> > takes it to D3. Vista just does a D2 to D3 transition (if a bus
>> > powered
>> > device is removed, it's certainly no longer in D2).
>> >
>> > However, my driver works regardless of whether or not it returned to D0
>> > first. Under WHQL testing, ithe driver is not handling any traffic, so
>> > has
>> > no cleanup to perform. Also, since the device went from D2 to D3
>> > directly,
>> > the driver does not perform a reset of the device (i.e. the device will
>> > not
>> > re-enumerate). When told to perform an "IO Flush", the driver assumes
>> > that
>> > the device is physically gone.
>> >
>> > Here's a DbgView output snippet starting from when the "IO Suspend" is
>> > received by my driver. My driver has a prefix of "CtbUsb":
>> >
>> > --------------------
>> > 00000226 64.85100555 Ctb:--> pwrIoSuspend
>> > 00000227 64.85101318 Ctb:--> CtbReaderStop
>> > 00000228 64.85102081 Ctb:<-- CtbReaderStop (not started)
>> > 00000229 64.85102081 Ctb:<-- pwrIoSuspend
>> > 00000230 64.85131073 PNPFILTR: List has 0 entries
>> > 00000231 64.85131836 PNPFILTR: Processed 0 IRPs
>> > 00000232 64.85133362 PNPFILTR: List has 0 entries
>> > 00000233 64.85133362 PNPFILTR: Processed 0 IRPs
>> > 00000234 64.85134125 Ctb:--> pwrD0Exit (3)
>> > 00000235 64.85134888 Ctb:<-- pwrD0Exit (in DFU mode/target
>> > state
>> > not 5)
>> > 00000236 66.62499237 PNPFILTR: Received
>> > IRP_MN_QUERY_CAPABILITIES
>> > which I am simply passing down
>> > 00000237 66.64597321 PNPFILTR: Received
>> > IRP_MN_QUERY_CAPABILITIES
>> > which I am simply passing down
>> > 00000238 66.65718079 PNPFILTR: Received
>> > IRP_MN_QUERY_INTERFACE
>> > which I am simply passing down
>> > 00000239 76.08638763 PNPFILTR: Received
>> > IOCTL_QUERY_DEVICE_COUNT
>> > 00000240 76.08644867 PNPFILTR: Received
>> > IOCTL_QUERY_HARDWARE_ID_SIZE for PDO 0x9DF3D030
>> > 00000241 76.08652496 PNPFILTR: Received
>> > IOCTL_QUERY_HARDWARE_ID
>> > for PDO 0x9DF3D030
>> > 00000242 76.08661652 PNPFILTR: Received
>> > IOCTL_SURPRISE_REMOVE_DEVICE for PDO 0x9DF3D030
>> > 00000243 76.08661652 PNPFILTR: Calling
>> > IoInvalidateDeviceState
>> > to
>> > start rebalance on PDO 9DF3D030
>> > 00000244 76.08663177 PNPFILTR: Received
>> > IRP_MN_QUERY_PNP_DEVICE_STATE for stack with PDO 0x9DF3D030
>> > 00000245 76.08679962 PNPFILTR: Recieved Query Result
>> > 00000246 76.08680725 PNPFILTR: Waiting for test to be
>> > completed -
>> > will wait for 50 seconds
>> > 00000247 76.08682251 PNPFILTR: FilterCompletionRoutine
>> > Completed,
>> > event set.
>> > 00000248 76.08683014 PNPFILTR: Completing
>> > IRP_MN_QUERY_PNP_DEVICE_STATE for PDO 0x9DF3D030 with status 0x00000000
>> > and
>> > information 0x00000004
>> > 00000249 76.08685303 PNPFILTR: Received
>> > IRP_MN_QUERY_DEVICE_RELATIONS which I am simply passing down
>> > 00000250 76.08687592 PNPFILTR: Received
>> > IRP_MN_SURPRISE_REMOVAL
>> > for stack with PDO 0x9DF3D030
>> > 00000251 76.08901215 Ctb:--> pwrIoFlush
>> > 00000252 76.08901978 Ctb:--> CtbReaderFlush
>> > 00000253 76.08902740 Ctb:<-- CtbReaderFlush
>> > 00000254 76.08902740 Ctb:--> pmdtStopPmdt
>> > 00000255 76.08902740 Ctb:<-- pmdtStopPmdt
>> > 00000256 76.08903503 Ctb:<-- pwrIoFlush
>> > 00000257 76.08925629 PNPFILTR: FilterSurpriseRemove
>> > returning
>> > 0x00000103 for stack with PDO 0x9DF3D030
>> > 00000258 76.11583710 PNPFILTR: Received IRP_MN_REMOVE_DEVICE
>> > for
>> > stack with PDO 0x9DF3D030
>> > 00000259 76.11583710 PNPFILTR: Setting the test completed
>> > event
>> > 00000260 76.11584473 PNPFILTR: Waiting for result to be
>> > stored
>> > 00000261 76.11585236 PNPFILTR: Query Result Wait
>> > Satisfied...
>> > 4
>> > 00000262 76.11585236 PNPFILTR: Number of IRPs Stored... 4
>> > 00000263 76.11586761 PNPFILTR: Query Result - Releasing the
>> > remove
>> > 00000264 76.11587524 PNPFILTR: Remove Wait completed... now
>> > deleting
>> > 00000265 76.11587524 PNPFILTR: List has 0 entries
>> > 00000266 76.11588287 PNPFILTR: Processed 0 IRPs
>> > 00000267 76.11589813 PNPFILTR: Query Result -Result Stored
>> > Event
>> > set
>> > 00000268 76.13028717 PNPFILTR: Deleting the global control
>> > object
>> > 00000269 76.13031006 PNPFILTR: FilterRemove returning
>> > 0x00000000
>> > for stack with PDO 0x9DF3D030
>> > --------------------
>> >
>> > Is there some new Vista requirement for D2 -> D3 support that's needed?
>> > I've removed the device while it was in selective suspend, and that
>> > operation
>> > works fine in both Vista and XP. Likewise, I've issued a "Disable"
>> > request
>> > from the device manager, and under that scenario Vista acts like XP.
>> > The
>> > only remaining issue seems to be with this PnP test.
>> >
>> > Thanks,
>> > Michael
>> >
>> > "Egidio [MSFT]" wrote:
>> >
>> >> The sequence below seems correct and consistent with the flow you can
>> >> find
>> >> in pages 181 to 189 of Windows Driver Foundation book. It may be
>> >> possible
>> >> that in XP the device doesn't support selective suspend. Please check
>> >> the
>> >> device characteristics of your node (device manager). Do you see the
>> >> PowerManager tab in XP? like you see in Vista.
>> >> What are the info you see in Details->Power Data in both XP and Vista
>> >> for
>> >> this device?
>> >> Is it possible that this device doesn't support selective suspend?
>> >>
>> >> Thx,
>> >> Egi.
>> >>
>> >> "dhmot" <dhmot(a)discussions.microsoft.com> wrote in message
>> >> news:1A229197-B74F-4822-9CC4-FAEE1510B4E9(a)microsoft.com...
>> >> > To answer your questions (#5 is probably the most important):
>> >> >
>> >> > 1) As far as I can tell, the test runs - I see the PnP window
>> >> > appear
>> >> > for
>> >> > a
>> >> > short period, maybe a few seconds, at least twice during the PnP
>> >> > test.
>> >> > At
>> >> > the end of my response, I've included the log file (uuencoded zip
>> >> > file).
>> >> >
>> >> > 2) I do nothing special for a surprise remove that I do for any
>> >> > other
>> >> > condition that causes the device to enter D3; it's the same code
>> >> > that's
>> >> > used
>> >> > if someone right-clicks on the device in device manager and
>> >> > "Disable"s
>> >> > it.
>> >> >
>> >> > 3) I re-ran the test with the selective suspend time-out cranked
>> >> > down
>> >> > to
>> >> > one second on Windows XP. This should cause the driver and device
>> >> > to
>> >> > enter
>> >> > selective suspend. The test still passed on Windows XP.
>> >> >
>> >> > 4) As far as I'm aware, my driver is not a child of USBCCGP. I
>> >> > assume
>> >> > this
>> >> > is something I'd have to call out explicitly. If not, please tell
>> >> > me
>> >> > how
>> >> > I'd
>> >> > know.
>> >> >
>> >> > 5) I performed a log comparison and found one major difference just
>> >> > prior
>> >> > to
>> >> > the second driver re-load (initial driver load on boot-up, first
>> >> > driver
>> >> > re-load after start of test, then second driver re-load). On XP,
>> >> > the
>> >> > callback sequence after the first driver re-load was as follows:
>> >> >
>> >> > DriverEntry
>> >> > Device Add
>> >> > Prepare Hardware
>> >> > IO Init
>> >> > IO Suspend
>> >> > D0 Exit to D3
>> >> > IO Flush
>> >> >
>> >> > The above is what I would normally expect. However, Vista threw the
>> >> > following at my driver:
>> >> >
>> >> > DriverEntry
>> >> > Device Add
>> >> > Prepare Hardware
>> >> > IO Init
>> >> > IO Suspend
>> >> > D0 Exit to D2 (selective suspend)
>> >> > IO Flush
>> >> >
>> >> > I would have expected it to have called my IO Restart callback after
>> >> > the
>> >> > D0
>> >> > Exit to D2, then IO Suspend, then D0 Exit to D3, and THEN IO Flush.
>> >> > Turning
>> >> > on WDF Verifier did not affect this. After this occurs, Vista
>> >> > re-loads
>> >> > my
>> >> > driver and stops testing while XP continues testing.
>> >> >
>> >> > 6) I did not have WDF Verifier enabled for either Vista or XP.
>> >> > Once I
>> >> > discovered #5, I re-ran the test on Vista with WDF Verifier enabled
>> >> > for
>> >> > the
>> >> > USB driver (I'm not sure how to enable it for WDF01000). There was
>> >> > no
>> >> > change
>> >> > in the test results.
>> >> >
>> >> > 7) I have no Windows 7 machines available to me at the moment.
>> >> >
>> >> > Any ideas why #5 is happening?
>> >> >
>> >> > Thanks,
>> >> > Michael
>> >> >
>> >> > PnP result log:
>> >> >
>> >> >
>> >>
>> >>
>> >>
>> >> >
>> >> >
>> >> > "Egidio [MSFT]" wrote:
>> >> >
>> >> >> Just to understand more about this error.
>> >> >> does the surprise remove test run? or doesnâ?Tt even run because
>> >> >> the
>> >> >> device is
>> >> >> not initializing correctly, i.e., the previous test left the device
>> >> >> in
>> >> >> a
>> >> >> strange state?
>> >> >> Do you do anything in your driver when you receiving surprise
>> >> >> remove?
>> >> >> When XP works, is the device in selective suspend? I.e., is it

From: dhmot on
Here is the post-failure WDF driver log for my driver. I'm not sure how far
it was along the failure, but the error code has been reported:

--- start of log ---
1: FxVerifierLock::InitializeLockOrder - Object Type 0x1036 does not have a
lock order defined in fx\inc\FxVerifierLock.hpp
2: FxVerifierLock::InitializeLockOrder - Object Type 0x1036 does not have a
lock order defined in fx\inc\FxVerifierLock.hpp
3: FxPkgPnp::PnpEnterNewState - WDFDEVICE 0x7A6C4A98 !devobj 0x9CCBEC70
entering PnP State WdfDevStatePnpInit from WdfDevStatePnpObjectCreated
4: FxPkgPnp::Dispatch - WDFDEVICE 0x7A6C4A98 !devobj 0x9CCBEC70, IRP_MJ_PNP,
0x00000000(IRP_MN_START_DEVICE) IRP 0x84CB3E28
5: FxPkgPnp::PnpEnterNewState - WDFDEVICE 0x7A6C4A98 !devobj 0x9CCBEC70
entering PnP State WdfDevStatePnpInitStarting from WdfDevStatePnpInit
6: FxPkgFdo::_PnpStartDeviceCompletionRoutine - PNP start failed with
0xc000000e(STATUS_NO_SUCH_DEVICE)
7: FxPkgPnp::PnpEnterNewState - WDFDEVICE 0x7A6C4A98 !devobj 0x9CCBEC70
entering PnP State WdfDevStatePnpInit from WdfDevStatePnpInitStarting
---- end of log ----

I do call WdfDeviceSuspendIdle/ResumeIdle in my driver. However, they are
always called one after another and are protected by a wait lock. Unlike
your code, if an error is returned, I still call ResumeIdle. The MSDN
documentation was not clear on exactly what the side effect of an error is.
These errors are logged, but I see no evidence of an error in my debug
output. I use the calls to WdfDeviceSuspenIdle/ResumeIdle as a method of
waking the device from selective suspend or keeping the device out of
selective suspend.

If I make the code changes you suggest, the PnP test passes. The surprise
removal callback is invoked, which causes the device to exit selective
suspend. After that, the logic flows pretty much the same as it did in
Windows XP.

What information does that provide? Is there anything else I should capture?

Thanks,
Michael

"Egidio [MSFT]" wrote:

> - Yes, log line 330 with error 0xC000000E means: a device which does not
> exist was specified.
>
> - Can you send also your WDF driver log after the failure? !load wdfkd.dll,
> !wdflogdump <your_driver_name>
> Of course you need to run the above dbg commands before the driver is
> removed from the system.
>
> - Do you call WdfDeviceSuspendIdle/ResumeIdle in your driver? If so, make
> sure they are called correctly and in pairs, for example don't call
> WdfDeviceResumeIdle if you didn't call WdfDeviceSuspendIdle. Remember also
> that these calls are counted.
>
> - Try the following code in the surprise removal callback, to make sure the
> device is in D0 and run the test again.
> VOID
> EvtDeviceSurpriseRemoval (
> __in WDFDEVICE Device
> )
> {
> NTSTATUS status;
>
> status = WdfDeviceStopIdle(Device, TRUE);
> if (NT_SUCCESS(status)) {
> resumeIdle = TRUE;
> }
> }
>
> Plus add the following in the DoExit callback:
> if (resumeIdle) {
> WdfDeviceResumeIdle(Device);
> }
>
> - Yes, http://support.microsoft.com/kb/314743 is for XP and before, in Vista
> you have the following changes:
> For Vista, the debug symbol in USBCCGP is dbgLevel. USBHUB debug output
> is via WPP only.
> Before starting to enable these traces let's see the results for above
> tests.
>
> Thx,
> Egi
>
> "dhmot" <dhmot(a)discussions.microsoft.com> wrote in message
> news:584EDD97-651D-41C3-BE14-D3C211686141(a)microsoft.com...
> > My device is a high speed device. I disabled the EHCI, which caused the
> > device to enumerate at full speed. When I run the PnP test under this
> > condition, I get the same results, and the log file looks very similar.
> >
> > I'm selecting the same PnP DTM test on both XP and Vista. However, I do
> > not
> > know what DTM is doing behind the scenes. DTM is aware that the OS is not
> > the same; I do not know if DTM is configuruing the PnP test slightly
> > different for XP versus Vista.
> >
> > I'm not quite sure why there is a failure, at least from the log file.
> > After the surprise removal test completes, my driver is reloaded. Here's
> > the
> > output from from the driver re-load to the end of the DbgView log file
> > (kernel output only captured):
> >
> > 00000311 60.73113251 Ctb:--> DriverEntry built Aug 31 2009
> > 12:38:03
> > 00000312 60.73143005 Ctb:<-- DriverEntry (0x0)
> > 00000313 60.73184204 Ctb:CtbRegGetDword: Found DebugFlags = 6
> > 00000314 60.73185349 Ctb:<-- CtbRegGetDword (DebugFlags)
> > 00000315 60.73185730 Ctb:CtbDeviceAdd: handle 0x61f39878,
> > Debug: 6
> > 00000316 60.73186111 Ctb:--> CtbRegGetDword (D3Flag)
> > 00000317 60.73195648 Ctb:CtbRegGetDword: Found D3Flag = 1
> > 00000318 60.73196030 Ctb:<-- CtbRegGetDword (D3Flag)
> > 00000319 60.73196411 Ctb:CtbDeviceAdd: D3Flag: 1
> > 00000320 60.75346756 Ctb:<-- CtbDeviceAdd
> > 00000321 60.75364685 PNPFILTR: Events being initialized
> > 00000322 60.75368881 PNPFILTR: Received
> > IRP_MN_QUERY_LEGACY_BUS_INFORMATION which I am simply passing down
> > 00000323 60.75377655 PNPFILTR: Received
> > IRP_MN_QUERY_RESOURCE_REQUIREMENTS which I am simply passing down
> > 00000324 60.75382233 PNPFILTR: Received
> > IRP_MN_FILTER_RESOURCE_REQUIREMENT for stack with PDO 0x85921030
> > 00000325 60.75382996 PNPFILTR: FilterCompletionRoutine
> > Completed,
> > event set.
> > 00000326 60.75383377 PNPFILTR: FilterFilterResourceRequirement
> > returning 0x00000000 for stack with PDO 0x85921030
> > 00000327 60.75416946 PNPFILTR: Received IRP_MN_START_DEVICE for
> > stack with PDO 0x85921030
> > 00000328 60.75426865 PNPFILTR: FilterCompletionRoutine
> > Completed,
> > event set.
> > 00000329 60.75428391 PNPFILTR: Time taken for
> > IRP_MN_START_DEVICE
> > to get processed for the PDO 85921030 is 0 miliseconds
> > 00000330 60.75429153 PNPFILTR: Completing Start request with
> > status == 0xC000000E PDO = 0x85921030
> > 00000331 60.83396530 PNPFILTR: Received IRP_MN_REMOVE_DEVICE
> > for
> > stack with PDO 0x85921030
> > 00000332 60.83398819 PNPFILTR: List has 0 entries
> > 00000333 60.83399582 PNPFILTR: Processed 0 IRPs
> > 00000334 60.88864517 PNPFILTR: Deleting the global control
> > object
> > 00000335 60.88867188 PNPFILTR: FilterRemove returning
> > 0x00000000
> > for stack with PDO 0x85921030
> >
> > Line 00000330 seems to be the error. However, my driver's callback was
> > never invoked (all my routines have entry and exit traces). Specifically,
> > after other entries like line 00000327 in this log file, I see my prepare
> > hardware callback being invoked.
> >
> > The link http://support.microsoft.com/kb/314743 is for XP and earlier. Is
> > there a similar page for Vista (Google couldn't find one)? If not, which
> > .sys files should I debug, what is the debug flag name, and what values
> > are
> > valid?
> >
> > Thanks,
> > Michael
> >
> > "Egidio [MSFT]" wrote:
> >
> >> WDF does not bring the device in D0 after receiving surprise_remove if
> >> the
> >> device is already suspended, the device goes into a special D3 state.
> >> Since
> >> you are using the same WDF 1.7 in both platforms (XP and Vista) and I
> >> assume
> >> the same driver, (and the same test? If not, try using the same test
> >> too),
> >> the only diff is the USB layer. USB layer has changed a lot from XP to
> >> Vista and from Vista to Win7. Thus this diff in behavior can be indeed
> >> attributed to the USB layer. But this doesn't explain why the test
> >> fails.
> >>
> >> Is your device a high speed device? Can you disable the EHCI drivers on
> >> your
> >> machine via device manager for your USB ports? This will allow your
> >> device
> >> to use UHCI or OHCI. Re-run again the same test and let me know if the
> >> test
> >> works.
> >>
> >> And what exactly does it fail on the next start? Is the driver called at
> >> all?
> >>
> >> Please also take a look at http://support.microsoft.com/kb/314743 for
> >> more
> >> info on how to get USB stack trace info.
> >> (For Vista, the debug symbol in USBCCGP is dbgLevel. USBHUB debug output
> >> is
> >> via WPP only).
> >>
> >> Thx,
> >> Egi.
> >>
> >> Note about the EvtDeviceSelfManagedIoFlush callback function from MSDN:
> >> the
> >> framework calls it after the device has been removed. The driver should
> >> flush (that is, remove) I/O requests that are associated with the
> >> device's
> >> self-managed I/O operations.
> >> http://msdn.microsoft.com/en-us/library/aa491132.aspx
> >>
> >> "dhmot" <dhmot(a)discussions.microsoft.com> wrote in message
> >> news:948B0825-EE66-4CA5-A1CE-79FD944B5717(a)microsoft.com...
> >> > I'm quite positive that the device supports selective suspend, and this
> >> > morning re-confirmed that it does with an Ellisys USB analyzer on both
> >> > XP
> >> > SP3
> >> > and Vista SP2. A "SetFeature(RemoteWakeup)" is sent out, the device
> >> > enters
> >> > selective suspend. Upon wake, a "Clear Feature(RemoteWakeup)" is sent
> >> > out.
> >> > Both transactions were successful and returned an "ACK" packet.
> >> >
> >> > The power management tab of both XP and Vista have a check box checked
> >> > that
> >> > says "Allow the computer to turn off this device to save power".
> >> >
> >> > Concerning the sequence, I was basing my statement off of the KMDF &
> >> > Kernel
> >> > Mode Driver Architecture documents provided on-line at MSDN (I do not
> >> > own
> >> > the
> >> > book you refer to, but it's now on my "Buy Real Soon" list). Under
> >> > "Windows
> >> > Driver Kit -> Kernel-Mode Driver Architecture -> Design Guide ->
> >> > Writing
> >> > WDM
> >> > Drivers -> Implementing Power Management -> Managing Power for
> >> > Individual
> >> > Devices -> Device Power States", the final paragraph says:
> >> >
> >> > "Like the system, a device can transition from the working state (D0)
> >> > to
> >> > any
> >> > sleeping state (D1-D3) and from any sleeping state to the working
> >> > state."
> >> >
> >> > Under "Windows Driver Kit -> Windows Driver Foundation -> Kernel-Mode
> >> > Driver
> >> > Framework -> Design Guide -> PnP and Power Management in
> >> > Framework-Based
> >> > Drivers -> PnP and Power Management Scenarios -> A Device Enters a
> >> > Low-Power
> >> > State", there's no mention of a call to the "IO Flush" callback. In
> >> > the
> >> > collected logs, the "IO Flush" callback takes place about 12
> >> > seconds -after-
> >> > the "D0 Exit to D2 (Selective Suspend)" callback completes, so I don't
> >> > think
> >> > it's part of the entry into selective suspend. The only time I see the
> >> > "IO
> >> > Flush" callback mentioned is under the "A User Unplugs a Device"
> >> > scenario.
> >> > And in order to hit that scenario, the driver must be brought back to
> >> > D0
> >> > per
> >> > the section I mentioned in the preceding paragraph. This seems to have
> >> > changed in Vista versus XP. XP brings the driver back to D0 first,
> >> > then
> >> > takes it to D3. Vista just does a D2 to D3 transition (if a bus
> >> > powered
> >> > device is removed, it's certainly no longer in D2).
> >> >
> >> > However, my driver works regardless of whether or not it returned to D0
> >> > first. Under WHQL testing, ithe driver is not handling any traffic, so
> >> > has
> >> > no cleanup to perform. Also, since the device went from D2 to D3
> >> > directly,
> >> > the driver does not perform a reset of the device (i.e. the device will
> >> > not
> >> > re-enumerate). When told to perform an "IO Flush", the driver assumes
> >> > that
> >> > the device is physically gone.
> >> >
> >> > Here's a DbgView output snippet starting from when the "IO Suspend" is
> >> > received by my driver. My driver has a prefix of "CtbUsb":
> >> >
> >> > --------------------
> >> > 00000226 64.85100555 Ctb:--> pwrIoSuspend
> >> > 00000227 64.85101318 Ctb:--> CtbReaderStop
> >> > 00000228 64.85102081 Ctb:<-- CtbReaderStop (not started)
> >> > 00000229 64.85102081 Ctb:<-- pwrIoSuspend
> >> > 00000230 64.85131073 PNPFILTR: List has 0 entries
> >> > 00000231 64.85131836 PNPFILTR: Processed 0 IRPs
> >> > 00000232 64.85133362 PNPFILTR: List has 0 entries
> >> > 00000233 64.85133362 PNPFILTR: Processed 0 IRPs
> >> > 00000234 64.85134125 Ctb:--> pwrD0Exit (3)
> >> > 00000235 64.85134888 Ctb:<-- pwrD0Exit (in DFU mode/target
> >> > state
> >> > not 5)
> >> > 00000236 66.62499237 PNPFILTR: Received
> >> > IRP_MN_QUERY_CAPABILITIES
> >> > which I am simply passing down
> >> > 00000237 66.64597321 PNPFILTR: Received
> >> > IRP_MN_QUERY_CAPABILITIES
> >> > which I am simply passing down
> >> > 00000238 66.65718079 PNPFILTR: Received
> >> > IRP_MN_QUERY_INTERFACE
> >> > which I am simply passing down
> >> > 00000239 76.08638763 PNPFILTR: Received
> >> > IOCTL_QUERY_DEVICE_COUNT
> >> > 00000240 76.08644867 PNPFILTR: Received
> >> > IOCTL_QUERY_HARDWARE_ID_SIZE for PDO 0x9DF3D030
> >> > 00000241 76.08652496 PNPFILTR: Received
> >> > IOCTL_QUERY_HARDWARE_ID
> >> > for PDO 0x9DF3D030
> >> > 00000242 76.08661652 PNPFILTR: Received
> >> > IOCTL_SURPRISE_REMOVE_DEVICE for PDO 0x9DF3D030
> >> > 00000243 76.08661652 PNPFILTR: Calling
> >> > IoInvalidateDeviceState
> >> > to
> >> > start rebalance on PDO 9DF3D030
> >> > 00000244 76.08663177 PNPFILTR: Received
> >> > IRP_MN_QUERY_PNP_DEVICE_STATE for stack with PDO 0x9DF3D030
> >> > 00000245 76.08679962 PNPFILTR: Recieved Query Result
> >> > 00000246 76.08680725 PNPFILTR: Waiting for test to be
> >> > completed -
> >> > will wait for 50 seconds
> >> > 00000247 76.08682251 PNPFILTR: FilterCompletionRoutine
> >> > Completed,
> >> > event set.
> >> > 00000248 76.08683014 PNPFILTR: Completing
> >> > IRP_MN_QUERY_PNP_DEVICE_STATE for PDO 0x9DF3D030 with status 0x00000000
> >> > and
> >> > information 0x00000004
> >> > 00000249 76.08685303 PNPFILTR: Received
> >> > IRP_MN_QUERY_DEVICE_RELATIONS which I am simply passing down
> >> > 00000250 76.08687592 PNPFILTR: Received
> >> > IRP_MN_SURPRISE_REMOVAL
> >> > for stack with PDO 0x9DF3D030
> >> > 00000251 76.08901215 Ctb:--> pwrIoFlush
> >> > 00000252 76.08901978 Ctb:--> CtbReaderFlush
> >> > 00000253 76.08902740 Ctb:<-- CtbReaderFlush
> >> > 00000254 76.08902740 Ctb:--> pmdtStopPmdt
> >> > 00000255 76.08902740 Ctb:<-- pmdtStopPmdt
> >> > 00000256 76.08903503 Ctb:<-- pwrIoFlush
> >> > 00000257 76.08925629 PNPFILTR: FilterSurpriseRemove