Go to main content

Oracle® Solaris 11.4 DTrace (Dynamic Tracing) Guide

Exit Print View

Updated: September 2020
 
 

Output Formatting in DTrace

System call tracing is a powerful way to observe the behavior of most user processes. If you have used the Oracle Solaris truss utility before as an administrator or developer, you have probably learned that it is a useful tool to keep around for whenever there is a problem. If you have never used truss before, type this command in one of your shells:

$ truss date

You will see a formatted trace of all the system calls executed by date followed by its one line of output at the end. The following example improves upon the earlier rw.d program by formatting its output to look more like truss so you can more easily understand the output. Type the following program and save it in a file called trussrw.d:

Example 3  Tracing System Calls with truss Output Format
syscall::read:entry,
syscall::write:entry
/pid == $1/
{
        printf("%s(%d, 0x%x, %4d)", probefunc, arg0, arg1, arg2);
}

syscall::read:return,
syscall::write:return
/pid == $1/
{
        printf("\t\t = %d\n", arg1);
}

In this example, the constant 12345 is replaced with the label $1 in each predicate. This label allows you to specify the process of interest as an argument to the script: $1 is replaced by the value of the first argument when the script is compiled. To execute trussrw.d, use the dtrace options –q and –s, followed by the process ID of your shell as the final argument. The –q option indicates that dtrace should be quiet and suppress the header line and the CPU and ID columns shown in the preceding examples. As a result, you will only see the output for the data that you explicitly traced. Type the following command after replacing 12345 with the process ID of a shell process and then press return a few times in the specified shell:

# dtrace -q -s trussrw.d 12345
                         = 1
write(2, 0x8089e48, 1)                = 1
read(63, 0x8090a38, 1024)             = 0
read(63, 0x8090a38, 1024)             = 0
write(2, 0x8089e48, 52)               = 52
read(0, 0x8089878, 1)                 = 1
write(2, 0x8089e48, 1)                = 1
read(63, 0x8090a38, 1024)             = 0
read(63, 0x8090a38, 1024)             = 0
write(2, 0x8089e48, 52)               = 52
read(0, 0x8089878, 1)                 = 1
write(2, 0x8089e48, 1)                = 1
read(63, 0x8090a38, 1024)             = 0
read(63, 0x8090a38, 1024)             = 0
write(2, 0x8089e48, 52)               = 52
read(0, 0x8089878, 1)^C
#

Examine the D program and its output in more detail. First, a clause instruments each of the shell's calls to read and write. For this example, a new function, printf(), is used to trace data and print it out in a specific format:

syscall::read:entry,
syscall::write:entry
/pid == $1/
{
        printf("%s(%d, 0x%x, %4d)", probefunc, arg0, arg1, arg2);
}

The printf() function combines the ability to trace data, as if by the trace() function used earlier, with the ability to output the data and other text in a specific format that you describe. The printf() function tells DTrace to trace the data associated with each argument after the first argument, and then to format the results using the rules described by the first printf argument, known as a format string.

The format string is a regular string that contains any number of format conversions, each beginning with the % character, that describe how to format the corresponding argument. The first conversion in the format string corresponds to the second printf argument, the second conversion to the third argument, and so on. All of the text between conversions is printed verbatim. The character following the % conversion character describes the format to use for the corresponding argument. Here are the meanings of the three format conversions used in trussrw.d:

%d

Print the corresponding value as a decimal integer

%s

Print the corresponding value as a string

%x

Print the corresponding value as a hexadecimal integer

DTrace printf works just like the C printf library routine or the shell printf utility. If you have never used printf, the formats and options are explained in detail in Output Formatting in DTrace. In D, printf is provided as a built-in utility and some new format conversions are available to you designed specifically for DTrace. For more information, see the printf(3C) man page.

To write correct programs, the D compiler validates each printf format string against its argument list. Try changing probefunc in the preceding clause to the integer 123. If you run the modified program, you will see an error message telling you that the string format conversion %s is not appropriate for use with an integer argument:

# dtrace -q -s trussrw.d
dtrace: failed to compile script trussrw.d: line 4: printf( )
           argument #2 is incompatible with conversion #1 prototype:
                conversion: %s
                 prototype: char [] or string (or use stringof)
                  argument: int
#

To print the name of the read or write system call and its arguments, use the printf statement.

printf("%s(%d, 0x%x, %4d)", probefunc, arg0, arg1, arg2);

The printf statement traces the name of the current probe function and the first three integer arguments to the system call, available in the DTrace variables arg0, arg1, and arg2. For more information about probe arguments, see Variables in DTrace. The first argument to read and write is a file descriptor, printed in decimal. The second argument is a buffer address, formatted as a hexadecimal value. The final argument is the buffer size, formatted as a decimal value. The format specifier %4d is used for the third argument to indicate that the value should be printed using the %d format conversion with a minimum field width of 4 characters. If the integer is less than 4 characters wide, printf will insert extra blanks to align the output.

To print the result of the system call and complete each line of output, use the following clause:

syscall::read:return,
syscall::write:return
/pid == $1/
{
        printf("tt = %dn", arg1);
}

Notice that the syscall provider also publishes a probe named return for each system call in addition to entry. The DTrace variable arg1 for the syscall return probes evaluates to the system call's return value. The return value is formatted as a decimal integer. The character sequences beginning with backwards slashes in the format string expand to tab (\t) and newline (\n) respectively. These escape sequences help you print or record characters that are difficult to type. D supports the same set of escape sequences as C, C++, and the Java programming language. For more information about escape sequences, see Types, Operators, and Expressions in DTrace.