Command Center

In my LKCD and Kdump tutorials, I've mentioned a large number of sequels, including tutorials showing how to work with kernel crash dump processing and analysis tools, how to debug applications and more. Well, one such sequel has just arrived and it's about the most important level II debugging tool available: strace.

Introduction

Strace is a utility that can trace system calls. If you're wondering what system calls are, they are a translation mechanism that provides interface between a process and the operating system (kernel). These calls can be intercepted and read, allowing for a better understanding of what a process is trying to do at a given runtime.
By hooking these calls, we can get a better understanding of how a process behaves, especially if it's misbehaving. The operating system functionality that allows tracing is called ptrace. Strace calls on ptrace and reads the process behavior, reporting back.
Today, we will learn when to use strace, how to use it, how to interpret its output, how to glean errors from the strace output, and solve problems quickly and efficiently.
Follow me.

Strace from the standpoint of a system administrator

Using strace requires some basic hacking instinct. It's not for everyone. Most desktop users will probably never need or want to use strace, but they just might. Likewise, most system administrators doing level I maintenance or helpdesk will probably not be tempted to put strace to good use.
However, if you have a curious nature or would like to understand better what your system is doing or perhaps your job requires that you dabble into the internals, then strace is a good place to start and then spend some time, never quite leaving. Like Hotel California, that is.
Now, when and how to use strace - and most importantly - what kind of information to pay attention to, this kind of takes a form of black art, but with some discipline and an inkling to code, you will be able to master strace and use it successfully.

Strace has friends ...

Strace is not the only utility that can trace system calls. There's another utility called ltrace, which can trace both system calls and library calls. Then, there's also the famous Gnu Debugger (gdb), which a fully featured code debugger.
We will talk about these in detail, as well. It is important to remember that while strace is less powerful than its two aforementioned friends, it is much easier and safer to use. ltrace is more prone to crash traced processes. gdb is much more complex, requires a deeper knowledge of code and works best if you have the sources available, which may not always be the case. strace may only be light artillery, but it's handy and ready at all times.

What you need to know before you start using strace

There are a few things I would like to emphasize before we start exploring the power of this great tool.
strace is not a magic bullet. It will only provide some, limited information about the running process. You will need much more to get the full picture, including using ltrace and a debugging, having your application and/or kernel compiled with debugging symbols, profiling the application run using a dedicated tool, and a bit more.
strace is only the beginning. But it's a very good beginning. It will point you in the right direction, whether to leave things be or power up the full debugging - or better yet - provide you with a solution to your problem.
strace should be used when you encounter reproducible issues with your programs without an obvious sign for problems. We will soon see a few examples that demonstrate this in crystal-clear detail.
strace hooks processes and basically forces them to repeat every thing they do twice, once for the trace and once for real. This introduces a time penalty into the run. Furthermore, this means that delicate problems dependent on exact timing of execution, like various race condition bugs, may not manifest when traced.
strace may crash your applications.
strace 64-bit may not work well with 32-bit programs.
Not all programs can be traced and may crash, either because of bugs or the way they have been coded, including purposefully trying to prevent tracing to keep the process execution as secret as possible. This is often the case with proprietary software.
Now, if you're ready, move on.

Examples!

We will begin with the basics and then, I will show you two testcases that simulate real problems with program execution, which cannot be solved by using the programs or looking for visual clues for the errors, but which are easily deciphered when strace is kicked into action.

Basic usage

First, to learn the basics, please read the man page.
strace can be invoked against a command line, which can be a binary or a script, or attached against an already running process. Output can be shown on the screen, but this is usually of limited value unless the runs are really short and simple, or redirected into a file, which is the preferred way of doing things.
Special flags can be used to measure system call timing, inside the system calls and in between them, child processes forked off the parent can also be traced, environment variables can also be shown, there's the string length for the output, the ability to filter only specific system calls, and create a useful summary for the entire run.
Here's the most basic form:
Here's an example, with dd command:

This will produce the following output:

Looks cluttered and messy and not easy to follow. Indeed, this is not how you should be using strace unless you can read really, really fast, kind of Dustin Hoffman in Rain Man.

Extra flags

So you should invoke strace with extra flags:

We used the following flags:
-o output file, this is where the output goes now and can be read at leisure.
-s 512 increases the string length to 512 bytes; the default is 32.
Now it looks cleaner:

And the file content:

Summary count

But we can enhance the tracing process even more. For example, you may not only be interested in the gory details, you may also want to see a summary table of all system calls used by the process, including errors. This can be quite useful when comparing a healthy system with a bad one, allowing you to spot notable differences instantly.
And our example:

For example, we had 1500 write calls, including 8 errors. 67% of the process time was spent writing, which is expected from the dd command. But we also had quite a few reads.
Other useful flags are -f (fork), -Tt (time inside/between system calls) and others. To trace an already running process, you need the -p flag against the process ID (PID), which you can find by running ps and looking for your process name.
Now that we know how to use strace, let's see what it can do:

Test case 1

We will copy a file. Very simple. Only, we will make sure the source file does not exist and redirect error output to /dev/null, so the command line user will not know what happens when the copy command is executed.
Our work area is the Documents directory in a default openSUSE 11.2 Gnome edition installation, which has some OpenOffice templates in there.

Now, if we rename the source and try to copy, we'll hit an error:

But what if you could not see the cp: cannot stat error message on your screen? How would you know if and what went wrong with the execution of your program?
To demonstrate this, I'm going to redirect all output to /dev/null, so no messages are displayed to the user:
The last bit, 2>&1, tells the system to redirect STDERR (FD 2) to the same location asSTDOUT (FD 1), in this case /dev/null, so you won't see any errors. Next, we will check the exit status with echo $?. If the exit status is 0, then it's good, anything else and we have a problem.

OK, the copy command has completed, no visible errors, right. Now, checking the exit status, it's 1, so something went wrong. When it's a simple copy, then investigating is easy, but what if you have a complex script that goes through tens of directories and copies hundreds of files?
Enter strace.
Now, I'm going to show you the tip of the real power that strace has. We will now trace the unsuccessfully copy command and then analyze the strace log.

We have the log file, called cp-fail. We'll open it in a text editor and look at it. The big question is, what to look for? Well, in our case, we have a copy, which requires source and destination. Either we have a problem with the existence of the source/destination or the permissions or maybe disk space. Any one of these is a possibility.
So we will look for the name of source file in the log and see if there are any errors there.

Indeed, it's there! The stat64 system call fails. It exits with ENOENT (No such file or directory). There's the problem right there. We do not have the source file!
strace is lovely, ain't it?
Now, we could have enhanced and simplified our search. Instead of tracing everything, we could have limited our investigation only to specific system calls. That's what the -e flag does.
-e allows you to trace only specific system calls. For example:
This means we're only interested in stat64 system call and no other.

Indeed, the output is now much shorter and easier to sort, since we only have two files that need to be accessed.

If you want to know more what the system call in question does - or any one, for that matter, you can use the man 2 pages to read more about them. The man 2 pages are really for geeks and system programmers, but if you want to expand your knowledge and understand a little better what your processes are trying to do, it's a good way of exploring.
In our case:

Let's see our second example.

Test case 2

In this example, I'll show you how to debug network problems. We will try to ping the gateway of our LAN. First, we'll see a successful example, then we will stop the network and see an error. Then, we will redirect all errors to /dev/null, as we did with the copy example, so we do not know what's happening. strace will help us pinpoint the root cause.
So, here's a healthy ping:

Now, we shut down the network:
And the ping fails with network unreachable error:

However, if we redirect the output and errors to /dev/null, we won't see the message and won't know what's wrong. Imagine this is some application that pings its server for license or tries to retrieve updates.

As you can see, the exit status is 2, which is no good. But we don't know why. Time to put strace to work and find out the root cause.

Now, let's take a look at the log file. Personally, I do not know what to expect, so let's browse and look for errors related to 192.168.1.1.

And there it is. We open a socket and try to connect. But then, we get the ENETUNREACH error, which is Network is unreachable. Root cause found. Of course, we now need to understand why the network is down, but we can focus on problem solution instead of wondering idly what might have gone wrong.
I hope you're convinced.

Conclusion

strace is a mighty tool. It's so simple to use, yet it offers rewards almost instantly. I do admit it's not for everyone, definitely not the majority of home users, but with some patience, basic investigative instinct combined with a curious soul and desire to learn, you can put strace to smart use.
I can give you several personal examples. I've used strace to debug all sorts of issues, ranging from file search via mount issues to fonts and performance problems. strace proved useful each and every time. And while many cases required much deeper attention, strace was an excellent pointer. What more, easily one third of the problems could be diagnosed almost immediately with strace.
Expand your mind and skills. Do not be afraid. Grab strace and start working with it. Very soon, you'll be enjoying greater freedom and productivity and you many even impress your girlfriend or your boss.
We will soon learn about several more super-duper admin tools, so make sure you visit the website now and then or subscribe to the RSS feed. Just a few buzzwords to whet your appetite: crash, gdb, oprofile, screen, ltrace, and a few more. Stay tuned.
Cheers.

REFERENCES
http://www.dedoimedo.com/computers/strace.html
http://www.dedoimedo.com/computers/crash.html
http://www.dedoimedo.com/computers/lsof.html

10 super-cool Linux hacks you did not know about
Linux cool hacks - Part II
Linux super-duper admin tools: lsof
Linux super-duper admin tools: screen
Linux super-duper admin tools: OProfile
Linux super-duper admin tools: Strace
Some external links:
Linux audit files to see who made changes to a file