[regression] usb_disk: KDL on USB drive disconnect

[X512]

This is hrev57062.

Observed on x86_64 and riscv64.

syslog:

publish device: node 0xffffffc038f99a00, path disk/usb/3/0/raw, module drivers/disk/usb_disk/device_v1
usb xhci 0: cancel queued transfers (0) for pipe 0xffffffc00702d600 (0)
usb xhci 0: cancel queued transfers (0) for pipe 0xffffffc007278460 (1)
usb xhci 0: transfer error on slot 4 endpoint 2: Length invalid
usb error xhci 0: TRB 0x412e6210 was not found in the endpoint!
usb xhci 0: cancel queued transfers (0) for pipe 0xffffffc007278410 (2)
usb xhci 0: transfer error on slot 4 endpoint 5: Length invalid
usb error xhci 0: TRB 0x412e64e0 was not found in the endpoint!
PANIC: _mutex_lock(): double lock of 0xffffffc00700d9e8 by thread 20
Welcome to Kernel Debugging Land...
Thread 20 "usb explore" running on CPU 2
Stack:
FP: 0xffffffc000fdea00
FP: 0xffffffc000fdea20, PC: 0xffffffc002154aec <kernel_riscv64> arch_debug_call_with_fault_handler + 32
FP: 0xffffffc000fdea70, PC: 0xffffffc0020d6178 <kernel_riscv64> debug_call_with_fault_handler.localalias + 128
FP: 0xffffffc000fdeb00, PC: 0xffffffc0020d74f8 <kernel_riscv64> _ZL20kernel_debugger_loopPKcS0_Pvi + 320
FP: 0xffffffc000fdeb70, PC: 0xffffffc0020d789e <kernel_riscv64> _ZL24kernel_debugger_internalPKcS0_Pvi + 284
FP: 0xffffffc000fdebb0, PC: 0xffffffc0020d7b30 <kernel_riscv64> panic + 86
FP: 0xffffffc000fdec40, PC: 0xffffffc0020c27f8 <kernel_riscv64> _mutex_lock.localalias + 424
FP: 0xffffffc000fdec80, PC: 0xffffffc002529686 <usb_disk> _ZL14usb_disk_closePv + 56
FP: 0xffffffc000fdeca0, PC: 0xffffffc002115246 <kernel_riscv64> _ZL10file_closeP15file_descriptor + 52
FP: 0xffffffc000fdecc0, PC: 0xffffffc002106ef2 <kernel_riscv64> put_fd.localalias + 70
FP: 0xffffffc000fded40, PC: 0xffffffc002115df2 <kernel_riscv64> _ZL29disconnect_mount_or_vnode_fdsP8fs_mountP5vnode + 186
FP: 0xffffffc000fded70, PC: 0xffffffc00211b852 <kernel_riscv64> vfs_disconnect_vnode + 50
FP: 0xffffffc000fdedb0, PC: 0xffffffc0020ed70c <kernel_riscv64> _Z22devfs_unpublish_devicePN8BPrivate10BaseDeviceEb + 146
FP: 0xffffffc000fdedf0, PC: 0xffffffc0020e672a <kernel_riscv64> _ZL16unpublish_deviceP11device_nodePKc + 132
FP: 0xffffffc000fdee20, PC: 0xffffffc00252745a <usb_disk> _ZL23usb_disk_device_removedPv + 78
FP: 0xffffffc000fdee40, PC: 0xffffffc0020ea29a <kernel_riscv64> _ZN11device_node13DeviceRemovedEv.localalias + 54
FP: 0xffffffc000fdee60, PC: 0xffffffc0020ea282 <kernel_riscv64> _ZN11device_node13DeviceRemovedEv.localalias + 30
FP: 0xffffffc000fdee80, PC: 0xffffffc0020ea388 <kernel_riscv64> _ZL15unregister_nodeP11device_node + 48
FP: 0xffffffc000fdeef0, PC: 0xffffffc002568100 <xhci> _ZN6DeviceD2Ev + 126
FP: 0xffffffc000fdef10, PC: 0xffffffc0025682d8 <xhci> _ZN6DeviceD0Ev + 20
FP: 0xffffffc000fdef30, PC: 0xffffffc002564148 <xhci> _ZN4XHCI10FreeDeviceEP6Device.localalias + 28
FP: 0xffffffc000fdef90, PC: 0xffffffc00251824e <usb> _ZN5Stack7ExploreEv + 258
FP: 0xffffffc000fdefc0, PC: 0xffffffc0025182f8 <usb> _ZN5Stack13ExploreThreadEPv + 38
FP: 0xffffffc000fdefe0, PC: 0xffffffc0020ba4dc <kernel_riscv64> _ZL19common_thread_entryPv + 52
FP: 0x0, PC: 0xffffffc002153748 <kernel_riscv64> arch_thread_entry + 0
kdebug>

[kallisti5]

I'm seeing other stall regressions on x86_64 with usb_disk's (usb flash)

KERN: usb hub 31: port 0: new device connected
KERN: usb_disk: device reports a lun count of 1
KERN: usb_disk: vendor_identification    "Mass    "
KERN: usb_disk: product_identification   "Storage Device  "
KERN: usb_disk: product_revision_level   "1.00"
KERN: publish device: node 0xffffffffe1bf4978, path disk/usb/0/0/raw, module drivers/disk/usb_disk/device_v1
KERN: DMAResource@0xffffff8048053788: low/high 0/ffffffffffffffff, max segment count 16, align 1, boundary 0, max transfer 65536, max segment size 18446744073709551615
KERN: usb_disk: got device name "Mass Storage Device 1.00": No error
KERN: intel: ep_std_ops(0x1)
KERN: intel: ep_std_ops(0x2)
KERN: intel: pm_std_ops(0x1)
KERN: intel: pm_identify_partition(109, 10: 0, 64021856256, 512)
KERN: btrfs: [2684259253: 165711] invalid superblock!
KERN: exfat: invalid superblock!
KERN: ext2: invalid superblock!
KERN: identify(109, 0xffffff804883f1c8)
KERN: ntfs: error: identify_partition: boot signature doesn't match
KERN: usb_disk: unhandled ioctl 10102
KERN: intel: pm_scan_partition(109, 10: 0, 64021856256, 512)
KERN: intel: ep_std_ops(0x1)
KERN: intel: ep_identify_partition(109, 2048, 33554432, 512)
KERN: intel: ep_std_ops(0x2)
KERN: intel: pm_identify_partition(109, 11: 2048, 33554432, 512)
KERN: btrfs: [2684318518: 165711] invalid superblock!
KERN: exfat: invalid superblock!
KERN: ext2: invalid superblock!
KERN: identify(109, 0xffffff80488110b0)
KERN: ntfs: error: identify_partition: boot signature doesn't match
KERN: usb_disk: unhandled ioctl 10102
KERN: intel: ep_std_ops(0x1)
KERN: intel: ep_identify_partition(109, 33556480, 314572800, 512)
KERN: intel: ep_std_ops(0x2)
KERN: intel: pm_identify_partition(109, 12: 33556480, 314572800, 512)
KERN: btrfs: [2684375258: 165711] invalid superblock!
KERN: exfat: invalid superblock!
KERN: ext2: invalid superblock!
KERN: identify(109, 0xffffff80488110b0)
KERN: ntfs: error: identify_partition: boot signature doesn't match
KERN: usb_disk: unhandled ioctl 10102
KERN: bfs: mounted "Haiku" (root node at 131072, device = /dev/disk/usb/0/0/1)
KERN: slab memory manager: created area 0xffffff804f001000 (7417720)
KERN: usb xhci 0: transfer error on slot 9 endpoint 3: Stall
KERN: usb error xhci 0: cancel queued transfers: halted endpoint, reset!
KERN: usb_disk: acquire_sem failed while waiting for data transfer: Operation timed out
KERN: usb_disk: receiving the command status wrapper failed: Operation timed out
KERN: usb_disk: acquire_sem failed while waiting for data transfer: Operation timed out
Last message repeated 1 time
KERN: usb_disk: receiving the command status wrapper failed: Operation timed out
KERN: usb_disk: acquire_sem failed while waiting for data transfer: Operation timed out
Last message repeated 1 time
KERN: usb_disk: receiving the command status wrapper failed: Operation timed out
KERN: usb_disk: acquire_sem failed while waiting for data transfer: Operation timed out
Last message repeated 1 time
KERN: usb_disk: receiving the command status wrapper failed: Operation timed out
KERN: usb_disk: acquire_sem failed while waiting for data transfer: Operation timed out
KERN: could not write back block 98312 (Operation timed out)
KERN: usb_disk: acquire_sem failed while waiting for data transfer: Operation timed out
Last message repeated 3 times
KERN: could not write back block 98312 (Operation timed out)
KERN: usb_disk: acquire_sem failed while waiting for data transfer: Operation timed out

$ lspci | grep USB
02:00.0 USB controller: Advanced Micro Devices, Inc. [AMD] Device 43d0 (rev 01)
0a:00.0 USB controller: ASMedia Technology Inc. ASM2142/ASM3142 USB 3.1 Host Controller
10:00.3 USB controller: Advanced Micro Devices, Inc. [AMD] Matisse USB 3.0 Host Controller

/:  Bus 01.Port 1: Dev 1, Class=root_hub, Driver=xhci_hcd/14p, 480M
    .
    |__ Port 5: Dev 4, If 0, Class=Hub, Driver=hub/4p, 480M
        |__ Port 1: Dev 11, If 0, Class=Mass Storage, Driver=usb-storage, 480M

[X512]

Proposed fix (tested):

src/add-ons/kernel/drivers/disk/usb/usb_disk/usb_disk.cpp

@@ -1234 +1234 @@
        disk_device *device = (disk_device *)cookie;
        mutex_lock(&device->lock);
 
-       for (uint8 i = 0; i < device->lun_count; i++)
+       for (uint8 i = 0; i < device->lun_count; i++) {
+               mutex_unlock(&device->lock);
                gDeviceManager->unpublish_device(device->node, device->luns[i]->name);
+               mutex_lock(&device->lock);
+       }
 
        device->removed = true;
        gUSBModule->cancel_queued_transfers(device->bulk_in);

[waddlesplash]

Fixed in hrev57063.