xref: /netbsd-src/external/cddl/dtracetoolkit/dist/Examples/hotkernel_example.txt (revision c29d51755812ace2e87aeefdb06cb2b4dac7087a)
1*c29d5175SchristosThe following are demonstrations of the hotkernel DTrace program.
2*c29d5175Schristos
3*c29d5175Schristos
4*c29d5175SchristosHere hotkernel is run for a couple of seconds then Ctrl-C is hit,
5*c29d5175Schristos
6*c29d5175Schristos   # ./hotkernel
7*c29d5175Schristos   Sampling... Hit Ctrl-C to end.
8*c29d5175Schristos   ^C
9*c29d5175Schristos   FUNCTION                                                COUNT   PCNT
10*c29d5175Schristos   unix`swtch                                                  1   0.1%
11*c29d5175Schristos   pcplusmp`apic_redistribute_compute                          1   0.1%
12*c29d5175Schristos   genunix`strrput                                             1   0.1%
13*c29d5175Schristos   unix`sys_call                                               1   0.1%
14*c29d5175Schristos   genunix`fsflush_do_pages                                    1   0.1%
15*c29d5175Schristos   TS`ts_wakeup                                                1   0.1%
16*c29d5175Schristos   genunix`callout_schedule_1                                  1   0.1%
17*c29d5175Schristos   unix`page_create_putback                                    1   0.1%
18*c29d5175Schristos   unix`mutex_enter                                            4   0.3%
19*c29d5175Schristos   unix`cpu_halt                                            1575  99.2%
20*c29d5175Schristos
21*c29d5175SchristosThe output summarises which kernel-level function was sampled on the
22*c29d5175SchristosCPU the most. This report shows that unix`cpu_halt was sampled 1575
23*c29d5175Schristostimes, which was 99.2% of the kernel-level samples.
24*c29d5175Schristos
25*c29d5175SchristosAs it turns out, unix`cpu_halt is called on this x86 server as part of the
26*c29d5175Schristoskernel idle thread - explaining why it is so often found on the CPU,
27*c29d5175Schristos
28*c29d5175Schristos   # dtrace -n 'fbt::cpu_halt:entry { @[stack()] = count(); }'
29*c29d5175Schristos   dtrace: description 'fbt::cpu_halt:entry ' matched 1 probe
30*c29d5175Schristos   ^C
31*c29d5175Schristos
32*c29d5175Schristos                 unix`idle+0x3b
33*c29d5175Schristos                 unix`thread_start+0x3
34*c29d5175Schristos                 956
35*c29d5175Schristos
36*c29d5175SchristosThis kernel stack trace indicates that cpu_halt() is called by idle().
37*c29d5175Schristos
38*c29d5175SchristosThe following is a SPARC example,
39*c29d5175Schristos
40*c29d5175Schristos   # ./hotkernel
41*c29d5175Schristos   Sampling... Hit Ctrl-C to end.
42*c29d5175Schristos   ^C
43*c29d5175Schristos   FUNCTION                                                COUNT   PCNT
44*c29d5175Schristos   genunix`fop_ioctl                                           1   0.1%
45*c29d5175Schristos   genunix`allocb_cred                                         1   0.1%
46*c29d5175Schristos   genunix`poll_common                                         1   0.1%
47*c29d5175Schristos   genunix`cv_block                                            1   0.1%
48*c29d5175Schristos   genunix`strioctl                                            1   0.1%
49*c29d5175Schristos   genunix`disp_lock_exit                                      1   0.1%
50*c29d5175Schristos   genunix`crfree                                              1   0.1%
51*c29d5175Schristos   ufs`ufs_getpage                                             1   0.1%
52*c29d5175Schristos   SUNW,UltraSPARC-IIi`copyin                                  1   0.1%
53*c29d5175Schristos   genunix`strmakedata                                         1   0.1%
54*c29d5175Schristos   genunix`cv_waituntil_sig                                    1   0.1%
55*c29d5175Schristos   SUNW,UltraSPARC-IIi`prefetch_page_r                         1   0.1%
56*c29d5175Schristos   unix`set_freemem                                            1   0.1%
57*c29d5175Schristos   unix`page_trylock                                           1   0.1%
58*c29d5175Schristos   genunix`anon_get_ptr                                        1   0.1%
59*c29d5175Schristos   unix`page_hashin                                            1   0.1%
60*c29d5175Schristos   genunix`bt_getlowbit                                        1   0.1%
61*c29d5175Schristos   unix`pp_load_tlb                                            1   0.1%
62*c29d5175Schristos   unix`_resume_from_idle                                      1   0.1%
63*c29d5175Schristos   unix`hat_pageunload                                         1   0.1%
64*c29d5175Schristos   genunix`strrput                                             1   0.1%
65*c29d5175Schristos   genunix`strpoll                                             1   0.1%
66*c29d5175Schristos   unix`page_do_hashin                                         1   0.1%
67*c29d5175Schristos   unix`cpu_vm_stats_ks_update                                 1   0.1%
68*c29d5175Schristos   genunix`sleepq_wakeone_chan                                 1   0.1%
69*c29d5175Schristos   unix`lock_set_spl                                           1   0.1%
70*c29d5175Schristos   tl`tl_wput                                                  1   0.1%
71*c29d5175Schristos   genunix`kstrgetmsg                                          1   0.1%
72*c29d5175Schristos   genunix`qbackenable                                         1   0.1%
73*c29d5175Schristos   genunix`releasef                                            1   0.1%
74*c29d5175Schristos   genunix`callout_execute                                     1   0.1%
75*c29d5175Schristos   uata`ata_hba_start                                          1   0.1%
76*c29d5175Schristos   genunix`pcacheset_cmp                                       1   0.1%
77*c29d5175Schristos   genunix`sleepq_insert                                       1   0.1%
78*c29d5175Schristos   genunix`syscall_mstate                                      1   0.1%
79*c29d5175Schristos   sockfs`sotpi_recvmsg                                        1   0.1%
80*c29d5175Schristos   genunix`strput                                              1   0.1%
81*c29d5175Schristos   genunix`timespectohz                                        1   0.1%
82*c29d5175Schristos   unix`lock_clear_splx                                        1   0.1%
83*c29d5175Schristos   genunix`read                                                1   0.1%
84*c29d5175Schristos   genunix`as_segcompar                                        1   0.1%
85*c29d5175Schristos   unix`atomic_cas_64                                          1   0.1%
86*c29d5175Schristos   unix`mutex_exit                                             1   0.1%
87*c29d5175Schristos   genunix`cv_unsleep                                          1   0.1%
88*c29d5175Schristos   unix`putnext                                                1   0.1%
89*c29d5175Schristos   unix`intr_thread                                            1   0.1%
90*c29d5175Schristos   genunix`hrt2tv                                              1   0.1%
91*c29d5175Schristos   sockfs`socktpi_poll                                         1   0.1%
92*c29d5175Schristos   unix`sfmmu_mlspl_enter                                      1   0.1%
93*c29d5175Schristos   SUNW,UltraSPARC-IIi`get_ecache_tag                          1   0.1%
94*c29d5175Schristos   SUNW,UltraSPARC-IIi`gethrestime                             1   0.1%
95*c29d5175Schristos   genunix`cv_timedwait_sig                                    1   0.1%
96*c29d5175Schristos   genunix`getq_noenab                                         1   0.1%
97*c29d5175Schristos   SUNW,UltraSPARC-IIi`flushecacheline                         1   0.1%
98*c29d5175Schristos   unix`utl0                                                   1   0.1%
99*c29d5175Schristos   genunix`anon_alloc                                          1   0.1%
100*c29d5175Schristos   unix`page_downgrade                                         1   0.1%
101*c29d5175Schristos   unix`setfrontdq                                             1   0.1%
102*c29d5175Schristos   genunix`timeout_common                                      1   0.1%
103*c29d5175Schristos   unix`bzero                                                  1   0.1%
104*c29d5175Schristos   unix`ktl0                                                   2   0.1%
105*c29d5175Schristos   genunix`canputnext                                          2   0.1%
106*c29d5175Schristos   genunix`clear_active_fd                                     2   0.1%
107*c29d5175Schristos   unix`sfmmu_tlb_demap                                        2   0.1%
108*c29d5175Schristos   unix`page_vpadd                                             2   0.1%
109*c29d5175Schristos   SUNW,UltraSPARC-IIi`check_ecache_line                       2   0.1%
110*c29d5175Schristos   genunix`cyclic_softint                                      2   0.1%
111*c29d5175Schristos   genunix`restore_mstate                                      2   0.1%
112*c29d5175Schristos   genunix`anon_map_getpages                                   2   0.1%
113*c29d5175Schristos   genunix`putq                                                2   0.1%
114*c29d5175Schristos   unix`page_lookup_create                                     2   0.1%
115*c29d5175Schristos   dtrace`dtrace_dynvar_clean                                  2   0.1%
116*c29d5175Schristos   unix`sfmmu_pageunload                                       2   0.1%
117*c29d5175Schristos   genunix`cpu_decay                                           2   0.1%
118*c29d5175Schristos   genunix`kmem_cache_alloc                                    3   0.2%
119*c29d5175Schristos   unix`rw_exit                                                3   0.2%
120*c29d5175Schristos   tl`tl_wput_data_ser                                         3   0.2%
121*c29d5175Schristos   unix`page_get_replacement_page                              3   0.2%
122*c29d5175Schristos   unix`page_sub                                               3   0.2%
123*c29d5175Schristos   genunix`clock                                               3   0.2%
124*c29d5175Schristos   SUNW,UltraSPARC-IIi`copyout                                 3   0.2%
125*c29d5175Schristos   unix`mutex_enter                                            4   0.2%
126*c29d5175Schristos   genunix`pcache_poll                                         5   0.3%
127*c29d5175Schristos   SUNW,UltraSPARC-IIi`scrub_ecache_line                       5   0.3%
128*c29d5175Schristos   SUNW,UltraSPARC-IIi`hwblkpagecopy                          22   1.2%
129*c29d5175Schristos   SUNW,UltraSPARC-IIi`hwblkclr                               39   2.1%
130*c29d5175Schristos   unix`generic_idle_cpu                                     506  26.8%
131*c29d5175Schristos   unix`idle                                                1199  63.5%
132*c29d5175Schristos
133*c29d5175SchristosWhich shows the most common function is unix`idle.
134*c29d5175Schristos
135*c29d5175Schristos
136*c29d5175Schristos
137*c29d5175Schristos
138*c29d5175SchristosNow the hotkernel tool is demonstrated with the -m option, to only print
139*c29d5175Schristosout samples by module,
140*c29d5175Schristos
141*c29d5175Schristos   # ./hotkernel -m
142*c29d5175Schristos   Sampling... Hit Ctrl-C to end.
143*c29d5175Schristos   ^C
144*c29d5175Schristos   MODULE                                                  COUNT   PCNT
145*c29d5175Schristos   usbms                                                       1   0.0%
146*c29d5175Schristos   specfs                                                      1   0.0%
147*c29d5175Schristos   uhci                                                        1   0.0%
148*c29d5175Schristos   sockfs                                                      2   0.0%
149*c29d5175Schristos   genunix                                                    28   0.6%
150*c29d5175Schristos   unix                                                     4539  99.3%
151*c29d5175Schristos
152*c29d5175SchristosHere, genunix and unix (the two core parts of the kernel) were the most
153*c29d5175Schristoscommon module to be executing on-CPU.
154