> A couple more questions here. ... > You still have idle time in this lockstat (and mpstat). > > What do you get for a lockstat -A -D 20 sleep 30? > > Do you see anyone with long lock hold times, long > sleeps, or excessive spinning?
Hmm, I ran a series of "lockstat -A -l ph_mutex -s 16 -D 20 sleep 5"
commands while writing to the gzip compressed zpool, and noticed
these high mutex block times:
Adaptive mutex block: 8 events in 5.100 seconds (2 events/sec)
-------------------------------------------------------------------------------
Count indv cuml rcnt nsec Lock Caller
5 62% 62% 0.00 317300109 ph_mutex+0x1380 page_create_va+0x334
nsec ------ Time Distribution ------ count Stack
536870912 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 5 segkmem_page_create+0x89
segkmem_xalloc+0xbc
segkmem_alloc_vn+0xcd
segkmem_alloc+0x20
vmem_xalloc+0x4fc
vmem_alloc+0x159
kmem_alloc+0x4f
kobj_alloc+0x7e
kobj_zalloc+0x1c
zcalloc+0x2d
z_deflateInit2_+0x1b8
z_deflateInit_+0x32
z_compress_level+0x77
gzip_compress+0x4b
zio_compress_data+0xbc
-------------------------------------------------------------------------------
Count indv cuml rcnt nsec Lock Caller
1 12% 75% 0.00 260247717 ph_mutex+0x1a40 page_create_va+0x334
nsec ------ Time Distribution ------ count Stack
268435456 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1 segkmem_page_create+0x89
segkmem_xalloc+0xbc
segkmem_alloc_vn+0xcd
segkmem_alloc+0x20
vmem_xalloc+0x4fc
vmem_alloc+0x159
kmem_alloc+0x4f
kobj_alloc+0x7e
kobj_zalloc+0x1c
zcalloc+0x2d
z_deflateInit2_+0x1de
z_deflateInit_+0x32
z_compress_level+0x77
gzip_compress+0x4b
zio_compress_data+0xbc
-------------------------------------------------------------------------------
Count indv cuml rcnt nsec Lock Caller
1 12% 88% 0.00 348135263 ph_mutex+0x1380 page_create_va+0x334
nsec ------ Time Distribution ------ count Stack
536870912 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1 segkmem_page_create+0x89
segkmem_xalloc+0xbc
segkmem_alloc_vn+0xcd
segkmem_alloc+0x20
vmem_xalloc+0x4fc
vmem_alloc+0x159
kmem_alloc+0x4f
kobj_alloc+0x7e
kobj_zalloc+0x1c
zcalloc+0x2d
z_deflateInit2_+0x1a1
z_deflateInit_+0x32
z_compress_level+0x77
gzip_compress+0x4b
zio_compress_data+0xbc
-------------------------------------------------------------------------------
Count indv cuml rcnt nsec Lock Caller
1 12% 100% 0.00 109836587 ph_mutex+0x1380 page_find+0x82
nsec ------ Time Distribution ------ count Stack
134217728 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1 segkmem_free_vn+0x81
segkmem_free+0x20
vmem_xfree+0x10c
vmem_free+0x25
kmem_free+0x47
kobj_free+0x23
zcfree+0x36
z_deflateEnd+0x91
z_compress_level+0x9d
gzip_compress+0x4b
zio_compress_data+0xbc
zio_write_compress+0x8d
taskq_thread+0x1a7
thread_start+0x8
-------------------------------------------------------------------------------
Or this one, a few seconds later:
Adaptive mutex block: 25 events in 5.208 seconds (5 events/sec)
-------------------------------------------------------------------------------
Count indv cuml rcnt nsec Lock Caller
3 12% 12% 0.00 643510908 ph_mutex+0x13c0 page_create_va+0x334
nsec ------ Time Distribution ------ count Stack
1073741824 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 3 segkmem_page_create+0x89
segkmem_xalloc+0xbc
segkmem_alloc_vn+0xcd
segkmem_alloc+0x20
vmem_xalloc+0x4fc
vmem_alloc+0x159
kmem_alloc+0x4f
kobj_alloc+0x7e
kobj_zalloc+0x1c
zcalloc+0x2d
z_deflateInit2_+0x18a
z_deflateInit_+0x32
z_compress_level+0x77
gzip_compress+0x4b
zio_compress_data+0xbc
-------------------------------------------------------------------------------
Count indv cuml rcnt nsec Lock Caller
3 12% 24% 0.00 210239890 ph_mutex+0x1380 page_create_va+0x334
nsec ------ Time Distribution ------ count Stack
268435456 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 3 segkmem_page_create+0x89
segkmem_xalloc+0xbc
segkmem_alloc_vn+0xcd
segkmem_alloc+0x20
vmem_xalloc+0x4fc
vmem_alloc+0x159
kmem_alloc+0x4f
kobj_alloc+0x7e
kobj_zalloc+0x1c
zcalloc+0x2d
z_deflateInit2_+0x1b8
z_deflateInit_+0x32
z_compress_level+0x77
gzip_compress+0x4b
zio_compress_data+0xbc
-------------------------------------------------------------------------------
Count indv cuml rcnt nsec Lock Caller
3 12% 36% 0.00 179186654 ph_mutex+0xd80 page_create_va+0x334
nsec ------ Time Distribution ------ count Stack
268435456 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 3 segkmem_page_create+0x89
segkmem_xalloc+0xbc
segkmem_alloc_vn+0xcd
segkmem_alloc+0x20
vmem_xalloc+0x4fc
vmem_alloc+0x159
kmem_alloc+0x4f
kobj_alloc+0x7e
kobj_zalloc+0x1c
zcalloc+0x2d
z_deflateInit2_+0x1b8
z_deflateInit_+0x32
z_compress_level+0x77
gzip_compress+0x4b
zio_compress_data+0xbc
-------------------------------------------------------------------------------
Count indv cuml rcnt nsec Lock Caller
2 8% 44% 0.00 649290823 ph_mutex+0x1680 page_create_va+0x334
nsec ------ Time Distribution ------ count Stack
1073741824 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 2 segkmem_page_create+0x89
segkmem_xalloc+0xbc
segkmem_alloc_vn+0xcd
segkmem_alloc+0x20
vmem_xalloc+0x4fc
vmem_alloc+0x159
kmem_alloc+0x4f
kobj_alloc+0x7e
kobj_zalloc+0x1c
zcalloc+0x2d
z_deflateInit2_+0x1a1
z_deflateInit_+0x32
z_compress_level+0x77
gzip_compress+0x4b
zio_compress_data+0xbc
-------------------------------------------------------------------------------
Count indv cuml rcnt nsec Lock Caller
2 8% 52% 0.00 220946732 ph_mutex+0x1380 page_create_va+0x334
nsec ------ Time Distribution ------ count Stack
268435456 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 2 segkmem_page_create+0x89
segkmem_xalloc+0xbc
segkmem_alloc_vn+0xcd
segkmem_alloc+0x20
vmem_xalloc+0x4fc
vmem_alloc+0x159
kmem_alloc+0x4f
kobj_alloc+0x7e
kobj_zalloc+0x1c
zcalloc+0x2d
z_deflateInit2_+0x1de
z_deflateInit_+0x32
z_compress_level+0x77
gzip_compress+0x4b
zio_compress_data+0xbc
-------------------------------------------------------------------------------
Count indv cuml rcnt nsec Lock Caller
2 8% 60% 0.00 199293221 ph_mutex+0xd80 page_create_va+0x334
nsec ------ Time Distribution ------ count Stack
268435456 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 2 segkmem_page_create+0x89
segkmem_xalloc+0xbc
segkmem_alloc_vn+0xcd
segkmem_alloc+0x20
vmem_xalloc+0x4fc
vmem_alloc+0x159
kmem_alloc+0x4f
kobj_alloc+0x7e
kobj_zalloc+0x1c
zcalloc+0x2d
z_deflateInit2_+0x1a1
z_deflateInit_+0x32
z_compress_level+0x77
gzip_compress+0x4b
zio_compress_data+0xbc
-------------------------------------------------------------------------------
Count indv cuml rcnt nsec Lock Caller
1 4% 64% 0.00 764285200 ph_mutex+0x1f00 page_create_va+0x334
nsec ------ Time Distribution ------ count Stack
1073741824 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1 segkmem_page_create+0x89
segkmem_xalloc+0xbc
segkmem_alloc_vn+0xcd
segkmem_alloc+0x20
vmem_xalloc+0x4fc
vmem_alloc+0x159
kmem_alloc+0x4f
kobj_alloc+0x7e
kobj_zalloc+0x1c
zcalloc+0x2d
z_deflateInit2_+0x1de
z_deflateInit_+0x32
z_compress_level+0x77
gzip_compress+0x4b
zio_compress_data+0xbc
-------------------------------------------------------------------------------
Count indv cuml rcnt nsec Lock Caller
1 4% 68% 0.00 761611341 ph_mutex+0x1f00 page_create_va+0x334
nsec ------ Time Distribution ------ count Stack
1073741824 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1 segkmem_page_create+0x89
segkmem_xalloc+0xbc
segkmem_alloc_vn+0xcd
segkmem_alloc+0x20
vmem_xalloc+0x4fc
vmem_alloc+0x159
kmem_alloc+0x4f
kobj_alloc+0x7e
kobj_zalloc+0x1c
zcalloc+0x2d
z_deflateInit2_+0x1a1
z_deflateInit_+0x32
z_compress_level+0x77
gzip_compress+0x4b
zio_compress_data+0xbc
-------------------------------------------------------------------------------
Count indv cuml rcnt nsec Lock Caller
1 4% 72% 0.00 762076326 ph_mutex+0x1b00 page_create_va+0x334
nsec ------ Time Distribution ------ count Stack
1073741824 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1 segkmem_page_create+0x89
segkmem_xalloc+0xbc
segkmem_alloc_vn+0xcd
segkmem_alloc+0x20
vmem_xalloc+0x4fc
vmem_alloc+0x159
kmem_alloc+0x4f
kobj_alloc+0x7e
kobj_zalloc+0x1c
zcalloc+0x2d
z_deflateInit2_+0x1b8
z_deflateInit_+0x32
z_compress_level+0x77
gzip_compress+0x4b
zio_compress_data+0xbc
-------------------------------------------------------------------------------
Count indv cuml rcnt nsec Lock Caller
1 4% 76% 0.00 762026717 ph_mutex+0x1b00 page_find+0x82
nsec ------ Time Distribution ------ count Stack
1073741824 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1 segkmem_free_vn+0x81
segkmem_free+0x20
vmem_xfree+0x10c
vmem_free+0x25
kmem_free+0x47
kobj_free+0x23
zcfree+0x36
z_deflateEnd+0x74
z_compress_level+0x9d
gzip_compress+0x4b
zio_compress_data+0xbc
zio_write_compress+0x8d
taskq_thread+0x1a7
thread_start+0x8
-------------------------------------------------------------------------------
Count indv cuml rcnt nsec Lock Caller
1 4% 80% 0.00 681787674 ph_mutex+0x1680 page_create_va+0x334
nsec ------ Time Distribution ------ count Stack
1073741824 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1 segkmem_page_create+0x89
segkmem_xalloc+0xbc
segkmem_alloc_vn+0xcd
segkmem_alloc+0x20
vmem_xalloc+0x4fc
vmem_alloc+0x159
kmem_alloc+0x4f
kobj_alloc+0x7e
kobj_zalloc+0x1c
zcalloc+0x2d
z_deflateInit2_+0x1de
z_deflateInit_+0x32
z_compress_level+0x77
gzip_compress+0x4b
zio_compress_data+0xbc
-------------------------------------------------------------------------------
Count indv cuml rcnt nsec Lock Caller
1 4% 84% 0.00 154470424 ph_mutex+0xd80 page_create_va+0x334
nsec ------ Time Distribution ------ count Stack
268435456 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1 segkmem_page_create+0x89
segkmem_xalloc+0xbc
segkmem_alloc_vn+0xcd
segkmem_alloc+0x20
vmem_xalloc+0x4fc
vmem_alloc+0x159
kmem_alloc+0x4f
kobj_alloc+0x7e
kobj_zalloc+0x1c
zcalloc+0x2d
z_deflateInit2_+0x1de
z_deflateInit_+0x32
z_compress_level+0x77
gzip_compress+0x4b
zio_compress_data+0xbc
-------------------------------------------------------------------------------
Count indv cuml rcnt nsec Lock Caller
1 4% 88% 0.00 61512189 ph_mutex+0x1380 page_find+0x82
nsec ------ Time Distribution ------ count Stack
67108864 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1 segkmem_free_vn+0x81
segkmem_free+0x20
vmem_xfree+0x10c
vmem_free+0x25
kmem_free+0x47
kobj_free+0x23
zcfree+0x36
z_deflateEnd+0xcb
z_compress_level+0x9d
gzip_compress+0x4b
zio_compress_data+0xbc
zio_write_compress+0x8d
taskq_thread+0x1a7
thread_start+0x8
-------------------------------------------------------------------------------
Count indv cuml rcnt nsec Lock Caller
1 4% 92% 0.00 200988978 ph_mutex+0x1380 page_create_va+0x334
nsec ------ Time Distribution ------ count Stack
268435456 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1 segkmem_page_create+0x89
segkmem_xalloc+0xbc
segkmem_alloc_vn+0xcd
segkmem_alloc+0x20
vmem_xalloc+0x4fc
vmem_alloc+0x159
kmem_alloc+0x4f
kobj_alloc+0x7e
kobj_zalloc+0x1c
zcalloc+0x2d
z_deflateInit2_+0x1a1
z_deflateInit_+0x32
z_compress_level+0x77
gzip_compress+0x4b
zio_compress_data+0xbc
-------------------------------------------------------------------------------
Count indv cuml rcnt nsec Lock Caller
1 4% 96% 0.00 11823303 ph_mutex+0x340 page_create_va+0x334
nsec ------ Time Distribution ------ count Stack
16777216 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1 segkmem_page_create+0x89
segkmem_xalloc+0xbc
segkmem_alloc_vn+0xcd
segkmem_alloc+0x20
vmem_xalloc+0x4fc
vmem_alloc+0x159
kmem_alloc+0x4f
kobj_alloc+0x7e
kobj_zalloc+0x1c
zcalloc+0x2d
z_deflateInit2_+0x1b8
z_deflateInit_+0x32
z_compress_level+0x77
gzip_compress+0x4b
zio_compress_data+0xbc
-------------------------------------------------------------------------------
Count indv cuml rcnt nsec Lock Caller
1 4% 100% 0.00 15941350 ph_mutex+0x340 page_create_va+0x334
nsec ------ Time Distribution ------ count Stack
16777216 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1 segkmem_page_create+0x89
segkmem_xalloc+0xbc
segkmem_alloc_vn+0xcd
segkmem_alloc+0x20
vmem_xalloc+0x4fc
vmem_alloc+0x159
kmem_alloc+0x4f
kobj_alloc+0x7e
kobj_zalloc+0x1c
zcalloc+0x2d
z_deflateInit2_+0x1de
z_deflateInit_+0x32
z_compress_level+0x77
gzip_compress+0x4b
zio_compress_data+0xbc
-------------------------------------------------------------------------------
This message posted from opensolaris.org
_______________________________________________
zfs-discuss mailing list
zfs-discuss@opensolaris.org
http://mail.opensolaris.org/mailman/listinfo/zfs-discuss
