Mar 31, 2012

Monitoring system calls on your linux: strace

Today i wanted to see the system calls of one of my processes on my laptop. A nice tool for doing this is strace. On a debian system you can this via
apt-get install strace
If you want to see, what your bash is doing just take the PID of your bash and do in another shell:
schroff@hades:$ strace -p 25551
Process 25551 attached - interrupt to quit
read(0,
Doing a ls results in something like this:
Process 25551 attached - interrupt to quit
read(0, "l", 1)                         = 1
rt_sigprocmask(SIG_BLOCK, [INT], [], 8) = 0
write(2, "l", 1)                        = 1
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
rt_sigprocmask(SIG_BLOCK, NULL, [], 8)  = 0
read(0, "s", 1)                         = 1
rt_sigprocmask(SIG_BLOCK, [INT], [], 8) = 0
write(2, "s", 1)                        = 1
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
rt_sigprocmask(SIG_BLOCK, NULL, [], 8)  = 0
read(0, "\r", 1)                        = 1
write(2, "\n", 1)                       = 1
rt_sigprocmask(SIG_BLOCK, [INT], [], 8) = 0
ioctl(0, SNDCTL_TMR_TIMEBASE or TCGETS, {B38400 opost isig -icanon -echo ...}) = 0
ioctl(0, SNDCTL_TMR_STOP or TCSETSW, {B38400 opost isig icanon echo ...}) = 0
ioctl(0, SNDCTL_TMR_TIMEBASE or TCGETS, {B38400 opost isig icanon echo ...}) = 0
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
rt_sigaction(SIGINT, {0x809c7c0, [], 0}, {0x80e2d40, [], 0}, 8) = 0
rt_sigaction(SIGTERM, {SIG_IGN, [], 0}, {SIG_IGN, [], 0}, 8) = 0
rt_sigaction(SIGQUIT, {SIG_IGN, [], 0}, {SIG_IGN, [], 0}, 8) = 0
rt_sigaction(SIGALRM, {0x809c500, [HUP INT ILL TRAP ABRT BUS FPE USR1 SEGV USR2 PIPE ALRM TERM XCPU XFSZ VTALRM SYS], 0}, {0x80e2d40, [], 0}, 8) = 0
rt_sigaction(SIGTSTP, {SIG_IGN, [], 0}, {SIG_IGN, [], 0}, 8) = 0
rt_sigaction(SIGTTOU, {SIG_IGN, [], 0}, {SIG_IGN, [], 0}, 8) = 0
rt_sigaction(SIGTTIN, {SIG_IGN, [], 0}, {SIG_IGN, [], 0}, 8) = 0
rt_sigaction(SIGWINCH, {0x809c310, [], 0}, {0x80e2c20, [], SA_RESTART}, 8) = 0
rt_sigaction(SIGINT, {0x809c7c0, [], 0}, {0x809c7c0, [], 0}, 8) = 0
time(NULL)                              = 1333218356
rt_sigprocmask(SIG_BLOCK, [INT CHLD], [], 8) = 0
pipe([3, 4])                            = 0
clone(child_stack=0, flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD, child_tidptr=0xb766f728) = 27965
setpgid(27965, 27965)                   = 0
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
rt_sigprocmask(SIG_BLOCK, [CHLD], [], 8) = 0
close(3)                                = 0
close(4)                                = 0
ioctl(255, TIOCGPGRP, [25551])          = 0
rt_sigprocmask(SIG_BLOCK, [CHLD TSTP TTIN TTOU], [CHLD], 8) = 0
ioctl(255, TIOCSPGRP, [27965])          = 0
rt_sigprocmask(SIG_SETMASK, [CHLD], NULL, 8) = 0
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
rt_sigprocmask(SIG_BLOCK, [CHLD], [], 8) = 0
waitpid(-1, [{WIFEXITED(s) && WEXITSTATUS(s) == 0}], WSTOPPED|WCONTINUED) = 27965
rt_sigprocmask(SIG_BLOCK, [CHLD TSTP TTIN TTOU], [CHLD], 8) = 0
ioctl(255, TIOCSPGRP, [25551])          = 0
rt_sigprocmask(SIG_SETMASK, [CHLD], NULL, 8) = 0
ioctl(255, SNDCTL_TMR_TIMEBASE or TCGETS, {B38400 opost isig icanon echo ...}) = 0
ioctl(255, TIOCGWINSZ, {ws_row=24, ws_col=80, ws_xpixel=499, ws_ypixel=316}) = 0
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
--- SIGCHLD (Child exited) @ 0 (0) ---
waitpid(-1, 0xbfc693fc, WNOHANG|WSTOPPED|WCONTINUED) = -1 ECHILD (No child processes)
sigreturn()                             = ? (mask now [])
rt_sigprocmask(SIG_BLOCK, NULL, [], 8)  = 0
rt_sigaction(SIGINT, {0x809c7c0, [], 0}, {0x809c7c0, [], 0}, 8) = 0
rt_sigprocmask(SIG_BLOCK, NULL, [], 8)  = 0
write(1, "\33]0;schroff@hades: /tmp\7", 24) = 24
stat64("/home/schroff/.bash_history", {st_mode=S_IFREG|0644, st_size=316074, ...}) = 0
open("/home/schroff/.bash_history", O_WRONLY|O_APPEND|O_LARGEFILE) = 3
write(3, "ls\n", 3)                     = 3
close(3)                                = 0
time(NULL)                              = 1333218356
time(NULL)                              = 1333218356
rt_sigprocmask(SIG_BLOCK, [CHLD TSTP TTIN TTOU], [], 8) = 0
ioctl(255, TIOCSPGRP, [25551])          = 0
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
rt_sigaction(SIGINT, {0x809c7c0, [], 0}, {0x809c7c0, [], 0}, 8) = 0
rt_sigprocmask(SIG_BLOCK, [INT], [], 8) = 0
ioctl(0, TIOCGWINSZ, {ws_row=24, ws_col=80, ws_xpixel=499, ws_ypixel=316}) = 0
ioctl(0, TIOCSWINSZ, {ws_row=24, ws_col=80, ws_xpixel=499, ws_ypixel=316}) = 0
ioctl(0, SNDCTL_TMR_TIMEBASE or TCGETS, {B38400 opost isig icanon echo ...}) = 0
ioctl(0, SNDCTL_TMR_TIMEBASE or TCGETS, {B38400 opost isig icanon echo ...}) = 0
ioctl(0, SNDCTL_TMR_STOP or TCSETSW, {B38400 opost isig -icanon -echo ...}) = 0
ioctl(0, SNDCTL_TMR_TIMEBASE or TCGETS, {B38400 opost isig -icanon -echo ...}) = 0
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
rt_sigprocmask(SIG_BLOCK, [INT QUIT ALRM TERM TSTP TTIN TTOU], [], 8) = 0
rt_sigaction(SIGINT, {0x80e2d40, [], 0}, {0x809c7c0, [], 0}, 8) = 0
rt_sigaction(SIGTERM, {0x80e2d40, [], 0}, {SIG_IGN, [], 0}, 8) = 0
rt_sigaction(SIGTERM, {SIG_IGN, [], 0}, {0x80e2d40, [], 0}, 8) = 0
rt_sigaction(SIGQUIT, {0x80e2d40, [], 0}, {SIG_IGN, [], 0}, 8) = 0
rt_sigaction(SIGQUIT, {SIG_IGN, [], 0}, {0x80e2d40, [], 0}, 8) = 0
rt_sigaction(SIGALRM, {0x80e2d40, [], 0}, {0x809c500, [HUP INT ILL TRAP ABRT BUS FPE USR1 SEGV USR2 PIPE ALRM TERM XCPU XFSZ VTALRM SYS], 0}, 8) = 0
rt_sigaction(SIGTSTP, {0x80e2d40, [], 0}, {SIG_IGN, [], 0}, 8) = 0
rt_sigaction(SIGTSTP, {SIG_IGN, [], 0}, {0x80e2d40, [], 0}, 8) = 0
rt_sigaction(SIGTTOU, {0x80e2d40, [], 0}, {SIG_IGN, [], 0}, 8) = 0
rt_sigaction(SIGTTOU, {SIG_IGN, [], 0}, {0x80e2d40, [], 0}, 8) = 0
rt_sigaction(SIGTTIN, {0x80e2d40, [], 0}, {SIG_IGN, [], 0}, 8) = 0
rt_sigaction(SIGTTIN, {SIG_IGN, [], 0}, {0x80e2d40, [], 0}, 8) = 0
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
rt_sigaction(SIGWINCH, {0x80e2c20, [], SA_RESTART}, {0x809c310, [], 0}, 8) = 0
rt_sigprocmask(SIG_BLOCK, [INT], [], 8) = 0
write(2, "schroff@hades:$ ", 16)        = 16
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
rt_sigprocmask(SIG_BLOCK, NULL, [], 8)  = 0
read(0, ^[[B
Ok - a lot of output and not really readable. But with -o you can pipe the output into a file and this you can use for statistics:
schroff@hades:$ cat /tmp/test |awk -F \( '{print $1}'|sort|uniq -c|sort -n
      1 clone
      1 open
      1 pipe
      1 setpgid
      1 --- SIGCHLD
      1 sigreturn
      1 stat64
      2 waitpid
      3 close
      3 time
      4 read
      6 write
     15 ioctl
     24 rt_sigaction
     29 rt_sigprocmask
Ok, it is not clear if this is more helpful, but you can at least see what files are opened by your program very easily:
 open("/foo/bar", O_RDONLY) = -1 ENOENT (No such file or directory)
Or you can detect all signals sent to this program, like shown here:
--- SIGTERM (Terminated) @ 0 (0) ---
read(0,  <unfinished ...>
+++ killed by SIGKILL +++

No comments:

Post a Comment