strace는 SunOS에서 System Call을 Trace를 하기위해서 만들어진 Debug Tool이며, 이를 이용하여 실행중인 Program도 Trace가 가능하다.
$ sudo apt-get install strace
https://en.wikipedia.org/wiki/Strace
1.1 STRACE 기본사용법
$ strace -h
usage: strace [-CdffhiqrtttTvVwxxy] [-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[dfw] [-I n] [-e expr]... [-O overhead] [-S sortby]
-p pid... / [-D] [-E var=val]... [-u username] PROG [ARGS]
Output format:
-a column alignment COLUMN for printing syscall results (default 40)
-i print instruction pointer at time of syscall
-o file send trace output to FILE instead of stderr
-q suppress messages about attaching, detaching, etc.
-r print relative timestamp
-s strsize limit length of print strings to STRSIZE chars (default 32)
-t print absolute timestamp
-tt print absolute timestamp with usecs
-T print time spent in each syscall
-x print non-ascii strings in hex
-xx print all strings in hex
-y print paths associated with file descriptor arguments
-yy print ip:port pairs associated with socket file descriptors
Statistics:
-c count time, calls, and errors for each syscall and report summary
-C like -c but also print regular output
-O overhead set overhead for tracing syscalls to OVERHEAD usecs
-S sortby sort syscall counts by: time, calls, name, nothing (default time)
-w summarise syscall latency (default is system time)
Filtering:
-e expr a qualifying expression: option=[!]all or option=[!]val1[,val2]...
options: trace, abbrev, verbose, raw, signal, read, write
-P path trace accesses to path
Tracing:
-b execve detach on execve syscall
-D run tracer process as a detached grandchild, not as parent
-f follow forks
-ff follow forks with output into separate files
-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)
Startup:
-E var remove var from the environment for command
-E var=val put var=val in the environment for command
-p pid trace process with process id PID, may be repeated
-u username run command as username handling setuid and/or setgid
Miscellaneous:
-d enable debug output to stderr
-v verbose mode: print unabbreviated argv, stat, termios, etc. args
-h print help message
-V print version
http://man7.org/linux/man-pages/man1/strace.1.html
1.2 /proc를 이용하여 동작중인 Process 확인
$ sudo cat /proc/550/maps // 실행과 관련된 공유라이브러리 확인 $ sudo cat /proc/550/status // Process 상태확인 $ readelf -h /proc/550/exe // 실행파일 확인 $ readelf -s /proc/550/exe // symbol table 확인
1.3 PID 기반으로 STRACE 사용
동작 중이 Process 기반으로 아래와 같이 PID를 넣어 직접 Profile을 해보고 Debug을 해봅니다.
- 상위 동작 중인 PID 기반으로 Debug
$ strace -p 550 -f -t -s 65535 // -p PID -f fork된 밑에 process들도 같이 분석, -t timestamp 출력 -s string 사이즈 변경
...........
[pid 994] 11:25:13 pselect6(0, NULL, NULL, NULL, {0, 10000000}, NULL) = 0 (Timeout)
[pid 994] 11:25:13 fstat(31, {st_mode=S_IFREG|0444, st_size=0, ...}) = 0
[pid 994] 11:25:13 fstat(31, {st_mode=S_IFREG|0444, st_size=0, ...}) = 0
[pid 994] 11:25:13 read(31, "count 180\nunhandled 0\nlast_unhan"..., 1024) = 42
...............
$ strace -p 550 -f -tt // -p PID -f fork된 밑에 process들도 같이 분석, -t timestamp 출력
[pid 994] 11:30:52.563464 fstat(31, {st_mode=S_IFREG|0444, st_size=0, ...}) = 0
[pid 994] 11:30:52.563761 fstat(31, {st_mode=S_IFREG|0444, st_size=0, ...}) = 0
[pid 994] 11:30:52.564047 read(31, "count 180\nunhandled 0\nlast_unhan"..., 1024) = 42
- System Call 함수의 호출의 통계
$ strace -cp 550 -f // -p PID -f fork된 밑에 process들도 같이 분석, -c count call
strace: Process 550 attached with 4 threads
^Cstrace: Process 550 detached
strace: Process 743 detached
strace: Process 994 detached
strace: Process 995 detached
% time seconds usecs/call calls errors syscall
------ ----------- ----------- --------- --------- ----------------
98.67 0.488000 1132 431 pselect6
0.94 0.004653 12 382 sendto
0.13 0.000666 2 382 openat
0.10 0.000495 1 382 close
0.09 0.000457 1 764 fstat
0.06 0.000310 1 382 read
0.00 0.000000 0 4 2 futex
------ ----------- ----------- --------- --------- ----------------
100.00 0.494581 2727 2 total
1.4 STRACE 사용
보통 아래와 같이 본인이 trace하고 싶은 app과 함께 같이 사용을 하며, 현재 test program을 없기에, ps command를 분석한다.
$ strace -c >/dev/null ps // ps program 내부 system call 분석 , ps의 내용은 /dev/null 출력
% time seconds usecs/call calls errors syscall
------ ----------- ----------- --------- --------- ----------------
38.53 0.012719 46 279 read
24.46 0.008074 31 260 6 open
13.92 0.004595 18 254 close
9.01 0.002973 25 119 3 stat64
3.72 0.001227 29 43 mmap2
2.82 0.000932 29 32 mprotect
1.75 0.000577 289 2 getdents64
1.25 0.000412 16 25 fstat64
1.17 0.000385 14 28 lseek
0.99 0.000328 14 24 rt_sigaction
0.99 0.000327 20 16 15 access
0.31 0.000102 51 2 2 statfs
0.31 0.000101 51 2 munmap
0.18 0.000061 15 4 3 ioctl
0.11 0.000035 12 3 brk
0.09 0.000031 16 2 _llseek
0.06 0.000021 21 1 cacheflush
0.05 0.000018 18 1 futex
0.05 0.000016 16 1 ugetrlimit
0.05 0.000015 15 1 set_tid_address
0.04 0.000014 14 1 rt_sigprocmask
0.04 0.000014 14 1 set_tls
0.04 0.000013 13 1 geteuid32
0.04 0.000013 13 1 set_robust_list
0.03 0.000009 9 1 write
0.00 0.000000 0 1 execve
0.00 0.000000 0 1 uname
------ ----------- ----------- --------- --------- ----------------
100.00 0.033012 1106 29 total
$ strace -e open >/dev/null ps // ps 프로그램에서 open만 검색
open("/etc/ld.so.preload", O_RDONLY|O_CLOEXEC) = 3
open("/usr/lib/arm-linux-gnueabihf/libarmmem.so", O_RDONLY|O_CLOEXEC) = 3
open("/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3
open("/lib/arm-linux-gnueabihf/libprocps.so.6", O_RDONLY|O_CLOEXEC) = 3
open("/lib/arm-linux-gnueabihf/libdl.so.2", O_RDONLY|O_CLOEXEC) = 3
open("/lib/arm-linux-gnueabihf/libc.so.6", O_RDONLY|O_CLOEXEC) = 3
open("/lib/arm-linux-gnueabihf/libsystemd.so.0", O_RDONLY|O_CLOEXEC) = 3
open("/lib/arm-linux-gnueabihf/libselinux.so.1", O_RDONLY|O_CLOEXEC) = 3
open("/lib/arm-linux-gnueabihf/librt.so.1", O_RDONLY|O_CLOEXEC) = 3
open("/lib/arm-linux-gnueabihf/liblzma.so.5", O_RDONLY|O_CLOEXEC) = 3
open("/usr/lib/arm-linux-gnueabihf/liblz4.so.1", O_RDONLY|O_CLOEXEC) = 3
open("/lib/arm-linux-gnueabihf/libgcrypt.so.20", O_RDONLY|O_CLOEXEC) = 3
open("/lib/arm-linux-gnueabihf/libgcc_s.so.1", O_RDONLY|O_CLOEXEC) = 3
open("/lib/arm-linux-gnueabihf/libpthread.so.0", O_RDONLY|O_CLOEXEC) = 3
open("/lib/arm-linux-gnueabihf/libpcre.so.3", O_RDONLY|O_CLOEXEC) = 3
open("/lib/arm-linux-gnueabihf/libgpg-error.so.0", O_RDONLY|O_CLOEXEC) = 3
.......
https://hokstad.com/5-simple-ways-to-troubleshoot-using-strace
http://www.brendangregg.com/perf.html
https://brunch.co.kr/@alden/12
http://linuxspot.tistory.com/253