I started the chapter with the simple and ubiquitous tool, top, and I will finish with another: strace. It is a very simple tracer that captures system calls made by a program and, optionally, its children. You can use it to do the following:
- Learn which system calls a program makes.
- Find those system calls that fail together with the error code. I find this useful if a program fails to start but doesn't print an error message or if the message is too general.
straceshows the failing syscall. - Find which files a program opens.
- Find out what syscalls a running program is making, for example to see if it is stuck in a loop.
There are many more examples online, just search for strace tips and tricks. Everybody has their own favorite story, for example, http://chadfowler.com/blog/2014/01/26/the-magic-of-strace
strace uses the ptrace(2) function to hook calls from user space to the kernel. If you want to know more about how ptrace works, the man page is detailed and surprisingly legible.
The simplest way to get a trace is to run the command with strace as shown here (the listing has been edited to make it clearer):
# strace ./helloworld execve("./helloworld", ["./helloworld"], [/* 14 vars */]) = 0 brk(0) = 0x11000 uname({sys="Linux", node="beaglebone", ...}) = 0 mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb6f40000 access("/etc/ld.so.preload", R_OK) = -1 ENOENT (No such file or directory) open("/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3 fstat64(3, {st_mode=S_IFREG|0644, st_size=8100, ...}) = 0 mmap2(NULL, 8100, PROT_READ, MAP_PRIVATE, 3, 0) = 0xb6f3e000 close(3) = 0 open("/lib/tls/v7l/neon/vfp/libc.so.6", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory) [...] open("/lib/libc.so.6", O_RDONLY|O_CLOEXEC) = 3 read(3, "177ELF111 3 ( 1 $`1 004 "..., 512) = 512 fstat64(3, {st_mode=S_IFREG|0755, st_size=1291884, ...}) = 0 mmap2(NULL, 1328520, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0xb6df9000 mprotect(0xb6f30000, 32768, PROT_NONE) = 0 mmap2(0xb6f38000, 12288, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x137000) = 0xb6f38000 mmap2(0xb6f3b000, 9608, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xb6f3b000 close(3) [...] write(1, "Hello, world! ", 14Hello, world! ) = 14 exit_group(0) = ? +++ exited with 0 +++
Most of the trace shows how the runtime environment is created. In particular you can see how the library loader hunts for libc.so.6, eventually finding it in /lib. Finally, it gets to running the main() function of the program, which prints its message and exits.
If you want strace to follow any child processes or threads created by the original process, add the -f option.
A common use of strace is to discover which files a program tries to open at start up. You can restrict the system calls that are traced through the -e option, and you can write the trace to a file instead of stdout by using the -o option:
# strace -e open -o ssh-strace.txt ssh localhost
This shows the libraries and configuration files ssh opens when it is setting up a connection.
You can even use strace as a basic profile tool: if you use the -c option, it accumulates the time spent in system calls and prints out a summary like this:
# strace -c grep linux /usr/lib/* > /dev/null % time seconds usecs/call calls errors syscall ------ ----------- ----------- --------- --------- ---------- 78.68 0.012825 1 11098 18 read 11.03 0.001798 1 3551 write 10.02 0.001634 8 216 15 open 0.26 0.000043 0 202 fstat64 0.00 0.000000 0 201 close 0.00 0.000000 0 1 execve 0.00 0.000000 0 1 1 access 0.00 0.000000 0 3 brk 0.00 0.000000 0 199 munmap 0.00 0.000000 0 1 uname 0.00 0.000000 0 5 mprotect 0.00 0.000000 0 207 mmap2 0.00 0.000000 0 15 15 stat64 0.00 0.000000 0 1 getuid32 0.00 0.000000 0 1 set_tls ------ ----------- ----------- --------- --------- ----------- 100.00 0.016300 15702 49 total