brunch

You can make anything
by writing

C.S.Lewis

by 강진우 Jun 26. 2018

커널 분석을 위한 systemtap 스크립트

systemtap

오늘은 systemtap이라는 것에 대해 이야기해 보겠습니다. systemtap이란 무엇인지 어떻게 구성되어 있는지 살펴보고 이를 통해서 무엇을 얻을 수 있을지에 대해 이야기해 보겠습니다.


systemtap이란


systemtap커널의 특정 정보들을 수집해서 디버깅하거나 문제를 해결하는 데에 사용되는 시스템 툴입니다. 예를 들어 어떤 프로세스가 UDP 프로토콜을 사용해서 통신을 하려고 하는지, 얼마나 많은 양의 메모리 할당을 요구하는지, 어떤 이유로 인해 CPU 사용량을 독점하고 있는지 등등 시스템에서 발생하는 다양한 이슈들에 대해서 이를 해결할 수 있는 정보들을 수집하고 분석할 수 있게 도와주는 툴입니다. 물론 현재도 top, ps, iostat, free, netstat 등과 같은 다양한 도구들을 이용해 문제를 분석할 수 있지만 systemtap을 사용하면 더 정확하게 필요한 정보들을 수집할 수 있습니다. 


systemtap의 동작 원리


systemtap의 동작을 이해하기 위해서는 eventhandler라는 두 가지 개념을 알아야 합니다. 먼저 event는 그 글자가 가진 의미 그대로 systemtap을 통해 모니터링하고자 하는 지점, handler는 설정해 놓은 event가 발생했을 때 처리하는 로직을 의미합니다.

간단한 systemtap 예제

만약 위와 같은 스크립트가 있다고 하면, syscall.openevent, 그 아래 로직이 정의된 부분이 handler가 됩니다. 그래서 위 스크립트를 실행하게 되면 프로세스들이 open() 시스템 콜을 호출할 때마다 프로세스의 이름과 PID를 출력하게 됩니다.

이렇게 systemtap 스크립트를 작성하고 난 후에 실행하게 되면 systemtap은 스크립트를 C언어로 번역하고, gcc를 이용해 커널 모듈로 빌드한 후 동적 바인딩을 통해서 생성된 모듈을 커널에 추가합니다. 

이렇게 생성된 모듈은 lsmod 명령을 이용하면 stap이라는 문자로 시작하는 모듈로 확인할 수 있습니다.

[root@server01 ~]# lsmod | grep -i stap
stap_8e406604cfafe3d25464c7ed4b5ea9ca_26053   144529  2

그리고 커널 레벨에서 살펴본다면 systemtap 스크립트로 인해 실행 과정은 아래와 같이 바뀝니다.

systemtap 스크립트로 인해 변경되는 동작

프로세스가 open() 시스템 콜을 호출하게 되면 systemtap에서 이벤트를 감지하고 handler를 실행시킨 후에 원래 실행되어야 할 open() 함수를 실행하게 됩니다. 이벤트 위치에 따라서 event가 시작될 때, 아니면 종료될 때 handler를 설정할 수 있습니다.



systemtap 설치하기


CentOS 6 이상이라면 아래와 같은 yum 명령을 통해서 설치할 수 있습니다.

yum install systemtap

그리고 앞절에서 예제로 들었던 syscall.open()을 추적하는 스크립트를 아래와 같이 작성한 후에 실행해 보겠습니다.

probe syscall.open
{
printf ("%s(%d) open\n", execname(), pid())
}

하지만 실행해 보면 에러 메시지를 볼 수 있습니다.

systemtap 에러 메세지

systemtap을 실행하기 위해서는 systemtap 명령어 외에 kernel-debuginfokernel-debuginfo-common, kernel-devel 세 개의 패키지를 필요로 하기 때문입니다. 이 패키지들을 설치한 후 실행하면 아래와 같은 결과를 얻을 수 있습니다.

이 패키지들은 http://debuginfo.centos.org/ 이곳에서 다운로드할 수 있습니다.
systemtap 결과

systemtap을 통해서 할 수 있는 것들


https://sourceware.org/systemtap/examples/에 가면 systemtap을 통해서 할 수 있는 다양한 스크립트들이 등록되어 있습니다. 보시는 것처럼 정말 많은 것들을 할 수 있습니다. 우리는 그중에서도 TCP 재전송 과정을 추적하는 systemtap 스크립트를 살펴보겠습니다. 

애플리케이션에서 타임아웃이 발생하게 되면 가장 먼저 해야 하는 것이 타임아웃이 발생하는 구간에 대한 tcpdump 일 겁니다. 하지만 통신량이 많고 타임아웃이 간헐적으로 발생하게 된다면 추적을 위해 생성해 놓은 덤프 파일이 너무 커서 분석하는데에 어려움을 겪을 수 있습니다. 이럴 때 systemtap 스크립트를 사용한다면 tcpdump를 분석하는 일도 줄일 수 있고 재전송이 발생하는 타이밍만을 정확하게 확인할 수 있기 때문에 문제 해결에 소요되는 시간을 줄일 수 있습니다.

스크립트를 살펴보겠습니다.

#! /usr/bin/env stap ################################################################# 
# tcp_retransmit.stp 
# Author: Yang Bingwu (detailyang) <detailyang@gmail.com> 
# This systemtap script will prints the tcp retransmission packet ################################################################# 

global record% 

function syslog(msg:string) {     
  sendit="/usr/bin/logger -t systemtap \"".msg."\""     
  system(sendit) 


probe begin {     
  log("Printing tcp retransmission") 


probe kernel.function("tcp_retransmit_skb") {     
  rto = tcp_get_info_rto($sk)     
  saddr   = format_ipaddr(__ip_sock_saddr($sk), __ip_sock_family($sk))     
  daddr   = format_ipaddr(__ip_sock_daddr($sk), __ip_sock_family($sk))     
  sport   = __tcp_sock_sport($sk)     
  dport   = __tcp_sock_dport($sk)    
  lastrto = record[saddr, sport, daddr, dport]     
  state = tcp_ts_get_info_state($sk)     

  if (lastrto != rto) {        
    if (lastrto) {             
      syslog( sprintf("%s:%d => %s:%d STATE:%s RTO:%d -> %d (ms)\n", saddr, sport,                 daddr, dport, tcp_sockstate_str(state), lastrto/1000, rto/1000) )         
    } else {             
      syslog( sprintf("%s:%d => %s:%d STATE:%s RTO:%d (ms)\n", saddr, sport,                 daddr, dport, tcp_sockstate_str(state), rto/1000) )         
    }     
  }    
   record[saddr, sport, daddr, dport] = rto 
}
예제의 스크립트에 syslog로 내용을 전송하는 함수를 추가했습니다. 

이 스크립트에서 event로 걸어 놓은 것은 tcp_retransmit_skb()라는 함수입니다. tcp_retransmit_skb() 함수가 실행될 때를 event로 걸고 tcp_retransmit_skb() 함수가 실행되면 아래에 정의해 놓은 handler를 실행시킵니다. tcp_retransmit_skb() 함수를 호출할 때 인자로 받게 되는 sk 구조체의 내용을 바탕으로 IPPort 정보, RTO 값 등등을 sprintf() 함수를 이용해 문자열로 만들고 이 문자열을 syslog 명령을 이용해서 시스템의 로그 파일에 저장합니다.

이 스크립트를 실행시켜 놓고 타임아웃이 발생했을 때 들어와서 syslog를 확인한다면 재전송이 일어났는지에 대해 확인할 수 있습니다.


마치며


이번 글에서는 짧게 systemtap이라는 것에 대해 살펴봤습니다. 사실 systemtap의 내용은 워낙 방대해서 한편의 글로 모든 것을 설명하기에는 한계가 있습니다. 하지만 이번 글을 통해서 systemtap이 무엇인지, 어떻게 동작하는지, 그리고 어떤 정보들을 얻을 수 있을지에 대해 알게 되셨을 겁니다. 

systemtap은 커널 레벨에서 성능에 영향을 줄 수 있을 만한 내용들을 자세히 살펴볼 수 있는 좋은 툴이지만, 사용자 고자 하는 사람이 문제가 발생했을 때 어떤 부분을 추적해야 하는지 알아야 한다는 아주 큰 허들이 있습니다. 예를 들면 TCP 재전송이 발생할 때는 tcp_retransmit_skb()라는 함수가 호출된다는 사실을 알아야 위 예제에서 사용했던 systemtap 스크립트를 만들 수가 있습니다. 

하지만 꼭 만들 정도의 수준으로 systemtap을 다루지 못한다고 하더라도, 이미 많이 만들어져 있는 예제를 잘 활용할 수만 있다면 성능 분석이나 장애 상황의 원인을 파악하는 데에 좋은 툴이 될 거라고 생각합니다. 

앞으로도 좋은 예제들을 통해서 systemtap을 좀 더 다뤄볼 생각입니다. 감사합니다.

브런치는 최신 브라우저에 최적화 되어있습니다. IE chrome safari