strace 명령어 상세 가이드

strace란 무엇인가?

strace 공식 문서에 따르면, strace는 진단, 디버깅 및 교육 목적으로 사용할 수 있는 Linux 사용자 공간 추적기입니다. 사용자 공간 프로세스와 커널 상호작용을 모니터링하는 데 사용되며, 시스템 호출, 신호 전달, 프로세스 상태 변경 등을 추적할 수 있습니다.

strace는 내부적으로 커널의 ptrace 기능을 사용하여 그 기능을 구현합니다.

운영 환경에서 장애 처리 및 문제 진단은 주요 업무이자 필수 기술입니다. strace는 동적 추적 도구로서 운영 엔지니어가 프로세스 및 서비스 장애를 효율적으로 진단하는 데 도움을 줍니다. 마치 탐정처럼 시스템 호출의 흔적을 통해 비정상적인 현상의 원인을 밝혀주는 역할을 합니다.

strace가 할 수 있는 일

운영 엔지니어들은 실무 중심적인 사람들이므로, 예제를 통해 바로 시작해 보겠습니다.

다른 머신에서 some_server라는 소프트웨어 패키지를 복사해왔습니다. 개발자는 그냥 실행하면 된다고 말했고, 설정 변경은 필요 없다고 했습니다. 하지만 실행 시도 시 오류가 발생하여 전혀 시작되지 않았습니다!

실행 명령어:

./some_server ../conf/some_server.conf

출력:

FATAL: InitLogFile failed iRet: -1!
Init error: -1655

왜 시작되지 않을까요? 로그를 보면 로그 파일 초기화에 실패한 것으로 보입니다. 진실은 어떨까요? strace를 사용하여 확인해 보겠습니다.

strace -tt -f ./some_server ../conf/some_server.conf

출력에서 InitLogFile failed 오류 바로 앞에 open 시스템 호출이 있음을 주목할 수 있습니다:

23:14:24.448034 open("/usr/local/apps/some_server/log//server_agent.log", O_RDWR|O_CREAT|O_APPEND|O_LARGEFILE, 0666) = -1 ENOENT (No such file or directory)

이 시스템 호출은 파일을 열려고 시도합니다(없으면 생성), 하지만 오류가 발생했습니다. 반환 코드는 -1이고, 시스템 오류 번호 errno는 ENOENT입니다. open 시스템 호출 매뉴얼 페이지를 확인해 보겠습니다:

man 2 open

ENOENT 오류 번호에 대한 설명을 검색합니다:

ENOENT O_CREAT가 설정되지 않았고 지정된 파일이 존재하지 않음. 또는 경로명의 디렉토리 구성 요소가 존재하지 않거나 유효하지 않은 심볼릭 링크입니다.

여기서 설명이 명확합니다. 예제의 open 옵션에서 O_CREAT 옵션이 지정되었으므로, errno가 ENOENT인 이유는 로그 경로의 일부가 존재하지 않거나 유효하지 않은 심볼릭 링크이기 때문입니다. 경로의 어느 부분이 없는지 확인해 보겠습니다:

ls -l /usr/local/apps/some_server/log
ls: cannot access /usr/local/apps/some_server/log: No such file or directory
ls -l /usr/local/apps/some_server
total 8
drwxr-xr-x 2 root users 4096 May 14 23:13 bin
drwxr-xr-x 2 root users 4096 May 14 22:48 conf

log 하위 디렉토리가 존재하지 않았습니다! 상위 디렉토리는 모두 존재합니다. log 하위 디렉토리를 수동으로 생성한 후 서비스가 정상적으로 시작되었습니다.

다시 돌아와서, strace가 정확히 어떤 일을 할 수 있는지 살펴보겠습니다.

이는 애플리케이션 프로세스의 이런 블랙박스를 열어 시스템 호출의 단서를 통해 프로세스가 무엇을 하는지 알려줍니다.

strace 사용법

strace는 사용자 공간 프로세스의 시스템 호출과 신호를 추적하는 도구이므로, strace 사용 주제로 들어가기 전에 시스템 호출이 무엇인지 이해해야 합니다.

시스템 호출에 대해:

위키피디아의 설명에 따르면, 컴퓨터에서 시스템 호출(system call)은 사용자 공간에서 실행 중인 프로그램이 더 높은 권한으로 실행해야 하는 서비스를 운영체제 커널에 요청하는 것입니다.

시스템 호출은 사용자 프로그램과 운영체제 간의 인터페이스를 제공합니다. 운영체제의 프로세스 공간은 사용자 공간과 커널 공간으로 나뉩니다:

• 운영체제 커널은 하드웨어에서 직접 실행되며, 장치 관리, 메모리 관리, 작업 스케줄링 등의 기능을 제공합니다.
• 사용자 공간은 API를 통해 커널 공간의 서비스를 요청하여 기능을 수행합니다 - 커널이 사용자 공간에 제공하는 이러한 API가 바로 시스템 호출입니다.

Linux 시스템에서 애플리케이션 코드는 glibc 라이브러리로 래핑된 함수를 통해 간접적으로 시스템 호출을 사용합니다.

현재 Linux 커널에는 300개가 넘는 시스템 호출이 있으며, 상세한 목록은 syscalls 매뉴얼 페이지에서 볼 수 있습니다. 이 시스템 호출은 주로 몇 가지 범주로 나뉩니다:

파일 및 장치 접근: open/close/read/write/chmod 등
프로세스 관리: fork/clone/execve/exit/getpid 등
신호 관련: signal/sigaction/kill 등
메모리 관리: brk/mmap/mlock 등
프로세스 간 통신 IPC: shmget/semget (세마포어, 공유 메모리, 메시지 큐 등)
네트워크 통신: socket/connect/sendto/sendmsg 등
기타

Linux 시스템 호출/시스템 프로그래밍에 익숙하면 strace 사용이 더 용이해집니다. 하지만 운영 환경의 문제 진단을 위해 strace 도구를 알고 시스템 호출 매뉴얼을 확인할 수 있으면 충분합니다.

더 깊이 학습하고 싶은 분들은 "Linux 시스템 프로그래밍", "Unix 환경 고급 프로그래밍" 등의 책을 읽어보시는 것을 권장합니다.

strace 사용으로 돌아가겠습니다. strace에는 두 가지 실행 모드가 있습니다.

하나는 strace를 사용하여 추적할 프로세스를 시작하는 것입니다. 사용법은 간단하며, 원래 명령 앞에 strace를 추가하기만 하면 됩니다. 예를 들어, "ls -lh /var/log/messages" 명령의 실행을 추적하려면 다음과 같이 할 수 있습니다:

strace ls -lh /var/log/messages

다른 하나는 이미 실행 중인 프로세스를 추적하는 것입니다. 프로세스 실행을 중단하지 않으면서 무엇을 하는지 이해할 수 있습니다. 이 경우, strace에 -p pid 옵션을 전달하면 됩니다.

예를 들어, 실행 중인 some_server 서비스가 있다면, 첫 번째로 pid를 확인합니다:

pidof some_server
17553

pid 17553을 얻은 후 strace를 사용하여 실행을 추적할 수 있습니다:

strace -p 17553

추적을 완료하면 ctrl + C를 눌러 strace를 종료하면 됩니다.

strace에는 동작을 조정할 수 있는 몇 가지 옵션이 있습니다. 여기서는 그중 몇 가지 일반적으로 사용되는 옵션을 소개하고, 예시를 통해 실제 적용 효과를 설명하겠습니다.

strace 일반 옵션:

예시 명령어에서 살펴보겠습니다:

strace -tt -T -v -f -e trace=file -o /data/log/strace.log -s 1024 -p 23489

-tt: 각 출력 줄 앞에 밀리초 단위의 시간 표시 -T: 각 시스템 호출에 소요된 시간 표시 -v: 일부 관련 호출에 대해 전체 환경 변수, 파일 stat 구조 등 출력 -f: 대상 프로세스 및 대상 프로세스가 생성한 모든 하위 프로세스 추적 -e: 추적할 이벤트와 추적 동작 제어, 예: 특정 시스템 호출 이름 지정 -o: strace 출력을 지정된 파일에만 작성 -s: 시스템 호출의 특정 인자가 문자열일 경우, 최대 길이 내용 출력 (기본값 32바이트) -p: 추적할 프로세스 pid 지정, 여러 pid를 동시에 추적하려면 -p 옵션을 여러 번 반복

예시: nginx 추적, 시작 시 접근한 파일 확인

strace -tt -T -f -e trace=file -o /data/log/strace.log -s 1024 ./nginx

일부 출력:

출력에서 첫 번째 열은 프로세스 pid를 표시하며, 다음은 밀리초 단위의 시간입니다. 이는 -tt 옵션의 효과입니다.

각 행의 마지막 열은 해당 호출에 소요된 시간을 표시하며, 이는 -T 옵션의 결과입니다.

여기서의 출력은 파일 접근과 관련된 내용만 표시됩니다. 이는 -e trace=file 옵션을 지정했기 때문입니다.

strace 문제 진단 사례

1. 프로세스 비정상 종료 진단

문제: 머신에 run.sh라는 상주 스크립트가 있으며, 실행 1분 후에 종료됩니다. 종료 원인을 찾아야 합니다.

진단: 프로세스가 실행 중일 때 ps 명령어를 사용하여 pid를 얻습니다. pid가 24298이라고 가정하겠습니다.

strace -o strace.log -tt -p 24298

strace.log를 확인하면 마지막 2행에 다음 내용이 있습니다:

22:47:42.803937 wait4(-1,  <unfinished ...>
22:47:43.228422 +++ killed by SIGKILL +++

여기서 프로세스가 다른 프로세스에 의해 KILL 신호로 종료되었음을 알 수 있습니다.

실제로 분석한 결과, 머신의 다른 서비스에 모니터링 스크립트가 있었으며, run.sh 프로세스 수가 2개 이상이면 이를 종료 후 재시작하는 것으로 나타났습니다. 이로 인해 우리의 run.sh 스크립트가 잘못 종료되었습니다.

프로세스가 종료될 때 strace는 killed by SIGX(SIGX는 프로세스에 전달된 신호를 의미) 등을 출력합니다. 그렇다면 프로세스가 자체적으로 종료될 때는 어떤 내용을 출력할까요?

test_exit라는 프로그램이 있는데, 코드는 다음과 같습니다:

#include <stdio.h>
#include <stdlib.h>

int main(int argc, char **argv) {
    exit(1);
}

종료 시 strace에서 어떤 흔적을 볼 수 있는지 확인해 보겠습니다.

strace -tt -e trace=process -f ./test_exit

설명: -e trace=process는 프로세스 관련 시스템 호출만 추적하라는 의미입니다.

출력:

23:07:24.672849 execve("./test_exit", ["./test_exit"], [/* 35 vars */]) = 0
23:07:24.674665 arch_prctl(ARCH_SET_FS, 0x7f1c0eca7740) = 0
23:07:24.675108 exit_group(1)          = ?
23:07:24.675259 +++ exited with 1 +++

프로세스가 자체적으로 종료될 때(exit 함수 호출 또는 main 함수 반환), 최종적으로 exit_group 시스템 호출을 사용하며, strace는 exited with X(X는 종료 코드)를 출력하는 것을 볼 수 있습니다.

exit_group가 아닌 exit 함수가 표시되어 혼란스러울 수 있습니다.

이 경우의 exit 함수는 시스템 호출이 아니라 glibc 라이브러리가 제공하는 함수입니다. exit 함수 호출은 최종적으로 exit_group 시스템 호출로 변환됩니다. 이는 현재 프로세스의 모든 스레드를 종료합니다. 실제로 _exit()라는 시스템 호출이 있으며(앞에 밑줄이 있음), 스레드가 종료될 때 이를 호출합니다.

2. 공유 메모리 이상 진단

서비스 시작 시 다음과 같은 오류가 발생합니다:

shmget 267264 30097568: Invalid argument
Can not get shm...exit!

오류 로그는 공유 메모리 가져오기 오류임을 알려주며, strace로 확인해 보겠습니다:

strace -tt -f -e trace=ipc ./a_mon_svr ../conf/a_mon_svr.conf

출력:

22:46:36.351798 shmget(0x5feb, 12000, 0666) = 0
22:46:36.351939 shmat(0, 0, 0)         = ?
Process 21406 attached
22:46:36.355439 shmget(0x41400, 30097568, 0666) = -1 EINVAL (Invalid argument)
shmget 267264 30097568: Invalid argument
Can not get shm...exit!

여기서 -e trace=ipc 옵션을 사용하여 strace가 프로세스 통신 관련 시스템 호출만 추적하도록 했습니다.

strace 출력에서 shmget 시스템 호출에서 오류가 발생했으며, errno가 EINVAL임을 알 수 있습니다. 마찬가지로 shmget 매뉴얼 페이지를 확인하고 EINVAL 오류 코드의 설명을 검색해 보겠습니다:

EINVAL 새 세그먼트를 생성하려고 했는데 size < SHMMIN 또는 size > SHMMAX이거나, 새 세그먼트를 생성하지 않았고, 주어진 키를 가진 세그먼트가 존재하지만 크기가 해당 세그먼트의 크기보다 큼

번역하면, shmget가 EINVAL 오류 코드를 설정하는 원인은 다음 중 하나입니다:

• 생성하려는 공유 메모리 세그먼트가 SHMMIN보다 작음 (일반적으로 1바이트)
• 생성하려는 공유 메모리 세그먼트가 SHMMAX보다 큼 (커널 매개변수 kernel.shmmax 설정)
• 지정된 키의 공유 메모리 세그먼트가 이미 존재하며, 크기가 shmget 호출 시 전달된 값과 다름

strace 출력에서 연결하려는 공유 메모리 키는 0x41400이고, 지정된 크기는 30097568바이트입니다. 이는 1, 2번 경우와 명확히 일치하지 않습니다. 따라서 3번 경우만 남습니다. ipcs를 사용하여 크기 불일치 여부를 확인해 보겠습니다:

ipcs -m | grep 41400
key        shmid      owner      perms      bytes      nattch     status    
0x00041400 1015822    root       666        30095516   1

0x41400 키가 이미 존재하며 크기가 30095516바이트이며, shmget 호출 매개변수의 30097568과 일치하지 않으므로 이 오류가 발생했습니다.

이 사례에서 공유 메모리 크기 불일치의 원인은 프로그램 그룹 중 하나가 32비트로 컴파일되고 다른 하나는 64비트로 컴파일된 것입니다. 코드에서 long이라는 가변 int 데이터 타입을 사용했습니다.

두 프로그램 모두를 64비트로 컴파일하여 이 문제를 해결했습니다.

여기서 strace의 -e trace 옵션을 특별히 설명하겠습니다.

특정 시스템 호출을 추적하려면 -e trace=xxx를 사용하면 됩니다. 하지만 때로는 파일 이름과 관련된 모든 호출이나 메모리 할당과 관련된 모든 호출 같은 특정 범주를 추적해야 할 수 있습니다.

각각의 구체적인 시스템 호출 이름을 수동으로 입력하면 누락될 수 있습니다. 따라서 strace는 몇 가지 일반적으로 사용되는 시스템 호출 조합 이름을 제공합니다.

-e trace=file: 파일 접근 관련 호출(파일 이름이 있는 인자) 추적 -e trace=process: 프로세스 관련 호출(fork/exec/exit_group 등) -e trace=network: 네트워크 통신 관련 호출(socket/sendto/connect 등) -e trace=signal: 신호 전송 및 처리 관련(kill/sigaction 등) -e trace=desc: 파일 설명자 관련(write/read/select/epoll 등) -e trace=ipc: 프로세스 간 통신 관련(shmget 등)

대부분의 경우 위의 조합 이름으로 충분합니다. 구체적인 시스템 호출을 추적해야 할 때는 C 라이브러리 구현의 차이에 주의해야 할 수 있습니다.

예를 들어 프로세스 생성에 fork 시스템 호출을 사용한다는 것을 알지만, glibc 내부에서 fork 호출은 실제로 더 낮은 수준의 clone 시스템 호출로 매핑됩니다. strace 사용 시 -e trace=clone을 지정해야 하며, -e trace=fork는 아무것도 일치하지 않습니다.

3. 성능 분석

Linux 4.5.4 버전 커널의 코드 줄 수(어셈블리 및 C 코드 포함)를 세야 하는 요구사항이 있다고 가정해 보겠습니다. 여기에 두 개의 셸 스크립트 구현을 제공합니다:

poor_script.sh:

#!/bin/bash

total_line=0
while read filename; do
    line=$(wc -l $filename | awk '{print $1}')
    (( total_line += line ))
done < <( find linux-4.5.4 -type f \( -iname '*.c' -o -iname '*.h' -o -iname '*.S' \) )
echo "total line: $total_line"

good_script.sh:

#!/bin/bash

find linux-4.5.4 -type f \( -iname '*.c' -o -iname '*.h' -o -iname '*.S' \) -print0 \
| wc -l --files0-from - | tail -n 1

두 코드는 동일한 목적을 수행합니다. strace의 -c 옵션을 사용하여 두 버전의 시스템 호출 상황과 소요 시간을 각각 통계하겠습니다(-f를 사용하여 하위 프로세스 상황 동시 통계).

두 출력에서 볼 수 있듯이, good_script.sh는 2초 만에 결과를 얻을 수 있습니다: 19613114줄. 대부분의 호출(calls) 비용은 파일 작업(read/open/write/close) 등이며, 코드 줄 수를 세는 것은 당연히 이러한 작업을 수행하는 것입니다.

반면 poor_script.sh는 동일한 작업을 완료하는 데 539초가 걸렸습니다. 대부분의 호출 비용은 프로세스 및 메모리 관리(wait4/mmap/getpid...)에 있습니다.

실제로 두 그래프에서 clone 시스템 호출 횟수를 보면, good_script.sh는 3개의 프로세스만 시작하는 반면, poor_script.sh는 전체 작업을 완료하는 데 무려 126335개의 프로세스를 시작합니다!

프로세스 생성 및 소멸의 비용은 상당히 높으며, 성능이 나쁘지 않을 수 없습니다.

결론

프로세스 또는 서비스가 비정상적으로 동작하는 것을 발견하면 strace를 사용하여 시스템 호출을 추적하고 "무엇을 하는지" 확인하여 비정상적인 원인을 찾을 수 있습니다. 일반적인 시스템 호출에 익숙하면 strace를 더 잘 이해하고 사용할 수 있습니다.

물론, 만능의 strace가 진정한 만능은 아닙니다. 대상 프로세스가 사용자 모드에서 멈춰 있을 때 strace는 출력이 없습니다.

이 경우에는 gdb/perf/SystemTap 등 다른 추적 수단이 필요합니다.

참고:

1. perf는 커널 지원이 필요합니다
2. ftrace는 커널 지원 가능 프로그래밍이 필요합니다
3. systemtap은 기능이 강력하며 RedHat 시스템을 지원하며 사용자 모드 및 커널 모드 로직 모두를 탐색할 수 있으므로 사용 범위가 더 넓습니다