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:
strace
shows the failing syscall.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, "\177ELF\1\1\1\0\0\0\0\0\0\0\0\0\3\0(\0\1\0\0\0$`\1\0004\0\0\0"..., 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!\n", 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