An important tool in any linux admin’s toolkit is the venerable strace command. It enables us to get insight into what a program is actually doing. As awesome as strace can be, it doesn’t tell us everything. This series of articles will get you familiar with some of the other commands and approaches to gain insight into program execution.

strace basics

For the purpose of this post, we will be using the following script.

<code>
#!/bin/bash

while [ 1 ]
do
    echo "test"
    sleep 10
done
</code>

The first thing you can do with strace is run:

<code>strace ./foo.sh</code>

This generates some output like:

<code>
execve("./foo.sh", ["./foo.sh"], [/* 23 vars */]) = 0
brk(0) = 0xda7000
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fd20e269000
access("/etc/ld.so.preload", R_OK) = -1 ENOENT (No such file or directory)
open("/etc/ld.so.cache", O_RDONLY) = 3
fstat(3, {st_mode=S_IFREG|0644, st_size=15913, ...}) = 0
mmap(NULL, 15913, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7fd20e262000
... omitted ...
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fd20e257000
write(1, "test\n", 5test
) = 5
stat(".", {st_mode=S_IFDIR|0550, st_size=4096, ...}) = 0
stat("/usr/local/sbin/sleep", 0x7fffe416b380) = -1 ENOENT (No such file or directory)
stat("/usr/local/bin/sleep", 0x7fffe416b380) = -1 ENOENT (No such file or directory)
stat("/sbin/sleep", 0x7fffe416b380) = -1 ENOENT (No such file or directory)
stat("/bin/sleep", {st_mode=S_IFREG|0755, st_size=24264, ...}) = 0
... omitted ...
wait4(-1, 0x7fffe416b4bc, 0, NULL) = ? ERESTARTSYS (To be restarted)
</code>

This is great information, but what if the process is already running?

This is where the -p argument comes in. If you are taking notes you will want to remember -p as it will be on the test.

<code>
[root@localhost ~]# strace -p 1385
Process 1385 attached - interrupt to quit
wait4(-1, [{WIFEXITED(s) && WEXITSTATUS(s) == 0}], 0, NULL) = 1499
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
--- SIGCHLD (Child exited) @ 0 (0) ---
wait4(-1, 0x7fff5862579c, WNOHANG, NULL) = -1 ECHILD (No child processes)
rt_sigreturn(0xffffffffffffffff) = 0
rt_sigaction(SIGINT, {SIG_DFL, [], SA_RESTORER, 0x7fbb69254920}, {0x43d060, [], SA_RESTORER, 0x7fbb69254920}, 8) = 0
rt_sigprocmask(SIG_BLOCK, NULL, [], 8) = 0
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
rt_sigprocmask(SIG_BLOCK, [CHLD], [], 8) = 0
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
write(1, "test\n", 5) = 5
</code>

Excellent, so we can tap into any running process in this way, however what if we dont need all of the extra output? It turns out, you can specify -e trace=<something> to trim down the system calls that are displayed. Combine this with 2>&1 | grep <something else> and you have something. It is worth noting that the output redirection is because strace writes to stderr.

<code>
[root@localhost ~]# strace -p 1385 -e trace=write 2>&1 | grep test
write(1, "test\n", 5) = 5
write(1, "test\n", 5) = 5
</code>

The number immediately after the open parenthesis is the file descriptor. We will cover that in the next post.