On Sat 29/07/2017 17:42, Tinker wrote:
> Bjorn,
>
> mpi@ and others would love to get a copy of your system's XHCI stack's debug
> output.
>
> Can you please enable XHCI_DEBUG in your kernel and post the output.
>
> Also please see some further notes here
> https://marc.info/?l=openbsd-misc&m=149658807922576&w=2 and here
> https://marc.info/?l=openbsd-misc&m=149641168519652&w=2 .
>
> You, me and some other people need to document what works and not and submit
> the logs.
>
> Please share the debug log reports and also what steps you took to produce
> them!
Output from a kernel compiled with XHCI_DEBUG is enclosed below. Steps to
reproduce (using an encrypted, external USB drive, that tests OK on USB2):
1.) Power-on system with external drive connected to USB 3.0 port;
2.) bioctl -c C -l ${_device} softraid0
3.) mount ${_device} /mnt
4.) rsync -av ${_files} /mnt/.
After step 4 a couple of files are copied and the process halts. As stated in
my previous mail the system is still responsive however umounting of the drive
is not possible, and a hard reset is required.
Output from XHCI_DEBUG
xhci0 at pci5 dev 0 function 0 "Renesas uPD720201 xHCI" rev 0x03: msi
xhci0: xHCI version 1.0
xhci0: CAPLENGTH=0x20
xhci0: DOORBELL=0x800
xhci0: RUNTIME=0x600
xhci0: 64 bytes context
xhci0: supported page size 0x00000001
xhci0: 6 ports and 32 slots
xhci0: 4 scratch pages
usb1 at xhci0: USB revision 3.0
xhci0: DCBAAP=00x97a0000
xhci0: CRCR=00 (00000000097a1000)
xhci0: ERSTBA=00xf1dc9000
xhci0: ERDP=00x97a2000
xhci0: USBCMD=0x5
xhci0: IMAN=0x2
xhci0: port=2 change=0x04
xhci0: port=2 change=0x04
xhci0: xhci_cmd_slot_control
xhci0: dev 1, input=0xffffff00097c0000 slot=0xffffff00097c0040
ep0=0xffffff00097c0080
xhci0: dev 1, setting DCBAA to 0x00000000097c1000
xhci0: xhci_cmd_set_address BSR=1
xhci0: xhci_cmd_set_address BSR=0
xhci0: dev 1 addr 1
xhci0: xhci_cmd_configure_ep dev 1
xhci0: xhci_cmd_configure_ep dev 1
xhci0: xhci_cmd_reset_ep_async dev 1 dci 3
xhci0: xhci_cmd_set_tr_deq_async dev 1 dci 3
xhci0: xhci_cmd_reset_ep_async dev 1 dci 3
xhci0: xhci_cmd_set_tr_deq_async dev 1 dci 3
xhci0: xhci_cmd_reset_ep_async dev 1 dci 3
xhci0: xhci_cmd_set_tr_deq_async dev 1 dci 3
xhci0: xhci_cmd_reset_ep_async dev 1 dci 3
xhci0: xhci_cmd_set_tr_deq_async dev 1 dci 3
xhci0: xhci_cmd_reset_ep_async dev 1 dci 3
xhci0: xhci_cmd_set_tr_deq_async dev 1 dci 3
xhci0: xhci_cmd_reset_ep_async dev 1 dci 3
xhci0: xhci_cmd_set_tr_deq_async dev 1 dci 3
xhci0: xhci_cmd_reset_ep_async dev 1 dci 3
xhci0: xhci_cmd_set_tr_deq_async dev 1 dci 3
xhci0: xhci_cmd_reset_ep_async dev 1 dci 3
xhci0: xhci_cmd_set_tr_deq_async dev 1 dci 3
xhci0: xhci_cmd_reset_ep_async dev 1 dci 3
xhci0: xhci_cmd_set_tr_deq_async dev 1 dci 3
xhci0: xhci_cmd_stop_ep dev 1 dci 4
xhci0: event error code=19, result=33 trb=0xffff800022185e80
(0x00000000097a1080 0x13000000 0x1008401<CYCLE>)
xhci0: error stopping endpoint
xhci0: xhci_cmd_set_tr_deq_async dev 1 dci 4
xhci0: xhci_cmd_stop_ep dev 1 dci 4
xhci0: event error code=19, result=33 trb=0xffff800022185e80
(0x00000000097a10a0 0x13000000 0x1008401<CYCLE>)
xhci0: error stopping endpoint
xhci0: xhci_cmd_set_tr_deq_async dev 1 dci 4
xhci0: xhci_cmd_stop_ep dev 1 dci 4
xhci0: event error code=19, result=33 trb=0xffff800022185e80
(0x00000000097a10c0 0x13000000 0x1008401<CYCLE>)
xhci0: error stopping endpoint
xhci0: xhci_cmd_set_tr_deq_async dev 1 dci 4
xhci0: xhci_cmd_stop_ep dev 1 dci 4
xhci0: event error code=19, result=33 trb=0xffff800022185e80
(0x00000000097a10e0 0x13000000 0x1008401<CYCLE>)
xhci0: error stopping endpoint
xhci0: xhci_cmd_set_tr_deq_async dev 1 dci 4
xhci0: xhci_cmd_stop_ep dev 1 dci 4
xhci0: event error code=19, result=33 trb=0xffff800022185e80
(0x00000000097a1010 0x13000000 0x1008401<CYCLE>)
xhci0: error stopping endpoint
xhci0: xhci_cmd_set_tr_deq_async dev 1 dci 4
xhci0: xhci_cmd_stop_ep dev 1 dci 4
xhci0: event error code=19, result=33 trb=0xffff800022185e80
(0x00000000097a1030 0x13000000 0x1008401<CYCLE>)
xhci0: error stopping endpoint
xhci0: xhci_cmd_set_tr_deq_async dev 1 dci 4
xhci0: xhci_cmd_stop_ep dev 1 dci 4
xhci0: event error code=19, result=33 trb=0xffff800022185e80
(0x00000000097a1050 0x13000000 0x1008401<CYCLE>)
xhci0: error stopping endpoint
xhci0: xhci_cmd_set_tr_deq_async dev 1 dci 4
xhci0: xhci_cmd_stop_ep dev 1 dci 4
xhci0: event error code=19, result=33 trb=0xffff800022185e80
(0x00000000097a1070 0x13000000 0x1008401<CYCLE>)
xhci0: error stopping endpoint
xhci0: xhci_cmd_set_tr_deq_async dev 1 dci 4
xhci0: xhci_cmd_stop_ep dev 1 dci 4
xhci0: event error code=19, result=33 trb=0xffff800022185e80
(0x00000000097a1090 0x13000000 0x1008401<CYCLE>)
xhci0: error stopping endpoint
xhci0: xhci_cmd_set_tr_deq_async dev 1 dci 4
xhci0: xhci_cmd_stop_ep dev 1 dci 4
xhci0: event error code=19, result=33 trb=0xffff800022185e80
(0x00000000097a10b0 0x13000000 0x1008401<CYCLE>)
xhci0: error stopping endpoint
xhci0: xhci_cmd_set_tr_deq_async dev 1 dci 4
xhci0: xhci_cmd_stop_ep dev 1 dci 4
xhci0: event error code=19, result=33 trb=0xffff800022185e80
(0x00000000097a10d0 0x13000000 0x1008401<CYCLE>)
xhci0: error stopping endpoint
xhci0: xhci_cmd_set_tr_deq_async dev 1 dci 4
xhci0: xhci_cmd_stop_ep dev 1 dci 4
xhci0: event error code=19, result=33 trb=0xffff800022185e80
(0x00000000097a1000 0x13000000 0x1008401<CYCLE>)
xhci0: error stopping endpoint
xhci0: xhci_cmd_set_tr_deq_async dev 1 dci 4
Output from dmesg
OpenBSD 6.1-current (GENERIC.MP) #1: Sat Jul 29 20:09:15 CEST 2017
b...@gateway.lan:/home/code/src/sys/arch/amd64/compile/GENERIC.MP
real mem = 4242419712 (4045MB)
avail mem = 4107472896 (3917MB)
mpath0 at root
scsibus0 at mpath0: 256 targets
mainbus0 at root
bios0 at mainbus0: SMBIOS rev. 2.7 @ 0xf3bdb000 (64 entries)
bios0: vendor HP version "J06" date 11/09/2013
bios0: HP ProLiant MicroServer Gen8
acpi0 at bios0: rev 2
acpi0: sleep states S0 S4 S5
acpi0: tables DSDT FACP SPCR MCFG HPET FFFF SPMI ERST APIC FFFF BERT HEST FFFF
FFFF SSDT SSDT SSDT SSDT SSDT
acpi0: wakeup devices PCI0(S4)
acpitimer0 at acpi0: 3579545 Hz, 24 bits
acpimcfg0 at acpi0 addr 0xf4000000, bus 0-63
acpihpet0 at acpi0: 14318179 Hz
acpimadt0 at acpi0 addr 0xfee00000: PC-AT compat
cpu0 at mainbus0: apid 0 (boot processor)
cpu0: Intel(R) Celeron(R) CPU G1610T @ 2.30GHz, 2295.10 MHz
cpu0:
FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SEP,MTRR,PGE,MCA,CMOV,PAT,PSE36,CFLUSH,DS,ACPI,MMX,FXSR,SSE,SSE2,SS,HTT,TM,PBE,SSE3,PCLMUL,DTES64,MWAIT,DS-CPL,VMX,EST,TM2,SSSE3,CX16,xTPR,PDCM,PCID,SSE4.1,SSE4.2,POPCNT,DEADLINE,XSAVE,NXE,RDTSCP,LONG,LAHF,PERF,ITSC,FSGSBASE,SMEP,ERMS,SENSOR,ARAT
cpu0: 256KB 64b/line 8-way L2 cache
cpu0: TSC frequency 2295104920 Hz
cpu0: smt 0, core 0, package 0
mtrr: Pentium Pro MTRR support, 10 var ranges, 88 fixed ranges
cpu0: apic clock running at 99MHz
cpu0: mwait min=64, max=64, C-substates=0.2.1.1, IBE
cpu1 at mainbus0: apid 2 (application processor)
cpu1: Intel(R) Celeron(R) CPU G1610T @ 2.30GHz, 2294.79 MHz
cpu1:
FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SEP,MTRR,PGE,MCA,CMOV,PAT,PSE36,CFLUSH,DS,ACPI,MMX,FXSR,SSE,SSE2,SS,HTT,TM,PBE,SSE3,PCLMUL,DTES64,MWAIT,DS-CPL,VMX,EST,TM2,SSSE3,CX16,xTPR,PDCM,PCID,SSE4.1,SSE4.2,POPCNT,DEADLINE,XSAVE,NXE,RDTSCP,LONG,LAHF,PERF,ITSC,FSGSBASE,SMEP,ERMS,SENSOR,ARAT
cpu1: 256KB 64b/line 8-way L2 cache
cpu1: smt 0, core 1, package 0
ioapic0 at mainbus0: apid 8 pa 0xfec00000, version 20, 24 pins
acpiprt0 at acpi0: bus 13 (IPT1)
acpiprt1 at acpi0: bus -1 (IPT2)
acpiprt2 at acpi0: bus -1 (IPT3)
acpiprt3 at acpi0: bus -1 (IPT4)
acpiprt4 at acpi0: bus 3 (IPT5)
acpiprt5 at acpi0: bus -1 (IPT6)
acpiprt6 at acpi0: bus 4 (IPT7)
acpiprt7 at acpi0: bus 1 (IPT8)
acpiprt8 at acpi0: bus 7 (PT02)
acpiprt9 at acpi0: bus -1 (PT03)
acpiprt10 at acpi0: bus 2 (PT05)
acpiprt11 at acpi0: bus 0 (PCI0)
acpicpu0 at acpi0: C2(350@96 mwait.1@0x20), C1(1000@1 mwait.1)
acpicpu1 at acpi0: C2(350@96 mwait.1@0x20), C1(1000@1 mwait.1)
acpitz0 at acpi0: critical temperature is 31 degC
"IPI0001" at acpi0 not configured
"PNP0A06" at acpi0 not configured
"PNP0303" at acpi0 not configured
"PNP0F13" at acpi0 not configured
"ACPI000D" at acpi0 not configured
ipmi at mainbus0 not configured
pci0 at mainbus0 bus 0
pchb0 at pci0 dev 0 function 0 "Intel Core 3G Host" rev 0x09
ppb0 at pci0 dev 1 function 0 "Intel Core 3G PCIE" rev 0x09: msi
pci1 at ppb0 bus 7
ppb1 at pci0 dev 6 function 0 "Intel Core 3G PCIE" rev 0x09: msi
pci2 at ppb1 bus 2
ehci0 at pci0 dev 26 function 0 "Intel 6 Series USB" rev 0x05: apic 8 int 21
usb0 at ehci0: USB revision 2.0
uhub0 at usb0 configuration 1 interface 0 "Intel EHCI root hub" rev 2.00/1.00
addr 1
ppb2 at pci0 dev 28 function 0 "Intel 6 Series PCIE" rev 0xb5
pci3 at ppb2 bus 13
ppb3 at pci0 dev 28 function 4 "Intel 6 Series PCIE" rev 0xb5
pci4 at ppb3 bus 3
bge0 at pci4 dev 0 function 0 "Broadcom BCM5720" rev 0x00, BCM5720 A0
(0x5720000), APE firmware NCSI 1.2.46.0: msi, address d0:bf:9c:46:de:14
brgphy0 at bge0 phy 1: BCM5720C 10/100/1000baseT PHY, rev. 0
bge1 at pci4 dev 0 function 1 "Broadcom BCM5720" rev 0x00, BCM5720 A0
(0x5720000), APE firmware NCSI 1.2.46.0: msi, address d0:bf:9c:46:de:15
brgphy1 at bge1 phy 2: BCM5720C 10/100/1000baseT PHY, rev. 0
ppb4 at pci0 dev 28 function 6 "Intel 6 Series PCIE" rev 0xb5
pci5 at ppb4 bus 4
xhci0 at pci5 dev 0 function 0 "Renesas uPD720201 xHCI" rev 0x03: msi
xhci0: xHCI version 1.0
xhci0: CAPLENGTH=0x20
xhci0: DOORBELL=0x800
xhci0: RUNTIME=0x600
xhci0: 64 bytes context
xhci0: supported page size 0x00000001
xhci0: 6 ports and 32 slots
xhci0: 4 scratch pages
usb1 at xhci0: USB revision 3.0
uhub1 at usb1 configuration 1 interface 0 "Renesas xHCI root hub" rev 3.00/1.00
addr 1
xhci0: DCBAAP=00x97a0000
xhci0: CRCR=00 (00000000097a1000)
xhci0: ERSTBA=00xf1dc9000
xhci0: ERDP=00x97a2000
xhci0: USBCMD=0x5
xhci0: IMAN=0x2
ppb5 at pci0 dev 28 function 7 "Intel 6 Series PCIE" rev 0xb5
pci6 at ppb5 bus 1
"Hewlett-Packard iLO3 Slave" rev 0x05 at pci6 dev 0 function 0 not configured
vga1 at pci6 dev 0 function 1 "Matrox MGA G200eH" rev 0x00
wsdisplay0 at vga1 mux 1: console (80x25, vt100 emulation)
wsdisplay0: screen 1-5 added (80x25, vt100 emulation)
"Hewlett-Packard iLO3 Management" rev 0x05 at pci6 dev 0 function 2 not
configured
uhci0 at pci6 dev 0 function 4 "Hewlett-Packard USB" rev 0x02: apic 8 int 16
usb2 at uhci0: USB revision 1.0
uhub2 at usb2 configuration 1 interface 0 "Hewlett-Packard UHCI root hub" rev
1.00/1.00 addr 1
ehci1 at pci0 dev 29 function 0 "Intel 6 Series USB" rev 0x05: apic 8 int 20
usb3 at ehci1: USB revision 2.0
uhub3 at usb3 configuration 1 interface 0 "Intel EHCI root hub" rev 2.00/1.00
addr 1
ppb6 at pci0 dev 30 function 0 "Intel 82801BA Hub-to-PCI" rev 0xa5
pci7 at ppb6 bus 20
pcib0 at pci0 dev 31 function 0 "Intel C204 LPC" rev 0x05
ahci0 at pci0 dev 31 function 2 "Intel 6 Series AHCI" rev 0x05: msi, AHCI 1.3
ahci0: port 0: 6.0Gb/s
ahci0: port 1: 6.0Gb/s
ahci0: port 2: 3.0Gb/s
ahci0: port 3: 3.0Gb/s
scsibus1 at ahci0: 32 targets
sd0 at scsibus1 targ 0 lun 0: <ATA, Hitachi HDS5C303, MZ6O> SCSI3 0/direct
fixed naa.5000cca37ec4cabf
sd0: 2861588MB, 512 bytes/sector, 5860533168 sectors
sd1 at scsibus1 targ 1 lun 0: <ATA, WDC WD30EFRX-68E, 80.0> SCSI3 0/direct
fixed naa.50014ee6ae93cca7
sd1: 2861588MB, 512 bytes/sector, 5860533168 sectors
sd2 at scsibus1 targ 2 lun 0: <ATA, SAMSUNG HD204UI, 1AQ1> SCSI3 0/direct fixed
naa.50024e9204c857d8
sd2: 1907729MB, 512 bytes/sector, 3907029168 sectors
sd3 at scsibus1 targ 3 lun 0: <ATA, SAMSUNG HD204UI, 1AQ1> SCSI3 0/direct fixed
naa.50024e900430ce1c
sd3: 1907729MB, 512 bytes/sector, 3907029168 sectors
isa0 at pcib0
isadma0 at isa0
com0 at isa0 port 0x3f8/8 irq 4: ns16550a, 16 byte fifo
com0: console
pckbc0 at isa0 port 0x60/5 irq 1 irq 12
pckbd0 at pckbc0 (kbd slot)
wskbd0 at pckbd0: console keyboard, using wsdisplay0
pcppi0 at isa0 port 0x61
spkr0 at pcppi0
vmm0 at mainbus0: VMX/EPT
xhci0: port=2 change=0x04
uhub4 at uhub0 port 1 configuration 1 interface 0 "Intel Rate Matching Hub" rev
2.00/0.00 addr 2
xhci0: port=2 change=0x04
xhci0: xhci_cmd_slot_control
xhci0: dev 1, input=0xffffff00097c0000 slot=0xffffff00097c0040
ep0=0xffffff00097c0080
xhci0: dev 1, setting DCBAA to 0x00000000097c1000
xhci_pipe_init: pipe=0xffff800000122000 addr=0 depth=1 port=2 speed=4 dev 1 dci
1 (epAddr=0x0)
xhci0: xhci_cmd_set_address BSR=1
xhci0: xhci_cmd_set_address BSR=0
xhci0: dev 1 addr 1
umass0 at uhub1 port 2 configuration 1 interface 0 "USB to ATA/ATAPI Brid USB
Device" rev 3.00/2.03 addr 2
umass0: using SCSI over Bulk-Only
xhci_pipe_init: pipe=0xffff800000124000 addr=2 depth=1 port=2 speed=4 dev 1 dci
4 (epAddr=0x2)
xhci0: xhci_cmd_configure_ep dev 1
xhci_pipe_init: pipe=0xffff800000125000 addr=2 depth=1 port=2 speed=4 dev 1 dci
3 (epAddr=0x81)
xhci0: xhci_cmd_configure_ep dev 1
scsibus2 at umass0: 2 targets, initiator 0
sd4 at scsibus2 targ 1 lun 0: <USB3.0, , 0203> SCSI4 0/direct fixed
serial.152d0578876543211167
xhci0: xhci_cmd_reset_ep_async dev 1 dci 3
xhci0: xhci_cmd_set_tr_deq_async dev 1 dci 3
sd4: 305245MB, 512 bytes/sector, 625142448 sectors
xhci0: xhci_cmd_reset_ep_async dev 1 dci 3
xhci0: xhci_cmd_set_tr_deq_async dev 1 dci 3
uhub5 at uhub3 port 1 configuration 1 interface 0 "Intel Rate Matching Hub" rev
2.00/0.00 addr 2
uhub6 at uhub5 port 3 configuration 1 interface 0 "Standard Microsystems
product 0x2660" rev 2.00/8.01 addr 3
umass1 at uhub6 port 1 configuration 1 interface 0 "Generic Ultra Fast Media
Reader" rev 2.00/2.09 addr 4
umass1: using SCSI over Bulk-Only
scsibus3 at umass1: 2 targets, initiator 0
sd5 at scsibus3 targ 1 lun 0: <HP iLO, Internal SD-CARD, 2.09> SCSI0 0/direct
fixed serial.04244030000002660A01
sd5: 7648MB, 512 bytes/sector, 15663104 sectors
vscsi0 at root
scsibus4 at vscsi0: 256 targets
softraid0 at root
scsibus5 at softraid0: 256 targets
xhci0: xhci_cmd_reset_ep_async dev 1 dci 3
xhci0: xhci_cmd_set_tr_deq_async dev 1 dci 3
xhci0: xhci_cmd_reset_ep_async dev 1 dci 3
xhci0: xhci_cmd_set_tr_deq_async dev 1 dci 3
xhci0: xhci_cmd_reset_ep_async dev 1 dci 3
xhci0: xhci_cmd_set_tr_deq_async dev 1 dci 3
root on sd5a (6988b9e1abe8eaad.a) swap on sd5b dump on sd5b
xhci0: xhci_cmd_reset_ep_async dev 1 dci 3
xhci0: xhci_cmd_set_tr_deq_async dev 1 dci 3
xhci0: xhci_cmd_reset_ep_async dev 1 dci 3
xhci0: xhci_cmd_set_tr_deq_async dev 1 dci 3
xhci0: xhci_cmd_reset_ep_async dev 1 dci 3
xhci0: xhci_cmd_set_tr_deq_async dev 1 dci 3
xhci0: xhci_cmd_reset_ep_async dev 1 dci 3
xhci0: xhci_cmd_set_tr_deq_async dev 1 dci 3
sd6 at scsibus5 targ 1 lun 0: <OPENBSD, SR CRYPTO, 006> SCSI2 0/direct fixed
sd6: 305245MB, 512 bytes/sector, 625141920 sectors
softraid0: roaming device sd5a -> sd4a
softraid0: sd6: i/o error 5 @ CRYPTO block 230236816
xhci_abort_xfer: xfer=0xffffff010b75f0f0 status=IN_PROGRESS err=TIMEOUT
actlen=0 len=31 idx=199
xhci0: xhci_cmd_stop_ep dev 1 dci 4
xhci0: event error code=19, result=33
trb=0xffff800022185e80 (0x00000000097a1080 0x13000000 0x1008401<CYCLE>)
xhci0: error stopping endpoint
xhci0: xhci_cmd_set_tr_deq_async dev 1 dci 4
softraid0: sd6: i/o error 5 @ CRYPTO block 230236880
xhci_abort_xfer: xfer=0xffffff010b75f0f0 status=IN_PROGRESS err=TIMEOUT
actlen=0 len=31 idx=200
xhci0: xhci_cmd_stop_ep dev 1 dci 4
xhci0: event error code=19, result=33
trb=0xffff800022185e80 (0x00000000097a10a0 0x13000000 0x1008401<CYCLE>)
xhci0: error stopping endpoint
xhci0: xhci_cmd_set_tr_deq_async dev 1 dci 4
softraid0: sd6: i/o error 5 @ CRYPTO block 230236944
xhci_abort_xfer: xfer=0xffffff010b75f0f0 status=IN_PROGRESS err=TIMEOUT
actlen=0 len=31 idx=201
xhci0: xhci_cmd_stop_ep dev 1 dci 4
xhci0: event error code=19, result=33
trb=0xffff800022185e80 (0x00000000097a10c0 0x13000000 0x1008401<CYCLE>)
xhci0: error stopping endpoint
xhci0: xhci_cmd_set_tr_deq_async dev 1 dci 4
softraid0: sd6: i/o error 5 @ CRYPTO block 230237008
xhci_abort_xfer: xfer=0xffffff010b75f0f0 status=IN_PROGRESS err=TIMEOUT
actlen=0 len=31 idx=202
xhci0: xhci_cmd_stop_ep dev 1 dci 4
xhci0: event error code=19, result=33
trb=0xffff800022185e80 (0x00000000097a10e0 0x13000000 0x1008401<CYCLE>)
xhci0: error stopping endpoint
xhci0: xhci_cmd_set_tr_deq_async dev 1 dci 4
softraid0: sd6: i/o error 5 @ CRYPTO block 230237072
