kern/139653: READ_BIG sluggish ata CD/DVD performance on HP DL360 G5

Charles Owens cowens at greatbaysoftware.com
Thu Oct 15 20:00:15 UTC 2009


>Number:         139653
>Category:       kern
>Synopsis:       READ_BIG sluggish ata CD/DVD performance on HP DL360 G5
>Confidential:   no
>Severity:       serious
>Priority:       low
>Responsible:    freebsd-bugs
>State:          open
>Quarter:        
>Keywords:       
>Date-Required:
>Class:          sw-bug
>Submitter-Id:   current-users
>Arrival-Date:   Thu Oct 15 20:00:06 UTC 2009
>Closed-Date:
>Last-Modified:
>Originator:     Charles Owens
>Release:        7.1-RELEASE
>Organization:
Great Bay Software
>Environment:
FreeBSD qaprofiler2 7.1-RELEASE-p5 FreeBSD 7.1-RELEASE-p5 #0: Thu Jun  4 11:47:32 UTC 2009     cowens at n_newcastle.greatbaysoftware.com:/usr/obj/usr/src/sys/BEACON  i386
>Description:
Note custom kernel is PAE-enabled but otherwise largely same as GENERIC.

Use of CD/DVD drive on HP ProLiant DL360 G5 servers is sluggish.  Same behavior verified on multiple server units of same model.

Symptoms are:

 * Booting install CD takes way too long (loading kernel takes well over a minute)
 * When mounting CD multiple "acd0: FAILURE - READ_BIG" error messages appear
 * During actual install reading from CD is noticeably sluggish
 * Same error messages and poor performance seen during non-install-time use of CD drive

Kernel see CD/DVD drive as:

   acd0: DVDROM <DV-28E-V/C.AB> at ata0-master UDMA33

Actual error messages seen during boot (or when otherwise trying to mount a CD):

acd0: FAILURE - READ_BIG MEDIUM ERROR asc=0x11 ascq=0x00 
acd0: FAILURE - READ_BIG MEDIUM ERROR asc=0x11 ascq=0x00 
acd0: FAILURE - READ_BIG MEDIUM ERROR asc=0x11 ascq=0x00 


Output of "vmstat -i" before/after performing mount of CD.

# Before
Thu Oct 15 13:39:07 EDT 2009
interrupt                          total       rate
irq1: atkbd0                         357          0
irq4: sio0                           170          0
irq14: ata0                           69          0
irq16: ciss0 uhci+               1062630          1
irq22: uhci4                          17          0
cpu0: timer                   1246144949       1999
irq258: bce0                     1831740          2
irq259: bce1                     6028128          9
cpu1: timer                   1246136522       1999
Total                         2501204582       4013
# Before (14 seconds later)
Thu Oct 15 13:39:21 EDT 2009
interrupt                          total       rate
irq1: atkbd0                         387          0
irq4: sio0                           170          0
irq14: ata0                           69          0
irq16: ciss0 uhci+               1062668          1
irq22: uhci4                          17          0
cpu0: timer                   1246171755       1999
irq258: bce0                     1831780          2
irq259: bce1                     6028216          9
cpu1: timer                   1246163327       1999
Total                         2501258389       4013

## CD mounted

# After
Thu Oct 15 13:39:57 EDT 2009
interrupt                          total       rate
irq1: atkbd0                         453          0
irq4: sio0                           415          0
irq14: ata0                          227          0
irq16: ciss0 uhci+               1062711          1
irq22: uhci4                          17          0
cpu0: timer                   1246244603       1999
irq258: bce0                     1831886          2
irq259: bce1                     6028640          9
cpu1: timer                   1246236176       1999
Total                         2501405128       4013
# After (11 seconds later)
Thu Oct 15 13:40:10 EDT 2009
interrupt                          total       rate
irq1: atkbd0                         503          0
irq4: sio0                           415          0
irq14: ata0                          227          0
irq16: ciss0 uhci+               1062832          1
irq22: uhci4                          17          0
cpu0: timer                   1246271059       1999
irq258: bce0                     1831926          2
irq259: bce1                     6028778          9
cpu1: timer                   1246262632       1999
Total                         2501458389       4013


Full boot-time kernel log:

Copyright (c) 1992-2009 The FreeBSD Project.
Copyright (c) 1979, 1980, 1983, 1986, 1988, 1989, 1991, 1992, 1993, 1994
        The Regents of the University of California. All rights reserved.
FreeBSD is a registered trademark of The FreeBSD Foundation.
FreeBSD 7.1-RELEASE-p5 #0: Thu Jun  4 11:47:32 UTC 2009
    cowens at n_newcastle.greatbaysoftware.com:/usr/obj/usr/src/sys/BEACON
Timecounter "i8254" frequency 1193182 Hz quality 0
CPU: Intel(R) Xeon(R) CPU            5160  @ 3.00GHz (3000.12-MHz 686-class CPU)
  Origin = "GenuineIntel"  Id = 0x6fb  Stepping = 11
  Features=0xbfebfbff<FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SEP,MTRR,PGE,MCA,C
MOV,PAT,PSE36,CLFLUSH,DTS,ACPI,MMX,FXSR,SSE,SSE2,SS,HTT,TM,PBE>
  Features2=0x4e3bd<SSE3,DTES64,MON,DS_CPL,VMX,EST,TM2,SSSE3,CX16,xTPR,PDCM,DCA>
  AMD Features=0x20000000<LM>
  AMD Features2=0x1<LAHF>
  Cores per package: 2
real memory  = 2145746944 (2046 MB)
avail memory = 2089566208 (1992 MB)
ACPI APIC Table: <HP     00000083>
FreeBSD/SMP: Multiprocessor System Detected: 2 CPUs
 cpu0 (BSP): APIC ID:  0
 cpu1 (AP): APIC ID:  1
ioapic0 <Version 2.0> irqs 0-23 on motherboard
ioapic1 <Version 2.0> irqs 24-47 on motherboard
registered firmware set <isp_1040>
registered firmware set <isp_1040_it>
registered firmware set <isp_1080>
registered firmware set <isp_1080_it>
registered firmware set <isp_12160>
registered firmware set <isp_12160_it>
registered firmware set <isp_2100>
registered firmware set <isp_2200>
registered firmware set <isp_2300>
registered firmware set <isp_2322>
registered firmware set <isp_2400>
kbd1 at kbdmux0
acpi0: <HP P58> on motherboard
acpi0: [ITHREAD]
acpi0: Power Button (fixed)
Timecounter "ACPI-fast" frequency 3579545 Hz quality 1000
acpi_timer0: <24-bit timer at 3.579545MHz> port 0x908-0x90b on acpi0
acpi_hpet0: <High Precision Event Timer> iomem 0xfed00000-0xfed003ff on acpi0
Timecounter "HPET" frequency 14318180 Hz quality 900
pcib0: <ACPI Host-PCI bridge> on acpi0
pci0: <ACPI PCI bus> on pcib0
pcib1: <ACPI PCI-PCI bridge> at device 2.0 on pci0
pci9: <ACPI PCI bus> on pcib1
pcib2: <ACPI PCI-PCI bridge> at device 0.0 on pci9
pci10: <ACPI PCI bus> on pcib2
pcib3: <ACPI PCI-PCI bridge> at device 0.0 on pci10
pci11: <ACPI PCI bus> on pcib3
em0: <Intel(R) PRO/1000 Network Connection 6.9.6> port 0x5000-0x501f mem 0xfdfe0
000-0xfdffffff,0xfdfc0000-0xfdfdffff irq 16 at device 0.0 on pci11
em0: Using MSI interrupt
em0: [FILTER]
em0: Ethernet address: 00:1b:78:5a:91:a4
em1: <Intel(R) PRO/1000 Network Connection 6.9.6> port 0x5020-0x503f mem 0xfdfa0
000-0xfdfbffff,0xfdf80000-0xfdf9ffff irq 17 at device 0.1 on pci11
em1: Using MSI interrupt
em1: [FILTER]
em1: Ethernet address: 00:1b:78:5a:91:a5
pcib4: <PCI-PCI bridge> at device 1.0 on pci10
pci14: <PCI bus> on pcib4
pcib5: <PCI-PCI bridge> at device 2.0 on pci10
pci15: <PCI bus> on pcib5
pcib6: <ACPI PCI-PCI bridge> at device 0.3 on pci9
pci16: <ACPI PCI bus> on pcib6
pci16: <encrypt/decrypt, network/computer crypto> at device 1.0 (no driver attac
hed)
pcib7: <ACPI PCI-PCI bridge> at device 3.0 on pci0
pci6: <ACPI PCI bus> on pcib7
pcib8: <PCI-PCI bridge> at device 0.0 on pci6
pci7: <PCI bus> on pcib8
pcib9: <PCI-PCI bridge> at device 4.0 on pci7
pci8: <PCI bus> on pcib9
ciss0: <HP Smart Array E200i> port 0x4000-0x40ff mem 0xfdd80000-0xfddfffff,0xfdd
70000-0xfdd77fff irq 16 at device 8.0 on pci7
ciss0: [ITHREAD]
pcib10: <ACPI PCI-PCI bridge> at device 4.0 on pci0
pci19: <ACPI PCI bus> on pcib10
pcib11: <PCI-PCI bridge> at device 5.0 on pci0
pci22: <PCI bus> on pcib11
pcib12: <ACPI PCI-PCI bridge> at device 6.0 on pci0
pci2: <ACPI PCI bus> on pcib12
pcib13: <ACPI PCI-PCI bridge> at device 0.0 on pci2
pci3: <ACPI PCI bus> on pcib13
bce0: <Broadcom NetXtreme II BCM5708 1000Base-T (B2)> mem 0xf8000000-0xf9ffffff 
irq 18 at device 0.0 on pci3
miibus0: <MII bus> on bce0
brgphy0: <BCM5708C 10/100/1000baseTX PHY> PHY 1 on miibus0
brgphy0:  10baseT, 10baseT-FDX, 100baseTX, 100baseTX-FDX, 1000baseT, 1000baseT-F
DX, auto
bce0: Ethernet address: 00:1e:0b:46:99:30
bce0: [ITHREAD]
bce0: ASIC (0x57081020); Rev (B2); Bus (PCI-X, 64-bit, 133MHz); F/W (0x01090605)
; Flags( MFW MSI )
pcib14: <ACPI PCI-PCI bridge> at device 7.0 on pci0
pci4: <ACPI PCI bus> on pcib14
pcib15: <ACPI PCI-PCI bridge> at device 0.0 on pci4
pci5: <ACPI PCI bus> on pcib15
bce1: <Broadcom NetXtreme II BCM5708 1000Base-T (B2)> mem 0xfa000000-0xfbffffff 
irq 19 at device 0.0 on pci5
miibus1: <MII bus> on bce1
brgphy1: <BCM5708C 10/100/1000baseTX PHY> PHY 1 on miibus1
brgphy1:  10baseT, 10baseT-FDX, 100baseTX, 100baseTX-FDX, 1000baseT, 1000baseT-F
DX, auto
bce1: Ethernet address: 00:1e:0b:46:99:3a
bce1: [ITHREAD]
bce1: ASIC (0x57081020); Rev (B2); Bus (PCI-X, 64-bit, 133MHz); F/W (0x01090605)
; Flags( MFW MSI )
uhci0: <Intel 631XESB/632XESB/3100 USB controller USB-1> port 0x1000-0x101f irq 
16 at device 29.0 on pci0
uhci0: [GIANT-LOCKED]
uhci0: [ITHREAD]
usb0: <Intel 631XESB/632XESB/3100 USB controller USB-1> on uhci0
usb0: USB revision 1.0
uhub0: <Intel UHCI root hub, class 9/0, rev 1.00/1.00, addr 1> on usb0
uhub0: 2 ports with 2 removable, self powered
uhci1: <Intel 631XESB/632XESB/3100 USB controller USB-2> port 0x1020-0x103f irq 
17 at device 29.1 on pci0
uhci1: [GIANT-LOCKED]
uhci1: [ITHREAD]
usb1: <Intel 631XESB/632XESB/3100 USB controller USB-2> on uhci1
usb1: USB revision 1.0
uhub1: <Intel UHCI root hub, class 9/0, rev 1.00/1.00, addr 1> on usb1
uhub1: 2 ports with 2 removable, self powered
uhci2: <Intel 631XESB/632XESB/3100 USB controller USB-3> port 0x1040-0x105f irq 
18 at device 29.2 on pci0
uhci2: [GIANT-LOCKED]
uhci2: [ITHREAD]
usb2: <Intel 631XESB/632XESB/3100 USB controller USB-3> on uhci2
usb2: USB revision 1.0
uhub2: <Intel UHCI root hub, class 9/0, rev 1.00/1.00, addr 1> on usb2
uhub2: 2 ports with 2 removable, self powered
uhci3: <Intel 631XESB/632XESB/3100 USB controller USB-4> port 0x1060-0x107f irq 
19 at device 29.3 on pci0
uhci3: [GIANT-LOCKED]
uhci3: [ITHREAD]
usb3: <Intel 631XESB/632XESB/3100 USB controller USB-4> on uhci3
usb3: USB revision 1.0
uhub3: <Intel UHCI root hub, class 9/0, rev 1.00/1.00, addr 1> on usb3
uhub3: 2 ports with 2 removable, self powered
ehci0: <Intel 63XXESB USB 2.0 controller> mem 0xf7df0000-0xf7df03ff irq 16 at de
vice 29.7 on pci0
ehci0: [GIANT-LOCKED]
ehci0: [ITHREAD]
usb4: waiting for BIOS to give up control
usb4: EHCI version 1.0
usb4: companion controllers, 2 ports each: usb0 usb1 usb2 usb3
usb4: <Intel 63XXESB USB 2.0 controller> on ehci0
usb4: USB revision 2.0
uhub4: <Intel EHCI root hub, class 9/0, rev 2.00/1.00, addr 1> on usb4
uhub4: 8 ports with 8 removable, self powered
pcib16: <ACPI PCI-PCI bridge> at device 30.0 on pci0
pci1: <ACPI PCI bus> on pcib16
vgapci0: <VGA-compatible display> port 0x3000-0x30ff mem 0xd8000000-0xdfffffff,0
xf7ff0000-0xf7ffffff irq 23 at device 3.0 on pci1
pci1: <base peripheral> at device 4.0 (no driver attached)
pci1: <base peripheral> at device 4.2 (no driver attached)
uhci4: <UHCI (generic) USB controller> port 0x3800-0x381f irq 22 at device 4.4 o
n pci1
uhci4: [GIANT-LOCKED]
uhci4: [ITHREAD]
usb5: <UHCI (generic) USB controller> on uhci4
usb5: USB revision 1.0
uhub5: <(0x103c) UHCI root hub, class 9/0, rev 1.00/1.00, addr 1> on usb5
uhub5: 2 ports with 2 removable, self powered
ipmi0: <IPMI System Interface> mem 0xf7ef0000-0xf7ef00ff irq 21 at device 4.6 on
 pci1
ipmi0: using KSC interface
isab0: <PCI-ISA bridge> at device 31.0 on pci0
isa0: <ISA bus> on isab0
atapci0: <Intel 63XXESB2 UDMA100 controller> port 0x1f0-0x1f7,0x3f6,0x170-0x177,
0x376,0x500-0x50f irq 17 at device 31.1 on pci0
ata0: <ATA channel 0> on atapci0
ata0: [ITHREAD]
ata1: <ATA channel 1> on atapci0
ata1: [ITHREAD]
acpi_tz0: <Thermal Zone> on acpi0
atkbdc0: <Keyboard controller (i8042)> port 0x60,0x64 irq 1 on acpi0
atkbd0: <AT Keyboard> irq 1 on atkbdc0
kbd0 at atkbd0
atkbd0: [GIANT-LOCKED]
atkbd0: [ITHREAD]
sio0: <Standard PC COM port> port 0x3f8-0x3ff irq 4 flags 0x10 on acpi0
sio0: type 16550A, console
sio0: [FILTER]
cpu0: <ACPI CPU> on acpi0
est0: <Enhanced SpeedStep Frequency Control> on cpu0
est: CPU supports Enhanced Speedstep, but is not recognized.
est: cpu_vendor GenuineIntel, msr 92a092a0600092a
device_attach: est0 attach returned 6
p4tcc0: <CPU Frequency Thermal Control> on cpu0
cpu1: <ACPI CPU> on acpi0
est1: <Enhanced SpeedStep Frequency Control> on cpu1
est: CPU supports Enhanced Speedstep, but is not recognized.
est: cpu_vendor GenuineIntel, msr 92a092a0600092a
device_attach: est1 attach returned 6
p4tcc1: <CPU Frequency Thermal Control> on cpu1
ipmi1: <IPMI System Interface> on isa0
device_attach: ipmi1 attach returned 16
pmtimer0 on isa0
orm0: <ISA Option ROMs> at iomem 0xc0000-0xcafff,0xe6000-0xe7fff pnpid ORM0000 o
n isa0
ppc0: parallel port not found.
sc0: <System console> at flags 0x100 on isa0
sc0: VGA <16 virtual consoles, flags=0x300>
sio1 at port 0x2f8-0x2ff irq 3 on isa0
sio1: type 16550A
sio1: [FILTER]
vga0: <Generic ISA VGA> at port 0x3c0-0x3df iomem 0xa0000-0xbffff on isa0
ukbd0: <HP Virtual Keyboard, class 0/0, rev 1.10/0.02, addr 2> on uhub5
kbd2 at ukbd0
ums0: <HP Virtual Keyboard, class 0/0, rev 1.10/0.02, addr 2> on uhub5
ums0: 3 buttons.
uhub6: <HP Virtual Hub, class 9/0, rev 1.10/0.01, addr 3> on uhub5
uhub6: 7 ports with 7 removable, self powered
Timecounters tick every 1.000 msec
acd0: DVDROM <DV-28E-V/C.AB> at ata0-master UDMA33
ipmi0: IPMI device rev. 1, firmware rev. 1.2, version 2.0
ipmi0: Number of channels 8
ipmi0: Attached watchdog
SMP: AP CPU #1 Launched!
da0 at ciss0 bus 0 target 0 lun 0
da0: <COMPAQ RAID 1  VOLUME OK> Fixed Direct Access SCSI-5 device 
da0: 135.168MB/s transfers
da0: 69973MB (143305920 512 byte sectors: 255H 32S/T 17562C)
GEOM_JOURNAL: Journal 3000843606: da0s1a contains data.
GEOM_JOURNAL: Journal 3000843606: da0s1a contains journal.
GEOM_JOURNAL: Journal da0s1a consistent.
GEOM_JOURNAL: BIO_FLUSH not supported by da0s1a.
GEOM_JOURNAL: Journal 1211260365: da0s1d contains data.
GEOM_JOURNAL: Journal 1211260365: da0s1d contains journal.
GWEAORMN_IJNOGU:R NEAxLp:e cJtoeudr nraalw odfaf0sse1td  0c,o nfsoiusntde n3t2.

GEOM_JOURNAL: BIO_FLUSH not supported by da0s1d.
Trying to mount root from ufs:/dev/da0s1a.journal
WARNING: / was not properly dismounted
WARNING: Expected rawoffset 0, found 32
eth0: link state changed to UP
eth1: link state changed to UP
acd0: FAILURE - READ_BIG MEDIUM ERROR asc=0x11 ascq=0x00 
GEOM_LABEL: Label for provider acd0t01 is iso9660/GreatBay_Beacon.
acd0: FAILURE - READ_BIG MEDIUM ERROR asc=0x11 ascq=0x00 
acd0: FAILURE - READ_BIG MEDIUM ERROR asc=0x11 ascq=0x00 

>How-To-Repeat:
Mount and read from any CD
>Fix:


>Release-Note:
>Audit-Trail:
>Unformatted:


More information about the freebsd-bugs mailing list