strace

The strace tool traces system calls and signals and is a fantastic tool for debugging and performance tuning. It can handle multithreaded processes and we can even set it to trace forked children.

We can trace processes launched together with strace of already running processes using the -p flag:

root:~> strace cat /tmp/dummy.txt           → trace and throw output to stdout
root:~> strace ­-p 26780                     → trace PID 26780 and throw output to stdout
root:~> strace ­-p 26780 ­-o /tmp/dummy.log   → trace PID 26780 and throw output to log file

Each line of strace output has the system call (red)+ arguments (yellow) + return code (blue) parameters on it. Let’s see a few examples to get a grip on its syntax and capabilities:

# strace with default options
root:~> strace cat /tmp/dummy.txt
execve(“/bin/cat”, [“cat”, “test.1”], [/* 40 vars */]) = 0
brk(0) = 0x25e5000
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, ­1, 0) = 0x7fe6f4e3a000
access(“/etc/ld.so.preload”, R_OK) = ­1 ENOENT (No such file or directory)
open(“/etc/ld.so.cache”, O_RDONLY|O_CLOEXEC) = 3
fstat(3, {st_mode=S_IFREG|0644, st_size=118326, …}) = 0
mmap(NULL, 118326, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7fe6f4e1d000
close(3) = 0
open(“/lib64/libc.so.6”, O_RDONLY|O_CLOEXEC) = 3
read(3, “177ELF2113��������3�>�1����12�����”…, 832) = 832
fstat(3, {st_mode=S_IFREG|0755, st_size=2082456, …}) = 0
mmap(NULL, 3919744, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7fe6f485d000
mprotect(0x7fe6f4a10000, 2097152, PROT_NONE) = 0
[…]
open(“/usr/lib/locale/locale­archive”, O_RDONLY|O_CLOEXEC) = 3
fstat(3, {st_mode=S_IFREG|0644, st_size=106374736, …}) = 0
mmap(NULL, 106374736, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7fe6ee2ea000
close(3) = 0
fstat(1, {st_mode=S_IFCHR|0620, st_rdev=makedev(136, 3), …}) = 0
open(“test.1”, O_RDONLY) = 3
fstat(3, {st_mode=S_IFREG|0644, st_size=7, …}) = 0
fadvise64(3, 0, 0, POSIX_FADV_SEQUENTIAL) = 0
read(3, “asdasdn”, 65536) = 7
write(1, “asdasdn”, 7asdasd) = 7
read(3, “”, 65536) = 0
close(3) = 0
close(1) = 0
close(2) = 0
exit_group(0) = ?
+++ exited with 0 +++

We can gather cumulative data with the -c flag:

root:/tmp> strace -­c cat test.1
% time     seconds  usecs/call     calls    errors syscall
­­­­­­------ ----------- ----------- --------- --------- --------------
 34.95    0.000115          13         9           mmap
 19.45    0.000064          13         5           fstat
 16.72    0.000055          55         1         1 access
 12.46    0.000041          10         4           brk
  6.99    0.000023           6         4           open
  2.74    0.000009           2         4           mprotect
  1.82    0.000006           6         1           munmap
  1.52    0.000005           2         3           read
  1.22    0.000004           4         1           write
  1.22    0.000004           1         6           close
  0.61    0.000002           2         1           execve
  0.30    0.000001           1         1           fadvise64
  0.00    0.000000           0         1           arch_prctl
­­­­­­ ­­­­­­­­­­­ ­­­­­­­­­­­ ­­­­­­­­­ ­­­­­­­­­ ­­­­­­­­­­­­­­­­------ ----------- ----------- --------- --------- --------------
100.00    0.000329                    41         1 total

With the -D flag we are tracing the desired process as a detached grandchild rather than as a parent and it reduces the distortion caused by strace itself:

root:/tmp> strace -­c -­D cat test.1
Process 24908 attached
% time    seconds  usecs/call     calls   errors syscall
------ ---------- ----------- --------- -------- --------------
26.22    0.000070           8         9           mmap
13.11    0.000035           9         4           brk
12.73    0.000034           9         4           open
11.99    0.000032          32         1           execve
 9.36    0.000025           6         4           mprotect
 6.37    0.000017          17         1           munmap
 4.87    0.000013           2         6           close
 4.12    0.000011           4         3           read
 3.75    0.000010           2         5           fstat
 3.37    0.000009           9         1        1  access
 3.00    0.000008           8         1           write
 0.75    0.000002           2         1           fadvise64
 0.37    0.000001           1         1           arch_prctl
­­­­­­ ­­­­­­­­­­­ ­­­­­­­­­­­ ­­­­­­­­­ ­­­­­­­­­ ­­­­­­­­­­­­­­­­------ ---------- ----------- --------- -------- --------------
100.00   0.000267                    41        1  total

If a process forks children we won’t trace the children unless we use the -f flag:

root:/tmp> strace ­-f -­p 25664

If a process forks more than a few children, we might want to use the -ff flag so that each traced process is dumped on a filename.pid to make analysis easier:

root:/tmp> strace -­ff -­p 25664

It is also very useful to use the -r flag to get an idea of where time is spent. This flag shows the timestamp upon entry of the system call:

root:/tmp> strace ­-r cat test.1
0.000000 execve(“/usr/bin/cat”, [“cat”, “test.1”], [/* 116 vars */]) = 0
0.000292 brk(0) = 0x22d1000
0.000201 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, ­1, 0) = 0x7f03e3f83000
0.000184 access(“/etc/ld.so.preload”, R_OK) = ­1 ENOENT (No such file or directory)
0.000182 open(“/etc/ld.so.cache”, O_RDONLY|O_CLOEXEC) = 3
0.000102 fstat(3, {st_mode=S_IFREG|0644, st_size=118326, …}) = 0
0.000029 mmap(NULL, 118326, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7f03e3f66000
0.000022 close(3) = 0
0.000019 open(“/lib64/libc.so.6”, O_RDONLY|O_CLOEXEC) = 3
0.000018 read(3, “177ELF2113��������3�>�1����12�����”…, 832) = 832
0.000016 fstat(3, {st_mode=S_IFREG|0755, st_size=2082456, …}) = 0

For more accurate timing we should use -T to show the time spent on each system call. This flag shows the difference between the entry and exit timestamps on each syscall:

root:/tmp> strace ­-T cat test.1
execve(“/usr/bin/cat”, [“cat”, “test.1”], [/* 116 vars */]) = 0 <0.000523>
brk(0) = 0xfdd000 <0.000038>
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, ­1, 0) = 0x7f76edc96000 <0.000107>
access(“/etc/ld.so.preload”, R_OK) = ­1 ENOENT (No such file or directory) <0.000105>
open(“/etc/ld.so.cache”, O_RDONLY|O_CLOEXEC) = 3 <0.000110>
fstat(3, {st_mode=S_IFREG|0644, st_size=118326, …}) = 0 <0.000052>

By default most output is abbreviated but with the -v flag we can switch it to verbose. Below we have 2 lines of strace output: the 1st without (red) and the 2nd with the -v flag (blue):

execve(“/usr/bin/cat”, [“cat”, “test.1”], [/* 116 vars */]) = 0
.
execve(“/usr/bin/cat”, [“cat”, “test.1”], [“XDG_VTNR=1”, “Green=\e[0;32m”, “Black=\e[0;30m”,
“URed=\e[4;31m”, “XDG_SESSION_ID=1”, “GUESTFISH_INIT=\e[1;34m”, “HOSTNAME=envy17”,
“GPG_AGENT_INFO=/run/user/1000/ke”…, “BICyan=\e[1;96m”, “TERM=xterm­256color”, “SHELL=/bin/bash”,
“VTE_VERSION=3803”, “XDG_MENU_PREFIX=gnome­”, “UPurple=\e[4;35m”, “BCyan=\e[1;36m”, “HISTSIZE=1000”,
“UYellow=\e[4;33m”, “BBlue=\e[1;34m”, “GJS_DEBUG_OUTPUT=stderr”, “On_Red=\e[41m”, “BGreen=\e[1;32m”, “WINDOWID=39849356”, “Coloroff=\e[0m”, “OLDPWD=/home/marc/.ssh”, “QTDIR=/usr/lib64/qt­3.3”,
“QTINC=/usr/lib64/qt­3.3/include”, “GJS_DEBUG_TOPICS=JS ERROR;JS LOG”, “Purple=\e[0;35m”,
“On_IYellow=\e[0;103m”, “On_IGreen=\e[0;102m”, “On_IRed=\e[0;101m”, “QT_GRAPHICSSYSTEM_CHECKED=1”,
“On_IPurple=\e[0;105m”, “USER=marc”, “UBlack=\e[4;30m”, “IBlue=\e[0;94m”, “IBlack=\e[0;90m”,
“SSH_AUTH_SOCK=/run/user/1000/key”…, “ICyan=\e[0;96m”, “SESSION_MANAGER=local/unix:@/tmp”…,
“USERNAME=marc”, “On_ICyan=\e[0;106m”, “BYellow=\e[1;33m”, “On_IBlue=\e[0;104m”, “BIYellow=\e[1;93m”,
“BBlack=\e[1;30m”, “GUESTFISH_PS1=\[\e[1;32m\]><fs>\”…, “UCyan=\e[4;36m”, “BIPurple=\e[1;95m”,
“Cyan=\e[0;36m”, “MAIL=/var/spool/mail/marc”, “DESKTOP_SESSION=gnome”, “PATH=/oracle/product/11.2.0/clie”…,
“IRed=\e[0;91m”, “On_Black=\e[40m”, “BRed=\e[1;31m”, “QT_IM_MODULE=ibus”, “PWD=/tmp”, “UGreen=\e[4;32m”,
“XMODIFIERS=@im=ibus”, “IPurple=\e[0;95m”, “On_Cyan=\e[46m”, “BIBlack=\e[1;90m”, “LANG=en_US.utf8”,
“IYellow=\e[0;93m”, “MODULEPATH=/etc/scl/modulefiles:”…, “GDM_LANG=en_US.utf8”, “On_IWhite=\e[0;107m”,
“On_Blue=\e[44m”, “On_Yellow=\e[43m”, “KDEDIRS=/usr”, “GUESTFISH_OUTPUT=\e[0m”, “LOADEDMODULES=”,
“On_Green=\e[42m”, “On_Purple=\e[45m”, “UWhite=\e[4;37m”, “Yellow=\e[0;33m”, “PS1=\[\e[1;34m\]\u:\
[\e[1;32m\]\”…, “GDMSESSION=gnome”, “SSH_ASKPASS=/usr/libexec/openssh”…, “HISTCONTROL=ignoredups”,
“BIRed=\e[1;91m”, “IWhite=\e[0;97m”, “Red=\e[0;31m”, “XDG_SEAT=seat0”, “HOME=/home/marc”, “SHLVL=2”,
“IGreen=\e[0;92m”, “On_IBlack=\e[0;100m”, “GNOME_DESKTOP_SESSION_ID=this­is”…, “BWhite=\e[1;37m”,
“XDG_SESSION_DESKTOP=gnome”, “LOGNAME=marc”, “Blue=\e[0;34m”, “QTLIB=/usr/lib64/qt­3.3/lib”, “LS_OPTS=­­
color=auto”, “On_White=\e[47m”, “DBUS_SESSION_BUS_ADDRESS=unix:ab”…, “MODULESHOME=/usr/share/Modules”,
“BIBlue=\e[1;94m”, “LESSOPEN=||/usr/bin/lesspipe.sh “…, “UBlue=\e[4;34m”, “WINDOWPATH=1”,
“BIWhite=\e[1;97m”, “XDG_RUNTIME_DIR=/run/user/1000”, “DISPLAY=:0”, “BIGreen=\e[1;92m”, “BPurple=\e[1;35m”,
“XDG_CURRENT_DESKTOP=GNOME”, “ORACLE_HOME=/oracle/product/11.2″…, “GUESTFISH_RESTORE=\e[0m”,
“White=\e[0;37m”, “XAUTHORITY=/run/gdm/auth­for­mar”…, “BASH_FUNC_module()=() { eval `/”…,
“BASH_FUNC_scl()=() { local CMD=”…, “_=/usr/bin/strace”]) = 0

When strings are shown (e.g. read & write calls) they’re truncated to 32 characters by default. We can increase that limit by using the -s <integer> option. See below:

root:/tmp> strace cat test.1
read(3, “asdasdn1234567890 abcdefghijklmn”…, 65536) = 121
.
root:/tmp> strace ­-s 132 test.1
read(3, “asdasdn1234567890 abcdefghijklmnopqrstuvwxyz 1234567890 abcdefghijklmnopqrstuvwxyz
1234567890 abcdefghijklmnopqrstuvwxyzn”, 65536) = 121

If we need to know all the input of a process performed through read calls we can do so using the -e trace=read -e read=<list filehandles> option as shown below:

root:/tmp> strace ­-e trace=read -­e read=3 cat test.1
read(3, “asdasdn1234567890 abcdefghijklmn”…, 65536) = 121
| 00000 61 73 64 61 73 64 0a 31 32 33 34 35 36 37 38 39 asdasd.123456789 |
| 00010 30 20 61 62 63 64 65 66 67 68 69 6a 6b 6c 6d 6e 0 abcdefghijklmn |
| 00020 6f 70 71 72 73 74 75 76 77 78 79 7a 20 31 32 33 opqrstuvwxyz 123 |
| 00030 34 35 36 37 38 39 30 20 61 62 63 64 65 66 67 68 4567890 abcdefgh |
| 00040 69 6a 6b 6c 6d 6e 6f 70 71 72 73 74 75 76 77 78 ijklmnopqrstuvwx |
| 00050 79 7a 20 31 32 33 34 35 36 37 38 39 30 20 61 62 yz 1234567890 ab |
| 00060 63 64 65 66 67 68 69 6a 6b 6c 6d 6e 6f 70 71 72 cdefghijklmnopqr |
| 00070 73 74 75 76 77 78 79 7a 0a stuvwxyz. |
read(3, “”, 65536) = 0

The same can be done with write calls:

root:/tmp> strace ­-e trace=write -­e write=1 ./script.sh
write(1, “1234567890 abcdefghijklmnopqrstu”…, 114) = 114
| 00000 31 32 33 34 35 36 37 38 39 30 20 61 62 63 64 65 1234567890 abcde |
| 00010 66 67 68 69 6a 6b 6c 6d 6e 6f 70 71 72 73 74 75 fghijklmnopqrstu |
| 00020 76 77 78 79 7a 20 31 32 33 34 35 36 37 38 39 30 vwxyz 1234567890 |
| 00030 20 61 62 63 64 65 66 67 68 69 6a 6b 6c 6d 6e 6f abcdefghijklmno |
| 00040 70 71 72 73 74 75 76 77 78 79 7a 20 31 32 33 34 pqrstuvwxyz 1234 |
| 00050 35 36 37 38 39 30 20 61 62 63 64 65 66 67 68 69 567890 abcdefghi |
| 00060 6a 6b 6c 6d 6e 6f 70 71 72 73 74 75 76 77 78 79 jklmnopqrstuvwxy |
| 00070 7a 0a z.

Let’s remind ourselves that each process has 3 default filehandles: 0 (stdin), 1 (stdout) & 2 (stderr). Thus, the filehandle 3 opened in the read call in the example above should be an external file whereas the filehandle 1 opened in the write call is likely to be stdout.

If you think twice about the statement above… you should realise that you can intercept the input & output (screen output, keyboard input, file I/O, etc) of any session provided you are root or have the appropriate privileges. In the example below we get a dump of any writes in STDIN (keyboard) and any reads to STDOUT (display) of process 30266:

root:~> strace -e trace=read,write -e read=1 -e write=0 -p 30266
strace: Process 30266 attached
read(0, “l”, 1) = 1
write(2, “l”, 1) = 1
read(0, “s”, 1) = 1
write(2, “s”, 1) = 1
read(0, “r”, 1) = 1
write(2, “n”, 1) = 1
— SIGCHLD {si_signo=SIGCHLD, si_code=CLD_EXITED, si_pid=1751, si_uid=1000, si_status=0, si_utime=0, si_stime=0} —
read(3, “lsn”, 128) = 3
read(3, “”, 128) = 0
— SIGCHLD {si_signo=SIGCHLD, si_code=CLD_EXITED, si_pid=1753, si_uid=1000, si_status=0, si_utime=0, si_stime=0} —
read(3, “33]7;file://envy17/home/marc7”, 128) = 28
read(3, “”, 128) = 0
— SIGCHLD {si_signo=SIGCHLD, si_code=CLD_EXITED, si_pid=1756, si_uid=1000, si_status=0, si_utime=0, si_stime=0} —
write(1, “33]777;notify;Command completed;l”…, 80) = 80
write(2, “33[1;34mmarc:33[1;32m~> 33[0m”, 26) = 26
read(0, “d”, 1) = 1
write(2, “d”, 1) = 1
read(0, “a”, 1) = 1
write(2, “a”, 1) = 1
read(0, “t”, 1) = 1
write(2, “t”, 1) = 1
read(0, “e”, 1) = 1
write(2, “e”, 1) = 1
read(0, “r”, 1) = 1
write(2, “n”, 1) = 1
— SIGCHLD {si_signo=SIGCHLD, si_code=CLD_EXITED, si_pid=1759, si_uid=1000, si_status=0, si_utime=0, si_stime=0} —
read(3, “daten”, 128) = 5
read(3, “”, 128) = 0
— SIGCHLD {si_signo=SIGCHLD, si_code=CLD_EXITED, si_pid=1760, si_uid=1000, si_status=0, si_utime=0, si_stime=0} —
read(3, “33]7;file://envy17/home/marc7”, 128) = 28
read(3, “”, 128) = 0
— SIGCHLD {si_signo=SIGCHLD, si_code=CLD_EXITED, si_pid=1763, si_uid=1000, si_status=0, si_utime=0, si_stime=0} —
write(1, “33]777;notify;Command completed;d”…, 82) = 82
write(2, “33[1;34mmarc:33[1;32m~> 33[0m”, 26) = 26

The -e trace=syscall option is used to filter just the syscalls we are interested on. For example, if we just want to see what files a process accesses…

root:/tmp> strace -­e trace=open ./script.sh
open(“/etc/ld.so.cache”, O_RDONLY|O_CLOEXEC) = 3
open(“/lib64/libtinfo.so.5”, O_RDONLY|O_CLOEXEC) = 3
open(“/lib64/libdl.so.2”, O_RDONLY|O_CLOEXEC) = 3
open(“/lib64/libc.so.6”, O_RDONLY|O_CLOEXEC) = 3
open(“/dev/tty”, O_RDWR|O_NONBLOCK) = 3
open(“/usr/lib/locale/locale­archive”, O_RDONLY|O_CLOEXEC) = 3
open(“/proc/meminfo”, O_RDONLY|O_CLOEXEC) = 3
open(“/usr/lib64/gconv/gconv­modules.cache”, O_RDONLY) = 3
open(“./script.sh”, O_RDONLY) = 3
open(“/tmp/3”, O_WRONLY|O_CREAT|O_TRUNC, 0666) = 3
.
root:/tmp> strace -­e trace=open,close ./script.sh
open(“/etc/ld.so.cache”, O_RDONLY|O_CLOEXEC) = 3
close(3) = 0
open(“/lib64/libtinfo.so.5”, O_RDONLY|O_CLOEXEC) = 3
close(3) = 0
open(“/lib64/libdl.so.2”, O_RDONLY|O_CLOEXEC) = 3
close(3) = 0
open(“/lib64/libc.so.6”, O_RDONLY|O_CLOEXEC) = 3
close(3) = 0
open(“/dev/tty”, O_RDWR|O_NONBLOCK) = 3
close(3) = 0
open(“/usr/lib/locale/locale­archive”, O_RDONLY|O_CLOEXEC) = 3
close(3) = 0
open(“/proc/meminfo”, O_RDONLY|O_CLOEXEC) = 3
close(3) = 0
open(“/usr/lib64/gconv/gconv­modules.cache”, O_RDONLY) = 3
close(3) = 0
open(“./script.sh”, O_RDONLY) = 3
close(3) = 0
open(“/tmp/3”, O_WRONLY|O_CREAT|O_TRUNC, 0666) = 3
close(3) = 0
close(10) = 0

If we are interested in file related syscalls and nothing else we should use -e trace=file:

root:/tmp> strace ­-e trace=file ./script.sh
execve(“./script.sh”, [“./script.sh”], [/* 99 vars */]) = 0
access(“/etc/ld.so.preload”, R_OK) = ­1 ENOENT (No such file or directory)
open(“/etc/ld.so.cache”, O_RDONLY|O_CLOEXEC) = 3
open(“/lib64/libtinfo.so.5”, O_RDONLY|O_CLOEXEC) = 3
open(“/lib64/libdl.so.2”, O_RDONLY|O_CLOEXEC) = 3
open(“/lib64/libc.so.6”, O_RDONLY|O_CLOEXEC) = 3
open(“/dev/tty”, O_RDWR|O_NONBLOCK) = 3
open(“/usr/lib/locale/locale­archive”, O_RDONLY|O_CLOEXEC) = 3
open(“/proc/meminfo”, O_RDONLY|O_CLOEXEC) = 3
open(“/usr/lib64/gconv/gconv­modules.cache”, O_RDONLY) = 3
stat(“/tmp”, {st_mode=S_IFDIR|S_ISVTX|0777, st_size=12288, …}) = 0
stat(“.”, {st_mode=S_IFDIR|S_ISVTX|0777, st_size=12288, …}) = 0
open(“./script.sh”, O_RDONLY) = 3
open(“/tmp/3”, O_WRONLY|O_CREAT|O_TRUNC, 0666) = 3
stat(“.”, {st_mode=S_IFDIR|S_ISVTX|0777, st_size=12288, …}) = 0
stat(“/sbin/cat”, 0x7ffd45e4b6b0) = ­1 ENOENT (No such file or directory)
stat(“/bin/cat”, {st_mode=S_IFREG|0755, st_size=54104, …}) = 0
stat(“/bin/cat”, {st_mode=S_IFREG|0755, st_size=54104, …}) = 0
access(“/bin/cat”, X_OK) = 0
stat(“/bin/cat”, {st_mode=S_IFREG|0755, st_size=54104, …}) = 0
access(“/bin/cat”, R_OK) = 0
stat(“/bin/cat”, {st_mode=S_IFREG|0755, st_size=54104, …}) = 0
stat(“/bin/cat”, {st_mode=S_IFREG|0755, st_size=54104, …}) = 0
access(“/bin/cat”, X_OK) = 0
stat(“/bin/cat”, {st_mode=S_IFREG|0755, st_size=54104, …}) = 0
access(“/bin/cat”, R_OK) = 0

If we just need to investigate the syscalls targeting a certain file we should use -P filepath:

root:/tmp> strace ­-P /tmp/3 ./script.sh
open(“/tmp/3”, O_WRONLY|O_CREAT|O_TRUNC, 0666) = 3
dup2(3, 1) = 1
close(3) = 0
fstat(1, {st_mode=S_IFREG|0644, st_size=0, …}) = 0
write(1, “1234567890 abcdefghijklmnopqrstu”…, 114) = 114
dup2(10, 1)

If we just need to analyse process management related syscalls we should use -e trace=process:

root:/tmp> strace ­-e trace=process ./script.sh
execve(“./script.sh”, [“./script.sh”], [/* 99 vars */]) = 0
arch_prctl(ARCH_SET_FS, 0x7f6d64c64700) = 0
clone(child_stack=0, flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD, child_tidptr=0x7f6d64c649d0) =
17593
wait4(­1, 1234567890 abcdefghijklmnopqrstuvwxyz 1234567890 abcdefghijklmnopqrstuvwxyz 1234567890
abcdefghijklmnopqrstuvwxyz
[{WIFEXITED(s) && WEXITSTATUS(s) == 0}], 0, NULL) = 17593
— SIGCHLD {si_signo=SIGCHLD, si_code=CLD_EXITED, si_pid=17593, si_uid=0, si_status=0, si_utime=0, si_stime=0}

wait4(­1, 0x7ffeeae5da90, WNOHANG, NULL) = ­1 ECHILD (No child processes)
exit_group(0)

If we just need to analyse network related syscalls we should use -e trace=network:

root:/tmp> strace -­f -­e trace=network ./script.sh
Process 17963 attached
[pid 17963] socket(PF_INET, SOCK_RAW, IPPROTO_ICMP) = 3
[pid 17963] socket(PF_INET, SOCK_DGRAM, IPPROTO_IP) = 4
[pid 17963] connect(4, {sa_family=AF_INET, sin_port=htons(1025), sin_addr=inet_addr(“124.240.25.220”)}, 16) = 0
[pid 17963] getsockname(4, {sa_family=AF_INET, sin_port=htons(28354), sin_addr=inet_addr(“24.240.25.220”)},
[16]) = 0
[pid 17963] setsockopt(3, SOL_RAW, ICMP_FILTER, ~(ICMP_ECHOREPLY|ICMP_DEST_UNREACH|ICMP_SOURCE_QUENCH|
ICMP_REDIRECT|ICMP_TIME_EXCEEDED|ICMP_PARAMETERPROB), 4) = 0
[pid 17963] setsockopt(3, SOL_IP, IP_RECVERR, [1], 4) = 0
[pid 17963] setsockopt(3, SOL_SOCKET, SO_SNDBUF, [324], 4) = 0
[pid 17963] setsockopt(3, SOL_SOCKET, SO_RCVBUF, [65536], 4) = 0
[pid 17963] getsockopt(3, SOL_SOCKET, SO_RCVBUF, [131072], [4]) = 0
PING 124.240.25.220 (124.240.25.220) 56(84) bytes of data.
[pid 17963] setsockopt(3, SOL_SOCKET, SO_TIMESTAMP, [1], 4) = 0
[pid 17963] setsockopt(3, SOL_SOCKET, SO_SNDTIMEO, “1���������������”, 16) = 0
[pid 17963] setsockopt(3, SOL_SOCKET, SO_RCVTIMEO, “1���������������”, 16) = 0
[pid 17963] sendmsg(3, {msg_name(16)={sa_family=AF_INET, sin_port=htons(0),
sin_addr=inet_addr(“124.240.25.220”)},
msg_iov(1)=[{“10�20SF+�1p256(V����F2513�����2021222324252627″…, 64}],
msg_controllen=0, msg_flags=0}, 0) = 64
[pid 17963] recvmsg(3, 0x7ffff2745e90, 0) = ­1 EAGAIN (Resource temporarily unavailable)
[pid 17963] recvmsg(3, 0x7ffff2745e90, 0) = ­1 EAGAIN (Resource temporarily unavailable)
[pid 17963] recvmsg(3, 0x7ffff2745e90, 0) = ­1 EAGAIN (Resource temporarily unavailable)
[pid 17963] recvmsg(3, 0x7ffff2745e90, 0) = ­1 EAGAIN (Resource temporarily unavailable)
[pid 17963] recvmsg(3, 0x7ffff2745e90, 0) = ­1 EINTR (Interrupted system call)

If we just need to analyse signal related syscalls we should use -e trace=signal:

root:/tmp> strace -­f -­e trace=signal ./script.sh
rt_sigprocmask(SIG_BLOCK, NULL, [], 8) = 0
rt_sigaction(SIGCHLD, {SIG_DFL, [], SA_RESTORER|SA_RESTART, 0x7f38d307}, {SIG_DFL, [], 0}, 8) = 0
rt_sigaction(SIGCHLD, {SIG_DFL, [], SA_RESTORER|SA_RESTART, 0x7f38d307}, {SIG_DFL, [], SA_RESTORER|SA_RESTART,
0x7f38d307}, 8) = 0
rt_sigaction(SIGINT, {SIG_DFL, [], SA_RESTORER, 0x7f38d307}, {SIG_DFL, [], 0}, 8) = 0
rt_sigaction(SIGINT, {SIG_DFL, [], SA_RESTORER, 0x7f38d307}, {SIG_DFL, [], SA_RESTORER, 0x7f38d307}, 8) = 0
rt_sigaction(SIGQUIT, {SIG_DFL, [], SA_RESTORER, 0x7f38d307}, {SIG_DFL, [], 0}, 8) = 0
rt_sigaction(SIGQUIT, {SIG_DFL, [], SA_RESTORER, 0x7f38d307}, {SIG_DFL, [], SA_RESTORER, 0x7f38d307}, 8) = 0
rt_sigprocmask(SIG_BLOCK, NULL, [], 8) = 0

If we just need to analyse memory related syscalls we should use -e trace=memory:

root:/tmp> strace ­-f -­e trace=memory ./script.sh
brk(0) = 0x55d5fedca000
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, ­1, 0) = 0x7f9c085c2000
mmap(NULL, 118326, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7f9c085a5000
mmap(NULL, 2269152, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f9c08178000
mprotect(0x7f9c0819e000, 2093056, PROT_NONE) = 0

If we just need to analyse file descriptor related syscalls we should use -e trace=desc:

root:/tmp> strace ­-f ­-e trace=desc ./script.sh
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, ­1, 0) = 0x7fa30dbf5000
open(“/etc/ld.so.cache”, O_RDONLY|O_CLOEXEC) = 3
fstat(3, {st_mode=S_IFREG|0644, st_size=118326, …}) = 0
mmap(NULL, 118326, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7fa30dbd8000
close(3) = 0
open(“/lib64/libtinfo.so.5”, O_RDONLY|O_CLOEXEC) = 3
read(3, “177ELF211���������3�>�1���@316������”…, 832) = 832
fstat(3, {st_mode=S_IFREG|0755, st_size=173136, …}) = 0
mmap(NULL, 2269152, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7fa30d7ab000
mmap(0x7fa30d9d0000, 20480, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x25000) = 0x7fa30d9d0000
close(3) = 0
open(“/lib64/libdl.so.2”, O_RDONLY|O_CLOEXEC) = 3
read(3, “177ELF211���������3�>�1���32016������”…, 832) = 832
fstat(3, {st_mode=S_IFREG|0755, st_size=19512, …}) = 0

If we just need to analyse IPC related syscalls we should use -e trace=ipc:

root:/tmp> strace ­-f ­-e trace=ipc ./script.sh

Finally, if we are root we can run a script as some other user, setting and unsetting environment variables as required. For example…

root:/tmp> strace ­-u oracle ­-e trace=network -­E ORACLE_HOME=$ORACLE_HOME ­-E var3 ./tnsping.sh

… would execute the script tnsping.sh logged in as oracle setting the specified environment variables.

<< watch                  mpstat >>