DTrace

Quite often it is more important for you to see the whole picture, rather than to know each case when a particular probe fires. For instance, observing a process which consumes a lot of CPU time according to prstat, we ask ourselves: what is this process doing? And often we think about the overall number of system calls executed by this process, and not every particular one of these system calls.

DTrace aggregations are created specifically for answering such questions. Working with sets of numerical data, aggregation functions help us to easily determing average, min and max values of data sets, count numbers and sums of elements in these data sets, and even build frequency distributions.

More information can be found here, but today I'll show only few examples of using aggregations.

DTrace stores the results of aggregation functions in objects called aggregations.

The syntax is:
@name[ keys ] = aggfunc ( args );
here:
name - name of our aggregation
keys - index keys, very similar to those of associative arrays.
aggfunc - aggregation function
args - function arguments, usually it's a set of numerical data

Today I'll use sum aggregation function, which as it's obvious from the name, helps us calculate the sum of a numerical data set,

Only the current value of the aggregation function is stored in the memory, it's calculated off the previous function argument values. Then the function is calculated for the current value of the argument, and this result is applied to the current aggregation value.

For basic analysis you can use as few aggregations keys as you can - for instance, use only PID, without specifying thread ID as another index key.You can even use execname - but keep in mind that there might be more than one process running on your system with the same name. Still, execname-based aggregation will be quite useful to track what's getting most of our system's attention:

Here's our script:


Save it into a file, do chmod a+x on this file and start it. You'll get an output similar to this:



The time in the last column is given in nanoseconds, so don't be scared with such huge numbers :) For timing some actions in your script timestamp proves to be VERY useful. It's a nanoseconds counter which increments from an arbitrary point, so it can be used for relative computations only.

Now you can look at the output and notice how much of unnecessary actions is happening on my laptop with started Gnome ;)

If you want a deeper analysis, you can make our script a bit more complex, and you'll get a powerful tool for determining what process was doing what on our system, and for how long.



If you save this code into syscalls.d and start the script, you'll probably get something similar (I've deleted lots of lines to save up some space):



If you leave such a script running for a couple of minutes, you'll get a very long output with the list of every process running on your system all the system calls it's been executing, with the time spent by each thread of each process.

Macro variables are meant to make your life MUCH easier when scripting with DTrace. Names of such variables must begin with a $ sign, and DTrace will automatically replace all the macro variables with the appropriate values when parsing your script.

Full list of macro variables can be found here, I will only talk about $target variable this time.

$target specifies the PID of the process you associate with your DTrace script.

DTrace has two useful command line options which can be used not only when running a dtrace command, but also when running DTrace-scripts:

./script.d -c xterm
This command asks DTrace to run a command which follows the -c option, and process the actual script.d only after this. Our macro variable, $target, will containt a PID of the started command we specified - xterm in this example.

./script.d -p 654
This is a similar way of running a DTrace script, only we notify DTrace that we'd like to work with the process with PID of 654. This way of using DTrace is especially useful as you don't have to start or restart an already running process. $target will contain the PID specified in the command line - 654 in this example.

$target may be used like this:



If you execute this script, you'll probably get an output like this:



Just a little bit later I'll talk about aggregations - yet another one of the wonderful DTrace features, and then I'll be able to give you more interesting and useful examples of DTrace scripting.

Just went to BigAdmin: DTrace once again, and bumped into this useful link - and decided to highlight it yet again.

This link leads to a pdf-file with the technical paper of the three guys who created DTrace - Bryan M. Cantrill, Michael W. Shapiro and Adam H. Leventhal, for the last USENIX conference. The title is: Dynamic Instrumentation of Production Systems.
Apart from listing all the advantages of DTrace, the paper also gives a thorough conceptual description of DTrace dynamic tracing mechanisms DTrace - I highly recommend you read it.

One of the most useful (for me) options in DTrace is flowindent. All it does is indent the entry to each function with "->", and mark the return from this function with "<-". Doesn't seem like much, does it? But just look at the results!

The following example catches all the probes of the fbt provided. By default (that's our case since we're not changing any other options but flowindent), DTrace registers and prints to the standard output all the probes matched in the tracing process.

Here is our script:


And this is the output we'll get by running this script:


But if we only add the flowindent option to our script (you can also achieve the same result by using -F dtrace command line option), the output is going to appear much more readable and easy to follow:

Our new script:


And this is the output we'll get:

You don't have conditional statements like if..then..else in DTrace, instead of them predicates are used.
Predicates are slash (/) wrapped conditions which are put right after the lines of probe definitions, defining whether DTrace should or should not executre the code of such probes.

Here's an example. The following script will print the list of all system calls, excluding write, for all the processes currently running on our system. Since DTrace tracks events on a thread-level, you can see in this example that some PIDs are the same. This is because these lines were printed by probes fired for different threads of the same process:



When you execute this script, you'll get something similar to this:



As you can see, our script even took a note of all the dtrace syscalls which was used to run the script. To exclude dtrace from our data, we should alter the predicate to include one more condition:


this will result in our output including all the processes but dtrace. In this example, we can see a couple of my rxvt terminals and java:



Predicates allow you to use any constants and variables defined earlier in the code, or standard ones, just like the ones shows in my examples. And if you keep in mind, that local variables are unique on thread-level, you can build up pretty complex constructions.

Thread-specific local variables are defined with the help of self indicator and a special -> operator, for instance: self->flag = 1;.

My next example will print only one message for each write syscall of every thread. As you can see in the code, every time we note a thread returning from write syscall, we mark this thread with a local variable, so that we know the thread has been processedt: self->processed = 1;. Next time a write probe fires for this thread, the predicate will take care of it and skip the probe code execution if needed:



As it's clearly seen, every thread has been registered only once:



It's impossibly to even try to cover all different ways of using DTrace predicates in only one entry, so I think I'll call it a day. Next time I'll show a few more ways of making your life easier.