부모 자식 프로세스 생성 실습 및 ftrace 로그 분석 


이번에 리눅스 시스템 프로그래밍으로 프로세스를 생성해 봅시다. 소스 코드는 다음과 같으니 같이 입력해 봅시다.
1  #include <stdio.h>
2  #include <unistd.h>
3  #include <sys/types.h>
4
5  #define PROC_TIMES  7
6  #define SLEEP_DURATION  2
7  #define FORK_MAX_TIMES  3
8
9  void raspbian_proc_process(void);
10
11 void raspbian_proc_process(void) 
12 {
13 int proc_times = 0;
14
15 for(proc_times = 0; proc_times < PROC_TIMES; proc_times++) {
16 printf("raspbian tracing ppid:%d pid:%d \n", getppid(), getpid());
17 sleep(SLEEP_DURATION);
18 }
19
20  exit(EXIT_SUCCESS);
21 }

22 int main() 
23 {
24 pid_t pid;
25 int fork_times = 0;
26
27 printf("About to fork process \n");
28
29 pid = fork();
30
31 if ( pid == 0 )  {
32 printf("start execution of child process\n");
33 raspbian_proc_process();
34 }
35
36 else if ( pid > 0 ) {
37 printf("start execution of parent process\n");
38 raspbian_proc_process();
39 }
40
41 return 0;
42 }

이전 절에 작성한 코드에서 다음 동작이 추가됐습니다. 29번째 줄 코드부터 분석을 시작합니다.
29 pid = fork();
30
31 if ( pid == 0 )  {
32 printf("start execution of child process\n");
33 raspbian_proc_process();
34 }
35
36 else if ( pid > 0 ) {
37 printf("start execution of parent process\n");
38 raspbian_proc_process();
39 }

fork() 함수를 호출해서 자식 프로세스를 생성합니다. fork() 함수는 실행 후 pid란 지역변수로 반환값을 저장합니다. pid가 0이면 자식 프로세스 혹은 pid가 0보다 크면 부모 프로세스가 생성된 겁니다. 만약 fork() 함수 실행 도중 오류가 발생하면 자식 프로세스가 생성되지 않고 -1를 반환합니다.

위 코드를 입력한 다음 raspbian_test_fork.c 란 이름으로 저장합시다.
raspbian_fork: raspbian_test_fork.c
gcc -o raspbian_fork raspbian_test_fork.c

이전 시간에 작성한 ftrace 로그 설정 셸 스크립트인 ./clone_process_debug.sh를 실행합니다.

다음 명령어로 raspbian_fork 프로세스를 실행합시다.
root@raspberrypi:/home/pi # ./raspbian_fork 
About to fork process 
start execution of parent process
raspbian tracing ppid:895 pid:17120 
start execution of child process
raspbian tracing ppid:17120 pid:17121 
raspbian tracing ppid:895 pid:17120 
raspbian tracing ppid:17120 pid:17121

화면에 출력되는 메시지는 raspbian_test_fork.c 파일에서 작성한 코드가 실행하면서 출력합니다. pid가 17120/17121인 프로세스가 실행하는 것으로 보입니다.

다음 명령어로 실행 중인 프로세스를 확인합시다.
root@raspberrypi:/home/pi # ps -ely | grep raspbian_fork
S   UID   PID  PPID  C PRI  NI   RSS    SZ WCHAN  TTY          TIME CMD
S  1000 17120   895  0  80   0   320   453 hrtime pts/0    00:00:00 raspbian_fork
S  1000 17121 17120  0  80   0    96   453 hrtime pts/0    00:00:00 raspbian_fork

위 메시지로 보아 pid가 17121인 raspbian_fork 프로세스의 부모 프로세스의 pid는 17120임을 알 수 있습니다. 마찬가지로 pid가 17120인 raspbian_fork 프로세스 부모 프로세스 pid는 895입니다. 

이렇게 raspbian_fork 프로세스를 실행하면 14초 정도 구동하다가 프로세스가 종료합니다. 그 이유는 14초 정도 raspbian_proc_process() 함수 실행 후 다음 20번째 줄 코드와 같이 exit() 함수를 실행해서 프로세스를 종료하기 때문입니다.
11 void raspbian_proc_process(void) 
12 {
13 int proc_times = 0;
14
15 for(proc_times = 0; proc_times < PROC_TIMES; proc_times++) {
16 printf("raspbian tracing ppid:%d pid:%d \n", getppid(), getpid());
17 sleep(SLEEP_DURATION);
18 }
19
20  exit(EXIT_SUCCESS);
21 }

이 후 이전에 썼던 방식으로 다음 스크립트를 실행해서 ftrace 로그를 라즈베리파이에서 추출합시다.
root@raspberrypi:/home/pi#./get_ftrace.sh

프로세스 생성과 종료 과정 메시지가 포함된 ftrace 전체 로그는 다음과 같습니다. 각 단계 별로 ftrace 로그를 분석하겠습니다.
1 raspbian_fork-17120 [003] ....1318.513909: copy_process+0x14/0x17d8 <-_do_fork+0xb0/0x3ec
2  raspbian_fork-17120 [003] ....1318.513921: <stack trace>
3 => _do_fork+0xb0
4 => SyS_clone+0x30
5 => ret_fast_syscall+0x0
...
6 raspbian_fork-17120 [003] d...1318.514446: sched_switch: prev_comm=raspbian_fork prev_pid=17120 prev_prio=120 prev_state=S ==> next_comm=swapper/3 next_pid=0 next_prio=120
7 raspbian_fork-17121 [002] d...1318.514869: sched_switch: prev_comm=raspbian_fork prev_pid=17121 prev_prio=120 prev_state=S ==> next_comm=swapper/2 next_pid=0 next_prio=120
...
8 raspbian_fork-17120 [003] d...1320.514615: sched_switch: prev_comm=raspbian_fork prev_pid=17120 prev_prio=120 prev_state=S ==> next_comm=swapper/3 next_pid=0 next_prio=120
9 raspbian_fork-17121 [002] d...1320.515011: sched_switch: prev_comm=raspbian_fork prev_pid=17121 prev_prio=120 prev_state=S ==> next_comm=kworker/u8:0 next_pid=17108 next_prio=120
...
10 raspbian_fork-17120 [003] d...1322.514829: sched_switch: prev_comm=raspbian_fork prev_pid=17120 prev_prio=120 prev_state=S ==> next_comm=kworker/u8:0 next_pid=17108 next_prio=120
11 raspbian_fork-17121 [002] d...1322.515192: sched_switch: prev_comm=raspbian_fork prev_pid=17121 prev_prio=120 prev_state=S ==> next_comm=kworker/u8:0 next_pid=17108 next_prio=120
...
12 raspbian_fork-17121 [002] ....  1343.333582: do_exit+0x14/0xc18 <-do_group_exit+0x50/0xe4
13 raspbian_fork-17120 [003] ....  1343.333583: do_exit+0x14/0xc18 <-do_group_exit+0x50/0xe4
14 raspbian_fork-17121 [002] ....  1343.333621: <stack trace>
15 => SyS_exit_group+0x24/SyS_exit_group+0x24
16 => ret_fast_syscall+0x0/0x28
17   raspbian_fork-17120 [003] ....  1343.333621: <stack trace>
18 => SyS_exit_group+0x24/SyS_exit_group+0x24
19 => ret_fast_syscall+0x0/0x28
20 lxterminal-876   [000] d...  1343.333844: sched_switch: prev_comm=lxterminal prev_pid=876 prev_prio=120 prev_state=S ==> next_comm=Xorg next_pid=454 next_prio=120
21 Xorg-454   [000] dn..  1343.333946: sched_wakeup: comm=lxterminal pid=876 prio=120 target_cpu=000
22 Xorg-454   [000] d...  1343.333957: sched_switch: prev_comm=Xorg prev_pid=454 prev_prio=120 prev_state=R ==> next_comm=lxterminal next_pid=876 next_prio=120
23 raspbian_fork-17120 [003] ....  1343.333959: sched_process_exit: comm=raspbian_fork pid=17120 prio=120
24 raspbian_fork-17121 [002] ....  1343.333980: sched_process_exit: comm=raspbian_fork pid=17121 prio=120
25 raspbian_fork-17120 [003] d...  1343.334028: signal_generate: sig=17 errno=0 code=2 comm=bash pid=895 grp=1 res=0
26 lxterminal-876   [000] dnh.  1343.334048: sched_wakeup: comm=bash pid=895 prio=120 target_cpu=000
27 raspbian_fork-17121 [002] d...  1343.334049: signal_generate: sig=17 errno=0 code=2 comm=systemd pid=1 grp=1 res=0

1번째 로그부터 분석을 시작합니다.
1 raspbian_fork-17120 [003] ....1318.513909: copy_process+0x14/0x17d8 <-_do_fork+0xb0/0x3ec
2 raspbian_fork-17120 [003] ....1318.513921: <stack trace>
3 => _do_fork+0xb0
4 => SyS_clone+0x30
5 => ret_fast_syscall+0x0

pid가 17120인 raspbian_fork 프로세스가 pid가 17121인 raspbian_fork 프로세스를 생성하는 동작입니다.
raspbian_test_fork.c 파일에서 유저 공간에서 프로세스를 생성하는 코드는 29번째 줄과 같았습니다. 
22 int main() 
23 {
24 pid_t pid;
25 int fork_times = 0;
26
27 printf("About to fork process \n");
28
29 pid = fork();

유저 공간에서 fork() 함수를 호출하면 시스템 콜이 실행해서 커널 공간에서 SyS_clone() 이란 함수를 호출하는 겁니다.

다음 6~11번째 줄 로그를 분석해봅시다.
6 raspbian_fork-17120 [003] d...1318.514446: sched_switch: prev_comm=raspbian_fork prev_pid=17120 prev_prio=120 prev_state=S ==> next_comm=swapper/3 next_pid=0 next_prio=120
7 raspbian_fork-17121 [002] d...1318.514869: sched_switch: prev_comm=raspbian_fork prev_pid=17121 prev_prio=120 prev_state=S ==> next_comm=swapper/2 next_pid=0 next_prio=120
...
8 raspbian_fork-17120 [003] d...1320.514615: sched_switch: prev_comm=raspbian_fork prev_pid=17120 prev_prio=120 prev_state=S ==> next_comm=swapper/3 next_pid=0 next_prio=120
9 raspbian_fork-17121 [002] d...1320.515011: sched_switch: prev_comm=raspbian_fork prev_pid=17121 prev_prio=120 prev_state=S ==> next_comm=kworker/u8:0 next_pid=17108 next_prio=120
...
10 raspbian_fork-17120 [003] d...1322.514829: sched_switch: prev_comm=raspbian_fork prev_pid=17120 prev_prio=120 prev_state=S ==> next_comm=kworker/u8:0 next_pid=17108 next_prio=120
11 raspbian_fork-17121 [002] d...1322.515192: sched_switch: prev_comm=raspbian_fork prev_pid=17121 prev_prio=120 prev_state=S ==> next_comm=kworker/u8:0 next_pid=17108 next_prio=120

raspbian_fork-17120와 raspbian_fork-17121 프로세스가 2초 간격으로 스케줄링되어 실행합니다. 
raspbian_test_fork.c 파일에서 다음과 같이 두 개 프로세스가 2초 주기로 휴면되도록 구현한 코드가 실행하는 겁니다.
11 void raspbian_proc_process(void) 
12 {
13 int proc_times = 0;
14
15 for(proc_times = 0; proc_times < PROC_TIMES; proc_times++) {
16 printf("raspbian tracing ppid:%d pid:%d \n", getppid(), getpid());
17 sleep(SLEEP_DURATION);
18 }
19
20  exit(EXIT_SUCCESS);
21 }

다음은 유저 레벨 프로세스에서 위에서 보이는 20번째 줄 exit(EXIT_SUCCESS); 함수를 실행하면 커널에서 어떤 동작을 하는지 살펴볼 차례입니다. 

exit() 리눅스 저수준 표준 함수 중 하나이며 리눅스 시스템 프로그램에서 많이 쓰는 함수입니다. 
다음 리눅스 메뉴얼 페이지에서 exit() 함수에 대한 내용을 읽을 수 있습니다.
EXIT(3)                   Linux Programmer's Manual                  EXIT(3)
NAME         top
       exit - cause normal process termination
SYNOPSIS         top
       #include <stdlib.h>

       void exit(int status);
DESCRIPTION         top
       The exit() function causes normal process termination and the value
       of status & 0377 is returned to the parent (see wait(2)).

명시적으로 프로세스를 종료시키는 동작입니다.
로그 분석으로 돌아가겠습니다.
12 raspbian_fork-17121 [002] ....  1343.333582: do_exit+0x14/0xc18 <-do_group_exit+0x50/0xe4
13 raspbian_fork-17120 [003] ....  1343.333583: do_exit+0x14/0xc18 <-do_group_exit+0x50/0xe4
14 raspbian_fork-17121 [002] ....  1343.333621: <stack trace>
15 => SyS_exit_group+0x24/SyS_exit_group+0x24
16 => ret_fast_syscall+0x0/0x28
17   raspbian_fork-17120 [003] ....  1343.333621: <stack trace>
18 => SyS_exit_group+0x24/SyS_exit_group+0x24
19 => ret_fast_syscall+0x0/0x28

raspbian_fork-17120와 raspbian_fork-17121 프로세스가 종료하는 동작입니다.
이 로그에서 프로세스가 종료하는 흐름은 다음 그림과 같습니다.

리눅스 저수준 exit() 함수를 유저 프로세스에서 실행하니 해당 함수에 대한 시스템 콜 핸들러인 sys_exit_group() 함수에서 do_group_exit() -> do_exit() 순서로 함수를 호출해서 두 프로세스를 종료합니다.

마지막으로 27~31번째 줄 로그를 봅시다.
27 raspbian_fork-17120 [003] ....  1343.333959: sched_process_exit: comm=raspbian_fork pid=17120 prio=120
28 raspbian_fork-17121 [002] ....  1343.333980: sched_process_exit: comm=raspbian_fork pid=17121 prio=120
29 raspbian_fork-17120 [003] d...  1343.334028: signal_generate: sig=17 errno=0 code=2 comm=bash pid=895 grp=1 res=0
30 lxterminal-876   [000] dnh.  1343.334048: sched_wakeup: comm=bash pid=895 prio=120 target_cpu=000
31 raspbian_fork-17121 [002] d...  1343.334049: signal_generate: sig=17 errno=0 code=2 comm=systemd pid=1 grp=1 res=0

sched_process_exit 이란 ftrace 이벤트로 pid 17120, 17121 인 raspbian_fork 프로세스가 종료하고, 각각 부모 프로세스에 시그널을 전달합니다.

raspbian_fork-17120 프로세스는 bash란 부모 프로세스에 시그널을 전달하고, raspbian_fork-17121 프로세스는 부모 프로세스인 raspbian_fork-17120가 종료됐으니 pid가 1인 systemd 프로세스에 시그널을 전달합니다.
29 raspbian_fork-17120 [003] d...  1343.334028: signal_generate: sig=17 errno=0 code=2 comm=bash pid=895 grp=1 res=0
30 lxterminal-876   [000] dnh.  1343.334048: sched_wakeup: comm=bash pid=895 prio=120 target_cpu=000
31 raspbian_fork-17121 [002] d...  1343.334049: signal_generate: sig=17 errno=0 code=2 comm=systemd pid=1 grp=1 res=0

유저 공간에서 fork() 이란 함수를 호출하면 리눅스 커널에서 어떤 과정으로 프로세스를 생성하는지 확인했습니다. 이번에 다룬 내용을 정리합시다.
1. 유저 공간에서 fork() 함수를 호출하면 시스템 콜이 실행되어 커널 공간에 있는 SyS_clone()이란 함수를 호출하고 _do_fork() 이란 프로세스를 생성하는 함수를 호출합니다.

2. 유저 레벨 프로세스는 스스로 프로세스를 생성하지 못합니다. 시스템 라이브러리 도움을 받아서 커널 공간에 프로세스 생성 요청을 합니다.

3. 프로세스를 종료할 때 do_exit() 함수를 호출합니다.

4. 프로세스가 종료할 때 부모 프로세스에게 자신이 종료됐다는 사실을 시그널로 알립니다.

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

Reference(프로세스 관리)
4.9 프로세스 컨택스트 정보는 어떻게 저장할까?
 4.9.1 컨택스트 소개
 4.9.2 인터럽트 컨택스트 정보 확인하기
 4.9.3 Soft IRQ 컨택스트 정보 확인하기
 4.9.4 선점 스케줄링 여부 정보 저장
4.10 프로세스 디스크립터 접근 매크로 함수
 4.10.1 current_thread_info()
 4.10.2 current 매크로란
4.11 프로세스 디버깅
 4.11.1 glibc fork 함수 gdb 디버깅
 4.11.2 유저 프로그램 실행 추적 



저작자표시

'리눅스 커널의 구조와 원리 > 4. 프로세스(Process) 관리' 카테고리의 다른 글

[리눅스커널] 프로세스를 생성 세부 함수 분석: do_fork() copy_process()  (0) 2019.03.10
[리눅스커널] 커널 스레드란 무엇인가  (0) 2019.03.10
[리눅스커널][프로세스] 기본 유저 레벨 프로세스 실행 실습 및 ftrace 로그 분석  (0) 2019.02.11
[리눅스커널][프로세스] 프로세스는 어떻게 생성하나?  (0) 2019.02.11
[리눅스커널][프로세스] ps 명령어로 프로세스 확인하기  (0) 2019.02.11
라즈베리파이에서 IRQ 스레드 생성 과정 디버깅하기

이번 절에선 request_threaded_irq() 함수를 호출하면 결국 kthread_create() 함수를 실행해서 IRQ 스레드를 생성하는 과정까지 짚어 봤습니다. 이제 디버깅 과정을 통해 배운 내용을 다지는 시간을 갖겠습니다.

먼저 디버깅을 위한 패치 코드를 소개합니다.

 

+기호로 볼드체로 된 부분이 추가할 코드입니다.
패치 코드를 입력할 함수는 __kthread_create_on_node() 입니다. 이전 절에서 분석하지 않은 __kthread_create_on_node() 함수에 IRQ 스레드를 생성하는 코드를 작성한 이유는 무엇일까요?

그 이유을 알게 위해서 다음 setup_irq_thread() 함수 코드를 살펴볼 필요가 있습니다.
1 static int
2 setup_irq_thread(struct irqaction *new, unsigned int irq, bool secondary)
3 {
...
4 if (!secondary) {
4 t = kthread_create(irq_thread, new, "irq/%d-%s", irq,
5    new->name);

4 번째 줄 코드와 같이 set_up_irqthread() 함수에서 kthread_create() 함수를 호출하면 IRQ 스레드를 생성한다고 알고 있습니다. kthread_create() 함수 구현부 코드를 보면 kthread_create_on_node() 함수를 바로 호출하고 이어서 __kthread_create_on_node() 함수를 호출합니다. 그래서 __kthread_create_on_node() 함수에 디버깅 코드를 작성한 것입니다. 

다음 코드에서 볼드체로 된 부분을 눈여겨봅시다.
1 #define kthread_create(threadfn, data, namefmt, arg...) \
2 kthread_create_on_node(threadfn, data, NUMA_NO_NODE, namefmt, ##arg)
3
4 struct task_struct *kthread_create_on_node(int (*threadfn)(void *data),
5    void *data, int node,
6    const char namefmt[],
7    ...)
8 {
9 struct task_struct *task;
10  va_list args;
11
12 va_start(args, namefmt);
13 task = __kthread_create_on_node(threadfn, data, node, namefmt, args);

우리는 kthread_create() 함수를 호출하면 커널 쓰레드를 생성한다고 알고 있습니다. kthread_create() 함수를 보면 2 번째 줄 코드와 같이 kthread_create_on_node() 함수로 치환됩니다. 

이어서 kthread_create_on_node() 함수를 열어보면 13 번째 줄 코드와 같이  __kthread_create_on_node() 함수를 호출합니다.

__kthread_create_on_node() 함수에 디버깅 코드를 작성한 이유를 살펴봤습니다. 이제 패치 코드를 분석할 차례입니다. 

먼저 수정한 4번째 줄 코드부터 분석합니다.
struct task_struct *__kthread_create_on_node(int (*threadfn)(void *data),
    void *data, int node,
    const char namefmt[],
    va_list args)
4 +
5 + int irq_thread_enable = !strncmp(namefmt, "irq", 3); 
6 +      char *process_name = &namefmt[0];

__kthread_create_on_node() 함수로 전달되는 namefmt란 파라미터를 “irq” 문자열과 비교합니다. Strncmp() 함수는 지정한 문자열 개수만큼만 스트링을 비교하는 라이브러리 함수입니다. 이때 namefmt 변수 첫 번째 주소 기준으로 세 개 스트링이 “irq” 이면 irq_thread_enable 변수를 1로 설정합니다. 

IRQ 스레드 이름은 setup_irq_thread() 함수에서 "irq/%d-%s" 인자로 kthread_create() 함수를 호출할 때 지정한다고 알고 있습니다. 

다음 5번째 줄 코드를 보겠습니다. 
setup_irq_thread() 함수에서 지정한 "irq/%d-%s" 가 __kthread_create_on_node() 함수의 namefmt 인자로 전달됩니다. 그래서 이 앞 세 개의 스트링이 “irq”인지 비교하는 코드를 작성한 것입니다.  
1 static int
2 setup_irq_thread(struct irqaction *new, unsigned int irq, bool secondary)
3 {
...
4 if (!secondary) {
5 t = kthread_create(irq_thread, new, "irq/%d-%s", irq,  // <<-[1]
6    new->name);

다음 디버깅 정보를 출력하는 13번째 줄 코드를 볼 차례입니다.
13+    if (irq_thread_enable) {
14+        void *irq_threadfn = (void*)threadfn;
15+        
16+        printk("[+] irq_thread handler: %pS caller:(%pS) \n", 
17+ irq_threadfn, (void *)__builtin_return_address(0)); 
18+        dump_stack();
19+ }

13~19번째 줄 코드는irq_thread_enable 지역변수가 1이면 실행합니다.
irq_thread_enable 변수가 1이면 무엇을 의미할까요? 쓰레드 이름이 “irq”로 시작하니 IRQ 스레드를 생성하는 조건입니다. 14번째 줄 코드에서 IRQ 스레드 핸들 함수 포인터를 저장하고 있는 threadfn을 irq_threadfn  포인터에 캐스팅합니다. threadfn인자는 irq_thread() 함수 주소를 저장하고 있습니다. 

16번째 줄 코드는 IRQ 스레드 핸들 함수와 자신을 호출한 함수 정보를 출력합니다. 
16+        printk("[+] irq_thread handler: %pS caller:(%pS) \n", 
17+ irq_threadfn, (void *)__builtin_return_address(0));

이어서 18번째 줄 코드는 콜스택을 출력하는 dump_stack 함수를 호출합니다.
18+        dump_stack();

이렇게 코드를 입력하고 커널 빌드를 완료한 후 라즈베리파이에 커널 이미지를 설치합니다.
이후 라즈베리파이를 리부팅 시키고 커널 로그(/var/log/kern.log)을 열어봅시다.

이번에는 패치 코드가 실행하면서 출력한 커널 로그를 분석하겠습니다. 분석할 전체 로그는 다음과 같습니다.
1  [0.722882] mmc-bcm2835 3f300000.mmc: mmc_debug:0 mmc_debug2:0
2  [0.722892] mmc-bcm2835 3f300000.mmc: DMA channel allocated
3  [0.722933] [+] process_name: irq/%d-%s caller:(kthread_create_on_node+0x30/0x38) 
4  [0.722947] [+] irq_thread handler: irq_thread+0x0/0x20c
 caller:(kthread_create_on_node+0x30/0x38) 
5  [0.722958] CPU: 0 PID: 31 Comm: kworker/0:1 Not tainted 4.14.39-v7+ #15
6  [0.722962] Hardware name: BCM2835
7  [0.722980] Workqueue: events deferred_probe_work_func
8  [0.723006] (unwind_backtrace) from [<8010c21c>] (show_stack+0x20/0x24)
9  [0.723022] (show_stack) from (dump_stack+0xc8/0x10c)
10 [0.723039] (dump_stack) from (__kthread_create_on_node+0x1c4/0x1e0)
11 [0.723055] (__kthread_create_on_node) from (kthread_create_on_node+0x30/0x38)
12 [0.723070] (kthread_create_on_node) from (setup_irq_thread+0x54/0xe4)
13 [0.723086] (setup_irq_thread) from (__setup_irq+0x260/0x730)
14 [0.723101] (__setup_irq) from (request_threaded_irq+0xec/0x160)
15 [0.723118] (request_threaded_irq) from (devm_request_threaded_irq+0x78/0xcc)
16 [0.723140] (devm_request_threaded_irq) from (bcm2835_mmc_probe+0x514/0x644)
17 [0.723159] (bcm2835_mmc_probe) from (platform_drv_probe+0x60/0xc0)
18 [0.723176] (platform_drv_probe) from (driver_probe_device+0x244/0x2f8)
19 [0.723193] (driver_probe_device) from (__device_attach_driver+0xa8/0xdc)
20 [0.723210] (__device_attach_driver) from (bus_for_each_drv+0x70/0xa4)
21 [0.723228] (bus_for_each_drv) from (__device_attach+0xc0/0x124)
22 [0.723245] (__device_attach) from (device_initial_probe+0x1c/0x20)
23 [0.723261] (device_initial_probe) from (bus_probe_device+0x94/0x9c)
24 [0.723278] (bus_probe_device) from (deferred_probe_work_func+0x68/0x150)
25 [0.723296] (deferred_probe_work_func) from (process_one_work+0x224/0x518)
26 [0.723317] (process_one_work) from (worker_thread+0x60/0x5f0)
27 [0.723333] (worker_thread) from (kthread+0x144/0x174)
28 [0.723348] (kthread) from (ret_from_fork+0x14/0x28)

먼저 커널 쓰레드 이름과 쓰레드 핸들 함수를 분석해 봅시다.
3  [0.722933] [+] process_name: irq/%d-%s caller:(kthread_create_on_node+0x30/0x38) 
4  [0.722947] [+] irq_thread handler: irq_thread+0x0/0x20c
 caller:(kthread_create_on_node+0x30/0x38) 

쓰레드 이름은 irq/%d-%s 이고 자신을 호출한 함수가 kthread_create_on_node+0x30입니다. 
또한 IRQ 스레드 핸들 함수는 irq_thread()란 정보를 알 수 있습니다.

다음 5~6 번째 줄 로그입니다.
5  [0.722958] CPU: 0 PID: 31 Comm: kworker/0:1 Not tainted 4.14.39-v7+ #15
6  [0.722962] Hardware name: BCM2835

이 함수가 어느 프로세스에서 실행됐는지 알려주는 로그입니다. PID가 31인 kworker/0:1란 워커쓰레드가 CPU0에서 수행됐음을 알 수 있습니다.

이번에는 콜스택을 살펴보겠습니다.
platform_drv_probe() 함수에서 bcm2835_mmc_probe() 함수를 호출하고 있습니다. 이 정보로 부팅 과정에 IRQ 스레드를 생성한다는 사실을 알 수 있습니다. 보통 드라이버에서 짠 코드의 함수 이름에 probe가 보이면 부팅 도중 한 번 실행합니다.
11 [0.723055] (__kthread_create_on_node) from (kthread_create_on_node+0x30/0x38)
12 [0.723070] (kthread_create_on_node) from (setup_irq_thread+0x54/0xe4)
13 [0.723086] (setup_irq_thread) from (__setup_irq+0x260/0x730)
14 [0.723101] (__setup_irq) from (request_threaded_irq+0xec/0x160)
15 [0.723118] (request_threaded_irq) from (devm_request_threaded_irq+0x78/0xcc)
16 [0.723140] (devm_request_threaded_irq) from (bcm2835_mmc_probe+0x514/0x644)
17 [0.723159] (bcm2835_mmc_probe) from (platform_drv_probe+0x60/0xc0)
18 [0.723176] (platform_drv_probe) from (driver_probe_device+0x244/0x2f8)

콜스택을 보면 이번 절에서 분석한 함수를 볼 수 있습니다.
request_threaded_irq() 함수로 출발해서 __kthread_create_on_node() 함수까지 호출되고 있습니다. kthread_create() 함수 대신 실제 kthread_create_on_node() 함수가 실행한다는 점도 확인할 수 있습니다.

이번 소절에선 IRQ 스레드를 생성하는 흐름을 점검했습니다. 
request_threaded_irq() 함수를 호출하면 __kthread_create_on_node() 함수를 호출해서 IRQ 스레드를 생성합니다. 

다음 절에서는 IRQ 스레드가 어떻게 실행하는지 점검해보겠습니다.


저작자표시

'리눅스 커널의 구조와 원리 > 6. 인터럽트 후반부 처리' 카테고리의 다른 글

[리눅스커널] IRQ 스레드를 생성하는 샘플 코드 살펴보기  (0) 2019.03.10
[리눅스커널] IRQ 스레드를 생성하는 시점 확인하기  (0) 2019.03.10
[리눅스커널] IRQ 스레드(threaded IRQ)에 대한 소개  (0) 2019.03.10
[리눅스커널] 인터럽트 후반부 기법은 왜 적용할까?  (0) 2019.03.10
IRQ 스레드는 언제 생성할까?

IRQ 스레드를 생성하기 위해서는 request_threaded_irq() 함수를 호출하면 됩니다. 
IRQ 스레드를 생성하는 흐름도는 다음과 같습니다. 










request_threaded_irq() 함수를 호출하면 다음 동작을 수행합니다.
 - 전달한 IRQ 스레드 정보를 인터럽트 컨택스트에 설정
 - kthread_create() 함수를 호출해서 IRQ 스레드 생성

kthread_create() 함수는 kthread_create_on_node() 함수로 치환됩니다. 위 그림에서 이해를 돕기 위해 kthread_create() 함수를 호출하면 kthread_create_on_node() 함수를 호출하는 것처럼 표시했습니다.

우리는 커널 쓰레드를 생성할 때 kthread_create() 함수를 호출한다고 배웠습니다. IRQ 스레드도 이 kthread_create() 함수를 호출해서 생성합니다. IRQ 스레드도 커널 스레드의 한 종류입니다. 

request_threaded_irq() 함수부터 __kthread_create_on_node() 함수까지 IRQ 스레드 어떤 방식으로 생성하는지 코드를 분석하겠습니다.
 
먼저 우선 인터럽트 핸들러를 설정하는 코드를 확인할 필요가 있습니다. 어떤 인터럽트 핸들러를 설정하는 코드를 봐야 할까요? 당연히 IRQ 스레드를 생성하는 인터럽트 핸들러 코드를 봐야합니다.

이전 소절에서 확인했듯이 라즈베리파이에서는 "irq/92-mmc1" IRQ Thread를 확인할 수 있습니다. 
root@raspberrypi:/home/pi/dev_raspberrian# ps –ely | grep irq
S   UID   PID  PPID  C PRI  NI   RSS    SZ WCHAN  TTY          TIME CMD
S     0    65     2  0   9   -     0     0 irq_th ?        00:00:00 irq/92-mmc1

IRQ 스레드는 어떤 자료구조에서 관리할까요?
정답은 인터럽트 디스크립터입니다. IRQ 스레드 핸들러와 관련 필드 정보를 관리합니다.

인터럽트 디스크립터는 인터럽트 세부 속성과 IRQ 스레드 정보까지 저장합니다.

IRQ 스레드를 생성하기 위해서 request_threaded_irq() 함수를 호출해야 합니다.
함수 선언부와 인자를 소개합니다.
extern int __must_check
request_threaded_irq(unsigned int irq, irq_handler_t handler,
     irq_handler_t thread_fn,
     unsigned long flags, const char *name, void *dev);

request_threaded_irq() 함수에 전달되는 인자들은 다음과 같습니다.

unsigned int  irq: 인터럽트 번호
irq_handler_t   handler: 인터럽트 핸들러 주소
irq_handler_t   thread_fn: IRQ 스레드 핸들 함수 주소
unsigned long  flags: 인터럽터 핸들링 플래그
const char   name: 인터럽트 이름

request_threaded_irq() 함수는 동작은 2단계로 나눌 수 있습니다.

1 단계: 인터럽트 디스크립터 설정
requested_threaded_irq() 함수에 전달된 인자를 인터럽트 디스크립터 필드에
저장합니다.

2 단계: IRQ 스레드 생성
irq_handler_t thread_fn 인자가 IRQ 스레드 핸들 주소를 저장하면 IRQ 스레드를 생성합니다.

request_threaded_irq() 함수 분석
IRQ 스레드 생성 단계에 대해 소개했으니 이제 코드 분석으로 넘어갑시다.
request_threaded_irq() 함수 코드를 소개합니다.
1 int request_threaded_irq(unsigned int irq, irq_handler_t handler,
2   irq_handler_t thread_fn, unsigned long irqflags,
3   const char *devname, void *dev_id)
4 {
5  struct irqaction *action;
6  struct irq_desc *desc;
7  int retval;
...
8 action = kzalloc(sizeof(struct irqaction), GFP_KERNEL);
9 if (!action)
10 return -ENOMEM;
...
11  action->handler = handler;
12  action->thread_fn = thread_fn;  
13  action->flags = irqflags;
14  action->name = devname;
15  action->dev_id = dev_id;
16 
17  chip_bus_lock(desc);
18  retval = __setup_irq(irq, desc, action);  

먼저 8~10 번째 줄 코드를 봅시다.
8 action = kzalloc(sizeof(struct irqaction), GFP_KERNEL);
9 if (!action)
10 return -ENOMEM;

struct irqaction 타입인 action 지역 변수에 struct irqaction 구조체 크기만큼 동적 메모리를 할당합니다. 

action란 포인터 타입 지역 변수의 타입은 struct irqaction 구조체입니다. 이 변수는 8번째 줄 코드와 같이 메모리 할당을 받은 다음에 9번째와 13번째 줄 코드와 같이 인터럽트 핸들러와 IRQ 스레드 핸들러 정보를 저장합니다. 이 변수는 나중에 인터럽트 디스크립터의 action 필드에 저장됩니다. 

만약 메모리를 할당 못하면 10 번째 줄 코드을 실행해 –ENOMEM 매크로를 반환하며 함수 실행을 종료합니다.

다음에 볼 11~15 번째 줄 코드는 인자를 action 필드에 저장하는 동작입니다.
11  action->handler = handler;
12  action->thread_fn = thread_fn;  
13  action->flags = irqflags;
14  action->name = devname;
15  action->dev_id = dev_id;

특히 12 번째 줄 코드를 보면 IRQ 스레드 핸들 함수 주소를 저장하고 있는 thread_fn 포인터를 action->thread_fn에 저장합니다.

struct irqaction 타입 action 변수는 해당 인터럽트 디스크립터에 저장됩니다.
Trace32로 확인한 인터럽트 디스크립터 자료 구조는 다음과 같습니다.
1 (struct irq_desc *) (struct irq_desc*)0xB008B300
...
2    (struct irqaction *) action = 0xBB4E6E40  
3      (irq_handler_t) handler = 0x8061EC00 = bcm2835_mmc_irq, /* 인터럽트 핸들러 */
4      (void *) dev_id = 0xBB47B010  /* 인터럽트 핸들러 핸들
5      (void *) percpu_dev_id = 0x0 = ,
6      (struct irqaction *) next = 0x0 = ,
7      (irq_handler_t) thread_fn = 0x8061DCC4 = bcm2835_mmc_thread_irq, /* IRQ Thread 핸들러 */
8      (struct task_struct *) thread = 0xBB516CC0 /* “irq/92-mmc1” IRQ 스레드의 태스크 디스크립터 */
9      (struct irqaction *) secondary = 0x0 = ,
10      (unsigned int) irq = 92, /* 인터럽트 번호 */

위 인터럽트 디스크립터는 라즈베리파이 92번 인터럽트를 관리하는 IRQ 스레드를 설정 정보를 포함합니다. 각각 필드에 대한 설명은 주석문을 참고하시기 바랍니다.

다음 18번째 줄 코드를 보면 __setup_irq() 함수를 호출합니다.
16  retval = __setup_irq(irq, desc, action);

여기까지는 인터럽트 핸들러를 등록하는 실행 흐름과 똑같습니다. 그런데 __setup_irq() 함수 코드를 조금 더 살펴보면 Thread 스레드로 설정할 때만 동작하는 코드를 볼 수 있습니다. 

__setup_irq() 함수 분석
이어서 __setup_irq() 코드를 같이 분석해 봅시다.
1 static int
2 __setup_irq(unsigned int irq, struct irq_desc *desc, struct irqaction *new)
3 {
4 struct irqaction *old, **old_ptr;
5 unsigned long flags, thread_mask = 0;
...
6 nested = irq_settings_is_nested_thread(desc);
...
7 if (new->thread_fn && !nested) {  
8 ret = setup_irq_thread(new, irq, false);
9 if (ret)
10 goto out_mput;

우선 __setup_irq 함수에 전달되는 파라미터는 아래와 같습니다.
irq: 인터럽트 번호
desc: 인터럽트 디스크립터
new: 인터럽트 디스크립터의 action 멤버(struct irq_desc->action)

__setup_irq() 함수는 IRQ 스레드 핸들 함수가 등록됐는지 점검한 후 등록이 됐으면 setup_irq_thread() 함수를 호출해서 IRQ 스래드를 생성합니다.

먼저 6 번째 줄 코드를 봅시다. 
6 if (new->thread_fn && !nested) {  
7 ret = setup_irq_thread(new, irq, false);

이 코드는 두 가지 조건을 점검합니다.  struct irqaction 타입인 new->thead_fn 필드에 함수 포인터가 등록됐거나 nested 변수가 0일 때 setup_irq_thread() 함수를 호출합니다. 

nested 변수는 현재 설정하는 IRQ 스레드가 nested 타입인지 점검합니다. 이 기능을 쓸 경우 nested 변수가 1이 됩니다. nested 변수를 읽어 오는 다음 코드를 눈여겨봅시다.
6 nested = irq_settings_is_nested_thread(desc);

여기서 new->thead_fn 로 IRQ 스레드 핸들러 함수가 등록됐고 nested 변수가 0이면 7번째 줄 코드가 실행됩니다.

setup_irq_thread() 함수 분석 

이어서 IRQ 스레드를 생성 역할을 수행하는 setup_irq_thread() 함수를 분석하겠습니다.
1 static int
2 setup_irq_thread(struct irqaction *new, unsigned int irq, bool secondary)
3 {
4 struct task_struct *t;
5 struct sched_param param = {
6 .sched_priority = MAX_USER_RT_PRIO/2,
7 };
8
9 if (!secondary) {
10 t = kthread_create(irq_thread, new, "irq/%d-%s", irq,   
11    new->name);
12 } else {
13 t = kthread_create(irq_thread, new, "irq/%d-s-%s", irq,
14    new->name);
15 param.sched_priority -= 1;
16 }

위 코드를 보면 특별한 동작을 수행하지 않습니다. kthread_create() 함수를 호출해서 커널 스레드를 생성합니다. 이 코드로 IRQ 스레드도 커널 스레드의 한 종류라고 말할 수 있겠습니다.


커널 스레드는 커널 공간에서만 실행하는 프로세스입니다. 
유저 공간과 시스템 콜로 통신하지 않고 배경 작업으로 커널 리소스를 관리하는 역할을 수행합니다.

커널에는 다양한 커널 스레드를 볼 수 있습니다.
커널 서브 시스템이나 드라이버 목적에 맞는 커널 스레드를 생성할 수 있는 것입니다.
워크큐를 실행하는 스레드를 워커 스레드, 메모리가 부족할 때 kswapd 스레드 그리고 Soft IRQ 후반부 처리용 ksoftirqd 스레드를 예를 들 수 있습니다.

IRQ 스레드로 여러 커널 스레드 중 하나입니다.


먼저 10번째 줄 코드를 보겠습니다. irq_thread() 이란 IRQ 스레드를 제어하는 함수와 함께 "irq/%d-%s"란 이름으로 IRQ Thread를 생성합니다. 
9 t = kthread_create(irq_thread, new, "irq/%d-%s", irq,   
10    new->name);

kthread_create() 함수를 호출할 때 다음과 같은 인자를 지정합니다.
   - irq_thread: IRQ 스레드 핸들 함수
   - new: IRQ 스레드 핸들 매개 인자(struct irqaction)
   - "irq/%d-%s": IRQ 스레드 이름 타입
   - irq: 인터럽트 번호
   - new->name: 인터럽트 이름 

kthread_create() 함수에 전달하는 두 번째 파라미터인 new는 스레드 핸들 함수로 전달되는 매개 인자입니다. 이 매개 인자는 struct irqaction 구조체 타입입니다.

IRQ 스레드의 스레드 핸들인 irq_thread() 함수 코드를 보면서 매개 인자 처리 방식에 대해 조금 더 살펴보겠습니다.
1 static int irq_thread(void *data)
2 {
3 struct callback_head on_exit_work;
4 struct irqaction *action = data;

우리는 커널 쓰레드를 생성하면 커널 스레드드 핸들 함수에서 무한 루프를 돌면서 스레드 목적에 맞는 동작을 수행합니다.  그런데 IRQ 스레드는 irq_thread() 함수가 이 역할을 수행합니다. 

IRQ 스레드가 실행할 때 irq_thread() 함수가 실행하는데 함수 인자로 void 타입 data 포인터를 전달합니다. 위 irq_thread() 함수 4 번째 줄 코드를 눈여겨보면 이 포인터를 struct irqaction * 타입으로 캐스팅합니다.

이 과정을 다음 다이어그램으로 정리할 수 있습니다.

이제 IRQ 스레드를 생성하는 함수 흐름을 알아봤으니 IRQ 스레드를 생성하는 예제 코드를 살펴보겠습니다. 
[drivers/mmc/host/bcm2835-mmc.c]
1 static int bcm2835_mmc_add_host(struct bcm2835_host *host)
2 {
3 struct mmc_host *mmc = host->mmc;
4 struct device *dev = mmc->parent;
...
5 bcm2835_mmc_init(host, 0);
6 ret = devm_request_threaded_irq(dev, host->irq, bcm2835_mmc_irq,
7 bcm2835_mmc_thread_irq, IRQF_SHARED,
8 mmc_hostname(mmc), host); 

bcm2835_mmc_add_host() 함수에서 라즈베리파이에서 92번 인터럽트 핸들러와 해당 IRQ Thread를 설정하는 코드를 볼 수 있습니다.

위 코드를 보면 request_threaded_irq() 함수 대신 devm_request_threaded_irq() 함수를 써서 IRQ 스레드를 설정합니다. 함수 이름이 다르니 다른 동작을 하는 함수로 보입니다. 하지만 devm_request_threaded_irq() 함수를 열어 보면 request_threaded_irq() 함수를 호출합니다.
1 int devm_request_threaded_irq(struct device *dev, unsigned int irq,
2       irq_handler_t handler, irq_handler_t thread_fn,
3       unsigned long irqflags, const char *devname,
4       void *dev_id)
5 {
6 struct irq_devres *dr;
7 int rc;
8
...
9
10 rc = request_threaded_irq(irq, handler, thread_fn, irqflags, devname,
11   dev_id);

devm_request_threaded_irq() 함수는 인터럽트 설정 정보를 디바이스 드라이버에서 체계적으로 관리하는 동작 이외에 request_threaded_irq() 함수와 같은 역할을 수행합니다. IRQ 스레드 관점으로 devm_request_threaded_irq() 함수를 호출하면 request_threaded_irq() 함수가 실행된다고 봐도 무방합니다.

아래 코드에서 devm_request_threaded_irq() 함수에서 호출하는 request_threaded_irq() 함수는 어디서 많이 본 함수 같지 않나요? 맞습니다. 인터럽트 핸들러를 등록할 때 호출하는 request_irq() 함수에서 request_threaded_irq() 함수를 호출했습니다.  5장에서 본 다음 자료 구조를 떠 올립시다.
static inline int __must_check
request_irq(unsigned int irq, irq_handler_t handler, unsigned long flags,
    const char *name, void *dev)
{
return request_threaded_irq(irq, handler, NULL, flags, name, dev);
}

이번에 request_threaded_irq() 함수에 전달하는 인자가 약간 다른 것 같습니다.
6 ret = devm_request_threaded_irq(dev, host->irq, bcm2835_mmc_irq,
7 bcm2835_mmc_thread_irq, IRQF_SHARED,
8 mmc_hostname(mmc), host); 

6번째 줄을 보면 bcm2835_mmc_irq() 함수를 인터럽트 핸들러로 등록합니다. 이 함수는 92번 “mmc1” 인터럽트가 발생하면 호출되는 함수입니다. 

7번째 줄 코드를 보면 request_threaded_irq() 함수 세 번째 인자로 bcm2835_mmc_thread_irq() 함수를 전달합니다. 이 함수를 IRQ Thread 핸들러라고 합니다. IRQ Thread가 실행될 때 호출되는 핸들러 함수입니다.  

조금 더 이해를 돕기 위해 request_threaded_irq() 함수의 선언부를 보면 세 번째 인자로 irq_handler_t thread_fn가 선언돼 있습니다. 두 번째 인자는 인터럽트 핸들러 함수입니다.
[include/linux/interrupt.h]
extern int __must_check
request_threaded_irq(unsigned int irq, irq_handler_t handler,
     irq_handler_t thread_fn,
     unsigned long flags, const char *name, void *dev);

thread_fn 이란 함수 포인터에 bcm2835_mmc_thread_irq() 이란 IRQ Thread 핸들러 함수를 등록하는 것입니다.

이를 알기 쉬운 코드 형식으로 표현하면 아래와 같이 각각 인자를 다음과 같이 등록합니다.
인터럽트 번호: irq = host->irq
인터럽트 핸들러:  handler = bcm2835_mmc_irq
IRQ Thread 핸들러: thread_fn = bcm2835_mmc_thread_irq

인터럽트가 발생했을 때 인터럽트 컨택스트에서 수행하는 인터럽트 핸들러는 bcm2835_mmc_irq() 함수이고 “irq/92-mmc1” IRQ Thread에서 실행하는 핸들러 함수는 bcm2835_mmc_thread_irq() 함수인 것입니다. 

다음은 IRQ 스레드를 생성하는 코드를 보면서 92번 인터럽트에 대한 IRQ 스레드 이름을 어떤 규칙으로 생성하는지 알아봅시다.
1 static int
2 setup_irq_thread(struct irqaction *new, unsigned int irq, bool secondary)
3 {
4 struct task_struct *t;
5 struct sched_param param = {
6 .sched_priority = MAX_USER_RT_PRIO/2,
7 };
8
9 if (!secondary) {
10 t = kthread_create(irq_thread, new, "irq/%d-%s", irq,   
11    new->name);
12 } else {
13 t = kthread_create(irq_thread, new, "irq/%d-s-%s", irq,
14    new->name);
15 param.sched_priority -= 1;
16 }


이 정보를 참고하면 “irq=92 name=mmc1” 인터럽트의 IRQ 스레드 이름은 “irq/92-mmc1”라는 점을 유추할 수 있습니다. 

“irq/92-mmc1” IRQ 스레드는 언제 실행될까요? 이 내용은 다음 소절에서 자세히 다룰 예정인데, 92번 인터럽트가 발생하면 호출되는 인터럽트 핸들러가 IRQ 스레드 실행 여부를 결정합니다. 만약 92번 인터럽트가 발생하지 않으면 IRQ 스레드는 실행하지 않습니다.
 


저작자표시

'리눅스 커널의 구조와 원리 > 6. 인터럽트 후반부 처리' 카테고리의 다른 글

[리눅스커널] IRQ 스레드 생성 과정을 디버깅으로 알아보기  (0) 2019.03.10
[리눅스커널] IRQ 스레드를 생성하는 샘플 코드 살펴보기  (0) 2019.03.10
[리눅스커널] IRQ 스레드(threaded IRQ)에 대한 소개  (0) 2019.03.10
[리눅스커널] 인터럽트 후반부 기법은 왜 적용할까?  (0) 2019.03.10

+ Recent posts

티스토리툴바