ミューテックスチェック
今回はカーネルミューテックスに関するリソース情報を取得する方法を紹介しようと思います。ユーザがこの情報を使うというか気にする必要はほとんどないとは思います。カーネルデベロッパでも、
カーネルミューテックスに関する情報はlockstat(1)コマンドはカーネルのロック情報およびプロファイリング統計情報を取得して表示するためのコマンドです。-Hでミューテックスのホールド時間、
% sudo lockstat -H '*'
lockstat: warning: * exited with code 127
lockstat: warning: 34632 dynamic variable drops with non-empty dirty list
lockstat: warning: ran out of data records (use -n for more)
Adaptive mutex hold: 235 events in 0.016 seconds (14558 events/sec)
Count indv cuml rcnt nsec Lock Caller
-------------------------------------------------------------------------------
28 12% 12% 0.00 653 process lock sys_sigprocmask+0x61
28 12% 24% 0.00 23481 pmap vmspace_fork+0x8d9
26 11% 35% 0.00 653 select mtxpool pipe_poll+0x1c3
26 11% 46% 0.00 654 select mtxpool kern_select+0xc8b
26 11% 57% 0.00 1733 pipe mutex kern_select+0x7df
13 6% 63% 0.00 613 ttymtx ttydev_poll+0x1f
13 6% 68% 0.00 723 cdev devfs_poll_f+0x36
12 5% 73% 0.00 606 ttymtx ttydev_read+0x20
12 5% 78% 0.00 613 cdev devfs_read_f+0x5c
6 3% 81% 0.00 576 vm page free queue _pmap_allocpte+0xaf
4 2% 83% 0.00 958 pmap vmspace_fork+0x5e7
2 1% 83% 0.00 625 vm page free queue uma_small_alloc+0x47
2 1% 84% 0.00 1085 vm page free queue get_pv_entry+0x6a
2 1% 85% 0.00 844 vm page free queue pmap_remove_pte+0x23f
2 1% 86% 0.00 886 vm page free queue vm_fault_hold+0x5b6
2 1% 87% 0.00 1946 vm page vm_fault+0x78
2 1% 88% 0.00 1048 process_ctor uma_zalloc_arg+0x6cc
2 1% 89% 0.00 597 process lock sys_ktimer_create+0x4b
2 1% 89% 0.00 1070 pmap pv chunk list pmap_try_insert_pv_entry+0x23
2 1% 90% 0.00 638 pmap pv chunk list pmap_remove_pte+0x23f
2 1% 91% 0.00 648 itimer keg_fetch_slab+0x16e
2 1% 92% 0.00 485 itimer kern_ktimer_create+0x330
2 1% 93% 0.00 1020 cdev devfs_ioctl_f+0x39
1 0% 93% 0.00 606 vm page free queue pmap_remove+0x5fc
1 0% 94% 0.00 586 vm page free queue pmap_pinit_type+0x33
1 0% 94% 0.00 2006 vm page vm_fault_hold+0x1221
1 0% 94% 0.00 643 vm active pagequeue vm_fault_hold+0x61b
1 0% 95% 0.00 584 ui_vmsize vm_map_delete+0x1bc
1 0% 95% 0.00 621 vm active pagequeue vm_fault_hold+0x212f
1 0% 96% 0.00 801 vm inactive pagequeue release_page+0xd2
1 0% 96% 0.00 825 process lock sys_ktimer_settime+0x4d
1 0% 97% 0.00 676 sigacts sys_sigaction+0x61
1 0% 97% 0.00 565 swapdev vm_map_delete+0x1bc
1 0% 97% 0.00 3168 itimer lock sys_ktimer_settime+0x4d
1 0% 98% 0.00 506 itimer uma_zalloc_arg+0x44e
1 0% 98% 0.00 2212 invlgn pmap_remove+0x5e9
1 0% 99% 0.00 3003 eventhandler proc_ctor+0x41
1 0% 99% 0.00 3360 pmap vm_fault_hold+0x1fe1
1 0% 100% 0.00 618 pmap vm_fault_hold+0x312
1 0% 100% 0.00 1927 process lock sys_sigaction+0x61
-------------------------------------------------------------------------------
Spin lock hold: 15 events in 0.016 seconds (929 events/sec)
Count indv cuml rcnt nsec Lock Caller
-------------------------------------------------------------------------------
3 20% 20% 0.00 1291 et_hw_mtx cpu_idle+0x56
2 13% 33% 0.00 1513 et_hw_mtx cpu_activeclock+0x7b
2 13% 47% 0.00 1342 et_hw_mtx timercb+0xb7
1 7% 53% 0.00 876 turnstile chain pmap_delayed_invl_finished+0xde
1 7% 60% 0.00 7453 smp rendezvous dtrace_sync+0x77
1 7% 67% 0.00 36588 smp rendezvous dtrace_xcall+0xb2
1 7% 73% 0.00 2126 sched lock 2 handleevents+0x105
1 7% 80% 0.00 699 et_hw_mtx callout_reset_sbt_on+0x2f1
1 7% 87% 0.00 2516 callout dtrace_state_clean+0x138
1 7% 93% 0.00 572 callout intr_event_execute_handlers+0x20f
1 7% 100% 0.00 683 callout realtimer_settime+0x29d
-------------------------------------------------------------------------------
R/W writer hold: 474 events in 0.016 seconds (29364 events/sec)
Count indv cuml rcnt nsec Lock Caller
-------------------------------------------------------------------------------
283 60% 60% 0.00 662 pmap pv list pmap_remove+0x497
156 33% 93% 0.00 1018 pmap pv list pmap_copy+0x65c
14 3% 96% 0.00 1175 vm object fork1+0x5ec
13 3% 98% 0.00 925 pmap pv list vmspace_fork+0x8d9
1 0% 99% 0.00 507 vm object sys_munmap+0xff
1 0% 99% 0.00 518 vm object vmspace_fork+0x70a
1 0% 99% 0.00 644 vm object vm_map_process_deferred+0x5d
1 0% 99% 0.00 3123 vm object vm_fault_hold+0x2212
1 0% 99% 0.00 575 vm object unlock_and_deallocate+0x276
1 0% 100% 0.00 8179 vm object vm_fault+0x78
1 0% 100% 0.00 725 pmap pv list vm_map_delete+0x18d
1 0% 100% 0.00 1324 pmap pv list vm_fault_hold+0x1fe1
-------------------------------------------------------------------------------
R/W reader hold: 3 events in 0.016 seconds (186 events/sec)
Count indv cuml rcnt nsec Lock Caller
-------------------------------------------------------------------------------
2 67% 67% 0.00 3623 vm object vm_fault+0x78
1 33% 100% 0.00 2622 vm object vm_fault_hold+0x2652
-------------------------------------------------------------------------------
SX shared hold: 100 events in 0.016 seconds (6195 events/sec)
Count indv cuml rcnt nsec Lock Caller
-------------------------------------------------------------------------------
48 48% 48% 0.00 651 devfsmount VOP_GETATTR_APV+0x87
48 48% 96% 0.00 757 devfsmount devfs_getattr+0x1e
2 2% 98% 0.00 5757300 vm map (user) fork1+0x5ec
2 2% 100% 0.00 1301 dtrace_lock dtrace_ioctl+0xf24
-------------------------------------------------------------------------------
SX exclusive hold: 20 events in 0.016 seconds (1239 events/sec)
Count indv cuml rcnt nsec Lock Caller
-------------------------------------------------------------------------------
15 75% 75% 0.00 688 vm map (user) useracc+0x76
2 10% 85% 0.00 17497 vm map (user) unlock_and_deallocate+0x289
2 10% 95% 0.00 1141 filedesc structure sys_ioctl+0x171
1 5% 100% 0.00 4835 vm map (user) vm_fault_hold+0x267e
-------------------------------------------------------------------------------
%
% sudo lockstat -C '*'
lockstat: warning: * exited with code 127
Thread lock spin: 21 events in 0.004 seconds (5679 events/sec)
Count indv cuml rcnt nsec Lock Caller
-------------------------------------------------------------------------------
2 10% 10% 0.00 43 sleepq chain sleepq_broadcast+0x96
1 5% 14% 0.00 38 sched lock 3 sched_idletd+0xcc
1 5% 19% 0.00 31 sched lock 3 umtx_thread_cleanup+0x12f
1 5% 24% 0.00 41 sched lock 3 thread_exit+0x2a8
1 5% 29% 0.00 53 sched lock 3 thread_wait+0x20
1 5% 33% 0.00 27 sched lock 1 ast+0x30a
1 5% 38% 0.00 35 sched lock 1 ast+0x4c
1 5% 43% 0.00 32 sched lock 2 statclock_cnt+0x126
1 5% 48% 0.00 118 sched lock 3 statclock_cnt+0x126
1 5% 52% 0.00 32 sched lock 3 ruxagg+0x23
1 5% 57% 0.00 29 sched lock 1 fork1+0x218f
1 5% 62% 0.00 32 sched lock 1 fork1+0x1138
1 5% 67% 0.00 34 sched lock 1 statclock_cnt+0x126
1 5% 71% 0.00 47 sched lock 0 statclock_cnt+0x126
1 5% 76% 0.00 67 sched lock 0 sched_idletd+0xcc
1 5% 81% 0.00 23 sched lock 1 sched_userret+0x3a
1 5% 86% 0.00 38 sched lock 1 sched_exit_thread+0x20
1 5% 90% 0.00 949 sched lock 1 sched_idletd+0xcc
1 5% 95% 0.00 40 sched lock 1 sleepq_add+0xf8
1 5% 100% 0.00 24 sched lock 1 sleepq_catch_signals+0x5d
-------------------------------------------------------------------------------
%
lockstat(1)は引数にコマンドを与えることで、
% sudo lockstat sleep 5
Adaptive mutex block: 3 events in 5.008 seconds (1 events/sec)
Count indv cuml rcnt nsec Lock Caller
-------------------------------------------------------------------------------
1 33% 33% 0.00 3701 uhci0 usb_process+0x167
1 33% 67% 0.00 6356 ehci0 usb_process+0x167
1 33% 100% 0.00 5934 ATA state lock ata_interrupt+0x7c
-------------------------------------------------------------------------------
Thread lock spin: 3047 events in 5.008 seconds (608 events/sec)
Count indv cuml rcnt nsec Lock Caller
-------------------------------------------------------------------------------
557 18% 18% 0.00 75 sched lock 0 critical_exit+0x58
547 18% 36% 0.00 51 sched lock 0 intr_event_schedule_thread+0x7f
545 18% 54% 0.00 51 sched lock 0 ithread_loop+0x197
519 17% 71% 0.00 102 sched lock 0 statclock_cnt+0x126
193 6% 77% 0.00 33 sched lock 0 ruxagg+0x23
165 5% 83% 0.00 59 sched lock 0 sleepq_add+0xf8
141 5% 88% 0.00 125 sleepq chain ruxagg+0x23
132 4% 92% 0.00 147 sleepq chain sleepq_timeout+0x1d
81 3% 95% 0.00 33 sched lock 0 sleepq_timedwait+0x2f
59 2% 96% 0.00 35 sched lock 0 sleepq_catch_signals+0x5d
25 1% 97% 0.00 31 sched lock 0 sleepq_wait+0x2f
23 1% 98% 0.00 55 sleepq chain sleepq_signal+0x9c
10 0% 98% 0.00 44 sched lock 0 sched_userret+0x3a
6 0% 99% 0.00 34 sched lock 0 ast+0x4c
5 0% 99% 0.00 217 sleepq chain sleepq_broadcast+0x96
5 0% 99% 0.00 33 sleepq chain tdsigwakeup+0xd2
5 0% 99% 0.00 31 sleepq chain signotify+0xf1
5 0% 99% 0.00 33 sched lock 0 sched_sync+0x8a1
4 0% 99% 0.00 42 sched lock 0 kern_yield+0x105
3 0% 99% 0.00 30 turnstile lock turnstile_unpend+0x282
3 0% 100% 0.00 29 sched lock 0 turnstile_unpend+0x68
3 0% 100% 0.00 100 sched lock 0 turnstile_wait+0x351
3 0% 100% 0.00 34 sched lock 0 propagate_priority+0xb9
2 0% 100% 0.00 53 sched lock 0 umtx_thread_cleanup+0x12f
1 0% 100% 0.00 39 sched lock 0 ast+0x30a
1 0% 100% 0.00 106 sched lock 0 fork1+0x1138
1 0% 100% 0.00 58 sched lock 0 fork1+0x218f
1 0% 100% 0.00 22 sched lock 0 thread_exit+0x2a8
1 0% 100% 0.00 255 sched lock 0 thread_wait+0x20
1 0% 100% 0.00 40 sched lock 0 sched_exit_thread+0x20
-------------------------------------------------------------------------------
%
オプションを指定すると、
%
sudo lockstat -H -D 10 -s 50 sleep 5
lockstat: warning: 17484 dynamic variable drops with non-empty dirty list
lockstat: warning: 4909 dynamic variable drops with non-empty dirty list
lockstat: warning: ran out of data records (use -n for more)
Adaptive mutex hold: 1120 events in 5.014 seconds (223 events/sec)
-------------------------------------------------------------------------------
Count indv cuml rcnt nsec Lock Caller
519 46% 46% 0.00 922 reseed mutex random_kthread+0x78
nsec ------ Time Distribution ------ count Stack
1024 |@@@@@@@@@@@@@@@@@@@@@@ 394 fork_exit+0x85
2048 |@@@@@ 98 0xffffffff80f8467e
4096 |@ 26
8192 | 0
16384 | 1
-------------------------------------------------------------------------------
Count indv cuml rcnt nsec Lock Caller
172 15% 62% 0.00 10171 process lock sys_getrusage+0x1d
nsec ------ Time Distribution ------ count Stack
1024 |@@@@@@@@@@@@@ 75 amd64_syscall+0x4ce
2048 |@ 6 0xffffffff80f8442b
4096 | 2
8192 | 2
16384 |@@@@@ 34
32768 |@@@@@@@@ 51
65536 | 2
-------------------------------------------------------------------------------
Count indv cuml rcnt nsec Lock Caller
92 8% 70% 0.00 765 select mtxpool kern_poll+0x71b
nsec ------ Time Distribution ------ count Stack
1024 |@@@@@@@@@@@@@@@@@@@@@@@@@@@ 84 sys_poll+0x61
2048 |@@ 8 amd64_syscall+0x4ce
0xffffffff80f8442b
-------------------------------------------------------------------------------
Count indv cuml rcnt nsec Lock Caller
48 4% 74% 0.00 1309 sellck kern_poll+0x296
nsec ------ Time Distribution ------ count Stack
1024 |@@@@@@@@@@@@@ 21 sys_poll+0x61
2048 |@@@@@@@@@@@ 19 amd64_syscall+0x4ce
4096 |@@@@@ 8 0xffffffff80f8442b
-------------------------------------------------------------------------------
Count indv cuml rcnt nsec Lock Caller
44 4% 78% 0.00 9447 Giant softclock_call_cc+0x1bc
nsec ------ Time Distribution ------ count Stack
8192 |@@@@@@ 9 softclock+0x94
16384 |@@@@@@@@@@@@@@@@@@@@@@@ 34 intr_event_execute_handlers+0x20f
32768 | 1 ithread_loop+0xc6
fork_exit+0x85
0xffffffff80f8467e
-------------------------------------------------------------------------------
Count indv cuml rcnt nsec Lock Caller
34 3% 81% 0.00 807 IP reassembly pfslowtimo+0x54
nsec ------ Time Distribution ------ count Stack
1024 |@@@@@@@@@@@@@@@@@@@@@@@@ 28 softclock_call_cc+0x18a
2048 |@@@@ 5 softclock+0x94
4096 | 1 intr_event_execute_handlers+0x20f
ithread_loop+0xc6
fork_exit+0x85
0xffffffff80f8467e
-------------------------------------------------------------------------------
Count indv cuml rcnt nsec Lock Caller
32 3% 84% 0.00 4113 pipe mutex kern_poll+0x650
nsec ------ Time Distribution ------ count Stack
4096 |@@@@@@@@@@@@@@@ 16 sys_poll+0x61
8192 |@@@@@@@@@@@@@@@ 16 amd64_syscall+0x4ce
0xffffffff80f8442b
-------------------------------------------------------------------------------
Count indv cuml rcnt nsec Lock Caller
21 2% 86% 0.00 7637 msgbuf lock softclock_call_cc+0x1bc
nsec ------ Time Distribution ------ count Stack
8192 |@@@@@@@@@@@@@@@@@@@@@@ 16 softclock+0x94
16384 |@@@@@@@ 5 intr_event_execute_handlers+0x20f
ithread_loop+0xc6
fork_exit+0x85
0xffffffff80f8467e
-------------------------------------------------------------------------------
Count indv cuml rcnt nsec Lock Caller
15 1% 87% 0.00 619 select mtxpool pipe_poll+0x1c3
nsec ------ Time Distribution ------ count Stack
1024 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 15 kern_poll+0x650
sys_poll+0x61
amd64_syscall+0x4ce
0xffffffff80f8442b
-------------------------------------------------------------------------------
Count indv cuml rcnt nsec Lock Caller
7 1% 88% 0.00 1001 Global Softdep Lock softdep_process_worklist+0xd5
nsec ------ Time Distribution ------ count Stack
1024 |@@@@@@@@@@@@@@@@@@@@@ 5 softdep_flush+0x17f
2048 |@@@@@@@@ 2 fork_exit+0x85
0xffffffff80f8467e
-------------------------------------------------------------------------------
Spin lock hold: 6971 events in 5.014 seconds (1390 events/sec)
-------------------------------------------------------------------------------
Count indv cuml rcnt nsec Lock Caller
521 7% 7% 0.00 9556302 sched lock 0 fork_exit+0x85
nsec ------ Time Distribution ------ count Stack
65536 | 1 0xffffffff80f8467e
131072 | 0
262144 | 0
524288 | 0
1048576 | 1
2097152 | 6
4194304 | 0
8388608 | 8
16777216 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 505
-------------------------------------------------------------------------------
Count indv cuml rcnt nsec Lock Caller
521 7% 15% 0.00 649 callout intr_event_execute_handlers+0x20f
nsec ------ Time Distribution ------ count Stack
1024 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 504 ithread_loop+0xc6
2048 | 16 fork_exit+0x85
4096 | 1 0xffffffff80f8467e
-------------------------------------------------------------------------------
Count indv cuml rcnt nsec Lock Caller
515 7% 22% 0.00 5013 callout dtrace_state_clean+0x138
nsec ------ Time Distribution ------ count Stack
1024 |@@ 46 softclock_call_cc+0x18a
2048 | 3 softclock+0x94
4096 | 0 intr_event_execute_handlers+0x20f
8192 |@@@@@@@@@@@@@@@@@@@@@@@@@ 441 ithread_loop+0xc6
16384 |@ 20 fork_exit+0x85
32768 | 5 0xffffffff80f8467e
-------------------------------------------------------------------------------
Count indv cuml rcnt nsec Lock Caller
489 7% 29% 0.00 755 callout softclock+0x94
nsec ------ Time Distribution ------ count Stack
1024 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 463 intr_event_execute_handlers+0x20f
2048 |@ 23 ithread_loop+0xc6
4096 | 0 fork_exit+0x85
8192 | 0 0xffffffff80f8467e
16384 | 3
-------------------------------------------------------------------------------
Count indv cuml rcnt nsec Lock Caller
464 7% 36% 0.00 724 et_hw_mtx callout_reset_sbt_on+0x2f1
nsec ------ Time Distribution ------ count Stack
1024 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 436 dtrace_state_clean+0x138
2048 |@ 24 softclock_call_cc+0x18a
4096 | 3 softclock+0x94
8192 | 0 intr_event_execute_handlers+0x20f
16384 | 1 ithread_loop+0xc6
fork_exit+0x85
0xffffffff80f8467e
-------------------------------------------------------------------------------
Count indv cuml rcnt nsec Lock Caller
438 6% 42% 0.00 1303 et_hw_mtx cpu_idle+0x56
nsec ------ Time Distribution ------ count Stack
2048 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 414 sched_idletd+0x3d3
4096 |@ 24 fork_exit+0x85
0xffffffff80f8467e
-------------------------------------------------------------------------------
Count indv cuml rcnt nsec Lock Caller
421 6% 48% 0.00 3294 sched lock 0 handleevents+0x105
nsec ------ Time Distribution ------ count Stack
2048 | 1 timercb+0xb7
4096 |@@@@@@@@@@@@@@@@@@@@@@@@@@ 366 lapic_handle_timer+0x9f
8192 |@@ 41 0xffffffff80f84d3c
16384 | 9 acpi_cpu_idle+0x2e2
32768 | 3 cpu_idle_acpi+0x3f
65536 | 1 cpu_idle+0x95
sched_idletd+0x3d3
fork_exit+0x85
0xffffffff80f8467e
-------------------------------------------------------------------------------
Count indv cuml rcnt nsec Lock Caller
418 6% 54% 0.00 7028 callout handleevents+0x17c
nsec ------ Time Distribution ------ count Stack
4096 | 2 timercb+0xb7
8192 |@@@@@@@@@@@@@@@@@@@@@@@@@ 350 lapic_handle_timer+0x9f
16384 |@@@@ 62 0xffffffff80f84d3c
32768 | 3 acpi_cpu_idle+0x2e2
65536 | 1 cpu_idle_acpi+0x3f
cpu_idle+0x95
sched_idletd+0x3d3
fork_exit+0x85
0xffffffff80f8467e
-------------------------------------------------------------------------------
Count indv cuml rcnt nsec Lock Caller
416 6% 60% 0.00 990 et_hw_mtx callout_process+0x2d6
nsec ------ Time Distribution ------ count Stack
1024 |@@@@@@@@@@@@@@@@@@@@@@@@@ 359 handleevents+0x17c
2048 |@@@ 50 timercb+0xb7
4096 | 1 lapic_handle_timer+0x9f
8192 | 0 0xffffffff80f84d3c
16384 | 6 acpi_cpu_idle+0x2e2
cpu_idle_acpi+0x3f
cpu_idle+0x95
sched_idletd+0x3d3
fork_exit+0x85
0xffffffff80f8467e
-------------------------------------------------------------------------------
Count indv cuml rcnt nsec Lock Caller
411 6% 66% 0.00 1097 entropy harvest mutex swi_sched+0x40
nsec ------ Time Distribution ------ count Stack
1024 |@@@@@@@@@@@@@@@@@@@@@ 290 callout_process+0x322
2048 |@@@@@@@@ 115 handleevents+0x17c
4096 | 2 timercb+0xb7
8192 | 0 lapic_handle_timer+0x9f
16384 | 4 0xffffffff80f84d3c
acpi_cpu_idle+0x2e2
cpu_idle_acpi+0x3f
cpu_idle+0x95
sched_idletd+0x3d3
fork_exit+0x85
0xffffffff80f8467e
-------------------------------------------------------------------------------
R/W writer hold: 50 events in 5.014 seconds (10 events/sec)
-------------------------------------------------------------------------------
Count indv cuml rcnt nsec Lock Caller
21 42% 42% 0.00 593 vm object vm_map_madvise+0x254
nsec ------ Time Distribution ------ count Stack
1024 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 20 sys_madvise+0x85
2048 |@ 1 amd64_syscall+0x4ce
0xffffffff80f8442b
-------------------------------------------------------------------------------
Count indv cuml rcnt nsec Lock Caller
7 14% 56% 0.00 7349 Per-Filesystem Softdep Lock softdep_flush+0x17f
nsec ------ Time Distribution ------ count Stack
8192 |@@@@@@@@@@@@@@@@@@@@@@@@@ 6 fork_exit+0x85
16384 |@@@@ 1 0xffffffff80f8467e
-------------------------------------------------------------------------------
Count indv cuml rcnt nsec Lock Caller
7 14% 70% 0.00 1270 Per-Filesystem Softdep Lock _sleep+0x1d8
nsec ------ Time Distribution ------ count Stack
2048 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 7 softdep_flush+0x254
fork_exit+0x85
0xffffffff80f8467e
-------------------------------------------------------------------------------
Count indv cuml rcnt nsec Lock Caller
7 14% 84% 0.00 2140 Per-Filesystem Softdep Lock fork_exit+0x85
nsec ------ Time Distribution ------ count Stack
2048 |@@@@@@@@ 2 0xffffffff80f8467e
4096 |@@@@@@@@@@@@@@@@@@@@@ 5
-------------------------------------------------------------------------------
Count indv cuml rcnt nsec Lock Caller
5 10% 94% 0.00 4303 pmap pv list vm_pageout+0x19b9
nsec ------ Time Distribution ------ count Stack
4096 |@@@@@@ 1 fork_exit+0x85
8192 |@@@@@@@@@@@@@@@@@@@@@@@@ 4 0xffffffff80f8467e
-------------------------------------------------------------------------------
Count indv cuml rcnt nsec Lock Caller
1 2% 96% 0.00 1328 vm object vm_map_insert+0x437
nsec ------ Time Distribution ------ count Stack
2048 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1 vm_map_find+0x1a0
vm_mmap_object+0x4ef
sys_mmap+0x449
amd64_syscall+0x4ce
0xffffffff80f8442b
-------------------------------------------------------------------------------
Count indv cuml rcnt nsec Lock Caller
1 2% 98% 0.00 3250 vm object vm_fault_hold+0x2212
nsec ------ Time Distribution ------ count Stack
4096 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1 vm_fault+0x78
trap_pfault+0xf9
trap+0x316
0xffffffff80f84141
-------------------------------------------------------------------------------
Count indv cuml rcnt nsec Lock Caller
1 2% 100% 0.00 794 pmap pv list vm_fault_hold+0x1fe1
nsec ------ Time Distribution ------ count Stack
1024 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1 vm_fault+0x78
trap_pfault+0xf9
trap+0x316
0xffffffff80f84141
-------------------------------------------------------------------------------
R/W reader hold: 5 events in 5.014 seconds (1 events/sec)
-------------------------------------------------------------------------------
Count indv cuml rcnt nsec Lock Caller
3 60% 60% 0.00 9320 vm object vm_fault+0x78
nsec ------ Time Distribution ------ count Stack
8192 |@@@@@@@@@@ 1 trap_pfault+0xf9
16384 |@@@@@@@@@@@@@@@@@@@@ 2 trap+0x316
0xffffffff80f84141
-------------------------------------------------------------------------------
Count indv cuml rcnt nsec Lock Caller
1 20% 80% 0.00 1970 udp udp_input+0x6b9
nsec ------ Time Distribution ------ count Stack
2048 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1 ip_input+0x15f
netisr_dispatch_src+0xa5
ether_demux+0x12a
ether_nh_input+0x322
netisr_dispatch_src+0xa5
ether_input+0x26
vmxnet3_rxq_eof+0x708
vmxnet3_legacy_intr+0x110
intr_event_execute_handlers+0x20f
ithread_loop+0xc6
fork_exit+0x85
0xffffffff80f8467e
-------------------------------------------------------------------------------
Count indv cuml rcnt nsec Lock Caller
1 20% 100% 0.00 2754 if_addr_lock ip_input+0x59d
nsec ------ Time Distribution ------ count Stack
4096 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1 netisr_dispatch_src+0xa5
ether_demux+0x12a
ether_nh_input+0x322
netisr_dispatch_src+0xa5
ether_input+0x26
vmxnet3_rxq_eof+0x708
vmxnet3_legacy_intr+0x110
intr_event_execute_handlers+0x20f
ithread_loop+0xc6
fork_exit+0x85
0xffffffff80f8467e
-------------------------------------------------------------------------------
SX shared hold: 5 events in 5.014 seconds (1 events/sec)
-------------------------------------------------------------------------------
Count indv cuml rcnt nsec Lock Caller
2 40% 40% 0.00 34230 dtrace_lock dtrace_ioctl+0x1d72
nsec ------ Time Distribution ------ count Stack
32768 |@@@@@@@@@@@@@@@ 1 devfs_ioctl_f+0x13f
65536 |@@@@@@@@@@@@@@@ 1 kern_ioctl+0x2d4
sys_ioctl+0x171
amd64_syscall+0x4ce
0xffffffff80f8442b
-------------------------------------------------------------------------------
Count indv cuml rcnt nsec Lock Caller
2 40% 80% 0.00 1327 dtrace_lock dtrace_ioctl+0xf24
nsec ------ Time Distribution ------ count Stack
1024 |@@@@@@@@@@@@@@@ 1 devfs_ioctl_f+0x13f
2048 |@@@@@@@@@@@@@@@ 1 kern_ioctl+0x2d4
sys_ioctl+0x171
amd64_syscall+0x4ce
0xffffffff80f8442b
-------------------------------------------------------------------------------
Count indv cuml rcnt nsec Lock Caller
1 20% 100% 0.00 16030 vm map (user) vm_map_find+0x1f7
nsec ------ Time Distribution ------ count Stack
16384 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1 vm_mmap_object+0x4ef
sys_mmap+0x449
amd64_syscall+0x4ce
0xffffffff80f8442b
-------------------------------------------------------------------------------
SX exclusive hold: 43 events in 5.014 seconds (9 events/sec)
-------------------------------------------------------------------------------
Count indv cuml rcnt nsec Lock Caller
30 70% 70% 0.00 14593 filedesc structure sys_poll+0x61
nsec ------ Time Distribution ------ count Stack
8192 |@@@@ 4 amd64_syscall+0x4ce
16384 |@@@@@@@@@@@@@@ 14 0xffffffff80f8442b
32768 |@@@@@@@@@@@@ 12
-------------------------------------------------------------------------------
Count indv cuml rcnt nsec Lock Caller
4 9% 79% 0.00 785 vm map (user) useracc+0x76
nsec ------ Time Distribution ------ count Stack
1024 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 4 userland_sysctl+0x8c
sys___sysctl+0x74
amd64_syscall+0x4ce
0xffffffff80f8442b
-------------------------------------------------------------------------------
Count indv cuml rcnt nsec Lock Caller
4 9% 88% 0.00 2157 filedesc structure sys_ioctl+0x171
nsec ------ Time Distribution ------ count Stack
1024 |@@@@@@@ 1 amd64_syscall+0x4ce
2048 | 0 0xffffffff80f8442b
4096 |@@@@@@@@@@@@@@@@@@@@@@ 3
-------------------------------------------------------------------------------
Count indv cuml rcnt nsec Lock Caller
3 7% 95% 0.00 25791 vm map (user) unlock_and_deallocate+0x289
nsec ------ Time Distribution ------ count Stack
32768 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 3 vm_fault_hold+0x2212
vm_fault+0x78
trap_pfault+0xf9
trap+0x316
0xffffffff80f84141
-------------------------------------------------------------------------------
Count indv cuml rcnt nsec Lock Caller
2 5% 100% 0.00 889 vm map (user) useracc+0x76
nsec ------ Time Distribution ------ count Stack
1024 |@@@@@@@@@@@@@@@ 1 userland_sysctl+0xba
2048 |@@@@@@@@@@@@@@@ 1 sys___sysctl+0x74
amd64_syscall+0x4ce
0xffffffff80f8442b
-------------------------------------------------------------------------------
%
こんな感じでコマンドを指定するだけでロック情報を詳しく取得することができます。DTraceの機能が統合されさまざまなポイントに観測点を設けることができるようになったおかげで、
開発者であればこれは垂涎モノの機能なわけですが、
勉強会
第59回 12月21日（水）19:00～FreeBSD勉強会会 (日程変更の可能性あり)
ストレージシステムの基盤として使われることの多いZFS。いったん運用を開始あるとあとはボリュームの管理や、
参加申請はこちらから。