DTrace Examples

This page contains a quick-start guide to DTrace and some useful examples of how to use DTrace to instrument your kernel for performance or functional analysis.

This script simply samples time spent in callout handlers and builds a histogram with the results so that you can quickly see if there are long-running callouts to investigate.

callout_execute:::callout_start
{
        self->cstart = timestamp;
}

callout_execute:::callout_end
{

        @length = quantize(timestamp - self->cstart);
}

Submitted by RobertWatson.

This script is loosely based on a similar one from OpenSolaris's sdt Provider page, but due to slight differences in types and probe naming, we can't use theirs verbatim:

callout_execute:::callout_start
{
        self->cstart = timestamp;
}

callout_execute:::callout_end
{

        @callouts[((struct callout *)arg0)->c_func] = sum(timestamp -
            self->cstart);
}

tick-1sec
{
        printa("%40a %10@d\n", @callouts);
        clear(@callouts);
        printf("\n");
}

Submitted by RobertWatson.

This script works by measuring the time at the start of a callout, then again on termination and billing that time incrementally to the callout function that ran. Once a second, we print the results and reset the counters.

The same as the previous script, but only include callouts that use Giant as their lock:

#pragma D option quiet
#pragma D option dynvarsize=64m

callout_execute:::callout_start
/(((struct callout *)arg0)->c_lock == &`Giant.lock_object)/
{
        self->start = timestamp;
}

callout_execute:::callout_end
/self->start/
{

        @callouts[((struct callout *)arg0)->c_func] = sum(timestamp -
            self->start);
        self->start = 0;
}

tick-10sec
{
        normalize(@callouts, 10);
        printa("%40a %10@d\n", @callouts);
        printf("\n");
        clear(@callouts);
}

BEGIN
{
        printf("%40s | %s\n", "function", "nanoseconds per second");
}

Submitted by RobertWatson

As before, except that only callouts using Giant are measured. Note the “`” before Giant in order to name a kernel global variable.

This script captures an array of counters, one for each stack trace leading to a non-zero return from priv_check_cred() using the fbt provider:

fbt::priv_check_cred:return
/arg1 != 0/
{
        @traces[stack()] = count();
}

Submitted by RobertWatson

Interestingly, fbt on my test box only appears to have an entry event for priv_check() and no return.