Opened 4 years ago

Closed 17 months ago

#16745 closed bug (fixed)

XHCI USB BD-RW drive attachment fails

Reported by: kallisti5 Owned by: nobody
Priority: normal Milestone: R1/beta5
Component: Drivers/Disk/USB Version: R1/Development
Keywords: Cc:
Blocked By: Blocking: #9264, #17284
Platform: All

Description

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]

Attachments (1)

IMG_20230531_134735.jpg (4.1 MB ) - added by kallisti5 17 months ago.

Change History (19)

comment:1 by waddlesplash, 4 years ago

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.)

comment:2 by waddlesplash, 3 years ago

Please retest under a recent nightly.

comment:3 by kallisti5, 3 years ago

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.

comment:4 by kallisti5, 3 years ago

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.

Last edited 3 years ago by kallisti5 (previous) (diff)

comment:5 by kallisti5, 3 years ago

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

comment:6 by kallisti5, 3 years ago

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"

comment:7 by waddlesplash, 3 years ago

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...

comment:8 by kallisti5, 3 years ago

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.

comment:9 by waddlesplash, 3 years ago

Blocking: 17284 added

comment:10 by waddlesplash, 2 years ago

Component: Drivers/USB/XHCIDrivers/Disk/USB
Keywords: CDROM removed

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

comment:11 by waddlesplash, 2 years ago

Owner: changed from waddlesplash to nobody
Status: newassigned

comment:12 by waddlesplash, 18 months ago

Blocking: 9264 added

comment:13 by waddlesplash, 17 months ago

Please retest after hrev57048.

comment:14 by kallisti5, 17 months ago

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)

(disc doesn't show up)

Last edited 17 months ago by kallisti5 (previous) (diff)

comment:15 by waddlesplash, 17 months ago

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

comment:16 by kallisti5, 17 months ago

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.

by kallisti5, 17 months ago

Attachment: IMG_20230531_134735.jpg added

comment:17 by kallisti5, 17 months ago

I think this one is solved!

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

comment:18 by waddlesplash, 17 months ago

Milestone: R1R1/beta5
Resolution: fixed
Status: assignedclosed

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.

Note: See TracTickets for help on using tickets.