Viewing busy code paths with DTrace

Periodically I want to see the busiest application and system code paths on a system. Prior to Solaris 10, this was a difficult questions to answer without custom instrumentation. Now that we have DTrace, we can use the DTrace profile provider and an aggregation to view the busiest code paths in the kernel:

$ dtrace -n ‘profile-1001 {@[stack(20)]=count()} END{trunc(@,2)}’

dtrace: description 'profile-1001 ' matched 2 probes
^C
CPU     ID                    FUNCTION:NAME
  0      2                             :END 


              unix`atomic_cas_32+0x10
              ufs`ufs_scan_inodes+0xf4
              ufs`ufs_update+0x1e9
              ufs`ufs_sync+0x213
              genunix`fsop_sync_by_kind+0x36
              genunix`fsflush+0x3e2
              unix`thread_start+0x8
               11

              unix`cpu_halt+0x100
              unix`idle+0x3f
              unix`thread_start+0x8
             3978

To see the busiest userland code paths, we can aggregate on the executable and userland stack frames, but only when we are in user context (arg1 indicates which context we are in):

$ dtrace -n ‘profile-1001 /arg1/ {@[execname,ustack()]=count()} END{trunc(@,2)}’

dtrace: description 'profile-1001 ' matched 2 probes
^C
CPU     ID                    FUNCTION:NAME
  0      2                             :END 

  kcfd                                              
              libmd.so.1`SHA1Transform+0x2ef
              libmd.so.1`SHA1Update+0xb6
              libelfsign.so.1`soft_digest_update+0x48
              libelfsign.so.1`C_DigestUpdate+0xd7
              libelfsign.so.1`_C01A7C0D+0x2d
              libelfsign.so.1`elfsign_hash_common+0x175
              libelfsign.so.1`_C01A7A0C+0x16
              libelfsign.so.1`_C01A7A0D+0x23d
              kcfd`kcfd_process_request+0x17e
              libc.so.1`__door_return+0x60
               12
  sshd                                              
              libc.so.1`memcpy+0x6b
              libcrypto.so.0.9.8`HMAC_Init_ex+0x1b2
              libcrypto.so.0.9.8`HMAC_Init+0x3d
              sshd`mac_compute+0x34
              sshd`packet_send2+0x23c
              sshd`packet_send+0x1b
              sshd`channel_output_poll+0x1d2
              sshd`server_loop2+0xe6
              sshd`do_authenticated2+0xe
              sshd`do_authenticated+0x3b
              sshd`main+0x1081
              sshd`_start+0x7a
               52

This is huge, and with two lines of DTrace, you can dynamically view the busiest code paths in kernel and user context. Nice!

Leave a Reply

Your email address will not be published. Required fields are marked *