Skip to content

Instantly share code, notes, and snippets.

@bijanebrahimi
Created February 20, 2017 14:03
Show Gist options
  • Star 2 You must be signed in to star a gist
  • Fork 1 You must be signed in to fork a gist
  • Save bijanebrahimi/4bd747332896e2eb59964e205122dc4b to your computer and use it in GitHub Desktop.
Save bijanebrahimi/4bd747332896e2eb59964e205122dc4b to your computer and use it in GitHub Desktop.
A guide to dtrace in FreeBSD

An introduction

what's dtrace?

DTrace dynamic tracing compiler and tracing utility DTrace is a comprehensive dynamic tracing framework for the Solaris Operating System. DTrace provides a powerful infrastructure that permits administrators, developers, and service personnel to concisely answer arbitrary questions about the behavior of the operating system and user programs.

How to enable dtrace?

you need have compiled your freebsd kernel with the following options:

makeoptions     DEBUG=-g
makeoptions     WITH_CTF=1
options         KDTRACE_FRAME
options         KDTRACE_HOOKS

To compile a new kernel with the following options, create a new config file for dtrace:

cd /usr/src
cp sys/amd64/conf/GENERIC sys/amd64/conf/DTRACE

add the above options, compile and install the new kernel.

make -j 4 buildkernel KERNCONF=DTRACE
make installkernel
reboot

After reboot, you should first load dtrace kernel module:

kldload dtraceall

dtrace

by loading the dtrace kernel module (described above), dtrace should be working. to check that, run the following command:

dtrace -l

There are five available columns in each probe as follow:

  • id
  • provider
  • module
  • function
  • name

dtrace command syntax

dtrace -P 'provider [predicate] [action]'
dtrace -m '[provider]:module [predicate] [action]'
dtrace -f '[provider]:[module]:function [predicate] [action]'
dtrace -n '[provider]:[module]:[function]:name [predicate] [action]'
  • providers:
  • fbt: (funtion boundary tracing) Implements probes for entry and return points of almost all kernel functions
  • io: Implements probes for I/O relared events
  • pid: Implements probes for user-level processes
  • proc: Implements probes for process creation
  • profile: Implements timer-driver probes
  • sched: Implements probes for scheduling-related events
  • sdt: (Statistically Defined Tracing)
  • syscall: Implements entry and return probes for all system calls
  • sysinfo: Probes for updates to the sys
  • vminfo: Probes for updates to the vm
  • module
  • function
  • name
  • predicate: determines whether an action should be taken.
  • syntaxt: /predicate/
  • Examples:
    /execname == "csh"/
    /pid != 1234/
    
  • Action: The action (in D scripting language) which should be taken when a probe is fired.
  • copyinstr(pointer): copy the string the pointer points at
  • panic: create a kernel panic useful for creating kernel core dump
  • raise(signal): sending specific signal to current process
  • stack(frame-numbers): copy maximum number of stack to buffer
  • unstask()
  • stop()
  • printf(format, ...)
  • Aggregation: Aggregating functions allow multiple data points to be combined and reported. syntax:
@name[keys] = aggregation-function(arguments)
  • avg()
  • min()
  • max()
  • sum()
  • count()
  • quantize()
  • lquantize()
  • Builtins: accessible variables within actions.
  • args[<N>]: typed arguments passed to function
  • arg<N>: unsiged int arguments passed to function
  • curpsinfo: psinfo object in the the current thread
  • curthread: current kthread_t object in the current thread
  • execname: current executable name
  • pid
  • ppid
  • probmod: module name of the probe
  • probefunc: function name of the probe
  • probename: probe name of the probe
  • timestamp: the timestamp since boot
  • vtimestamp: the time current thread spent in CPU
  • self: an pointer to thread object

Examples

  • List all system calls to read*:
$ dtrace -l | grep 'syscall.*read'
21543        fbt            kernel              syscall_thread_enter entry
21544        fbt            kernel              syscall_thread_enter return
25811        fbt            kernel               syscall_thread_exit entry
25812        fbt            kernel               syscall_thread_exit return
  • Print out filename of each open system calls:
$ dtrace -n 'syscall::open*:entry { printf("%s %s", execname, copyinstr(arg0)); }'
dtrace: description 'syscall::open*:entry ' matched 6 probes
dtrace: buffer size lowered to 2m
CPU     ID                    FUNCTION:NAME
  0  35306                       open:entry runAgent /usr/local/etc/zharfcore/zharf.conf
  0  35306                       open:entry runAgent /usr/local/etc/zharfcore/ifManager/ifManager.conf.tmp
  0  35306                       open:entry runAgent /usr/local/etc/zharfcore//runagent_lock/ifmanager.lck
  0  35306                       open:entry runAgent /usr/local/etc/zharfcore//tmpIfName.tmp
  0  35306                       open:entry wc /etc/libmap.conf
  • System calls count by process name:
$ dtrace -n 'syscall:::entry { @[execname, probefunc] = count(); }'
  • Timing read system call:
$ dtrace -n 'syscall::read:entry { self->ts = timestamp; } syscall::read:return /self->ts/ {
    @ = quantize(timestamp - self->ts); self->ts = 0; }'
  • Timing read system call in CPU:
dtrace -n 'syscall::read:entry { self->vts = vtimestamp; } syscall::read:return /self->vts/ {
    @["On-CPU us:"] = lquantize((vtimestamp - self->vts) / 1000, 0, 10000, 10); self->vts = 0; }'
  • Report each system call entry time:
$ dtrace -n 'syscall:::entry {trace(timestamp)}' | head
dtrace: description 'syscall:::entry ' matched 1048 probes
dtrace: buffer size lowered to 2m
CPU     ID                    FUNCTION:NAME
 14  35404                      ioctl:entry    20447341571863
 14  35404                      ioctl:entry    20447341921730
 14  35304                      write:entry    20447341934427
 14  35304                      write:entry    20447341941592
 14  35958                sigprocmask:entry    20447341949188
 14  36110                  sigaction:entry    20447341950939
 14  35958                sigprocmask:entry    20447341952901
 14  35958                sigprocmask:entry    20447341953806
 14  36110                  sigaction:entry    20447341954792
  • Prints files opened by read syscall:
dtrace -n 'syscall::read:return /execname=="ssh"/ { @quantize(arg0); }'
  • Displays all execnames fired by count:
dtrace -n 'syscall:::entry { @num[execname] = count(); }'

D scripting

#!/usr/sbin/dtrace -s
#pragma D option [flowindent|quiet]
probe-description [,probe-description [,...]]
{
 action; [action;[...]]
}

References

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment