From owner-freebsd-scsi Sat Jan 2 01:52:24 1999 Return-Path: Received: (from majordom@localhost) by hub.freebsd.org (8.8.8/8.8.8) id BAA00820 for freebsd-scsi-outgoing; Sat, 2 Jan 1999 01:52:24 -0800 (PST) (envelope-from owner-freebsd-scsi@FreeBSD.ORG) Received: from news2.du.gtn.com (news2.du.gtn.com [194.77.9.57]) by hub.freebsd.org (8.8.8/8.8.8) with ESMTP id BAA00814 for ; Sat, 2 Jan 1999 01:52:19 -0800 (PST) (envelope-from ticso@cicely7.cicely.de) Received: from cicely7.cicely.de (cicely.de [194.231.9.142]) by news2.du.gtn.com (8.8.6/8.8.6) with ESMTP id KAA21626; Sat, 2 Jan 1999 10:51:49 +0100 (MET) Received: (from ticso@localhost) by cicely7.cicely.de (8.9.0/8.9.0) id KAA00515; Sat, 2 Jan 1999 10:51:38 +0100 (CET) Message-ID: <19990102105138.35033@cicely.de> Date: Sat, 2 Jan 1999 10:51:38 +0100 From: Bernd Walter To: freebsd-scsi@FreeBSD.ORG, grog@lemis.com Subject: new Quirk candidate and vinum behavour Mime-Version: 1.0 Content-Type: text/plain; charset=us-ascii X-Mailer: Mutt 0.89i Sender: owner-freebsd-scsi@FreeBSD.ORG Precedence: bulk X-Loop: FreeBSD.org I have had one of my hosts crashed sometime. Today I got a crash after setting logs to another volume: Jan 2 03:30:16 cicely7 /kernel: (da0:ahc0:0:1:0): tagged openings now 32 Jan 2 03:30:18 cicely7 /kernel: (da0:ahc0:0:1:0): tagged openings now 31 Jan 2 03:30:32 cicely7 syslogd: /var/log/messages: Input/output error Jan 2 03:30:32 cicely7 syslogd: /var/log/all.log: Input/output error Jan 2 03:30:32 cicely7 /kernel: ahc0:A:1: no active SCB for reconnecting target - issuing BUS DEVICE RESET Jan 2 03:30:32 cicely7 /kernel: SAVED_TCL == 0x10, ARG_1 == 0x20, SEQ_FLAGS == 0x0 Jan 2 03:30:32 cicely7 /kernel: ahc0: Bus Device Reset on A:1. 1 SCBs aborted Jan 2 03:30:32 cicely7 /kernel: vinum: subdisk var.p0.s0 is crashed Jan 2 03:30:32 cicely7 /kernel: vinum: plex var.p0 is degraded Jan 2 03:30:32 cicely7 /kernel: vinum: subdisk var.p0.s0 is stale Jan 2 03:30:32 cicely7 /kernel: vinum: plex var.p0 is down Jan 2 03:30:48 cicely7 /kernel: (da0:ahc0:0:1:0): tagged openings now 32 Jan 2 03:30:48 cicely7 /kernel: (da0:ahc0:0:1:0): tagged openings now 31 Jan 2 03:30:48 cicely7 /kernel: ahc0:A:1: no active SCB for reconnecting target - issuing BUS DEVICE RESET Jan 2 03:30:48 cicely7 /kernel: SAVED_TCL == 0x10, ARG_1 == 0x20, SEQ_FLAGS == 0x40 Jan 2 03:30:48 cicely7 /kernel: ahc0: Bus Device Reset on A:1. 31 SCBs aborted Jan 2 03:30:48 cicely7 /kernel: (da0:ahc0:0:1:0): tagged openings now 32 Jan 2 03:30:48 cicely7 /kernel: (da0:ahc0:0:1:0): tagged openings now 31 Jan 2 03:30:48 cicely7 /kernel: ahc0:A:1: no active SCB for reconnecting target - issuing BUS DEVICE RESET Jan 2 03:30:48 cicely7 /kernel: SAVED_TCL == 0x10, ARG_1 == 0x20, SEQ_FLAGS == 0x40 Jan 2 03:30:48 cicely7 /kernel: ahc0: Bus Device Reset on A:1. 31 SCBs aborted Jan 2 03:30:48 cicely7 /kernel: (da0:ahc0:0:1:0): tagged openings now 32 Jan 2 03:30:48 cicely7 /kernel: (da0:ahc0:0:1:0): tagged openings now 31 Jan 2 03:30:48 cicely7 /kernel: ahc0:A:1: no active SCB for reconnecting target - issuing BUS DEVICE RESET Jan 2 03:30:48 cicely7 /kernel: SAVED_TCL == 0x10, ARG_1 == 0x20, SEQ_FLAGS == 0x40 Jan 2 03:30:48 cicely7 /kernel: ahc0: Bus Device Reset on A:1. 31 SCBs aborted Jan 2 03:30:48 cicely7 /kernel: (da0:ahc0:0:1:0): tagged openings now 32 Jan 2 03:30:48 cicely7 /kernel: (da0:ahc0:0:1:0): tagged openings now 31 Jan 2 03:30:48 cicely7 /kernel: ahc0:A:1: no active SCB for reconnecting target - issuing BUS DEVICE RESET Jan 2 03:30:49 cicely7 /kernel: SAVED_TCL == 0x10, ARG_1 == 0x0, SEQ_FLAGS == 0x40 Jan 2 03:30:49 cicely7 /kernel: ahc0: Bus Device Reset on A:1. 16 SCBs aborted Jan 2 03:31:04 cicely7 /kernel: (da0:ahc0:0:1:0): tagged openings now 32 Jan 2 03:31:04 cicely7 /kernel: ahc0:A:1: no active SCB for reconnecting target - issuing BUS DEVICE RESET Jan 2 03:31:04 cicely7 /kernel: SAVED_TCL == 0x10, ARG_1 == 0x20, SEQ_FLAGS == 0x40 Jan 2 03:31:04 cicely7 /kernel: ahc0: Bus Device Reset on A:1. 32 SCBs aborted Jan 2 03:31:04 cicely7 /kernel: (da0:ahc0:0:1:0): tagged openings now 31 Jan 2 03:31:33 cicely7 sendmail[810]: DAA00810: SYSERR(root): collect: Cannot write tfDAA00810: Input/output error Jan 2 03:31:33 cicely7 syslogd: /var/log/maillog: Input/output error Jan 2 03:31:33 cicely7 sendmail[810]: DAA00810: SYSERR(root): Error writing control file tfDAA00810: Input/output error Jan 2 03:31:33 cicely7 sendmail[2798]: NOQUEUE: SYSERR(root): queuename: Cannot create "qfDAA02798" in "/var/spool/mqueue" (euid=0) : Input/output error Jan 2 03:31:33 cicely7 syslogd: /var/cron/log: Input/output error Jan 2 03:42:41 cicely7 /kernel: spec_getpages: I/O read failure: (error code=5) Jan 2 03:42:41 cicely7 /kernel: size: 36864, resid: 36864, a_count: 36864, valid: 0x0 Jan 2 03:42:41 cicely7 /kernel: nread: 0, reqpage: 0, pindex: 0, pcount: 9 Jan 2 03:42:41 cicely7 /kernel: vm_fault: pager read error, pid 250 (sshd1) Jan 2 03:42:41 cicely7 last message repeated 23 times Jan 2 03:42:41 cicely7 /kernel: vm_fault: p and so on ... As you can see the host was not realy crashed but unuseable after it happened. The Problem with da0:ahc0:0:1:0 happens every time the tagged openings are increased The side effect is that I'm now running /var on a vinum volume on da1 and da2 which are drives on the same channel and it looks like the bdr or anything between the tag increase and the bdr is the reason for the subdisk crash. root@cicely7# dmesg Copyright (c) 1992-1998 FreeBSD Inc. Copyright (c) 1982, 1986, 1989, 1991, 1993 The Regents of the University of California. All rights reserved. FreeBSD 3.0-CURRENT #0: Sun Dec 20 13:55:04 CET 1998 root@cicely5.cicely.de:/usr/src/sys/compile/CICELY7 Timecounter "i8254" frequency 1193182 Hz Timecounter "TSC" frequency 90205005 Hz CPU: Pentium/P54C (90.21-MHz 586-class CPU) Origin = "GenuineIntel" Id = 0x525 Stepping=5 Features=0x1bf real memory = 67108864 (65536K bytes) config> quit avail memory = 62066688 (60612K bytes) Probing for devices on PCI bus 0: chip0: rev 0x01 on pci0.0.0 chip1: rev 0x01 on pci0.7.0 ide_pci0: rev 0x00 on pci0.7.1 ahc0: rev 0x00 int a irq 5 on pci0.8.0 ahc0: aic7880 Wide Channel A, SCSI Id=7, 16/255 SCBs ahc1: rev 0x00 int a irq 5 on pci0.9.0 ahc1: aic7870 Single Channel A, SCSI Id=7, 16/255 SCBs vga0: rev 0x00 on pci0.10.0 de0: rev 0x20 int a irq 5 on pci0.11.0 de0: Cogent 21140A [10-100Mb/s] pass 2.0 de0: address 00:00:92:9b:31:51 Probing for devices on the ISA bus: video#0: WARNING: video mode switching is not fully supported on this adapter sc0 at 0x60-0x6f irq 1 on motherboard sc0: VGA color <16 virtual consoles, flags=0x0> sio0 at 0x3f8-0x3ff irq 4 flags 0x10 on isa sio0: type 16550A sio1 at 0x2f8-0x2ff irq 7 on isa sio1: type 16550A sio2 at 0x3e8-0x3ef irq 11 on isa sio2: type 16550A sio3: configured irq 12 not in bitmap of probed irqs 0 sio3 at 0x2e8-0x2ef irq 12 on isa sio3: type 16550A fdc0 at 0x3f0-0x3f7 irq 6 drq 2 on isa fdc0: FIFO enabled, 8 bytes threshold fd0: 1.44MB 3.5in wdc0 at 0x1f0-0x1f7 irq 14 on isa wdc0: unit 0 (atapi): , removable atapi0.0: unknown phase wdc0: unit 1 (atapi): , removable, intr, iordis wcd1: 689KB/sec, 256KB cache, audio play, 255 volume levels, ejectable tray wcd1: 120mm data disc loaded, unlocked wdc1 at 0x170-0x177 irq 15 on isa wdc1: unit 0 (wd2): wd2: 1536MB (3145968 sectors), 3121 cyls, 16 heads, 63 S/T, 512 B/S npx0 on motherboard npx0: INT 16 interface Intel Pentium F00F detected, installing workaround Waiting 15 seconds for SCSI devices to settle (probe15:ahc1:0:0:0): Sending SDTR!! (probe19:ahc1:0:4:0): Sending SDTR!! da3 at ahc1 bus 0 target 0 lun 0 da3: Fixed Direct Access SCSI2 device da3: 10.0MB/s transfers (10.0MHz, offset 15), Tagged Queueing Enabled da3: 1665MB (3409965 512 byte sectors: 64H 32S/T 1665C) da0 at ahc0 bus 0 target 1 lun 0 da0: Fixed Direct Access SCSI2 device da0: 10.0MB/s transfers (10.0MHz, offset 15), Tagged Queueing Enabled da0: 1030MB (2110812 512 byte sectors: 64H 32S/T 1030C) cd0 at ahc0 bus 0 target 5 lun 0 cd0: Removable CD-ROM SCSI2 device cd0: 4.237MB/s transfers (4.237MHz, offset 15) cd0: cd present [270169 x 2048 byte records] da2 at ahc0 bus 0 target 4 lun 0 da2: Fixed Direct Access SCSI2 device da2: 10.0MB/s transfers (10.0MHz, offset 15), Tagged Queueing Enabled da2: 2006MB (4110000 512 byte sectors: 64H 32S/T 2006C) da1 at ahc0 bus 0 target 2 lun 0 da1: Fixed Direct Access SCSI2 device da1: 10.0MB/s transfers (10.0MHz, offset 15), Tagged Queueing Enabled da1: 2006MB (4110000 512 byte sectors: 64H 32S/T 2006C) da4 at ahc1 bus 0 target 4 lun 0 da4: Fixed Direct Access SCSI2 device da4: 10.0MB/s transfers (10.0MHz, offset 15), Tagged Queueing Enabled da4: 1665MB (3409965 512 byte sectors: 64H 32S/T 1665C) changing root device to da0s1a de0: autosense failed: cable problem? vinum: loaded vinum: drive cuda1 is up vinum: drive cuda2 is up vinum: drive fujitsu1 is up vinum: drive fujitsu2 is up vinum: subdisk var.p0.s0 is up vinum: subdisk var.p0.s1 is up vinum: subdisk news.p0.s0 is up vinum: subdisk news.p0.s1 is up vinum: plex var.p0 is up vinum: plex news.p0 is up vinum: volume var is up vinum: volume news is up WARNING: R/W mount of /var denied. Filesystem is not clean - run fsck de0: enabling 100baseTX port de0: enabling Full Duplex 100baseTX port root@cicely7# cat /etc/vinum.conf drive cuda1 device /dev/da1e drive cuda2 device /dev/da2e drive fujitsu1 device /dev/da3e drive fujitsu2 device /dev/da4e volume var setupstate plex org striped 128b sd length 4108000b drive cuda1 sd length 4108000b drive cuda2 volume news setupstate plex org striped 128b sd length 3402065b drive fujitsu1 sd length 3402065b drive fujitsu2 -- B.Walter To Unsubscribe: send mail to majordomo@FreeBSD.org with "unsubscribe freebsd-scsi" in the body of the message