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