truss, apptrace - 윈디하나의 솔라나라

목차

개요

실시간을 요하는 프로세스에 대해 사용주의

truss(1)와 같은 유틸은
- 시스템 콜의 진입 시점에서, 실행중인 프로세스를 중단하고, 시스템 콜 호출 인자를 알아낸 후, 다시 프로세스를 실행한다.
- 시스템 콜의 반환 시점에서, 실행중인 프로세스를 중단하고, 시스템 콜 반환 내용을 알아낸 후, 다시 프로세스를 실행한다.
즉 추적하려하는 프로세스의 시스템 콜 정보를 얻기 위해 프로세스를 정지했다가 재시작(정확히는 컨텍스트 스위칭)하는 일을 반복한다.

단일 프로세스, 단일 쓰레드를 사용하는 경우에는 문제가 될 일이 없지만, 타이밍에 민감한 멀티 쓰레드 프로그램이나 실시간 프로세스는 큰 문제가 될 수 있다. 또한 64비트 프로세스에서는 더 느려진다. 이러한 문제는 DTrace에서 해결되었다. 윈디하나의 솔라나라: DTrace (작성중)를 읽어보자. 또한 DTrace 기반으로 truss 를 흉내낸 dtruss 라는 스크립트가 DTraceToolkit에 포함되어 배포되고 있으니 사용해보자.

truss 사용 - 기본

  1. 실행방법

    원하는 프로세스를 트레이스 하기 위해, truss를 실행하는 방법에는 아래와 같이 두가지 방법이 있다. 하나는 명령을 주어 실행시킨 후 트레이스하는 방법이고, 다른 하나는 이미 실행된 프로세스를 잡아 트레이스하는 방법이다.
    truss [옵션] 명령
    truss [옵션] -p PID
    exec(2), fork(2) 시스템 콜에 의해 생성된 프로세스까지 트레이스 하려면 -f 옵션을 같이 사용하면 된다.

  2. 예제

    truss 를 설명하기 위해 아래와 같은 예제를 사용했다. fork(2)를 사용했기 때문에 truss에 -f옵션을 주어 실행해야 원하는 트레이싱이 가능하다.
    truss_sample.c
    		 (363 바이트)
    #include <stdio.h>
#include <sys/types.h>
#include <unistd.h>

void main() {
    printf("Wait for 10 secs\n");
    sleep(10);
    pid_t f = fork();
    if (f < 0) {
        printf("Unable to fork.\n");
    } else if (f == 0) {
        printf("Hello, World! I'm child. PID=%d\n", getpid());
    } else {
        printf("Hello, World! PID=%d\n", getpid());
    }
}

    root@wl ~ # cc -o truss_sample truss_sample.c
root@wl ~ # ./truss_sample
Wait for 10 secs
Hello, World! I'm child. PID=11791
Hello, World! PID=11790
root@wl ~ #

    ※ 첫번째 방법
root@wl ~ # truss ./truss_sample
execve("truss_sample", 0x08047D48, 0x08047D50)  argc = 1
mmap(0x00000000, 4096, PROT_READ|PROT_WRITE|PROT_EXEC, MAP_PRIVATE|MAP_ANON, -1, 0) = 0xCFFF0000
resolvepath("/usr/lib/ld.so.1", "/lib/ld.so.1", 1023) = 12
getcwd("/root", 1013)              = 0
resolvepath("/root/truss_sample", "/root/truss_sample", 1023) = 28
xstat(2, "/root/truss_sample", 0x08047B28) = 0
open("/var/ld/ld.config", O_RDONLY)             Err#2 ENOENT
xstat(2, "/usr/local/xml/lib/libc.so.1", 0x08047358) Err#2 ENOENT
xstat(2, "/usr/lib/libc.so.1", 0x08047358)      = 0
resolvepath("/usr/lib/libc.so.1", "/lib/libc.so.1", 1023) = 14
open("/usr/lib/libc.so.1", O_RDONLY)            = 3
mmap(0x00010000, 32768, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_ALIGN, 3, 0) = 0xCFFB0000
mmap(0x00010000, 1212416, PROT_NONE, MAP_PRIVATE|MAP_NORESERVE|MAP_ANON|MAP_ALIGN, -1, 0) = 0xCFE80000
mmap(0xCFE80000, 1101957, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_TEXT, 3, 0) = 0xCFE80000
mmap(0xCFF9E000, 30183, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_INITDATA, 3, 1105920) = 0xCFF9E000
mmap(0xCFFA6000, 4240, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANON, -1, 0) = 0xCFFA6000
munmap(0xCFF8E000, 65536)                       = 0
memcntl(0xCFE80000, 123808, MC_ADVISE, MADV_WILLNEED, 0, 0) = 0
close(3)                                        = 0
sysconfig(_CONFIG_PAGESIZE)                     = 4096
mmap(0x00010000, 24576, PROT_READ|PROT_WRITE|PROT_EXEC, MAP_PRIVATE|MAP_ANON|MAP_ALIGN, -1, 0) = 0xCFF90000
munmap(0xCFFB0000, 32768)                       = 0
getcontext(0x080478E0)
getrlimit(RLIMIT_STACK, 0x080478D8)             = 0
getpid()                                        = 20610 [20609]
lwp_private(0, 1, 0xCFF92A00)                   = 0x000001C3
setustack(0xCFF92A60)
sysi86(SI86FPSTART, 0xCFFA6740, 0x0000133F, 0x00001F80) = 0x00000001
ioctl(1, TCGETA, 0x08047074)                    = 0
fstat64(1, 0x08046FE0)                          = 0
Wait for 10 secs
write(1, " W a i t   f o r   1 0  ".., 17)      = 17
nanosleep(0x08047CF0, 0x08047CF8) (sleeping...)
nanosleep(0x08047CF0, 0x08047CF8)               = 0
schedctl()                                      = 0xCFFF4000
Hello, World! I'm child. PID=20611
fork1()                                         = 20611
lwp_sigmask(SIG_SETMASK, 0x00000000, 0x00000000) = 0xFFBFFEFF [0x0000FFFF]
getpid()                                        = 20610 [20609]
Hello, World! PID=20610
write(1, " H e l l o ,   W o r l d".., 24)      = 24
_exit(24)

※ 두번째 방법
root@wl ~ # ./truss_sample &
Wait for 10 secs
[1] 11893
root@wl ~ # truss -p 11893
nanosleep(0x08047CF0, 0x08047CF8) (sleeping...)
nanosleep(0x08047CF0, 0x08047CF8)               = 0
schedctl()                                      = 0xCFFF3000
Hello, World! I'm child. PID=11895
fork1()                                         = 11895
lwp_sigmask(SIG_SETMASK, 0x00000000, 0x00000000) = 0xFFBFFEFF [0x0000FFFF]
getpid()                                        = 11893 [10585]
Hello, World! PID=11893
write(1, " H e l l o ,   W o r l d".., 24)      = 24
_exit(24)
[1]+  Exit 24                 ./truss_sample

※ 차일드 프로세스까지 트레이스
root@wl ~ # truss -f ./truss_sample
...
23203:  fstat64(1, 0x08046F70)                          = 0
Wait for 10 secs
23203:  write(1, " W a i t   f o r   1 0  ".., 17)      = 17
23203:  nanosleep(0x08047C80, 0x08047C88) (sleeping...)
23203:  nanosleep(0x08047C80, 0x08047C88)               = 0
23203:  schedctl()                                      = 0xCFFF4000
23203:  fork1()                                         = 23204
23204:  fork1()         (returning as child ...)        = 23203
23204:  getpid()                                        = 23204 [23203]
23204:  lwp_self()                                      = 1
23204:  lwp_sigmask(SIG_SETMASK, 0x00000000, 0x00000000) = 0xFFBFFEFF [0x0000FFFF]
23204:  getpid()                                        = 23204 [23203]
Hello, World! I'm child. PID=23204
23204:  write(1, " H e l l o ,   W o r l d".., 35)      = 35
23204:  _exit(35)
23203:  lwp_sigmask(SIG_SETMASK, 0x00000000, 0x00000000) = 0xFFBFFEFF [0x0000FFFF]
23203:  getpid()                                        = 23203 [23202]
Hello, World! PID=23203
23203:  write(1, " H e l l o ,   W o r l d".., 24)      = 24
23203:  _exit(24)

truss 사용 - 커맨드

apptrace

apptrace(1)은 라이브러리 로드 상황 및 실행한 함수 이름을 보여주는 툴이다. truss(1)에도 같은 옵션을 줄 수 있지만 이게 더 보기 편하다. 
root@wl ~ # apptrace ./truss_sample
-> truss_sample -> libc.so.1:int atexit(int (*)() = 0xcffd5ed8)
<- truss_sample -> libc.so.1:atexit()
-> truss_sample -> libc.so.1:int atexit(int (*)() = 0x80507e8)
<- truss_sample -> libc.so.1:atexit()
-> truss_sample -> libc.so.1:void __fpstart(void)
<- truss_sample -> libc.so.1:__fpstart() = 0xcfd266fc
-> truss_sample -> libc.so.1:int printf(const char * = 0x8050808 "Wait for 10 secs", void * = 0x0, ...)
Wait for 10 secs
<- truss_sample -> libc.so.1:printf() = 0x11
-> truss_sample -> libc.so.1:unsigned sleep(unsigned = 0xa)
<- truss_sample -> libc.so.1:sleep()
-> truss_sample -> libc.so.1:pid_t fork(void)
<- truss_sample -> libc.so.1:fork()
-> truss_sample -> libc.so.1:getpid(0x0, 0x8047ce0, 0x80506bd) ** NR
-> truss_sample -> libc.so.1:int printf(const char * = 0x8050830 "Hello, World! I'm child. PID=%d", void * = 0x51a5, ...)
Hello, World! I'm child. PID=20901
<- truss_sample -> libc.so.1:printf() = 0x23
-> truss_sample -> libc.so.1:exit(0x23, 0x8047ce0, 0x805065f) ** NR
<- truss_sample -> libc.so.1:fork() = 0x51a5
-> truss_sample -> libc.so.1:getpid(0x51a5, 0x8047ce0, 0x80506bd) ** NR
-> truss_sample -> libc.so.1:int printf(const char * = 0x8050854 "Hello, World! PID=%d", void * = 0x51a4, ...)
Hello, World! PID=20900
<- truss_sample -> libc.so.1:printf() = 0x18
-> truss_sample -> libc.so.1:exit(0x18, 0x8047ce0, 0x805065f) ** NR
root@wl ~ #

솔라리스의 TNF

솔라리스의 트레이스 기능중 하나가 TNF다. 사용하기 위해서는 소스 코드를 수정해야 하지만 그만큼 강력한 기능을 제공한다.

dtrace vs. truss

milek's blog 에서 DTrace와 truss의 비교 글의 일부를 인용해보았다. 극단적인 예이긴 하지만, 전체적인 맥락에서는 맞는 결과다.
truss_compare.c
 (893 바이트)
// Based On http://milek.blogspot.com/2009/04/truss1m-vs-dtrace1m.html

#include <thread.h>
#include <stdlib.h>
#include <pthread.h>
#include <fcntl.h>
#include <sys/types.h>
#include <sys/stat.h>
#include <unistd.h>
#include <stdio.h>

void *thread_func(void *arg)
{
  int *N=arg;
  int i;
  struct stat buf;

  for (i=0; i<*N; i++)
    stat("/tmp", &buf);

  return(0);
}

int main(int argc, char **argv)
{
  int N, iter;
  int i;
  int rc;
  pthread_t tid[255];

  if (argc != 3)
  {
    printf("%s number_of_threads number_of_iterations_per_thread\n", argv[0]);
    exit(1);
  }

  N = atoi(argv[1]);
  iter = atoi(argv[2]);

  for (i=0; i<N; i++)
  {
    if (rc = pthread_create(&tid[i], NULL, thread_func, &iter))
      printf("Thread #%d creation failed [%d]\n", i, rc);
  }


  /* wait for all threads to complete */
  for (i=0; i<N; i++)
    pthread_join(tid[i], NULL);

  exit(0);
}

root@wl ~/t # cc -fast truss_compare.c -o threads-2
root@wl ~/t # ptime truss -t xstat -c ./threads-2 10 100000

syscall               seconds   calls  errors
xstat                   6.108 1000000
stat64                   .000       7       5
                     --------  ------   ----
sys totals:             6.108 1000007      5
usr time:                .925
elapsed:               23.050

real       23.056
user        8.380
sys        22.410
root@wl ~/t # ptime dtrace -n 'syscall::stat:entry{@=count();}' -c 'ptime ./threads-2 10 100000'
dtrace: description 'syscall::stat:entry' matched 1 probe

real        1.267
user        0.225
sys         2.278
dtrace: pid 15368 has exited

               46

real        1.673
user        0.280
sys         0.119
root@wl ~/t # ptime ./threads-2 10 100000

real        1.260
user        0.224
sys         2.277
root@wl ~/t #
RSS ATOM XHTML 5 CSS3

Copyright © 2004-2025 Jo HoSeok. All rights reserved.