tech-kern archive
[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index][Old Index]
tstile lockup (was: Serious WAPL performance problems)
> Invoke crash(8), then just perform "ps" and "t/a address" on each LWP
> which seems to be stuck (on "tstile" or elsewhere).
So it seems I can sort of lock up the machine for minutes with a simple
dd if=/dev/zero of=/dev/dk14 bs=64k count=1000
(In case it matters, dk14 is on a RAID5 on 4+1 mpt(4) SAS discs)
I get an impressive dd throughput of around 350kB/s
Here's the crash(8) output during one of the partial lock-ups:
crash> ps | fgrep vnode
25995 1 3 1 1000000 fffffe8414a24100 dd vnode
crash> t/a fffffe8414a24100
trace: pid 25995 lid 1 at 0xfffffe811e7de8f0
sleepq_block() at sleepq_block+0xad
cv_wait() at cv_wait+0x9f
vflushbuf() at vflushbuf+0x10f
ffs_spec_fsync() at ffs_spec_fsync+0x3e
VOP_FSYNC() at VOP_FSYNC+0x3e
vinvalbuf() at vinvalbuf+0xf2
spec_close() at spec_close+0x73
VOP_CLOSE() at VOP_CLOSE+0x33
vn_close() at vn_close+0x4e
closef() at closef+0x4a
fd_close() at fd_close+0x116
syscall() at syscall+0xc4
crash> ps | fgrep tstile
10629 5 3 5 0 fffffe838c989680 slave tstile
10629 4 3 3 0 fffffe838c989260 slave tstile
10629 3 3 4 0 fffffe8415e82060 slave tstile
10629 2 3 2 0 fffffe8267e74ac0 slave tstile
crash> t/a fffffe838c989680
trace: pid 10629 lid 5 at 0xfffffe811e25e4f0
sleepq_block() at sleepq_block+0xad
turnstile_block() at turnstile_block+0x2bb
rw_vector_enter() at rw_vector_enter+0x1eb
wapbl_begin() at wapbl_begin+0x54
ffs_write() at ffs_write+0x8b9
VOP_WRITE() at VOP_WRITE+0x37
nfsrv_write() at nfsrv_write+0x923
nfssvc_nfsd() at nfssvc_nfsd+0x1d7
sys_nfssvc() at sys_nfssvc+0x22c
syscall() at syscall+0xc4
crash> t/a fffffe838c989260
trace: pid 10629 lid 4 at 0xfffffe811e27e4f0
sleepq_block() at sleepq_block+0xad
turnstile_block() at turnstile_block+0x2bb
rw_vector_enter() at rw_vector_enter+0x1eb
wapbl_flush() at wapbl_flush+0x54
ffs_fsync() at ffs_fsync+0x112
VOP_FSYNC() at VOP_FSYNC+0x3e
nfsrv_commit() at nfsrv_commit+0x69a
nfssvc_nfsd() at nfssvc_nfsd+0x1d7
sys_nfssvc() at sys_nfssvc+0x22c
syscall() at syscall+0xc4
crash> t/a fffffe8415e82060
trace: pid 10629 lid 3 at 0xfffffe811dbde3c0
sleepq_block() at sleepq_block+0xad
turnstile_block() at turnstile_block+0x2bb
rw_vector_enter() at rw_vector_enter+0x1eb
genfs_lock() at genfs_lock+0x7b
VOP_LOCK() at VOP_LOCK+0x32
vn_lock() at vn_lock+0x7d
vget() at vget+0xa2
ufs_ihashget() at ufs_ihashget+0x84
ffs_vget() at ffs_vget+0xc1
ufs_fhtovp() at ufs_fhtovp+0x1f
ffs_fhtovp() at ffs_fhtovp+0x55
VFS_FHTOVP() at VFS_FHTOVP+0x1c
nfsrv_fhtovp() at nfsrv_fhtovp+0x9a
nfsrv_write() at nfsrv_write+0x502
nfssvc_nfsd() at nfssvc_nfsd+0x1d7
sys_nfssvc() at sys_nfssvc+0x22c
syscall() at syscall+0xc4
crash> t/a fffffe8267e74ac0
trace: pid 10629 lid 2 at 0xfffffe811e29e3c0
sleepq_block() at sleepq_block+0xad
turnstile_block() at turnstile_block+0x2bb
rw_vector_enter() at rw_vector_enter+0x1eb
genfs_lock() at genfs_lock+0x7b
VOP_LOCK() at VOP_LOCK+0x32
vn_lock() at vn_lock+0x7d
vget() at vget+0xa2
ufs_ihashget() at ufs_ihashget+0x84
ffs_vget() at ffs_vget+0xc1
ufs_fhtovp() at ufs_fhtovp+0x1f
ffs_fhtovp() at ffs_fhtovp+0x55
VFS_FHTOVP() at VFS_FHTOVP+0x1c
nfsrv_fhtovp() at nfsrv_fhtovp+0x9a
nfsrv_write() at nfsrv_write+0x502
nfssvc_nfsd() at nfssvc_nfsd+0x1d7
sys_nfssvc() at sys_nfssvc+0x22c
syscall() at syscall+0xc4
crash> ps | fgrep tstile
10629 5 3 5 0 fffffe838c989680 slave tstile
10629 4 3 3 0 fffffe838c989260 slave tstile
10629 3 3 4 0 fffffe8415e82060 slave tstile
10629 2 3 2 0 fffffe8267e74ac0 slave tstile
crash> ps | fgrep vnode
25995 1 3 1 1000000 fffffe8414a24100 dd vnode
crash> t/a fffffe8414a24100
trace: pid 25995 lid 1 at 0xfffffe811e7de8f0
sleepq_block() at sleepq_block+0xad
cv_wait() at cv_wait+0x9f
vflushbuf() at vflushbuf+0x10f
ffs_spec_fsync() at ffs_spec_fsync+0x3e
VOP_FSYNC() at VOP_FSYNC+0x3e
vinvalbuf() at vinvalbuf+0xf2
spec_close() at spec_close+0x73
VOP_CLOSE() at VOP_CLOSE+0x33
vn_close() at vn_close+0x4e
closef() at closef+0x4a
fd_close() at fd_close+0x116
syscall() at syscall+0xc4
crash> ps | fgrep bio
0 81 3 2 200 fffffe811dcc7b20 ioflush biolock
0 43 1 5 200 fffffe811d3631a0 softbio/5
0 37 1 4 200 fffffe811d33c160 softbio/4
0 31 1 3 200 fffffe811d318120 softbio/3
0 25 1 2 200 fffffe811d2f10e0 softbio/2
0 19 1 1 200 fffffe811d2cd0a0 softbio/1
0 4 1 0 200 fffffe841df43000 softbio/0
crash> t/a fffffe811dcc7b20
trace: pid 0 lid 81 at 0xfffffe811d8de980
sleepq_block() at sleepq_block+0xad
cv_timedwait() at cv_timedwait+0xa7
bbusy() at bbusy+0xe4
getblk() at getblk+0x60
bio_doread.clone.1() at bio_doread.clone.1+0x1d
bread() at bread+0x1a
ffs_update() at ffs_update+0x12c
ffs_sync() at ffs_sync+0x395
VFS_SYNC() at VFS_SYNC+0x1c
sync_fsync() at sync_fsync+0x78
VOP_FSYNC() at VOP_FSYNC+0x3e
sched_sync() at sched_sync+0x196
crash> ps | fgrep bio
0 81 3 2 200 fffffe811dcc7b20 ioflush biolock
0 43 1 5 200 fffffe811d3631a0 softbio/5
0 37 1 4 200 fffffe811d33c160 softbio/4
0 31 1 3 200 fffffe811d318120 softbio/3
0 25 1 2 200 fffffe811d2f10e0 softbio/2
0 19 1 1 200 fffffe811d2cd0a0 softbio/1
0 4 1 0 200 fffffe841df43000 softbio/0
crash> ps | fgrep tstile
10629 5 3 5 0 fffffe838c989680 slave tstile
10629 4 3 3 0 fffffe838c989260 slave tstile
10629 3 3 4 0 fffffe8415e82060 slave tstile
10629 2 3 2 0 fffffe8267e74ac0 slave tstile
crash> ps | fgrep vnode
25995 1 3 1 1000000 fffffe8414a24100 dd vnode
crash> t/a fffffe838c989680
trace: pid 10629 lid 5 at 0xfffffe811e25e4f0
sleepq_block() at sleepq_block+0xad
turnstile_block() at turnstile_block+0x2bb
rw_vector_enter() at rw_vector_enter+0x1eb
wapbl_begin() at wapbl_begin+0x54
ffs_write() at ffs_write+0x8b9
VOP_WRITE() at VOP_WRITE+0x37
nfsrv_write() at nfsrv_write+0x923
nfssvc_nfsd() at nfssvc_nfsd+0x1d7
sys_nfssvc() at sys_nfssvc+0x22c
syscall() at syscall+0xc4
crash> t/a fffffe838c989260
trace: pid 10629 lid 4 at 0xfffffe811e27e4f0
sleepq_block() at sleepq_block+0xad
turnstile_block() at turnstile_block+0x2bb
rw_vector_enter() at rw_vector_enter+0x1eb
wapbl_flush() at wapbl_flush+0x54
ffs_fsync() at ffs_fsync+0x112
VOP_FSYNC() at VOP_FSYNC+0x3e
nfsrv_commit() at nfsrv_commit+0x69a
nfssvc_nfsd() at nfssvc_nfsd+0x1d7
sys_nfssvc() at sys_nfssvc+0x22c
syscall() at syscall+0xc4
crash> t/a fffffe8415e82060
trace: pid 10629 lid 3 at 0xfffffe811dbde3c0
sleepq_block() at sleepq_block+0xad
turnstile_block() at turnstile_block+0x2bb
rw_vector_enter() at rw_vector_enter+0x1eb
genfs_lock() at genfs_lock+0x7b
VOP_LOCK() at VOP_LOCK+0x32
vn_lock() at vn_lock+0x7d
vget() at vget+0xa2
ufs_ihashget() at ufs_ihashget+0x84
ffs_vget() at ffs_vget+0xc1
ufs_fhtovp() at ufs_fhtovp+0x1f
ffs_fhtovp() at ffs_fhtovp+0x55
VFS_FHTOVP() at VFS_FHTOVP+0x1c
nfsrv_fhtovp() at nfsrv_fhtovp+0x9a
nfsrv_write() at nfsrv_write+0x502
nfssvc_nfsd() at nfssvc_nfsd+0x1d7
sys_nfssvc() at sys_nfssvc+0x22c
syscall() at syscall+0xc4
crash> t/a fffffe8267e74ac0
trace: pid 10629 lid 2 at 0xfffffe811e29e3c0
sleepq_block() at sleepq_block+0xad
turnstile_block() at turnstile_block+0x2bb
rw_vector_enter() at rw_vector_enter+0x1eb
genfs_lock() at genfs_lock+0x7b
VOP_LOCK() at VOP_LOCK+0x32
vn_lock() at vn_lock+0x7d
vget() at vget+0xa2
ufs_ihashget() at ufs_ihashget+0x84
ffs_vget() at ffs_vget+0xc1
ufs_fhtovp() at ufs_fhtovp+0x1f
ffs_fhtovp() at ffs_fhtovp+0x55
VFS_FHTOVP() at VFS_FHTOVP+0x1c
nfsrv_fhtovp() at nfsrv_fhtovp+0x9a
nfsrv_write() at nfsrv_write+0x502
nfssvc_nfsd() at nfssvc_nfsd+0x1d7
sys_nfssvc() at sys_nfssvc+0x22c
syscall() at syscall+0xc4
crash> ps | fgrep tstile
10629 5 3 5 0 fffffe838c989680 slave tstile
10629 4 3 3 0 fffffe838c989260 slave tstile
10629 3 3 4 0 fffffe8415e82060 slave tstile
10629 2 3 2 0 fffffe8267e74ac0 slave tstile
crash> ps | fgrep bio
0 81 3 2 200 fffffe811dcc7b20 ioflush biolock
0 43 1 5 200 fffffe811d3631a0 softbio/5
0 37 1 4 200 fffffe811d33c160 softbio/4
0 31 1 3 200 fffffe811d318120 softbio/3
0 25 1 2 200 fffffe811d2f10e0 softbio/2
0 19 1 1 200 fffffe811d2cd0a0 softbio/1
0 4 1 0 200 fffffe841df43000 softbio/0
crash> t/a fffffe811dcc7b20
trace: pid 0 lid 81 at 0xfffffe811d8de980
sleepq_block() at sleepq_block+0xad
cv_timedwait() at cv_timedwait+0xa7
bbusy() at bbusy+0xe4
getblk() at getblk+0x60
bio_doread.clone.1() at bio_doread.clone.1+0x1d
bread() at bread+0x1a
ffs_update() at ffs_update+0x12c
ffs_sync() at ffs_sync+0x395
VFS_SYNC() at VFS_SYNC+0x1c
sync_fsync() at sync_fsync+0x78
VOP_FSYNC() at VOP_FSYNC+0x3e
sched_sync() at sched_sync+0x196
crash> ps
PID LID S CPU FLAGS STRUCT LWP * NAME WAIT
1289 1 3 5 80 fffffe8409149aa0 top select
25995 1 3 1 1000000 fffffe8414a24100 dd vnode
22136 1 3 5 80 fffffe83b08c8620 bash ttyraw
29161 1 3 5 80 fffffe834e863660 sshd select
25652 1 3 5 80 fffffe830277f980 sshd select
1189 > 1 7 5 0 fffffe82d1efd1a0 crash
28039 1 3 5 80 fffffe82f8d9d960 bash wait
24356 1 3 4 80 fffffe830a8fd320 sshd select
1238 1 3 5 80 fffffe82d5a5d220 sshd select
27367 1 3 3 80 fffffe828a76b1e0 pickup kqueue
8870 1 3 5 80 fffffe830949f920 bash wait
26261 1 2 5 0 fffffe811dd31300 sshd
28509 1 3 5 80 fffffe830277f140 sshd select
29114 1 3 1 80 fffffe8267e74280 bash wait
21390 1 3 4 80 fffffe811dd31720 sshd select
26363 1 3 5 80 fffffe83f47cb520 sshd select
23707 1 3 5 80 fffffe82d45be180 ssh-agent select
10451 1 3 2 80 fffffe8309edd040 ssh-agent select
3379 1 3 4 80 fffffe8414ed4960 ssh-agent select
1606 1 3 0 80 fffffe838c989aa0 rpc.lockd select
29647 1 3 2 80 fffffe83894bd240 rpc.statd select
10629 5 3 5 0 fffffe838c989680 slave tstile
10629 4 3 3 0 fffffe838c989260 slave tstile
10629 3 3 4 0 fffffe8415e82060 slave tstile
10629 2 3 2 0 fffffe8267e74ac0 slave tstile
10629 1 3 5 80 fffffe811e269780 master select
4721 1 3 5 80 fffffe8152a3c420 bash ttyraw
7479 1 3 0 80 fffffe8267e746a0 sshd select
4722 1 3 0 80 fffffe840f343180 sshd select
1004 1 3 5 80 fffffe811dd31b40 getty ttyraw
1013 1 3 4 80 fffffe8414b1b560 cron nanoslp
639 1 3 1 80 fffffe815213c900 inetd kqueue
675 1 3 1 80 fffffe8414b1b980 qmgr kqueue
941 1 3 3 80 fffffe84155ec0e0 master kqueue
600 1 3 5 80 fffffe84155ec500 sshd select
580 20438 5 1 0 fffffe830949f0e0 dsmc
580 1006 3 1 80 fffffe8414a24520 dsmc sigwait
580 580 3 5 80 fffffe815215c0a0 dsmc nanoslp
560 1 3 2 80 fffffe815213c0c0 powerd kqueue
338 1 3 3 80 fffffe815213c4e0 ntpd pause
495 1 3 4 80 fffffe815215c8e0 ipmon nanoslp
381 1 3 5 80 fffffe8152a3c000 mountd select
337 1 3 3 80 fffffe811e02db80 rpcbind select
316 1 3 2 80 fffffe8152a3c840 syslogd kqueue
1 1 3 1 80 fffffe811d83d6c0 init wait
0 165 5 3 200 fffffe840ea231a0 (zombie)
0 90 3 4 200 fffffe8419a7a040 nfsio nfsiod
0 89 3 4 200 fffffe8419a7a460 nfsio nfsiod
0 88 3 4 200 fffffe8419a7a880 nfsio nfsiod
0 87 3 4 200 fffffe841a08e020 nfsio nfsiod
0 86 3 0 200 fffffe841a08e440 ipmi0 ipmi0
0 85 3 0 200 fffffe811e269ba0 raidio1 raidiow
0 84 3 2 200 fffffe811e02d760 raid1 rfnodeq
0 83 3 0 200 fffffe811e02d340 physiod physiod
0 82 3 5 200 fffffe811dcc72e0 aiodoned aiodoned
0 81 3 2 200 fffffe811dcc7b20 ioflush biolock
0 80 3 4 200 fffffe811dcc7700 pgdaemon pgdaemon
0 77 3 3 200 fffffe811d86f2c0 raidio0 raidiow
0 76 3 5 200 fffffe811d86f6e0 raid0 rfnodeq
0 75 3 5 200 fffffe811d7f2ac0 cryptoret crypto_w
0 74 3 3 200 fffffe811d791260 usb6 usbevt
0 73 3 1 200 fffffe811d791680 usb5 usbevt
0 72 3 4 200 fffffe811d791aa0 usb4 usbevt
0 71 3 5 200 fffffe811d7b0240 usb3 usbevt
0 70 3 4 200 fffffe811d7b0660 usb2 usbevt
0 69 3 1 200 fffffe811d7b0a80 usb1 usbevt
0 68 3 5 200 fffffe811d86fb00 usbtask-dr usbtsk
0 67 3 5 200 fffffe811d83d2a0 usbtask-hc usbtsk
0 66 3 0 200 fffffe811d7f26a0 usb0 usbevt
0 65 3 5 200 fffffe811d83dae0 unpgc unpgc
0 64 3 1 200 fffffe811d7f2280 vmem_rehash vmem_rehash
0 55 3 5 200 fffffe811d666220 iic0 iicintr
0 54 3 0 200 fffffe811d666640 atabus5 atath
0 53 3 0 200 fffffe811d666a60 atabus4 atath
0 52 3 0 200 fffffe811d699200 atabus3 atath
0 51 3 0 200 fffffe811d699620 atabus2 atath
0 50 3 0 200 fffffe811d699a40 atabus1 atath
0 49 3 0 200 fffffe811d3bf1e0 atabus0 atath
0 48 3 0 200 fffffe811d3bf600 scsibus0 sccomp
0 47 3 5 200 fffffe811d3bfa20 ipmi ipmipoll
0 46 3 5 200 fffffe811d3841c0 xcall/5 xcall
0 45 1 5 200 fffffe811d3845e0 softser/5
0 44 1 5 200 fffffe811d384a00 softclk/5
0 43 1 5 200 fffffe811d3631a0 softbio/5
0 42 1 5 200 fffffe811d3635c0 softnet/5
0 41 1 5 201 fffffe811d3639e0 idle/5
0 40 3 4 200 fffffe811d332180 xcall/4 xcall
0 39 1 4 200 fffffe811d3325a0 softser/4
0 38 1 4 200 fffffe811d3329c0 softclk/4
0 37 1 4 200 fffffe811d33c160 softbio/4
0 36 1 4 200 fffffe811d33c580 softnet/4
0 > 35 7 4 201 fffffe811d33c9a0 idle/4
0 34 3 3 200 fffffe811d338140 xcall/3 xcall
0 33 1 3 200 fffffe811d338560 softser/3
0 32 1 3 200 fffffe811d338980 softclk/3
0 31 1 3 200 fffffe811d318120 softbio/3
0 30 1 3 200 fffffe811d318540 softnet/3
0 > 29 7 3 201 fffffe811d318960 idle/3
0 28 3 2 200 fffffe811d2f3100 xcall/2 xcall
0 27 1 2 200 fffffe811d2f3520 softser/2
0 26 1 2 200 fffffe811d2f3940 softclk/2
0 25 1 2 200 fffffe811d2f10e0 softbio/2
0 24 1 2 200 fffffe811d2f1500 softnet/2
0 > 23 7 2 201 fffffe811d2f1920 idle/2
0 22 3 1 200 fffffe811d2eb0c0 xcall/1 xcall
0 21 1 1 200 fffffe811d2eb4e0 softser/1
0 20 1 1 200 fffffe811d2eb900 softclk/1
0 19 1 1 200 fffffe811d2cd0a0 softbio/1
0 18 1 1 200 fffffe811d2cd4c0 softnet/1
0 > 17 7 1 201 fffffe811d2cd8e0 idle/1
0 16 3 0 200 fffffe841a31b080 sysmon smtaskq
0 15 3 0 200 fffffe841a31b4a0 pmfsuspend pmfsuspend
0 14 3 0 200 fffffe841a31b8c0 pmfevent pmfevent
0 13 3 5 200 fffffe841cf2a060 sopendfree sopendfr
0 12 3 0 200 fffffe841cf2a480 nfssilly nfssilly
0 11 3 3 200 fffffe841cf2a8a0 cachegc cachegc
0 10 3 5 200 fffffe841df33040 vrele vrele
0 9 3 3 200 fffffe841df33460 vdrain vdrain
0 8 3 0 200 fffffe841df33880 modunload mod_unld
0 7 3 0 200 fffffe841df3a020 xcall/0 xcall
0 6 1 0 200 fffffe841df3a440 softser/0
0 5 1 0 200 fffffe841df3a860 softclk/0
0 4 1 0 200 fffffe841df43000 softbio/0
0 3 1 0 200 fffffe841df43420 softnet/0
0 > 2 7 0 201 fffffe841df43840 idle/0
0 1 3 3 200 ffffffff806db020 swapper uvm
Does that help?
Home |
Main Index |
Thread Index |
Old Index