Compute

How to use strace in vCenter

haewon83 2023. 5. 25. 00:32

vCenter는 Photon OS를 이용하는 Appliance 중 하나로, 다른 Linux와 마찬가지로 strace를 built-in 도구로 가지고 있습니다.

오늘은 이 strace를 vCenter에서 어떻게 실행하는지 알아보겠습니다.

 

 

strace -h

# 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
  -k             obtain stack trace between each 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
  -X format      set the format for printing of named constants and flags
  -y             print paths associated with file descriptor arguments
  -yy            print protocol specific information 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, fault, inject, kvm
  -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

 

주로 사용하는 옵션

"-p" : PID를 이용하여 모니터링

"-P" : 접근 경로 필터링

" " : 실행 프로그램 지정

# strace ls
execve("/usr/bin/ls", ["ls"], 0x7ffe23ab3270 /* 76 vars */) = 0
brk(NULL)                               = 0x5561fd4ad000
access("/etc/ld.so.preload", R_OK)      = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3
fstat(3, {st_mode=S_IFREG|0644, st_size=26158, ...}) = 0
mmap(NULL, 26158, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7fb68db8e000
close(3)                                = 0
openat(AT_FDCWD, "/lib/libc.so.6", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\2\1\1\3\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\240,\2\0\0\0\0\0"..., 832) = 832
fstat(3, {st_mode=S_IFREG|0755, st_size=1832816, ...}) = 0
mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fb68db8c000
mmap(NULL, 1800224, PROT_READ, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7fb68d9d4000
mprotect(0x7fb68d9f6000, 1622016, PROT_NONE) = 0
mmap(0x7fb68d9f6000, 1306624, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x22000) = 0x7fb68d9f6000
mmap(0x7fb68db35000, 311296, PROT_READ, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x161000) = 0x7fb68db35000
mmap(0x7fb68db82000, 24576, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x1ad000) = 0x7fb68db82000
mmap(0x7fb68db88000, 14368, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7fb68db88000
close(3)                                = 0
arch_prctl(ARCH_SET_FS, 0x7fb68db8d540) = 0
mprotect(0x7fb68db82000, 16384, PROT_READ) = 0
mprotect(0x5561fb54b000, 4096, PROT_READ) = 0
mprotect(0x7fb68dbbc000, 4096, PROT_READ) = 0
munmap(0x7fb68db8e000, 26158)           = 0
brk(NULL)                               = 0x5561fd4ad000
brk(0x5561fd4ce000)                     = 0x5561fd4ce000
openat(AT_FDCWD, "/usr/lib/locale/locale-archive", O_RDONLY|O_CLOEXEC) = 3
fstat(3, {st_mode=S_IFREG|0644, st_size=11822128, ...}) = 0
mmap(NULL, 11822128, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7fb68ce8d000
close(3)                                = 0
ioctl(1, TCGETS, {B38400 opost isig icanon echo ...}) = 0
ioctl(1, TIOCGWINSZ, {ws_row=44, ws_col=157, ws_xpixel=0, ws_ypixel=0}) = 0
openat(AT_FDCWD, ".", O_RDONLY|O_NONBLOCK|O_CLOEXEC|O_DIRECTORY) = 3
fstat(3, {st_mode=S_IFDIR|0700, st_size=4096, ...}) = 0
getdents64(3, /* 15 entries */, 32768)  = 512
getdents64(3, /* 0 entries */, 32768)   = 0
close(3)                                = 0
fstat(1, {st_mode=S_IFCHR|0620, st_rdev=makedev(0x88, 0), ...}) = 0
write(1, "HealthStatus  ngc_pkg_remover.sh"..., 91HealthStatus  ngc_pkg_remover.sh  outofsync.txt  storage_provider_unreg.log  unreg_vasa.py
) = 91
close(1)                                = 0
close(2)                                = 0
exit_group(0)                           = ?
+++ exited with 0 +++

 

"-e" : 특정 System Call만 출력

# 아래 예제는 ls 명령어 실행 시 mmap() 호출만 출력

# strace -e mmap ls
mmap(NULL, 26158, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7fda8141e000
mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fda8141c000
mmap(NULL, 1800224, PROT_READ, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7fda81264000
mmap(0x7fda81286000, 1306624, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x22000) = 0x7fda81286000
mmap(0x7fda813c5000, 311296, PROT_READ, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x161000) = 0x7fda813c5000
mmap(0x7fda81412000, 24576, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x1ad000) = 0x7fda81412000
mmap(0x7fda81418000, 14368, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7fda81418000
mmap(NULL, 11822128, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7fda8071d000
HealthStatus  ngc_pkg_remover.sh  outofsync.txt  storage_provider_unreg.log  unreg_vasa.py
+++ exited with 0 +++

 

# trace 옵션을 이용하면, 여러 System Call을 같이 출력

# strace -e trace=mmap,access ls
access("/etc/ld.so.preload", R_OK)      = -1 ENOENT (No such file or directory)
mmap(NULL, 26158, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7f64fd82c000
mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f64fd82a000
mmap(NULL, 1800224, PROT_READ, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f64fd672000
mmap(0x7f64fd694000, 1306624, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x22000) = 0x7f64fd694000
mmap(0x7f64fd7d3000, 311296, PROT_READ, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x161000) = 0x7f64fd7d3000
mmap(0x7f64fd820000, 24576, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x1ad000) = 0x7f64fd820000
mmap(0x7f64fd826000, 14368, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7f64fd826000
mmap(NULL, 11822128, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7f64fcb2b000
HealthStatus  ngc_pkg_remover.sh  outofsync.txt  storage_provider_unreg.log  unreg_vasa.py
+++ exited with 0 +++

 

"-t" : 각 Trace 라인별 시간 출력

# strace -t -e trace=mmap,access ls
14:56:16 access("/etc/ld.so.preload", R_OK) = -1 ENOENT (No such file or directory)
14:56:16 mmap(NULL, 26158, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7f1cfd892000
14:56:16 mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f1cfd890000
14:56:16 mmap(NULL, 1800224, PROT_READ, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f1cfd6d8000
14:56:16 mmap(0x7f1cfd6fa000, 1306624, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x22000) = 0x7f1cfd6fa000
14:56:16 mmap(0x7f1cfd839000, 311296, PROT_READ, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x161000) = 0x7f1cfd839000
14:56:16 mmap(0x7f1cfd886000, 24576, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x1ad000) = 0x7f1cfd886000
14:56:16 mmap(0x7f1cfd88c000, 14368, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7f1cfd88c000
14:56:16 mmap(NULL, 11822128, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7f1cfcb91000
HealthStatus  ngc_pkg_remover.sh  outofsync.txt  storage_provider_unreg.log  unreg_vasa.py
14:56:16 +++ exited with 0 +++

 

"-r" : 각 Trace 라인별 상대적 시간 출력

# strace -r -e trace=mmap,access ls
     0.000000 access("/etc/ld.so.preload", R_OK) = -1 ENOENT (No such file or directory)
     0.000280 mmap(NULL, 26158, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7f173ee60000
     0.000248 mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f173ee5e000
     0.000097 mmap(NULL, 1800224, PROT_READ, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f173eca6000
     0.000145 mmap(0x7f173ecc8000, 1306624, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x22000) = 0x7f173ecc8000
     0.000092 mmap(0x7f173ee07000, 311296, PROT_READ, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x161000) = 0x7f173ee07000
     0.000106 mmap(0x7f173ee54000, 24576, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x1ad000) = 0x7f173ee54000
     0.000107 mmap(0x7f173ee5a000, 14368, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7f173ee5a000
     0.000676 mmap(NULL, 11822128, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7f173e15f000
HealthStatus  ngc_pkg_remover.sh  outofsync.txt  storage_provider_unreg.log  unreg_vasa.py
     0.000727 +++ exited with 0 +++

 

"-k" : strace를 이용하면 기본적으로 Kernel의 System Call만 출력해주는데 User-mode Call도 출력 가능

# strace -k ls
execve("/usr/bin/ls", ["ls"], 0x7fff7d48a108 /* 76 vars */) = 0
 > No DWARF information found
brk(NULL)                               = 0x55f11063b000
 > /usr/lib/ld-2.28.so() [0x19699]
 > /usr/lib/ld-2.28.so() [0x18400]
 > /usr/lib/ld-2.28.so() [0x20e7]
 > /usr/lib/ld-2.28.so() [0x1217]
 > No DWARF information found
 
<snip>
 
exit_group(0)                           = ?
+++ exited with 0 +++
 > /usr/lib/libc-2.28.so(_exit+0x36) [0xc2826]
 > /usr/lib/libc-2.28.so() [0x37ea1]
 > /usr/lib/libc-2.28.so(exit+0x19) [0x37ec9]
 > /usr/lib/libc-2.28.so(__libc_start_main+0xed) [0x22b8d]
 > /usr/bin/ls() [0x6079]

 

"-c" : System Call 통계

# strace -c ls
HealthStatus  ngc_pkg_remover.sh  outofsync.txt  storage_provider_unreg.log  unreg_vasa.py
% time     seconds  usecs/call     calls    errors syscall
------ ----------- ----------- --------- --------- ----------------
  0.00    0.000000           0         1           read
  0.00    0.000000           0         1           write
  0.00    0.000000           0         6           close
  0.00    0.000000           0         5           fstat
  0.00    0.000000           0         8           mmap
  0.00    0.000000           0         4           mprotect
  0.00    0.000000           0         1           munmap
  0.00    0.000000           0         3           brk
  0.00    0.000000           0         2           ioctl
  0.00    0.000000           0         1         1 access
  0.00    0.000000           0         1           execve
  0.00    0.000000           0         1           arch_prctl
  0.00    0.000000           0         2           getdents64
  0.00    0.000000           0         4           openat
------ ----------- ----------- --------- --------- ----------------
100.00    0.000000                    40         1 total

 

## 아래 예제는 Name Resolution 시도 시 사용하는 dig 툴을 호출할 때, strace 결과

# strace dig ad01.contoso.com
execve("/usr/bin/dig", ["dig", "ad01.contoso.com"], 0x7ffc677a8928 /* 76 vars */) = 0
brk(NULL)                               = 0x56505c56b000
access("/etc/ld.so.preload", R_OK)      = -1 ENOENT (No such file or directory)

<snip>

close(4)                                = 0
close(5)                                = 0
exit_group(0)                           = ?
+++ exited with 0 +++