From owner-freebsd-i386@FreeBSD.ORG Wed Mar 23 20:20:03 2005 Return-Path: Delivered-To: freebsd-i386@hub.freebsd.org Received: from mx1.FreeBSD.org (mx1.freebsd.org [216.136.204.125]) by hub.freebsd.org (Postfix) with ESMTP id CBF5016A4CE for ; Wed, 23 Mar 2005 20:20:03 +0000 (GMT) Received: from freefall.freebsd.org (freefall.freebsd.org [216.136.204.21]) by mx1.FreeBSD.org (Postfix) with ESMTP id 153E643D54 for ; Wed, 23 Mar 2005 20:20:03 +0000 (GMT) (envelope-from gnats@FreeBSD.org) Received: from freefall.freebsd.org (gnats@localhost [127.0.0.1]) by freefall.freebsd.org (8.13.3/8.13.3) with ESMTP id j2NKK3Li012818 for ; Wed, 23 Mar 2005 20:20:03 GMT (envelope-from gnats@freefall.freebsd.org) Received: (from gnats@localhost) by freefall.freebsd.org (8.13.3/8.13.1/Submit) id j2NKK3gh012817; Wed, 23 Mar 2005 20:20:03 GMT (envelope-from gnats) Resent-Date: Wed, 23 Mar 2005 20:20:03 GMT Resent-Message-Id: <200503232020.j2NKK3gh012817@freefall.freebsd.org> Resent-From: FreeBSD-gnats-submit@FreeBSD.org (GNATS Filer) Resent-To: freebsd-i386@FreeBSD.org Resent-Reply-To: FreeBSD-gnats-submit@FreeBSD.org, John Pettitt Received: from mx1.FreeBSD.org (mx1.freebsd.org [216.136.204.125]) by hub.freebsd.org (Postfix) with ESMTP id A3DF516A4CE for ; Wed, 23 Mar 2005 20:10:35 +0000 (GMT) Received: from www.freebsd.org (www.freebsd.org [216.136.204.117]) by mx1.FreeBSD.org (Postfix) with ESMTP id 2FAD943D1F for ; Wed, 23 Mar 2005 20:10:35 +0000 (GMT) (envelope-from nobody@FreeBSD.org) Received: from www.freebsd.org (localhost [127.0.0.1]) by www.freebsd.org (8.13.1/8.13.1) with ESMTP id j2NKAY9a016151 for ; Wed, 23 Mar 2005 20:10:34 GMT (envelope-from nobody@www.freebsd.org) Received: (from nobody@localhost) by www.freebsd.org (8.13.1/8.13.1/Submit) id j2NKAYA9016150; Wed, 23 Mar 2005 20:10:34 GMT (envelope-from nobody) Message-Id: <200503232010.j2NKAYA9016150@www.freebsd.org> Date: Wed, 23 Mar 2005 20:10:34 GMT From: John Pettitt To: freebsd-gnats-submit@FreeBSD.org X-Send-Pr-Version: www-2.3 Subject: i386/79169: USB Drives fail under high stress X-BeenThere: freebsd-i386@freebsd.org X-Mailman-Version: 2.1.1 Precedence: list List-Id: I386-specific issues for FreeBSD List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Wed, 23 Mar 2005 20:20:03 -0000 >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 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: Mar 23 00:46:55 gatekeeper kernel: ioapic0 irqs 0-23 on motherboard Mar 23 00:46:55 gatekeeper kernel: netsmb_dev: loaded Mar 23 00:46:55 gatekeeper kernel: npx0: on motherboard Mar 23 00:46:55 gatekeeper kernel: npx0: INT 16 interface Mar 23 00:46:55 gatekeeper kernel: acpi0: 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: on acpi0 Mar 23 00:46:55 gatekeeper kernel: acpi_throttle0: on cpu0 Mar 23 00:46:55 gatekeeper kernel: pcib0: port 0xcf8-0xcff on acpi0 Mar 23 00:46:55 gatekeeper kernel: pci0: on pcib0 Mar 23 00:46:55 gatekeeper kernel: agp0: 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: 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: 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: 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: 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: 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: 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: 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: 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: at device 30.0 on pci0 Mar 23 00:46:55 gatekeeper kernel: pci1: on pcib1 Mar 23 00:46:55 gatekeeper kernel: skc0: 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: 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: on sk0 Mar 23 00:46:55 gatekeeper kernel: e1000phy0: 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: 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: on fwohci0 Mar 23 00:46:55 gatekeeper kernel: fwe0: 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: 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: port 0xdc00-0xdc3f mem 0xff8fa000-0xff8fafff irq 20 at device 8.0 on pci1 Mar 23 00:46:55 gatekeeper kernel: miibus1: on fxp0 Mar 23 00:46:55 gatekeeper kernel: inphy0: 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: at device 31.0 on pci0 Mar 23 00:46:55 gatekeeper kernel: isa0: on isab0 Mar 23 00:46:55 gatekeeper kernel: atapci0: 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: at device 31.3 (no driver attached) Mar 23 00:46:55 gatekeeper kernel: pci0: at device 31.5 (no driver attached) Mar 23 00:46:55 gatekeeper kernel: acpi_button0: 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: port 0x64,0x60 irq 1 on acpi0 Mar 23 00:46:55 gatekeeper kernel: atkbd0: irq 1 on atkbdc0 Mar 23 00:46:55 gatekeeper kernel: kbd0 at atkbd0 Mar 23 00:46:55 gatekeeper kernel: psm0: 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: 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: 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 [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: 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: 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: 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: