Linux,  Programming

[Linux] strace

August 16, 2021 /

System call tracing을 하는데 사용하는 linux utility다. 특히 error log가 부족할 때 사용한다.

ENOENT Example

#include <sys/types.h>
#include <sys/stat.h>
#include <fcntl.h>
int main()
{
    int fd;
    int i=0;
    fd = open("/tmp/hello",  O_RDONLY );
    if ( fd < 0 )
        i=1;
    else 
        i=0;
    return i;
}
$ ./a.out

위 프로그램을 실행시켰을 때 정상적으로 된지 안된지 출력이 되지 않는다. 이 때 strace를 사용하면 보다 쉽게 확인 가능하다. 이때 정확한 binary 위치 표시 ./가 필요하다.

$ strace ./a.out
execve("./a.out", ["./a.out"], 0x7fff0a5f2910 /* 19 vars */) = 0
brk(NULL)                               = 0x559a29d41000
access("/etc/ld.so.nohwcap", F_OK)      = -1 ENOENT (No such file or directory)
access("/etc/ld.so.preload", R_OK)      = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "tls/x86_64/x86_64/libc.so.6", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "tls/x86_64/libc.so.6", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "tls/x86_64/libc.so.6", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "tls/libc.so.6", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "x86_64/x86_64/libc.so.6", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "x86_64/libc.so.6", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "x86_64/libc.so.6", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "libc.so.6", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/home/shumin/local/systemc-2.3.3/lib/tls/x86_64/x86_64/libc.so.6", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
stat("/home/shumin/local/systemc-2.3.3/lib/tls/x86_64/x86_64", 0x7ffcc9b7df80) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/home/shumin/local/systemc-2.3.3/lib/tls/x86_64/libc.so.6", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
stat("/home/shumin/local/systemc-2.3.3/lib/tls/x86_64", 0x7ffcc9b7df80) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/home/shumin/local/systemc-2.3.3/lib/tls/x86_64/libc.so.6", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
stat("/home/shumin/local/systemc-2.3.3/lib/tls/x86_64", 0x7ffcc9b7df80) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/home/shumin/local/systemc-2.3.3/lib/tls/libc.so.6", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
stat("/home/shumin/local/systemc-2.3.3/lib/tls", 0x7ffcc9b7df80) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/home/shumin/local/systemc-2.3.3/lib/x86_64/x86_64/libc.so.6", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
stat("/home/shumin/local/systemc-2.3.3/lib/x86_64/x86_64", 0x7ffcc9b7df80) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/home/shumin/local/systemc-2.3.3/lib/x86_64/libc.so.6", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
stat("/home/shumin/local/systemc-2.3.3/lib/x86_64", 0x7ffcc9b7df80) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/home/shumin/local/systemc-2.3.3/lib/x86_64/libc.so.6", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
stat("/home/shumin/local/systemc-2.3.3/lib/x86_64", 0x7ffcc9b7df80) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/home/shumin/local/systemc-2.3.3/lib/libc.so.6", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
stat("/home/shumin/local/systemc-2.3.3/lib", 0x7ffcc9b7df80) = -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=38944, ...}) = 0
mmap(NULL, 38944, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7f25d08eb000
close(3)                                = 0
access("/etc/ld.so.nohwcap", F_OK)      = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/lib/x86_64-linux-gnu/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\20\35\2\0\0\0\0\0"..., 832) = 832
fstat(3, {st_mode=S_IFREG|0755, st_size=2030928, ...}) = 0
mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f25d08e9000
mmap(NULL, 4131552, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f25d02db000
mprotect(0x7f25d04c2000, 2097152, PROT_NONE) = 0
mmap(0x7f25d06c2000, 24576, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x1e7000) = 0x7f25d06c2000
mmap(0x7f25d06c8000, 15072, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7f25d06c8000
close(3)                                = 0
arch_prctl(ARCH_SET_FS, 0x7f25d08ea4c0) = 0
mprotect(0x7f25d06c2000, 16384, PROT_READ) = 0
mprotect(0x559a290e2000, 4096, PROT_READ) = 0
mprotect(0x7f25d08f5000, 4096, PROT_READ) = 0
munmap(0x7f25d08eb000, 38944)           = 0
openat(AT_FDCWD, "/tmp/foo", O_RDONLY)  = -1 ENOENT (No such file or directory)
exit_group(5)                           = ?
+++ exited with 5 +++

마지막에 openat(AT_FDCWD, "/tmp/foo", O_RDONLY) = -1 ENOENT (No such file or directory)에서 End of Entry error가 보인다.

malloc Example

#include <stdlib.h>
int main()
{
    char *p = malloc(8192);
    *p = 1;
    return 0;
}

위 프로그램을 strace로 분석하면 다음과 같이 된다.

$ strace ./a.out
execve("./a.out", ["./a.out"], 0x7fff7d9ac5c0 /* 19 vars */) = 0
brk(NULL)                               = 0x556303b7a000
access("/etc/ld.so.nohwcap", F_OK)      = -1 ENOENT (No such file or directory)
access("/etc/ld.so.preload", R_OK)      = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "tls/x86_64/x86_64/libc.so.6", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "tls/x86_64/libc.so.6", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "tls/x86_64/libc.so.6", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "tls/libc.so.6", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "x86_64/x86_64/libc.so.6", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "x86_64/libc.so.6", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "x86_64/libc.so.6", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "libc.so.6", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/home/shumin/local/systemc-2.3.3/lib/tls/x86_64/x86_64/libc.so.6", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
stat("/home/shumin/local/systemc-2.3.3/lib/tls/x86_64/x86_64", 0x7ffcd533efe0) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/home/shumin/local/systemc-2.3.3/lib/tls/x86_64/libc.so.6", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
stat("/home/shumin/local/systemc-2.3.3/lib/tls/x86_64", 0x7ffcd533efe0) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/home/shumin/local/systemc-2.3.3/lib/tls/x86_64/libc.so.6", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
stat("/home/shumin/local/systemc-2.3.3/lib/tls/x86_64", 0x7ffcd533efe0) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/home/shumin/local/systemc-2.3.3/lib/tls/libc.so.6", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
stat("/home/shumin/local/systemc-2.3.3/lib/tls", 0x7ffcd533efe0) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/home/shumin/local/systemc-2.3.3/lib/x86_64/x86_64/libc.so.6", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
stat("/home/shumin/local/systemc-2.3.3/lib/x86_64/x86_64", 0x7ffcd533efe0) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/home/shumin/local/systemc-2.3.3/lib/x86_64/libc.so.6", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
stat("/home/shumin/local/systemc-2.3.3/lib/x86_64", 0x7ffcd533efe0) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/home/shumin/local/systemc-2.3.3/lib/x86_64/libc.so.6", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
stat("/home/shumin/local/systemc-2.3.3/lib/x86_64", 0x7ffcd533efe0) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/home/shumin/local/systemc-2.3.3/lib/libc.so.6", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
stat("/home/shumin/local/systemc-2.3.3/lib", 0x7ffcd533efe0) = -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=38944, ...}) = 0
mmap(NULL, 38944, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7f2a058b2000
close(3)                                = 0
access("/etc/ld.so.nohwcap", F_OK)      = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/lib/x86_64-linux-gnu/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\20\35\2\0\0\0\0\0"..., 832) = 832
fstat(3, {st_mode=S_IFREG|0755, st_size=2030928, ...}) = 0
mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f2a058b0000
mmap(NULL, 4131552, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f2a052a2000
mprotect(0x7f2a05489000, 2097152, PROT_NONE) = 0
mmap(0x7f2a05689000, 24576, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x1e7000) = 0x7f2a05689000
mmap(0x7f2a0568f000, 15072, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7f2a0568f000
close(3)                                = 0
arch_prctl(ARCH_SET_FS, 0x7f2a058b14c0) = 0
mprotect(0x7f2a05689000, 16384, PROT_READ) = 0
mprotect(0x556302d48000, 4096, PROT_READ) = 0
mprotect(0x7f2a058bc000, 4096, PROT_READ) = 0
munmap(0x7f2a058b2000, 38944)           = 0
brk(NULL)                               = 0x556303b7a000
brk(0x556303b9b000)                     = 0x556303b9b000
exit_group(0)                           = ?
+++ exited with 0 +++

Log 마지막에 보면 brk라고 나오는데, 이 주소의 의미를 설명하기 위해 시각화 하면 다음과 같다.

brk가 나타내는 주소는 실제 OS가 page에 접근하기위해 사용하는데, 상위 주소부터 page directory, page table, page table index로 순차적으로 접근한다. 만약 이 때 physical address 할당이 되어있지 않다면 page fault exception이 발생하면서 새로 할당을 해준다.

Leave a Reply

Your email address will not be published. Required fields are marked *