Unix Administration: Learn D, the DTrace Scripting Language

Sun's DTrace provides powerful system visibility tools for Solaris, Mac OS X and BSD users, but the scripts that come out of the box only scratch the surface. Mastering D, the DTrace scripting language, unlocks its full potential.

By Charlie Schluting | Posted Apr 30, 2008
Print ArticleEmail Article
  • Share on Facebook
  • Share on Twitter
  • Share on LinkedIn

Charlie Schluting To get the most out of DTrace, you’ll need to dive into the D scripting language a bit. The ability to ask an arbitrary question of a system—DTrace’s claim to fame—is fully realized when you venture outside of others’ pre-programmed scripts. To add to last week’s DTrace introduction, we’ll now cover how the D language works.

Last week we showed two simple command-line examples using 'dtrace –n.' In reality, D is a structured programming language (very very similar to Awk). The basic structure of a D program is:

probe description
/predicate/
{
    actions
}

The probe description lists which probes to enable when the script is run, and the 'actions' portion will be run if the predicate is true. We'll get back to predicates shortly, but first let us understand how probes are defined.

A probe has four parts: modifier, module, function, name. An example probe from last week's demonstration is: "syscall:::entry.” We left out the module and function specifications, which acts as wildcards. The provider used was "syscall," which means we want to monitor system calls. The name of  "entry" meant that we were interested in the entry point of the system call (exactly when it was called). The module and function fields specify which DTrace module you want to use, and which function you're interested in, respectively.

Take a look at an example using the function field:

syscall::open*:entry
/execname == "zsh"/
{             
  printf("It happened!");
}

If I save that to a file, called zsh.d, I can run it with 'dtrace –s:'

dtrace: script 'scripts/zsh.d' matched 2 probes
CPU     ID                    FUNCTION:NAME
  0   3468                     open64:entry It happened!
  0   3468                     open64:entry It happened!

To get a zsh process to open two files, I ran 'who' in a different shell.

Also notice that I used a predicate of "execname," which is the DTrace lingo for a process name. An action was used as well, in this case a simple printf() call.
Well that's neat, but what file was opened? Let's try accessing argument 0 of the call, as it should have the file name:

syscall::open*:entry
/execname == "zsh"/
{
    printf("opened %s", copyinstr(arg0));
}

The copyinstr() function is required because probes (and the predicates and actions you define) are run in the kernel. All user-space data must be copied into the kernel before DTrace can use it. The copyinstr() function simply copies in the data and converts it to a DTrace string type.

When run, I see exactly which two files were opened when I ran "who:"

dtrace: script 'scripts/zsh.d' matched 2 probes
CPU     ID                    FUNCTION:NAME
  0   3468                     open64:entry opened /u/manos/.history.11906
  0   3468                     open64:entry opened /u/manos/.history

We also need to know about aggregate functions, because the tremendous power of DTrace is best leveraged using count and timing features. Aggregate functions can be used if you create a table to store your data. This looks like: 'syscall:::entry {@[probefunc]=count(); }' (you can run that with dtrace –n on the command line). The @ symbol begins a table, optionally taking a name: @tablename. Next, you must specify what indexes to record by adding [list of indexes]. Finally, =aggregate_function_name() will tell DTrace to use the aggregate function you specify.

So, the unnamed table, using the built-in D variable probefunc (same as execname), will store data using the count aggregator until you hit ^c to stop it. Then, and only then, will you get a summarization.

What if we want to know how much time is being spent in each function? Let's see how my trusty shell is faring with the following script:

pid$1:::entry
{
   ts[execname] = timestamp;
}

pid$1:::return
{
   @func_time[execname] = sum(timestamp - ts[execname]);
   ts[execname] = 0;
}

This script, which contains two probes, should cause DTrace to fire the actions upon any function entry, and upon any return. Notice also that we used pid$1 as the modifier. Every pid can be addressed by saying pid###, and $1 of course means the first command-line argument to the script.

The built-in variable 'ts' (for timestamp) records the timestamp at entry, and then subtracts it from the current timestamp when the function returns (and of course stores it in a table named func_time). This works, because every function call with the same name gets one entry in the table, indexed by its name. Each time the sum aggregator is called with an integer argument, it simply adds the current time to the existing value in the table.

When I run the above script with the pid of another shell, I should see some timings of function calls:

dtrace: script 'scripts/exec.d' matched 13792 probes
  malloc                                                     44685507
  fstat64                                                    58004498
  fork                                                     2059790081
  zleread                                              19476899167009
  gettok                                               19476900278173

Clearly my shell (zsh) spends a lot more time in zleread and gettok than it takes a malloc call to return. Good, that's how it should be. If I run this same script on a busy NFS server's nfsd process, I can see what functions are eating the most time:

  poll                                           6562536956861900

Indeed, it is doing tons of I/O, so it's heavily using the poll() system call.

That's really all there is to DTrace. You should be able to understand the scripts in the DTrace ToolKit now that the basics are no longer foreign. They get complex because often times they're parsing command-line arguments for display options, but once you drill down to the meat of the script, they are generally simple. For example, execsnoop, which prints every time something is executed, is essentially this:

proc:::exec-success
{
       printf("%s(pid=%d) started by uid: %dn",execname, pid, uid);
}

Hopefully this has been a gentle, yet enlightening introduction to DTrace's scripting language. D is quite simple if you're familiar with Awk, but it soon becomes clear that the stumbling block is not the language itself, but rather knowing what questions to ask. That, fortunately, requires that you really understand your system. For Solaris users, I'd highly recommend the Solaris Internals books.

Comment and Contribute
(Maximum characters: 1200). You have
characters left.
Get the Latest Scoop with Enterprise Networking Planet Newsletter