[Libusb-devel] Testing the Lakeview Research Generic WinUSB Firmware with libusb 1.0

[Xiaofan Chen]

I am trying to write a test program for Jan Axelson's generic
WinUSB example using libusb 1.0.

Firmware adapted from:
http://www.lvr.com/files/winusb_c18_fsusb_fw2-5.zip
"The firmware in this zip file demonstrates control, bulk, and interrupt
transfers on a USB device that uses the Windows WinUSB driver.
The firmware does the following:

Receives 2 bytes in a vendor-defined control write transfer.
Sends back the received data in a vendor-defined control read transfer.

Receives up to 64 bytes on a bulk OUT endpoint.
Sends back the received data via a bulk IN endpoint.

Receives 2 bytes on an interrupt OUT endpoint.
Sends back the received data via an interrupt IN endpoint."

Firmware is tested ok under Windows with her host
software with WinUSB:
http://www.lvr.com/winusb.htm

My libusb codes (Post 61)
http://www.microchip.com/forums/tm.aspx?m=340892&mpage=4

Please take a look to see if there is something obviously wrong
with the codes. Sometimes I could not get it working under Linux.
Testing the control transfer sometimes failed with error number -7
and it will block the testing of of interrupt and bulk transfer. That
is why I put the control transfer testing at the end. Still sometimes
it will fail and then I need to reset the firmware.

I need to get it working more stable under Linux first. But I have also
tried the new Windows WinUSB backend and I see more issues than
the Linux side. Basically it is not working at all. It may have something
to do with the short transfer size.

[Xiaofan Chen]

Post by Xiaofan Chen
I am trying to write a test program for Jan Axelson's generic
WinUSB example using libusb 1.0.
Firmware is tested ok under Windows with her host
http://www.lvr.com/winusb.htm
My libusb codes (Post 61)
http://www.microchip.com/forums/tm.aspx?m=340892&mpage=4
Please take a look to see if there is something obviously wrong
with the codes. Sometimes I could not get it working under Linux.
Testing the control transfer sometimes failed with error number -7
and it will block the testing of of interrupt and bulk transfer. That
is why I put the control transfer testing at the end. Still sometimes
it will fail and then I need to reset the firmware.

Ok, adding a libusb_reset_device() solved all the problems
under Linux. Maybe there is a potential bug in the firmware
which only exhibits under Linux. This is under Ubuntu 9.10.
***@ubuntu:~$ uname -a
Linux ubuntu 2.6.31-17-generic #54-Ubuntu SMP Thu Dec 10 16:20:31 UTC
2009 i686 GNU/Linux

Now I will test the libusb 1.0 WinUSB backend under Windows.

[Xiaofan Chen]

Post by Xiaofan Chen
Ok, adding a libusb_reset_device() solved all the problems
under Linux. Maybe there is a potential bug in the firmware
which only exhibits under Linux. This is under Ubuntu 9.10.
Now I will test the libusb 1.0 WinUSB backend under Windows.

Hmm, I think the WinUSB backend is working after all. But
the libusb_reset_device() does not solve the firmware problem.

First run is okay. But 2nd run will not be okay (interrupt transfer
and bulk transfer failed). I need to physically
reset the MCU to get it working again.

***@ACERPC /c/cygwin/home/mcuee/mcu/libusb1win32/winusb_new/lvrWinusb
$ ./libusb1_LVR_WinUSB2.exe
libusb:debug [libusb_init]
libusb:debug [windows_clock_gettime_threaded] hires timer available (Frequency:
25000000 Hz)
libusb:debug [usbi_add_pollfd] add fd 3 events 1
libusb:debug [libusb_init] created default context
libusb:debug [libusb_get_device_list]
libusb:debug [usb_enumerate_hub] busnum 0 devaddr 0 session_id 0
libusb:debug [usb_enumerate_hub] allocating new device for session 0
libusb:debug [initialize_device] active config: 1
libusb:debug [usb_enumerate_hub] 8 ports Hub: \\.\USB#ROOT_HUB20#4&7056C45&0#{F1
8A0E88-C30C-11D0-8815-00A0C906BED8}
libusb:debug [usb_enumerate_hub] busnum 0 devaddr 1 session_id 1
libusb:debug [usb_enumerate_hub] allocating new device for session 1
libusb:debug [initialize_device] active config: 1
libusb:debug [cache_config_descriptors] cached config descriptor #1 (25 bytes)
libusb:debug [usb_enumerate_hub] 4 ports Hub: \\.\USB#VID_05E3&PID_0606#5&17D847
74&0&2#{F18A0E88-C30C-11D0-8815-00A0C906BED8}
libusb:debug [usb_enumerate_hub] busnum 0 devaddr 3 session_id 3
libusb:debug [usb_enumerate_hub] allocating new device for session 3
libusb:debug [initialize_device] active config: 1
libusb:debug [cache_config_descriptors] cached config descriptor #1 (41 bytes)
libusb:debug [usb_enumerate_hub] busnum 0 devaddr 2 session_id 2
libusb:debug [usb_enumerate_hub] allocating new device for session 2
libusb:debug [initialize_device] active config: 1
libusb:debug [cache_config_descriptors] cached config descriptor #1 (32 bytes)
libusb:debug [usb_enumerate_hub] busnum 1 devaddr 0 session_id 256
libusb:debug [usb_enumerate_hub] allocating new device for session 256
libusb:debug [initialize_device] active config: 1
libusb:debug [usb_enumerate_hub] 8 ports Hub: \\.\USB#ROOT_HUB#4&278C294E&0#{F18
A0E88-C30C-11D0-8815-00A0C906BED8}
libusb:debug [usb_enumerate_hub] busnum 1 devaddr 1 session_id 257
libusb:debug [usb_enumerate_hub] allocating new device for session 257
libusb:debug [initialize_device] active config: 1
libusb:debug [cache_config_descriptors] cached config descriptor #1 (32 bytes)
libusb:debug [usb_enumerate_hub] busnum 1 devaddr 2 session_id 258
libusb:debug [usb_enumerate_hub] allocating new device for session 258
libusb:debug [initialize_device] active config: 1
libusb:debug [cache_config_descriptors] cached config descriptor #1 (59 bytes)
libusb:debug [usb_enumerate_hub] busnum 1 devaddr 3 session_id 259
libusb:debug [usb_enumerate_hub] allocating new device for session 259
libusb:debug [initialize_device] active config: 1
libusb:debug [cache_config_descriptors] cached config descriptor #1 (34 bytes)
libusb:debug [usb_enumerate_hub] busnum 1 devaddr 4 session_id 260
libusb:debug [usb_enumerate_hub] allocating new device for session 260
libusb:debug [initialize_device] active config: 1
libusb:debug [cache_config_descriptors] cached config descriptor #1 (32 bytes)
libusb:debug [discovered_devs_append] need to increase capacity
libusb:debug [usb_enumerate_hub] busnum 1 devaddr 5 session_id 261
libusb:debug [usb_enumerate_hub] allocating new device for session 261
libusb:debug [initialize_device] active config: 1
libusb:debug [cache_config_descriptors] cached config descriptor #1 (46 bytes)
libusb:debug [usb_enumerate_hub] busnum 1 devaddr 6 session_id 262
libusb:debug [usb_enumerate_hub] allocating new device for session 262
libusb:debug [initialize_device] active config: 1
libusb:debug [cache_config_descriptors] cached config descriptor #1 (41 bytes)
libusb:debug [set_device_paths] path (1:4): \\.\USB#VID_0403&PID_6001#FTDEH51S#{
A5DCBF10-6530-11D2-901F-00C04FB951ED}
libusb:debug [set_device_paths] driver: FTDIBUS
libusb:debug [set_device_paths] path (1:3): \\.\USB#VID_046D&PID_C054#5&207B166D
&0&4#{A5DCBF10-6530-11D2-901F-00C04FB951ED}
libusb:debug [set_device_paths] driver: HidUsb
libusb:debug [set_hid_device] interface_path[0]: \\.\HID#VID_046D&PID_C054#6&A6C
CB04&0&0000#{4D1E55B2-F16F-11CF-88CB-001111000030}
libusb:debug [set_device_paths] path (1:6): \\.\USB#VID_046D&PID_C216#5&207B166D
&0&8#{A5DCBF10-6530-11D2-901F-00C04FB951ED}
libusb:debug [set_device_paths] driver: HidUsb
libusb:debug [set_hid_device] interface_path[0]: \\.\HID#VID_046D&PID_C216#6&A62
4C3A&0&0000#{4D1E55B2-F16F-11CF-88CB-001111000030}
libusb:debug [set_device_paths] path (0:3): \\.\USB#VID_04D8&PID_900A#BUR0932115
63#{A5DCBF10-6530-11D2-901F-00C04FB951ED}
libusb:debug [set_device_paths] driver: HidUsb
libusb:debug [set_hid_device] interface_path[0]: \\.\HID#VID_04D8&PID_900A#6&3B5
3DF4C&0&0000#{4D1E55B2-F16F-11CF-88CB-001111000030}
libusb:debug [set_device_paths] path (1:2): \\.\USB#VID_04F2&PID_0760#5&207B166D
&0&3#{A5DCBF10-6530-11D2-901F-00C04FB951ED}
libusb:debug [set_device_paths] driver: usbccgp
libusb:warning [set_composite_device] interface_path[0]: unhandled API - interfa
ce will be disabled
libusb:debug [set_composite_device] interface_nr = 1, error = 5
libusb:warning [set_composite_device] composite device: no interfaces were found

libusb:debug [set_device_paths] path (1:1): \\.\USB#VID_058F&PID_9360#2004888#{A
5DCBF10-6530-11D2-901F-00C04FB951ED}
libusb:debug [set_device_paths] driver: USBSTOR
libusb:debug [set_device_paths] path (0:2): \\.\USB#VID_0781&PID_5151#0000B87023
60177D#{A5DCBF10-6530-11D2-901F-00C04FB951ED}
libusb:debug [set_device_paths] driver: USBSTOR
libusb:debug [set_device_paths] path (1:5): \\.\USB#VID_0925&PID_1456#5&207B166D
&0&6#{A5DCBF10-6530-11D2-901F-00C04FB951ED}
libusb:debug [set_device_paths] driver: WinUSB
libusb:debug [libusb_get_device_descriptor]
libusb:debug [libusb_get_device_descriptor]
libusb:debug [libusb_get_device_descriptor]
libusb:debug [libusb_get_device_descriptor]
libusb:debug [libusb_get_device_descriptor]
libusb:debug [libusb_get_device_descriptor]
libusb:debug [libusb_get_device_descriptor]
libusb:debug [libusb_get_device_descriptor]
libusb:debug [libusb_get_device_descriptor]
libusb:debug [libusb_get_device_descriptor]
libusb:debug [libusb_open] open 1.5
libusb:debug [libusb_unref_device] destroy device 0.0
libusb:debug [libusb_unref_device] destroy device 0.1
libusb:debug [libusb_unref_device] destroy device 0.3
libusb:debug [libusb_unref_device] destroy device 0.2
libusb:debug [libusb_unref_device] destroy device 1.0
libusb:debug [libusb_unref_device] destroy device 1.1
libusb:debug [libusb_unref_device] destroy device 1.2
libusb:debug [libusb_unref_device] destroy device 1.3
libusb:debug [libusb_unref_device] destroy device 1.4
libusb:debug [libusb_unref_device] destroy device 1.6
Successfully find the LVR WINUSB device
libusb:debug [libusb_set_configuration] configuration 1
libusb:debug [libusb_claim_interface] interface 0
libusb:debug [winusb_claim_interface] claimed interface 0
libusb:debug [libusb_get_config_descriptor] index 0
libusb:debug [windows_assign_endpoints] (re)assigned endpoint 01 to interface 0
libusb:debug [windows_assign_endpoints] (re)assigned endpoint 81 to interface 0
libusb:debug [windows_assign_endpoints] (re)assigned endpoint 02 to interface 0
libusb:debug [windows_assign_endpoints] (re)assigned endpoint 82 to interface 0
libusb:warning [winusb_submit_control_transfer] auto-claimed interface 0 for con
trol request
libusb:debug [winusb_submit_control_transfer] will use interface 0
libusb:debug [usbi_add_pollfd] add fd 5 events 1
libusb:debug [libusb_get_next_timeout] next timeout in 0.974320s
libusb:debug [handle_events] poll() 2 fds with timeout in 975ms
libusb:debug [handle_events] poll() returned 1
libusb:debug [windows_handle_events] checking fd 3 with revents = 0000
libusb:debug [windows_handle_events] checking fd 5 with revents = 0001
libusb:debug [usbi_remove_pollfd] remove fd 5
libusb:debug [windows_transfer_callback] handling I/O completion with status 0
libusb:debug [ctrl_transfer_cb] actual_length=0
Successfully set usb configuration 1
libusb:debug [libusb_claim_interface] interface 0
Successfully claimed interface
Testing control transfer: libusb:debug [winusb_submit_control_transfer] will use
interface 0
libusb:debug [usbi_add_pollfd] add fd 5 events 1
libusb:debug [libusb_get_next_timeout] next timeout in 4.995480s
libusb:debug [handle_events] poll() 2 fds with timeout in 4996ms
libusb:debug [handle_events] poll() returned 1
libusb:debug [windows_handle_events] checking fd 3 with revents = 0000
libusb:debug [windows_handle_events] checking fd 5 with revents = 0001
libusb:debug [usbi_remove_pollfd] remove fd 5
libusb:debug [windows_transfer_callback] handling I/O completion with status 0
libusb:debug [ctrl_transfer_cb] actual_length=2
libusb:debug [winusb_submit_control_transfer] will use interface 0
libusb:debug [usbi_add_pollfd] add fd 5 events 1
libusb:debug [libusb_get_next_timeout] next timeout in 4.995720s
libusb:debug [handle_events] poll() 2 fds with timeout in 4996ms
libusb:debug [handle_events] poll() returned 1
libusb:debug [windows_handle_events] checking fd 3 with revents = 0000
libusb:debug [windows_handle_events] checking fd 5 with revents = 0001
libusb:debug [usbi_remove_pollfd] remove fd 5
libusb:debug [windows_transfer_callback] handling I/O completion with status 0
libusb:debug [ctrl_transfer_cb] actual_length=2

20, 20; 21, 21;

Testing interrupt transfer: libusb:debug [winusb_submit_bulk_transfer] matched e
ndpoint 02 with interface 0
libusb:debug [winusb_submit_bulk_transfer] writing 2 bytes
libusb:debug [usbi_add_pollfd] add fd 5 events 4
libusb:debug [libusb_get_next_timeout] next timeout in 4.992480s
libusb:debug [handle_events] poll() 2 fds with timeout in 4993ms
libusb:debug [handle_events] poll() returned 1
libusb:debug [windows_handle_events] checking fd 3 with revents = 0000
libusb:debug [windows_handle_events] checking fd 5 with revents = 0004
libusb:debug [usbi_remove_pollfd] remove fd 5
libusb:debug [windows_transfer_callback] handling I/O completion with status 0
libusb:debug [bulk_transfer_cb] actual_length=2
libusb:debug [winusb_submit_bulk_transfer] matched endpoint 82 with interface 0
libusb:debug [winusb_submit_bulk_transfer] reading 2 bytes
libusb:debug [usbi_add_pollfd] add fd 5 events 1
libusb:debug [libusb_get_next_timeout] next timeout in 4.993320s
libusb:debug [handle_events] poll() 2 fds with timeout in 4994ms
libusb:debug [handle_events] poll() returned 1
libusb:debug [windows_handle_events] checking fd 3 with revents = 0000
libusb:debug [windows_handle_events] checking fd 5 with revents = 0001
libusb:debug [usbi_remove_pollfd] remove fd 5
libusb:debug [windows_transfer_callback] handling I/O completion with status 0
libusb:debug [bulk_transfer_cb] actual_length=2

00, 00; 01, 01;

Testing bulk transfer: libusb:debug [winusb_submit_bulk_transfer] matched endpoi
nt 01 with interface 0
libusb:debug [winusb_submit_bulk_transfer] writing 64 bytes
libusb:debug [usbi_add_pollfd] add fd 5 events 4
libusb:debug [libusb_get_next_timeout] next timeout in 4.992800s
libusb:debug [handle_events] poll() 2 fds with timeout in 4993ms
libusb:debug [handle_events] poll() returned 1
libusb:debug [windows_handle_events] checking fd 3 with revents = 0000
libusb:debug [windows_handle_events] checking fd 5 with revents = 0004
libusb:debug [usbi_remove_pollfd] remove fd 5
libusb:debug [windows_transfer_callback] handling I/O completion with status 0
libusb:debug [bulk_transfer_cb] actual_length=64
libusb:debug [winusb_submit_bulk_transfer] matched endpoint 81 with interface 0
libusb:debug [winusb_submit_bulk_transfer] reading 64 bytes
libusb:debug [usbi_add_pollfd] add fd 5 events 1
libusb:debug [libusb_get_next_timeout] next timeout in 4.993080s
libusb:debug [handle_events] poll() 2 fds with timeout in 4994ms
libusb:debug [handle_events] poll() returned 1
libusb:debug [windows_handle_events] checking fd 3 with revents = 0000
libusb:debug [windows_handle_events] checking fd 5 with revents = 0001
libusb:debug [usbi_remove_pollfd] remove fd 5
libusb:debug [windows_transfer_callback] handling I/O completion with status 0
libusb:debug [bulk_transfer_cb] actual_length=64

00, 00; 01, 01; 02, 02; 03, 03; 04, 04; 05, 05; 06, 06; 07, 07;
08, 08; 09, 09; 0a, 0a; 0b, 0b; 0c, 0c; 0d, 0d; 0e, 0e; 0f, 0f;
10, 10; 11, 11; 12, 12; 13, 13; 14, 14; 15, 15; 16, 16; 17, 17;
18, 18; 19, 19; 1a, 1a; 1b, 1b; 1c, 1c; 1d, 1d; 1e, 1e; 1f, 1f;
20, 20; 21, 21; 22, 22; 23, 23; 24, 24; 25, 25; 26, 26; 27, 27;
28, 28; 29, 29; 2a, 2a; 2b, 2b; 2c, 2c; 2d, 2d; 2e, 2e; 2f, 2f;
30, 30; 31, 31; 32, 32; 33, 33; 34, 34; 35, 35; 36, 36; 37, 37;
38, 38; 39, 39; 3a, 3a; 3b, 3b; 3c, 3c; 3d, 3d; 3e, 3e; 3f, 3f;

libusb:debug [libusb_release_interface] interface 0
libusb:debug [libusb_get_config_descriptor] index 0
libusb:debug [windows_assign_endpoints] (re)assigned endpoint 01 to interface 0
libusb:debug [windows_assign_endpoints] (re)assigned endpoint 81 to interface 0
libusb:debug [windows_assign_endpoints] (re)assigned endpoint 02 to interface 0
libusb:debug [windows_assign_endpoints] (re)assigned endpoint 82 to interface 0
libusb:debug [libusb_reset_device]
libusb:debug [winusb_reset_device] resetting ep 01
libusb:error [winusb_reset_device] WinUsb_AbortPipe (pipe address 01) failed: [6
] The handle is invalid.

libusb:error [winusb_reset_device] WinUsb_ResetPipe (pipe address 01) failed: [6
] The handle is invalid.

libusb:debug [winusb_reset_device] resetting ep 81
libusb:error [winusb_reset_device] WinUsb_AbortPipe (pipe address 81) failed: [6
] The handle is invalid.

libusb:error [winusb_reset_device] WinUsb_FlushPipe (pipe address 81) failed: [6
] The handle is invalid.

libusb:error [winusb_reset_device] WinUsb_ResetPipe (pipe address 81) failed: [6
] The handle is invalid.

libusb:debug [winusb_reset_device] resetting ep 02
libusb:error [winusb_reset_device] WinUsb_AbortPipe (pipe address 02) failed: [6
] The handle is invalid.

libusb:error [winusb_reset_device] WinUsb_ResetPipe (pipe address 02) failed: [6
] The handle is invalid.

libusb:debug [winusb_reset_device] resetting ep 82
libusb:error [winusb_reset_device] WinUsb_AbortPipe (pipe address 82) failed: [6
] The handle is invalid.

libusb:error [winusb_reset_device] WinUsb_FlushPipe (pipe address 82) failed: [6
] The handle is invalid.

libusb:error [winusb_reset_device] WinUsb_ResetPipe (pipe address 82) failed: [6
] The handle is invalid.

libusb:debug [libusb_close]
libusb:debug [libusb_unref_device] destroy device 1.5
libusb:debug [libusb_exit]
libusb:debug [usbi_remove_pollfd] remove fd 3
libusb:debug [windows_clock_gettime_threaded] timer thread quitting
libusb:debug [libusb_exit] freeing default context

***@ACERPC /c/cygwin/home/mcuee/mcu/libusb1win32/winusb_new/lvrWinusb
$ ./libusb1_LVR_WinUSB2.exe
libusb:debug [libusb_init]
libusb:debug [windows_clock_gettime_threaded] hires timer available (Frequency:
25000000 Hz)
libusb:debug [usbi_add_pollfd] add fd 3 events 1
libusb:debug [libusb_init] created default context
libusb:debug [libusb_get_device_list]
libusb:debug [usb_enumerate_hub] busnum 0 devaddr 0 session_id 0
libusb:debug [usb_enumerate_hub] allocating new device for session 0
libusb:debug [initialize_device] active config: 1
libusb:debug [usb_enumerate_hub] 8 ports Hub: \\.\USB#ROOT_HUB20#4&7056C45&0#{F1
8A0E88-C30C-11D0-8815-00A0C906BED8}
libusb:debug [usb_enumerate_hub] busnum 0 devaddr 1 session_id 1
libusb:debug [usb_enumerate_hub] allocating new device for session 1
libusb:debug [initialize_device] active config: 1
libusb:debug [cache_config_descriptors] cached config descriptor #1 (25 bytes)
libusb:debug [usb_enumerate_hub] 4 ports Hub: \\.\USB#VID_05E3&PID_0606#5&17D847
74&0&2#{F18A0E88-C30C-11D0-8815-00A0C906BED8}
libusb:debug [usb_enumerate_hub] busnum 0 devaddr 3 session_id 3
libusb:debug [usb_enumerate_hub] allocating new device for session 3
libusb:debug [initialize_device] active config: 1
libusb:debug [cache_config_descriptors] cached config descriptor #1 (41 bytes)
libusb:debug [usb_enumerate_hub] busnum 0 devaddr 2 session_id 2
libusb:debug [usb_enumerate_hub] allocating new device for session 2
libusb:debug [initialize_device] active config: 1
libusb:debug [cache_config_descriptors] cached config descriptor #1 (32 bytes)
libusb:debug [usb_enumerate_hub] busnum 1 devaddr 0 session_id 256
libusb:debug [usb_enumerate_hub] allocating new device for session 256
libusb:debug [initialize_device] active config: 1
libusb:debug [usb_enumerate_hub] 8 ports Hub: \\.\USB#ROOT_HUB#4&278C294E&0#{F18
A0E88-C30C-11D0-8815-00A0C906BED8}
libusb:debug [usb_enumerate_hub] busnum 1 devaddr 1 session_id 257
libusb:debug [usb_enumerate_hub] allocating new device for session 257
libusb:debug [initialize_device] active config: 1
libusb:debug [cache_config_descriptors] cached config descriptor #1 (32 bytes)
libusb:debug [usb_enumerate_hub] busnum 1 devaddr 2 session_id 258
libusb:debug [usb_enumerate_hub] allocating new device for session 258
libusb:debug [initialize_device] active config: 1
libusb:debug [cache_config_descriptors] cached config descriptor #1 (59 bytes)
libusb:debug [usb_enumerate_hub] busnum 1 devaddr 3 session_id 259
libusb:debug [usb_enumerate_hub] allocating new device for session 259
libusb:debug [initialize_device] active config: 1
libusb:debug [cache_config_descriptors] cached config descriptor #1 (34 bytes)
libusb:debug [usb_enumerate_hub] busnum 1 devaddr 4 session_id 260
libusb:debug [usb_enumerate_hub] allocating new device for session 260
libusb:debug [initialize_device] active config: 1
libusb:debug [cache_config_descriptors] cached config descriptor #1 (32 bytes)
libusb:debug [discovered_devs_append] need to increase capacity
libusb:debug [usb_enumerate_hub] busnum 1 devaddr 5 session_id 261
libusb:debug [usb_enumerate_hub] allocating new device for session 261
libusb:debug [initialize_device] active config: 1
libusb:debug [cache_config_descriptors] cached config descriptor #1 (46 bytes)
libusb:debug [usb_enumerate_hub] busnum 1 devaddr 6 session_id 262
libusb:debug [usb_enumerate_hub] allocating new device for session 262
libusb:debug [initialize_device] active config: 1
libusb:debug [cache_config_descriptors] cached config descriptor #1 (41 bytes)
libusb:debug [set_device_paths] path (1:4): \\.\USB#VID_0403&PID_6001#FTDEH51S#{
A5DCBF10-6530-11D2-901F-00C04FB951ED}
libusb:debug [set_device_paths] driver: FTDIBUS
libusb:debug [set_device_paths] path (1:3): \\.\USB#VID_046D&PID_C054#5&207B166D
&0&4#{A5DCBF10-6530-11D2-901F-00C04FB951ED}
libusb:debug [set_device_paths] driver: HidUsb
libusb:debug [set_hid_device] interface_path[0]: \\.\HID#VID_046D&PID_C054#6&A6C
CB04&0&0000#{4D1E55B2-F16F-11CF-88CB-001111000030}
libusb:debug [set_device_paths] path (1:6): \\.\USB#VID_046D&PID_C216#5&207B166D
&0&8#{A5DCBF10-6530-11D2-901F-00C04FB951ED}
libusb:debug [set_device_paths] driver: HidUsb
libusb:debug [set_hid_device] interface_path[0]: \\.\HID#VID_046D&PID_C216#6&A62
4C3A&0&0000#{4D1E55B2-F16F-11CF-88CB-001111000030}
libusb:debug [set_device_paths] path (0:3): \\.\USB#VID_04D8&PID_900A#BUR0932115
63#{A5DCBF10-6530-11D2-901F-00C04FB951ED}
libusb:debug [set_device_paths] driver: HidUsb
libusb:debug [set_hid_device] interface_path[0]: \\.\HID#VID_04D8&PID_900A#6&3B5
3DF4C&0&0000#{4D1E55B2-F16F-11CF-88CB-001111000030}
libusb:debug [set_device_paths] path (1:2): \\.\USB#VID_04F2&PID_0760#5&207B166D
&0&3#{A5DCBF10-6530-11D2-901F-00C04FB951ED}
libusb:debug [set_device_paths] driver: usbccgp
libusb:warning [set_composite_device] interface_path[0]: unhandled API - interfa
ce will be disabled
libusb:debug [set_composite_device] interface_nr = 1, error = 5
libusb:warning [set_composite_device] composite device: no interfaces were found

libusb:debug [set_device_paths] path (1:1): \\.\USB#VID_058F&PID_9360#2004888#{A
5DCBF10-6530-11D2-901F-00C04FB951ED}
libusb:debug [set_device_paths] driver: USBSTOR
libusb:debug [set_device_paths] path (0:2): \\.\USB#VID_0781&PID_5151#0000B87023
60177D#{A5DCBF10-6530-11D2-901F-00C04FB951ED}
libusb:debug [set_device_paths] driver: USBSTOR
libusb:debug [set_device_paths] path (1:5): \\.\USB#VID_0925&PID_1456#5&207B166D
&0&6#{A5DCBF10-6530-11D2-901F-00C04FB951ED}
libusb:debug [set_device_paths] driver: WinUSB
libusb:debug [libusb_get_device_descriptor]
libusb:debug [libusb_get_device_descriptor]
libusb:debug [libusb_get_device_descriptor]
libusb:debug [libusb_get_device_descriptor]
libusb:debug [libusb_get_device_descriptor]
libusb:debug [libusb_get_device_descriptor]
libusb:debug [libusb_get_device_descriptor]
libusb:debug [libusb_get_device_descriptor]
libusb:debug [libusb_get_device_descriptor]
libusb:debug [libusb_get_device_descriptor]
libusb:debug [libusb_open] open 1.5
libusb:debug [libusb_unref_device] destroy device 0.0
libusb:debug [libusb_unref_device] destroy device 0.1
libusb:debug [libusb_unref_device] destroy device 0.3
libusb:debug [libusb_unref_device] destroy device 0.2
libusb:debug [libusb_unref_device] destroy device 1.0
libusb:debug [libusb_unref_device] destroy device 1.1
libusb:debug [libusb_unref_device] destroy device 1.2
libusb:debug [libusb_unref_device] destroy device 1.3
libusb:debug [libusb_unref_device] destroy device 1.4
libusb:debug [libusb_unref_device] destroy device 1.6
Successfully find the LVR WINUSB device
libusb:debug [libusb_set_configuration] configuration 1
libusb:debug [libusb_claim_interface] interface 0
libusb:debug [winusb_claim_interface] claimed interface 0
libusb:debug [libusb_get_config_descriptor] index 0
libusb:debug [windows_assign_endpoints] (re)assigned endpoint 01 to interface 0
libusb:debug [windows_assign_endpoints] (re)assigned endpoint 81 to interface 0
libusb:debug [windows_assign_endpoints] (re)assigned endpoint 02 to interface 0
libusb:debug [windows_assign_endpoints] (re)assigned endpoint 82 to interface 0
libusb:warning [winusb_submit_control_transfer] auto-claimed interface 0 for con
trol request
libusb:debug [winusb_submit_control_transfer] will use interface 0
libusb:debug [usbi_add_pollfd] add fd 5 events 1
libusb:debug [libusb_get_next_timeout] next timeout in 0.973800s
libusb:debug [handle_events] poll() 2 fds with timeout in 974ms
libusb:debug [handle_events] poll() returned 1
libusb:debug [windows_handle_events] checking fd 3 with revents = 0000
libusb:debug [windows_handle_events] checking fd 5 with revents = 0001
libusb:debug [usbi_remove_pollfd] remove fd 5
libusb:debug [windows_transfer_callback] handling I/O completion with status 0
libusb:debug [ctrl_transfer_cb] actual_length=0
Successfully set usb configuration 1
libusb:debug [libusb_claim_interface] interface 0
Successfully claimed interface
Testing control transfer: libusb:debug [winusb_submit_control_transfer] will use
interface 0
libusb:debug [usbi_add_pollfd] add fd 5 events 1
libusb:debug [libusb_get_next_timeout] next timeout in 4.995480s
libusb:debug [handle_events] poll() 2 fds with timeout in 4996ms
libusb:debug [handle_events] poll() returned 1
libusb:debug [windows_handle_events] checking fd 3 with revents = 0000
libusb:debug [windows_handle_events] checking fd 5 with revents = 0001
libusb:debug [usbi_remove_pollfd] remove fd 5
libusb:debug [windows_transfer_callback] handling I/O completion with status 0
libusb:debug [ctrl_transfer_cb] actual_length=2
libusb:debug [winusb_submit_control_transfer] will use interface 0
libusb:debug [usbi_add_pollfd] add fd 5 events 1
libusb:debug [libusb_get_next_timeout] next timeout in 4.995720s
libusb:debug [handle_events] poll() 2 fds with timeout in 4996ms
libusb:debug [handle_events] poll() returned 1
libusb:debug [windows_handle_events] checking fd 3 with revents = 0000
libusb:debug [windows_handle_events] checking fd 5 with revents = 0001
libusb:debug [usbi_remove_pollfd] remove fd 5
libusb:debug [windows_transfer_callback] handling I/O completion with status 0
libusb:debug [ctrl_transfer_cb] actual_length=2

20, 20; 21, 21;

Testing interrupt transfer: libusb:debug [winusb_submit_bulk_transfer] matched e
ndpoint 02 with interface 0
libusb:debug [winusb_submit_bulk_transfer] writing 2 bytes
libusb:debug [usbi_add_pollfd] add fd 5 events 4
libusb:debug [libusb_get_next_timeout] next timeout in 4.992920s
libusb:debug [handle_events] poll() 2 fds with timeout in 4993ms
libusb:debug [handle_events] poll() returned 1
libusb:debug [windows_handle_events] checking fd 3 with revents = 0000
libusb:debug [windows_handle_events] checking fd 5 with revents = 0004
libusb:debug [usbi_remove_pollfd] remove fd 5
libusb:debug [windows_transfer_callback] handling I/O completion with status 0
libusb:debug [bulk_transfer_cb] actual_length=2
libusb:debug [winusb_submit_bulk_transfer] matched endpoint 82 with interface 0
libusb:debug [winusb_submit_bulk_transfer] reading 2 bytes
libusb:debug [usbi_add_pollfd] add fd 5 events 1
libusb:debug [libusb_get_next_timeout] next timeout in 4.993320s
libusb:debug [handle_events] poll() 2 fds with timeout in 4994ms
libusb:debug [handle_events] poll() returned 0
libusb:debug [libusb_cancel_transfer]
libusb:debug [usbi_remove_pollfd] remove fd 5
libusb:debug [winusb_abort_transfers] will use interface 0
libusb:debug [usbi_handle_transfer_cancellation] detected timeout cancellation
libusb:debug [bulk_transfer_cb] actual_length=0
Interrupt read error -7
Testing bulk transfer: libusb:debug [winusb_submit_bulk_transfer] matched endpoi
nt 01 with interface 0
libusb:debug [winusb_submit_bulk_transfer] writing 64 bytes
libusb:debug [usbi_add_pollfd] add fd 5 events 4
libusb:debug [libusb_get_next_timeout] next timeout in 4.984240s
libusb:debug [handle_events] poll() 2 fds with timeout in 4985ms
libusb:debug [handle_events] poll() returned 1
libusb:debug [windows_handle_events] checking fd 3 with revents = 0000
libusb:debug [windows_handle_events] checking fd 5 with revents = 0004
libusb:debug [usbi_remove_pollfd] remove fd 5
libusb:debug [windows_transfer_callback] handling I/O completion with status 0
libusb:debug [bulk_transfer_cb] actual_length=64
libusb:debug [winusb_submit_bulk_transfer] matched endpoint 81 with interface 0
libusb:debug [winusb_submit_bulk_transfer] reading 64 bytes
libusb:debug [usbi_add_pollfd] add fd 5 events 1
libusb:debug [libusb_get_next_timeout] next timeout in 4.987280s
libusb:debug [handle_events] poll() 2 fds with timeout in 4988ms
libusb:debug [handle_events] poll() returned 0
libusb:debug [libusb_cancel_transfer]
libusb:debug [usbi_remove_pollfd] remove fd 5
libusb:debug [winusb_abort_transfers] will use interface 0
libusb:debug [usbi_handle_transfer_cancellation] detected timeout cancellation
libusb:debug [bulk_transfer_cb] actual_length=0
Bulk read error -7
libusb:debug [libusb_release_interface] interface 0
libusb:debug [libusb_get_config_descriptor] index 0
libusb:debug [windows_assign_endpoints] (re)assigned endpoint 01 to interface 0
libusb:debug [windows_assign_endpoints] (re)assigned endpoint 81 to interface 0
libusb:debug [windows_assign_endpoints] (re)assigned endpoint 02 to interface 0
libusb:debug [windows_assign_endpoints] (re)assigned endpoint 82 to interface 0
libusb:debug [libusb_reset_device]
libusb:debug [winusb_reset_device] resetting ep 01
libusb:error [winusb_reset_device] WinUsb_AbortPipe (pipe address 01) failed: [6
] The handle is invalid.

libusb:error [winusb_reset_device] WinUsb_ResetPipe (pipe address 01) failed: [6
] The handle is invalid.

libusb:debug [winusb_reset_device] resetting ep 81
libusb:error [winusb_reset_device] WinUsb_AbortPipe (pipe address 81) failed: [6
] The handle is invalid.

libusb:error [winusb_reset_device] WinUsb_FlushPipe (pipe address 81) failed: [6
] The handle is invalid.

libusb:error [winusb_reset_device] WinUsb_ResetPipe (pipe address 81) failed: [6
] The handle is invalid.

libusb:debug [winusb_reset_device] resetting ep 02
libusb:error [winusb_reset_device] WinUsb_AbortPipe (pipe address 02) failed: [6
] The handle is invalid.

libusb:error [winusb_reset_device] WinUsb_ResetPipe (pipe address 02) failed: [6
] The handle is invalid.

libusb:debug [winusb_reset_device] resetting ep 82
libusb:error [winusb_reset_device] WinUsb_AbortPipe (pipe address 82) failed: [6
] The handle is invalid.

libusb:error [winusb_reset_device] WinUsb_FlushPipe (pipe address 82) failed: [6
] The handle is invalid.

libusb:error [winusb_reset_device] WinUsb_ResetPipe (pipe address 82) failed: [6
] The handle is invalid.

libusb:debug [libusb_close]
libusb:debug [libusb_unref_device] destroy device 1.5
libusb:debug [libusb_exit]
libusb:debug [usbi_remove_pollfd] remove fd 3
libusb:debug [windows_clock_gettime_threaded] timer thread quitting
libusb:debug [libusb_exit] freeing default context

[Xiaofan Chen]

Post by Xiaofan Chen

Post by Xiaofan Chen
Ok, adding a libusb_reset_device() solved all the problems
under Linux. Maybe there is a potential bug in the firmware
which only exhibits under Linux. This is under Ubuntu 9.10.
Now I will test the libusb 1.0 WinUSB backend under Windows.

Hmm, I think the WinUSB backend is working after all. But
the libusb_reset_device() does not solve the firmware problem.
First run is okay. But 2nd run will not be okay (interrupt transfer
and bulk transfer failed). I need to physically
reset the MCU to get it working again.

In the end, I think the WinUSB backend is working fine.
There may be some differences of the behavior of
libusb_reset_device().

Still I do not have this problem with the host program
from Jan Axelson's website. So it is still a bit strange.

[Pete Batard]

Post by Xiaofan Chen
In the end, I think the WinUSB backend is working fine.
There may be some differences of the behavior of
libusb_reset_device().

This doesn't really surprise me. libusb_reset_device() was a bit
problematic to implement, because WinUSB does not provide an actual
device reset facility. If you look at our implementation, you'll see
that I just went all out with and abort reset and flush for all
endpoints of all interfaces during reset, but that's not the same as
doing an actual device reset.

[Xiaofan Chen]

 

[Alan Stern]

Post by Xiaofan Chen
Ok, adding a libusb_reset_device() solved all the problems
under Linux. Maybe there is a potential bug in the firmware
which only exhibits under Linux. This is under Ubuntu 9.10.
Linux ubuntu 2.6.31-17-generic #54-Ubuntu SMP Thu Dec 10 16:20:31 UTC
2009 i686 GNU/Linux

If you can isolate a test case that demonstrates the firmware bug, Jan
Axelson might like to hear about it.

Alan Stern

[Xiaofan Chen]

Post by Alan Stern

Post by Xiaofan Chen
Ok, adding a libusb_reset_device() solved all the problems
under Linux. Maybe there is a potential bug in the firmware
which only exhibits under Linux. This is under Ubuntu 9.10.
Linux ubuntu 2.6.31-17-generic #54-Ubuntu SMP Thu Dec 10 16:20:31 UTC
2009 i686 GNU/Linux

If you can isolate a test case that demonstrates the firmware bug, Jan
Axelson might like to hear about it.

Her firmware is based on Microchip's USB Stack (V2.5 in this case),
which is known to have various bugs. That is why I think this
is more likely a firmware bug.
http://www.microchip.com/forums/tm.aspx?m=275422&mpage=5

However, this seems to only happen when using libusb to
communicate the device. I will post a usbmon log and you
may be able to to confirm that libusb and Linux are not the
cause of the problem.

[Xiaofan Chen]

Post by Xiaofan Chen
Her firmware is based on Microchip's USB Stack (V2.5 in this case),
which is known to have various bugs. That is why I think this
is more likely a firmware bug.
http://www.microchip.com/forums/tm.aspx?m=275422&mpage=5
However, this seems to only happen when using libusb to
communicate the device. I will post a usbmon log and you
may be able to to confirm that libusb and Linux are not the
cause of the problem.

I encounter very similar problem with the libusb program
to drive her generic HID program. Without the reset
device, the testing of interrupt transfer will fail after the 2nd
run of the test program. This did not happen
for the V2.1 stack based older firmware. So I think
this could well be a regression on the firmware side.

[Alan Stern]

Host program (post 3) (without commenting out the reset code)
http://www.microchip.com/forums/tm.aspx?m=340898
First run is ok.
./libusb1_hidusb4
Successfully find the LVR Generic HID device
Successfully set usb configuration 1
Successfully claimed interface
Testing control transfer using loop back test of feature report
20, 20; 21, 21;
Testing interrupt transfer using loop back test of input/output report
40, 40; 41, 41;
^C
Second run is not ok.
./libusb1_hidusb4
Successfully find the LVR Generic HID device
Successfully set usb configuration 1
Successfully claimed interface
Testing control transfer using loop back test of feature report
20, 20; 21, 21;
Interrupt read error -7
Testing interrupt transfer using loop back test of input/output report
^C
The file size is too big to be attached to the mailing list.

Actually the files get very small once you remove all the lines that
are meant for other devices (i.e., every line containing ":002:" or
":003:").

If you have time, please take a look at the usbmon and see where is the problem.
Thanks in advance.

Here's the first test:

e1cba300 189320505 S Co:2:008:0 s 00 09 0001 0000 0000 0
e1cba300 189321672 C Co:2:008:0 0 0
e1cba300 189321750 S Co:2:008:0 s 21 09 0300 0000 0002 2 = 2021
e1cba300 189324670 C Co:2:008:0 0 2 >
e1cba300 189324711 S Ci:2:008:0 s a1 01 0300 0000 0002 2 <
e1cba300 189327670 C Ci:2:008:0 0 2 = 2021
e1cba300 189327754 S Io:2:008:1 -115:1 2 = 4041
e1cba300 189329669 C Io:2:008:1 0:1 2 >
e1cba300 189329708 S Ii:2:008:1 -115:1 2 <
e1cba300 189331671 C Ii:2:008:1 0:1 2 = 4041

And here's the second:

e1c2be00 244368748 S Co:2:008:0 s 00 09 0001 0000 0000 0
e1c2be00 244371189 C Co:2:008:0 0 0
e1c2be00 244371347 S Co:2:008:0 s 21 09 0300 0000 0002 2 = 2021
e1c2be00 244375194 C Co:2:008:0 0 2 >
e1c2be00 244375323 S Ci:2:008:0 s a1 01 0300 0000 0002 2 <
e1c2be00 244379189 C Ci:2:008:0 0 2 = 2021
e1c2be00 244379296 S Io:2:008:1 -115:1 2 = 4041
e1c2be00 244381183 C Io:2:008:1 0:1 2 >
e1c2be00 244381218 S Ii:2:008:1 -115:1 2 <
e1c2be00 249382230 C Ii:2:008:1 -2:1 0

The only significant difference is that in the second test, the final
interrupt-IN transfer timed out and was cancelled. So as you said,
this appears to be a firmware bug.

Alan Stern

[Xiaofan Chen]

Post by Alan Stern

Host program (post 3) (without commenting out the reset code)
http://www.microchip.com/forums/tm.aspx?m=340898
First run is ok.
./libusb1_hidusb4
Successfully find the LVR Generic HID device
Successfully set usb configuration 1
Successfully claimed interface
Testing control transfer using loop back test of feature report
20, 20; 21, 21;
Testing interrupt transfer using loop back test of input/output report
40, 40; 41, 41;
^C
Second run is not ok.
./libusb1_hidusb4
Successfully find the LVR Generic HID device
Successfully set usb configuration 1
Successfully claimed interface
Testing control transfer using loop back test of feature report
20, 20; 21, 21;
Interrupt read error -7
Testing interrupt transfer using loop back test of input/output report
^C
The file size is too big to be attached to the mailing list.

Actually the files get very small once you remove all the lines that
are meant for other devices (i.e., every line containing ":002:" or
":003:").

If you have time, please take a look at the usbmon and see where is the problem.
Thanks in advance.

e1cba300 189320505 S Co:2:008:0 s 00 09 0001 0000 0000 0
e1cba300 189321672 C Co:2:008:0 0 0
e1cba300 189321750 S Co:2:008:0 s 21 09 0300 0000 0002 2 = 2021
e1cba300 189324670 C Co:2:008:0 0 2 >
e1cba300 189324711 S Ci:2:008:0 s a1 01 0300 0000 0002 2 <
e1cba300 189327670 C Ci:2:008:0 0 2 = 2021
e1cba300 189327754 S Io:2:008:1 -115:1 2 = 4041
e1cba300 189329669 C Io:2:008:1 0:1 2 >
e1cba300 189329708 S Ii:2:008:1 -115:1 2 <
e1cba300 189331671 C Ii:2:008:1 0:1 2 = 4041
e1c2be00 244368748 S Co:2:008:0 s 00 09 0001 0000 0000 0
e1c2be00 244371189 C Co:2:008:0 0 0
e1c2be00 244371347 S Co:2:008:0 s 21 09 0300 0000 0002 2 = 2021
e1c2be00 244375194 C Co:2:008:0 0 2 >
e1c2be00 244375323 S Ci:2:008:0 s a1 01 0300 0000 0002 2 <
e1c2be00 244379189 C Ci:2:008:0 0 2 = 2021
e1c2be00 244379296 S Io:2:008:1 -115:1 2 = 4041
e1c2be00 244381183 C Io:2:008:1 0:1 2 >
e1c2be00 244381218 S Ii:2:008:1 -115:1 2 <
e1c2be00 249382230 C Ii:2:008:1 -2:1 0
The only significant difference is that in the second test, the final
interrupt-IN transfer timed out and was cancelled.  So as you said,
this appears to be a firmware bug.

This is an old thread. But I just want to give a quick update.

It seems to me that finally the firmware bug is identified to be
a data toggle problem. I will need to carry out some more
tests to confirm.
http://www.microchip.com/forums/tm.aspx?m=503200

[Alan Stern]

Post by Xiaofan Chen
This is an old thread. But I just want to give a quick update.
It seems to me that finally the firmware bug is identified to be
a data toggle problem. I will need to carry out some more
tests to confirm.
http://www.microchip.com/forums/tm.aspx?m=503200

That's interesting. The posts in that forum identified
Set-Configuration and Clear-Halt as two requests that must reset an
endpoint's data toggle. However Set-Interface must also reset the data
toggles for all endpoints in the interface, if the device supports it
(USB-2.0 specification, section 9.1.1.5).

Alan Stern

[Xiaofan Chen]

Post by Xiaofan Chen
This is an old thread. But I just want to give a quick update.
It seems to me that finally the firmware bug is identified to be
a data toggle problem. I will need to carry out some more
tests to confirm.
http://www.microchip.com/forums/tm.aspx?m=503200

That's interesting.  The posts in that forum identified
Set-Configuration and Clear-Halt as two requests that must reset an
endpoint's data toggle.  However Set-Interface must also reset the data
toggles for all endpoints in the interface, if the device supports it
(USB-2.0 specification, section 9.1.1.5).

You are right!
Tsuneo confirms that there is a bug with data toggle for the Microchip
USB Stack when dealing with Set_Interface request as well.

============
http://www.microchip.com/forums/fb.aspx?m=503423
Quoting him:
libusb_claim_interface() puts Set_Interface() request to the device,
even when the device has no alternate interface. Of course, it is
allowed to host, but I don't recommend it. Implementation of
Set_Interface() handler often has error on many USB device
stacks, not just Microchip's.

Here is KEIL's one.
http://www.keil.com/forum/docs/thread16287.asp
============