Strace

Overview

리눅스 명령어 strace 내용 정리

Basic

strace 는 프로세스의 system call 및 signal 을 추적한다. 이를 이용하면 프로세스에서 어떤 system call/signal 을 과도하게 사용하고 있는지를 확인할 수 있다. 프로세스 시작때부터 같이 실행할 필요 없이, 이미 기존에 동작중인 프로세스의 pid 를 이용하여 추적이 가능하기 때문에, 언제든 사용율을 확인할 수 있다.

Synopsis

  strace [-CdffhiqrtttTvVxxy] [-In] [-bexecve] [-eexpr]...  [-acolumn] [-ofile] [-sstrsize] [-Ppath]... -ppid... / [-D] [-Evar[=val]]... [-uusername] command [args]

  strace -c[df] [-In] [-bexecve] [-eexpr]...  [-Ooverhead] [-Ssortby] -ppid... / [-D] [-Evar[=val]]... [-uusername] command [args]

Usage

usage: strace [-CdffhiqrtttTvVxxy] [-I n] [-e expr]...
              [-a column] [-o file] [-s strsize] [-P path]...
              -p pid... / [-D] [-E var=val]... [-u username] PROG [ARGS]
   or: strace -c[df] [-I n] [-e expr]... [-O overhead] [-S sortby]
              -p pid... / [-D] [-E var=val]... [-u username] PROG [ARGS]
-c -- count time, calls, and errors for each syscall and report summary
-C -- like -c but also print regular output
-d -- enable debug output to stderr
-D -- run tracer process as a detached grandchild, not as parent
-f -- follow forks, -ff -- with output into separate files
-i -- print instruction pointer at time of syscall
-q -- suppress messages about attaching, detaching, etc.
-r -- print relative timestamp, -t -- absolute timestamp, -tt -- with usecs
-T -- print time spent in each syscall
-v -- verbose mode: print unabbreviated argv, stat, termios, etc. args
-x -- print non-ascii strings in hex, -xx -- print all strings in hex
-y -- print paths associated with file descriptor arguments
-h -- print help message, -V -- print version
-a column -- alignment COLUMN for printing syscall results (default 40)
-b execve -- detach on this syscall
-e expr -- a qualifying expression: option=[!]all or option=[!]val1[,val2]...
   options: trace, abbrev, verbose, raw, signal, read, write
-I interruptible --
   1: no signals are blocked
   2: fatal signals are blocked while decoding syscall (default)
   3: fatal signals are always blocked (default if '-o FILE PROG')
   4: fatal signals and SIGTSTP (^Z) are always blocked
      (useful to make 'strace -o FILE PROG' not stop on ^Z)
-o file -- send trace output to FILE instead of stderr
-O overhead -- set overhead for tracing syscalls to OVERHEAD usecs
-p pid -- trace process with process id PID, may be repeated
-s strsize -- limit length of print strings to STRSIZE chars (default 32)
-S sortby -- sort syscall counts by: time, calls, name, nothing (default time)
-u username -- run command as username handling setuid and/or setgid
-E var=val -- put var=val in the environment for command
-E var -- remove var from the environment for command
-P path -- trace accesses to path

Example

Too much CPU use

$ sudo time strace -c -p 19268
Process 19268 attached
^CProcess 19268 detached
% time     seconds  usecs/call     calls    errors syscall
------ ----------- ----------- --------- --------- ----------------
 41.99    0.006640           0   1302011           read
 32.11    0.005078           0   1302091           lseek
 25.30    0.004000          20       198           epoll_wait
  0.34    0.000053           0      1957           fcntl
  0.18    0.000029           0       430       430 access
  0.08    0.000013           0        34           munmap
  0.00    0.000000           0        45           write
  0.00    0.000000           0       102           open
  0.00    0.000000           0       102           close
  0.00    0.000000           0       509           fstat
  0.00    0.000000           0        34           mmap
  0.00    0.000000           0        11           ftruncate
  0.00    0.000000           0        34           unlink
------ ----------- ----------- --------- --------- ----------------
100.00    0.015813               2607558       430 total

real    0m33.987s
user    0m4.794s
sys     0m13.986s

하나의 프로세스에서 30% 가량의 CPU 사용율을 나타내서 strace를 돌려 확인한 내용이다. 위의 내용을 보면 과도한 read/lseek 사용 빈도를 확인할 수 있다. 내부적으로 sqlite3 를 사용하고 있었는데, 과도한 query 질의가 원인이었다.

Trace error

strace 에서 확인된 error 내용을 따라갈 수도 있다.

# strace -v -o calls.txt -e access -p 26293

# cat calls.txt
access("/opt/bin/sms_manage.db-journal", F_OK) = -1 ENOENT (No such file or directory)
access("/opt/bin/sms_manage.db-journal", F_OK) = -1 ENOENT (No such file or directory)
access("/opt/bin/sms_manage.db-journal", F_OK) = -1 ENOENT (No such file or directory)
access("/opt/bin/sms_manage.db-journal", F_OK) = -1 ENOENT (No such file or directory)