Bob, Catching up late on this thread.
Would it be possible for you to collect the following data : - /usr/sbin/lockstat -CcwP -n 50000 -D 20 -s 40 sleep 5 - /usr/sbin/lockstat -HcwP -n 50000 -D 20 -s 40 sleep 5 - /usr/sbin/lockstat -kIW -i 977 -D 20 -s 40 sleep 5 Or if you have access to the GUDs tool please collect data using that. We need to understand how ARC plays a role here. Thanks and regards, Sanjeev. On Sat, Jul 04, 2009 at 02:49:05PM -0500, Bob Friesenhahn wrote: > On Sat, 4 Jul 2009, Jonathan Edwards wrote: >> >> this is only going to help if you've got problems in zfetch .. you'd >> probably see this better by looking for high lock contention in zfetch >> with lockstat > > This is what lockstat says when performance is poor: > > Adaptive mutex spin: 477 events in 30.019 seconds (16 events/sec) > > Count indv cuml rcnt nsec Lock Caller > ------------------------------------------------------------------------------- > 47 10% 10% 0.00 5813 0xffffffff80256000 untimeout+0x24 > 46 10% 19% 0.00 2223 0xffffffffb0a2f200 taskq_thread+0xe3 > 38 8% 27% 0.00 2252 0xffffffffb0a2f200 cv_wait+0x70 > 29 6% 34% 0.00 1115 0xffffffff80256000 callout_execute+0xeb > 26 5% 39% 0.00 3006 0xffffffffb0a2f200 taskq_dispatch+0x1b8 > 22 5% 44% 0.00 1200 0xffffffffa06158c0 post_syscall+0x206 > 18 4% 47% 0.00 3858 arc_eviction_mtx arc_do_user_evicts+0x76 > 16 3% 51% 0.00 1352 arc_eviction_mtx arc_buf_add_ref+0x2d > 15 3% 54% 0.00 5376 0xffffffffb1adac28 taskq_thread+0xe3 > 11 2% 56% 0.00 2520 0xffffffffb1adac28 taskq_dispatch+0x1b8 > 9 2% 58% 0.00 2158 0xffffffffbb909e20 pollwakeup+0x116 > 9 2% 60% 0.00 2431 0xffffffffb1adac28 cv_wait+0x70 > 8 2% 62% 0.00 3912 0xffffffff80259000 untimeout+0x24 > 7 1% 63% 0.00 3679 0xffffffffb10dfbc0 polllock+0x3f > 7 1% 65% 0.00 2171 0xffffffffb0a2f2d8 cv_wait+0x70 > 6 1% 66% 0.00 771 0xffffffffb3f23708 pcache_delete_fd+0xac > 6 1% 67% 0.00 4679 0xffffffffb0a2f2d8 taskq_dispatch+0x1b8 > 5 1% 68% 0.00 500 0xffffffffbe555040 fifo_read+0xf8 > 5 1% 69% 0.00 15838 0xffffffff8025c000 untimeout+0x24 > 4 1% 70% 0.00 1213 0xffffffffac44b558 sd_initpkt_for_buf+0x110 > 4 1% 71% 0.00 638 0xffffffffa28722a0 polllock+0x3f > 4 1% 72% 0.00 610 0xffffffff80259000 timeout_common+0x39 > 4 1% 73% 0.00 10691 0xffffffff80256000 timeout_common+0x39 > 3 1% 73% 0.00 1559 htable_mutex+0x78 htable_release+0x8a > 3 1% 74% 0.00 3610 0xffffffffbb909e20 cv_timedwait_sig+0x1c1 > 3 1% 74% 0.00 1636 0xffffffffa240d410 > ohci_allocate_periodic_in_resource+0x71 > 2 0% 75% 0.00 5959 0xffffffffbe555040 fifo_read+0x5c > 2 0% 75% 0.00 3744 0xffffffffbe555040 polllock+0x3f > 2 0% 76% 0.00 635 0xffffffffb3f23708 pollwakeup+0x116 > 2 0% 76% 0.00 709 0xffffffffb3f23708 cv_timedwait_sig+0x1c1 > 2 0% 77% 0.00 831 0xffffffffb3dd2070 pcache_insert+0x13d > 2 0% 77% 0.00 5976 0xffffffffb3dd2070 pollwakeup+0x116 > 2 0% 77% 0.00 1339 0xffffffffb1eb9b80 > metaslab_group_alloc+0x136 > 2 0% 78% 0.00 1514 0xffffffffb0a2f2d8 taskq_thread+0xe3 > 2 0% 78% 0.00 4042 0xffffffffb0a22988 vdev_queue_io_done+0xc3 > 2 0% 79% 0.00 3428 0xffffffffb0a21f08 vdev_queue_io_done+0xc3 > 2 0% 79% 0.00 1002 0xffffffffac44b558 sd_core_iostart+0x37 > 2 0% 79% 0.00 1387 0xffffffffa8c56d80 xbuf_iostart+0x7d > 2 0% 80% 0.00 698 0xffffffffa58a3318 sd_return_command+0x11b > 2 0% 80% 0.00 385 0xffffffffa58a3318 sd_start_cmds+0x115 > 2 0% 81% 0.00 562 0xffffffffa5647800 ssfcp_scsi_start+0x30 > 2 0% 81% 0.00 1620 0xffffffffa4162d58 ssfcp_scsi_init_pkt+0x1be > 2 0% 82% 0.00 897 0xffffffffa4162d58 ssfcp_scsi_start+0x42 > 2 0% 82% 0.00 475 0xffffffffa4162b78 ssfcp_scsi_start+0x42 > 2 0% 82% 0.00 697 0xffffffffa40fb158 sd_start_cmds+0x115 > 2 0% 83% 0.00 10901 0xffffffffa28722a0 fifo_write+0x5b > 2 0% 83% 0.00 4379 0xffffffffa28722a0 fifo_read+0xf8 > 2 0% 84% 0.00 1534 0xffffffffa2638390 emlxs_tx_get+0x38 > 2 0% 84% 0.00 1601 0xffffffffa2638350 emlxs_issue_iocb_cmd+0xc1 > 2 0% 84% 0.00 6697 0xffffffffa2503f08 vdev_queue_io_done+0x7b > 2 0% 85% 0.00 4113 0xffffffffa24040b0 > gcpu_ntv_mca_poll_wrapper+0x64 > 2 0% 85% 0.00 928 0xfffffe85dc140658 pollwakeup+0x116 > 1 0% 86% 0.00 404 iommulib_lock lookup_cache+0x2c > 1 0% 86% 0.00 4867 pidlock thread_exit+0x6f > 1 0% 86% 0.00 1245 plocks+0x3c0 pollhead_delete+0x23 > 1 0% 86% 0.00 2452 plocks+0x3c0 pollhead_insert+0x35 > 1 0% 86% 0.00 882 htable_mutex+0x3c0 htable_lookup+0x83 > 1 0% 87% 0.00 28547 htable_mutex+0x3c0 htable_create+0xe3 > 1 0% 87% 0.00 21173 htable_mutex+0x3c0 htable_release+0x8a > 1 0% 87% 0.00 1235 htable_mutex+0x370 htable_lookup+0x83 > 1 0% 87% 0.00 3212 htable_mutex+0x370 htable_release+0x8a > 1 0% 87% 0.00 793 htable_mutex+0x78 htable_lookup+0x83 > 1 0% 88% 0.00 981 buf_hash_table+0x1210 arc_buf_add_ref+0x7c > 1 0% 88% 0.00 1222 buf_hash_table+0x1c50 arc_buf_add_ref+0x7c > 1 0% 88% 0.00 1585 buf_hash_table+0x2490 arc_buf_remove_ref+0x6d > 1 0% 88% 0.00 1545158 ARC_mru+0x58 remove_reference+0x56 > 1 0% 88% 0.00 564 0xffffffffbcad4a00 strrput+0x19a > 1 0% 89% 0.00 1033 0xffffffffbcad4a00 polllock+0x3f > 1 0% 89% 0.00 587 0xffffffffbd328098 putnext+0x6c > 1 0% 89% 0.00 11576 0xffffffffbd328098 strrput+0x19a > 1 0% 89% 0.00 847 0xffffffffb3f23708 pcache_insert+0x13d > 1 0% 90% 0.00 703 0xffffffffbb909e20 poll_common+0x258 > 1 0% 90% 0.00 1286 0xffffffffbcad4870 kstrgetmsg+0x79 > 1 0% 90% 0.00 1528 0xffffffffb1012e00 cv_wait+0x70 > 1 0% 90% 0.00 404 0xffffffffb1011de0 zio_notify_parent+0x37 > 1 0% 90% 0.00 764 0xffffffffb1011de0 zio_create+0x29f > 1 0% 91% 0.00 5887 0xffffffffb0a2f3b0 cv_wait+0x70 > 1 0% 91% 0.00 883 0xffffffffb1ad3de0 metaslab_group_alloc+0x7e > 1 0% 91% 0.00 555 0xffffffffb10dfbc0 fifo_write+0x5b > 1 0% 91% 0.00 692 0xffffffffb3dd2070 pollrelock+0x36 > 1 0% 91% 0.00 4390 0xffffffffb0a22988 vdev_queue_io+0x6e > 1 0% 92% 0.00 1449 0xffffffffb0a21f60 vdev_cache_write+0x64 > 1 0% 92% 0.00 859 0xffffffffb0a21a20 vdev_cache_write+0x64 > 1 0% 92% 0.00 446 0xffffffffb0a20ec8 vdev_queue_io+0x6e > 1 0% 92% 0.00 1987 0xffffffffb0a21f08 vdev_queue_io+0x6e > 1 0% 92% 0.00 5968 0xffffffffb0a21f08 vdev_queue_io_done+0x3a > 1 0% 93% 0.00 280 0xffffffffac44b558 sd_start_cmds+0x115 > 1 0% 93% 0.00 527 0xffffffffac44b118 sd_core_iostart+0x37 > 1 0% 93% 0.00 380 0xffffffffac51aed8 sd_initpkt_for_buf+0x110 > 1 0% 93% 0.00 742 0xffffffffac51aed8 sdstrategy+0x53 > 1 0% 94% 0.00 696 0xffffffffac51aed8 sd_start_cmds+0x115 > 1 0% 94% 0.00 5398 0xffffffffb0a1c988 vdev_queue_io_done+0x3a > 1 0% 94% 0.00 6102 0xffffffffb0a1c988 vdev_queue_io_done+0x7b > 1 0% 94% 0.00 988 0xffffffffa40fbcd8 sd_return_command+0x11b > 1 0% 94% 0.00 298 0xffffffffa4101460 ssfcp_scsi_init_pkt+0x3b4 > 1 0% 95% 0.00 302 0xffffffffa40fbcd8 sdstrategy+0x53 > 1 0% 95% 0.00 1436 0xffffffffa40fb158 sdintr+0x3a > 1 0% 95% 0.00 764 0xffffffffa40fbcd8 sd_initpkt_for_buf+0x110 > 1 0% 95% 0.00 846 0xffffffffa40fbcd8 sd_start_cmds+0x115 > 1 0% 95% 0.00 1172 0xffffffffa5644f60 vdev_cache_write+0x64 > 1 0% 96% 0.00 8401 0xffffffffa5644f08 vdev_queue_io_done+0xc3 > 1 0% 96% 0.00 417 0xffffffffa5644f08 vdev_queue_io+0x6e > 1 0% 96% 0.00 3419 0xffffffffa5644f08 vdev_queue_io_done+0x7b > 1 0% 96% 0.00 1341 0xffffffffa58a3318 sd_core_iostart+0x37 > 1 0% 96% 0.00 431 0xffffffffa22cc840 fc_ulp_init_packet+0x31 > 1 0% 97% 0.00 569 0xffffffff807a4000 callout_execute+0xeb > 1 0% 97% 0.00 695 0xffffffff8025c000 callout_execute+0xeb > 1 0% 97% 0.00 500 0xffffffff80244000 callout_execute+0xeb > 1 0% 97% 0.00 855 0xfffffe85dc140658 pcache_insert+0x13d > 1 0% 97% 0.00 13339 0xfffffe85d67ddc48 cv_wait+0x70 > 1 0% 98% 0.00 5377 0xffffffff80253000 untimeout+0x24 > 1 0% 98% 0.00 5104 0xffffffff80253000 timeout_common+0x39 > 1 0% 98% 0.00 508 0xffffffff80253000 callout_execute+0xeb > 1 0% 98% 0.00 260 0xffffffffa2638420 emlxs_register_pkt+0x30 > 1 0% 99% 0.00 1059 0xffffffffa2638390 emlxs_tx_put+0x79 > 1 0% 99% 0.00 411 0xffffffffa3e3a298 sdstrategy+0x53 > 1 0% 99% 0.00 336 0xffffffffa3d6e380 fc_ulp_init_packet+0x31 > 1 0% 99% 0.00 926 0xffffffffa3cdfc58 sd_start_cmds+0x115 > 1 0% 99% 0.00 894 0xffffffffa3e3a298 sd_core_iostart+0x37 > 1 0% 100% 0.00 766 0xffffffffa3e3a298 sd_buf_iodone+0x23 > 1 0% 100% 0.00 340 0xffffffffa3e58420 emlxs_register_pkt+0x30 > 1 0% 100% 0.00 1516 0xffffffffa3e58420 emlxs_unregister_pkt+0x53 > ------------------------------------------------------------------------------- > > Adaptive mutex block: 7 events in 30.019 seconds (0 events/sec) > > Count indv cuml rcnt nsec Lock Caller > ------------------------------------------------------------------------------- > 1 14% 14% 0.00 39004 0xffffffffbe555040 fifo_read+0x5c > 1 14% 29% 0.00 78624 0xffffffffb3dd2070 pollwakeup+0x116 > 1 14% 43% 0.00 6668 0xffffffffb0a2f200 taskq_dispatch+0x1b8 > 1 14% 57% 0.00 35694 0xffffffffb0a2f3b0 cv_wait+0x70 > 1 14% 71% 0.00 22697 0xffffffffb0a21f08 vdev_queue_io_done+0xc3 > 1 14% 86% 0.00 20174 0xffffffffb0a1c988 vdev_queue_io_done+0x3a > 1 14% 100% 0.00 7365 0xfffffe85d67ddc48 cv_wait+0x70 > ------------------------------------------------------------------------------- > > Spin lock spin: 478 events in 30.019 seconds (16 events/sec) > > Count indv cuml rcnt nsec Lock Caller > ------------------------------------------------------------------------------- > 131 27% 27% 0.00 1383 0xffffffffa21a89f8 disp_lock_enter+0x1e > 93 19% 47% 0.00 962 0xffffffffa250e9c0 disp_lock_enter+0x1e > 84 18% 64% 0.00 3085 0xffffffffa21a8a28 disp_lock_enter+0x1e > 73 15% 80% 0.00 2105 cpu0_disp disp_lock_enter+0x1e > 33 7% 87% 0.00 3548 0xffffffffa21a8a28 disp_lock_enter_high+0x9 > 22 5% 91% 0.00 6011 cpu0_disp disp_lock_enter_high+0x9 > 21 4% 96% 0.00 2222 hres_lock hr_clock_lock+0x1d > 9 2% 97% 0.00 3869 0xffffffffa21a89f8 disp_lock_enter_high+0x9 > 8 2% 99% 0.00 1649 0xffffffffa250e9c0 disp_lock_enter_high+0x9 > 4 1% 100% 0.00 624 cp_default disp_lock_enter+0x1e > > ------------------------------------------------------------------------------- > > Thread lock spin: 6 events in 30.019 seconds (0 events/sec) > > Count indv cuml rcnt nsec Lock Caller > ------------------------------------------------------------------------------- > 2 33% 33% 0.00 698 transition_lock ts_update_list+0x5c > 2 33% 67% 0.00 779 cpu[3]+0xf8 cv_wait+0x3e > 1 17% 83% 0.00 452 cpu[3]+0xf8 cv_timedwait_sig+0xe1 > 1 17% 100% 0.00 324 cpu[2]+0xf8 > cv_timedwait_sig+0xe1 > ------------------------------------------------------------------------------- > > -- > Bob Friesenhahn > bfrie...@simple.dallas.tx.us, http://www.simplesystems.org/users/bfriesen/ > GraphicsMagick Maintainer, http://www.GraphicsMagick.org/ > _______________________________________________ > zfs-discuss mailing list > zfs-discuss@opensolaris.org > http://mail.opensolaris.org/mailman/listinfo/zfs-discuss -- ---------------- Sanjeev Bagewadi Solaris RPE Bangalore, India _______________________________________________ zfs-discuss mailing list zfs-discuss@opensolaris.org http://mail.opensolaris.org/mailman/listinfo/zfs-discuss
