21.3 Tracing System Calls

Most Unix-style operating systems offer a
"tracing utility" that intercepts
and records the system calls that are called by a process and the
signals that are received by a process. In this respect it is similar
to gdb. The name of each system call, its
arguments, and its return value are printed to
STDERR or to the specified file.

The tracing utility is a useful
diagnostic, instructional, and debugging tool. You can learn a lot
about the underlying system while examining traces of the running
programs. In the case of mod_perl, tracing improves performance by
enabling us to spot and eliminate redundant system calls. It also
useful in cases of problem debugging?for example, when some
process hangs.

Depending on your operating system, you should have available one of
the utilities strace,
truss, tusc,
ktrace, or similar. In this book we will use the
Linux strace utility.

There are two ways to get a trace of the process with
strace. One way is
to tell strace to start the process and do the
tracing on it:

panic% strace perl -le 'print "mod_perl rules"'

Another way is to tell strace to
attach to a process that's
already running:

panic% strace -p PID

Replace PID with the process number you want to
check on.

Many other useful arguments are accepted by
strace. For example, you can tell it to trace
only specific system calls:

In this example we have asked strace to show us
only the calls to open( ), write( ),
close( ), and nanosleep( ),
which reduces the output generated by strace,
making it simpler to understand?providing you know what you are
looking for.

The generated traces are too long (unless filtered with
trace=tag) to be presented here completely. For
example, if we ask for only the write( ) system
calls, we get the following output:

The output of the Perl one-liner gets mixed with the trace, so the
actual trace is:

write(1, "mod_perl rules\n", 15) = 15

Note that the newline was automatically appended because of the
-l option on the Perl command line.

Each line in the trace contains the system call name, followed by its
arguments in parentheses and its return value. In the last example, a
string of 15 characters was written to STDOUT,
whose file descriptor is 1. And we can see that they were all
successfully written, since the write( ) system
call has returned a value of 15, the number of characters written.

The strace manpage provides a comprehensive
explanation of how to interpret all parts of the traces; you may want
to refer to this manpage to learn more about it.