2.2.10-ac8 SCSI timeout/wait_on_bh

Paul Fulghum (paulkf@austin.rr.com)
Sun, 04 Jul 1999 15:14:26 -0500


I got the following output on the serial console while
stressing 2.2.10-ac8. Bonnie was running locally and two
other machines were running Bonnie over NFS to the local
machine. After this occurred, X-windows locked, no network
traffic, no telnet etc. None of this made it to the logs.

several lines of

aborting command due to timeout scsi 1 chan 0 id 1 lun 0
read (10) 00 00 d4 86 29 00 00 30 00
aborting command due to timeout scsi 1 chan 0 id 1 lun 0
write

etc...

followed by
wait_on_bh, CPU0:
irq: 0 [0 0]
bh: 1 [0 1]
c010b31d synchronize_bh (c010b2e0)
c018dade tcp_listen_poll(c018dacc)
c018db59 tcp_poll (c018db1c)
c019cec5 inet_poll (c019cea4)
c0179ee7 sock_poll (c0179ec8)
c0132687 do_select (c0132540)
c0133b76 sys_select (c013277c)

followed by:
scsi host 1 channel 0 reset (pid:xxx) timed out - trying harder
scsi bus is being reset for host 1 channel 0

these last lines were repeated every 10-15 seconds until I reset
the machine.

Information about system:
(all was taken after reboot)

Jul 4 14:32:06 p6 syslogd 1.3-3: restart.
Jul 4 14:32:06 p6 syslog: syslogd startup succeeded
Jul 4 14:32:06 p6 kernel: klogd 1.3-3, log source = /proc/kmsg started.
Jul 4 14:32:06 p6 kernel: Inspecting /boot/System.map-2.2.10-ac8
Jul 4 14:32:06 p6 syslog: klogd startup succeeded
Jul 4 14:32:06 p6 kernel: Loaded 7498 symbols from
/boot/System.map-2.2.10-ac8.
Jul 4 14:32:06 p6 kernel: Symbols match kernel version 2.2.10.
Jul 4 14:32:06 p6 kernel: Loaded 2 symbols from 3 modules.
Jul 4 14:32:06 p6 kernel: Linux version 2.2.10-ac8
(root@p6.pipehead.org) (gcc version egcs-2.91.66 19990314/Linux
(egcs-1.1.2 release)) #1 SMP Sun Jul 4 09:59:46 CDT 1999
Jul 4 14:32:06 p6 kernel: Intel MultiProcessor Specification v1.1
Jul 4 14:32:06 p6 kernel: Virtual Wire compatibility mode.
Jul 4 14:32:06 p6 kernel: OEM ID: INTEL Product ID: 440BX
APIC at: 0xFEE00000
Jul 4 14:32:06 p6 kernel: Processor #0 Pentium(tm) Pro APIC version 17
Jul 4 14:32:06 p6 kernel: Processor #1 Pentium(tm) Pro APIC version 17
Jul 4 14:32:06 p6 kernel: I/O APIC #2 Version 17 at 0xFEC00000.
Jul 4 14:32:06 p6 kernel: Processors: 2
Jul 4 14:32:06 p6 kernel: mapped APIC to ffffe000 (fee00000)
Jul 4 14:32:06 p6 kernel: mapped IOAPIC to ffffd000 (fec00000)
Jul 4 14:32:06 p6 kernel: Detected 400913033 Hz processor.
Jul 4 14:32:06 p6 kernel: Console: colour VGA+ 80x25
Jul 4 14:32:06 p6 kernel: Calibrating delay loop... 399.77 BogoMIPS
Jul 4 14:32:06 p6 kernel: Memory: 127816k/131072k available (1212k
kernel code, 416k reserved, 1580k data, 48k init)
Jul 4 14:32:06 p6 kernel: VFS: Diskquotas version dquot_6.4.0
initialized
Jul 4 14:32:06 p6 kernel: Checking 386/387 coupling... OK, FPU using
exception 16 error reporting.
Jul 4 14:32:06 p6 kernel: Checking 'hlt' instruction... OK.
Jul 4 14:32:06 p6 kernel: POSIX conformance testing by UNIFIX
Jul 4 14:32:06 p6 kernel: mtrr: v1.35 (19990512) Richard Gooch
(rgooch@atnf.csiro.au)
Jul 4 14:32:06 p6 kernel: per-CPU timeslice cutoff: 100.22 usecs.
Jul 4 14:32:06 p6 kernel: CPU0: Intel Pentium II (Deschutes) stepping
01
Jul 4 14:32:06 p6 kernel: calibrating APIC timer ...
Jul 4 14:32:06 p6 kernel: ..... CPU clock speed is 400.9141 MHz.
Jul 4 14:32:06 p6 kernel: ..... system bus clock speed is 100.2283 MHz.
Jul 4 14:32:06 p6 kernel: Booting processor 1 eip 2000
Jul 4 14:32:06 p6 kernel: Calibrating delay loop... 400.59 BogoMIPS
Jul 4 14:32:06 p6 kernel: OK.
Jul 4 14:32:06 p6 kernel: CPU1: Intel Pentium II (Deschutes) stepping
01
Jul 4 14:32:06 p6 kernel: Total of 2 processors activated (800.36
BogoMIPS).
Jul 4 14:32:06 p6 kernel: enabling symmetric IO mode... ...done.
Jul 4 14:32:06 p6 kernel: ENABLING IO-APIC IRQs
Jul 4 14:32:06 p6 kernel: init IO_APIC IRQs
Jul 4 14:32:06 p6 kernel: IO-APIC pin 0, 5, 10, 11, 15, 20, 21, 22, 23
not connected.
Jul 4 14:32:06 p6 kernel: number of MP IRQ sources: 17.
Jul 4 14:32:06 p6 kernel: number of IO-APIC registers: 24.
Jul 4 14:32:06 p6 kernel: testing the IO APIC.......................
Jul 4 14:32:06 p6 kernel: .... register #00: 02000000
Jul 4 14:32:06 p6 kernel: ....... : physical APIC id: 02
Jul 4 14:32:06 p6 kernel: .... register #01: 00170011
Jul 4 14:32:06 p6 kernel: ....... : max redirection entries: 0017
Jul 4 14:32:06 p6 kernel: ....... : IO APIC version: 0011
Jul 4 14:32:06 p6 kernel: .... register #02: 00000000
Jul 4 14:32:06 p6 kernel: ....... : arbitration: 00
Jul 4 14:32:07 p6 atd: atd startup succeeded
Jul 4 14:32:06 p6 kernel: .... IRQ redirection table:
Jul 4 14:32:06 p6 kernel: NR Log Phy Mask Trig IRR Pol Stat Dest Deli
Vect:
Jul 4 14:32:06 p6 kernel: 00 000 00 1 0 0 0 0 0 0
00
Jul 4 14:32:06 p6 kernel: 01 000 00 0 0 0 0 0 1 1
59
Jul 4 14:32:06 p6 kernel: 02 0FF 0F 0 0 0 0 0 1 1
51
Jul 4 14:32:06 p6 kernel: 03 000 00 0 0 0 0 0 1 1
61
Jul 4 14:32:06 p6 kernel: 04 000 00 0 0 0 0 0 1 1
69
Jul 4 14:32:06 p6 kernel: 05 000 00 1 0 0 0 0 0 0
00
Jul 4 14:32:06 p6 kernel: 06 000 00 0 0 0 0 0 1 1
71
Jul 4 14:32:06 p6 kernel: 07 000 00 0 0 0 0 0 1 1
79
Jul 4 14:32:06 p6 kernel: 08 000 00 0 0 0 0 0 1 1
81
Jul 4 14:32:06 p6 kernel: 09 000 00 0 0 0 0 0 1 1
89
Jul 4 14:32:06 p6 kernel: 0a 000 00 1 0 0 0 0 0 0
00
Jul 4 14:32:07 p6 crond: crond startup succeeded
Jul 4 14:32:06 p6 kernel: 0b 000 00 1 0 0 0 0 0 0
00
Jul 4 14:32:06 p6 kernel: 0c 000 00 0 0 0 0 0 1 1
91
Jul 4 14:32:06 p6 kernel: 0d 000 00 1 0 0 0 0 0 0
00
Jul 4 14:32:06 p6 kernel: 0e 000 00 0 0 0 0 0 1 1
99
Jul 4 14:32:06 p6 kernel: 0f 000 00 1 0 0 0 0 0 0
00
Jul 4 14:32:06 p6 kernel: 10 0FF 0F 1 1 0 1 0 1 1
A1
Jul 4 14:32:06 p6 kernel: 11 0FF 0F 1 1 0 1 0 1 1
A9
Jul 4 14:32:06 p6 kernel: 12 0FF 0F 1 1 0 1 0 1 1
B1
Jul 4 14:32:06 p6 kernel: 13 0FF 0F 1 1 0 1 0 1 1
B9
Jul 4 14:32:06 p6 kernel: 14 000 00 1 0 0 0 0 0 0
00
Jul 4 14:32:06 p6 kernel: 15 000 00 1 0 0 0 0 0 0
00
Jul 4 14:32:06 p6 kernel: 16 000 00 1 0 0 0 0 0 0
00
Jul 4 14:32:06 p6 kernel: 17 000 00 1 0 0 0 0 0 0
00
Jul 4 14:32:07 p6 rc: Starting pcmcia succeeded
Jul 4 14:32:06 p6 kernel: .................................... done.
Jul 4 14:32:06 p6 kernel: PCI: PCI BIOS revision 2.10 entry at 0xfdb81
Jul 4 14:32:06 p6 kernel: PCI: Using configuration type 1
Jul 4 14:32:06 p6 kernel: PCI: Probing PCI hardware
Jul 4 14:32:06 p6 kernel: Linux NET4.0 for Linux 2.2
Jul 4 14:32:06 p6 kernel: Based upon Swansea University Computer
Society NET3.039
Jul 4 14:32:06 p6 kernel: NET4: Unix domain sockets 1.0 for Linux
NET4.0.
Jul 4 14:32:08 p6 inet: inetd startup succeeded
Jul 4 14:32:06 p6 kernel: NET4: Linux TCP/IP 1.0 for NET4.0
Jul 4 14:32:06 p6 kernel: IP Protocols: ICMP, UDP, TCP
Jul 4 14:32:06 p6 kernel: Initializing RT netlink socket
Jul 4 14:32:06 p6 kernel: Starting kswapd v 1.5
Jul 4 14:32:06 p6 kernel: Detected PS/2 Mouse Port.
Jul 4 14:32:06 p6 kernel: Serial driver version 4.27 with no serial
options enabled
Jul 4 14:32:06 p6 kernel: ttyS01 at 0x02f8 (irq = 3) is a 16550A
Jul 4 14:32:06 p6 kernel: pty: 256 Unix98 ptys configured
Jul 4 14:32:06 p6 kernel: Real Time Clock Driver v1.09
Jul 4 14:32:06 p6 kernel: Non-volatile memory driver v1.0
Jul 4 14:32:06 p6 kernel: RAM disk driver initialized: 16 RAM disks of
4096K size
Jul 4 14:32:06 p6 kernel: Floppy drive(s): fd0 is 1.44M
Jul 4 14:32:06 p6 kernel: FDC 0 is a post-1991 82077
Jul 4 14:32:06 p6 kernel: (scsi0) <Adaptec AIC-7895 Ultra SCSI host
adapter> found at PCI 14/0
Jul 4 14:32:06 p6 kernel: (scsi0) Wide Channel A, SCSI ID=7, 32/255
SCBs
Jul 4 14:32:08 p6 snmpd: snmpd startup succeeded
Jul 4 14:32:06 p6 kernel: (scsi0) Downloading sequencer code... 374
instructions downloaded
Jul 4 14:32:06 p6 kernel: (scsi1) <Adaptec AIC-7895 Ultra SCSI host
adapter> found at PCI 14/1
Jul 4 14:32:06 p6 kernel: (scsi1) Wide Channel B, SCSI ID=7, 32/255
SCBs
Jul 4 14:32:06 p6 kernel: (scsi1) Downloading sequencer code... 374
instructions downloaded
Jul 4 14:32:06 p6 kernel: scsi0 : Adaptec AHA274x/284x/294x
(EISA/VLB/PCI-Fast SCSI) 5.1.18/3.2.4
Jul 4 14:32:06 p6 kernel: <Adaptec AIC-7895 Ultra SCSI host
adapter>
Jul 4 14:32:06 p6 kernel: scsi1 : Adaptec AHA274x/284x/294x
(EISA/VLB/PCI-Fast SCSI) 5.1.18/3.2.4
Jul 4 14:32:06 p6 kernel: <Adaptec AIC-7895 Ultra SCSI host
adapter>
Jul 4 14:32:06 p6 kernel: scsi : 2 hosts.
Jul 4 14:32:06 p6 kernel: (scsi0:0:3:0) Synchronous at 10.0 Mbyte/sec,
offset 15.
Jul 4 14:32:06 p6 kernel: Vendor: PLEXTOR Model: CD-ROM PX-20TS
Rev: 1.01
Jul 4 14:32:06 p6 kernel: Type: CD-ROM
ANSI SCSI revision: 02
Jul 4 14:32:08 p6 lpd: lpd startup succeeded
Jul 4 14:32:06 p6 kernel: Detected scsi CD-ROM sr0 at scsi0, channel 0,
id 3, lun 0
Jul 4 14:32:06 p6 kernel: Vendor: RICOH Model: MP6200S
Rev: 1.20
Jul 4 14:32:06 p6 kernel: Type: CD-ROM
ANSI SCSI revision: 02
Jul 4 14:32:06 p6 kernel: Detected scsi CD-ROM sr1 at scsi0, channel 0,
id 4, lun 0
Jul 4 14:32:06 p6 kernel: (scsi1:0:0:0) Synchronous at 40.0 Mbyte/sec,
offset 8.
Jul 4 14:32:06 p6 kernel: Vendor: IBM Model: DDRS-39130W
Rev: S92A
Jul 4 14:32:06 p6 kernel: Type: Direct-Access
ANSI SCSI revision: 02
Jul 4 14:32:06 p6 kernel: Detected scsi disk sda at scsi1, channel 0,
id 0, lun 0
Jul 4 14:32:06 p6 kernel: (scsi1:0:1:0) Synchronous at 40.0 Mbyte/sec,
offset 8.
Jul 4 14:32:06 p6 kernel: Vendor: IBM Model: DDRS-39130W
Rev: S97B
Jul 4 14:32:06 p6 kernel: Type: Direct-Access
ANSI SCSI revision: 02
Jul 4 14:32:06 p6 kernel: Detected scsi disk sdb at scsi1, channel 0,
id 1, lun 0
Jul 4 14:32:09 p6 nfs: Starting NFS services: succeeded
Jul 4 14:32:06 p6 kernel: scsi : detected 2 SCSI cdroms 2 SCSI disks
total.
Jul 4 14:32:06 p6 kernel: Uniform CDROM driver Revision: 2.55
Jul 4 14:32:06 p6 kernel: sr1: scsi3-mmc drive: 6x/6x writer cd/rw
xa/form2 cdda tray
Jul 4 14:32:06 p6 kernel: SCSI device sda: hdwr sector= 512 bytes.
Sectors= 17850000 [8715 MB] [8.7 GB]
Jul 4 14:32:06 p6 kernel: SCSI device sdb: hdwr sector= 512 bytes.
Sectors= 17850000 [8715 MB] [8.7 GB]
Jul 4 14:32:06 p6 kernel: Partition check:
Jul 4 14:32:06 p6 kernel: sda: sda1 sda2 < sda5 sda6 sda7 >
Jul 4 14:32:06 p6 kernel: sdb: sdb1! sdb3 < sdb5 sdb6 sdb7 > < sdb8
sdb9 sdb10 >
Jul 4 14:32:06 p6 kernel: NTFS version 990411
Jul 4 14:32:06 p6 kernel: VFS: Mounted root (ext2 filesystem) readonly.
Jul 4 14:32:06 p6 kernel: Freeing unused kernel memory: 48k freed
Jul 4 14:32:06 p6 kernel: Adding Swap: 120452k swap-space (priority -1)
Jul 4 14:32:06 p6 kernel: 3c59x.c:v0.99H 11/17/98 Donald Becker
http://cesdis.gsfc.nasa.gov/linux/drivers/vortex.html
Jul 4 14:32:09 p6 nfs: rpc.statd startup succeeded
Jul 4 14:32:06 p6 kernel: eth0: 3Com 3c900 Boomerang 10baseT at
0xef00, 00:10:4b:d5:71:f9, IRQ 11
Jul 4 14:32:06 p6 kernel: 8K word-wide RAM 3:5 Rx:Tx split,
autoselect/10baseT interface.
Jul 4 14:32:06 p6 kernel: Enabling bus-master transmits and
whole-frame receives.
Jul 4 14:32:09 p6 kernel: Installing knfsd (copyright (C) 1996
okir@monad.swb.de).
Jul 4 14:32:10 p6 nfs: rpc.rquotad startup succeeded
Jul 4 14:32:10 p6 nfs: rpc.mountd startup succeeded
Jul 4 14:32:11 p6 nfs: rpc.nfsd startup succeeded
Jul 4 14:32:11 p6 keytable: Loading keymap:
Jul 4 14:32:12 p6 keytable: Loading
/usr/lib/kbd/keymaps/i386/qwerty/us.kmap.gz
Jul 4 14:32:12 p6 keytable: Loading system font:
Jul 4 14:32:12 p6 rc: Starting keytable succeeded
Jul 4 14:32:13 p6 sendmail: sendmail startup succeeded
Jul 4 14:32:13 p6 gpm: gpm startup succeeded
Jul 4 14:32:14 p6 httpd: httpd startup succeeded
Jul 4 14:32:14 p6 sound: Starting sound configuration:
Jul 4 14:32:14 p6 sound: sound
Jul 4 14:32:14 p6 sound:
Jul 4 14:32:14 p6 rc: Starting sound succeeded
Jul 4 14:32:15 p6 xfs: xfs startup succeeded
Jul 4 14:32:16 p6 smb: smbd startup succeeded
Jul 4 14:32:16 p6 smb: nmbd startup succeeded
Jul 4 14:32:16 p6 linuxconf: Linuxconf final setup
Jul 4 14:32:16 p6 rc: Starting linuxconf succeeded
Jul 4 14:32:16 p6 rc: Starting local succeeded

CPU0 CPU1
0: 114014 110225 IO-APIC-edge timer
1: 2643 2282 IO-APIC-edge keyboard
2: 0 0 XT-PIC cascade
3: 135 101 IO-APIC-edge serial
8: 2 0 IO-APIC-edge rtc
10: 22426 22897 IO-APIC-level aic7xxx, aic7xxx
11: 171084 169611 IO-APIC-level eth0
12: 12292 11202 IO-APIC-edge PS/2 Mouse
13: 1 0 XT-PIC fpu
NMI: 0
ERR: 0
Adaptec AIC7xxx driver version: 5.1.18/3.2.4
Compile Options:
TCQ Enabled By Default : Enabled
AIC7XXX_PROC_STATS : Enabled
AIC7XXX_RESET_DELAY : 5

Adapter Configuration:
SCSI Adapter: Adaptec AIC-7895 Ultra SCSI host adapter
Ultra Wide Controller Channel B
PCI MMAPed I/O Base: 0xfebff000
Adapter SEEPROM Config: SEEPROM found and used.
Adaptec SCSI BIOS: Enabled
IRQ: 10
SCBs: Active 0, Max Active 24,
Allocated 60, HW 32, Page 255
Interrupts: 45384
BIOS Control Word: 0x18a6
Adapter Control Word: 0x005e
Extended Translation: Enabled
Disconnect Enable Flags: 0xffff
Ultra Enable Flags: 0x0003
Tag Queue Enable Flags: 0x0003
Ordered Queue Tag Flags: 0x0003
Default Tag Queue Depth: 24
Tagged Queue By Device array for aic7xxx host instance 1:
{0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0}
Actual queue depth per device for aic7xxx host instance 1:
{24,24,1,1,1,1,1,1,1,1,1,1,1,1,1,1}

Statistics:

(scsi1:0:0:0)
Device using Wide/Sync transfers at 40.0 MByte/sec, offset 8
Transinfo settings: current(12/8/1/0), goal(12/8/1/0), user(12/15/1/0)
Total transfers 289 (289 reads and 0 writes)
< 2K 2K+ 4K+ 8K+ 16K+ 32K+ 64K+
128K+
Reads: 289 0 0 0 0 0 0
0
Writes: 0 0 0 0 0 0 0
0

(scsi1:0:1:0)
Device using Wide/Sync transfers at 40.0 MByte/sec, offset 8
Transinfo settings: current(12/8/1/0), goal(12/8/1/0), user(12/15/1/0)
Total transfers 45007 (31637 reads and 13370 writes)
< 2K 2K+ 4K+ 8K+ 16K+ 32K+ 64K+
128K+
Reads: 11172 1442 5549 6639 2157 3471 1207
0
Writes: 4910 1922 1261 2697 133 78 2369
0

-- 
Paul Fulghum
paulkf@austin.rr.com
"what kind of party is this?
 there's no booze and only one hooker..." - Bender

- To unsubscribe from this list: send the line "unsubscribe linux-kernel" in the body of a message to majordomo@vger.rutgers.edu Please read the FAQ at http://www.tux.org/lkml/