Linux Kernel(4.19) Hacks

rousalome.egloos.com

포토로그 Kernel Crash


통계 위젯 (화이트)

230224
1178
109352


[리눅스커널] 프로세스: exit() 함수로 프로세스 종료 과정 및 ftrace 로그 분석 4. Process Management

이전 절에서 유저 프로세스에게 종료 시그널을 전달하면 유저 프로세스가 소멸되는 흐름을 살펴봤습니다. 그런데 유저 프로세스는 '종료' 시그널을 받아 소멸될 수 있지만 다음과 같이 스스로 종료할 수 있습니다. 

이전 절에서 유저 프로세스에게 종료 시그널을 전달하면 유저 프로세스가 소멸되는 흐름을 살펴봤습니다. 그런데 유저 프로세스는 '종료' 시그널을 받아 소멸될 수 있지만 다음과 같이 스스로 종료할 수 있습니다. 

    프로세스가 POSIX exit 시스템 콜을 호출한다.

이번 시간에는 유저 프로세스가 POSIX exit 시스템 콜을 발생하면 커널 내부에서 어떤 흐름으로 프로세스가 종료되는지 실습으로 배워보겠습니다.

실습 코드를 작성하고 컴파일해보기

자, 그러면 실습할 유저 어플리케이션 코드를 함께 볼까요?
01 #include <stdio.h>
02 #include <unistd.h>
03 #include <stdlib.h>
04 
05 #define PROC_TIMES 3
06 #define SLEEP_DURATION 3  // second unit
07 
08 int main() 
09 {
10 int proc_times = 0;
11
12 for(proc_times = 0; proc_times < PROC_TIMES; proc_times++) {
13 printf("rpi tracing \n");
14 sleep(SLEEP_DURATION);
15 }
16
17 exit(EXIT_SUCCESS);
18
19 return 0;
20 }

이전 소절에서 다룬 코드와 거의 비슷하니 차이점만 설명을 드려볼까요?
05번째 줄 코드를 먼저 보겠습니다.
05 #define PROC_TIMES 3

PROC_TIMES 이 3으로 변경돼서 printf로 3번 "rpi tracing \n" 문자열을 출력합니다.
for 루프 실행을 끝낸 후 17번째 줄과 같이 exit() 함수를 호출합니다.

이전 소절에서 본 코드와 가장 큰 차이점은 유저 프로세스가 exit() 함수를 호출해 스스로 종료를 시도한다는 점입니다. 그리고 exit() 함수를 호출할 때는 플래그를 줄 수 있는데 17번째 줄에서 보이는 EXIT_SUCCESS는 정상 종료임을 알려줍니다.

위 코드를 입력한 다음 rpi_process_exit.c 이름으로 저장합시다. 컴파일을 쉽게 하기 위해 다음과 같은 코드를 작성하고 파일 이름을 Makefile으로 저장합시다.
rpi_proc_exit:rpi_process_exit.c
gcc -o rpi_proc_exit rpi_process_exit.c

코드를 작성했으니 컴파일을 할 차례입니다. “make” 명령어로 위에서 메이크 파일을 실행하면 rpi_proc_exit 실행 파일이 생성됩니다.

ftrace 설정은 이전 4.4.1 소절에서 소개한 clone_process_debug.sh를 실행해 ftrace를 설정합니다.

이제 실습할 준비가 끝났습니다. 이전 소절보단 실습 과정이 간단하니 긴장을 풀고 실습 과정을 배워봅시다.

rpi_proc_exit 프로세스를 실행하고 ftrace 로그 추출해보기

이제, 다음 단계로 실습을 해보겠습니다.

1 단계: 라즈베리파이에서 터미널을 열고 다음 명령어를 입력해 ftrace 로그 설정합니다. 
root@raspberrypi:/home/pi# ./clone_process_debug.sh 

2 단계:  다음 명령어로 rpi_proc_exit 프로그램을 실행합니다.
root@raspberrypi:/home/pi# ./rpi_proc_exit
 
3 단계: 9초 후 rpi_proc_exit 프로그램이 종료하면 이전 소절에서 소개한 get_ftrace.sh 셸 스크립트를 실행해 ftrace 로그를 받읍시다.
root@raspberrypi:/home/pi#./get_ftrace.sh

ftrace 메시지로 프로세스 생성과 종료 과정 분석하기

이제 확보한 ftrace 로그를 보면서 커널 공간에서 프로세스가 어떤 흐름으로 생성하고 종료하는지 살펴봅시다.

분석할 전체 ftrace 로그는 다음과 같습니다.
01 bash-2181 [003] .... 11491.709994: copy_process.part.5+0x14/0x1b08 <-_do_fork+0xd8/0x438
02 bash-2181 [003] .... 11491.710037: <stack trace>
03 => copy_process.part.5+0x18/0x1b08
04 => _do_fork+0xd8/0x438
05 => sys_clone+0x34/0x3c
06 => ret_fast_syscall+0x0/0x28
07 => 0x7ed03260
...
08 rpi_proc_exit-30382 [003] .... 11500.715929: do_exit+0x14/0xc18 <-do_group_exit+0x4c/0xe4
09 rpi_proc_exit-30382 [003] .... 11500.715968: <stack trace>
10 => do_exit+0x18/0xc18
11 => do_group_exit+0x4c/0xe4
12 => __wake_up_parent+0x0/0x30
13 => ret_fast_syscall+0x0/0x28
14 => 0x7ec325a8
15 rpi_proc_exit-30382 [003] .... 11500.716469: sched_process_exit: comm=rpi_proc_exit pid=30382 prio=120
16 rpi_proc_exit-30382 [003] d... 11500.716565: signal_generate: sig=17 errno=0 code=1 comm=bash pid=2181 grp=1 res=0
17 bash-2181 [003] d... 11500.716840: signal_deliver: sig=17 errno=0 code=1 sa_handler=55a6c sa_flags=14000000 

먼저 프로세스 생성 단계 ftrace 로그를 보겠습니다.
01 bash-2181 [003] .... 11491.709994: copy_process.part.5+0x14/0x1b08 <-_do_fork+0xd8/0x438
02 bash-2181 [003] .... 11491.710037: <stack trace>
03 => copy_process.part.5+0x18/0x1b08
04 => _do_fork+0xd8/0x438
05 => sys_clone+0x34/0x3c
06 => ret_fast_syscall+0x0/0x28
07 => 0x7ed03260

01~02번째 메시지 가장 왼쪽에 보이는 'bash-2181' 정보로 01~07번째 ftrace 로그를 출력하는 실체는 pid가 2181인 'bash' 프로세스입니다.

    pid가 2181인 'bash' 프로세스가 rpi_proc_exit 프로세스를 생성하는 흐름입니다.

위와 같이 ftrace 로그를 해석할 수 있는 근거는 sys_clone() 함수를 통해 _do_fork() 함수를 호출하기 때문입니다.

이번에는 rpi_proc_exit 프로세스가 종료하는 로그를 보겠습니다.
08 rpi_proc_exit-30382 [003] .... 11500.715929: do_exit+0x14/0xc18 <-do_group_exit+0x4c/0xe4
09 rpi_proc_exit-30382 [003] .... 11500.715968: <stack trace>
10 => do_exit+0x18/0xc18
11 => do_group_exit+0x4c/0xe4
12 => __wake_up_parent+0x0/0x30
13 => ret_fast_syscall+0x0/0x28

유저 공간에서 exit() 함수를 호출하면 커널 공간에서 실행되는 sys_exit_group() 함수가 호출됩니다. 이후 다음 함수 흐름으로 do_exit() 함수가 호출됩니다.
do_group_exit()
do_exit() 

이전 소절에서는 종료 시그널을 받아 커널 do_exit() 함수가 호출됐습니다. 그런데 이번에는 유저 공간에서 exit() 함수를 호출해 커널 공간에서 해당 시스템 콜 핸들러인 sys_exit_group() 함수로 시작해 do_exit() 함수가 호출됩니다.

분석 내용을 토대로 다음과 같은 사실을 알 수 있습니다.

    프로세스가 종료할 때는 커널 do_exit() 함수가 호출된다. 



여기서 한 가지 의문이 생깁니다.

    ftrace 로그에서 sys_exit_group() 함수 이름이 보이지 않는다.
   어떻게 sys_exit_group() 함수가 호출됐다고 판단하는가?

아주 예리한 질문입니다. 이제 차근 차근 그 이유에 대해서 설명을 드리겠습니다.

위 ftrace 로그에서 함수 이름을 보면 특정한 패턴이 있습니다. 함수 심볼 이름과 함수가 호출되는 코드의 함수 오프셋 주소를 출력하는 것입니다.
do_group_exit+0x4c/0xe4

예를 들어 위와 같은 ftrace 메시지는 어떻게 해석할 수 있을까요? 

    do_group_exit() 함수 시작 주소 기준 0x4c 떨어진 코드를 의미합니다.

그런데 우리가 한 가지 기억해야 할 내용이 있습니다. ARMv7 프로세스는 파이프라인을 적용한 아키텍처라 실제 호출되는 코드 주소보다 +0x4 바이트 오프셋을 출력합니다. 그렇다면 'do_group_exit+0x4c' 메시지를 다음과 같이 보는 것이 맞습니다.

    'do_group_exit+0x4c'의 실제 코드 오프셋은 do_group_exit+0x48이다.
    계산식은 0x48 = 0x48 - 0x4;

그런데 12번째 줄 메시지를 보면 __wake_up_parent 함수 시작 주소 기준 0x0만큼 주소 정보를 출력합니다.
11 => do_group_exit+0x4c/0xe4
12 => __wake_up_parent+0x0/0x30
13 => ret_fast_syscall+0x0/0x28

'__wake_up_parent 함수 시작 주소 기준으로 0x0만큼 떨어진 주소'이니 뭔가 이상합니다.

어셈블리 코드를 보면서 __wake_up_parent() 함수에서 -0x4 바이트 주소 코드를 확인해볼까요?
01 801213c4 <sys_exit_group>:
02 801213c4: e1a0c00d mov ip, sp
03 801213c8: e92dd800 push {fp, ip, lr, pc}
...
04 801213dc: e2000cff and r0, r0, #65280 ; 0xff00
05 801213e0: ebffffbe bl 801212e0 <do_group_exit>
06
07 801213e4 <__wake_up_parent>:

06 번째 줄 코드를 보면 sys_exit_group 함수 마지막 줄 명령어로 do_group_exit() 함수를 호출합니다.

__wake_up_parent() 함수 시작 주소에서 -0x4 바이트에 있는 어셈블리 코드를 보니 sys_exit_group() 함수 코드가 보입니다. 코드 내용은 do_group_exit() 함수를 호출하는 동작입니다.

이제 조금 정리가 되는 듯 합니다. 위에서 분석 내용을 토대로 다음과 같은 사실을 이끌어 낼 수 있습니다.

    '__wake_up_parent+0x0/0x30' 메시지로 실제 동작한 코드 정보는
    'sys_exit_group+0x1c/0x1c'이다.

즉 '__wake_up_parent+0x0' 주소에서 -0x4 바이트만큼 떨어진 주소에 sys_exit_group() 함수 코드가 있는 것입니다.

정리하면 12번째 줄 함수 정보는 다음과 같이 바꿀 수 있습니다.
// 기존
11 => do_group_exit+0x4c/0xe4
12 => __wake_up_parent+0x0/0x30
13 => ret_fast_syscall+0x0/0x28

// 수정
11 => do_group_exit+0x4c/0xe4
12 => sys_exit_group+0x1c/0x1c
13 => ret_fast_syscall+0x0/0x28


이번에는 16~17번째 줄 로그를 분석하겠습니다.
16 rpi_proc_exit-30382 [003] d... 11500.716565: signal_generate: sig=17 errno=0 code=1 comm=bash pid=2181 grp=1 res=0
17 bash-2181 [003] d... 11500.716840: signal_deliver: sig=17 errno=0 code=1 sa_handler=55a6c sa_flags=14000000 

이번에는 16~17번째 줄 로그를 보겠습니다.

먼저 16번째 줄 메시지를 분석해볼까요?
16 rpi_proc_exit-30382 [003] d... 11500.716565: signal_generate: sig=17 errno=0 code=1 comm=bash pid=2181 grp=1 res=0

rpi_proc_exit 프로세스는 종료 과정에서 다음과 같은 시그널을 부모 프로세스에게 전달합니다.

    pid가 2181인 부모 bash 프로세스에게 SIGCHLD 시그널을 보낸다.

16번째 줄은 ftrace signal_generate 이벤트로 시그널이 생성됐음을 알립니다. 

16번째 줄에서 보이는 메시지를 조금 더 자세히 해석해볼까요? 
'sig=17': SIGCHLD 시그널 
'comm=bash pid=2181': 시그널을 전달 받을 프로세스가 pid가 2181인 bash 프로세스  

이렇게 프로세스는 종료할 때 부모 프로세스에게 SIGCHLD 시그널을 보내 자신이 소멸할 것이란 정보를 알립니다.

다음 17번째 줄 로그를 보겠습니다.
17 bash-2181 [003] d... 11500.716840: signal_deliver: sig=17 errno=0 code=1 sa_handler=55a6c sa_flags=14000000 

먼저 로그 가장 왼쪽에 보이는 'bash-2181' 정보로 이 메시지를 출력하는 주인공은 pid가 2181인 bash 프로세스임을 알 수 있습니다.
signal_deliver: 시그널을 전달 받음
sig=17: 전달 받은 시그널
sa_handler=55a6c: 시그널 핸들러 함수 주소(유저 공간)

이번 소절에서 다룬 실습으로 다음과 같은 내용을 알게 됐습니다.
프로세스가 스스로 exit POSIX 시스템 콜을 호출하면 스스로 소멸할 수 있다.
exit POSIX 시스템 콜에 대한 시스템 콜 핸들러는 sys_exit_group() 함수다.
프로세스는 소멸되는 과정에서 부모 프로세스에게 SIGCHLD 시그널을 전달해 자신이 종료될 것이라고 통지한다.

유저 공간에서 어떤 함수를 호출하면 리눅스 커널에서 어떤 함수 흐름으로 코드가 실행되는지 전체 그림을 그리면서 파악하는 것이 중요합니다.


"혹시 궁금한 점이 있으면 댓글로 질문 남겨주세요. 아는 한 성실히 답변 올려드리겠습니다!" 

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

#Reference(프로세스 관리)
프로세스 디버깅
   glibc fork 함수 gdb 디버깅


    핑백

    덧글

    댓글 입력 영역