Linux Kernel(4.19) Hacks

rousalome.egloos.com

포토로그 Kernel Crash


통계 위젯 (화이트)

30137
1186
128675


[리눅스커널] 시스템 콜: strace와 ftrace로 시스템 콜 디버깅하기 11. 시스템 콜

이전 소절에서 strace를 활용해 유저 공간에서 시스템 콜 동작을 확인했습니다. 이번에는 strace와 ftrace를 함께 보면서 시스템 콜 세부 동작을 분석해보겠습니다. 

먼저 설정 방법을 단계별로 알아봅시다.
ftrace 설정 
strace 실행 

ftrace 이벤트를 설정하고 strace를 실행하기

시스템 콜 ftrace 이벤트를 설정하는 전체 명령어는 다음과 같습니다.
#!/bin/bash

echo  > /sys/kernel/debug/tracing/set_event
sleep 1

echo 0 > /sys/kernel/debug/tracing/tracing_on
sleep 1

echo nop > /sys/kernel/debug/tracing/current_tracer
sleep 1"

echo 1 > /sys/kernel/debug/tracing/events/raw_syscalls/sys_enter/enable
echo 1 > /sys/kernel/debug/tracing/events/raw_syscalls/sys_exit/enable
sleep 1

echo 1 > /sys/kernel/debug/tracing/tracing_on
sleep 1

syscall_ftrace.sh 란 셸 스크립트 파일로 저장해서 실행합니다.

다음으로 이전 소절에서 소개한 바와 같이 strace를 실행합니다. 
strace –fF ./simple_exit

이어서 다음 명령어로 get_ftrace.sh 셸 스크립트를 실행해 ftrace 로그를 받습니다.  
root@raspberrypi:/home/pi# ./get_ftrace.sh 
ftrace off

ftrace와 strace 메시지를 함께 분석해보기

이번에는 strace 프로그램을 실행했을때 동작한 ftrace 로그를 함께 분석하겠습니다.

1 simple_exit-896 [003] 330.985283: sys_enter: NR 64 (0, 7ec6b5f8, 10, 1, 37e, 0)
2 simple_exit-896 [003] 330.985286: sys_exit: NR 64 = 894
3 simple_exit-896 [003] 330.985434: sys_enter: NR 20 (37e, 7ec6b5f8, 10, 1, 37e, 0)
4 simple_exit-896 [003] 330.985436: sys_exit: NR 20 = 896
5 simple_exit-896 [003] 330.985631: sys_enter: NR 4 (1, 32c008, 23, 0, 23, 32c008)
6 simple_exit-896 [003] 330.985644: sys_exit: NR 4 = 35
7 simple_exit-896 [003] 330.985816: sys_enter: NR 162 (7ec6b5f8, 7ec6b5f8, 10, 2, 0, 7ec6b5f8)
8 simple_exit-896  [003] 332.9859 60: sys_exit: NR 162 = 0
9 simple_exit-896 [003] 332.986414: sys_enter: NR 248 (0, 0, 0, ffffffff, 1, 0)
10 simple_exit-896 [003] 332.986418: do_exit+0x14/0xb60 <-do_group_exit+0x50/0xe4
11 simple_exit-896 [003] 332.986446: <stack trace>
12 simple_exit-896 [003] 332.986848: sched_process_exit: comm=simple_exit pid=896 prio=120

1번째 줄 로그를 보겠습니다.
1 simple_exit-896 [003] 330.985283: sys_enter: NR 64 (0, 7ec6b5f8, 10, 1, 37e, 0)
2 simple_exit-896 [003] 330.985286: sys_exit: NR 64 = 894

64번 시스템 콜이 실행됐음을 알 수 있습니다. 다음 경로에 있는 unistd.h 해더 파일로 64번 시스템 콜 핸들러 매크로는 __NR_getppid 임을 알 수 있습니다. 
[/usr/include/arm-linux-gnueabihf/asm/unistd-common.h]
#define __NR_getppid (__NR_SYSCALL_BASE+ 64)

위 ftrace 로그는 다음 strace 로그에 대응합니다.
[pid   896] getppid()                   = 894

위 정보를 토대로 다음과 같은 사실을 알 수 있습니다. 

    getppid() 시스템 콜 함수를 호출해서 894란 값을 반환했다.

같은 방식으로 ftrace 로그와 strace 로그를 시스템 콜 종류 별로 함께 보겠습니다.

다음은 부모 PID를 읽는 시스템 콜 동작입니다.
[ftrace 로그]
3 simple_exit-896 [003] 330.985434: sys_enter: NR 20 (37e, 7ec6b5f8, 10, 1, 37e, 0)
4 simple_exit-896 [003] 330.985436: sys_exit: NR 20 = 896
...
[strace 로그]
 [pid   896] getpid()                    = 896

[시스템 콜 번호]
[/usr/include/arm-linux-gnueabihf/asm/unistd-common.h]
#define __NR_getpid (__NR_SYSCALL_BASE+ 20)

다음은 write 시스템 콜 동작입니다. ftrace 와 strace 로그 같이 파일 스트링을 쓴 길이 35를 반환합니다.
[ftrace]
5 simple_exit-896 [003] 330.985631: sys_enter: NR 4 (1, 32c008, 23, 0, 23, 32c008)
6 simple_exit-896 [003] 330.985644: sys_exit: NR 4 = 35

[strace]
57 [pid   896] write(1, "raspbian tracing ppid:894 pid:89"..., 35raspbian tracing ppid:894 pid:896 
58 ) = 35

[시스템 콜 번호]
[/usr/include/arm-linux-gnueabihf/asm/unistd-common.h]
#define __NR_write (__NR_SYSCALL_BASE+  4)

다음은 슬립에 진입하는 nanosleep 시스템 콜 동작입니다.
[ftrace]
7 simple_exit-896 [003] 330.985816: sys_enter: NR 162 (7ec6b5f8, 7ec6b5f8, 10, 2, 0, 7ec6b5f8)
8 simple_exit-896  [003] 332.985960: sys_exit: NR 162 = 0

[strace]
[pid   896] nanosleep({tv_sec=2, tv_nsec=0},  <unfinished ...>

[시스템 콜 번호]
[/usr/include/arm-linux-gnueabihf/asm/unistd-common.h]
#define __NR_nanosleep (__NR_SYSCALL_BASE+162)

이번 소절에서 소개한 방식을 활용하면 유저 공간과 커널 공간에서 시스템 콜 동작을 하나의 그림으로 분석할 수 있습니다. 특히 다음과 같은 상황에서 유용하게 활용할 수 있습니다.
유저 공간에서 시스템 콜이 제대로 발생했는지 확인하고 싶을 때
유저 공간에서 시스템 콜을 발생했는데 커널 공간에서 시스템 콜 핸들러가 실행 여부를 확인하고 싶을 때 
시스템 콜 발생과 시스템 콜 핸들러 실행 시 오류 메시지를 확인하고 싶을 때

이렇게 리눅스에서 제공하는 ftrace와 strace를 활용하면 더 유익한 디버깅 정보를 얻을 수 있습니다.

"이 포스팅이 유익하다고 생각되시면 공감 혹은 댓글로 응원해주시면 감사하겠습니다.
"혹시 궁금한 점이 있으면 댓글로 질문 남겨주세요. 아는 한 성실히 답변 올려드리겠습니다!" 

Thanks,
Austin Kim(austindh.kim@gmail.com)


#Reference: 시스템 콜
시스템 콜 주요 개념 소개
유저 공간에서 시스템 콜은 어떻게 발생할까
시스템 콜 핸들러는 어떤 동작을 할까? 
시스템 콜 실행 완료 후 무슨 일을 할까?
시스템 콜 관련 함수  
시스템 콜 디버깅  






핑백

덧글

  • lpc 2019/12/31 00:06 # 삭제 답글

    Guider라는 툴이 둘다 지원합니다.
    sysrec 명령어는 ftrace,
    strace / systop 명령어는 ptrace를 사용합니다.
    repo는 https://github.com/iipeace/guider
  • AustinKim 2019/12/31 08:06 #

    Guider라는 툴을 소개해주셔서 감사합니다. 꼭 써 봐야 겠군요.
댓글 입력 영역