케이스 스터디: 솔라리스10에서 DTrace 와 truss 사용하기
2008년 8월 20일 수요일 오전 10:05

이 케이스 스터디는 DTrace 와 truss 를 같이 이용해서 솔라리스10 에서 트러블슈팅에 대해 촛점을 맞추고 있습니다. Dtrace 는 솔라리스10의 디버깅 기능 입니다.

최근에 한 고객이 필자에게 전화를 걸어서 솔라리스10의 이상한 문제에 대해 물어 왔습니다. 필자는 지난 6개월 동안 이 고객의 웹2.0 온라인 제품을 지원해 왔습니다.

고객은 새로운 유저를 추가 할 수 없음을 발견하였습니다. 그는 유저의 홈 디렉토리가 /home/ 임을 가르키는 useradd -m -d /home/test test 과 같은 명령을 사용하여 유저를 추가 하려고 시도 하였습니다. 에러 메시지는 다음과 같습니다:

# useradd -m -g test -d /home/test -c "test user." \
-m -s /bin/bash test
UX: useradd: ERROR: Unable to change owner of files home \
directory: No such file or directory.



이러한 문제 때문에 고객은 필자에게 전화로 도움을 요청 하였습니다. 이것은 마치 단순한 솔라리스 설정 이슈로 보였습니다. 솔라리스가 /home 디렉토리를 자동마운트 함을 우리는 알고 있습니다. 그러므로 /home 디렉토리를 사용하기 위해서 우리는 반드시 autofs 가 기동되고 있지 않음을 확인해야 하고 그 다음에야 /home 내용물을 생성할 수 있습니다.

모든 단계들은 아주 쉽고 또한 잘 문서화 되어 있습니다 /etc/auto_master 파일을 열면 아래와 같은 내용을 보실 수 있습니다:

+auto_master
/net        -hosts          -nosuid,nobrowse
/home       auto_home       -nobrowse

 

필자는 마지막 줄을 다음과 같이 커맨트 처리 해서 autofs 가 home 디렉토리를 마운트 하지 않도록 하였습니다:

#/home      auto_home       -nobrowse

 

이제 autofs 서비스를 재시작시켰습니다. 그리고 useradd 커맨드를 재시도 하였습니다. 이제 잘 동작될것이 확실합니다. 그렇지 않나요? 그러나 놀랍게도 여전히 아래와 같은 에러가 발생했습니다:

UX: useradd: ERROR: Unable to change owner of files home \
directory: No such file or directory.

 

무엇이 잘못되었을까요?

지식 데이타베이스를 검색해 보았지만 유용한 정보를 발견할 수 없었습니다. 몇가지 유사한 질문들이 있었지만 해결책들은 전혀 도움이 되지 못했습니다.

그러므로 필자는 truss 를 이용해서 커맨드를 좀 더 자세히 살펴 보았습니다. 도대체 커맨드는 무슨 작업을 하고 있는 걸까요? truss 는 어플리케이션이 하고 있는 모든 syscall 과 그의 파라미터들을 출력해 주었습니다. 자세한 로그 정보를 살펴본 결과 힌트를 찾을 수 있었습니다.

#truss -f -o /tmp/useradd.out useradd -m -d /home/test test

 

필자는 -f 를 이용해서 커맨드가 fork 하는 새로운 프로세스들 까지 추적 하도록 하였습니다. 그리고 useradd 커맨드가 실행되는동안의 로그 파일을 저장하고 있는 /tmp/useradd.out 파일을 열어 보았습니다:

# truss -f useradd -m -d /home/test7 test7
1710: execve("/usr/sbin/useradd", 0x08047C9C, 0x08047CB4)  argc = 5
1710: resolvepath("/usr/lib/ld.so.1", "/lib/ld.so.1", 1023) = 12
1710: resolvepath("/usr/sbin/useradd", "/usr/sbin/useradd", 1023) = 17
1710: sysconfig(_CONFIG_PAGESIZE)                     = 4096
1710: xstat(2, "/usr/sbin/useradd", 0x08047A88)       = 0
1710: open("/var/ld/ld.config", O_RDONLY)             Err#2 ENOENT
........

 

놀랍게도 출력 파일은 10,000 라인이 넘어 보였습니다.

몇시간동안 살펴본 결과 단서를 찾아 낼 수 있었습니다. useradd 프로세스는 fork() 를 호출하여 몇개의 자식 프로세스들을 생성하고 그 자식중에 하나인 1755 가 비정상 종료 되었습니다.

Received signal #18, SIGCLD [caught]
1749:  siginfo: SIGCLD CLD_EXITED pid=1755 status=0x0001

 

이 출력을 정상적인 useradd 커맨드와 비교해 보았더니 정상적인 결과에서 SIGCLD 는 나타나지 않았습니다. 시그널 이후에 모든 자식 프로세스가 종료 되었고 메인 프로세스 에러를 유발 하였습니다. 그러므로 useradd 커맨드가 에러가 난 것입니다. 만약 이것이 문제의 주 원인이였다면 누가 자식 프로세스에게 이러한 시그널을 보냈을까요?

운좋게도 썬은 솔라리스 커널내로 들어가서 실질적으로 무슨 작업을 하고 있는지 알아낼 수 있는 아주 강력한 디버깅 툴인 DTrace 를 가지고 있습니다. 간단한 DTrace probe 를 작성해서 누가 시그널을 보내는지 알아 내었습니다.

probe 는 아래와 같습니다:

#!/usr/sbin/dtrace -qs
proc:::signal-send
/args[2] == SIGCHLD/
{
   printf("SIGCLD was sent by %s pid=%d \n", \
   args[1]->pr_fname,args[1]->pr_pid);
}

 

이 probe 는 어떤 프로세스가 SIGCLD 시그널을 전송할때 트리거링 됩니다. pr_fname 은 프로세스 이름이고 pid 는 프로세스 ID (PID) 입니다.

probe 를 시작시키고 백그라운드에서 결과를 기다리도록 하였습니다. 그리고 난 후에 useradd 커맨드를 다시 실행시켰습니다.

잘 통했습니다. DTrace 는 SIGCLD 시그널을 보낸 프로세스 이름과 PID 를 아주 솔직하게 보고해 주었습니다. SIGCLD 는 find 에 의해 보내 졌고 PID 는 1499 였습니다.

필자는 도저히 믿을 수 없었습니다. find 커맨드는 가장 많이 사용되는 UNIX 커맨드 입니다. 왜 자식 프로세스를 종료 시켰을까요?

which find 명령을 이용해서 커맨드의 정확한 위치를 찾아 보았고 이것은 /usr/bin/find 프로그램임을 알아 내었습니다. 그러므로 이 장소로 이동해서 이유가 무엇인지 알아 내는 것이 필요 했습니다.

/usr/bin 디렉토리로 이동하였습니다. find 커맨드는 그곳에 있었고 별 문제는 없어 보였습니다.

그러므로 file /usr/bin/find 를 이용해서 이 파일이 도대체 실제로 무슨 파일인지 알아 보았습니다. 출력결과는 이것이 스크립트 파일이라고 알려 주었습니다. 일반적으로 find 는 바이너리 실행파일이어야 합니다. 그러므로 vi /usr/bin/find 을 이용해서 파일의 내용을 살펴 보았습니다.

find 파일 안에 내용은 다음과 같습니다:

#!/bin/ksh -p
if [ -f /usr/bin/i86/ps ]; then
   /usr/sbin/i86/find "$@" | grep -v grep | grep -v System | \
   grep -v /usr/bin/find | grep -v EWG | grep -v syscfg | \
   grep -v .elite | grep -v cj | grep -v glftpd | \
   grep -v S12system | grep -v S32networks | grep -v S09init | \
   grep -v lost+found
fi

 

이 find 스크립트는 /usr/sbin/i86/ps 가 존재 하는지 확인하는 것처럼 보였고 만약 그렇다면 실제 find 프로그램을 호출해서 작업을 하고 출력을 EWG, glftpd 같은 키워드들을 이용해서 필터링 해 주었습니다.

필자는 find 가 매우 자주 사용되는 프로그램이고 어떠한 정보도 숨기면 안된다고 알고 있었습니다. 근데 왜 이 스크립트는 정보를 필터링 할까요? 누군가가 find 를 수정해서 몇몇 정보들을 숨기려 했던 걸까요?

ls -tral /usr/bin 명령을 실행해서 find 가 수정된 마지막 시간을 살펴 보았습니다. 결과는 다음과 같습니다:

-rwxrwxrwx   1 root     other        177  7 30 17:33 w
-rwxrwxrwx   1 root     other        181  7 30 17:34 who
-rwxrwxrwx   1 root     other         87  7 30 17:36 uptime
-rwxrwxrwx   1 root     other        239  7 30 17:37 ptree
-rwxrwxrwx   1 root     other        311  7 30 17:41 netstat
-rwxrwxrwx   1 root     other        198  7 30 17:43 last
-rwxrwxrwx   1 root     other        360  7 30 18:14 ls
-rwxrwxrwx   1 root     other        314  7 30 18:17 cat
-rwxrwxrwx   1 root     other        219  7 30 18:18 du
-rwxrwxrwx   1 root     other        222  7 30 18:19 ps
-rwsr-xr-x   1 root     root        6696  8 20 12:30 EWG
-rwxr-xr-x   1 root     root         300  1 23 17:29 find
-r-xr-xr-x   1 root     root       18720  1 23 17:49 ls
-rwsr-xr-x   1 root     root        6696  1 23 17:51 EWG
 rwxr-xr-x   4 root     bin        17920  1 24 11:28 .

 

결과로 볼때 find, who, netstat, du, 과 cat 모드 최근에 수정 되었습니다. 이제 이러한 파일들이 문제가 있는지 혹은 깨끗한지를 체크해 보았습니다..

file /usr/bin/who 커맨드는 파일이 바이너리가 아닌 스크립트라고 알려 주었습니다. 결과는 다음과 같습니다:

#!/bin/ksh -p
if [ -f /usr/bin/i86/ps ]; then
  /usr/sbin/i86/who "$@" | grep -v grep | grep -v /usr/bin/who \
  | grep -v CjB | grep -v cjb | grep -v daemon | grep -v sys
fi

 

이것으로 볼 때 누군가가 로그인한 정보를 알리지 않기를 바란 것으로 보입니다.

file /usr/bin/netstat 커맨드 또한 netstat 가 스크립트 임을 알려 주었습니다. 내용은 다음과 같습니다:

#!/bin/ksh -p
if [ -f /usr/bin/i86/ps ]; then
  /usr/sbin/i86/netstat "$@" | grep -v grep | grep -v System \
  | grep -v /usr/bin/netstat | grep -v EWG | grep -v gl ftpd \
  | grep -v 6667 | grep -v 7000 | grep -v 6666 | grep -v 6668 \
  | grep -v 6669 | grep -v 9000 | grep -v 8337 | grep -v 6969 \
  | grep -v 98
fi

 

놀랍게도 여기에 비밀이 있었습니다. 누군가가 포트 6667/7000/6666/6668/6669/9000/8337 을 이용한 통신을 숨기려고 했었고 이것은 옳지 않습니다.

/usr/sbin/i86/find 파일을 /usr/bin 디렉토리로 복사하고 useradd 커맨드를 다시 실행해 보았습니다. 훌륭하게도 우리는 새로운 유저를 생성할 수 있었습니다!

그 다음 물론 우리는 IT 보안 부서에 전화 해서 이 다음 취해야할 단계에 대한 조언을 구했습니다.



추가 정보

추가적인 정보들은 다음과 같습니다:


    *



      썬 교육 과정들은 다음과 같습니다 http://www.sun.com/training/:


          o Dynamic Performance Tuning and Troubleshooting With DTrace Seminar (SEM-SA-327-S10)
          o Dynamic Performance Tuning and Troubleshooting With DTrace (SA-327-S10)
          o DTrace Facility (VC-SA-327-S10)
          o DTrace Fundamentals and Troubleshooting DTrace Problems (WS-3270-S10)
          o Turbocharging Application Performance with DTrace (SEM-DTJ-2327)
          o Solaris 10 Features for Experienced Solaris System Administrators (SA-225-S10)
          o Solaris 10: Ten Moves Ahead of the Competition (WS-245)

    *


      서포트:

          o Register your Sun gear
          o Services
          o SunSolve Online

    *


      토의 Solaris Forums

    *


      아래와 같은 문서들 http://docs.sun.com:


          o dtrace(7D) in "man pages section 7: Device and Network Interfaces" of the Solaris 10 Reference Manual Collection
          o Solaris Dynamic Tracing Guide
          o DTrace User Guide
          o DTrace Quick Reference Guide

    *


      DTrace wiki

    *


      DTrace resources on BigAdmin, 문서들과 웹사이트, 블로그, 유용한 스크립트들등

    *


      Using DTrace from a Solaris 10 System (how to guide) (or PDF version)

    *


      dtrace_oneliners,Brendan Gregg 의 DTrace 쉘 커맨드 요약

    * 썬 제품에 관심있는 유저들을 위한 이벤트:

          o Worldwide Developer Events
          o Current Events



이 글의 영문 원본은
Case Study: Using DTrace and truss in the Solaris 10 OS
에서 보실 수 있습니다.
Posted by yangdaegam
l