Strace

From 탱이의 잡동사니
Jump to navigation Jump to search
The printable version is no longer supported and may have rendering errors. Please update your browser bookmarks and please use the default browser print function instead.

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)