[Bug 261989] USB Joystick disconnects every three seconds

https://bugs.freebsd.org/bugzilla/show_bug.cgi?id=261989

            Bug ID: 261989
           Summary: USB Joystick disconnects every three seconds
           Product: Base System
           Version: 12.2-RELEASE
          Hardware: amd64
                OS: Any
            Status: New
          Severity: Affects Only Me
          Priority: ---
         Component: usb
          Assignee: usb@FreeBSD.org
          Reporter: janm@transactionware.com

Created attachment 231868
  --> https://bugs.freebsd.org/bugzilla/attachment.cgi?id=231868&action=edit
usbdump file capturing the USB traffic during the failure.

When attaching an APEM VM Desktop joystick,
https://www.apem.com/int/vm-desktop-93.html, to a 12.2 system, the device
disconnects every three seconds, and then reconnects.

The first time it connects, usb_needs_explore() is called which then gets a
port status from the hub for the port the device is connected to. This
succeeds. The next call to usb_needs_explore(), three seconds later, gets a
port status from the hub for that port, which reports the port change bit set.
The device is then detached, and then immediately detected for the cycle to
repeat.

This mailing list post from 2016 describes a nearly identical issue with a USB
UPS: https://lists.freebsd.org/pipermail/freebsd-usb/2016-November/014542.html

In this trace, quirks have been set up so that device is not detected as a
mouse or a keyboard, but is left as a plain HID device.


Feb 17 03:12:01 test-tipro kernel: uhub_read_port_status: port 2,
wPortStatus=0x0101, wPortChange=0x0001, err=USB_ERR_NORMAL_COMPLETION
Feb 17 03:12:01 test-tipro kernel: uhub_reattach_port: reattaching port 2
Feb 17 03:12:01 test-tipro kernel: ugen0.11: <CH Products VM Desktop> at usbus0
(disconnected)
Feb 17 03:12:01 test-tipro kernel: uhid4: at uhub3, port 2, addr 26
(disconnected)
Feb 17 03:12:01 test-tipro kernel: usb_fifo_detach: detached 0xfffff8001cdccc80
Feb 17 03:12:01 test-tipro kernel: uhub_child_location_string: device not on
hub
Feb 17 03:12:01 test-tipro kernel: uhub_child_pnpinfo_string: device not on hub
Feb 17 03:12:01 test-tipro kernel: uhid4: detached
Feb 17 03:12:01 test-tipro kernel: uhid5: at uhub3, port 2, addr 26
(disconnected)
Feb 17 03:12:01 test-tipro kernel: usb_fifo_detach: detached 0xfffff8001cdccd00
Feb 17 03:12:01 test-tipro kernel: uhub_child_location_string: device not on
hub
Feb 17 03:12:01 test-tipro kernel: uhub_child_pnpinfo_string: device not on hub
Feb 17 03:12:01 test-tipro kernel: uhid5: detached
Feb 17 03:12:01 test-tipro kernel: uhid6: at uhub3, port 2, addr 26
(disconnected)
Feb 17 03:12:01 test-tipro kernel: usb_fifo_detach: detached 0xfffff8001cdccd80
Feb 17 03:12:01 test-tipro kernel: uhub_child_location_string: device not on
hub
Feb 17 03:12:01 test-tipro kernel: uhub_child_pnpinfo_string: device not on hub
Feb 17 03:12:01 test-tipro kernel: uhid6: detached
Feb 17 03:12:01 test-tipro kernel: usb_bus_port_set_device: bus
0xfffffe002b984428 devices[11] = 0
Feb 17 03:12:01 test-tipro kernel: uhub_read_port_status: port 2,
wPortStatus=0x0101, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION
Feb 17 03:12:01 test-tipro kernel: uhub_reattach_port: Port 2 is in Host Mode
Feb 17 03:12:02 test-tipro kernel: uhub_intr_callback:
Feb 17 03:12:02 test-tipro kernel: usb_needs_explore:
Feb 17 03:12:02 test-tipro kernel: uhub_read_port_status: port 2,
wPortStatus=0x0103, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION
Feb 17 03:12:02 test-tipro kernel: usb_bus_port_set_device: bus
0xfffffe002b984428 devices[11] = 0xfffff8001c2d1000
Feb 17 03:12:02 test-tipro kernel: ugen0.11: <CH Products VM Desktop> at usbus0
Feb 17 03:12:02 test-tipro kernel: uhid4 on uhub3
Feb 17 03:12:02 test-tipro kernel: uhid4: <VM Joystick Interface> on usbus0
Feb 17 03:12:02 test-tipro kernel: usb_fifo_attach: attached
0xfffff80089718c00/0xfffff80014f1ec00
Feb 17 03:12:02 test-tipro kernel: uhid5 on uhub3
Feb 17 03:12:02 test-tipro kernel: uhid5: <VM Keyboard Interface> on usbus0
Feb 17 03:12:02 test-tipro kernel: usb_fifo_attach: attached
0xfffff8001c13a200/0xfffff80089718e00
Feb 17 03:12:02 test-tipro kernel: uhid6 on uhub3
Feb 17 03:12:02 test-tipro kernel: uhid6: <VM Mouse Interface> on usbus0
Feb 17 03:12:02 test-tipro kernel: usb_fifo_attach: attached
0xfffff8001c1fc600/0xfffff80089a36800
Feb 17 03:12:02 test-tipro kernel: uhub_read_port_status: port 3,
wPortStatus=0x0100, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION
Feb 17 03:12:02 test-tipro kernel: uhub_read_port_status: port 4,
wPortStatus=0x0303, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION
Feb 17 03:12:02 test-tipro kernel: uhub_read_port_status: port 5,
wPortStatus=0x0100, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION
Feb 17 03:12:02 test-tipro kernel: uhub_read_port_status: port 6,
wPortStatus=0x0100, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION
Feb 17 03:12:02 test-tipro kernel: uhub_read_port_status: port 7,
wPortStatus=0x0100, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION
Feb 17 03:12:02 test-tipro kernel: uhub_read_port_status: port 4,
wPortStatus=0x0100, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION
Feb 17 03:12:02 test-tipro kernel: uhub_read_port_status: port 5,
wPortStatus=0x06a0, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION
Feb 17 03:12:02 test-tipro kernel: uhub_read_port_status: port 6,
wPortStatus=0x06a0, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION
Feb 17 03:12:02 test-tipro kernel: uhub_read_port_status: port 7,
wPortStatus=0x06a0, wPortChange=0x0020, err=USB_ERR_NORMAL_COMPLETION
Feb 17 03:12:02 test-tipro kernel: usb_bus_powerd: bus=0xfffffe002b984428
Feb 17 03:12:02 test-tipro kernel: uhub_read_port_status: port 1,
wPortStatus=0x06a0, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION
Feb 17 03:12:02 test-tipro kernel: uhub_read_port_status: port 2,
wPortStatus=0x06a0, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION
Feb 17 03:12:02 test-tipro kernel: uhub_read_port_status: port 3,
wPortStatus=0x06a0, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION
Feb 17 03:12:02 test-tipro kernel: uhub_read_port_status: port 4,
wPortStatus=0x0403, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION
Feb 17 03:12:02 test-tipro kernel: uhub_read_port_status: port 1,
wPortStatus=0x0100, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION
Feb 17 03:12:02 test-tipro kernel: uhub_read_port_status: port 2,
wPortStatus=0x0103, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION
Feb 17 03:12:02 test-tipro kernel: uhub_read_port_status: port 1,
wPortStatus=0x0103, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION
Feb 17 03:12:02 test-tipro kernel: uhub_read_port_status: port 2,
wPortStatus=0x0103, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION
Feb 17 03:12:02 test-tipro kernel: uhub_read_port_status: port 3,
wPortStatus=0x0103, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION
Feb 17 03:12:02 test-tipro kernel: uhub_read_port_status: port 4,
wPortStatus=0x0103, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION
Feb 17 03:12:02 test-tipro kernel: uhub_read_port_status: port 5,
wPortStatus=0x0103, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION
Feb 17 03:12:02 test-tipro kernel: uhub_read_port_status: port 6,
wPortStatus=0x0100, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION
Feb 17 03:12:02 test-tipro kernel: uhub_read_port_status: port 7,
wPortStatus=0x0100, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION
Feb 17 03:12:02 test-tipro kernel: uhub_read_port_status: port 3,
wPortStatus=0x0103, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION
Feb 17 03:12:02 test-tipro kernel: uhub_read_port_status: port 1,
wPortStatus=0x0100, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION
Feb 17 03:12:02 test-tipro kernel: uhub_read_port_status: port 2,
wPortStatus=0x0103, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION
Feb 17 03:12:02 test-tipro kernel: uhub_read_port_status: port 3,
wPortStatus=0x0100, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION
Feb 17 03:12:02 test-tipro kernel: uhub_read_port_status: port 4,
wPortStatus=0x0303, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION
Feb 17 03:12:02 test-tipro kernel: uhub_read_port_status: port 5,
wPortStatus=0x0100, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION
Feb 17 03:12:02 test-tipro kernel: uhub_read_port_status: port 6,
wPortStatus=0x0100, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION
Feb 17 03:12:02 test-tipro kernel: uhub_read_port_status: port 7,
wPortStatus=0x0100, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION
Feb 17 03:12:02 test-tipro kernel: uhub_read_port_status: port 4,
wPortStatus=0x0100, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION
Feb 17 03:12:02 test-tipro kernel: uhub_read_port_status: port 5,
wPortStatus=0x06a0, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION
Feb 17 03:12:02 test-tipro kernel: uhub_read_port_status: port 6,
wPortStatus=0x06a0, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION
Feb 17 03:12:02 test-tipro kernel: uhub_read_port_status: port 7,
wPortStatus=0x06a0, wPortChange=0x0020, err=USB_ERR_NORMAL_COMPLETION
Feb 17 03:12:02 test-tipro kernel: usb_needs_explore:
Feb 17 03:12:02 test-tipro kernel: usb_bus_powerd: bus=0xfffffe002b984428
Feb 17 03:12:02 test-tipro kernel: uhub_read_port_status: port 1,
wPortStatus=0x06a0, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION
Feb 17 03:12:02 test-tipro kernel: uhub_read_port_status: port 2,
wPortStatus=0x06a0, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION
Feb 17 03:12:02 test-tipro kernel: uhub_read_port_status: port 3,
wPortStatus=0x06a0, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION
Feb 17 03:12:02 test-tipro kernel: uhub_read_port_status: port 4,
wPortStatus=0x0403, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION
Feb 17 03:12:02 test-tipro kernel: uhub_read_port_status: port 1,
wPortStatus=0x0100, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION
Feb 17 03:12:02 test-tipro kernel: uhub_read_port_status: port 2,
wPortStatus=0x0103, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION
Feb 17 03:12:02 test-tipro kernel: uhub_read_port_status: port 1,
wPortStatus=0x0103, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION
Feb 17 03:12:02 test-tipro kernel: uhub_read_port_status: port 2,
wPortStatus=0x0103, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION
Feb 17 03:12:02 test-tipro kernel: uhub_read_port_status: port 3,
wPortStatus=0x0103, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION
Feb 17 03:12:02 test-tipro kernel: uhub_read_port_status: port 4,
wPortStatus=0x0103, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION
Feb 17 03:12:02 test-tipro kernel: uhub_read_port_status: port 5,
wPortStatus=0x0103, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION
Feb 17 03:12:02 test-tipro kernel: uhub_read_port_status: port 6,
wPortStatus=0x0100, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION
Feb 17 03:12:02 test-tipro kernel: uhub_read_port_status: port 7,
wPortStatus=0x0100, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION
Feb 17 03:12:02 test-tipro kernel: uhub_read_port_status: port 3,
wPortStatus=0x0103, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION
Feb 17 03:12:02 test-tipro kernel: uhub_read_port_status: port 1,
wPortStatus=0x0100, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION
Feb 17 03:12:02 test-tipro kernel: uhub_read_port_status: port 2,
wPortStatus=0x0103, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION
Feb 17 03:12:02 test-tipro kernel: uhub_read_port_status: port 3,
wPortStatus=0x0100, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION
Feb 17 03:12:02 test-tipro kernel: uhub_read_port_status: port 4,
wPortStatus=0x0303, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION
Feb 17 03:12:02 test-tipro kernel: uhub_read_port_status: port 5,
wPortStatus=0x0100, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION
Feb 17 03:12:02 test-tipro kernel: uhub_read_port_status: port 6,
wPortStatus=0x0100, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION
Feb 17 03:12:02 test-tipro kernel: uhub_read_port_status: port 7,
wPortStatus=0x0100, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION
Feb 17 03:12:02 test-tipro kernel: uhub_read_port_status: port 4,
wPortStatus=0x0100, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION
Feb 17 03:12:02 test-tipro kernel: uhub_read_port_status: port 5,
wPortStatus=0x06a0, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION
Feb 17 03:12:02 test-tipro kernel: uhub_read_port_status: port 6,
wPortStatus=0x06a0, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION
Feb 17 03:12:02 test-tipro kernel: uhub_read_port_status: port 7,
wPortStatus=0x06a0, wPortChange=0x0020, err=USB_ERR_NORMAL_COMPLETION
Feb 17 03:12:04 test-tipro kernel: uhub_intr_callback:
Feb 17 03:12:04 test-tipro kernel: usb_needs_explore:
Feb 17 03:12:04 test-tipro kernel: usb_bus_powerd: bus=0xfffffe002b984428
Feb 17 03:12:04 test-tipro kernel: uhub_read_port_status: port 1,
wPortStatus=0x06a0, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION
Feb 17 03:12:04 test-tipro kernel: uhub_read_port_status: port 2,
wPortStatus=0x06a0, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION
Feb 17 03:12:04 test-tipro kernel: uhub_read_port_status: port 3,
wPortStatus=0x06a0, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION
Feb 17 03:12:04 test-tipro kernel: uhub_read_port_status: port 4,
wPortStatus=0x0403, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION
Feb 17 03:12:04 test-tipro kernel: uhub_read_port_status: port 1,
wPortStatus=0x0100, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION
Feb 17 03:12:04 test-tipro kernel: uhub_read_port_status: port 2,
wPortStatus=0x0103, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION
Feb 17 03:12:04 test-tipro kernel: uhub_read_port_status: port 1,
wPortStatus=0x0103, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION
Feb 17 03:12:04 test-tipro kernel: uhub_read_port_status: port 2,
wPortStatus=0x0103, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION
Feb 17 03:12:04 test-tipro kernel: uhub_read_port_status: port 3,
wPortStatus=0x0103, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION
Feb 17 03:12:04 test-tipro kernel: uhub_read_port_status: port 4,
wPortStatus=0x0103, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION
Feb 17 03:12:04 test-tipro kernel: uhub_read_port_status: port 5,
wPortStatus=0x0103, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION
Feb 17 03:12:04 test-tipro kernel: uhub_read_port_status: port 6,
wPortStatus=0x0100, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION
Feb 17 03:12:04 test-tipro kernel: uhub_read_port_status: port 7,
wPortStatus=0x0100, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION
Feb 17 03:12:04 test-tipro kernel: uhub_read_port_status: port 3,
wPortStatus=0x0103, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION
Feb 17 03:12:04 test-tipro kernel: uhub_read_port_status: port 1,
wPortStatus=0x0100, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION
Feb 17 03:12:04 test-tipro kernel: uhub_read_port_status: port 2,
wPortStatus=0x0100, wPortChange=0x0001, err=USB_ERR_NORMAL_COMPLETION
Feb 17 03:12:04 test-tipro kernel: uhub_reattach_port: reattaching port 2
Feb 17 03:12:04 test-tipro kernel: ugen0.11: <CH Products VM Desktop> at usbus0
(disconnected)
Feb 17 03:12:04 test-tipro kernel: uhid4: at uhub3, port 2, addr 27
(disconnected)
Feb 17 03:12:04 test-tipro kernel: usb_fifo_detach: detached 0xfffff8001cdccc80
Feb 17 03:12:04 test-tipro kernel: uhub_child_location_string: device not on
hub
Feb 17 03:12:04 test-tipro kernel: uhub_child_pnpinfo_string: device not on hub
Feb 17 03:12:04 test-tipro kernel: uhid4: detached
Feb 17 03:12:04 test-tipro kernel: uhid5: at uhub3, port 2, addr 27
(disconnected)
Feb 17 03:12:04 test-tipro kernel: usb_fifo_detach: detached 0xfffff8001cdccd00
Feb 17 03:12:04 test-tipro kernel: uhub_child_location_string: device not on
hub
Feb 17 03:12:04 test-tipro kernel: uhub_child_pnpinfo_string: device not on hub
Feb 17 03:12:04 test-tipro kernel: uhid5: detached
Feb 17 03:12:04 test-tipro kernel: uhid6: at uhub3, port 2, addr 27
(disconnected)
Feb 17 03:12:04 test-tipro kernel: usb_fifo_detach: detached 0xfffff8001cdccd80
Feb 17 03:12:04 test-tipro kernel: uhub_child_location_string: device not on
hub
Feb 17 03:12:04 test-tipro kernel: uhub_child_pnpinfo_string: device not on hub
Feb 17 03:12:04 test-tipro kernel: uhid6: detached

-- 
You are receiving this mail because:
You are the assignee for the bug.