search

dctucker / USBHost_t41

USB Host Library for Teensy 3.6 and 4.0
1 stars 0 forks source link

Korg Opsix reconnect causes EHCI halt #1

Open dctucker opened 3 years ago

dctucker commented 3 years ago

Problem

Currently, when disconnecting and then reconnecting the Korg Opsix, the EHCI Host will stop responding to new connections indefinitely, reporting "dummy halt".

I have verified that this does not occur with the Korg Electribe Sampler, Roland JUNO-DS88, or Novation Circuit. I've also verified that the Opsix works normally under Windows, and since the Opsix has its own DC power supply (as does the USB hub) I'm less suspicious of it being a power draw issue.

Steps to reproduce:

The InputFunctions example is a good place to start, but use MIDIDriver_BigBuffer, since Opsix uses a buffer size of 512 and MIDIDriver will refuse to assign a callback for buffers larger than 64.

It seems isolated to when power is cycled, and independent of connecting/disconnecting with the Opsix powered on.

Output

If USBHOST_PRINT_DEBUG is defined, the following will be output from the serial port:

HUB Callback (member)
status = 4
getstatus, port = 2
USBHub control callback
01 01 01 00 
New Port Status
  status=10101  port=2
  state=1
  Device is present: 
  Has Power
USBHub control callback
Port Status Cleared, port=2
timer event (20000 us): Debounce Timer, this = 2000A9A0, timer = 2000ACB8
ports in use bitmask = 4
getstatus, port = 2
USBHub control callback
01 01 00 00 
New Port Status
  status=101  port=2
  state=2
  Device is present: 
  Has Power
HUB Callback (member)
status = 4
getstatus, port = 2
USBHub control callback
00 01 01 00 
New Port Status
  status=10100  port=2
  state=3
  Has Power
timer event (19999 us): Debounce Timer, this = 2000A9A0, timer = 2000ACB8
ports in use bitmask = 0
HUB Callback (member)
status = 4
getstatus, port = 2
USBHub control callback
00 01 01 00 
New Port Status
  status=10100  port=2
  state=1
  Has Power
HUB Callback (member)
status = 4
getstatus, port = 2
USBHub control callback
01 01 01 00 
New Port Status
  status=10101  port=2
  state=1
  Device is present: 
  Has Power
USBHub control callback
Port Status Cleared, port=2
timer event (20000 us): Debounce Timer, this = 2000A9A0, timer = 2000ACB8
ports in use bitmask = 4
getstatus, port = 2
USBHub control callback
01 01 00 00 
New Port Status
  status=101  port=2
  state=2
  Device is present: 
  Has Power
timer event (19999 us): Debounce Timer, this = 2000A9A0, timer = 2000ACB8
ports in use bitmask = 4
getstatus, port = 2
USBHub control callback
01 01 00 00 
New Port Status
  status=101  port=2
  state=3
  Device is present: 
  Has Power
timer event (19999 us): Debounce Timer, this = 2000A9A0, timer = 2000ACB8
ports in use bitmask = 4
getstatus, port = 2
USBHub control callback
01 01 00 00 
New Port Status
  status=101  port=2
  state=4
  Device is present: 
  Has Power
timer event (19999 us): Debounce Timer, this = 2000A9A0, timer = 2000ACB8
ports in use bitmask = 4
getstatus, port = 2
USBHub control callback
01 01 00 00 
New Port Status
  status=101  port=2
  state=5
  Device is present: 
  Has Power
timer event (19999 us): Debounce Timer, this = 2000A9A0, timer = 2000ACB8
ports in use bitmask = 4
getstatus, port = 2
USBHub control callback
01 01 00 00 
New Port Status
  status=101  port=2
  state=6
  Device is present: 
  Has Power
sending reset
send_setreset
USBHub control callback
unhandled setup, message = 40323
timer event (19999 us): Debounce Timer, this = 2000A9A0, timer = 2000ACB8
ports in use bitmask = 0
HUB Callback (member)
status = 4
getstatus, port = 2
USBHub control callback
03 01 10 00 
New Port Status
  status=100103  port=2
  state=7
  Device is present: 
  Enabled, speed = 12 Mbit/sec
  Has Power
USBHub control callback
unhandled setup, message = 140123
timer event (25000 us): Hello, I'm resettimer, this = 2000A9A0, timer = 2000ACD8
port_doing_reset = 2
PORT_RECOVERY
new_Device: 12 Mbit/sec
new_Pipe
ERROR Followup
    remain on followup list
    remove from followup list
    remove from followup list
  dummy halt: 20009A60
    remain on followup list
dctucker commented 3 years ago

Update

When plugging the Opsix directly into the Teensy's USB host port it can power on without causing a halt. When going through a USB hub. This was tested on two different hubs:

  1. The first is a RadioShack Ultra Compact 4-port USB 2.0 hub that can operate with or without power. Power was applied via a 2.1A USB port on a power strip via the supplied two-connector (USB-A) connector.
    • The halt occurs whether or not power is applied to the hub.
  2. The second is a UUGear 7-port hub for Raspberry Pi.
    • This hub requires power and will not connect any device until power is supplied to it.
    • Cycling the power on the hub disconnects and reconnects all devices.
    • Cycling the power on the Opsix (as with the previous hub) causes halt.

Here are some logs to compare (the 7-port hub was used). One noteworthy difference is the speed being the expected 480 Mbit/sec, versus being 12 Mbit/sec in the case of failure with halt.

Opsix then Teensy (works as expected)

``` port change: 14001403 connect port change: 1C001002 disconnect port change: 10001803 connect begin reset port change: 18001205 port enabled end recovery new_Device: 480 Mbit/sec new_Pipe enumeration: enumeration: enumeration: Device Descriptor: 12 01 00 02 09 00 02 40 40 1A 01 02 00 01 00 01 00 01 VendorID = 1A40, ProductID = 0201, Version = 0100 Class/Subclass/Protocol = 9(Hub) / 0 / 2(Multi-TT) Number of Configurations = 1 enumeration: enumeration: Product: USB 2.0 Hub [MTT] enumeration: Config data length = 41 enumeration: Configuration Descriptor: 09 02 29 00 01 01 00 E0 32 NumInterfaces = 1 ConfigurationValue = 1 09 04 00 00 01 09 00 01 00 Interface = 0 Number of endpoints = 1 Class/Subclass/Protocol = 9(Hub) / 0 / 1(Single-TT) 07 05 81 03 01 00 0C Endpoint = 1 IN Type = Interrupt Max Size = 1 Polling Interval = 12 09 04 00 01 01 09 00 02 00 Interface = 0 Number of endpoints = 1 Class/Subclass/Protocol = 9(Hub) / 0 / 2(Multi-TT) 07 05 81 03 01 00 0C Endpoint = 1 IN Type = Interrupt Max Size = 1 Polling Interval = 12 enumeration: USBHub memory usage = 960 USBHub claim_device this=2000A9C0 found possible interface, altsetting=0 found possible interface, altsetting=1 number of interfaces found = 2 best interface is 0 using altsetting 1 USBHub control callback 09 29 07 88 00 32 64 00 FF 00 00 00 00 00 00 00 Hub ports = 7 USBHub control callback unhandled setup, message = 10B01 USBHub control callback USBHub control callback USBHub control callback USBHub control callback USBHub control callback USBHub control callback USBHub control callback power turned on to all ports device addr = 7 new_Pipe allocate_interrupt_pipe_bandwidth ep interval = 12 interval = 256 best_bandwidth = 2, at offset = 0 pipe cap1 = F0012107 HUB Callback (member) status = 10 getstatus, port = 4 USBHub control callback 01 01 01 00 New Port Status status=10101 port=4 state=0 Device is present: Has Power USBHub control callback Port Status Cleared, port=4 timer event (20000 us): Debounce Timer, this = 2000A9C0, timer = 2000ACD8 ports in use bitmask = 10 getstatus, port = 4 USBHub control callback 01 01 00 00 New Port Status status=101 port=4 state=2 Device is present: Has Power timer event (19999 us): Debounce Timer, this = 2000A9C0, timer = 2000ACD8 ports in use bitmask = 10 getstatus, port = 4 USBHub control callback 01 01 00 00 New Port Status status=101 port=4 state=3 Device is present: Has Power timer event (19999 us): Debounce Timer, this = 2000A9C0, timer = 2000ACD8 ports in use bitmask = 10 getstatus, port = 4 USBHub control callback 01 01 00 00 New Port Status status=101 port=4 state=4 Device is present: Has Power timer event (19999 us): Debounce Timer, this = 2000A9C0, timer = 2000ACD8 ports in use bitmask = 10 getstatus, port = 4 USBHub control callback 01 01 00 00 New Port Status status=101 port=4 state=5 Device is present: Has Power timer event (19999 us): Debounce Timer, this = 2000A9C0, timer = 2000ACD8 ports in use bitmask = 10 getstatus, port = 4 USBHub control callback 01 01 00 00 New Port Status status=101 port=4 state=6 Device is present: Has Power sending reset send_setreset USBHub control callback unhandled setup, message = 40323 timer event (19999 us): Debounce Timer, this = 2000A9C0, timer = 2000ACD8 ports in use bitmask = 0 HUB Callback (member) status = 10 getstatus, port = 4 USBHub control callback 03 05 10 00 New Port Status status=100503 port=4 state=7 Device is present: Enabled, speed = 480 Mbit/sec Has Power USBHub control callback unhandled setup, message = 140123 timer event (25000 us): Hello, I'm resettimer, this = 2000A9C0, timer = 2000ACF8 port_doing_reset = 4 PORT_RECOVERY new_Device: 480 Mbit/sec new_Pipe enumeration: enumeration: enumeration: Device Descriptor: 12 01 00 02 EF 02 01 40 44 09 0A 0F 14 04 01 02 03 01 VendorID = 0944, ProductID = 0F0A, Version = 0414 Class/Subclass/Protocol = 239 / 2 / 1 Number of Configurations = 1 enumeration: enumeration: Manufacturer: KORG Inc. enumeration: Product: opsix enumeration: Serial Number: 3f7e0ee0 enumeration: Config data length = 167 enumeration: Configuration Descriptor: 09 02 A7 00 04 01 04 C0 01 NumInterfaces = 4 ConfigurationValue = 1 08 0B 00 02 02 06 00 07 Interface Association = 0 through 1 Class / Subclass / Protocol = 2 / 6 / 7 09 04 00 00 01 02 02 FF 05 Interface = 0 Number of endpoints = 1 Class/Subclass/Protocol = 2 / 2 / 255 05 24 00 10 01 05 24 01 00 01 04 24 02 00 05 24 06 00 01 07 05 82 03 08 00 09 Endpoint = 2 IN Type = Interrupt Max Size = 8 Polling Interval = 9 09 04 01 00 02 0A 00 00 06 Interface = 1 Number of endpoints = 2 Class/Subclass/Protocol = 10 / 0 / 0 07 05 81 02 00 02 00 Endpoint = 1 IN Type = Bulk Max Size = 512 Polling Interval = 0 07 05 01 02 00 02 00 Endpoint = 1 OUT Type = Bulk Max Size = 512 Polling Interval = 0 09 04 02 00 00 01 01 00 09 Interface = 2 Number of endpoints = 0 Class/Subclass/Protocol = 1 / 1 / 0 09 24 01 00 01 09 00 01 03 09 04 03 00 02 01 03 00 00 Interface = 3 Number of endpoints = 2 Class/Subclass/Protocol = 1 / 3 / 0 07 24 01 00 01 25 00 06 24 02 02 01 00 09 24 03 01 02 01 01 01 0B 06 24 02 01 03 0A 09 24 03 02 04 01 03 01 00 09 05 02 02 00 02 00 00 00 Endpoint = 2 OUT Type = Bulk Max Size = 512 Polling Interval = 0 05 25 01 01 03 09 05 83 02 00 02 00 00 00 Endpoint = 3 IN Type = Bulk Max Size = 512 Polling Interval = 0 05 25 01 01 02 enumeration: USBHub memory usage = 960 USBHub claim_device this=2000ADA0 Descriptor 11 = IAD Descriptor 4 = INTERFACE MIDIDevice claim this=20003020 len = 150 MIDIDevice claim this=20004140 len = 150 MIDIDevice claim this=20005260 len = 150 MIDIDevice claim this=20006380 len = 150 MIDIDevice claim this=200074A0 len = 150 MIDIDevice claim this=200085C0 len = 150 MIDIDevice claim this=200096E0 len = 150 Descriptor 36 = ??? Descriptor 36 = ??? Descriptor 36 = ??? Descriptor 36 = ??? Descriptor 5 = ENDPOINT Descriptor 4 = INTERFACE MIDIDevice claim this=20003020 len = 115 MIDIDevice claim this=20004140 len = 115 MIDIDevice claim this=20005260 len = 115 MIDIDevice claim this=20006380 len = 115 MIDIDevice claim this=200074A0 len = 115 MIDIDevice claim this=200085C0 len = 115 MIDIDevice claim this=200096E0 len = 115 Descriptor 5 = ENDPOINT Descriptor 5 = ENDPOINT Descriptor 4 = INTERFACE MIDIDevice claim this=20003020 len = 92 Interface is unknown (might be Yahama) type: 36, len: 9 MIDI Header (ignored) type: 4, len: 9 No IN endpoint was found No OUT endpoint was found MIDIDevice claim this=20004140 len = 92 Interface is unknown (might be Yahama) type: 36, len: 9 MIDI Header (ignored) type: 4, len: 9 No IN endpoint was found No OUT endpoint was found MIDIDevice claim this=20005260 len = 92 Interface is unknown (might be Yahama) type: 36, len: 9 MIDI Header (ignored) type: 4, len: 9 No IN endpoint was found No OUT endpoint was found MIDIDevice claim this=20006380 len = 92 Interface is unknown (might be Yahama) type: 36, len: 9 MIDI Header (ignored) type: 4, len: 9 No IN endpoint was found No OUT endpoint was found MIDIDevice claim this=200074A0 len = 92 Interface is unknown (might be Yahama) type: 36, len: 9 MIDI Header (ignored) type: 4, len: 9 No IN endpoint was found No OUT endpoint was found MIDIDevice claim this=200085C0 len = 92 Interface is unknown (might be Yahama) type: 36, len: 9 MIDI Header (ignored) type: 4, len: 9 No IN endpoint was found No OUT endpoint was found MIDIDevice claim this=200096E0 len = 92 Interface is unknown (might be Yahama) type: 36, len: 9 MIDI Header (ignored) type: 4, len: 9 No IN endpoint was found No OUT endpoint was found Descriptor 36 = ??? Descriptor 4 = INTERFACE MIDIDevice claim this=20003020 len = 74 Interface is MIDI type: 36, len: 7 MIDI Header (ignored) type: 36, len: 6 MIDI IN Jack (ignored) type: 36, len: 9 MIDI OUT Jack (ignored) type: 36, len: 6 MIDI IN Jack (ignored) type: 36, len: 9 MIDI OUT Jack (ignored) type: 5, len: 9 MIDI Endpoint: 2 tx_size = 512 type: 37, len: 5 MIDI Endpoint Jack Association (ignored) type: 5, len: 9 MIDI Endpoint: 83 rx_size = 512 type: 37, len: 5 MIDI Endpoint Jack Association (ignored) new_Pipe Found IN endpoint, assigning callback new_Pipe Found OUT endpoint, assigning callback Descriptor 36 = ??? Descriptor 36 = ??? Descriptor 36 = ??? Descriptor 36 = ??? Descriptor 36 = ??? Descriptor 5 = ENDPOINT Descriptor 37 = ??? Descriptor 5 = ENDPOINT Descriptor 37 = ??? Connected port 4 KORG Inc. opsix MIDIDevice Receive MIDI Data: avail = 399 queue another receive packet MIDIDevice Receive MIDI Data: 0F FE 00 00 avail = 398 queue another receive packet read: FE0F ```

Teensy then Opsix (results in halt)

``` HUB Callback (member) status = 10 getstatus, port = 4 USBHub control callback 01 01 01 00 New Port Status status=10101 port=4 state=0 Device is present: Has Power USBHub control callback Port Status Cleared, port=4 timer event (20000 us): Debounce Timer, this = 2000A9C0, timer = 2000ACD8 ports in use bitmask = 10 getstatus, port = 4 USBHub control callback 01 01 00 00 New Port Status status=101 port=4 state=2 Device is present: Has Power HUB Callback (member) status = 10 getstatus, port = 4 USBHub control callback 00 01 01 00 New Port Status status=10100 port=4 state=3 Has Power timer event (19999 us): Debounce Timer, this = 2000A9C0, timer = 2000ACD8 ports in use bitmask = 0 HUB Callback (member) status = 10 getstatus, port = 4 USBHub control callback 00 01 01 00 New Port Status status=10100 port=4 state=1 Has Power HUB Callback (member) status = 10 getstatus, port = 4 USBHub control callback 01 01 01 00 New Port Status status=10101 port=4 state=1 Device is present: Has Power USBHub control callback Port Status Cleared, port=4 timer event (20000 us): Debounce Timer, this = 2000A9C0, timer = 2000ACD8 ports in use bitmask = 10 getstatus, port = 4 USBHub control callback 01 01 00 00 New Port Status status=101 port=4 state=2 Device is present: Has Power timer event (19999 us): Debounce Timer, this = 2000A9C0, timer = 2000ACD8 ports in use bitmask = 10 getstatus, port = 4 USBHub control callback 01 01 00 00 New Port Status status=101 port=4 state=3 Device is present: Has Power timer event (19999 us): Debounce Timer, this = 2000A9C0, timer = 2000ACD8 ports in use bitmask = 10 getstatus, port = 4 USBHub control callback 01 01 00 00 New Port Status status=101 port=4 state=4 Device is present: Has Power timer event (19999 us): Debounce Timer, this = 2000A9C0, timer = 2000ACD8 ports in use bitmask = 10 getstatus, port = 4 USBHub control callback 01 01 00 00 New Port Status status=101 port=4 state=5 Device is present: Has Power timer event (19999 us): Debounce Timer, this = 2000A9C0, timer = 2000ACD8 ports in use bitmask = 10 getstatus, port = 4 USBHub control callback 01 01 00 00 New Port Status status=101 port=4 state=6 Device is present: Has Power sending reset send_setreset USBHub control callback unhandled setup, message = 40323 timer event (19999 us): Debounce Timer, this = 2000A9C0, timer = 2000ACD8 ports in use bitmask = 0 HUB Callback (member) status = 10 getstatus, port = 4 USBHub control callback 03 01 10 00 New Port Status status=100103 port=4 state=7 Device is present: Enabled, speed = 12 Mbit/sec Has Power USBHub control callback unhandled setup, message = 140123 timer event (25000 us): Hello, I'm resettimer, this = 2000A9C0, timer = 2000ACF8 port_doing_reset = 4 PORT_RECOVERY new_Device: 12 Mbit/sec new_Pipe ERROR Followup remove from followup list remove from followup list dummy halt: 20009B40 remain on followup list TODO: handle errors from periodic schedule! ```