For example, the following D statements access an associative array, whose values must all be type int and whose tuples must all have signature string,int, setting an element to 456 and then incrementing it to 457:

a["hello", 123] = 456;
a["hello", 123]++;

Now let us use an associative array in a D program. Type the following program and save it in a file named rwtime.d:

syscall::read:entry,
syscall::write:entry
/pid == $1/
{
  ts[probefunc] = timestamp;
}
syscall::read:return,
syscall::write:return
/pid == $1 && ts[probefunc] != 0/
{
  printf("%d nsecs", timestamp - ts[probefunc]);
}

As with stracerw.d, specify the ID of the shell process when you execute rwtime.d. If you type a few shell commands, you will see the time elapsed during each system call. Type in the following command and then press return a few times in your other shell:

# dtrace -s rwtime.d `/usr/bin/pgrep -n bash`
dtrace: script 'rwtime.d' matched 4 probes
CPU     ID                    FUNCTION:NAME
  0      8                     write:return 51962 nsecs
  0      8                     write:return 45257 nsecs
  0      8                     write:return 40787 nsecs
  1      6                      read:return 925959305 nsecs
  1      8                     write:return 46934 nsecs
  1      8                     write:return 41626 nsecs
  1      8                     write:return 176839 nsecs
...
^C
#

To trace the elapsed time for each system call, you must instrument both the entry to and return from read() and write() and measure the time at each point. Then, on return from a given system call, you must compute the difference between our first and second timestamp. You could use separate variables for each system call, but this would make the program annoying to extend to additional system calls. Instead, it is easier to use an associative array indexed by the probe function name. The following is the first probe clause:

syscall::read:entry,
syscall::write:entry
/pid == $1/
{
  ts[probefunc] = timestamp;
}

This clause defines an array named ts and assigns the appropriate member the value of the DTrace variable timestamp. This variable returns the value of an always-incrementing nanosecond counter. When the entry timestamp is saved, the corresponding return probe samples timestamp again and reports the difference between the current time and the saved value:

syscall::read:return,
syscall::write:return
/pid == $1 && ts[probefunc] != 0/
{
  printf("%d nsecs", timestamp - ts[probefunc]);
}

The predicate on the return probe requires that DTrace is tracing the appropriate process and that the corresponding entry probe has already fired and assigned ts[probefunc] a non-zero value. This trick eliminates invalid output when DTrace first starts. If your shell is already waiting in a read() system call for input when you execute dtrace, the read:return probe fires without a preceding read:entry for this first read() and ts[probefunc] will evaluate to zero because it has not yet been assigned.