Linux Performance
오늘 다룰 주제는 Linux에서 제공하는 최강의 디버깅 도구 중에 하나인 strace입니다. strace를 사용하는 방법과 활용하는 방법에 대해서 간단하게 다뤄보겠습니다. 사실 너무나도 많은 영역에 사용될 수 있어서, 오늘 다루게 되는 내용은 아주 기초적인 내용에 불과할 겁니다. 이 내용을 바탕으로 다양한 문제 해결에 도움이 되었으면 합니다.
man 페이지를 보면 아래와 같이 나와 있습니다.
strace - trace system calls and signals
네. 맞습니다.
strace는 애플리케이션들이 사용하는 system call과 signal 등을 추적해서 성능 저하를 일으키는 부분은 없는지, 에러가 나는 부분은 없는지를 확인하는데 사용하는 디버깅 툴입니다.
여러 가지 옵션이 있지만 반드시 사용해야 하는 옵션들은 아래와 같습니다.
-s strsize Specify the maximum string size to print (the default is 32).
strace를 통해 추적할 때 화면 혹은 파일에 뿌려 줄 문자열에 대한 최댓값을 설정해 줍니다. 이 값을 디폴트 값으로 사용하면 strace를 떠 놓고도 많은 부분이 잘려서 제대로 확인을 할 수 없는 상태가 됩니다.
-f Trace child processes
여러 개의 워크 프로세스 혹은 워커 스레드를 만들어서 사용하는 애플리케이션을 추적할 때에는 -f 옵션이 필수입니다. 그렇지 않으면 아무 작업도 하지 않는 마스터 프로세스만 추적이 될 수 있습니다.
-t Prefix each line of the trace with the time of day.
시스템 콜 간의 소요 시간 등을 측정하기 위해서는 추적하는 동안 타임 스탬프를 찍는 것이 필수입니다.
-p pid Attach to the process with the process ID pid
-p 옵션을 통해 추적하려는 프로세스의 pid를 입력해 주어야 추적이 시작됩니다. 이미 생성되어 있는 프로세스를 pid를 통해 추적할 수도 있고 뒤에 직접 커맨드를 넣어서 추적할 수도 있습니다.
그래서 완성된 명령은 아래와 같은 형태를 띱니다.
strace -s 65535 -f -t -o strace_dump -p <pid>
그럼 간단하게 사용법을 알아 봤으니 실제로 어떻게 활용할 수 있는지 살펴보겠습니다. 간단하게 hostname이라는 리눅스 명령을 추적해 보면서 살펴보겠습니다.
혹시 hostname 명령 중에 -f 옵션과 -A 옵션의 차이를 아시나요? 둘 다 FQDN을 보여준다고는 하는데, 왜 두 개의 옵션이 따로 있는 걸까요? 이 차이점을 strace를 통해서 살펴보겠습니다.
strace -s 65535 -f -t -o strace_dump_1 hostname -f
생성된 파일 strace_dump_1을 살펴보겠습니다.
상단 내용을 보시면 execve라는 시스템 콜을 통해서 새로운 프로세스를 만들고 명령을 실행하는 것을 볼 수 있습니다. shell에서 명령을 입력하면 fork를 통해서 새로운 프로세스가 만들어진다는 것을 확인할 수 있는 줄입니다. 그리고 필요로 하는 라이브러리들을 찾아서 open 등의 시스템 콜을 통해서 읽고 있습니다.
hostname 명령은 서버의 호스트명을 읽어오는 명령이기 때문에 당연히 /etc/resolv.conf를 읽게 됩니다. strace를 통해서 이런 과정을 직접 확인할 수 있습니다.
이 부분이 가장 핵심인데요, 107번째 줄에 보시면 도메인 질의를 하기 위해 소켓을 만드는 것을 볼 수 있습니다. 그리고 108번째 줄에서 도메인 서버와 connect 함수로 연결을 요청하고요, 110번 줄에서 도메인 질의를 하는 것을 볼 수 있습니다. 내용을 자세히 보시면 server.example.com이라는 호스트가 있는지를 묻고 있습니다. example.com 은 /etc/resolv.conf 파일에 있는 search 지시자 안에 있는 도메인입니다.
그리고 113번 줄에는 도메인 서버로부터의 응답을 받는 것을 확인할 수 있습니다. 그리고 이런 식으로 /etc/resolv.conf에 있는 search 지시자를 붙여서 도메인 서버에 계속 질의하는 것을 볼 수 있습니다.
즉, hostname -f 명령은 search 지시자에 자신의 호스트명을 붙여서 도메인 서버에 질의를 하고 이에 대한 응답을 받아서 사용자에게 보여 주는 것임을 확인할 수 있습니다.
그럼 이번에는 hostname -A 명령을 살펴보겠습니다.
strace -s 65535 -f -t -o strace_dump_2 hostname -A
116번 줄을 보시면 역시 -f 때와 마찬가지로 소켓을 여는 것을 볼 수 있습니다. 중요한 차이점은 119번 줄에서 볼 수 있는데요, -f 옵션과 달리 리버스 도메인 질의를 하는 것을 볼 수 있습니다. 잘린 부분은 IP 노출 때문에 제가 임의로 잘랐는데요 ^^; 뒤에 보시면 in-addr.arpa로 메시지를 보내는 것을 볼 수 있습니다. -f는 search 지시자를 붙여서 도메인 질의를 했다면 -A 옵션은 IP를 가지고 리버스 도메인 질의를 하는 것을 볼 수 있습니다.
이렇게 비슷해 보이는 기능이지만 strace를 통해 확인해 보면 전혀 동작 원리가 다른 명령임을 알 수 있습니다.
이번엔 실제로 발생했던 문제를 strace를 통해 어떻게 확인하고 수정할 수 있는지 살펴보겠습니다.
지난번 글에서 언급했던 nginx upstream keepalive를 기억하시나요? ^^ 관련해서 발생했던 이슈 중 하나인데, 증상은 nginx upstream keepalive를 적용했음에도 불구하고 내부 통신에서 TIME_WAIT 소켓이 다수 발생하는 증상 이었습니다.
이를 추적하기 위해 strace를 사용해 봤습니다.
우선 nginx 프로세스에 대해 strace를 걸었습니다.
5번에 보시면 사용자로부터의 GET 요청을 nginx가 받았음을 볼 수 있습니다. 그리고 play로 넘겨주기 위해서 내부 소켓을 만들고요 (7번 줄), connect 시스템 콜을 통해 play 에 접속하고 있습니다. (10번 줄).
그 후에 사용자의 GET 요청을 그대로 프록싱 해 주고 있고요 (14번 줄), 16번 줄에서 정상적으로 응답을 받아서 돌려 주고 있습니다. 그런데, 18번 줄을 잘 보시면 바로 close()를 호출하고 있습니다. FD가 5번인데 5번은 nginx에서 play로 데이터를 넘겨주기 위해 생성한 로컬 포트입니다. (7번 줄에 socket 함수의 리턴 값이 5 임을 통해 알 수 있습니다.)
아.. 분명 14번 줄을 보면 HTTP/1.1로 요청하는 것을 확인했는데 왜 끊어질까요? play의 버그일까요? 아닙니다. 16번 줄의 응답 내용을 잘 보면 Connection: close라는 헤더가 내려 오는 것을 볼 수 있습니다. play에서 임의로 헤더 값을 수정해서 close로 내려주었기 때문에 nginx에서는 먼저 연결을 끊을 수밖에 없었습니다.
네 사실 이 이슈는 tcpdump를 통해서 확인하는 것이 더 빠를 수 있습니다. (내부 통신이기 때문에 -i any 옵션을 반드시 붙여야 합니다.) 다만 이 글에서 strace를 활용하는 방법을 보여 드리기 위해 strace를 사용해 봤습니다. ^^
두 가지 예제를 통해서 strace를 사용하는 방법을 살펴봤습니다.
그리 문법이 복잡하지 않고 사용법이 까다롭지 않기 때문에 strace는 시스템 엔지니어가 반드시 익혀 두어야 할 필수 도구 중에 하나라고 생각합니다.
또한 디버깅할 때뿐 아니라 애플리케이션이 동작하는 내부 원리나 구조를 파악하는 데에도 많은 도움이 됩니다. 물론 내부 로직까지는 확인할 수 없지만, 소켓을 열 때 어떤 옵션을 사용하는지 (setsockopt), 연결 맺기와 끊기는 잘 되는지 (connect, close) , 정상적으로 컨피그 파일을 잘 읽는지 (access, read) 등의 확인을 통해서 간단하게나마 애플리케이션의 구조를 파악하는데 도움이 됩니다.
긴 글 읽어 주셔서 감사합니다.