DTrace Introduction

DTrace is Solaris 10's new Dynamic Tracing facility. It allows us to peer into the innards of running processes and customize our view to exclude extraneous information and close in on the source of a problem.

DTrace also has capabilities that allow us to examine a crash dump or trace the boot process.

A number of freely available scripts have been made available as the DTrace Toolkit. The toolkit provides both programming examples and also extremely useful tools for different types of system monitoring.

The DTrace facility provides data to a number of consumers, including commands such as dtrace and lockstat, as well as programs calling libraries that access DTrace through the dtrace kernel driver.

DTrace is built on a foundation of objects called probes. Probes are event handlers that fire when their particular event occurs. DTrace can bind a particular action to the probe to make use of the information.

Probes report on a variety of information about their event. For example, a probe for a kernel function may report on arguments, global variables, timestamps, stack traces, currently running processes or the thread that called the function.

Kernel modules that enable probes are packaged into sets known as providers. In a DTrace context, a module is a kernel module (for kernel probes) or a library name (for applications). A function in DTrace refers to the function associated with a probe, if it belongs to a program location.

Probes may be uniquely addressed by a combination of the provider, module, function and name. These are frequently organized into a 4-tuple when invoked by the dtrace command.

Alternatively, each probe has a unique integer identifier, which can vary depending on Solaris patch level.

These numbers, as well as the provider, module, function and name, can be listed out through the dtrace -l command. The list will vary from system to system, depending on what is installed. Probes can be listed by function, module or name by specifying it with the -f, -m or -n options, respectively.

Running a dtrace without a -l, but with a -f, -m or -n option, enables all matching probes. All the probes in a provider can be enabled by using the -P option. An individual probe can be enabled by using its 4-tuple with the -n option.

(Note: Do not enable more probes than necessary. If too many probes are enabled, it may adversely impact performance. This is particularly true of sched probes.)

Some probes do not list a module or function. These are called "unanchored" probes. Their 4-tuple just omits the nonexistent information.

Providers are kernel modules that create related groups of probes. The most commonly referenced providers are:

• fbt: (Function Boundary Tracing) Implements probes at the entry and return points of almost all kernel functions.
• io: Implements probes for I/O-related events.
• pid: Implements probes for user-level processes at entry, return and instruction.
• proc: Implements probes for process creation and life-cycle events.
• profile: Implements timer-driven probes.
• sched: Implements probes for scheduling-related events.
• sdt: (Statistically Defined Tracing) Implements programmer-defined probes at arbitrary locations and names within code. Obviously, the programmer should define names whose meaning is intuitively clear.
• syscall: Implements entry and return probes for all system calls.
• sysinfo: Probes for updates to the sys kstat.
• vminfo: Probes for updates to the vm kstat.

The dtrace command has several components:

• A 4-tuple identifier:
  provider:module :function:name
  Leaving any of these blank is equivalent to using a wildcard match. (If left blank, the left-most members of the 4-tuple are optional.)
• A predicate determines whether the action should be taken. They are enclosed in slashes: /predicate/. The predicate is a C-style relational expression which must evaluate to an integer or pointer. If omitted, the action is executed when the probe fires. Some predicate examples are:
  • executable name matches csh:
    /execname == "csh"/
  • process ID does not match 1234:
    /pid != 1234/
  • arg0 is 1 and arg1 is not 0:
    /arg0 == 1 && arg1 !=0/
• An action (in the D scripting language) to be taken when the probe fires and the predicate is satisfied. Typically, this is listed in curly brackets: {}

Several command examples are provided at the bottom of the page.

In order to deal with operations that can become confusing on a single command line, a D script can be saved to a file and run as desired. A D script will have one or more probe clauses, which consist of one or more probe-descriptions, along with the associated predicates and actions:

#!/usr/sbin/dtrace -s
probe-description[, probe-description...]
/predicate/
{
action; [action; ...]
}

The probe-description section consists of one or more 4-tuple identifiers. If the predicate line is not present, it is the same as a predicate that is always true. The action(s) specified are to be run if the probe fires and the predicate is true.

Each recording action dumps data to a trace buffer. By default, this is the principal buffer.

Several programming examples are provided at the bottom of the page.

D specifies both associative arrays and scalar variables. Storage for these variables is not pre-allocated. It is allocated when a non-zero value is assigned and deallocated when a zero value is assigned.

D defines several built-in variables, which are frequently used in creating predicates and actions. The most commonly used built-in variables for D are the following:

• args[]: The args[] array contains the arguments, specified from 0 to the number of arguments less one. These can also be specified by argn, where this is the n+1th argument.
• curpsinfo: psinfo structure of current process.
• curthread: pointer to the current thread's kthread_t
• execname: Current executable name
• pid: Current process ID
• ppid: Parent process ID
• probefunc: function name of the current probe
• probemod: module name of the current probe
• probename: name of the current probe
• timestamp: Time since boot in ns

Variable scope can be global, thread-local or clause-local.

Thread-local variables allow separate storage for each thread's copy of that variable. They are referenced with names of the form:
self->variable-name

Associative arrays can be indexed by an arbitrary name. There is no pre-defined limit on the number of elements.

Scalar variables hold a single data value.

We can also access Solaris kernel symbols by specifying them in backquotes.

Providers define arguments based on their own requirements. Some of the more useful such arguments are listed below:

The most commonly used built-in actions are:

• breakpoint(): System stops and transfers control to kernel debugger.
• chill(number-nanoseconds): DTrace spins for the specified number of nanoseconds.
• copyinstr(pointer): Returns null terminated string from address space referenced by pointer.
• copyout(buffer, address, number-bytes): Copies number-bytes from the buffer to a memory address.
• copyoutstr(string, address, max-length): Copies a string to a memory address.
• normalize(aggregation, normalization-factor): Divides aggregation values by the normalization-factor.
• panic(): Panics the kernel; may be used to generate a core dump.
• printf(format, arguments): Dumps the arguments to the buffer in the specified format. printa(aggregation) does the same thing for aggregation data.
• raise(signal): Sends the signal to the current process.
• stack(number-frames): Copies the specified number of frames of the kernel thread's stack to the buffer.
• stop(): Stops the process that fired the probe.
• stringof(): Converts values to DTrace string values.
• system(command): Runs a program as if from the shell.
• trace(D-expression): Dumps the output of D-expression to the trace buffer.
• tracemem(address, size_t number-bytes): Dumps the contents from the memory address to the buffer.
• trunc(aggregation): Truncates or removes the contents of the specified aggregation.
• ustack(number-frames): Copies the specified number of frames of the user stack to the buffer.

Multiple actions in a probe clause can be combined using a semicolon between them inside the curly brackets.

Aggregating functions allow multiple data points to be combined and reported. Aggregations take the form:
@name[ keys ] = aggregating-function( arguments );
Here, the name is a name assigned to the aggregation, the keys are a comma-separated list of D expressions which index the output, the arguments are a comma-separated list and the aggregating functions may be one of the following:

• avg: Average of the expressions in the arguments.
• count: Number of times that the function is called.
• lquantize: The arguments are a scalar expression, a lower bound, an upper bound and a step value. This function increments the value in the highest linearly-sized bucket that is less than the expression.
• max: The largest value among the arguments.
• min: The smallest value among the arguments.
• quantize: Increments the value in the highest power of two bucket less than the expression in the argument.
• sum: Total value of the expressions in the arguments.

Directives provide options to a D script that can increase readability of the output. Each option is enabled by including a line like the following at the beginning of a D script:
#pragma D option option-name

The following are the most commonly-used directives.

• flowindent: Indentation increased on function entry; decreased on function return.
• quiet: Don't print anything not explicitly specified.

To report on each active PID for the readch function:
dtrace -n 'readch {trace(pid)}'

To report on each system call's entry time:
dtrace -n 'syscall:::entry {trace(timestamp)}'

Tracing executable names (stored on a UFS filesystem):
dtrace -m 'ufs {trace(execname)}'

To print all functions from libc for process 123:
dtrace -n 'pid123:libc::entry'

To count the occurrences of each libc function for PID 123:

#!/usr/sbin/dtrace -s
pid123:libc::entry
{
@function_count[probefunc]=count();
}

To identify how much time is spent in each function, we would add a probe-clause as follows. In the below, the timestmp[] array stores the timestamps for each function as it is entered; the aggregation function_duration[] stores the sum total of durations for invocations of each function. Also note that the scope of the timestmp[] array is limited to a single thread to deal with the possibility of multiple concurrent copies of the same function:

#!/usr/sbin/dtrace -s
pid123:libc::entry
{
self->timestmp[probefunc] = timestmp;
}
pid123:libc::return
/self->timestmp[probefunc] != 0/
{
@function_duration[probefunc] = sum(timestmp - self->timestmp[probefunc]);
timestmp[probefunc] = 0;
}

The following script prints out the name of every program that calls the exec or exece system calls, as well as the name of the program being executed:

#!/usr/sbin/dtrace -s
syscall::exec*:entry
{
trace(execname);
trace(copyinstr(arg0));
}

#!/usr/sbin/dtrace -s
#pragma D option quiet
syscall::exec*:entry
{
self->prog = copyinstr(arg0);
self->exn = execname;
}
syscall::exec*:return
/ self->prog != NULL /
{
printf ("%-20s %s\n", self->exn, self->prog);
self->prog = 0;
self->exn = 0;
}

A number of freely available scripts have been made available as the DTrace Toolkit. The toolkit provides both programming examples and also extremely useful tools for different types of system monitoring.

• Bennett, Chip. Learning DTrace-Parts 1-5. SysAdmin Magazine, Sep 2006-Jan 2007. Also at Laurus.
• Gregg, Brendan. DTrace Tools web page.
• McDougall, Richard; Mauro, Jim; Gregg, Brendan. Solaris Performance and Tools. October, 2006. Prentice Hall.
• DTrace User Guide. May, 2006. Sun Microsystems.
• Solaris Dynamic Tracing Guide. 2005. Sun Microsystems.
• Using DTrace from a Solaris 10 System. Sun Microsystems.

Solaris Troubleshooting Main Page