Date: Tue, 12 Apr 2022 21:47:34 +0000 From: "Poul-Henning Kamp" <phk@phk.freebsd.dk> To: mahesh mv <maheshm_v@yahoo.com> Cc: "freebsd-hackers@freebsd.org" <freebsd-hackers@freebsd.org> Subject: Re: xhci USB transaction error and subsequent recovery mechanism on Freebsd stable/12 Message-ID: <202204122147.23CLlYjE014614@critter.freebsd.dk> In-Reply-To: <1524993805.98701.1649776236883@mail.yahoo.com> References: <1524993805.98701.1649776236883.ref@mail.yahoo.com> <1524993805.98701.1649776236883@mail.yahoo.com>
next in thread | previous in thread | raw e-mail | index | archive | help
--------
mahesh mv writes:
> READ(10) errors. The READ(10) error recovers with in couple of retries m=
ost
> of the times but few cases we have observed that the read retries gets e=
xhausted and [...]
About once a week I see the same general phenomena on a RockPro64 running =
13.0-RELEASE-p6.
After "usbconfig -d 5.7 reset" and "zpool clear" the ZFS mirror is back in=
operation.
The other drive in the mirror, (-d 5.4) never does this.
This server has a twin ("keith") with different USB disks, never seen it t=
here either.
Despite spending a fair amount of time on it, I have never been
able to find any hints of hardware trouble (ie: USB drive, USB cables
or the industrial-grade powered USB-hub.)
Usbconfig on the system in question:
ugen0.1: <Generic EHCI root HUB> at usbus0, cfg=3D0 md=3DHOST spd=3DHIGH =
(480Mbps) pwr=3DSAVE (0mA)
ugen2.1: <Generic EHCI root HUB> at usbus2, cfg=3D0 md=3DHOST spd=3DHIGH =
(480Mbps) pwr=3DSAVE (0mA)
ugen1.1: <Generic OHCI root HUB> at usbus1, cfg=3D0 md=3DHOST spd=3DFULL =
(12Mbps) pwr=3DSAVE (0mA)
ugen5.1: <Synopsys XHCI root HUB> at usbus5, cfg=3D0 md=3DHOST spd=3DSUPE=
R (5.0Gbps) pwr=3DSAVE (0mA)
ugen4.1: <Synopsys XHCI root HUB> at usbus4, cfg=3D0 md=3DHOST spd=3DSUPE=
R (5.0Gbps) pwr=3DSAVE (0mA)
ugen3.1: <Generic OHCI root HUB> at usbus3, cfg=3D0 md=3DHOST spd=3DFULL =
(12Mbps) pwr=3DSAVE (0mA)
ugen5.2: <vendor 0x1a40 USB 2.0 Hub MTT> at usbus5, cfg=3D0 md=3DHOST spd=
=3DHIGH (480Mbps) pwr=3DSAVE (100mA)
ugen5.3: <FTDI TTL-234X-5V> at usbus5, cfg=3D0 md=3DHOST spd=3DFULL (12Mb=
ps) pwr=3DON (90mA)
ugen5.4: <Seagate Expansion> at usbus5, cfg=3D0 md=3DHOST spd=3DHIGH (480=
Mbps) pwr=3DON (500mA)
ugen5.5: <FTDI USB-RS485 Cable> at usbus5, cfg=3D0 md=3DHOST spd=3DFULL (=
12Mbps) pwr=3DON (300mA)
ugen5.6: <ASIX Elec. Corp. AX88178> at usbus5, cfg=3D0 md=3DHOST spd=3DHI=
GH (480Mbps) pwr=3DON (450mA)
ugen5.7: <LaCie Rugged USB-C> at usbus5, cfg=3D0 md=3DHOST spd=3DHIGH (48=
0Mbps) pwr=3DON (500mA)
Most recent event was yesterday:
Apr 11 03:01:04 <0.2> mick kernel: (da1:umass-sim1:1:0:0): READ(10). CDB:=
28 00 08 42 8f 60 00 00 08 00 =
Apr 11 03:01:04 <0.2> mick kernel: (da1:umass-sim1:1:0:0): CAM status: CC=
B request completed with an error
Apr 11 03:01:04 <0.2> mick kernel: (da1:umass-sim1:1:0:0): Retrying comma=
nd, 3 more tries remain
Apr 11 03:01:04 <0.2> mick kernel: (da1:umass-sim1:1:0:0): READ(10). CDB:=
28 00 08 42 8f 60 00 00 08 00 =
Apr 11 03:01:04 <0.2> mick kernel: (da1:umass-sim1:1:0:0): CAM status: CC=
B request completed with an error
Apr 11 03:01:04 <0.2> mick kernel: (da1:umass-sim1:1:0:0): Retrying comma=
nd, 2 more tries remain
Apr 11 03:01:05 <0.2> mick kernel: (da1:umass-sim1:1:0:0): READ(10). CDB:=
28 00 08 42 8f 60 00 00 08 00 =
Apr 11 03:01:05 <0.2> mick kernel: (da1:umass-sim1:1:0:0): CAM status: CC=
B request completed with an error
Apr 11 03:01:05 <0.2> mick kernel: (da1:umass-sim1:1:0:0): Retrying comma=
nd, 1 more tries remain
Apr 11 03:01:05 <0.2> mick kernel: (da1:umass-sim1:1:0:0): READ(10). CDB:=
28 00 08 42 8f 60 00 00 08 00 =
Apr 11 03:01:05 <0.2> mick kernel: (da1:umass-sim1:1:0:0): CAM status: CC=
B request completed with an error
Apr 11 03:01:05 <0.2> mick kernel: (da1:umass-sim1:1:0:0): Retrying comma=
nd, 0 more tries remain
Apr 11 03:01:06 <0.2> mick kernel: (da1:umass-sim1:1:0:0): READ(10). CDB:=
28 00 08 42 8f 60 00 00 08 00 =
Apr 11 03:01:06 <0.2> mick kernel: (da1:umass-sim1:1:0:0): CAM status: CC=
B request completed with an error
Apr 11 03:01:06 <0.2> mick kernel: (da1:umass-sim1:1:0:0): Error 5, Retri=
es exhausted
Apr 11 03:01:06 <0.2> mick kernel: (da1:umass-sim1:1:0:0): READ(10). CDB:=
28 00 00 00 02 10 00 00 10 00 =
Apr 11 03:01:06 <0.2> mick kernel: (da1:umass-sim1:1:0:0): CAM status: CC=
B request completed with an error
Apr 11 03:01:06 <0.2> mick kernel: (da1:umass-sim1:1:0:0): Retrying comma=
nd, 3 more tries remain
Apr 11 03:01:07 <0.2> mick kernel: (da1:umass-sim1:1:0:0): READ(10). CDB:=
28 00 00 00 02 10 00 00 10 00 =
Apr 11 03:01:07 <0.2> mick kernel: (da1:umass-sim1:1:0:0): CAM status: CC=
B request completed with an error
Apr 11 03:01:07 <0.2> mick kernel: (da1:umass-sim1:1:0:0): Retrying comma=
nd, 2 more tries remain
Apr 11 03:01:07 <0.2> mick kernel: (da1:umass-sim1:1:0:0): READ(10). CDB:=
28 00 00 00 02 10 00 00 10 00 =
Apr 11 03:01:07 <0.2> mick kernel: (da1:umass-sim1:1:0:0): CAM status: CC=
B request completed with an error
Apr 11 03:01:07 <0.2> mick kernel: (da1:umass-sim1:1:0:0): Retrying comma=
nd, 1 more tries remain
Apr 11 03:01:08 <0.2> mick kernel: (da1:umass-sim1:1:0:0): READ(10). CDB:=
28 00 00 00 02 10 00 00 10 00 =
Apr 11 03:01:08 <0.2> mick kernel: (da1:umass-sim1:1:0:0): CAM status: CC=
B request completed with an error
Apr 11 03:01:08 <0.2> mick kernel: (da1:umass-sim1:1:0:0): Retrying comma=
nd, 0 more tries remain
Apr 11 03:01:08 <0.2> mick kernel: (da1:umass-sim1:1:0:0): READ(10). CDB:=
28 00 00 00 02 10 00 00 10 00 =
Apr 11 03:01:08 <0.2> mick kernel: (da1:umass-sim1:1:0:0): CAM status: CC=
B request completed with an error
Apr 11 03:01:08 <0.2> mick kernel: (da1:umass-sim1:1:0:0): Error 5, Retri=
es exhausted
Apr 11 03:01:09 <23.4> mick ZFS[48383]: vdev I/O failure, zpool=3Dmick pa=
th=3D/dev/da1 offset=3D4000786423808 size=3D8192 error=3D5
Apr 11 03:01:09 <23.4> mick ZFS[48387]: vdev I/O failure, zpool=3Dmick pa=
th=3D/dev/da1 offset=3D4000786685952 size=3D8192 error=3D5
Apr 11 03:01:09 <23.4> mick ZFS[48391]: vdev I/O failure, zpool=3Dmick pa=
th=3D/dev/da1 offset=3D270336 size=3D8192 error=3D5
Apr 11 03:01:09 <23.3> mick ZFS[48395]: vdev probe failure, zpool=3Dmick =
path=3D/dev/da1
Apr 11 03:01:09 <0.2> mick kernel: (da1:umass-sim1:1:0:0): READ(10). CDB:=
28 00 00 00 02 10 00 00 10 00 =
Apr 11 03:01:09 <0.2> mick kernel: (da1:umass-sim1:1:0:0): CAM status: CC=
B request completed with an error
Apr 11 03:01:09 <0.2> mick kernel: (da1:umass-sim1:1:0:0): Retrying comma=
nd, 3 more tries remain
Apr 11 03:01:10 <0.2> mick kernel: (da1:umass-sim1:1:0:0): READ(10). CDB:=
28 00 00 00 02 10 00 00 10 00 =
Apr 11 03:01:10 <0.2> mick kernel: (da1:umass-sim1:1:0:0): CAM status: CC=
B request completed with an error
Apr 11 03:01:10 <0.2> mick kernel: (da1:umass-sim1:1:0:0): Retrying comma=
nd, 2 more tries remain
Apr 11 03:01:10 <0.2> mick kernel: (da1:umass-sim1:1:0:0): READ(10). CDB:=
28 00 00 00 02 10 00 00 10 00 =
Apr 11 03:01:10 <0.2> mick kernel: (da1:umass-sim1:1:0:0): CAM status: CC=
B request completed with an error
Apr 11 03:01:10 <0.2> mick kernel: (da1:umass-sim1:1:0:0): Retrying comma=
nd, 1 more tries remain
Apr 11 03:01:11 <0.2> mick kernel: (da1:umass-sim1:1:0:0): READ(10). CDB:=
28 00 00 00 02 10 00 00 10 00 =
Apr 11 03:01:11 <0.2> mick kernel: (da1:umass-sim1:1:0:0): CAM status: CC=
B request completed with an error
Apr 11 03:01:11 <0.2> mick kernel: (da1:umass-sim1:1:0:0): Retrying comma=
nd, 0 more tries remain
Apr 11 03:01:11 <0.2> mick kernel: (da1:umass-sim1:1:0:0): READ(10). CDB:=
28 00 00 00 02 10 00 00 10 00 =
Apr 11 03:01:11 <0.2> mick kernel: (da1:umass-sim1:1:0:0): CAM status: CC=
B request completed with an error
Apr 11 03:01:11 <0.2> mick kernel: (da1:umass-sim1:1:0:0): Error 5, Retri=
es exhausted
Apr 11 03:01:11 <23.3> mick ZFS[48399]: vdev probe failure, zpool=3Dmick =
path=3D/dev/da1
Apr 11 03:01:11 <23.5> mick ZFS[48403]: vdev state changed, pool_guid=3D7=
854867548980906247 vdev_guid=3D14874313982910104056
Apr 11 03:01:16 <0.2> mick kernel: (da1:umass-sim1:1:0:0): got CAM status=
0x44
Apr 11 03:01:16 <0.2> mick kernel: (da1:umass-sim1:1:0:0): fatal error, f=
ailed to attach to device
Apr 11 03:01:16 <0.2> mick kernel: da1 at umass-sim1 bus 1 scbus1 target =
0 lun 0
Apr 11 03:01:16 <0.2> mick kernel: da1: <LaCie Rugged USB-C 1153> s/n 00=
00NL6AE1LV detached
Apr 11 03:01:16 <0.2> mick kernel: (da1:umass-sim1:1:0:0): Periph destroy=
ed
Poul-Henning
PS: "completed with an error" without any details about the error is not v=
ery helpful for debugging...
-- =
Poul-Henning Kamp | UNIX since Zilog Zeus 3.20
phk@FreeBSD.ORG | TCP/IP since RFC 956
FreeBSD committer | BSD since 4.3-tahoe =
Never attribute to malice what can adequately be explained by incompetence=
.
Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?202204122147.23CLlYjE014614>