Date: Thu, 19 Feb 2004 03:08:45 +1100 From: Tony Frank <tfrank@optushome.com.au> To: freebsd-questions@freebsd.org Subject: 4.9-stable system lockup with vinum raid5 activity Message-ID: <20040218160845.GA6332@marvin.home.local>
next in thread | raw e-mail | index | archive | help
Hi all,
I'm running 4.9-STABLE built 17th Feb based on cvsup on same day.
Custom kernel in use with device polling enabled on fxp0.
Kernel config is attached in case anyone can spot anything obvious there.
It's an 'older' system, Pentium2-200, 132mb ram, basic Asus slot1 m/b
(Via chipset) with 2 ide/ata disks (ad0, ad2)
Also has a adaptec 2940UW SCSI (ahc0) with 4x4g scsi drives (da0-da3)
kernel + vinum loaded via loader.conf with vinum root environment
built around ad0 & ad2.
See some other messages in questions regarding exact build of this box
due to previous problems with vinum & raid5 volume.
First I noticed fsck had errors right after I newfs'd my raid5 volume.
I let fsck fix the errors and mounted the volume.
I then copied some test data across and while this appeared to work, the
md5 checksum of the files copied across no longer matches my original
md5 records taken from both a separate system (transferred via ftp) and
from another volume (a vinum mirror) on the same system.
My test data is an iso CD image + a tar archive containing /usr/obj from
my build system. Around 1gig all up and lots of files/dirs in the tar file.
I then tried extracting the tar archive and after about 20 mins the
system appeared to freeze.
At this time vty switching was still working and I noticed the following
on the console:
(hand copy)
devstat_end_transaction: HELP!! busy_count for da2 is < 0 (-1)!
devstat_end_transaction: HELP!! busy_count for da2 is < 0 (-1)!
devstat_end_transaction: HELP!! busy_count for da3 is < 0 (-1)!
devstat_end_transaction: HELP!! busy_count for da3 is < 0 (-1)!
devstat_end_transaction: HELP!! busy_count for da3 is < 0 (-2)!
ahc0: Timedout SCB already complete. Interrupts may not be functioning.
ahc0: Timedout SCB already complete. Interrupts may not be functioning.
ahc0: Timedout SCB already complete. Interrupts may not be functioning.
ahc0: Timedout SCB already complete. Interrupts may not be functioning.
ahc0: Timedout SCB already complete. Interrupts may not be functioning.
ahc0: Timedout SCB already complete. Interrupts may not be functioning.
I tried a few commands but while the first few went through any
new command I ran through the console appeared to pause for ~5 mins
before running, eg "vmstat -i"
Pressing ctrl-t on the console for vmstat shows:
load: 0.00 cmd: vmstat 455 [flswai] 0.00u 0.01s 0% 472k
I eventually pressed 'ctl-alt-del' (no debugger in this kernel)
and after ~20 mins the box has now rebooted but did no restart.
As it is a test system I am now going to further investigate in
the morning.
Full history of what I was doing:
raider# umount /data
raider# newfs -v /dev/vinum/data
Warning: Block size and bytes per inode restrict cylinders per group to 22.
Warning: 1856 sector(s) in last cylinder unallocated
/dev/vinum/data: 35211456 sectors in 8597 cylinders of 1 tracks, 4096 sectors
17193.1MB in 391 cyl groups (22 c/g, 44.00MB/g, 10944 i/g)
super-block backups (for fsck -b #) at:
32, 90144, 180256, 270368, 360480, 450592, 540704, 630816, 720928, 811040, 901152, 991264, 1081376, 1171488, 1261600, 1351712, 1441824, 1531936, 1622048,
1712160, 1802272, 1892384, 1982496, 2072608, 2162720, 2252832, 2342944, 2433056, 2523168, 2613280, 2703392, 2793504, 2883616, 2973728, 3063840, 3153952,
3244064, 3334176, 3424288, 3514400, 3604512, 3694624, 3784736, 3874848, 3964960, 4055072, 4145184, 4235296, 4325408, 4415520, 4505632, 4595744, 4685856,
4775968, 4866080, 4956192, 5046304, 5136416, 5226528, 5316640, 5406752, 5496864, 5586976, 5677088, 5767200, 5857312, 5947424, 6037536, 6127648, 6217760,
6307872, 6397984, 6488096, 6578208, 6668320, 6758432, 6848544, 6938656, 7028768, 7118880, 7208992, 7299104, 7389216, 7479328, 7569440, 7659552, 7749664,
7839776, 7929888, 8020000, 8110112, 8200224, 8290336, 8380448, 8470560, 8560672, 8650784, 8740896, 8831008, 8921120, 9011232, 9101344, 9191456, 9281568,
9371680, 9461792, 9551904, 9642016, 9732128, 9822240, 9912352, 10002464, 10092576, 10182688, 10272800, 10362912, 10453024, 10543136, 10633248, 10723360,
10813472, 10903584, 10993696, 11083808, 11173920, 11264032, 11354144, 11444256, 11534368, 11624480, 11714592, 11804704, 11894816, 11984928, 12075040,
12165152, 12255264, 12345376, 12435488, 12525600, 12615712, 12705824, 12795936, 12886048, 12976160, 13066272, 13156384, 13246496, 13336608, 13426720,
13516832, 13606944, 13697056, 13787168, 13877280, 13967392, 14057504, 14147616, 14237728, 14327840, 14417952, 14508064, 14598176, 14688288, 14778400,
14868512, 14958624, 15048736, 15138848, 15228960, 15319072, 15409184, 15499296, 15589408, 15679520, 15769632, 15859744, 15949856, 16039968, 16130080,
16220192, 16310304, 16400416, 16490528, 16580640, 16670752, 16760864, 16850976, 16941088, 17031200, 17121312, 17211424, 17301536, 17391648, 17481760,
17571872, 17661984, 17752096, 17842208, 17932320, 18022432, 18112544, 18202656, 18292768, 18382880, 18472992, 18563104, 18653216, 18743328, 18833440,
18923552, 19013664, 19103776, 19193888, 19284000, 19374112, 19464224, 19554336, 19644448, 19734560, 19824672, 19914784, 20004896, 20095008, 20185120,
20275232, 20365344, 20455456, 20545568, 20635680, 20725792, 20815904, 20906016, 20996128, 21086240, 21176352, 21266464, 21356576, 21446688, 21536800,
21626912, 21717024, 21807136, 21897248, 21987360, 22077472, 22167584, 22257696, 22347808, 22437920, 22528032, 22618144, 22708256, 22798368, 22888480,
22978592, 23068704, 23158816, 23248928, 23339040, 23429152, 23519264, 23609376, 23699488, 23789600, 23879712, 23969824, 24059936, 24150048, 24240160,
24330272, 24420384, 24510496, 24600608, 24690720, 24780832, 24870944, 24961056, 25051168, 25141280, 25231392, 25321504, 25411616, 25501728, 25591840,
25681952, 25772064, 25862176, 25952288, 26042400, 26132512, 26222624, 26312736, 26402848, 26492960, 26583072, 26673184, 26763296, 26853408, 26943520,
27033632, 27123744, 27213856, 27303968, 27394080, 27484192, 27574304, 27664416, 27754528, 27844640, 27934752, 28024864, 28114976, 28205088, 28295200,
28385312, 28475424, 28565536, 28655648, 28745760, 28835872, 28925984, 29016096, 29106208, 29196320, 29286432, 29376544, 29466656, 29556768, 29646880,
29736992, 29827104, 29917216, 30007328, 30097440, 30187552, 30277664, 30367776, 30457888, 30548000, 30638112, 30728224, 30818336, 30908448, 30998560,
31088672, 31178784, 31268896, 31359008, 31449120, 31539232, 31629344, 31719456, 31809568, 31899680, 31989792, 32079904, 32170016, 32260128, 32350240,
32440352, 32530464, 32620576, 32710688, 32800800, 32890912, 32981024, 33071136, 33161248, 33251360, 33341472, 33431584, 33521696, 33611808, 33701920,
33792032, 33882144, 33972256, 34062368, 34152480, 34242592, 34332704, 34422816, 34512928, 34603040, 34693152, 34783264, 34873376, 34963488, 35053600,
35143712
raider# tunefs -n enable /dev/vinum/data
tunefs: soft updates set
raider# fsck /dev/vinum/data
** /dev/vinum/data
** Last Mounted on
** Phase 1 - Check Blocks and Sizes
PARTIALLY ALLOCATED INODE I=52408
UNEXPECTED SOFT UPDATE INCONSISTENCY
CLEAR? [yn] y
UNKNOWN FILE TYPE I=52409
UNEXPECTED SOFT UPDATE INCONSISTENCY
CLEAR? [yn] y
PARTIALLY ALLOCATED INODE I=970704
UNEXPECTED SOFT UPDATE INCONSISTENCY
CLEAR? [yn] ^C
***** FILE SYSTEM MARKED DIRTY *****
raider# fsck -y /dev/vinum/data
** /dev/vinum/data
** Last Mounted on
** Phase 1 - Check Blocks and Sizes
PARTIALLY ALLOCATED INODE I=970704
UNEXPECTED SOFT UPDATE INCONSISTENCY
CLEAR? yes
UNKNOWN FILE TYPE I=970705
UNEXPECTED SOFT UPDATE INCONSISTENCY
CLEAR? yes
PARTIALLY ALLOCATED INODE I=2916201
UNEXPECTED SOFT UPDATE INCONSISTENCY
CLEAR? yes
** Phase 2 - Check Pathnames
** Phase 3 - Check Connectivity
** Phase 4 - Check Reference Counts
** Phase 5 - Check Cyl groups
1 files, 1 used, 17064560 free (8 frags, 2133069 blocks, 0.0% fragmentation)
***** FILE SYSTEM MARKED CLEAN *****
***** FILE SYSTEM WAS MODIFIED *****
raider# fsck -y /dev/vinum/data
** /dev/vinum/data
** Last Mounted on
** Phase 1 - Check Blocks and Sizes
** Phase 2 - Check Pathnames
** Phase 3 - Check Connectivity
** Phase 4 - Check Reference Counts
** Phase 5 - Check Cyl groups
1 files, 1 used, 17064560 free (8 frags, 2133069 blocks, 0.0% fragmentation)
raider# mount /data
raider# tar cf - -C /usr/tmp . | tar xpf - -C /data
raider# tar cf - -C /usr/tmp . | tar xpf - -C /data
raider# pwd
/usr/tmp
raider# cd /data
raider# ll
total 1046006
-rw-r--r-- 1 root wheel 510709760 Feb 7 15:12 objtest.tar
-rw-r--r-- 1 root wheel 53 Feb 19 01:20 objtest.tar.d.md5
-rw-r--r-- 1 root wheel 53 Feb 19 01:00 objtest.tar.md5
-rw-r--r-- 1 root wheel 53 Feb 19 01:04 objtest.tar.r.md5
-rw-r--r-- 1 root wheel 559839232 Apr 13 2003 otest.iso
-rw-r--r-- 1 root wheel 54 Feb 19 01:21 otest.iso.d.md5
-rw-r--r-- 1 root wheel 54 Feb 19 01:00 otest.iso.md5
-rw-r--r-- 1 root wheel 54 Feb 19 01:07 otest.iso.r.md5
raider# md5 otest.iso > /usr/tmp/otest.iso.d.md5 &
[1] 398
raider# md5 objtest.tar > /usr/tmp/objtest.tar.d.md5 &
[2] 399
raider# fg
md5 otest.iso > /usr/tmp/otest.iso.d.md5
raider#
[2] Done md5 objtest.tar > /usr/tmp/objtest.tar.d.md5
raider# cd /usr/tmp
raider# ll
total 1046006
-rw-r--r-- 1 root wheel 510709760 Feb 7 15:12 objtest.tar
-rw-r--r-- 1 root wheel 53 Feb 19 01:51 objtest.tar.d.md5
-rw-r--r-- 1 root wheel 53 Feb 19 01:00 objtest.tar.md5
-rw-r--r-- 1 root wheel 53 Feb 19 01:04 objtest.tar.r.md5
-rw-r--r-- 1 root wheel 559839232 Apr 13 2003 otest.iso
-rw-r--r-- 1 root wheel 54 Feb 19 01:51 otest.iso.d.md5
-rw-r--r-- 1 root wheel 54 Feb 19 01:00 otest.iso.md5
-rw-r--r-- 1 root wheel 54 Feb 19 01:07 otest.iso.r.md5
raider# diff otest.iso.d.md5 otest.iso.r.md5
1c1
< MD5 (otest.iso) = f3b9f26df24416227d6f9734c858ee49
---
> MD5 (otest.iso) = 41ab9f997013558fdc9bf656ce570c64
raider# diff objtest.tar.d.md5 objtest.tar.r.md5
1c1
< MD5 (objtest.tar) = af81d3a24a9eec107a8bf14b3a8cc4bf
---
> MD5 (objtest.tar) = e09df10d7a58ab2db661803750c8764d
raider# pwd
/usr/tmp
raider# cd /
raider# umount /data
raider# fsck -y /data
** /dev/vinum/data
** Last Mounted on /data
** Phase 1 - Check Blocks and Sizes
** Phase 2 - Check Pathnames
** Phase 3 - Check Connectivity
** Phase 4 - Check Reference Counts
** Phase 5 - Check Cyl groups
9 files, 1046007 used, 16018554 free (2 frags, 2002319 blocks, 0.0% fragmentation)
raider# mount /data
raider# cd /data
raider# ls
objtest.tar objtest.tar.md5 otest.iso otest.iso.md5
objtest.tar.d.md5 objtest.tar.r.md5 otest.iso.d.md5 otest.iso.r.md5
raider# ls -al
total 1046008
drwxr-xr-x 2 root wheel 512 Feb 19 01:46 .
drwxr-xr-x 19 root wheel 512 Feb 18 15:30 ..
-rw-r--r-- 1 root wheel 510709760 Feb 7 15:12 objtest.tar
-rw-r--r-- 1 root wheel 53 Feb 19 01:20 objtest.tar.d.md5
-rw-r--r-- 1 root wheel 53 Feb 19 01:00 objtest.tar.md5
-rw-r--r-- 1 root wheel 53 Feb 19 01:04 objtest.tar.r.md5
-rw-r--r-- 1 root wheel 559839232 Apr 13 2003 otest.iso
-rw-r--r-- 1 root wheel 54 Feb 19 01:21 otest.iso.d.md5
-rw-r--r-- 1 root wheel 54 Feb 19 01:00 otest.iso.md5
-rw-r--r-- 1 root wheel 54 Feb 19 01:07 otest.iso.r.md5
raider# tar xf objtest.tar
<froze here>
vinum setup:
6 drives:
D vinumdrive0 State: up Device /dev/ad0s1h Avail: 0/8055 MB (0%)
D vinumdrive5 State: up Device /dev/ad2s1h Avail: 0/3093 MB (0%)
D vinumdrive1 State: up Device /dev/da0s1h Avail: 0/4298 MB (0%)
D vinumdrive2 State: up Device /dev/da1s1h Avail: 0/4298 MB (0%)
D vinumdrive3 State: up Device /dev/da2s1h Avail: 0/4298 MB (0%)
D vinumdrive4 State: up Device /dev/da3s1h Avail: 0/4298 MB (0%)
7 volumes:
V root State: up Plexes: 2 Size: 256 MB
V swap State: up Plexes: 2 Size: 256 MB
V var State: up Plexes: 2 Size: 256 MB
V tmp State: up Plexes: 2 Size: 256 MB
V usr State: up Plexes: 2 Size: 2069 MB
V data State: up Plexes: 1 Size: 16 GB
V junk State: up Plexes: 1 Size: 664 MB
12 plexes:
P root.p0 C State: up Subdisks: 1 Size: 256 MB
P swap.p0 C State: up Subdisks: 1 Size: 256 MB
P var.p0 C State: up Subdisks: 1 Size: 256 MB
P tmp.p0 C State: up Subdisks: 1 Size: 256 MB
P usr.p0 C State: up Subdisks: 1 Size: 2069 MB
P root.p1 C State: up Subdisks: 1 Size: 256 MB
P swap.p1 C State: up Subdisks: 1 Size: 256 MB
P var.p1 C State: up Subdisks: 1 Size: 256 MB
P tmp.p1 C State: up Subdisks: 1 Size: 256 MB
P usr.p1 C State: up Subdisks: 1 Size: 2069 MB
P data.p0 R5 State: up Subdisks: 5 Size: 16 GB
P junk.p0 C State: up Subdisks: 1 Size: 664 MB
16 subdisks:
S root.p0.s0 State: up PO: 0 B Size: 256 MB
S swap.p0.s0 State: up PO: 0 B Size: 256 MB
S var.p0.s0 State: up PO: 0 B Size: 256 MB
S tmp.p0.s0 State: up PO: 0 B Size: 256 MB
S usr.p0.s0 State: up PO: 0 B Size: 2069 MB
S root.p1.s0 State: up PO: 0 B Size: 256 MB
S swap.p1.s0 State: up PO: 0 B Size: 256 MB
S var.p1.s0 State: up PO: 0 B Size: 256 MB
S tmp.p1.s0 State: up PO: 0 B Size: 256 MB
S usr.p1.s0 State: up PO: 0 B Size: 2069 MB
S data.p0.s0 State: up PO: 0 B Size: 4298 MB
S data.p0.s1 State: up PO: 492 kB Size: 4298 MB
S data.p0.s2 State: up PO: 984 kB Size: 4298 MB
S data.p0.s3 State: up PO: 1476 kB Size: 4298 MB
S data.p0.s4 State: up PO: 1968 kB Size: 4298 MB
S junk.p0.s0 State: up PO: 0 B Size: 664 MB
My kernel config file RAIDER:
machine i386
cpu I686_CPU
ident RAIDER
maxusers 0
options NO_F00F_HACK
#makeoptions DEBUG=-g #Build kernel with gdb(1) debug symbols
options INCLUDE_CONFIG_FILE
options DEVICE_POLLING
options HZ=1000
options DUMMYNET
options IPSTEALTH
options IPDIVERT
options IPFIREWALL_FORWARD
options IPFIREWALL_VERBOSE
options IPFIREWALL
options IPFW2
options RANDOM_IP_ID
options IPSEC_ESP
options IPSEC
options INET #InterNETworking
options FFS #Berkeley Fast Filesystem
options FFS_ROOT #FFS usable as root device [keep this!]
options SOFTUPDATES #Enable FFS soft updates support
options UFS_DIRHASH #Improve performance on big directories
options MFS
options MD_ROOT
options NFS #Network Filesystem
options NFS_ROOT #NFS usable as root device, NFS required
options PROCFS #Process filesystem
options COMPAT_43 #Compatible with BSD 4.3 [KEEP THIS!]
options SCSI_DELAY=9000 #Delay (in ms) before probing SCSI
options UCONSOLE #Allow users to grab the console
options USERCONFIG #boot -c editor
options KTRACE #ktrace(1) support
options SYSVSHM #SYSV-style shared memory
options SYSVMSG #SYSV-style message queues
options SYSVSEM #SYSV-style semaphores
options P1003_1B #Posix P1003_1B real-time extensions
options _KPOSIX_PRIORITY_SCHEDULING
options ICMP_BANDLIM #Rate limit bad replies
options KBD_INSTALL_CDEV # install a CDEV entry in /dev
options AHC_REG_PRETTY_PRINT # Print register bitfields in debug
# output. Adds ~128k to driver.
device isa
device pci
options PCI_ENABLE_IO_MODES
# Floppy drives
device fdc0 at isa? port IO_FD1 irq 6 drq 2
device fd0 at fdc0 drive 0
# ATA and ATAPI devices
device ata
device atadisk # ATA disk drives
device atapicd # ATAPI CDROM drives
device atapicam
options ATA_STATIC_ID #Static device numbering
# SCSI Controllers
device ahc # AHA2940 and onboard AIC7xxx devices
options AHC_ALLOW_MEMIO
# SCSI peripherals
device scbus # SCSI bus (required)
device da # Direct Access (disks)
device cd # CD
device pass # Passthrough device (direct SCSI access)
# atkbdc0 controls both the keyboard and the PS/2 mouse
device atkbdc0 at isa? port IO_KBD
device atkbd0 at atkbdc? irq 1 flags 0x1
device psm0 at atkbdc? irq 12
device vga0 at isa?
# splash screen/screen saver
pseudo-device splash
options VESA
# syscons is the default console driver, resembling an SCO console
device sc0 at isa? flags 0x100
options SC_HISTORY_SIZE=1024
device agp # support several AGP chipsets
# Floating point support - do not disable.
device npx0 at nexus? port IO_NPX irq 13
# Power management support (see LINT for more options)
device apm0 at nexus? # Advanced Power Management
# Serial (COM) ports
device sio0 at isa? port IO_COM1 flags 0x10 irq 4
device sio1 at isa? port IO_COM2 irq 3
# Parallel port
device ppc0 at isa? irq 7
device ppbus # Parallel port bus (required)
device lpt # Printer
device ppi # Parallel port interface device
# PCI Ethernet NICs that use the common MII bus controller code.
# NOTE: Be sure to keep the 'device miibus' line in order to use these NICs!
device miibus # MII bus support
device fxp # Intel EtherExpress PRO/100B (82557, 82558)
# Pseudo devices - the number indicates how many units to allocate.
pseudo-device loop # Network loopback
pseudo-device ether # Ethernet support
pseudo-device tun # Packet tunnel.
pseudo-device pty # Pseudo-ttys (telnet etc)
pseudo-device md # Memory "disks"
pseudo-device gif # IPv6 and IPv4 tunneling
pseudo-device faith 1 # IPv6-to-IPv4 relaying (translation)
pseudo-device vn
# The `bpf' pseudo-device enables the Berkeley Packet Filter.
# Be aware of the administrative consequences of enabling this!
pseudo-device bpf #Berkeley packet filter
Thanks,
Tony
Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?20040218160845.GA6332>