XHCI USB BD-RW drive attachment fails

[kallisti5]

hrev54880, x86_64

KERN: usb_disk: device reports a lun count of 1
KERN: usb_disk: vendor_identification    "PIONEER "
KERN: usb_disk: product_identification   "BD-RW   BDR-XS06"
KERN: usb_disk: product_revision_level   "1.01"
KERN: usb_disk: operation 0x1b failed at the SCSI level
KERN: Last message repeated 2 times.
KERN: usb_disk: operation 0x1b failed at the SCSI level
Last message repeated 1 time
KERN: usb xhci 0: transfer error on slot 6 endpoint 3: Stall
KERN: usb error xhci 2: link descriptor for pipe: max transfers count exceeded
KERN: usb error hub 73: KERN: error updating port status
KERN: usb error xhci 2: KERN: link descriptor for pipe: max transfers count exceeded
KERN: usb error hub 73: KERN: error updating port status
KERN: usb error xhci 2: KERN: link descriptor for pipe: max transfers count exceeded
KERN: usb error hub 73: KERN: error updating port status
KERN: usb error xhci 2: KERN: link descriptor for pipe: max transfers count exceeded
KERN: usb error hub 73: KERN: error updating port status
KERN: usb error xhci 2: link descriptor for pipe: max transfers count exceeded
KERN: usb error hub 73: KERN: error updating port status
KERN: usb error xhci 2: KERN: link descriptor for pipe: max transfers count exceeded
KERN: usb error hub 73: KERN: error updating port status

0bda:8771 /dev/bus/usb/0/10 "Realtek Semiconductor Corp." "Bluetooth Radio" ver. 0200
046d:c52b /dev/bus/usb/0/11 "Logitech, Inc." "Unifying Receiver" ver. 2407
04d9:0169 /dev/bus/usb/0/15 "Holtek Semiconductor, Inc." "" ver. 0209
0b05:1872 /dev/bus/usb/0/16 "ASUSTek Computer, Inc." "AURA LED Controller" ver. 0200
2433:b200 /dev/bus/usb/0/21 "ASETEK" "690LC" ver. 0100
08e4:017a /dev/bus/usb/0/5 "Pioneer Corp." "Pioneer Blu-ray Drive" ver. 0100
0000:0000 /dev/bus/usb/0/hub "HAIKU Inc." "XHCI RootHub" ver. 0300
0781:5596 /dev/bus/usb/1/0 "SanDisk Corp." "Ultra T C" ver. 0100
0000:0000 /dev/bus/usb/1/hub "HAIKU Inc." "XHCI RootHub" ver. 0300
1532:0510 /dev/bus/usb/2/3/0 "Razer USA, Ltd" "Razer Kraken 7.1 V2" ver. 6702
0bda:5411 /dev/bus/usb/2/3/hub "Realtek Semiconductor Corp." "" ver. 0104
0bda:0411 /dev/bus/usb/2/7/hub "Realtek Semiconductor Corp." "" ver. 0104
0000:0000 /dev/bus/usb/2/hub "HAIKU Inc." "XHCI RootHub" ver. 0300

device Serial bus controller (USB controller, XHCI) [c|3|30]
  vendor 1022: Advanced Micro Devices, Inc. [AMD]
--
device Serial bus controller (USB controller, XHCI) [c|3|30]
  vendor 1b21: ASMedia Technology Inc.
--
device Serial bus controller (USB controller, XHCI) [c|3|30]
  vendor 1022: Advanced Micro Devices, Inc. [AMD]

[waddlesplash]

I really do not know so much about the interaction between USB device drivers and the stack. Transfer stalls are reported to drivers, which are theoretically supposed to handle recovery, and indeed there are other tickets where the usb_disk driver does not seem to recover from them. Why that is or what the solution is, I don't know, but I would be hesitant to blame XHCI for this. (See if the same problem occurs under EHCI.)

[waddlesplash]

Please retest under a recent nightly.

[kallisti5]

It just so happens I have this USB drive on my desk and my XPS 13 running hrev55384.

Plugging the drive into the running laptop... nothing happens oddly. No messages in syslog. The drive powers up, but Haiku doesn't even notice it's plug event.

I switched from USB C to USB A on another port. Now getting:

usb_disk: got device name "PIONEER BD-RW BDR-XS06 1.01": No error
usb_disk: operation 0x1b failed at the SCSI level
Last message repeated 4 times
Last message repeated 2 times

Insert a disc...

Last message repeated 18 times
Last message repeated 6 times

Disc never shows up in Tracker.

[kallisti5]

Oddly, attaching the drive with a disc inserted to USB A results in an alternative result:

KERN: usb_disk: device reports a lun count of 1
KERN: usb_disk: vendor_identification    "PIONEER "
KERN: usb_disk: product_identification   "BD-RW   BDR-XS06"
KERN: usb_disk: product_revision_level   "1.01"
KERN: usb_disk: operation 0x1b failed at the SCSI level
usb xhci 0: transfer error on slot 8 endpoint 3: Stall
usb xhci 0: cancel queued transfers (1) for pipe 0xffffffffa336c158 (1)
usb error xhci 0: KERN: cancel queued transfers: halted endpoint, reset!
usb_disk: acquire_sem failed while waiting for data transfer: Operation times out
usb xhci 0: cancel queued transfers (1) for pipe 0xffffffffa336c158 (1)
usb xhci 0: transfer error on slot 8 endpoint 3: Stopped
usb_disk: acquire_sem failed while waiting on data transfer: Operation timed out
usb_disk: receiving the command status wrapper failed: Operation timed out
usb_disk: failed to update capacity: Operation timed out

Overall it looks like the bus does recover unlike before (likely that recent change I made to stalled / stopped transfers "exiting the error state". Doesn't fix any issues though.

[kallisti5]

Updating to hrev55436 to see if the recent changes impact the above...

[kallisti5]

as of hrev55436:

• Plugging into USB C / Thunderbolt 3 port. Same result
• Plugging into USB A port with disc inserted:

  usb_disk: device reports a lun count of 1
  usb_disk: vendor_identification    "PIONEER "
  usb_disk: product_identification   "BD-RW   BDR-XS06"
  usb_disk: product_revision_level   "1.01"
  usb_disk: operation 0x1b failed at the SCSI level
  usb xhci 0: transfer error on slot 5 endpoint 3: Stall
  usb xhci 0: cancel queued transfers (1) for pipe 0xffffffffa32d6e60 (1)
  usb error xhci 0: KERN: cancel queued transfers: halted endpoint, reset!
  usb_disk: acquire_sem failed while waiting for data transfer: Operation times out
  usb xhci 0: cancel queued transfers (1) for pipe 0xffffffffa32d6e60 (1)
  usb xhci 0: transfer error on slot 5 endpoint 3: Stopped
  usb_disk: acquire_sem failed while waiting on data transfer: Operation timed out
  usb_disk: receiving the command status wrapper failed: Operation timed out
  usb_disk: failed to update capacity: Operation timed out
  

So no changes between hrev55384 and hrev55436.

To be honest, everything looks and sounds normal until that first stall. The drive even starts to read the disc.

For the controller in the XPS 13. "Sunrise Point-LP USB 3.0 xHCI Controller 0x9d2f"

[waddlesplash]

Does this work on EHCI? Because if not, this may be a usb_disk bug and not an XHCI bug. I don't think the usb_disk driver recovers well from "failed at the SCSI level" errors...

[kallisti5]

I found a MicroUSB cable short enough to power the drive... no luck using a USB 2 spec cable on the XHCI port. Same error.

I really don't have any Haiku systems with EHCI ports anymore.

[waddlesplash]

I don't think this is an XHCI issue, but another usb_disk issue failing to handle stalls properly.

[waddlesplash]

Please retest after hrev57048.

[kallisti5]

Tested on hrev57051:

Plug empty drive, insert DVD disc:

KERN: usb hub 65: port 0: new device connected
KERN: usb_disk: device reports a lun count of 1
KERN: usb_disk: vendor_identification    "PIONEER "
KERN: usb_disk: product_identification   "BD-RW   BDR-XS06"
KERN: usb_disk: product_revision_level   "1.01"
KERN: usb_disk: operation 0x1b failed at the SCSI level
KERN: publish device: node 0xfffffffff1a5e338, path disk/usb/0/0/raw, module drivers/disk/usb_disk/device_v1
KERN: usb_disk: operation 0x1b failed at the SCSI level
KERN: usb_disk: got device name "PIONEER BD-RW BDR-XS06 1.01": No error
KERN: usb_disk: operation 0x1b failed at the SCSI level
KERN: Last message repeated 4 times.
Last message repeated 2 times
KERN: Last message repeated 5 times.
KERN: Last message repeated 2 times.
KERN: Last message repeated 6 times.
KERN: Last message repeated 2 times.
KERN: register_domain(9, unix)

[waddlesplash]

It appears we try to send SCSI_START_STOP_UNIT_6 for "ATAPI" devices, but this fails repeatedly.

[kallisti5]

Ok. So. Unplug the drive, and i get a KDL. (attaching) Boot with the drive attached, and a DVD already inserted...

I can play the DVD in MediaPlayer. No errors.

[kallisti5]

I think this one is solved!

The remaining issue seems to be us not supporting LUN / disk changes in usb_disk

[waddlesplash]

KDL should be fixed in hrev57059.

We do actually support LUN changes in usb_disk, but we poll for them. We also have separate logic for ATAPI devices like these, which may not be entirely correct.

Probably the driver needs to be reworked to not poll for changes, at least on ATAPI devices, to detect insertion/removal. Not sure how that is supposed to happen, but indeed it's a problem for another ticket.