Project

General

Profile

Actions

Bug #13843

open

USB errors: slot in wrong state: 19

Added by Stephan Althaus over 1 year ago. Updated 3 months ago.

Status:
New
Priority:
Normal
Assignee:
-
Category:
-
Start date:
Due date:
% Done:

0%

Estimated time:
Difficulty:
Medium
Tags:
Gerrit CR:
External Bug:

Description

Hello!

Since a few weeks i get I/O errors "failed to read cluster"
when i read my SDCard with 2 different adapters. It worked fine last
year, i think january, too.

I checked the SDCard with badblocks on a linux with the same Adapter in
a USB2 port - all went ok.
I checked the SDCard on a different OI box with the same Adapter in
a USB3 port - all went ok.

I use a fuse for the exfat filesystem, but i think it is a USB driver
bug.

What can i do to get to the root cause ?

Any hints are welcome!

Stephan

This i got this morning when i did a copy:

/home1/home/steven/Documents/Pictures/Test/2021-05-31/DS306054.ARW: I/O error
/home1/home/steven/Documents/Pictures/Test/2021-05-31/DS306055.ARW: I/O error
cp: cannot access /media/sdcard/DCIM/103MSDCF/*

steven@dell6510:~$ dmesg

May 31, 2021 at 07:18:39 AM CEST
May 31 07:18:23 dell6510 xhci: [ID 617155 kern.info] NOTICE: xhci2: endpoint is in state 3
May 31 07:18:23 dell6510 mount.exfat-fus2691: [ID 251512 user.error] failed to read cluster 0xb7f8
May 31 07:18:23 dell6510 xhci: [ID 902155 kern.info] NOTICE: xhci2: xhci stop endpoint command (2)/slot (8) in wrong state: 19
May 31 07:18:23 dell6510 xhci: [ID 617155 kern.info] NOTICE: xhci2: endpoint is in state 3
May 31 07:18:23 dell6510 xhci: [ID 902155 kern.info] NOTICE: xhci2: xhci stop endpoint command (3)/slot (8) in wrong state: 19
May 31 07:18:23 dell6510 xhci: [ID 617155 kern.info] NOTICE: xhci2: endpoint is in state 3

Actions #1

Updated by Stephan Althaus over 1 year ago

$ sudo prtconf -dD | grep -i xhci
pci1028,7b1 (pciex8086,a12f) [Intel Corporation 100 Series/C230 Series Chipset Family USB 3.0 xHCI Controller], instance #2 (driver name: xhci)
pci1028,7b1 (pciex8086,15db) [Intel Corporation JHL6340 Thunderbolt 3 USB 3.1 Controller (C step) [Alpine Ridge 2C 2016]] (driver name: xhci)

$ mdb -ke '::prtusb'
INDEX DRIVER INST NODE GEN VID.PID PRODUCT
1 xhci 2 pci1028,7b1 3.0 0000.0000 No Product String
2 hid 39 mouse 1.1 045e.0040 Microsoft 3-Button Mouse with IntelliEye(TM)
3 usb_mid 31 device 1.1 0bf8.100c FSC KBPC PX
4 hubd 18 hub 2.0 413c.2513 No Product String
5 usb_mid 32 device 2.0 8087.0a2b No Product String
6 hubd 19 hub 2.0 413c.2513 No Product String
7 usb_mid 33 device 1.1 0a5c.5832 5880
8 scsa2usb 24 storage 3.1 0781.cfca SDDR-409

Actions #2

Updated by Stephan Althaus over 1 year ago

$ mdb ke '::xhci_device'
<--
snip --->

SANDISK - SDDR-409
Port 21 | Slot 10 | # Endpoints 01
EP Type State Head Tail
0 CONTROL Running 0xdb 0xdb

Actions #3

Updated by Stephan Althaus over 1 year ago

$ mdb ke "::prtusb -v"
<-
snip -->
INDEX DRIVER INST NODE GEN VID.PID PRODUCT
8 scsa2usb 24 storage 3.1 0781.cfca SDDR-409

Device Descriptor {
bLength = 0x12
bDescriptorType = 0x1
bcdUSB = 0x310
bDeviceClass = 0
bDeviceSubClass = 0
bDeviceProtocol = 0
bMaxPacketSize0 = 0x9
idVendor = 0x781
idProduct = 0xcfca
bcdDevice = 0x3
iManufacturer = 0x3
iProduct = 0x4
iSerialNumber = 0x2
bNumConfigurations = 0x1
}
-- Active Config Index 0
Configuration Descriptor {
bLength = 0x9
bDescriptorType = 0x2
wTotalLength = 0x2c
bNumInterfaces = 0x1
bConfigurationValue = 0x1
iConfiguration = 0x0
bmAttributes = 0x80
bMaxPower = 0x70
}
Interface Descriptor {
bLength = 0x9
bDescriptorType = 0x4
bInterfaceNumber = 0x0
bAlternateSetting = 0x0
bNumEndpoints = 0x2
bInterfaceClass = 0x8
bInterfaceSubClass = 0x6
bInterfaceProtocol = 0x50
iInterface = 0x0
}
Endpoint Descriptor {
bLength = 0x7
bDescriptorType = 0x5
bEndpointAddress = 0x81
bmAttributes = 0x2
wMaxPacketSize = 0x400
bInterval = 0x0
}
SuperSpeed Endpoint Companion Descriptor {
bLength = 0x6
bDescriptorType = 0x30
bMaxBurst = 0x4
bmAttributes = 0x0
wBytesPerInterval = 0x0
}
Endpoint Descriptor {
bLength = 0x7
bDescriptorType = 0x5
bEndpointAddress = 0x2
bmAttributes = 0x2
wMaxPacketSize = 0x400
bInterval = 0x0
}
SuperSpeed Endpoint Companion Descriptor {
bLength = 0x6
bDescriptorType = 0x30
bMaxBurst = 0x4
bmAttributes = 0x0
wBytesPerInterval = 0x0
}

Actions #4

Updated by Stephan Althaus over 1 year ago

Hello!

I would happily run some dtrace script on my laptop setup to get closer to the root cause.

May someone please provide such a script ?

Thanks!
Stephan

Actions #5

Updated by Stephan Althaus over 1 year ago

BTW, there is a small typo in
illumos-gate/usr/src/uts/common/io/usb/hcd/xhci/xhci_command.c

on line 720

xhci_log (xhcip, "!unexpected error when resetting enpoint : %d",
Actions #6

Updated by Stephan Althaus over 1 year ago

Maybe this output shows some light to developers:

./DS305964.ARW: I/O error
./DS305965.ARW: I/O error
steven@dell6510:~/tmp$ echo '::usba_debug_buf' | mdb -k
t rval: 0
s2u24:          bulk-in pipe clear stall: 0
s2u24:          bulk-out pipe clear stall: 0
usbai:  usba_req_exc_cb: scsa2usb24: ph_data=0xfffffe2cf0429a78 (ep2) state=1 wrp=0xfffffe2cde4e96b8 ref=2 reqcnt=1 cr=5
s2u24:  scsa2usb_bulk_only_handle_error: req = 0xfffffe2cde4e9748, cr = 0x5
s2u24:  scsa2usb_bulk_only_reset_recovery: scsa2usbp = 0xfffffe2cfa2ec000
s2u24:          bulk-only device-reset rval: 0
s2u24:          bulk-in pipe clear stall: 0
s2u24:          bulk-out pipe clear stall: 0
usbai:  usba_req_exc_cb: scsa2usb24: ph_data=0xfffffe2cf0429a78 (ep2) state=1 wrp=0xfffffe2cde4e96b8 ref=2 reqcnt=1 cr=5
s2u24:  scsa2usb_bulk_only_handle_error: req = 0xfffffe2cde4e9748, cr = 0x5
s2u24:  scsa2usb_bulk_only_reset_recovery: scsa2usbp = 0xfffffe2cfa2ec000
s2u24:          bulk-only device-reset rval: 0
s2u24:          bulk-in pipe clear stall: 0
s2u24:          bulk-out pipe clear stall: 0
usbai:  usba_req_exc_cb: scsa2usb24: ph_data=0xfffffe2cf0429a78 (ep2) state=1 wrp=0xfffffe2cde4e96b8 ref=2 reqcnt=1 cr=5
s2u24:  scsa2usb_bulk_only_handle_error: req = 0xfffffe2cde4e9748, cr = 0x5
s2u24:  scsa2usb_bulk_only_reset_recovery: scsa2usbp = 0xfffffe2cfa2ec000
s2u24:          bulk-only device-reset rval: 0
s2u24:          bulk-in pipe clear stall: 0
s2u24:          bulk-out pipe clear stall: 0
usbai:  usba_req_exc_cb: scsa2usb24: ph_data=0xfffffe2cf0429a78 (ep2) state=1 wrp=0xfffffe2cd03f1770 ref=2 reqcnt=1 cr=5
s2u24:  scsa2usb_bulk_only_handle_error: req = 0xfffffe2cd03f1800, cr = 0x5
s2u24:  scsa2usb_bulk_only_reset_recovery: scsa2usbp = 0xfffffe2cfa2ec000
s2u24:          bulk-only device-reset rval: 0
s2u24:          bulk-in pipe clear stall: 0
s2u24:          bulk-out pipe clear stall: 0
usbai:  usba_req_exc_cb: scsa2usb24: ph_data=0xfffffe2cf0429a78 (ep2) state=1 wrp=0xfffffe2cd1806568 ref=2 reqcnt=1 cr=5
s2u24:  scsa2usb_bulk_only_handle_error: req = 0xfffffe2cd18065f8, cr = 0x5
s2u24:  scsa2usb_bulk_only_reset_recovery: scsa2usbp = 0xfffffe2cfa2ec000
s2u24:          bulk-only device-reset rval: 0
s2u24:          bulk-in pipe clear stall: 0
s2u24:          bulk-out pipe clear stall: 0
usbai:  usba_req_exc_cb: scsa2usb24: ph_data=0xfffffe2cf0429a78 (ep2) state=1 wrp=0xfffffe2cd1806568 ref=2 reqcnt=1 cr=5
s2u24:  scsa2usb_bulk_only_handle_error: req = 0xfffffe2cd18065f8, cr = 0x5
s2u24:  scsa2usb_bulk_only_reset_recovery: scsa2usbp = 0xfffffe2cfa2ec000
s2u24:          bulk-only device-reset rval: 0
s2u24:          bulk-in pipe clear stall: 0
s2u24:          bulk-out pipe clear stall: 0
usbai:  usba_req_exc_cb: scsa2usb24: ph_data=0xfffffe2cf0429a78 (ep2) state=1 wrp=0xfffffe2cd1806568 ref=2 reqcnt=1 cr=5
s2u24:  scsa2usb_bulk_only_handle_error: req = 0xfffffe2cd18065f8, cr = 0x5
s2u24:  scsa2usb_bulk_only_reset_recovery: scsa2usbp = 0xfffffe2cfa2ec000
s2u24:          bulk-only device-reset rval: 0
s2u24:          bulk-in pipe clear stall: 0
s2u24:          bulk-out pipe clear stall: 0
usbai:  usba_req_exc_cb: scsa2usb24: ph_data=0xfffffe2cf0429a78 (ep2) state=1 wrp=0xfffffe2cd1806568 ref=2 reqcnt=1 cr=5
s2u24:  scsa2usb_bulk_only_handle_error: req = 0xfffffe2cd18065f8, cr = 0x5
s2u24:  scsa2usb_bulk_only_reset_recovery: scsa2usbp = 0xfffffe2cfa2ec000
s2u24:          bulk-only device-reset rval: 0
s2u24:          bulk-in pipe clear stall: 0
s2u24:          bulk-out pipe clear stall: 0
usbai:  usba_req_exc_cb: scsa2usb24: ph_data=0xfffffe2cf0429a78 (ep2) state=1 wrp=0xfffffe2cd1806028 ref=2 reqcnt=1 cr=5
s2u24:  scsa2usb_bulk_only_handle_error: req = 0xfffffe2cd18060b8, cr = 0x5
s2u24:  scsa2usb_bulk_only_reset_recovery: scsa2usbp = 0xfffffe2cfa2ec000
s2u24:          bulk-only device-reset rval: 0
s2u24:          bulk-in pipe clear stall: 0
s2u24:          bulk-out pipe clear stall: 0
usbai:  usba_req_exc_cb: scsa2usb24: ph_data=0xfffffe2cf0429a78 (ep2) state=1 wrp=0xfffffe2cd1806028 ref=2 reqcnt=1 cr=5
s2u24:  scsa2usb_bulk_only_handle_error: req = 0xfffffe2cd18060b8, cr = 0x5
s2u24:  scsa2usb_bulk_only_reset_recovery: scsa2usbp = 0xfffffe2cfa2ec000
s2u24:          bulk-only device-reset rval: 0
s2u24:          bulk-in pipe clear stall: 0
s2u24:          bulk-out pipe clear stall: 0
usbai:  usba_req_exc_cb: scsa2usb24: ph_data=0xfffffe2cf0429a78 (ep2) state=1 wrp=0xfffffe2cdfbfa940 ref=2 reqcnt=1 cr=5
s2u24:  scsa2usb_bulk_only_handle_error: req = 0xfffffe2cdfbfa9d0, cr = 0x5
s2u24:  scsa2usb_bulk_only_reset_recovery: scsa2usbp = 0xfffffe2cfa2ec000
s2u24:          bulk-only device-reset rval: 0
s2u24:          bulk-in pipe clear stall: 0
s2u24:          bulk-out pipe clear stall: 0
usbai:  usba_req_exc_cb: scsa2usb24: ph_data=0xfffffe2cf0429a78 (ep2) state=1 wrp=0xfffffe2cdfbfa940 ref=2 reqcnt=1 cr=5
s2u24:  scsa2usb_bulk_only_handle_error: req = 0xfffffe2cdfbfa9d0, cr = 0x5
s2u24:  scsa2usb_bulk_only_reset_recovery: scsa2usbp = 0xfffffe2cfa2ec000
s2u24:          bulk-only device-reset rval: 0
s2u24:          bulk-in pipe clear stall: 0
s2u24:          bulk-out pipe clear stall: 0
usbai:  usba_req_exc_cb: scsa2usb24: ph_data=0xfffffe2cf0429a78 (ep2) state=1 wrp=0xfffffe2cdfbfa940 ref=2 reqcnt=1 cr=5
s2u24:  scsa2usb_bulk_only_handle_error: req = 0xfffffe2cdfbfa9d0, cr = 0x5
s2u24:  scsa2usb_bulk_only_reset_recovery: scsa2usbp = 0xfffffe2cfa2ec000
s2u24:          bulk-only device-reset rval: 0
s2u24:          bulk-in pipe clear stall: 0
s2u24:          bulk-out pipe clear stall: 0
usbai:  usba_req_exc_cb: scsa2usb24: ph_data=0xfffffe2cf0429a78 (ep2) state=1 wrp=0xfffffe2cdfbfa940 ref=2 reqcnt=1 cr=5
s2u24:  scsa2usb_bulk_only_handle_error: req = 0xfffffe2cdfbfa9d0, cr = 0x5
s2u24:  scsa2usb_bulk_only_reset_recovery: scsa2usbp = 0xfffffe2cfa2ec000
s2u24:          bulk-only device-reset rval: 0
s2u24:          bulk-in pipe clear stall: 0
s2u24:          bulk-out pipe clear stall: 0
usbai:  usba_req_exc_cb: scsa2usb24: ph_data=0xfffffe2cf0429a78 (ep2) state=1 wrp=0xfffffe2cdfbfa940 ref=2 reqcnt=1 cr=5
s2u24:  scsa2usb_bulk_only_handle_error: req = 0xfffffe2cdfbfa9d0, cr = 0x5
s2u24:  scsa2usb_bulk_only_reset_recovery: scsa2usbp = 0xfffffe2cfa2ec000
s2u24:          bulk-only device-reset rval: 0
s2u24:          bulk-in pipe clear stall: 0
s2u24:          bulk-out pipe clear stall: 0
usbai:  usba_req_exc_cb: scsa2usb24: ph_data=0xfffffe2cf0429a78 (ep2) state=1 wrp=0xfffffe2cdfbfa940 ref=2 reqcnt=1 cr=5
s2u24:  scsa2usb_bulk_only_handle_error: req = 0xfffffe2cdfbfa9d0, cr = 0x5
s2u24:  scsa2usb_bulk_only_reset_recovery: scsa2usbp = 0xfffffe2cfa2ec000
s2u24:          bulk-only device-reset rval: 0
s2u24:          bulk-in pipe clear stall: 0
s2u24:          bulk-out pipe clear stall: 0
usbai:  usba_req_exc_cb: scsa2usb24: ph_data=0xfffffe2cf0429a78 (ep2) state=1 wrp=0xfffffe2cdfbfa940 ref=2 reqcnt=1 cr=5
s2u24:  scsa2usb_bulk_only_handle_error: req = 0xfffffe2cdfbfa9d0, cr = 0x5
s2u24:  scsa2usb_bulk_only_reset_recovery: scsa2usbp = 0xfffffe2cfa2ec000
s2u24:          bulk-only device-reset rval: 0
s2u24:          bulk-in pipe clear stall: 0
s2u24:          bulk-out pipe clear stall: 0
usbai:  usba_req_exc_cb: scsa2usb24: ph_data=0xfffffe2cf0429a78 (ep2) state=1 wrp=0xfffffe2cdfbfa940 ref=2 reqcnt=1 cr=5
s2u24:  scsa2usb_bulk_only_handle_error: req = 0xfffffe2cdfbfa9d0, cr = 0x5
s2u24:  scsa2usb_bulk_only_reset_recovery: scsa2usbp = 0xfffffe2cfa2ec000
s2u24:          bulk-only device-reset rval: 0
s2u24:          bulk-in pipe clear stall: 0
s2u24:          bulk-out pipe clear stall: 0
usbai:  usba_req_exc_cb: scsa2usb24: ph_data=0xfffffe2cf0429a78 (ep2) state=1 wrp=0xfffffe2cdfbfa940 ref=2 reqcnt=1 cr=5
s2u24:  scsa2usb_bulk_only_handle_error: req = 0xfffffe2cdfbfa9d0, cr = 0x5
s2u24:  scsa2usb_bulk_only_reset_recovery: scsa2usbp = 0xfffffe2cfa2ec000
s2u24:          bulk-only device-reset rval: 0
s2u24:          bulk-in pipe clear stall: 0
s2u24:          bulk-out pipe clear stall: 0
usbai:  usba_req_exc_cb: scsa2usb24: ph_data=0xfffffe2cf0429a78 (ep2) state=1 wrp=0xfffffe2cdfbfa940 ref=2 reqcnt=1 cr=5
s2u24:  scsa2usb_bulk_only_handle_error: req = 0xfffffe2cdfbfa9d0, cr = 0x5
s2u24:  scsa2usb_bulk_only_reset_recovery: scsa2usbp = 0xfffffe2cfa2ec000
s2u24:          bulk-only device-reset rval: 0
s2u24:          bulk-in pipe clear stall: 0
s2u24:          bulk-out pipe clear stall: 0
usbai:  usba_req_exc_cb: scsa2usb24: ph_data=0xfffffe2cf0429a78 (ep2) state=1 wrp=0xfffffe2cdfbfa940 ref=2 reqcnt=1 cr=5
s2u24:  scsa2usb_bulk_only_handle_error: req = 0xfffffe2cdfbfa9d0, cr = 0x5
s2u24:  scsa2usb_bulk_only_reset_recovery: scsa2usbp = 0xfffffe2cfa2ec000
s2u24:          bulk-only device-reset rval: 0
s2u24:          bulk-in pipe clear stall: 0
s2u24:          bulk-out pipe clear stall: 0
usbai:  usba_req_exc_cb: scsa2usb24: ph_data=0xfffffe2cf0429a78 (ep2) state=1 wrp=0xfffffe2cdfbfa940 ref=2 reqcnt=1 cr=5
s2u24:  scsa2usb_bulk_only_handle_error: req = 0xfffffe2cdfbfa9d0, cr = 0x5
s2u24:  scsa2usb_bulk_only_reset_recovery: scsa2usbp = 0xfffffe2cfa2ec000
s2u24:          bulk-only device-reset rval: 0
s2u24:          bulk-in pipe clear stall: 0
s2u24:          bulk-out pipe clear stall: 0
usbai:  usba_req_exc_cb: scsa2usb24: ph_data=0xfffffe2cf0429a78 (ep2) state=1 wrp=0xfffffe2cdfbfa940 ref=2 reqcnt=1 cr=5
s2u24:  scsa2usb_bulk_only_handle_error: req = 0xfffffe2cdfbfa9d0, cr = 0x5
s2u24:  scsa2usb_bulk_only_reset_recovery: scsa2usbp = 0xfffffe2cfa2ec000
s2u24:          bulk-only device-reset rval: 0
s2u24:          bulk-in pipe clear stall: 0
s2u24:          bulk-out pipe clear stall: 0
usbai:  usba_req_exc_cb: scsa2usb24: ph_data=0xfffffe2cf0429a78 (ep2) state=1 wrp=0xfffffe2cdfbfa940 ref=2 reqcnt=1 cr=5
s2u24:  scsa2usb_bulk_only_handle_error: req = 0xfffffe2cdfbfa9d0, cr = 0x5
s2u24:  scsa2usb_bulk_only_reset_recovery: scsa2usbp = 0xfffffe2cfa2ec000
s2u24:          bulk-only device-reset rval: 0
s2u24:          bulk-in pipe clear stall: 0
s2u24:          bulk-out pipe clear stall: 0
usbai:  usba_req_exc_cb: scsa2usb24: ph_data=0xfffffe2cf0429a78 (ep2) state=1 wrp=0xfffffe2cdfbfa940 ref=2 reqcnt=1 cr=5
s2u24:  scsa2usb_bulk_only_handle_error: req = 0xfffffe2cdfbfa9d0, cr = 0x5
s2u24:  scsa2usb_bulk_only_reset_recovery: scsa2usbp = 0xfffffe2cfa2ec000
s2u24:          bulk-only device-reset rval: 0
s2u24:          bulk-in pipe clear stall: 0
s2u24:          bulk-out pipe clear stall: 0
usbai:  usba_req_exc_cb: scsa2usb24: ph_data=0xfffffe2cf0429a78 (ep2) state=1 wrp=0xfffffe2cd3fb08c0 ref=2 reqcnt=1 cr=5
s2u24:  scsa2usb_bulk_only_handle_error: req = 0xfffffe2cd3fb0950, cr = 0x5
s2u24:  scsa2usb_bulk_only_reset_recovery: scsa2usbp = 0xfffffe2cfa2ec000
s2u24:          bulk-only device-reset rval: 0
s2u24:          bulk-in pipe clear stall: 0
s2u24:          bulk-out pipe clear stall: 0
usbai:  usba_req_exc_cb: scsa2usb24: ph_data=0xfffffe2cf0429a78 (ep2) state=1 wrp=0xfffffe2cd199bbb0 ref=2 reqcnt=1 cr=5
s2u24:  scsa2usb_bulk_only_handle_error: req = 0xfffffe2cd199bc40, cr = 0x5
s2u24:  scsa2usb_bulk_only_reset_recovery: scsa2usbp = 0xfffffe2cfa2ec000
s2u24:          bulk-only device-reset rval: 0
s2u24:          bulk-in pipe clear stall: 0
s2u24:          bulk-out pipe clear stall: 0
usbai:  usba_req_exc_cb: scsa2usb24: ph_data=0xfffffe2cf0429a78 (ep2) state=1 wrp=0xfffffe2cd159de08 ref=2 reqcnt=1 cr=5
s2u24:  scsa2usb_bulk_only_handle_error: req = 0xfffffe2cd159de98, cr = 0x5
s2u24:  scsa2usb_bulk_only_reset_recovery: scsa2usbp = 0xfffffe2cfa2ec000
s2u24:          bulk-only device-reset rval: 0
s2u24:          bulk-in pipe clear stall: 0
s2u24:          bulk-out pipe clear stall: 0
usbai:  usba_req_exc_cb: scsa2usb24: ph_data=0xfffffe2cf0429a78 (ep2) state=1 wrp=0xfffffe2cd159de08 ref=2 reqcnt=1 cr=5
s2u24:  scsa2usb_bulk_only_handle_error: req = 0xfffffe2cd159de98, cr = 0x5
s2u24:  scsa2usb_bulk_only_reset_recovery: scsa2usbp = 0xfffffe2cfa2ec000
s2u24:          bulk-only device-reset rval: 0
s2u24:          bulk-in pipe clear stall: 0
s2u24:          bulk-out pipe clear stall: 0
usbai:  usba_req_exc_cb: scsa2usb24: ph_data=0xfffffe2cf0429a78 (ep2) state=1 wrp=0xfffffe2cd159de08 ref=2 reqcnt=1 cr=5
s2u24:  scsa2usb_bulk_only_handle_error: req = 0xfffffe2cd159de98, cr = 0x5
s2u24:  scsa2usb_bulk_only_reset_recovery: scsa2usbp = 0xfffffe2cfa2ec000
s2u24:          bulk-only device-reset rval: 0
s2u24:          bulk-in pipe clear stall: 0
s2u24:          bulk-out pipe clear stall: 0
usbai:  usba_req_exc_cb: scsa2usb24: ph_data=0xfffffe2cf0429a78 (ep2) state=1 wrp=0xfffffe2cd13f14e8 ref=2 reqcnt=1 cr=5
s2u24:  scsa2usb_bulk_only_handle_error: req = 0xfffffe2cd13f1578, cr = 0x5
s2u24:  scsa2usb_bulk_only_reset_recovery: scsa2usbp = 0xfffffe2cfa2ec000
s2u24:          bulk-only device-reset rval: 0
s2u24:          bulk-in pipe clear stall: 0
s2u24:          bulk-out pipe clear stall: 0
usbai:  usba_req_exc_cb: scsa2usb24: ph_data=0xfffffe2cf0429a78 (ep2) state=1 wrp=0xfffffe2cde4e96b8 ref=2 reqcnt=1 cr=5
s2u24:  scsa2usb_bulk_only_handle_error: req = 0xfffffe2cde4e9748, cr = 0x5
s2u24:  scsa2usb_bulk_only_reset_recovery: scsa2usbp = 0xfffffe2cfa2ec000
s2u24:          bulk-only device-reset rval: 0
s2u24:          bulk-in pipe clear stall: 0
s2u24:          bulk-out pipe clear stall: 0
usbai:  usba_req_exc_cb: scsa2usb24: ph_data=0xfffffe2cf0429a78 (ep2) state=1 wrp=0xfffffe2cd13eb2b0 ref=2 reqcnt=1 cr=5
s2u24:  scsa2usb_bulk_only_handle_error: req = 0xfffffe2cd13eb340, cr = 0x5
s2u24:  scsa2usb_bulk_only_reset_recovery: scsa2usbp = 0xfffffe2cfa2ec000
s2u24:          bulk-only device-reset rval: 0
s2u24:          bulk-in pipe clear stall: 0
s2u24:          bulk-out pipe clear stall: 0
usbai:  usba_req_exc_cb: scsa2usb24: ph_data=0xfffffe2cf0429a78 (ep2) state=1 wrp=0xfffffe2cd13eb2b0 ref=2 reqcnt=1 cr=5
s2u24:  scsa2usb_bulk_only_handle_error: req = 0xfffffe2cd13eb340, cr = 0x5
s2u24:  scsa2usb_bulk_only_reset_recovery: scsa2usbp = 0xfffffe2cfa2ec000
s2u24:          bulk-only device-reset rval: 0
s2u24:          bulk-in pipe clear stall: 0
s2u24:          bulk-out pipe clear stall: 0
usbai:  usba_req_exc_cb: scsa2usb24: ph_data=0xfffffe2cf0429a78 (ep2) state=1 wrp=0xfffffe2cd13eb2b0 ref=2 reqcnt=1 cr=5
s2u24:  scsa2usb_bulk_only_handle_error: req = 0xfffffe2cd13eb340, cr = 0x5
s2u24:  scsa2usb_bulk_only_reset_recovery: scsa2usbp = 0xfffffe2cfa2ec000
s2u24:          bulk-only device-reset rval: 0
s2u24:          bulk-in pipe clear stall: 0
s2u24:          bulk-out pipe clear stall: 0
usbai:  usba_req_exc_cb: scsa2usb24: ph_data=0xfffffe2cf0429a78 (ep2) state=1 wrp=0xfffffe2cd199bbb0 ref=2 reqcnt=1 cr=5
s2u24:  scsa2usb_bulk_only_handle_error: req = 0xfffffe2cd199bc40, cr = 0x5
s2u24:  scsa2usb_bulk_only_reset_recovery: scsa2usbp = 0xfffffe2cfa2ec000
s2u24:          bulk-only device-reset rval: 0
s2u24:          bulk-in pipe clear stall: 0
s2u24:          bulk-out pipe clear stall: 0
usbai:  usba_req_exc_cb: scsa2usb24: ph_data=0xfffffe2cf0429a78 (ep2) state=1 wrp=0xfffffe2cdfbfa860 ref=2 reqcnt=1 cr=5
s2u24:  scsa2usb_bulk_only_handle_error: req = 0xfffffe2cdfbfa8f0, cr = 0x5
s2u24:  scsa2usb_bulk_only_reset_recovery: scsa2usbp = 0xfffffe2cfa2ec000
s2u24:          bulk-only device-reset rval: 0
s2u24:          bulk-in pipe clear stall: 0
s2u24:          bulk-out pipe clear stall: 0
xusb2:  hubd_resume_port: port=6 not suspended
xusb2:  hubd_resume_port: port=10 not suspended
xusb2:  hubd_resume_port: port=3 not suspended
xusb2:  hubd_resume_port: port=6 not suspended
xusb2:  hubd_resume_port: port=10 not suspended
xusb2:  hubd_resume_port: port=3 not suspended
xusb2:  hubd_resume_port: port=6 not suspended
xusb2:  hubd_resume_port: port=10 not suspended
xusb2:  hubd_resume_port: port=3 not suspended
hid34:  hid_pm_busy_component failed: 0
hid34:  hid_pm_busy_component failed: 0
hid34:  hid_pm_busy_component failed: 0
hid34:  hid_pm_busy_component failed: 0
hid34:  hid_pm_busy_component failed: 0
hid34:  hid_pm_busy_component failed: 0
hid34:  hid_pm_busy_component failed: 0
hid34:  hid_pm_busy_component failed: 0
xusb2:  hubd_resume_port: port=6 not suspended
xusb2:  hubd_resume_port: port=10 not suspended
xusb2:  hubd_resume_port: port=3 not suspended
hid34:  hid_pm_busy_component failed: 0
hid34:  hid_pm_busy_component failed: 0
hid34:  hid_pm_busy_component failed: 0
hid34:  hid_pm_busy_component failed: 0
hid34:  hid_pm_busy_component failed: 0
hid34:  hid_pm_busy_component failed: 0
hid34:  hid_pm_busy_component failed: 0
hid34:  hid_pm_busy_component failed: 0
hid34:  hid_pm_busy_component failed: 0
hid34:  hid_pm_busy_component failed: 0
hid34:  hid_pm_busy_component failed: 0
hid34:  hid_pm_busy_component failed: 0
hid34:  hid_pm_busy_component failed: 0
hid34:  hid_pm_busy_component failed: 0
xusb2:  hubd_resume_port: port=6 not suspended
xusb2:  hubd_resume_port: port=10 not suspended
xusb2:  hubd_resume_port: port=3 not suspended
usbai:  usba_req_exc_cb: scsa2usb24: ph_data=0xfffffe2cd66b9c10 (ep2) state=1 wrp=0xfffffe2cd0034730 ref=2 reqcnt=1 cr=5
s2u24:  scsa2usb_bulk_only_handle_error: req = 0xfffffe2cd00347c0, cr = 0x5
s2u24:  scsa2usb_bulk_only_reset_recovery: scsa2usbp = 0xfffffe2cfa2ec000
s2u24:          bulk-only device-reset rval: 0
s2u24:          bulk-in pipe clear stall: 0
s2u24:          bulk-out pipe clear stall: 0
hid34:  hid_pm_busy_component failed: 0
hid34:  hid_pm_busy_component failed: 0
xusb2:  hubd_resume_port: port=6 not suspended
xusb2:  hubd_resume_port: port=10 not suspended
xusb2:  hubd_resume_port: port=3 not suspended
hid34:  hid_pm_busy_component failed: 0
hid34:  hid_pm_busy_component failed: 0
>>>>

Actions #7

Updated by Stephan Althaus 4 months ago

This issue related to my SDCard-Reader is solved with #14944.
However, sometimes, my mouse stops working, dmesg says:

Oct 16 13:13:58 dell7720 xhci: [ID 902155 kern.info] NOTICE: xhci2: xhci stop endpoint command (2)/slot (10) in wrong state: 19
Oct 16 13:13:58 dell7720 xhci: [ID 617155 kern.info] NOTICE: xhci2: endpoint is in state 3

Re-plug of the mouse device helps. Sometimes it is more seldom, sometimes multiple times per minute, then for hours it is ok :-/

Maybe it is related to my hardware - but linux and windows are ok ith it. Maybe they do a reset in this cases, i don't know..

I did try using the mouse behind a USB Hub connected to a USB2 slot, but then the hub gets this error :-/
Standard USB 1.0 3-button mouse btw.

Oct 16 13:14:04 dell7720 usba: [ID 912658 kern.info] USB 2.0 device (usb46d,c05b) operating at low speed (USB 1.x) on USB 3.0 root hub: mouse@4, hid33 at bus address 4
Oct 16 13:14:04 dell7720 usba: [ID 349649 kern.info] Logitech USB Optical Mouse
Oct 16 13:14:04 dell7720 genunix: [ID 936769 kern.info] hid33 is /pci@0,0/pci1028,7b1@14/mouse@4
Oct 16 13:14:04 dell7720 genunix: [ID 408114 kern.info] /pci@0,0/pci1028,7b1@14/mouse@4 (hid33) online

Actions #8

Updated by Stephan Althaus 4 months ago

Regarded to XHCI and hotplug,
the re-connecting of mouse and keyboard works well on OI within X/mate, that is very good!

tail -f /var/adm/messages shows, that when there is the wrong state on the USB port with the mouse,
the USB port ist marked "online" automagically, but X does not get a signal that it is available again.

Does someone familiar to XHCI have a debug script to dig into this?

Oct 21 08:49:46 dell7720 last message repeated 2 times
Oct 21 08:59:47 dell7720 apcupsd1218: [ID 702911 daemon.warning] Communications with UPS lost.
Oct 21 09:05:33 dell7720 xhci: [ID 902155 kern.info] NOTICE: xhci2: xhci stop endpoint command (2)/slot (23) in wrong state: 19
Oct 21 09:05:33 dell7720 xhci: [ID 617155 kern.info] NOTICE: xhci2: endpoint is in state 3
Oct 21 09:05:34 dell7720 genunix: [ID 408114 kern.info] /pci@0,0/pci1028,7b1@14/mouse@2 (hid39) online

Actions #9

Updated by Stephan Althaus 3 months ago

This is related to #11776, here it is not the keyboard but the mouse...
Mouse works from the start, the stops working - after re-connecting it works again.

I did not find a way to see the messages from system/hal yet.

Xorg.0.log contains this:

[ 33370.211] (II) config/hal: removing device mouse
[ 33370.212] (WW) mouse: cannot pop module 'usbms' off mouse device: Invalid argument
[ 33370.213] (II) UnloadModule: "mouse"
[ 33374.411] (II) config/hal: Adding input device mouse
[ 33374.411] (II) Using input driver 'mouse' for 'mouse'
[ 33374.411] () mouse: always reports core events
[ 33374.411] (
) Option "Protocol" "VUID"
[ 33374.411] () Option "Device" "/dev/usb/hid0"
[ 33374.411] (
) Option "StreamsModule" "usbms"
[ 33374.412] () mouse: Protocol: "VUID"
[ 33374.412] (
) mouse: always reports core events
[ 33374.412] (==) mouse: Emulate3Buttons, Emulate3Timeout: 50
[ 33374.412] () mouse: ZAxisMapping: buttons 4 and 5
[ 33374.412] (
) mouse: Buttons: 9
[ 33374.412] () Option "config_info" "hal:/org/freedesktop/Hal/devices/pci_0_0/pci1028_7b1_14/mouse_4_if0_33_logicaldev_input"
[ 33374.412] (II) XINPUT: Adding extended input device "mouse" (type: MOUSE, id 9)
[ 33374.412] (
) mouse: (accel) keeping acceleration scheme 1
[ 33374.412] () mouse: (accel) acceleration profile 0
[ 33374.412] (
) mouse: (accel) acceleration factor: 2.000
[ 33374.412] (**) mouse: (accel) acceleration threshold: 4

dbus-monitor --system shows something that i will try to examine tomorrow

  1. dbus-monitor --system|grep Hal
    string "org.freedesktop.Hal"
    string "type='signal',interface='org.freedesktop.Hal.Manager',sender='org.freedesktop.Hal',path='/org/freedesktop/Hal/Manager'"
    method call time=1666731247.518723 sender=:1.61 -> destination=org.freedesktop.Hal serial=24 path=/org/freedesktop/Hal/Manager; interface=org.freedesktop.Hal.Manager; member=FindDeviceStringMatch
    string "type='signal',interface='org.freedesktop.Hal.Manager',sender='org.freedesktop.Hal',path='/org/freedesktop/Hal/Manager'"
    signal time=1666731283.017150 sender=:1.123 -> destination=(null destination) serial=105 path=/org/freedesktop/Hal/Manager; interface=org.freedesktop.Hal.Manager; member=DeviceRemoved
Actions #10

Updated by Stephan Althaus 3 months ago

Shortly after the mouse stops working, i have still the deive in the list of usb devices:

  1. mdb -ke '::prtusb'
    INDEX DRIVER INST NODE GEN VID.PID PRODUCT
    1 xhci 2 pci1028,7b1 3.0 0000.0000 No Product String
    2 usb_mid 57 device 2.0 1395.0099 Sennheiser PC 8.2 USB
    3 usb_mid 35 device 1.1 0bf8.100c FSC KBPC PX
    4 hubd 18 hub 2.0 413c.2513 No Product String
    5 usb_mid 32 device 2.0 8087.0a2b No Product String
    6 hubd 19 hub 2.0 413c.2134 USB2134
    7 usb_mid 33 device 1.1 0a5c.5832 5880
    8 hid 36 mouse 2.0 046d.c05b USB Optical Mouse

however, the XHCI port is stopped:

  1. mdb -ke '::xhci_device'
    Logitech - USB Optical Mouse
    Port 03 | Slot 13 | # Endpoints 02
    EP Type State Head Tail
    0 CONTROL Stopped 0x2e 0x2e
    2 INTR IN Stopped 0xd7 0xd7

dmesg says the device is "online" - that is not correct if the XHCI device is stopped..

  1. dmesg
    Oct 26 10:13:03 dell7720 xhci: [ID 902155 kern.info] NOTICE: xhci2: xhci stop endpoint command (2)/slot (13) in wrong state: 19
    Oct 26 10:13:03 dell7720 xhci: [ID 617155 kern.info] NOTICE: xhci2: endpoint is in state 3
    Oct 26 10:13:03 dell7720 genunix: [ID 408114 kern.info] /pci@0,0/pci1028,7b1@14/mouse@3 (hid36) online

Is there a way to re-activate the XHCI device in this state ? maybe automagically ?

Actions

Also available in: Atom PDF