Linux Kernel(4.19) Hacks

rousalome.egloos.com

포토로그 Kernel Crash


통계 위젯 (화이트)

115199
1107
135843


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

이전 절에서 유저 프로세스에게 종료 시그널을 전달했을 때 유저 프로세스가 소멸되는 흐름을 살펴봤습니다. 그런데 유저 프로세스는 '종료' 시그널을 받아 소멸될 수 있지만 프로세스가 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 명령어로 앞에서 작성한 Makefile을 실행하면 rpi_proc_exit라는 실행 파일이 만들어집니다. 아울러 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 로그에서 함수의 이름을 보면 특정한 패턴이 있습니다. 함수의 심벌 이름과 함수가 호출되는 코드의 함수 오프셋 주소가 출력된다는 것입니다. 예를 들어 다음과 같은 ftrace 메시지는 어떻게 해석할 수 있을까요?

do_group_exit+0x4c/0xe4

이것은 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>:

05 번째 줄을 보면 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번째 줄의 메시지를 분석해볼까요?

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 시그널을 전달해 자신이 종료될 것이라고 통지한다.

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


#프로세스

프로세스 소개 
프로세스 확인하기  
프로세스는 어떻게 생성할까?  
유저 레벨 프로세스 실행 실습  
커널 스레드  
커널 내부 프로세스의 생성 과정   
프로세스의 종료 과정 분석  
태스크 디스크립터(task_struct 구조체)  
스레드 정보: thread_info 구조체  
프로세스의 태스크 디스크립터에 접근하는 매크로 함수  
프로세스 디버깅  
   * glibc의 fork() 함수를 gdb로 디버깅하기  


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

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



    핑백

    덧글

    댓글 입력 영역