cddl/contrib/dtracetoolkit/Examples/hotkernel_example.txt

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