Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Overflow with USB Stress Ball #4

Closed
AstraLuma opened this issue Apr 5, 2016 · 24 comments
Closed

Overflow with USB Stress Ball #4

AstraLuma opened this issue Apr 5, 2016 · 24 comments

Comments

@AstraLuma
Copy link

Thank you for writing this! However, I just compiled master (83894e2) and I'm getting a runtime error:

$ sudo ./bonkers -v      
Attempting to open Dream Cheeky - USB Fidget (Soccer [Football]) (vendor 0x1d34, device 0x0001)
Attempting to open Dream Cheeky - USB Fidget (Basketball) (vendor 0x1d34, device 0x0002)
Attempting to open Dream Cheeky - USB Fidget (Golf) (vendor 0x1d34, device 0x0003)
Attempting to open Dream Cheeky - Big Red Button (vendor 0x1d34, device 0x000d)
Attempting to open Dream Cheeky - Stress Ball (vendor 0x1d34, device 0x0020)
Kernel driver not active
Interface claimed
Detecting events
Error sending report - libusb error -8
Exit code was changed: 1
Closing USB

The libusb documentation reports this as simply "overflow".

Not sure how this happens or why.

Yes, I tried unplugging it, plugging it back in, and immediately re-running bonkers.

@AstraLuma
Copy link
Author

Some additional debugging information from libusb:

$ sudo env LIBUSB_DEBUG="5" ./bonkers -v
libusb: debug [libusb_init] created default context
libusb: debug [libusb_init] libusb v1.0.20.11004
libusb: debug [find_usbfs_path] found usbfs at /dev/bus/usb
libusb: debug [op_init] bulk continuation flag supported
libusb: debug [op_init] zero length packet flag supported
libusb: debug [op_init] sysfs can relate devices
libusb: debug [op_init] sysfs has complete descriptors
libusb: debug [linux_udev_event_thread_main] udev event thread entering.
libusb: debug [linux_get_device_address] getting address for device: usb1 detached: 0
libusb: debug [linux_get_device_address] scan usb1
libusb: debug [linux_get_device_address] bus=1 dev=1
libusb: debug [linux_enumerate_device] busnum 1 devaddr 1 session_id 257
libusb: debug [linux_enumerate_device] allocating new device for 1/1 (session 257)
libusb: debug [linux_get_device_address] getting address for device: 1-1 detached: 0
libusb: debug [linux_get_device_address] scan 1-1
libusb: debug [linux_get_device_address] bus=1 dev=2
libusb: debug [linux_enumerate_device] busnum 1 devaddr 2 session_id 258
libusb: debug [linux_enumerate_device] allocating new device for 1/2 (session 258)
libusb: debug [linux_get_parent_info] Dev 0x1c380e0 (1-1) has parent 0x1c30740 (usb1) port 1
libusb: debug [linux_get_device_address] getting address for device: 1-1.6 detached: 0
libusb: debug [linux_get_device_address] scan 1-1.6
libusb: debug [linux_get_device_address] bus=1 dev=3
libusb: debug [linux_enumerate_device] busnum 1 devaddr 3 session_id 259
libusb: debug [linux_enumerate_device] allocating new device for 1/3 (session 259)
libusb: debug [linux_get_parent_info] Dev 0x1c381b0 (1-1.6) has parent 0x1c380e0 (1-1) port 6
libusb: debug [linux_get_device_address] getting address for device: usb2 detached: 0
libusb: debug [linux_get_device_address] scan usb2
libusb: debug [linux_get_device_address] bus=2 dev=1
libusb: debug [linux_enumerate_device] busnum 2 devaddr 1 session_id 513
libusb: debug [linux_enumerate_device] allocating new device for 2/1 (session 513)
libusb: debug [linux_get_device_address] getting address for device: 2-1 detached: 0
libusb: debug [linux_get_device_address] scan 2-1
libusb: debug [linux_get_device_address] bus=2 dev=2
libusb: debug [linux_enumerate_device] busnum 2 devaddr 2 session_id 514
libusb: debug [linux_enumerate_device] allocating new device for 2/2 (session 514)
libusb: debug [linux_get_parent_info] Dev 0x1c33ef0 (2-1) has parent 0x1c33e30 (usb2) port 1
libusb: debug [linux_get_device_address] getting address for device: 2-1.2 detached: 0
libusb: debug [linux_get_device_address] scan 2-1.2
libusb: debug [linux_get_device_address] bus=2 dev=8
libusb: debug [linux_enumerate_device] busnum 2 devaddr 8 session_id 520
libusb: debug [linux_enumerate_device] allocating new device for 2/8 (session 520)
libusb: debug [linux_get_parent_info] Dev 0x1c33fb0 (2-1.2) has parent 0x1c33ef0 (2-1) port 2
libusb: debug [usbi_add_pollfd] add fd 6 events 1
libusb: debug [usbi_io_init] using timerfd for timeouts
libusb: debug [usbi_add_pollfd] add fd 8 events 1
Attempting to open Dream Cheeky - USB Fidget (Soccer [Football]) (vendor 0x1d34, device 0x0001)
libusb: debug [libusb_get_device_list] 
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] 
Attempting to open Dream Cheeky - USB Fidget (Basketball) (vendor 0x1d34, device 0x0002)
libusb: debug [libusb_get_device_list] 
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] 
Attempting to open Dream Cheeky - USB Fidget (Golf) (vendor 0x1d34, device 0x0003)
libusb: debug [libusb_get_device_list] 
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] 
Attempting to open Dream Cheeky - Big Red Button (vendor 0x1d34, device 0x000d)
libusb: debug [libusb_get_device_list] 
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] 
Attempting to open Dream Cheeky - Stress Ball (vendor 0x1d34, device 0x0020)
libusb: debug [libusb_get_device_list] 
libusb: debug [libusb_get_device_descriptor] 
libusb: debug [libusb_open] open 2.8
libusb: debug [usbi_add_pollfd] add fd 9 events 4
libusb: debug [libusb_kernel_driver_active] interface 0
Kernel driver not active
libusb: debug [libusb_claim_interface] interface 0
Interface claimed
Detecting events
libusb: debug [libusb_alloc_transfer] transfer 0x1c34108
libusb: debug [libusb_submit_transfer] transfer 0x1c34108
libusb: debug [add_to_flying_list] arm timerfd for timeout in 200ms (first in line)
libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
libusb: debug [handle_events] poll fds modified, reallocating
libusb: debug [handle_events] poll() 3 fds with timeout in 60000ms
libusb: debug [handle_events] poll() returned 1
libusb: debug [reap_for_handle] urb type=2 status=-75 transferred=8
libusb: debug [handle_control_completion] handling completion status -75
libusb: debug [handle_control_completion] control overflow error
libusb: debug [disarm_timerfd] 
libusb: debug [usbi_handle_transfer_completion] transfer 0x1c34108 has callback 0x7f97329e5b90
libusb: debug [sync_transfer_cb] actual_length=8
libusb: debug [libusb_free_transfer] transfer 0x1c34108
Error sending report - libusb error -8
Exit code was changed: 1
Closing USB
libusb: debug [libusb_close] 
libusb: debug [usbi_remove_pollfd] remove fd 9

@fidian
Copy link
Owner

fidian commented Apr 5, 2016

I installed libusb-1.0-0-dev and compiled this tool tonight on my Ubuntu 15.10 laptop. Unfortunately I did not replicate your situation yet.

21:01 slate:~/repo/bonkers (master)$ sudo env LIBUSB_DEBUG="5" ./bonkers -v
libusb: debug [libusb_init] created default context
libusb: debug [libusb_init] libusb v1.0.19.10903
libusb: debug [find_usbfs_path] found usbfs at /dev/bus/usb
libusb: debug [op_init] bulk continuation flag supported
libusb: debug [op_init] zero length packet flag supported
libusb: debug [op_init] sysfs can relate devices
libusb: debug [op_init] sysfs has complete descriptors
libusb: debug [linux_udev_event_thread_main] udev event thread entering.
libusb: debug [linux_get_device_address] getting address for device: usb1 detached: 0
libusb: debug [linux_get_device_address] scan usb1
libusb: debug [linux_get_device_address] bus=1 dev=1
libusb: debug [linux_enumerate_device] busnum 1 devaddr 1 session_id 257
libusb: debug [linux_enumerate_device] allocating new device for 1/1 (session 257)
libusb: debug [linux_get_device_address] getting address for device: 1-2 detached: 0
libusb: debug [linux_get_device_address] scan 1-2
libusb: debug [linux_get_device_address] bus=1 dev=8
libusb: debug [linux_enumerate_device] busnum 1 devaddr 8 session_id 264
libusb: debug [linux_enumerate_device] allocating new device for 1/8 (session 264)
libusb: debug [linux_get_parent_info] Dev 0x10074f0 (1-2) has parent 0x10184e0 (usb1) port 2
libusb: debug [linux_get_device_address] getting address for device: 1-4 detached: 0
libusb: debug [linux_get_device_address] scan 1-4
libusb: debug [linux_get_device_address] bus=1 dev=2
libusb: debug [linux_enumerate_device] busnum 1 devaddr 2 session_id 258
libusb: debug [linux_enumerate_device] allocating new device for 1/2 (session 258)
libusb: debug [linux_get_parent_info] Dev 0x10037b0 (1-4) has parent 0x10184e0 (usb1) port 4
libusb: debug [linux_get_device_address] getting address for device: 1-6 detached: 0
libusb: debug [linux_get_device_address] scan 1-6
libusb: debug [linux_get_device_address] bus=1 dev=4
libusb: debug [linux_enumerate_device] busnum 1 devaddr 4 session_id 260
libusb: debug [linux_enumerate_device] allocating new device for 1/4 (session 260)
libusb: debug [linux_get_parent_info] Dev 0x10075b0 (1-6) has parent 0x10184e0 (usb1) port 6
libusb: debug [linux_get_device_address] getting address for device: 1-7 detached: 0
libusb: debug [linux_get_device_address] scan 1-7
libusb: debug [linux_get_device_address] bus=1 dev=5
libusb: debug [linux_enumerate_device] busnum 1 devaddr 5 session_id 261
libusb: debug [linux_enumerate_device] allocating new device for 1/5 (session 261)
libusb: debug [linux_get_parent_info] Dev 0x1005410 (1-7) has parent 0x10184e0 (usb1) port 7
libusb: debug [linux_get_device_address] getting address for device: usb2 detached: 0
libusb: debug [linux_get_device_address] scan usb2
libusb: debug [linux_get_device_address] bus=2 dev=1
libusb: debug [linux_enumerate_device] busnum 2 devaddr 1 session_id 513
libusb: debug [linux_enumerate_device] allocating new device for 2/1 (session 513)
libusb: debug [linux_get_device_address] getting address for device: usb3 detached: 0
libusb: debug [linux_get_device_address] scan usb3
libusb: debug [linux_get_device_address] bus=3 dev=1
libusb: debug [linux_enumerate_device] busnum 3 devaddr 1 session_id 769
libusb: debug [linux_enumerate_device] allocating new device for 3/1 (session 769)
libusb: debug [linux_get_device_address] getting address for device: 3-1 detached: 0
libusb: debug [linux_get_device_address] scan 3-1
libusb: debug [linux_get_device_address] bus=3 dev=2
libusb: debug [linux_enumerate_device] busnum 3 devaddr 2 session_id 770
libusb: debug [linux_enumerate_device] allocating new device for 3/2 (session 770)
libusb: debug [linux_get_parent_info] Dev 0x1019fa0 (3-1) has parent 0x1019ee0 (usb3) port 1
libusb: debug [usbi_add_pollfd] add fd 6 events 1
libusb: debug [usbi_add_pollfd] add fd 8 events 1
libusb: debug [usbi_io_init] using timerfd for timeouts
libusb: debug [usbi_add_pollfd] add fd 10 events 1
Attempting to open Dream Cheeky - USB Fidget (Soccer [Football]) (vendor 0x1d34, device 0x0001)
libusb: debug [libusb_get_device_list] 
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] 
Attempting to open Dream Cheeky - USB Fidget (Basketball) (vendor 0x1d34, device 0x0002)
libusb: debug [libusb_get_device_list] 
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] 
Attempting to open Dream Cheeky - USB Fidget (Golf) (vendor 0x1d34, device 0x0003)
libusb: debug [libusb_get_device_list] 
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] 
Attempting to open Dream Cheeky - Big Red Button (vendor 0x1d34, device 0x000d)
libusb: debug [libusb_get_device_list] 
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] 
Attempting to open Dream Cheeky - Stress Ball (vendor 0x1d34, device 0x0020)
libusb: debug [libusb_get_device_list] 
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.8
libusb: debug [usbi_add_pollfd] add fd 11 events 4
libusb: debug [libusb_kernel_driver_active] interface 0
Kernel driver not active
libusb: debug [libusb_claim_interface] interface 0
Interface claimed
Detecting events
libusb: debug [add_to_flying_list] arm timerfd for timeout in 200ms (first in line)
libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
libusb: debug [handle_events] poll() 4 fds with timeout in 60000ms
libusb: debug [handle_events] poll() returned 1
libusb: debug [reap_for_handle] urb type=2 status=-71 transferred=0
libusb: debug [handle_control_completion] handling completion status -71
libusb: debug [handle_control_completion] low-level bus error occurred
libusb: debug [disarm_timerfd] 
libusb: debug [usbi_handle_transfer_completion] transfer 0x10038d0 has callback 0x7f60721bb0b0
libusb: debug [sync_transfer_cb] actual_length=0
Error sending report - libusb error -1
libusb: debug [add_to_flying_list] arm timerfd for timeout in 200ms (first in line)
libusb: debug [submit_bulk_transfer] need 1 urbs for new transfer with length 8
libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
libusb: debug [handle_events] poll() 4 fds with timeout in 60000ms
libusb: debug [handle_events] poll() returned 1
libusb: debug [reap_for_handle] urb type=1 status=0 transferred=8
libusb: debug [handle_bulk_completion] handling completion status 0 of bulk urb 1/1
libusb: debug [handle_bulk_completion] last URB in transfer --> complete!
libusb: debug [disarm_timerfd] 
libusb: debug [usbi_handle_transfer_completion] transfer 0x10038d0 has callback 0x7f60721bb0b0
libusb: debug [sync_transfer_cb] actual_length=8
libusb: debug [add_to_flying_list] arm timerfd for timeout in 200ms (first in line)
libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
libusb: debug [handle_events] poll() 4 fds with timeout in 60000ms
libusb: debug [handle_events] poll() returned 1
libusb: debug [reap_for_handle] urb type=2 status=-71 transferred=0
libusb: debug [handle_control_completion] handling completion status -71
libusb: debug [handle_control_completion] low-level bus error occurred
libusb: debug [disarm_timerfd] 
libusb: debug [usbi_handle_transfer_completion] transfer 0x10038d0 has callback 0x7f60721bb0b0
libusb: debug [sync_transfer_cb] actual_length=0
Error sending report - libusb error -1
libusb: debug [add_to_flying_list] arm timerfd for timeout in 200ms (first in line)
libusb: debug [submit_bulk_transfer] need 1 urbs for new transfer with length 8
libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
libusb: debug [handle_events] poll() 4 fds with timeout in 60000ms
libusb: debug [handle_events] poll() returned 1
libusb: debug [reap_for_handle] urb type=1 status=0 transferred=8
libusb: debug [handle_bulk_completion] handling completion status 0 of bulk urb 1/1
libusb: debug [handle_bulk_completion] last URB in transfer --> complete!
libusb: debug [disarm_timerfd] 
libusb: debug [usbi_handle_transfer_completion] transfer 0x10038d0 has callback 0x7f60721bb0b0
libusb: debug [sync_transfer_cb] actual_length=8
State switched from '' to '111 138 181'
libusb: debug [add_to_flying_list] arm timerfd for timeout in 200ms (first in line)
libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
libusb: debug [handle_events] poll() 4 fds with timeout in 60000ms
libusb: debug [handle_events] poll() returned 1
libusb: debug [reap_for_handle] urb type=2 status=-71 transferred=0
libusb: debug [handle_control_completion] handling completion status -71
libusb: debug [handle_control_completion] low-level bus error occurred
libusb: debug [disarm_timerfd] 
libusb: debug [usbi_handle_transfer_completion] transfer 0x10038d0 has callback 0x7f60721bb0b0
libusb: debug [sync_transfer_cb] actual_length=0
Error sending report - libusb error -1

It then continues to repeat with lots of errors and scattered responses from the device.

@fidian
Copy link
Owner

fidian commented Apr 5, 2016

What version of which OS are you using? Are you on special hardware, like a Raspberry PI or other non-typical device? Does this device work for anyone else or with any other drivers? I would love to eliminate a hardware issue as the cause of the problem.

Here's the stuff that I see from my logs that doesn't seem to match yours:

libusb: debug [libusb_init] libusb v1.0.19.10903
...
libusb: debug [usbi_add_pollfd] add fd 10 events 1
...
libusb: debug [libusb_open] open 1.8
...
libusb: debug [reap_for_handle] urb type=2 status=-71 transferred=0
libusb: debug [handle_control_completion] handling completion status -71
libusb: debug [handle_control_completion] low-level bus error occurred
libusb: debug [disarm_timerfd] 
libusb: debug [usbi_handle_transfer_completion] transfer 0x10038d0 has callback 0x7f60721bb0b0
libusb: debug [sync_transfer_cb] actual_length=0
Error sending report - libusb error -1

And here's the stuff from your logs:

libusb: debug [libusb_init] libusb v1.0.20.11004
...
libusb: debug [libusb_open] open 2.8
...
libusb: debug [libusb_alloc_transfer] transfer 0x1c34108
libusb: debug [libusb_submit_transfer] transfer 0x1c34108
...
libusb: debug [handle_events] poll fds modified, reallocating
...
libusb: debug [reap_for_handle] urb type=2 status=-75 transferred=8
libusb: debug [handle_control_completion] handling completion status -75
libusb: debug [handle_control_completion] control overflow error
libusb: debug [disarm_timerfd] 
libusb: debug [usbi_handle_transfer_completion] transfer 0x1c34108 has callback 0x7f97329e5b90
libusb: debug [sync_transfer_cb] actual_length=8
libusb: debug [libusb_free_transfer] transfer 0x1c34108
Error sending report - libusb error -8

Could be a difference that's coming up with the next version of the libusb library?

@AstraLuma
Copy link
Author

I'm running arch linux, updated, on a Thinkpad T420 (about as bog-standard and supported as they come).

  • core/libusb 1.0.20-1
  • core/gcc 5.3.0-5

@AstraLuma
Copy link
Author

Oh, and my USB tree:

$ lsusb -t    
/:  Bus 02.Port 1: Dev 1, Class=root_hub, Driver=ehci-pci/3p, 480M
    |__ Port 1: Dev 2, If 0, Class=Hub, Driver=hub/8p, 480M
        |__ Port 2: Dev 8, If 0, Class=Human Interface Device, Driver=, 1.5M
/:  Bus 01.Port 1: Dev 1, Class=root_hub, Driver=ehci-pci/3p, 480M
    |__ Port 1: Dev 2, If 0, Class=Hub, Driver=hub/6p, 480M
        |__ Port 6: Dev 3, If 0, Class=Video, Driver=uvcvideo, 480M
        |__ Port 6: Dev 3, If 1, Class=Video, Driver=uvcvideo, 480M

@fidian
Copy link
Owner

fidian commented Apr 5, 2016

Digging more:

I think I will have to make a VM or Docker container and experiment for a while to get this to work (fail?) properly. Since I really don't know USB that well, I may need to ask people for help on this one. I don't want to admit this, but this tool is mostly just hobbled together from little bits and snippets. It's almost as bad as a Stack Overflow post.

@AstraLuma
Copy link
Author

What's the maximum packet you send? I've got the line wMaxPacketSize 0x0008 1x 8 bytes from lsusb -vd 1d34: (based on the this description).

@AstraLuma
Copy link
Author

(Also, if you have something you want tried, let me know. I do know my way around a C compiler, I just make a habit of avoiding it in my own work.)

@AstraLuma
Copy link
Author

Well, it happens in Python, too: https://gist.github.com/astronouth7303/d5cea052a0b33e423b312ddbd1c00441

@fidian
Copy link
Owner

fidian commented Apr 5, 2016

I created a VM in VirtualBox and installed Arch from a freshly downloaded ISO. Reminded me a lot of Gentoo. Strangely I get a different problem with VirtualBox. How sad.

Attempting to open Dream Cheeky - USB Fidget (Soccer [Football]) (vendor 0x1d34, device 0x0001)
Attempting to open Dream Cheeky - USB Fidget (Basketball) (vendor 0x1d34, device 0x0002)
Attempting to open Dream Cheeky - USB Fidget (Golf) (vendor 0x1d34, device 0x0003)
Attempting to open Dream Cheeky - Big Red Button (vendor 0x1d34, device 0x000d)
Attempting to open Dream Cheeky - Stress Ball (vendor 0x1d34, device 0x0020)
Kernel driver not active
Interface claimed
Detecting events
Error sending report - libusb error -9
Exit code was changed: 1
Closing USB

I guess some experimentation is in order.

@astronouth7303 would you mind editing line 305 to read as follows? It could work if we just ignore overflow errors.... maybe.

if (ret != 8 && ret != LIBUSB_ERROR_OVERFLOW && ret != LIBUSB_ERROR_IO) {

@fidian
Copy link
Owner

fidian commented Apr 5, 2016

For the adventurous, here's the full set of libusb logs from the VirtualBox instance.

libusb: debug [libusb_init] created default context
libusb: debug [libusb_init] libusb v1.0.20.11004
libusb: debug [find_usbfs_path] found usbfs at /dev/bus/usb
libusb: debug [op_init] bulk continuation flag supported
libusb: debug [op_init] zero length packet flag supported
libusb: debug [op_init] sysfs can relate devices
libusb: debug [op_init] sysfs has complete descriptors
libusb: debug [linux_get_device_address] getting address for device: usb1 detached: 0
libusb: debug [linux_get_device_address] scan usb1
libusb: debug [linux_get_device_address] bus=1 dev=1
libusb: debug [linux_enumerate_device] busnum 1 devaddr 1 session_id 257
libusb: debug [linux_enumerate_device] allocating new device for 1/1 (session 257)
libusb: debug [linux_get_device_address] getting address for device: 1-1 detached: 0
libusb: debug [linux_get_device_address] scan 1-1
libusb: debug [linux_get_device_address] bus=1 dev=2
libusb: debug [linux_enumerate_device] busnum 1 devaddr 2 session_id 258
libusb: debug [linux_enumerate_device] allocating new device for 1/2 (session 258)
libusb: debug [linux_get_parent_info] Dev 0x89feb80 (1-1) has parent 0x89feaa8 (usb1) port 1
libusb: debug [linux_get_device_address] getting address for device: 1-2 detached: 0
libusb: debug [linux_get_device_address] scan 1-2
libusb: debug [linux_get_device_address] bus=1 dev=3
libusb: debug [linux_enumerate_device] busnum 1 devaddr 3 session_id 259
libusb: debug [linux_enumerate_device] allocating new device for 1/3 (session 259)
libusb: debug [linux_get_parent_info] Dev 0x89febe8 (1-2) has parent 0x89feaa8 (usb1) port 2
libusb: debug [linux_udev_event_thread_main] udev event thread entering.
libusb: debug [linux_get_device_address] getting address for device: usb2 detached: 0
libusb: debug [linux_get_device_address] scan usb2
libusb: debug [linux_get_device_address] bus=2 dev=1
libusb: debug [linux_enumerate_device] busnum 2 devaddr 1 session_id 513
libusb: debug [linux_enumerate_device] allocating new device for 2/1 (session 513)
libusb: debug [usbi_add_pollfd] add fd 6 events 1
libusb: debug [usbi_io_init] using timerfd for timeouts
libusb: debug [usbi_add_pollfd] add fd 8 events 1
Attempting to open Dream Cheeky - USB Fidget (Soccer [Football]) (vendor 0x1d34, device 0x0001)
libusb: debug [libusb_get_device_list] 
libusb: debug [libusb_get_device_descriptor] 
libusb: debug [libusb_get_device_descriptor] 
libusb: debug [libusb_get_device_descriptor] 
libusb: debug [libusb_get_device_descriptor] 
Attempting to open Dream Cheeky - USB Fidget (Basketball) (vendor 0x1d34, device 0x0002)
libusb: debug [libusb_get_device_list] 
libusb: debug [libusb_get_device_descriptor] 
libusb: debug [libusb_get_device_descriptor] 
libusb: debug [libusb_get_device_descriptor] 
libusb: debug [libusb_get_device_descriptor] 
Attempting to open Dream Cheeky - USB Fidget (Golf) (vendor 0x1d34, device 0x0003)
libusb: debug [libusb_get_device_list] 
libusb: debug [libusb_get_device_descriptor] 
libusb: debug [libusb_get_device_descriptor] 
libusb: debug [libusb_get_device_descriptor] 
libusb: debug [libusb_get_device_descriptor] 
Attempting to open Dream Cheeky - Big Red Button (vendor 0x1d34, device 0x000d)
libusb: debug [libusb_get_device_list] 
libusb: debug [libusb_get_device_descriptor] 
libusb: debug [libusb_get_device_descriptor] 
libusb: debug [libusb_get_device_descriptor] 
libusb: debug [libusb_get_device_descriptor] 
Attempting to open Dream Cheeky - Stress Ball (vendor 0x1d34, device 0x0020)
libusb: debug [libusb_get_device_list] 
libusb: debug [libusb_get_device_descriptor] 
libusb: debug [libusb_get_device_descriptor] 
libusb: debug [libusb_open] open 1.3
libusb: debug [usbi_add_pollfd] add fd 9 events 4
libusb: debug [libusb_kernel_driver_active] interface 0
Kernel driver not active
libusb: debug [libusb_claim_interface] interface 0
Interface claimed
Detecting events
libusb: debug [libusb_alloc_transfer] transfer 0x89f8b48
libusb: debug [libusb_submit_transfer] transfer 0x89f8b48
libusb: debug [add_to_flying_list] arm timerfd for timeout in 200ms (first in line)
libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
libusb: debug [handle_events] poll fds modified, reallocating
libusb: debug [handle_events] poll() 3 fds with timeout in 60000ms
libusb: debug [handle_events] poll() returned 1
libusb: debug [reap_for_handle] urb type=2 status=-32 transferred=8
libusb: debug [handle_control_completion] handling completion status -32
libusb: debug [handle_control_completion] unsupported control request
libusb: debug [disarm_timerfd] 
libusb: debug [usbi_handle_transfer_completion] transfer 0x89f8b48 has callback 0xb778d9c0
libusb: debug [sync_transfer_cb] actual_length=8
libusb: debug [libusb_free_transfer] transfer 0x89f8b48
Error sending report - libusb error -9
Exit code was changed: 1
Closing USB
libusb: debug [libusb_close] 
libusb: debug [usbi_remove_pollfd] remove fd 9

@AstraLuma
Copy link
Author

Huh. LIBUSB_ERROR_PIPE seems to be in the flavor, but it keeps getting weirder. I'm starting to wonder if dream cheeky abused the USB standard in some way that broke over the course of time.

If I change lines 305 and 320, it starts working intermittently, so as well as it did before.

@AstraLuma
Copy link
Author

Hm. Ran a long-running test with ./bonkers -qc echo|pv -lra > /dev/null. It starts at about 13 samples/second, but decreases over time.

Edit: Oh, might be a feature of the device? Using it gets the rate back up.

@fidian
Copy link
Owner

fidian commented Apr 6, 2016

To answer your previous question, the packet size I send (and the size I receive) is 8 bytes, which matches the protocol docs ... well, it matches as much as I understand them.

I use usleep(20000). 20,000 microseconds = 20 ms = 0.02 seconds. It should poll roughly 50 times a second, which might be a little fast but I did want to pick up events that happened for just moments (like the keypresses with the other buttons). This one device did have the slowest response time out of all of the buttons I tried. Maybe I should poll for this one every 0.1 seconds instead? I guess I don't mind gobbling up USB errors and hiding them in exchange for faster response times. If I do change the delay, I would need to base the delay on the device. As it is, I already lose events from other buttons (like the big ! button I have).

Perhaps Dream Cheeky is abusing the USB standard. Perhaps I am. I think I'll ask the developers of libusb to help take a look at this problem. To that end, the following is just a log of what I've done to try to eliminate or find this error.

I've downloaded the libusb from git in my virtual machine and compiled it. Ran LIBUSB_DEBUG=5 LD_LIBRARY_PATH=/root/libusb/libusb/.libs ./bonkers -v to the same effect. I can guarantee the git version is being used (I changed the version number temporarily). -9 is still the result. I've compiled from the v1.0.19 and v1.0.18 tags and those also do not work. I'm starting to suspect it is a kernel issue or else the USB in VirtualBox is broken. My failing VirtualBox is using Linux 4.4.5-1-ARCH. My working Ubuntu kernel is 4.2.0-35-generic.

I tried the rest of the Dream Cheeky buttons I own with the VirtualBox arch linux (different products, none with analog outputs) and they work as expected. I do get the occasional "Error getting interrupt data: -7" but I've experienced that in the past and no amount of slowdown actually eliminates that problem.

After that I tried compiling and using the libusb from git on my main Ubuntu system. It worked! Then I installed Lubuntu in a virtual machine and it failed with -9. I suspect VirtualBox is the source of my errors for -9, but that doesn't give me any clues about why you are getting -8. For the record, the Lubuntu is using libusb 1.0.19.10903 with kernel 4.2.0-16-generic.

I have no other things I can check at this moment so I will be asking for help from the libusb developers mailing list. I hope they can help decide if my code is crap or if there might be an obscure problem that's showing up with either Arch or a newer Linux kernel.

Protocol information: http://files.dreamcheeky.com.s3.amazonaws.com/uploads/dc/808/StresSBall-DeveloperManualv1.0.pdf
Stress ball device information: https://github.com/fidian/bonkers/tree/master/doc/stress-ball

@AstraLuma
Copy link
Author

I suspect the VM's seeing -9 is just VirtualBox reinterpreting USB problems. My suggestion to suss that would be to try different virtualization systems or even containers.

I'm still not sure why Ubuntu and Arch are giving different errors, unless it's a recent change in the kernel.

I also wonder if something in the stack/chain is reporting an underflow as an overflow.

@fidian
Copy link
Owner

fidian commented Apr 8, 2016

The libusb developers have responded a bit:

Alan:

You can find out what the kernel thinks is happening by using usbmon.
See the instructions in Documentation/usb/usbmon.txt in the kernel
source.

Tim then quoted the bit about me having issues with VirtualBox and asked ...

Can you post the descriptors for this device? The lsusb shows that this
is a low-speed device, but the logs describe making a bulk request.
Low-speed devices cannot have bulk endpoints. Now, bulk and interrupt
transfers look a lot alike, so it may actually be an interrupt endpoint,
which is allowed.

@astronouth7303, feel like digging into usbmon a bit? I'll try hard to find some time this weekend to do the same. I also might steal my wife's laptop to install Arch just so I can reproduce this problem.

@vpelletier
Copy link

Quick intro to usbmon the wireshark way:
As root, do:

# on my system, it is root:root 600 by default.
echo 'SUBSYSTEM=="usbmon", GROUP="wireshark", MODE="0640"' > /etc/udev/rules/wireshark-usbmon.rules
modprobe usbmon
# or "udevadm trigger -s usbmon" if module was already loaded

Then, as a regular user member of the wireshark group, run wireshark and select the appropriate bus (from lsusb -t output above, that would be usbmon2).

@AstraLuma
Copy link
Author

I'm going to start digging into this, but here's the wireshark file:
wireshark.zip

Should be able to extract, open in wireshark, and get results.

@AstraLuma
Copy link
Author

@fidian I still think that the different errors represent the same base problem, and that Arch and Ubuntu aren't handling it fundamentally differently. They're just exposing it with more detail. But please prove me wrong!

@fidian
Copy link
Owner

fidian commented Apr 11, 2016

I also captured pcap files for both the host Ubuntu system and guest Arch machine. They're in tshark.zip. I decided to sudo instead of modifying udev rules, so I hope @vpelletier doesn't mind and I also hope that this still produces the results that were desired. Very brief:

sudo modprobe -v usbmon
sudo tshark -D # find the usbmon devices
sudo tshark -i usbmon1 -i usbmon2 -i usbmon3 -w usbmon.pcap

@vpelletier
Copy link

@fidian: I don't mind, but I did not intend to analyse the content of the dump either :) . I came here from the bug report @astronouth7303 filled about my python libusb wrapper module, so i'm a tourist/spectator here.

AFAIK wireshark produces pcap files too, so it should actually be just the same format (it uses pcap's ability to interface with usbmon, after all).

Also, yes, I do not know how safe it is to grant a regular user read access to low-level usb buses (it certainly allows keylogging for example). My overall train of thought about this setup is (and the last point is very important for security):

  • I prefer to use wireshark over cat /sys/debug/usbmon/... (as in kernel docs) for the eye-candy dissecting and for the ability to restart & live-monitor capture easily (avoiding stuff like tcpdump [...] | tee [...] save_file | wiresark [...] or mkfifo the_fifo; tcpdump [...] | tee [...] save_file > the_fifo and wireshark [...] the_fifo with options I always forget)
  • I do not want to run wireshark (or any gui) as root
  • I do not want to have to remember what devices should have which permissions
  • I can rmmod usbmon when I'm done to easily revoke my own access

@fidian
Copy link
Owner

fidian commented Apr 13, 2016

@vpelletier Don't worry - I wasn't intending to have you inspect the USB traffic. Instead, I was merely calling out that I didn't follow your instructions. I do love your last comment - very thorough. :-) Anyway, my zip file was mostly for the libusb developers mailing list so they could help inspect my traffic. And, for reference (mostly by myself or maybe astronouth7303) here is their analysis of my zip. It gives me a place to start looking and a direction to take when looking at the other zip that contained astronouth7303's USB packets.

This is a confusing bug report. You're talking about two different
people using at least three different environments and getting
different sets of errors.

I looked at the tshark.zip file attached to issues/4 in the GitHub
fidian/bonkers project. It basically shows two errors:

    An EPIPE error that showed up when the computer sent a
    Get-Report request for input report 0 to the device.
    Apparently the Stress Ball doesn't support this request.  This
    appeared in both the host and guest logs.

    An EPROTO error that showed up when the computer sent a
    Set-Report request for output request 0.  It looks like the
    VM translated this error code to EPIPE when sending it through
    to the guest.

There were no EOVERFLOW errors.

It's entirely possible that the device would have handled the
Set-Report request correctly if it had not gotten confused by the
earlier Get-Report request.

It's worth noting that the kernel's HID driver contains blacklist
entries for the Dream Cheeky devices with product IDs 0x0004 and
0x000a, but not for product ID 0x0020 (the Stress Ball). Adding such a
blacklist entry might help solve the problem.

I have no idea why things should behave differently on systems with a
different Linux distribution installed. Maybe if someone provided a
usbmon trace from one of those other systems I could tell.

Before I follow up on the mailing list I will need to inspect my code again, test this more on my computer, capture the "working" packet dump, and compare versus the broken packet dumps. Probably won't get solved this week - that's a lot of stuff to do and, like everyone I know, my idle time at home is limited.

@baelish
Copy link

baelish commented Oct 24, 2016

Hello, Fidian asked me to check the stress ball device on my Arch linux installation:

It appears to work fine if I plug the device in through a double usb hubs (one powered) as my keyboard is plugged into my monitor and my monitor into my laptop. However when plugging in directly it appears to crash within seconds.

It seems to me the failures I experience are to do with the stressball hardware not being particularly reliable.

Some details:

Tyrion$>date
Mon 24 Oct 18:20:18 BST 2016

/mnt/infodb/dev/bonkers master
Tyrion$>sudo pacman -Syu
:: Synchronising package databases...
 core is up to date
 extra is up to date
 community is up to date
:: Starting full system upgrade...
 there is nothing to do

/mnt/infodb/dev/bonkers master
Tyrion$>uname -a
Linux Tyrion 4.8.4-1-macbook #1 SMP PREEMPT Sun Oct 23 18:12:03 BST 2016 x86_64 GNU/Linux

/mnt/infodb/dev/bonkers master
Tyrion$>ldd bonkers
        linux-vdso.so.1 (0x00007ffed3397000)
        libusb-1.0.so.0 => /usr/lib/libusb-1.0.so.0 (0x00007f6636d69000)
        libc.so.6 => /usr/lib/libc.so.6 (0x00007f66369cb000)
        libudev.so.1 => /usr/lib/libudev.so.1 (0x00007f663714c000)
        libpthread.so.0 => /usr/lib/libpthread.so.0 (0x00007f66367ae000)
        /lib64/ld-linux-x86-64.so.2 (0x00007f6636f82000)
        libresolv.so.2 => /usr/lib/libresolv.so.2 (0x00007f6636597000)
        libcap.so.2 => /usr/lib/libcap.so.2 (0x00007f6636393000)
        librt.so.1 => /usr/lib/librt.so.1 (0x00007f663618b000)
        libm.so.6 => /usr/lib/libm.so.6 (0x00007f6635e87000)

/mnt/infodb/dev/bonkers master
Tyrion$>lsusb -v -s 001:066

Bus 001 Device 066: ID 1d34:0020 Dream Cheeky 
Device Descriptor:
  bLength                18
  bDescriptorType         1
  bcdUSB               1.10
  bDeviceClass            0 
  bDeviceSubClass         0 
  bDeviceProtocol         0 
  bMaxPacketSize0         8
  idVendor           0x1d34 Dream Cheeky
  idProduct          0x0020 
  bcdDevice            0.01
  iManufacturer           1 Dream Link
  iProduct                2 DL120A Dream Cheeky Generic Controller
  iSerial                 3 0x01
  bNumConfigurations      1
  Configuration Descriptor:
    bLength                 9
    bDescriptorType         2
    wTotalLength           34
    bNumInterfaces          1
    bConfigurationValue     1
    iConfiguration          0 
    bmAttributes         0x80
      (Bus Powered)
    MaxPower               72mA
    Interface Descriptor:
      bLength                 9
      bDescriptorType         4
      bInterfaceNumber        0
      bAlternateSetting       0
      bNumEndpoints           1
      bInterfaceClass         3 Human Interface Device
      bInterfaceSubClass      0 
      bInterfaceProtocol      0 
      iInterface              0 
        HID Device Descriptor:
          bLength                 9
          bDescriptorType        33
          bcdHID               1.00
          bCountryCode            0 Not supported
          bNumDescriptors         1
          bDescriptorType        34 Report
          wDescriptorLength      48
          Report Descriptor: (length is 48)
            Item(Global): Usage Page, data= [ 0xa0 0xff ] 65440
                            (null)
            Item(Local ): Usage, data= [ 0x01 ] 1
                            (null)
            Item(Main  ): Collection, data= [ 0x01 ] 1
                            Application
            Item(Local ): Usage, data= [ 0x02 ] 2
                            (null)
            Item(Main  ): Collection, data= [ 0x00 ] 0
                            Physical
            Item(Global): Usage Page, data= [ 0xa1 0xff ] 65441
                            (null)
            Item(Local ): Usage, data= [ 0x01 ] 1
                            (null)
            Item(Global): Logical Minimum, data= [ 0x80 ] 128
            Item(Global): Logical Maximum, data= [ 0x7f ] 127
            Item(Global): Physical Minimum, data= [ 0x00 ] 0
            Item(Global): Physical Maximum, data= [ 0xff ] 255
            Item(Global): Report Size, data= [ 0x08 ] 8
            Item(Global): Report Count, data= [ 0x08 ] 8
            Item(Main  ): Input, data= [ 0x02 ] 2
                            Data Variable Absolute No_Wrap Linear
                            Preferred_State No_Null_Position Non_Volatile Bitfield
            Item(Local ): Usage, data= [ 0x11 ] 17
                            (null)
            Item(Global): Logical Minimum, data= [ 0x80 ] 128
            Item(Global): Logical Maximum, data= [ 0x7f ] 127
            Item(Global): Physical Minimum, data= [ 0x00 ] 0
            Item(Global): Physical Maximum, data= [ 0xff ] 255
            Item(Global): Report Size, data= [ 0x08 ] 8
            Item(Global): Report Count, data= [ 0x08 ] 8
            Item(Main  ): Output, data= [ 0x02 ] 2
                            Data Variable Absolute No_Wrap Linear
                            Preferred_State No_Null_Position Non_Volatile Bitfield
            Item(Main  ): End Collection, data=none
            Item(Main  ): End Collection, data=none
      Endpoint Descriptor:
        bLength                 7
        bDescriptorType         5
        bEndpointAddress     0x81  EP 1 IN
        bmAttributes            3
          Transfer Type            Interrupt
          Synch Type               None
          Usage Type               Data
        wMaxPacketSize     0x0008  1x 8 bytes
        bInterval               4
can't get debug descriptor: Resource temporarily unavailable
Device Status:     0x0000
  (Bus Powered)

/mnt/infodb/dev/bonkers master
Tyrion$>

Output of failures directly connected to laptop.

Error sending report - libusb error -1
Error sending report - libusb error -1
Error sending report - libusb error -1
Error sending report - libusb error -1
Error sending report - libusb error -1
Error sending report - libusb error -1
Error sending report - libusb error -1
Error sending report - libusb error -1
Error sending report - libusb error -1
Error sending report - libusb error -1
Error sending report - libusb error -1
Error sending report - libusb error -1
State switched from '112 144 186' to '111 144 186'
Error sending report - libusb error -1
Error sending report - libusb error -1
State switched from '111 144 186' to '112 144 186'
Error sending report - libusb error -1
Error sending report - libusb error -1
Error sending report - libusb error -1
Error sending report - libusb error -1
State switched from '112 144 186' to '113 144 186'
Error sending report - libusb error -1
Error sending report - libusb error -1
State switched from '113 144 186' to '112 144 186'
Error sending report - libusb error -1
Error sending report - libusb error -1
State switched from '112 144 186' to '111 146 186'
Error sending report - libusb error -1
Error sending report - libusb error -1
State switched from '111 146 186' to '113 147 187'
Error sending report - libusb error -1
Error getting interrupt data: -4
Exit code was changed: 1
Closing USB

/mnt/infodb/dev/bonkers master
Tyrion$>

Output of failure when connected through monitor and keyboard usb hubs. The failures occurs when I give shake the stressball if I leave it lying on the table undisturbed it seems to run fine for extended periods.

Error sending report - libusb error -1
Error sending report - libusb error -1
State switched from '109 141 186' to '108 141 186'
Error sending report - libusb error -1
Error sending report - libusb error -1
Error sending report - libusb error -1
Error sending report - libusb error -1
State switched from '108 141 186' to '109 140 186'
Error sending report - libusb error -1
Error sending report - libusb error -1
State switched from '109 140 186' to '108 140 186'
Error sending report - libusb error -1
Error sending report - libusb error -1
Error sending report - libusb error -1
Error sending report - libusb error -1
State switched from '108 140 186' to '108 141 186'
Error sending report - libusb error -1
Error sending report - libusb error -1
State switched from '108 141 186' to '109 141 186'
Error sending report - libusb error -1
Error sending report - libusb error -1
State switched from '109 141 186' to '109 137 185'
Error sending report - libusb error -9
Exit code was changed: 1
Closing USB

/mnt/infodb/dev/bonkers master
Tyrion$>

@fidian
Copy link
Owner

fidian commented Nov 15, 2016

I can not replicate the issue with my device. As you can see, when it is shaken it must short out or something. For your issue I suspect your hardware is also a little crazy (like mine) or there's something unique to your setup. Closing this issue.

@fidian fidian closed this as completed Nov 15, 2016
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

4 participants