Date: Wed, 23 Mar 2005 20:10:34 GMT From: John Pettitt <jpp@cloudview.com> To: freebsd-gnats-submit@FreeBSD.org Subject: i386/79169: USB Drives fail under high stress Message-ID: <200503232010.j2NKAYA9016150@www.freebsd.org> Resent-Message-ID: <200503232020.j2NKK3gh012817@freefall.freebsd.org>
next in thread | raw e-mail | index | archive | help
>Number: 79169
>Category: i386
>Synopsis: USB Drives fail under high stress
>Confidential: no
>Severity: critical
>Priority: high
>Responsible: freebsd-i386
>State: open
>Quarter:
>Keywords:
>Date-Required:
>Class: sw-bug
>Submitter-Id: current-users
>Arrival-Date: Wed Mar 23 20:20:02 GMT 2005
>Closed-Date:
>Last-Modified:
>Originator: John Pettitt
>Release: 5.4-PRERELEASE
>Organization:
>Environment:
FreeBSD gatekeeper.no-such-agency.net 5.4-PRERELEASE FreeBSD 5.4-PRERELEASE #39: Wed Mar 23 01:18:51 PST 2005 root@gatekeeper.no-such-agency.net:/usr/src/sys/i386/compile/GATEKEEPER i386
>Description:
USB Drives fail under high stress.
Environment FreeBSD 5.4PRE (with the latest USB updates).
Intel D845GVSR MB with Celeron 2.9Ghz. / 512M
Symptom::
Under high load USB stripe disk lock up whole system (console dead, not mouse, cursor or caps lock)
Steps to reproduce:
Create a stripe set
gstripe label –s 65536 data da1 da2
newfs /dev/stripe/data
tunefs –n enable /dev/stripe/data
mount /dev/stripe/data /data
cd /data
restore –rf /home/data.dmp
data.dmp is a 110GB dump file containing a BackupPC data tree (lots of small files).
System will lock up between 10 mins and 2 hours into restore (repeated 8 times). The high load (gstat shows 100% seems to be important)
Moving the drives to Firewire and making not other changes resulted in a complete restore (6 hours)
Other issues:
Short, recoverable hangs were observed when the block size on the striped file system was set to 64K. This was attributed to buffer management issues and the block size reduced to the default 16K.
Intermittent non recoverable disk hangs (system responsive but drive hung) were observed and fixed by adding quirks (see usb/79140).
Drive hang was reproduced using alternate USB/IDE controller to eliminate WD as an issue.
Uname –a:
FreeBSD gatekeeper.no-such-agency.net 5.4-PRERELEASE FreeBSD 5.4-PRERELEASE #39: Wed Mar 23 01:18:51 PST 2005 root@gatekeeper.no-such-agency.net:/usr/src/sys/i386/compile/GATEKEEPER i386
Boot message log:
Mar 23 00:46:55 gatekeeper syslogd: restart
Mar 23 00:46:55 gatekeeper syslogd: kernel boot file is /boot/kernel/kernel
Mar 23 00:46:55 gatekeeper kernel: Copyright (c) 1992-2005 The FreeBSD Project.
Mar 23 00:46:55 gatekeeper kernel: Copyright (c) 1979, 1980, 1983, 1986, 1988, 1989, 1991, 1992, 1993, 1994
Mar 23 00:46:55 gatekeeper kernel: The Regents of the University of California. All rights reserved.
Mar 23 00:46:55 gatekeeper kernel: FreeBSD 5.4-PRERELEASE #38: Tue Mar 22 23:24:41 PST 2005
Mar 23 00:46:55 gatekeeper kernel: root@gatekeeper.no-such-agency.net:/usr/src/sys/i386/compile/GATEKEEPER
Mar 23 00:46:55 gatekeeper kernel: Timecounter "i8254" frequency 1193182 Hz quality 0
Mar 23 00:46:55 gatekeeper kernel: CPU: Intel(R) Celeron(R) CPU 2.93GHz (2933.45-MHz 686-class CPU)
Mar 23 00:46:55 gatekeeper kernel: Origin = "GenuineIntel" Id = 0xf34 Stepping = 4
Mar 23 00:46:55 gatekeeper kernel: Features=0xbfebfbff<FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SEP,MTRR,PGE,MCA,CMOV,PAT,PSE36,CLFLUSH,DTS,ACPI,MMX,FXSR,SSE,SSE2,SS,HTT,TM,PBE>
Mar 23 00:46:55 gatekeeper kernel: real memory = 527695872 (503 MB)
Mar 23 00:46:55 gatekeeper kernel: avail memory = 506716160 (483 MB)
Mar 23 00:46:55 gatekeeper kernel: ACPI APIC Table: <INTEL D845GVS1>
Mar 23 00:46:55 gatekeeper kernel: ioapic0 <Version 2.0> irqs 0-23 on motherboard
Mar 23 00:46:55 gatekeeper kernel: netsmb_dev: loaded
Mar 23 00:46:55 gatekeeper kernel: npx0: <math processor> on motherboard
Mar 23 00:46:55 gatekeeper kernel: npx0: INT 16 interface
Mar 23 00:46:55 gatekeeper kernel: acpi0: <INTEL D845GVS1> on motherboard
Mar 23 00:46:55 gatekeeper kernel: acpi0: Power Button (fixed)
Mar 23 00:46:55 gatekeeper kernel: Timecounter "ACPI-fast" frequency 3579545 Hz quality 1000
Mar 23 00:46:55 gatekeeper kernel: acpi_timer0: <24-bit timer at 3.579545MHz> port 0x408-0x40b on acpi0
Mar 23 00:46:55 gatekeeper kernel: cpu0: <ACPI CPU> on acpi0
Mar 23 00:46:55 gatekeeper kernel: acpi_throttle0: <ACPI CPU Throttling> on cpu0
Mar 23 00:46:55 gatekeeper kernel: pcib0: <ACPI Host-PCI bridge> port 0xcf8-0xcff on acpi0
Mar 23 00:46:55 gatekeeper kernel: pci0: <ACPI PCI bus> on pcib0
Mar 23 00:46:55 gatekeeper kernel: agp0: <Intel 82845G (845G GMCH) SVGA controller> mem 0xffa80000-0xffafffff,0xf0000000-0xf7ffffff irq 16 at device 2.0 on pci0
Mar 23 00:46:55 gatekeeper kernel: agp0: detected 8060k stolen memory
Mar 23 00:46:55 gatekeeper kernel: agp0: aperture size is 128M
Mar 23 00:46:55 gatekeeper kernel: uhci0: <Intel 82801DB (ICH4) USB controller USB-A> port 0xe800-0xe81f irq 16 at device 29.0 on pci0
Mar 23 00:46:55 gatekeeper kernel: uhci0: LegSup = 0x0f30
Mar 23 00:46:55 gatekeeper kernel: usb0: <Intel 82801DB (ICH4) USB controller USB-A> on uhci0
Mar 23 00:46:55 gatekeeper kernel: usb0: USB revision 1.0
Mar 23 00:46:55 gatekeeper kernel: usbd_get_string: getting lang failed, using 0
Mar 23 00:46:55 gatekeeper kernel: uhub0: Intel UHCI root hub, class 9/0, rev 1.00/1.00, addr 1
Mar 23 00:46:55 gatekeeper kernel: uhub0: 2 ports with 2 removable, self powered
Mar 23 00:46:55 gatekeeper kernel: uhci1: <Intel 82801DB (ICH4) USB controller USB-B> port 0xe880-0xe89f irq 19 at device 29.1 on pci0
Mar 23 00:46:55 gatekeeper kernel: uhci1: LegSup = 0x0f30
Mar 23 00:46:55 gatekeeper kernel: usb1: <Intel 82801DB (ICH4) USB controller USB-B> on uhci1
Mar 23 00:46:55 gatekeeper kernel: usb1: USB revision 1.0
Mar 23 00:46:55 gatekeeper kernel: usbd_get_string: getting lang failed, using 0
Mar 23 00:46:55 gatekeeper kernel: uhub1: Intel UHCI root hub, class 9/0, rev 1.00/1.00, addr 1
Mar 23 00:46:55 gatekeeper kernel: uhub1: 2 ports with 2 removable, self powered
Mar 23 00:46:55 gatekeeper kernel: uhci2: <Intel 82801DB (ICH4) USB controller USB-C> port 0xec00-0xec1f irq 18 at device 29.2 on pci0
Mar 23 00:46:55 gatekeeper kernel: uhci2: LegSup = 0x0f30
Mar 23 00:46:55 gatekeeper kernel: usb2: <Intel 82801DB (ICH4) USB controller USB-C> on uhci2
Mar 23 00:46:55 gatekeeper kernel: usb2: USB revision 1.0
Mar 23 00:46:55 gatekeeper kernel: usbd_get_string: getting lang failed, using 0
Mar 23 00:46:55 gatekeeper kernel: uhub2: Intel UHCI root hub, class 9/0, rev 1.00/1.00, addr 1
Mar 23 00:46:55 gatekeeper kernel: uhub2: 2 ports with 2 removable, self powered
Mar 23 00:46:55 gatekeeper kernel: ehci0: <EHCI (generic) USB 2.0 controller> mem 0xffa7fc00-0xffa7ffff irq 23 at device 29.7 on pci0
Mar 23 00:46:55 gatekeeper kernel: ehci_pci_attach: companion usb0
Mar 23 00:46:55 gatekeeper kernel: ehci_pci_attach: companion usb1
Mar 23 00:46:55 gatekeeper kernel: ehci_pci_attach: companion usb2
Mar 23 00:46:55 gatekeeper kernel: usb3: EHCI version 1.0
Mar 23 00:46:55 gatekeeper kernel: usb3: companion controllers, 2 ports each: usb0 usb1 usb2
Mar 23 00:46:55 gatekeeper kernel: usb3: <EHCI (generic) USB 2.0 controller> on ehci0
Mar 23 00:46:55 gatekeeper kernel: usb3: USB revision 2.0
Mar 23 00:46:55 gatekeeper kernel: uhub3: Intel EHCI root hub, class 9/0, rev 2.00/1.00, addr 1
Mar 23 00:46:55 gatekeeper kernel: uhub3: single transaction translator
Mar 23 00:46:55 gatekeeper kernel: uhub3: 6 ports with 6 removable, self powered
Mar 23 00:46:55 gatekeeper kernel: pcib1: <ACPI PCI-PCI bridge> at device 30.0 on pci0
Mar 23 00:46:55 gatekeeper kernel: pci1: <ACPI PCI bus> on pcib1
Mar 23 00:46:55 gatekeeper kernel: skc0: <Marvell Gigabit Ethernet> port 0xd800-0xd8ff mem 0xff8fc000-0xff8fffff irq 21 at device 0.0 on pci1
Mar 23 00:46:55 gatekeeper kernel: skc0: SMC EZ Card 1000 (SMC9452TX V.2)
Mar 23 00:46:55 gatekeeper kernel: sk0: <Marvell Semiconductor, Inc. Yukon> on skc0
Mar 23 00:46:55 gatekeeper kernel: sk0: Ethernet address: 00:04:e2:aa:d9:c7
Mar 23 00:46:55 gatekeeper kernel: miibus0: <MII bus> on sk0
Mar 23 00:46:55 gatekeeper kernel: e1000phy0: <Marvell 88E1000 Gigabit PHY> on miibus0
Mar 23 00:46:55 gatekeeper kernel: e1000phy0: 10baseT, 10baseT-FDX, 100baseTX, 100baseTX-FDX, 1000baseTX-FDX, auto
Mar 23 00:46:55 gatekeeper kernel: fwohci0: <Texas Instruments TSB82AA2> mem 0xff8f4000-0xff8f7fff,0xff8fb800-0xff8fbfff irq 22 at device 1.0 on pci1
Mar 23 00:46:55 gatekeeper kernel: fwohci0: OHCI version 1.10 (ROM=1)
Mar 23 00:46:55 gatekeeper kernel: fwohci0: No. of Isochronous channels is 4.
Mar 23 00:46:55 gatekeeper kernel: fwohci0: EUI64 55:aa:55:aa:55:aa:55:aa
Mar 23 00:46:55 gatekeeper kernel: fwohci0: invalid speed 7 (fixed to 3).
Mar 23 00:46:55 gatekeeper kernel: fwohci0: Phy 1394a available S800, 3 ports.
Mar 23 00:46:55 gatekeeper kernel: fwohci0: Link S800, max_rec 4096 bytes.
Mar 23 00:46:55 gatekeeper kernel: firewire0: <IEEE1394(FireWire) bus> on fwohci0
Mar 23 00:46:55 gatekeeper kernel: fwe0: <Ethernet over FireWire> on firewire0
Mar 23 00:46:55 gatekeeper kernel: if_fwe0: Fake Ethernet address: 56:aa:55:aa:55:aa
Mar 23 00:46:55 gatekeeper kernel: fwe0: Ethernet address: 56:aa:55:aa:55:aa
Mar 23 00:46:55 gatekeeper kernel: fwe0: if_start running deferred for Giant
Mar 23 00:46:55 gatekeeper kernel: sbp0: <SBP-2/SCSI over FireWire> on firewire0
Mar 23 00:46:55 gatekeeper kernel: fwohci0: Initiate bus reset
Mar 23 00:46:55 gatekeeper kernel: fwohci0: node_id=0xc800ffc1, gen=1, CYCLEMASTER mode
Mar 23 00:46:55 gatekeeper kernel: firewire0: 2 nodes, maxhop <= 1, cable IRM = 1 (me)
Mar 23 00:46:55 gatekeeper kernel: firewire0: bus manager 1 (me)
Mar 23 00:46:55 gatekeeper kernel: fwohci0: phy int
Mar 23 00:46:55 gatekeeper kernel: fxp0: <Intel 82801DB (ICH4) Pro/100 VE Ethernet> port 0xdc00-0xdc3f mem 0xff8fa000-0xff8fafff irq 20 at device 8.0 on pci1
Mar 23 00:46:55 gatekeeper kernel: miibus1: <MII bus> on fxp0
Mar 23 00:46:55 gatekeeper kernel: inphy0: <i82562ET 10/100 media interface> on miibus1
Mar 23 00:46:55 gatekeeper kernel: inphy0: 10baseT, 10baseT-FDX, 100baseTX, 100baseTX-FDX, auto
Mar 23 00:46:55 gatekeeper kernel: fxp0: Ethernet address: 00:11:11:82:e2:00
Mar 23 00:46:55 gatekeeper kernel: isab0: <PCI-ISA bridge> at device 31.0 on pci0
Mar 23 00:46:55 gatekeeper kernel: isa0: <ISA bus> on isab0
Mar 23 00:46:55 gatekeeper kernel: atapci0: <Intel ICH4 UDMA100 controller> port 0xffa0-0xffaf,0x376,0x170-0x177,0x3f6,0x1f0-0x1f7 at device 31.1 on pci0
Mar 23 00:46:55 gatekeeper kernel: ata0: channel #0 on atapci0
Mar 23 00:46:55 gatekeeper kernel: ata1: channel #1 on atapci0
Mar 23 00:46:55 gatekeeper kernel: pci0: <serial bus, SMBus> at device 31.3 (no driver attached)
Mar 23 00:46:55 gatekeeper kernel: pci0: <multimedia, audio> at device 31.5 (no driver attached)
Mar 23 00:46:55 gatekeeper kernel: acpi_button0: <Sleep Button> on acpi0
Mar 23 00:46:55 gatekeeper kernel: sio0: <16550A-compatible COM port> port 0x3f8-0x3ff irq 4 flags 0x10 on acpi0
Mar 23 00:46:55 gatekeeper kernel: sio0: type 16550A
Mar 23 00:46:55 gatekeeper kernel: atkbdc0: <Keyboard controller (i8042)> port 0x64,0x60 irq 1 on acpi0
Mar 23 00:46:55 gatekeeper kernel: atkbd0: <AT Keyboard> irq 1 on atkbdc0
Mar 23 00:46:55 gatekeeper kernel: kbd0 at atkbd0
Mar 23 00:46:55 gatekeeper kernel: psm0: <PS/2 Mouse> irq 12 on atkbdc0
Mar 23 00:46:55 gatekeeper kernel: psm0: model IntelliMouse, device ID 3
Mar 23 00:46:55 gatekeeper kernel: pmtimer0 on isa0
Mar 23 00:46:55 gatekeeper kernel: ppc0: parallel port not found.
Mar 23 00:46:55 gatekeeper kernel: sc0: <System console> at flags 0x100 on isa0
Mar 23 00:46:55 gatekeeper kernel: sc0: VGA <16 virtual consoles, flags=0x300>
Mar 23 00:46:55 gatekeeper kernel: sio1: configured irq 3 not in bitmap of probed irqs 0
Mar 23 00:46:55 gatekeeper kernel: sio1: port may not be enabled
Mar 23 00:46:55 gatekeeper kernel: vga0: <Generic ISA VGA> at port 0x3c0-0x3df iomem 0xa0000-0xbffff on isa0
Mar 23 00:46:55 gatekeeper kernel: uhub4: Philips Semiconductors product 0x1521, class 9/0, rev 2.00/2.00, addr 2
Mar 23 00:46:55 gatekeeper kernel: uhub4: single transaction translator
Mar 23 00:46:55 gatekeeper kernel: uhub4: 7 ports with 0 removable, self powered
Mar 23 00:46:55 gatekeeper kernel: Timecounter "TSC" frequency 2933449090 Hz quality 800
Mar 23 00:46:55 gatekeeper kernel: Timecounters tick every 10.000 msec
Mar 23 00:46:55 gatekeeper kernel: IP Filter: v3.4.35 initialized. Default = pass all, Logging = disabled
Mar 23 00:46:55 gatekeeper kernel: ipfw2 initialized, divert enabled, rule-based forwarding disabled, default to deny, logging unlimited
Mar 23 00:46:55 gatekeeper kernel: ad0: 76319MB <WDC WD800BB-22FJA0/13.03G13> [155061/16/63] at ata0-master UDMA100
Mar 23 00:46:55 gatekeeper kernel: firewire0: New S400 device ID:0090a95000005f28
Mar 23 00:46:55 gatekeeper kernel: umass0: Genesys Logic USB TO IDE, rev 2.00/0.33, addr 3
Mar 23 00:46:55 gatekeeper kernel: umass0: 8070i (ATAPI) over Bulk-Only; quirks = 0x008c
Mar 23 00:46:55 gatekeeper kernel: umass0:1:0:-1: Attached to scbus1
Mar 23 00:46:55 gatekeeper kernel: umass1: Genesys Logic USB TO IDE, rev 2.00/0.33, addr 4
Mar 23 00:46:55 gatekeeper kernel: umass1: 8070i (ATAPI) over Bulk-Only; quirks = 0x008c
Mar 23 00:46:55 gatekeeper kernel: umass1:2:1:-1: Attached to scbus2
Mar 23 00:46:55 gatekeeper kernel: da0 at sbp0 bus 0 target 0 lun 0
Mar 23 00:46:55 gatekeeper kernel: da0: <WDC FireWire/USB2.0 0417> Fixed Simplified Direct Access SCSI-4 device
Mar 23 00:46:55 gatekeeper kernel: da0: 50.000MB/s transfers
Mar 23 00:46:55 gatekeeper kernel: da0: 238475MB (488397168 512 byte sectors: 255H 63S/T 30401C)
Mar 23 00:46:55 gatekeeper kernel: da2 at umass-sim1 bus 1 target 0 lun 0
Mar 23 00:46:55 gatekeeper kernel: da2: <Maxtor 6 B300R0 0811> Fixed Direct Access SCSI-0 device
Mar 23 00:46:55 gatekeeper kernel: da2: 40.000MB/s transfers
Mar 23 00:46:55 gatekeeper kernel: da2: 286188MB (586114704 512 byte sectors: 255H 63S/T 36483C)
Mar 23 00:46:55 gatekeeper kernel: da1 at umass-sim0 bus 0 target 0 lun 0
Mar 23 00:46:55 gatekeeper kernel: da1: <Maxtor 6 B300R0 0811> Fixed Direct Access SCSI-0 device
Mar 23 00:46:55 gatekeeper kernel: da1: 40.000MB/s transfers
Mar 23 00:46:55 gatekeeper kernel: da1: 286188MB (586114704 512 byte sectors: 255H 63S/T 36483C)
Mar 23 00:46:55 gatekeeper kernel: GEOM_LABEL: Label for provider da0 is ufs/data.
Mar 23 00:46:55 gatekeeper kernel: GEOM_STRIPE: Device data2 created (id=3128874803).
Mar 23 00:46:55 gatekeeper kernel: GEOM_STRIPE: Disk da1 attached to data2.
Mar 23 00:46:55 gatekeeper kernel: GEOM_STRIPE: Disk da2 attached to data2.
Mar 23 00:46:55 gatekeeper kernel: GEOM_STRIPE: Device data2 activated.
>How-To-Repeat:
See description
>Fix:
>Release-Note:
>Audit-Trail:
>Unformatted:
Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?200503232010.j2NKAYA9016150>