Debugging with strace

Dig Deep

© Stephen Mcsweeny, 123RF

© Stephen Mcsweeny, 123RF

Article from Issue 105/2009

After "Hello World," you really need to look at system calls in more detail. In this second of two articles, we'll look at debugging in the real world.

An article in the June issue [1] explored the very useful system call tracer strace [2]. Strace helps you hunt down the source of problems with home-grown apps or buggy open source programs that won't quite work on your system. In this article, I take a closer look at how to interpret some of the system call information discovered through strace and describe some ways to make strace more useful in practical situations.

Hello Again!

In the previous article, I introduced the simple test program shown in Listing 1. To run strace on this program and send the output to a file, I typed:

strace -o outputfile.txt helloworld.c

The strace output for Listing 1 is shown in Listing 2. A close look at a couple of lines in the output will give you some insights into how Linux deals with files and memory.

Listing 1



Listing 2

Complete strace for helloworld.c



In Listing 2, notice that the program tries to access /etc/ without success. For instance, line 11 provides the message:

access flfl
("/etc/", F_OK) flfl
= -1 ENOENT flfl
(No such file or directory)

In this case, the problem is pretty hard to track down because /etc/ is an under-documented file. This step reveals what sorts of libraries the linker looks for.

If /etc/ is present, the linker loads the non-optimized version of a library (i.e., not optimized for your particular hardware). If it's not present, the linker will go looking for the hardware-optimized version.

For more information on, you can check out the man page, but basically it's responsible for loading all shared libraries, preparing a program to run, and running it. Any Linux program will need to do its thing before it can run, unless it has been linked statically.

Sandboxes and Pointers

One of the great things about Linux is how well documented the system calls are. From the man pages, you can get information on any of the functions you see in strace output with man functionname or man 2 functionname. The documentation makes it easy to learn a lot just by looking at strace output.

User programs on a modern system run in a little sandbox: They're not permitted to interact directly with the computer (so you can't just shove numbers into registers to make things happen, as you could 20 years ago). Instead, everything goes through the kernel, and strace traces these messages to the kernel. If you don't see any strace output for a bit, it doesn't necessarily mean that your program is stuck; it might be doing stuff within its own sandbox (e.g., calculations) that doesn't require it to talk to the kernel.

System calls often use pointers to data structures. A pointer is a memory reference that tells the system where to look in memory to find a particular piece of information. If you were a computer, this would be great, but it's not so good when you're a human, because digging around in memory isn't easy. When strace sees a pointer, instead of giving you the value of the pointer, it does the lookup for you and returns the contents of that pointer so that you're shown the actual data. When you're reading man pages and it talks about a pointer to a data structure or a pointer to a buffer, remember that what you see in the strace output is the contents of that data structure.

Files and Memory

As you might have noticed when first looking at the output for this program, one of the lines that comes up quite frequently is mmap. The mmap call is responsible for mapping files or devices into memory. Look at how an mmap call is structured in Listing 3, for example.

Listing 3

mmap Call


Before the mmap call, the output shows that the /etc/ file has opened successfully with a file descriptor of 3.

Then there's a call to fstat. The first argument, 3, is the file descriptor for the file opened in the previous line.

Perhaps you've noticed that when files are opened to a number, the numbers start at 3. This occurs because the file descriptors 0-2 are already allocated: 0 to stdin, 1 to stdout, and 2 to stderr.

The fstat call returns information about a file. The first argument is the file descriptor, which, as here, will have been set up by an earlier open call. The next section in the brackets is a stat structure. Strace doesn't actually show all of it (hence the … at the end), but the stat structure contains information about the file: user and group ID of owner, device ID, time last modified, and so on. (If you want to get full information on these sorts of structures, you can use the strace option -v.)

From the stat structure, you can see the file protection and size (in bytes) of the file. You should be able to interpret both of these values: The protection uses the same coding as chmod, so here, that's owner+group read, owner write, and owner execute (0644), and the size is just a number. (The other part of the mode field is a flag identifying whether it's a regular file, directory, or something else: S_IFREG means it's a regular file.) The fstat call returns 0 for success, as here: When called, the function fills in the stat structure that is recorded here.

In the mmap call, the first argument is a memory location, intended as a hint to the system as to where the memory mapping might start. Usually, as in this case, it's zero (NULL, i.e., the system has free rein to use any location it likes). The next number, which you might recognize, is the size in bytes of the file (so here, 43270 matches the size in the stat structure in the fstat call). The PROT* section specifies the protection that this memory should have, and it can't conflict with the mode of the file. Here, I'm opening with READ only. Because I'm not running as root, I don't have write or execute access to this file.

Next, the mmap call maps data from a file into memory, and these options specify how that mapping works. Here, MAP_PRIVATE means that any changes made to the mapped region (i.e., any changes made to memory) aren't shared with any other processes and aren't written back to the original file, which obviously is a good idea in the case of a system file like! The next argument is, yet again, 3, the file descriptor. The final value is the offset, which here is set to 0.

The value returned by mmap is the memory address at which the mapping starts. To see when the system cleans up after itself, look for a munmap call later on with that memory address – that will clear out the memory address.

Note that you will get this call in a C trace, but not in a Perl trace. Because C explicitly sets up its own memory, it also explicitly clears up after itself (or it can, depending on the details of the implementation of malloc). Perl, on the other hand, just leaves this to be done by the system in due course.

While I'm looking at system calls in detail, what about the exit_group call that ends both strace outputs? All this does is exit threads. Unlike exit, it clears up not only that thread, but all threads in the current group.

Static or Dynamic

Static linking means that a program brings its own libraries. Dynamic linking means that a program uses the system libraries. With dynamic linking, you only have to have one copy of all the standard system libraries, rather than a copy per program. Pretty much all Linux programs use dynamic linking now, unless they've been specifically optimized to reduce overhead.

Buy Linux Magazine

Get it on Google Play

US / Canada

Get it on Google Play

UK / Australia

Related content

  • strace

    Get started with strace by examining a pair of "Hello World" programs. Next month, in the second part of this two-part series, I'll take a deeper look at strace output.

  • Tracing Tools

    Programs rarely reveal what they are doing in the background, but a few clever tools, of interest to both programmers and administrators, monitor this activity and log system functions.

comments powered by Disqus

Direct Download

Read full article as PDF: