Strace
Jump to navigation
Jump to search
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)