none
HIDI2C device error during WHCK PnP-stop-rebalance RRS feed

  • Question

  • While trying to certify our HIDI2C sensor collection we've encountered a WHCK failure during the DF-PnP Stop-Rebalance test.

    In summary, while running this test (I've pared it down to running the PnP Stop-Rebalance test from VS-2013, setting DoSimpleIO and DoConcurrentIO to False.  I set my DQ to 'DeviceID='ACPI\xxx0001\1' -- the I2C HID device for the Sensor Collection) the test will stop the device, hidi2c goes to D4, resumes, powers on, does a HID reset and then does an errant IOCTL_HID_READ_REPORT.  This IOCTL is done before the reset response arrives and it seems 'sensorssimplehidclassdriver' is not happy with this sequence of events.

    By comparison, when doing a simple device disable/enable via Device Manager (of the I2C HID device, not the sensor collection), a similar (but successful) sequence of events occurs.  The key difference being that there is no errant IOCTL_HID_READ_REPORT.  HIDI2C proceeds to read the report descriptor while the Reset is taking place (as the HID-I2C spec suggested would happen).  After the report descriptor is obtained, the reset response arrives and the driver starts as normal.

    Is the PnP-Stop-Rebalance test even applicable to I2C devices?

    My hypothesis regarding this failure is that HID_READ_REPORT are stuck in some queue in the HIDI2C implementation.  During HCK the HIDI2C driver doesn't stop and the queue is not emptied/released.  But after the reset command is issued these pending operations pop out of their queue.  But via device manager the HIDI2C is stopped and any lingering operations are flushed out.

    Thank you for taking the time to review these logs.  I look forward to your response.

    Regards,
    --Miles Bintz

    ==============  Failure Log  (HCK test) ================

    Here is a capture of TraceView for hidi2c and sensorssimplehidclassdriver when running the test (adjusted for readability):

    00042888 sensorssimplehidclassdriver [CMyDevice::OnQueryStop]CMyDevice::OnQueryStop Entry 00042889 sensorssimplehidclassdriver [CMyDevice::OnD0Exit]CMyDevice::OnD0Exit Entry 00042890 sensorssimplehidclassdriver [CMyDevice::OnReleaseHardware]CMyDevice::OnRelease 00042891 sensorssimplehidclassdriver [CMyDevice::EnterShutdown]CMyDevice::EnterShutdown Entry 00042892 sensorssimplehidclassdriver [CSensorManager::Stop]CSensorManager::Stop Entry 00042893 sensorssimplehidclassdriver [CReadWriteRequest::OnCompletion]Async read request 00042894 sensorssimplehidclassdriver [CSensorManager::Stop]CSensorManager::Stop Exit, hr = S_OK 00042895 sensorssimplehidclassdriver [CMyDevice::OnReleaseHardware]CMyDevice::OnReleaseHardware Exit, hr = S_OK 00042896 sensorssimplehidclassdriver [CMyDevice::OnReleaseHardware]----- END ----------- 00042909 hidi2c Device:0x00001FFFF95EB388 is going to D4 state 00042989 hidi2c Power command (opcode:0x801) sent to device at offset:0x5 00043020 hidi2c WdfObjectDelete closed and deleted SpbIoTarget 00043021 hidi2c I2C resource found with connection id: 0x1 00043022 hidi2c Interrupt resource found at index: 1 00043030 hidi2c Found supported DSM function:1 00043031 hidi2c HID Descriptor offset:0xf retrieved from ACPI 00043032 hidi2c Device:0x00001FFFF95EB388 is resuming from D4 state 00043120 hidi2c HID descriptor retrieved from offset:0xf 00043198 hidi2c Power command (opcode:0x800) sent to device at offset:0x5 00043199 hidi2c WdfIoQueueRetrieveNextRequest failed to find idle notification request in IdleQueue 00043290 hidi2c Reset command sent to device at offset:0x5 00043299 hidi2c Received IOCTL_HID_READ_REPORT, Queue:0x00001FFFF732D3D8, Request:0x00001FFFF9915AB8 00043301 hidi2c Received IOCTL_HID_READ_REPORT, Queue:0x00001FFFF732D3D8, Request:0x00001FFFFA918818 00043302 sensorssimplehidclassdriver [CMyQueue::OnDeviceIoControl]IOCTL 0xb01a8 for request 00000005272FC74 00043303 sensorssimplehidclassdriver [CMyQueue::OnDeviceIoControl]Failed to process IOCTL request 00043304 sensorssimplehidclassdriver [CMyDevice::OnPrepareHardware]CMyDevice::OnPrepareHardware Entry 00043305 sensorssimplehidclassdriver [CMyQueue::CreateInstance]CMyQueue::CreateInstance: Could not create default I/O queue 00043306 sensorssimplehidclassdriver [CMyDevice::OnPrepareHardware]Abnormal results during hardware initialization 00043307 sensorssimplehidclassdriver [CMyDevice::OnPrepareHardware]CMyDevice::OnPrepareHardware Exit 00043308 sensorssimplehidclassdriver [CMyDevice::OnReleaseHardware]CMyDevice::OnReleaseHardware Entry 00043309 sensorssimplehidclassdriver [CMyDevice::EnterShutdown]CMyDevice::EnterShutdown Entry 00043310 sensorssimplehidclassdriver [CMyDevice::OnReleaseHardware]CMyDevice::OnReleaseHardware Exit, hr = S_OK 00043311 sensorssimplehidclassdriver [CMyDevice::OnReleaseHardware]------- END ------------ 00043312 sensorssimplehidclassdriver [CMyQueue::OnDeviceIoControl]IOCTL 0xb01a8 for request 00043313 sensorssimplehidclassdriver [CMyQueue::OnDeviceIoControl]Failed to process IOCTL 00043421 sensorssimplehidclassdriver [CMyQueue::OnDeviceIoControl]IOCTL 0xb01a8 for request 00043422 sensorssimplehidclassdriver [CMyQueue::OnDeviceIoControl]Failed to process IOCTL 00043423 sensorssimplehidclassdriver [CMyQueue::OnDeviceIoControl]IOCTL 0xb01a8 for request 00043424 sensorssimplehidclassdriver [CMyQueue::OnDeviceIoControl]Failed to process IOCTL 00043425 sensorssimplehidclassdriver [CMyDevice::OnSurpriseRemoval]CMyDevice::OnSurpriseRemoval Entry 00043426 hidi2c Received IOCTL_HID_SEND_IDLE_NOTIFICATION_REQUEST, Queue:0x00001FFFF732D3D8, Request:0x00001FFFF814DB38 00043427 hidi2c Acknowledged stop on idle Request:0x00001FFFF814DB38 on Queue:0x00001FFFF732D3D8

    ==============  Succesful Log (device manager) ================

    00048500 hidi2c Created WDF driver object:0xFFFFE00007913CF0
    00048501 hidi2c Created device:0x00001FFFF86216B8 status:STATUS_SUCCESS
    00048502 hidi2c I2C resource found with connection id: 0x1
    00048503 hidi2c Interrupt resource found at index: 1
    00048511 hidi2c Found supported DSM function:1
    00048512 hidi2c HID Descriptor offset:0xf retrieved from ACPI
    00048513 hidi2c Device:0x00001FFFF86216B8 is resuming from D4 state
    00048608 hidi2c HID descriptor retrieved from offset:0xf
    00048679 hidi2c Power command (opcode:0x800) sent to device at offset:0x5
    00048680 hidi2c WdfIoQueueRetrieveNextRequest failed to find idle notification request in IdleQueue:0x00001FFFF6BAD708 status:0x8000001a(STATUS_NO_MORE_ENTRIES)
    00048797 hidi2c Reset command sent to device at offset:0x5
    00048807 hidi2c Received IOCTL_HID_GET_DEVICE_DESCRIPTOR, Queue:0x00001FFFFA1D83D8, Request:0x00001FFFF85C0D78
    00048808 hidi2c Device descriptor retrieved
    00048809 hidi2c Received IOCTL_HID_GET_DEVICE_ATTRIBUTES, Queue:0x00001FFFFA1D83D8, Request:0x00001FFFF85C0D78
    00048810 hidi2c Received IOCTL_HID_GET_REPORT_DESCRIPTOR, Queue:0x00001FFFFA1D83D8, Request:0x00001FFFF85C0D78
    00050213 hidi2c Report descriptor retrieved from offset:0x2
    00050223 hidi2c Received IOCTL_HID_READ_REPORT, Queue:0x00001FFFFA1D83D8, Request:0x00001FFFF85C0D78
    00050224 hidi2c First Read Report received, interrupt processing Active
    00050225 hidi2c Received IOCTL_HID_READ_REPORT, Queue:0x00001FFFFA1D83D8, Request:0x00001FFFF864CD08
    00050333 sensorssimplehidclassdriver [CMyDriver::OnDeviceAdd]------------------------- START (SensorsHIDClassDriver) -------------------------
    00050334 sensorssimplehidclassdriver [CMyDriver::OnDeviceAdd]Trace log running with TRACE_LEVEL == CRITICAL
    00050335 sensorssimplehidclassdriver [CMyDriver::OnDeviceAdd]Trace log running with TRACE_LEVEL == ERROR
    00050336 sensorssimplehidclassdriver [CMyDriver::OnDeviceAdd]Trace log running with TRACE_LEVEL == WARNING
    00050337 sensorssimplehidclassdriver [CMyDriver::OnDeviceAdd]Trace log running with TRACE_LEVEL == INFORMATION
    00050338 sensorssimplehidclassdriver [CMyDriver::OnDeviceAdd]Trace log running with TRACE_LEVEL == VERBOSE
    00050339 sensorssimplehidclassdriver [CMyDriver::OnDeviceAdd]CMyDriver::OnDeviceAdd Entry
    00050340 sensorssimplehidclassdriver [CMyDevice::CreateInstance]CMyDevice::CreateInstance Entry
    00050341 sensorssimplehidclassdriver [CMyDevice::OnPrepareHardware]CMyDevice::OnPrepareHardware Entry
    00050342 sensorssimplehidclassdriver [CSensorManager::Start]CSensorManager::Start Entry
    00050343 hidi2c Received IOCTL_HID_GET_STRING, Queue:0x00001FFFFA1D83D8, Request:0x00001FFFFA918818
    00050344 hidi2c Received IOCTL_HID_GET_STRING, Queue:0x00001FFFFA1D83D8, Request:0x00001FFFFA918818
    00050345 hidi2c Received IOCTL_HID_GET_STRING, Queue:0x00001FFFFA1D83D8, Request:0x00001FFFFA918818
    00050346 sensorssimplehidclassdriver [CSensorManager::RequestDeviceInfo]Device VID = 0x2047
    00050347 sensorssimplehidclassdriver [CSensorManager::RequestDeviceInfo]Device PID = 0x401
    00050348 sensorssimplehidclassdriver [CSensorManager::RequestDeviceInfo]Device Version = 0x100
    00050349 sensorssimplehidclassdriver [CSensorManager::RequestDeviceInfo]Device Serial Number = 9999
    00050350 sensorssimplehidclassdriver [CSensorManager::RequestDeviceInfo]Device ID = 0100:9999
    00050351 sensorssimplehidclassdriver [CSensorManager::RequestDeviceInfo]Device Manufacturer = Microsoft
    00050352 sensorssimplehidclassdriver [CSensorManager::RequestDeviceInfo]Device Product = HIDI2C Device
    00050353 sensorssimplehidclassdriver [CSensor::GetSensorPropertiesFromDevice]Getting Accelerometer Feature Report
    00050354 hidi2c Received IOCTL_HID_GET_FEATURE, Queue:0x00001FFFFA1D83D8, Request:0x00001FFFFA918818
    
    
    
    Tuesday, October 22, 2013 4:40 PM

All replies

  • Hi Miles Bintz,

    Do you resolve this problem? Because I am now facing this issue.

    The sensors class driver could work as normal after enabled from disabled status using device manager.

    However, when testing with whck 2.1, the test failed and the log show that after the driver was stop, the shutdown is still progress so the initialize failed. 

    If you are solved this problem, please give me some hint.

    Many thanks,

    Tuesday, November 11, 2014 8:59 AM