Date: Tue, 24 Sep 2002 14:00:49 +0300 From: Angelin Lazarov Lalev <alalev@uni-svishtov.bg> To: freebsd-hackers@freebsd.org Subject: What does this log mean (SCSI problem ?) Message-ID: <3D9045E1.7040302@uni-svishtov.bg>
next in thread | raw e-mail | index | archive | help
I think I have a problem. From time to tme, apparently when the disk activity of my IBM SCSI disk becomes higher, all disk operations are suspended for about 30 seconds. After that all continues ok, but the following log messages are written to the syslog. Is that normal? Sep 18 16:39:53 ns1 /kernel: (da0:ahc0:0:6:0): SCB 0x15 - timed out Sep 18 16:40:11 ns1 /kernel: ahc0: Dumping Card State in Data-out phase, at SEQADDR 0x8c Sep 18 16:40:11 ns1 /kernel: ACCUM = 0x0, SINDEX = 0x22, DINDEX = 0xe4, ARG_2 = 0x5 Sep 18 16:40:11 ns1 /kernel: HCNT = 0x0 SCBPTR = 0x12 Sep 18 16:40:11 ns1 /kernel: SCSISEQ = 0x12, SBLKCTL = 0xa Sep 18 16:40:11 ns1 /kernel: DFCNTRL = 0x2c, DFSTATUS = 0x82 Sep 18 16:40:11 ns1 /kernel: LASTPHASE = 0x0, SCSISIGI = 0x4, SXFRCTL0 = 0x80 Sep 18 16:40:11 ns1 /kernel: SSTAT0 = 0x0, SSTAT1 = 0x2 Sep 18 16:40:11 ns1 /kernel: STACK == 0x8a, 0x64, 0x165, 0x0 Sep 18 16:40:11 ns1 /kernel: SCB count = 30 Sep 18 16:40:11 ns1 /kernel: Kernel NEXTQSCB = 17 Sep 18 16:40:11 ns1 /kernel: Card NEXTQSCB = 29 Sep 18 16:40:11 ns1 /kernel: QINFIFO entries: 29 0 4 8 7 23 28 5 24 18 9 25 15 1 2 11 10 3 16 22 19 27 Sep 18 16:40:11 ns1 /kernel: Waiting Queue entries: Sep 18 16:40:11 ns1 /kernel: Disconnected Queue entries: Sep 18 16:40:11 ns1 /kernel: QOUTFIFO entries: Sep 18 16:40:11 ns1 /kernel: Sequencer Free SCB List: 11 25 9 26 19 23 28 12 20 22 21 2 5 0 10 8 14 16 3 15 1 4 6 7 17 24 27 13 29 30 31 Sep 18 16:40:11 ns1 /kernel: Sequencer SCB Info: 0(c 0x60, s 0x67, l 0, t 0xff) 1(c 0x60, s 0x67, l 0, t 0xff) 2(c 0x60, s 0x67, l 0, t 0xff) 3(c 0x60, s 0x67, l 0, t 0x ff) 4(c 0x60, s 0x67, l 0, t 0xff) 5(c 0x60, s 0x67, l 0, t 0xff) 6(c 0x60, s 0x67, l 0, t 0xff) 7(c 0x60, s 0x67, l 0, t 0xff) 8(c 0x60, s 0x67, l 0, t 0xff) 9(c 0x60, s 0x67, l 0, t 0xff) 10(c 0x60, s 0x67, l 0, t 0xff) 11(c 0x62, s 0x67, l 0, t 0xff) 12(c 0x60, s 0x67, l 0, t 0xff) 13(c 0x60, s 0x67, l 0, t 0xff) 14(c 0x60, s 0x67, l 0, t 0xff) 15(c 0x60, s 0x67, l 0, t 0xff) 16(c 0x60, s 0x67, l 0, t 0xff) 17(c 0x60, s 0x67, l 0, t 0xff) 18(c 0x60, s 0x67, l 0, t 0x15) 19(c 0x60, s 0x67, l 0, t 0xf f) 20(c 0x60, s 0x67, l 0, t 0xff) 21(c 0x60, s 0x67, l 0, t 0xff) 22(c 0x60, s 0x67, l 0, t 0xff) 23(c 0x60, s 0x67, l 0, t 0xff) 24(c 0x60, s 0x67, l 0, t 0xff) 25(c 0 x60, s 0x67, l 0, t 0xff) 26(c 0x60, s 0x67, l 0, t 0xff) 27(c 0x60, s 0x67, l 0, t 0xff) 28(c 0x60, s 0x67, l 0, t 0xff) 29(c 0x0, s 0x67, l 0, t 0xff) 30(c 0x0, s 0x67 , l 0, t 0xff) 31(c 0x0, s 0x6 Sep 18 16:40:11 ns1 /kernel: t 0xff) Sep 18 16:40:11 ns1 /kernel: Pending list: 27(c 0x60, s 0x67, l 0), 19(c 0x62, s 0x67, l 0), 22(c 0x60, s 0x67, l 0), 16(c 0x60, s 0x67, l 0), 3(c 0x60, s 0x67, l 0), 10 (c 0x60, s 0x67, l 0), 11(c 0x60, s 0x67, l 0), 2(c 0x60, s 0x67, l 0), 1(c 0x60, s 0x67, l 0), 15(c 0x60, s 0x67, l 0), 25(c 0x60, s 0x67, l 0), 9(c 0x60, s 0x67, l 0), 18(c 0x60, s 0x67, l 0), 24(c 0x60, s 0x67, l 0), 5(c 0x60, s 0x67, l 0), 28(c 0x60, s 0x67, l 0), 23(c 0x60, s 0x67, l 0), 7(c 0x60, s 0x67, l 0), 8(c 0x60, s 0x67, l 0), 4(c 0x60, s 0x67, l 0), 0(c 0x60, s 0x67, l 0), 29(c 0x60, s 0x67, l 0), 21(c 0x60, s 0x67, l 0) Sep 18 16:40:11 ns1 /kernel: Kernel Free SCB list: 12 6 26 20 14 13 Sep 18 16:40:11 ns1 /kernel: sg[0] - Addr 0x60f5000 : Length 4096 Sep 18 16:40:11 ns1 /kernel: sg[1] - Addr 0x6a16000 : Length 4096 Sep 18 16:40:12 ns1 /kernel: sg[2] - Addr 0x6077000 : Length 4096 Sep 18 16:40:12 ns1 /kernel: sg[3] - Addr 0x6778000 : Length 4096 Sep 18 16:40:12 ns1 /kernel: (da0:ahc0:0:6:0): BDR message in message buffer Sep 18 16:40:12 ns1 /kernel: (da0:ahc0:0:6:0): SCB 0x15 - timed out Sep 18 16:40:12 ns1 /kernel: ahc0: Dumping Card State in Data-out phase, at SEQADDR 0x8b Sep 18 16:40:12 ns1 /kernel: ACCUM = 0x0, SINDEX = 0x22, DINDEX = 0xe4, ARG_2 = 0x5 Sep 18 16:40:12 ns1 /kernel: HCNT = 0x0 SCBPTR = 0x12 Sep 18 16:40:12 ns1 /kernel: SCSISEQ = 0x12, SBLKCTL = 0xa Sep 18 16:40:12 ns1 /kernel: DFCNTRL = 0x2c, DFSTATUS = 0x82 Sep 18 16:40:12 ns1 /kernel: LASTPHASE = 0x0, SCSISIGI = 0x14, SXFRCTL0 = 0x80 Sep 18 16:40:12 ns1 /kernel: SSTAT0 = 0x0, SSTAT1 = 0x2 Sep 18 16:40:12 ns1 /kernel: STACK == 0x8a, 0x64, 0x165, 0x0 Sep 18 16:40:12 ns1 /kernel: SCB count = 30 Sep 18 16:40:12 ns1 /kernel: Kernel NEXTQSCB = 17 Sep 18 16:40:12 ns1 /kernel: Card NEXTQSCB = 29 Sep 18 16:40:12 ns1 /kernel: QINFIFO entries: 29 0 4 8 7 23 28 5 24 18 9 25 15 1 2 11 10 3 16 22 19 27 Sep 18 16:40:12 ns1 /kernel: Waiting Queue entries: Sep 18 16:40:12 ns1 /kernel: Disconnected Queue entries: Sep 18 16:40:12 ns1 /kernel: QOUTFIFO entries: Sep 18 16:40:12 ns1 /kernel: Sequencer Free SCB List: 11 25 9 26 19 23 28 12 20 22 21 2 5 0 10 8 14 16 3 15 1 4 6 7 17 24 27 13 29 30 31 Sep 18 16:40:12 ns1 /kernel: Sequencer SCB Info: 0(c 0x60, s 0x67, l 0, t 0xff) 1(c 0x60, s 0x67, l 0, t 0xff) 2(c 0x60, s 0x67, l 0, t 0xff) 3(c 0x60, s 0x67, l 0, t 0x ff) 4(c 0x60, s 0x67, l 0, t 0xff) 5(c 0x60, s 0x67, l 0, t 0xff) 6(c 0x60, s 0x67, l 0, t 0xff) 7(c 0x60, s 0x67, l 0, t 0xff) 8(c 0x60, s 0x67, l 0, t 0xff) 9(c 0x60, s 0x67, l 0, t 0xff) 10(c 0x60, s 0x67, l 0, t 0xff) 11(c 0x62, s 0x67, l 0, t 0xff) 12(c 0x60, s 0x67, l 0, t 0xff) 13(c 0x60, s 0x67, l 0, t 0xff) 14(c 0x60, s 0x67, l 0, t 0xff) 15(c 0x60, s 0x67, l 0, t 0xff) 16(c 0x60, s 0x67, l 0, t 0xff) 17(c 0x60, s 0x67, l 0, t 0xff) 18(c 0x60, s 0x67, l 0, t 0x15) 19(c 0x60, s 0x67, l 0, t 0xf f) 20(c 0x60, s 0x67, l 0, t 0xff) 21(c 0x60, s 0x67, l 0, t 0xff) 22(c 0x60, s 0x67, l 0, t 0xff) 23(c 0x60, s 0x67, l 0, t 0xff) 24(c 0x60, s 0x67, l 0, t 0xff) 25(c 0 x60, s 0x67, l 0, t 0xff) 26(c 0x60, s 0x67, l 0, t 0xff) 27(c 0x60, s 0x67, l 0, t 0xff) 28(c 0x60, s 0x67, l 0, t 0xff) 29(c 0x0, s 0x67, l 0, t 0xff) 30(c 0x0, s 0x67 , l 0, t 0xff) 31(c 0x0, s 0x6 Sep 18 16:40:12 ns1 /kernel: t 0xff) Sep 18 16:40:12 ns1 /kernel: Pending list: 27(c 0x60, s 0x67, l 0), 19(c 0x62, s 0x67, l 0), 22(c 0x60, s 0x67, l 0), 16(c 0x60, s 0x67, l 0), 3(c 0x60, s 0x67, l 0), 10 (c 0x60, s 0x67, l 0), 11(c 0x60, s 0x67, l 0), 2(c 0x60, s 0x67, l 0), 1(c 0x60, s 0x67, l 0), 15(c 0x60, s 0x67, l 0), 25(c 0x60, s 0x67, l 0), 9(c 0x60, s 0x67, l 0), 18(c 0x60, s 0x67, l 0), 24(c 0x60, s 0x67, l 0), 5(c 0x60, s 0x67, l 0), 28(c 0x60, s 0x67, l 0), 23(c 0x60, s 0x67, l 0), 7(c 0x60, s 0x67, l 0), 8(c 0x60, s 0x67, l 0), 4(c 0x60, s 0x67, l 0), 0(c 0x60, s 0x67, l 0), 29(c 0x60, s 0x67, l 0), 21(c 0x60, s 0x67, l 0) Sep 18 16:40:13 ns1 /kernel: Kernel Free SCB list: 12 6 26 20 14 13 Sep 18 16:40:13 ns1 /kernel: sg[0] - Addr 0x60f5000 : Length 4096 Sep 18 16:40:13 ns1 /kernel: sg[1] - Addr 0x6a16000 : Length 4096 Sep 18 16:40:13 ns1 /kernel: sg[2] - Addr 0x6077000 : Length 4096 Sep 18 16:40:13 ns1 /kernel: sg[3] - Addr 0x6778000 : Length 4096 Sep 18 16:40:13 ns1 /kernel: (da0:ahc0:0:6:0): no longer in timeout, status = 34b Sep 18 16:40:13 ns1 /kernel: ahc0: Issued Channel A Bus Reset. 23 SCBs aborted And this is what my kernel prints when I'm booting. Aug 21 10:07:39 ns1 /kernel: Copyright (c) 1992-2002 The FreeBSD Project. Aug 21 10:07:39 ns1 /kernel: Copyright (c) 1979, 1980, 1983, 1986, 1988, 1989, 1991, 1992, 1993, 1994 Aug 21 10:07:39 ns1 /kernel: The Regents of the University of California. All rights reserved. Aug 21 10:07:39 ns1 /kernel: FreeBSD 4.6.1-RELEASE-p7 #1: Fri Aug 2 16:04:44 EEST 2002 Aug 21 10:07:39 ns1 /kernel: root@lalev.uni-svishtov.bg:/usr/opt/obj/usr/opt/src/sys/GENERIC Aug 21 10:07:39 ns1 /kernel: Timecounter "i8254" frequency 1193182 Hz Aug 21 10:07:39 ns1 /kernel: CPU: Pentium III/Pentium III Xeon/Celeron (451.02-MHz 686-class CPU) Aug 21 10:07:39 ns1 /kernel: Origin = "GenuineIntel" Id = 0x673 Stepping = 3 Aug 21 10:07:39 ns1 /kernel: Features=0x383f9ff<FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,SEP,MTRR,PGE,MCA,CMOV,PAT,PSE36,MMX,FXSR,SSE> Aug 21 10:07:39 ns1 /kernel: real memory = 268423168 (262132K bytes) Aug 21 10:07:39 ns1 /kernel: avail memory = 256253952 (250248K bytes) Aug 21 10:07:39 ns1 /kernel: Preloaded elf kernel "kernel" at 0xc04d4000. Aug 21 10:07:39 ns1 /kernel: Preloaded elf module "splash_bmp.ko" at 0xc04d409c. Aug 21 10:07:39 ns1 /kernel: Pentium Pro MTRR support enabled Aug 21 10:07:39 ns1 /kernel: md0: Malloc disk Aug 21 10:07:39 ns1 /kernel: module_register_init: MOD_LOAD (splash_bmp, c04cf790, 0) error 2 Aug 21 10:07:39 ns1 /kernel: Using $PIR table, 7 entries at 0xc00f0d10 Aug 21 10:07:39 ns1 /kernel: npx0: <math processor> on motherboard Aug 21 10:07:39 ns1 /kernel: npx0: INT 16 interface Aug 21 10:07:39 ns1 /kernel: pcib0: <Intel 82443BX (440 BX) host to PCI bridge> on motherboard Aug 21 10:07:39 ns1 /kernel: pci0: <PCI bus> on pcib0 Aug 21 10:07:39 ns1 /kernel: pcib1: <Intel 82443BX (440 BX) PCI-PCI (AGP) bridge> at device 1.0 on pci0 Aug 21 10:07:39 ns1 /kernel: pci1: <PCI bus> on pcib1 Aug 21 10:07:39 ns1 /kernel: isab0: <Intel 82371AB PCI to ISA bridge> at device 4.0 on pci0 Aug 21 10:07:39 ns1 /kernel: isa0: <ISA bus> on isab0 Aug 21 10:07:39 ns1 /kernel: atapci0: <Intel PIIX4 ATA33 controller> port 0xd800-0xd80f at device 4.1 on pci0 Aug 21 10:07:39 ns1 /kernel: ata0: at 0x1f0 irq 14 on atapci0 Aug 21 10:07:39 ns1 /kernel: ata1: at 0x170 irq 15 on atapci0 Aug 21 10:07:39 ns1 /kernel: uhci0: <Intel 82371AB/EB (PIIX4) USB controller> port 0xd400-0xd41f irq 10 at device 4.2 on pci0 Aug 21 10:07:39 ns1 /kernel: usb0: <Intel 82371AB/EB (PIIX4) USB controller> on uhci0 Aug 21 10:07:39 ns1 /kernel: usb0: USB revision 1.0 Aug 21 10:07:39 ns1 /kernel: uhub0: Intel UHCI root hub, class 9/0, rev 1.00/1.00, addr 1 Aug 21 10:07:39 ns1 /kernel: uhub0: 2 ports with 2 removable, self powered Aug 21 10:07:39 ns1 /kernel: chip1: <Intel 82371AB Power management controller> port 0xe800-0xe80f at device 4.3 on pci0 Aug 21 10:07:39 ns1 /kernel: ahc0: <Adaptec aic7890/91 Ultra2 SCSI adapter> port 0xd000-0xd0ff mem 0xcd000000-0xcd000fff irq 10 at device 6.0 on pci0 Aug 21 10:07:39 ns1 /kernel: aic7890/91: Ultra2 Wide Channel A, SCSI Id=7, 32/253 SCBs Aug 21 10:07:39 ns1 /kernel: pci0: <Matrox MGA Millennium II 2164W graphics accelerator> at 9.0 irq 10 Aug 21 10:07:39 ns1 /kernel: tl0: <Compaq Netelligent 10/100> port 0xb800-0xb80f mem 0xcb800000-0xcb80000f irq 11 at device 11.0 on pci0 Aug 21 10:07:39 ns1 /kernel: tl0: Ethernet address: 00:08:c7:28:9d:96 Aug 21 10:07:40 ns1 /kernel: miibus0: <MII bus> on tl0 Aug 21 10:07:40 ns1 /kernel: nsphy0: <DP83840 10/100 media interface> on miibus0 Aug 21 10:07:40 ns1 /kernel: nsphy0: 10baseT, 10baseT-FDX, 100baseTX, 100baseTX-FDX, auto Aug 21 10:07:40 ns1 /kernel: tlphy0: <ThunderLAN 10baseT media interface> on miibus0 Aug 21 10:07:40 ns1 /kernel: tlphy0: 10base2/BNC, 10base5/AUI Aug 21 10:07:40 ns1 /kernel: orm0: <Option ROMs> at iomem 0xc0000-0xc7fff,0xc8000-0xcd7ff on isa0 Aug 21 10:07:40 ns1 /kernel: fdc0: <NEC 72065B or clone> at port 0x3f0-0x3f5,0x3f7 irq 6 drq 2 on isa0 Aug 21 10:07:40 ns1 /kernel: fdc0: FIFO enabled, 8 bytes threshold Aug 21 10:07:40 ns1 /kernel: atkbdc0: <Keyboard controller (i8042)> at port 0x60,0x64 on isa0 Aug 21 10:07:40 ns1 /kernel: atkbd0: <AT Keyboard> flags 0x1 irq 1 on atkbdc0 Aug 21 10:07:40 ns1 /kernel: kbd0 at atkbd0 Aug 21 10:07:40 ns1 /kernel: vga0: <Generic ISA VGA> at port 0x3c0-0x3df iomem 0xa0000-0xbffff on isa0 Aug 21 10:07:40 ns1 /kernel: sc0: <System console> at flags 0x100 on isa0 Aug 21 10:07:40 ns1 /kernel: sc0: VGA <16 virtual consoles, flags=0x300> Aug 21 10:07:40 ns1 /kernel: sio0 at port 0x3f8-0x3ff irq 4 flags 0x10 on isa0 Aug 21 10:07:40 ns1 /kernel: sio0: type 16550A Aug 21 10:07:40 ns1 /kernel: sio1 at port 0x2f8-0x2ff irq 3 on isa0 Aug 21 10:07:40 ns1 /kernel: sio1: type 16550A Aug 21 10:07:40 ns1 /kernel: ppc0: <Parallel port> at port 0x378-0x37f irq 7 on isa0 Aug 21 10:07:40 ns1 /kernel: ppc0: SMC-like chipset (ECP/EPP/PS2/NIBBLE) in COMPATIBLE mode Aug 21 10:07:40 ns1 /kernel: ppc0: FIFO with 16/16/9 bytes threshold Aug 21 10:07:40 ns1 /kernel: plip0: <PLIP network interface> on ppbus0 Aug 21 10:07:40 ns1 /kernel: lpt0: <Printer> on ppbus0 Aug 21 10:07:40 ns1 /kernel: lpt0: Interrupt-driven port Aug 21 10:07:40 ns1 /kernel: ppi0: <Parallel I/O> on ppbus0 Aug 21 10:07:40 ns1 /kernel: ad2: DMA limited to UDMA33, non-ATA66 cable or device Aug 21 10:07:40 ns1 /kernel: ad2: 38166MB <WDC WD400EB-00CPF0> [77545/16/63] at ata1-master UDMA33 Aug 21 10:07:40 ns1 /kernel: acd0: CDROM <ASUS CD-S400/A> at ata0-master PIO4 Aug 21 10:07:40 ns1 /kernel: Waiting 15 seconds for SCSI devices to settle Aug 21 10:07:40 ns1 /kernel: Mounting root from ufs:/dev/da0s1a Aug 21 10:07:40 ns1 /kernel: da0 at ahc0 bus 0 target 6 lun 0 Aug 21 10:07:40 ns1 /kernel: da0: <IBM DNES-309170W SA30> Fixed Direct Access SCSI-3 device Aug 21 10:07:40 ns1 /kernel: da0: 80.000MB/s transfers (40.000MHz, offset 31, 16bit), Tagged Queueing Enabled Aug 21 10:07:40 ns1 /kernel: da0: 8748MB (17916240 512 byte sectors: 255H 63S/T 1115C) To Unsubscribe: send mail to majordomo@FreeBSD.org with "unsubscribe freebsd-hackers" in the body of the message
Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?3D9045E1.7040302>