Date: Sat, 21 Feb 2004 14:47:49 +1100 From: Tony Frank <tfrank@optushome.com.au> To: FreeBSD-questions@freebsd.org Subject: ahc + vinum raid5 deadlocks? Message-ID: <20040221034749.GA98919@marvin.home.local>
next in thread | raw e-mail | index | archive | help
Hi again,
Refer earlier thread on -stable for more background.
4.9-STABLE (cvsup 20th Feb)
Kernel was compiled with DDB, INVARIANTS, DIAGNOSTICS.
All options removed from /etc/make.conf except 'NOPROFILE=TRUE'
I get the following on the console before system freezes:
ahc0: WARNING no command for scb 14 (cmdcmplt)
QOUTPOS = 44
Dropping into DDB I can run 'ps' and see lots of
process in 'flswai' (tar, cvsup etc) plus
others in state 'vrlock' (bufdaemon)
See below for a full 'ps' output.
At this point system was still accessible from network
(ping + login via ssh) but new shells froze.
As mentioned in other email to -stable I can run some
simple remote commands.
I managed to get a remote 'sync' command in and there was a
quick burst of disk activity before it promptly wedged again.
This is repeatable a few times but it just freezes again soon
after.
No further console output.
Hardware is currently Adaptec AHA-2940W S71 (F/w 1.19S8)
Same issues occured with Adaptec AHA-2940UW/B (F/w 1.32S8)
I have 4 x 4G IBM SCSI disks on the single internal 68-pin connector.
Connections are good & termination is correct
The 4 disks are combined into a single vinum raid5 plex.
System is well ventilated and cool to the touch.
Pentium 2 200Mhz, 128mb SDRAM, Asus P2V m/b.
Currently takes ~2 hours of solid activity to trigger the issue.
My 'test bench':
Copying files over NFSv3/udp to vinum raid5 volume via cp & tar
+ make -j4 buildworld
+ Copying large dir trees (/usr/ports, /usr/obj, /usr/src)
+ cvsuping second copy of /usr/src
+ extracting tar archive of /usr/obj
I have second vinum volume (mirrored/concat) on two IDE drives
connected to the m/b and the test bench runs just fine when using
these disks/volume.
It suggest to me an issue between ahc and vinum or vinum & scsi ?
Also seem to be experiencing corruption writing to the raid5 volume.
- Some files do not have correct md5 checksum after copying to the raid5.
Last parts of "vinum info -V" that I got in just before it froze:
13:52:13.709220 4DN Write 0xc387b238 13.527 0x3d9471 2048 12 3d9368 0 0
13:52:13.710332 4DN Write 0xc387b238 13.535 0x3d9471 2048 13 3d9368 0 0
13:52:13.710347 Unlock 0xc387b238 0xf64ce1
13:52:13.713943 1VS Read 0xc38633a4 91.0 0x4d2a0 8192
13:52:13.714026 2LR Read 0xc38633a4 91.0 0x4d2a0 8192
13:52:13.714039 3RQ Read 0xc38633a4 116.535 0xcd3a9 8192 5 4d2a0 0 0
13:52:13.716327 1VS Write 0xc3863788 91.5 0x361e10 65536
13:52:13.716733 2LR Write 0xc3863788 91.5 0x361e10 65536
13:52:13.716746 Lock 0xc3863788 0x361ce1
13:52:13.716752 3RQ Read 0xc3863788 13.535 0xd8971 65536 13 d8868 0 0
13:52:13.716844 3RQ Read 0xc3863788 116.519 0x6e3349 65536 10 d8868 0 0
13:52:13.733942 1VS Write 0xc38ab9c0 91.5 0x15d40e0 8192
13:52:13.734204 2LR Write 0xc38ab9c0 91.5 0x15d40e0 8192
13:52:13.734218 Lock 0xc38ab9c0 0x15d3da1
13:52:13.734225 3RQ Read 0xc38ab9c0 13.543 0x5753b1 8192 14 5752a8 0 0
13:52:13.734340 3RQ Read 0xc38ab9c0 116.519 0xb7fd89 8192 10 5752a8 0 0
13:52:13.735175 1VS Write 0xc38bca18 91.5 0x361ed0 8192
13:52:13.735287 2LR Write 0xc38bca18 91.5 0x361ed0 8192
13:52:13.735322 Lockwait 0xc38bca18 0x361ce1
13:52:13.735679 1VS Read 0xc3890dc8 91.2 0x42018 1024
13:52:13.735747 2LR Read 0xc3890dc8 91.2 0x42018 1024
13:52:13.735755 3RQ Read 0xc3890dc8 116.519 0x142121 1024 2 42018 0 0
13:52:13.740781 4DN Read 0xc3863788 13.535 0xd8971 65536 13 d8868 0 0
13:52:13.745513 4DN Read 0xc38ab9c0 13.543 0x5753b1 8192 14 5752a8 0 0
13:52:13.765800 4DN Read 0xc38633a4 116.535 0xcd3a9 8192 5 4d2a0 0 0
and then again after I did a sync:
Flags: 0x80204
Total of 120 blocks malloced, total memory: 253624
Maximum allocs: 732, malloc table at 0xc03bc7c0
10 requests active, maximum 419 active
Time Event Buf Dev Offset Bytes SD SDoff Doffset Goffset
13:57:52.971644 3RQ Write 0xc38a8348 116.535 0x5f4149 8192 9 3f4040 0 0
13:57:52.972151 4DN Write 0xc38a8348 116.535 0x5f4149 8192 9 3f4040 0 0
13:57:52.972241 4DN Write 0xc38a8348 116.519 0x5f4149 8192 4 3f4040 0 0
13:57:52.973372 1VS Write 0xc389ef70 91.0 0x2c070 8192
13:57:52.973452 2LR Write 0xc389ef70 91.0 0x2c070 8192
13:57:52.973461 3RQ Write 0xc389ef70 116.519 0xac179 8192 0 2c070 0 0
13:57:52.973518 3RQ Write 0xc389ef70 116.535 0xac179 8192 5 2c070 0 0
13:57:52.973981 4DN Write 0xc389ef70 116.519 0xac179 8192 0 2c070 0 0
13:57:52.974093 4DN Write 0xc389ef70 116.535 0xac179 8192 5 2c070 0 0
13:57:52.986904 1VS Write 0xc38a8348 91.4 0x3f4040 8192
13:57:52.987014 2LR Write 0xc38a8348 91.4 0x3f4040 8192
13:57:52.987026 3RQ Write 0xc38a8348 116.519 0x5f4149 8192 4 3f4040 0 0
13:57:52.987128 3RQ Write 0xc38a8348 116.535 0x5f4149 8192 9 3f4040 0 0
13:57:52.987596 4DN Write 0xc38a8348 116.519 0x5f4149 8192 4 3f4040 0 0
13:57:52.987845 4DN Write 0xc38a8348 116.535 0x5f4149 8192 9 3f4040 0 0
13:57:52.989122 1VS Write 0xc389ef70 91.0 0x2c070 8192
13:57:52.989203 2LR Write 0xc389ef70 91.0 0x2c070 8192
13:57:52.989211 3RQ Write 0xc389ef70 116.519 0xac179 8192 0 2c070 0 0
13:57:52.989272 3RQ Write 0xc389ef70 116.535 0xac179 8192 5 2c070 0 0
13:57:52.989702 4DN Write 0xc389ef70 116.519 0xac179 8192 0 2c070 0 0
13:57:52.989859 4DN Write 0xc389ef70 116.535 0xac179 8192 5 2c070 0 0
13:57:52.998370 1VS Write 0xc3875770 91.0 0x2c060 8192
13:57:52.998457 2LR Write 0xc3875770 91.0 0x2c060 8192
13:57:52.998468 3RQ Write 0xc3875770 116.519 0xac169 8192 0 2c060 0 0
13:57:52.998555 3RQ Write 0xc3875770 116.535 0xac169 8192 5 2c060 0 0
13:57:52.999018 4DN Write 0xc3875770 116.519 0xac169 8192 0 2c060 0 0
13:57:52.999275 4DN Write 0xc3875770 116.535 0xac169 8192 5 2c060 0 0
13:57:53.004388 1VS Write 0xc3875770 91.0 0x2c060 8192
13:57:53.004465 2LR Write 0xc3875770 91.0 0x2c060 8192
13:57:53.004474 3RQ Write 0xc3875770 116.519 0xac169 8192 0 2c060 0 0
13:57:53.004963 4DN Write 0xc3875770 116.519 0xac169 8192 0 2c060 0 0
13:57:53.005113 4DN Write 0xc3875770 116.535 0xac169 8192 5 2c060 0 0
13:57:53.009702 1VS Write 0xc38cda70 91.0 0x42040 8192
13:57:53.009778 2LR Write 0xc38cda70 91.0 0x42040 8192
13:57:53.009787 3RQ Write 0xc38cda70 116.519 0xc2149 8192 0 42040 0 0
13:57:53.009847 3RQ Write 0xc38cda70 116.535 0xc2149 8192 5 42040 0 0
13:57:53.010336 4DN Write 0xc38cda70 116.519 0xc2149 8192 0 42040 0 0
13:57:53.020114 4DN Write 0xc38cda70 116.535 0xc2149 8192 5 42040 0 0
13:57:53.020686 1VS Write 0xc38c7694 91.0 0x58040 8192
13:57:53.020762 2LR Write 0xc38c7694 91.0 0x58040 8192
13:57:53.020771 3RQ Write 0xc38c7694 116.519 0xd8149 8192 0 58040 0 0
13:57:53.020832 3RQ Write 0xc38c7694 116.535 0xd8149 8192 5 58040 0 0
13:57:53.021268 4DN Write 0xc38c7694 116.519 0xd8149 8192 0 58040 0 0
13:57:53.021502 4DN Write 0xc38c7694 116.535 0xd8149 8192 5 58040 0 0
13:57:53.022589 1VS Write 0xc38c31d8 91.4 0x2aa040 8192
13:57:53.022666 2LR Write 0xc38c31d8 91.4 0x2aa040 8192
13:57:53.022674 3RQ Write 0xc38c31d8 116.519 0x4aa149 8192 4 2aa040 0 0
13:57:53.022730 3RQ Write 0xc38c31d8 116.535 0x4aa149 8192 9 2aa040 0 0
13:57:53.023188 4DN Write 0xc38c31d8 116.519 0x4aa149 8192 4 2aa040 0 0
13:57:53.023349 4DN Write 0xc38c31d8 116.535 0x4aa149 8192 9 2aa040 0 0
13:57:53.024838 1VS Write 0xc38d000c 91.4 0x210040 8192
13:57:53.024942 2LR Write 0xc38d000c 91.4 0x210040 8192
13:57:53.024951 3RQ Write 0xc38d000c 116.519 0x410149 8192 4 210040 0 0
13:57:53.025006 3RQ Write 0xc38d000c 116.535 0x410149 8192 9 210040 0 0
13:57:53.025465 4DN Write 0xc38d000c 116.519 0x410149 8192 4 210040 0 0
13:57:53.025661 4DN Write 0xc38d000c 116.535 0x410149 8192 9 210040 0 0
13:57:53.026275 1VS Write 0xc38be938 91.4 0x39c040 8192
13:57:53.026350 2LR Write 0xc38be938 91.4 0x39c040 8192
13:57:53.026359 3RQ Write 0xc38be938 116.519 0x59c149 8192 4 39c040 0 0
13:57:53.026414 3RQ Write 0xc38be938 116.535 0x59c149 8192 9 39c040 0 0
13:57:53.026890 4DN Write 0xc38be938 116.519 0x59c149 8192 4 39c040 0 0
13:57:53.027052 4DN Write 0xc38be938 116.535 0x59c149 8192 9 39c040 0 0
13:57:53.027563 1VS Write 0xc38a9e84 91.4 0xb0070 8192
13:57:53.027636 2LR Write 0xc38a9e84 91.4 0xb0070 8192
13:57:53.027644 3RQ Write 0xc38a9e84 116.519 0x2b0179 8192 4 b0070 0 0
13:57:53.027701 3RQ Write 0xc38a9e84 116.535 0x2b0179 8192 9 b0070 0 0
13:57:53.028161 4DN Write 0xc38a9e84 116.519 0x2b0179 8192 4 b0070 0 0
13:57:53.028295 4DN Write 0xc38a9e84 116.535 0x2b0179 8192 9 b0070 0 0
13:57:53.028808 1VS Write 0xc3880a68 91.4 0x84050 8192
13:57:53.028905 2LR Write 0xc3880a68 91.4 0x84050 8192
13:57:53.028914 3RQ Write 0xc3880a68 116.519 0x284159 8192 4 84050 0 0
13:57:53.028969 3RQ Write 0xc3880a68 116.535 0x284159 8192 9 84050 0 0
13:57:53.029428 4DN Write 0xc3880a68 116.519 0x284159 8192 4 84050 0 0
13:57:53.029563 4DN Write 0xc3880a68 116.535 0x284159 8192 9 84050 0 0
13:57:53.031736 1VS Write 0xc38a8348 91.4 0x3f4040 8192
13:57:53.031810 2LR Write 0xc38a8348 91.4 0x3f4040 8192
13:57:53.031820 3RQ Write 0xc38a8348 116.519 0x5f4149 8192 4 3f4040 0 0
13:57:53.031896 3RQ Write 0xc38a8348 116.535 0x5f4149 8192 9 3f4040 0 0
13:57:53.032337 4DN Write 0xc38a8348 116.519 0x5f4149 8192 4 3f4040 0 0
13:57:53.032491 4DN Write 0xc38a8348 116.535 0x5f4149 8192 9 3f4040 0 0
13:57:53.036720 1VS Write 0xc38a8348 91.4 0x3f4040 8192
13:57:53.036798 2LR Write 0xc38a8348 91.4 0x3f4040 8192
13:57:53.036807 3RQ Write 0xc38a8348 116.519 0x5f4149 8192 4 3f4040 0 0
13:57:53.036864 3RQ Write 0xc38a8348 116.535 0x5f4149 8192 9 3f4040 0 0
13:57:53.037358 4DN Write 0xc38a8348 116.519 0x5f4149 8192 4 3f4040 0 0
13:57:53.037434 4DN Write 0xc38a8348 116.535 0x5f4149 8192 9 3f4040 0 0
13:57:53.038830 1VS Write 0xc3873c34 91.3 0xab0 1024
13:57:53.038930 2LR Write 0xc3873c34 91.3 0xab0 1024
13:57:53.038940 3RQ Write 0xc3873c34 116.519 0x180bb9 1024 3 ab0 0 0
13:57:53.038996 3RQ Write 0xc3873c34 116.535 0x180bb9 1024 8 ab0 0 0
13:57:53.039154 1VS Write 0xc38633a4 91.3 0x17770 16384
13:57:53.039226 2LR Write 0xc38633a4 91.3 0x17770 16384
13:57:53.039233 3RQ Write 0xc38633a4 116.519 0x197879 16384 3 17770 0 0
13:57:53.039251 3RQ Write 0xc38633a4 116.535 0x197879 16384 8 17770 0 0
13:57:53.039303 1VS Write 0xc38a3aa8 91.3 0x16010 1024
13:57:53.039399 4DN Write 0xc3873c34 116.535 0x180bb9 1024 8 ab0 0 0
13:57:53.039469 2LR Write 0xc38a3aa8 91.3 0x16010 1024
13:57:53.039486 3RQ Write 0xc38a3aa8 116.519 0x196119 1024 3 16010 0 0
13:57:53.039515 3RQ Write 0xc38a3aa8 116.535 0x196119 1024 8 16010 0 0
13:57:53.039629 4DN Write 0xc3873c34 116.519 0x180bb9 1024 3 ab0 0 0
13:57:53.039930 1VS Write 0xc38c9468 91.3 0x16012 1024
13:57:53.040015 2LR Write 0xc38c9468 91.3 0x16012 1024
13:57:53.040022 3RQ Write 0xc38c9468 116.519 0x19611b 1024 3 16012 0 0
13:57:53.040041 3RQ Write 0xc38c9468 116.535 0x19611b 1024 8 16012 0 0
13:57:53.040101 1VS Write 0xc387bc98 91.3 0x16014 1024
13:57:53.040177 2LR Write 0xc387bc98 91.3 0x16014 1024
13:57:53.040184 3RQ Write 0xc387bc98 116.519 0x19611d 1024 3 16014 0 0
13:57:53.040200 3RQ Write 0xc387bc98 116.535 0x19611d 1024 8 16014 0 0
13:57:53.040241 4DN Write 0xc38a3aa8 116.519 0x196119 1024 3 16010 0 0
13:57:53.040334 4DN Write 0xc38633a4 116.535 0x197879 16384 8 17770 0 0
13:57:53.040765 3RQ Write 0xc3870324 116.535 0x196139 8192 8 16030 0 0
13:57:53.040864 4DN Write 0xc387bc98 116.519 0x19611d 1024 3 16014 0 0
13:57:53.043508 1VS Read 0xc3861b00 91.4 0x72e70 65536
13:57:53.043580 2LR Read 0xc3861b00 91.4 0x72e70 65536
13:57:53.043588 3RQ Read 0xc3861b00 116.535 0x272f79 65536 9 72e70 0 0
13:57:53.045055 1VS Write 0xc3861ee4 91.5 0x1f0a4e0 65536
13:57:53.045427 2LR Write 0xc3861ee4 91.5 0x1f0a4e0 65536
13:57:53.045438 Lockwait 0xc3861ee4 0x1f09fe1
13:57:53.055975 4DN Read 0xc3862d28 13.527 0x7c29c9 32768 12 7c28c0 0 0
13:57:53.065071 4DN Write 0xc38a3aa8 116.535 0x196119 1024 8 16010 0 0
13:57:53.065687 4DN Write 0xc38c9468 116.535 0x19611b 1024 8 16012 0 0
13:57:53.066156 4DN Write 0xc387bc98 116.535 0x19611d 1024 8 16014 0 0
13:57:53.066733 4DN Write 0xc3870324 116.535 0x196139 8192 8 16030 0 0
13:57:53.073392 1VS Write 0xc386f778 91.5 0x370110 8192
13:57:53.073525 2LR Write 0xc386f778 91.5 0x370110 8192
13:57:53.073538 Lock 0xc386f778 0x36f421
13:57:53.073547 3RQ Read 0xc386f778 13.543 0xdbf79 8192 14 dbe70 0 0
13:57:53.073657 3RQ Read 0xc386f778 13.535 0xdbf79 8192 13 dbe70 0 0
DDB prints:
raider# Stopped at siointr1+0x102: movl $0,brk_state2.757
db> ps
pid proc addr uid ppid pgrp flag stat wmesg wchan cmd
2443 cce66a40 cd163000 1001 2442 2442 004004 3 inode c110da00 sync
2442 cce67260 cd11d000 1001 2441 2442 2004084 3 pause cd11d260 tcsh
2441 cce67a80 cd0f3000 1001 2438 127 000184 3 select c032d4a8 sshd
2438 cce65860 cd194000 0 127 127 000184 3 sbwait cc5baec8 sshd
2429 cce685e0 ccfca000 1001 2428 2428 004004 3 inode c110da00 sync
2428 cce64ea0 cd1fa000 1001 1 2428 2004084 3 pause cd1fa260 tcsh
2398 cce67c20 cd0ec000 1001 2397 2397 004004 3 inode c110da00 sync
2397 cce68100 ccfe9000 1001 1 2397 2004084 3 pause ccfe9260 tcsh
2387 cce66d80 cd10f000 1001 2386 2386 004004 3 vrlock c1047828 sync
2386 cce66220 cd197000 1001 1 2386 2004084 3 pause cd197260 tcsh
2309 cce66f20 cd125000 0 2105 2309 004086 3 ttyin c1b63030 csh
2105 cce649c0 cd1e8000 1001 183 2105 2004086 3 pause cd1e8260 tcsh
2068 cce670c0 cd121000 1001 222 2068 004006 3 getblk c38c8268 cp
1491 cce65ee0 cd1a0000 1001 469 1491 004006 3 biowr c38c8240 tar
469 cce678e0 cd0fe000 1001 183 469 2004086 3 pause cd0fe260 tcsh
393 cce68440 ccfdd000 1001 392 393 004086 3 ttyin c19fda30 tcsh
392 cce68780 ccefe000 1001 296 392 004086 3 select c032d4a8 script
306 cce682a0 ccfe1000 0 1 306 000204 3 vinum c03a45d0 vinum
296 cce68920 ccef9000 1001 183 296 2004086 3 pause ccef9260 tcsh
295 cce68ac0 ccea3000 1001 288 295 004006 3 flswai c03167f0 tar
288 cce68c60 cce78000 1001 183 288 2004086 3 pause cce78260 tcsh
287 c7f7b1e0 cce6d000 1001 268 287 004006 3 flswai c03167f0 tar
283 cce68e00 cce57000 1001 257 282 004006 3 flswai c03167f0 tar
282 c7f7b040 cce61000 1001 257 282 004086 3 pipdwt ccd30980 tar
268 c7f7aea0 cce71000 1001 183 268 2004086 3 pause cce71260 tcsh
264 c7f7b520 ccde1000 1001 184 264 004086 3 select c032d4a8 cvsup
257 c7f7ba00 ccdd4000 1001 183 257 2004086 3 pause ccdd4260 tcsh
256 c7f7b380 cce5a000 1001 250 256 004006 3 flswai c03167f0 cvsup
250 c7f7b860 ccdd8000 1001 183 250 2004086 3 pause ccdd8260 tcsh
222 c7f7bba0 ccdcf000 1001 183 222 2004086 3 pause ccdcf260 tcsh
184 c7f7bd40 ccdcc000 1001 183 184 2004086 3 pause ccdcc260 tcsh
183 c7f7bee0 ccdc7000 1001 182 183 000104 3 flswai c03167f0 screen
182 c7f7c080 ccdc2000 1001 176 182 2004186 3 pause ccdc2260 screen
176 c7f7c220 ccdbf000 1001 175 176 2004086 3 pause ccdbf260 tcsh
175 c7f7c3c0 ccdb8000 1001 173 127 000184 3 select c032d4a8 sshd
173 c7f7c560 ccdad000 0 127 127 000184 3 sbwait cc5b9608 sshd
171 c7f7d5a0 ccd6b000 0 164 171 004006 3 flswai c03167f0 csh
168 c7f7c8a0 ccd9c000 1001 163 168 004106 3 flswai c03167f0 systat
165 c7f7ca40 ccd97000 1001 162 165 004106 3 flswai c03167f0 top
164 c7f7cf20 ccd83000 0 1 164 004186 3 wait c7f7cf20 login
163 c7f7c700 ccda0000 0 1 163 004186 3 wait c7f7c700 login
162 c7f7df60 ccd22000 0 1 162 004186 3 wait c7f7df60 login
127 c7f7cbe0 ccd8b000 0 1 127 000184 3 select c032d4a8 sshd
125 c7f7cd80 ccd87000 0 1 125 000084 3 nanslp c03165f0 cron
117 c7f7d0c0 ccd77000 0 1 113 000084 3 nfsidl c03339ec nfsiod
116 c7f7d260 ccd73000 0 1 113 000084 3 nfsidl c03339e8 nfsiod
115 c7f7d400 ccd6f000 0 1 113 000084 3 nfsidl c03339e4 nfsiod
114 c7f7ddc0 ccd2a000 0 1 113 000084 3 nfsidl c03339e0 nfsiod
110 c7f7d740 ccd49000 0 1 110 000084 3 select c032d4a8 ntpd
105 c7f7dc20 ccd32000 0 1 105 000004 3 flswai c03167f0 syslogd
69 c7f7da80 ccd36000 0 1 69 000084 3 select c032d4a8 dhclient
27 c7f7d8e0 ccd3a000 0 1 27 2000084 3 pause ccd3a260 adjkerntz
9 c7f7e100 ccaba000 0 0 0 000204 3 vlruwt c7f7e100 vnlru
8 c7f7e2a0 ccab7000 0 0 0 000204 3 drainvp ccda80c4 syncer
7 c7f7e440 ccab4000 0 0 0 000204 3 vrlock c1047828 bufdaemon
6 c7f7e5e0 ccab1000 0 0 0 000204 3 psleep c03245a0 vmdaemon
5 c7f7e780 ccaae000 0 0 0 000204 3 psleep c0309198 pagedaemon
4 c7f7e920 cc5b4000 0 0 0 000204 3 idle c0f9a200 aic_recovery0
3 c7f7eac0 cc5b1000 0 0 0 000204 3 idle c0f9a200 aic_recovery0
2 c7f7ec60 c8566000 0 0 0 000204 3 tqthr c032d4a4 taskqueue
1 c7f7ee00 c7f83000 0 0 1 004284 3 wait c7f7ee00 init
0 c032c7a0 c0481000 0 0 0 000204 3 sched c032c7a0 swapper
Thanks,
Tony
Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?20040221034749.GA98919>