Arm Linux Kernel Hacks

rousalome.egloos.com

포토로그 Kernel Crash


통계 위젯 (화이트)

5363
1898
209234


[리눅스커널] 라즈베리파이에서 IRQ 스레드 생성 과정 디버깅하기 6. 인터럽트 후반부 처리


지금까지 IRQ 스레드를 생성하면 커널 내부에서 다음과 같이 처리한다는 사실을 배웠습니다.

request_threaded_irq() 함수를 호출하면 인터럽트 속성을 설정한다. 
내부 함수에서 kthread_create() 함수를 실행해서 IRQ 스레드를 생성한다.

이번 시간에는 우리가 배운 함수가 실제 리눅스 시스템에서 어떻게 호출되는지 실습으로 알아보겠습니다. 디버깅 실습으로 코드를 분석한 내용을 다지는 기회가 되길 희망합니다.

패치 코드 소개

이번 실습을 하려면 '리눅스 커널 소스 코드'를 수정할 필요가 있습니다. 이를 위한 패치 코드를 소개합니다.
diff --git a/kernel/kthread.c b/kernel/kthread.c
index 1c19edf82..0bc8a0037 100644
--- a/kernel/kthread.c
+++ b/kernel/kthread.c
@@ -275,13 +275,25 @@ struct task_struct *__kthread_create_on_node(int (*threadfn)(void *data),
  struct task_struct *task;
01 struct kthread_create_info *create = kmalloc(sizeof(*create),
02      GFP_KERNEL);
03 -
04 + int irq_thread_enable = !strncmp(namefmt, "irq", 3); 
05 +    char *process_name = &namefmt[0];
06 +    
07 if (!create)
08 return ERR_PTR(-ENOMEM);
09 create->threadfn = threadfn;
10 create->data = data;
11 create->node = node;
12 create->done = &done;
13 +
14 + if ( process_name )
15 + printk("[+] process_name: %s caller:(%pS) \n", process_name, (void *)__builtin_return_address(0)); 
16 +    
17 +    if (irq_thread_enable) {
18 +        void *irq_threadfn = (void*)threadfn;
19 +        
20 +        printk("[+] irq_thread handler: %pS caller:(%pS) \n", irq_threadfn, (void *)__builtin_return_address(0));
21 +        dump_stack();
22 + }
23 
24 spin_lock(&kthread_create_lock);
25 list_add_tail(&create->list, &kthread_create_list);

위에서 소개한 패치 코드에서 +기호로 볼드체로 된 부분이 추가할 코드 블락입니다.
참고로 대부분 리눅스 프로젝트에서는 이 방식으로 코드가 어떻게 바뀌었는지 표현합니다. 이와 같이 패치 코드를 표현하는 방식을 잘 기억해둡시다.

패치 코드 설명을 드리기 전에 먼저 패치 코드 입력 방법을 소개하겠습니다.
 
다음은 패치 코드를 입력하기 전 오리지널 __kthread_create_on_node() 함수입니다. 소스 코드와 함께 있는 주석문을 보면 ‘패치 코드’를 입력할 코드 위치를 알 수 있습니다.
  
https://elixir.bootlin.com/linux/v4.19.30/source/kernel/kthread.c 
static __printf(4, 0)
struct task_struct *__kthread_create_on_node(int (*threadfn)(void *data),
    void *data, int node,
    const char namefmt[],
    va_list args)
{
DECLARE_COMPLETION_ONSTACK(done);
struct task_struct *task;
struct kthread_create_info *create = kmalloc(sizeof(*create),
     GFP_KERNEL);
/* 첫 번째 패치 코드 조각을 입력하세요 */

if (!create)
return ERR_PTR(-ENOMEM);
create->threadfn = threadfn;
create->data = data;
create->node = node;
create->done = &done;

/* 두 번째 패치 코드 조각 입력하세요 */

spin_lock(&kthread_create_lock);
list_add_tail(&create->list, &kthread_create_list);
spin_unlock(&kthread_create_lock);

위 주석문으로 된 /* 첫 번째 패치 코드 조각을 입력하세요 */ 부분에 다음 코드를 입력합시다. 

04 + int irq_thread_enable = !strncmp(namefmt, "irq", 3); 
05 +    char *process_name = &namefmt[0];
06 +    

다음 주석문인 /* 두 번째 패치 코드 조각을 입력하세요 */에 다음 코드를 작성합니다.

14 + if ( process_name )
15 + printk("[+] process_name: %s caller:(%pS) \n", process_name, (void *)__builtin_return_address(0)); 
16 +    
17 +    if (irq_thread_enable) {
18 +        void *irq_threadfn = (void*)threadfn;
19 +        
20 +        printk("[+] irq_thread handler: %pS caller:(%pS) \n", irq_threadfn, (void *)__builtin_return_address(0));
21 +        dump_stack();
22 + }

패치 코드 설명
첫 번째 패치 코드는 __kthread_create_on_node() 함수에 추가합니다. 여기서 한 가지 의문이 생깁니다.

    이전 절에서 분석하지 않은 __kthread_create_on_node() 함수에 IRQ 스레드를 
     생성하는 코드를 작성한 이유는 무엇일까?
 
여기에는 그럴만한 이유가 있습니다. 

    커널 스레드를 생성할 때 호출하는 kthread_create() 함수의 실제 구현부는 
      __kthread_create_on_node() 함수이다.

이 이유를 알려면 먼저 setup_irq_thread() 함수 코드를 살펴볼 필요가 있습니다.

https://elixir.bootlin.com/linux/v4.19.30/source/kernel/irq/manage.c 
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,
6    new->name);

5 번째 줄 코드와 같이 set_up_irqthread() 함수에서 kthread_create() 함수를 호출하면 IRQ 스레드를 생성한다고 알고 있습니다. 

5 번째 줄 코드를 보면 kthread_create() 함수를 호출합니다. 우리는 kthread_create() 함수를 하면 다음 동작을 수행한다고 알고 있습니다. 

    커널 스레드인 IRQ 스레드를 생성한다.

그런데 kthread_create() 함수는 다음 선언부와 같이 매크로 타입으로 커널 컴파일 과정에서 kthread_create_on_node() 함수로 치환됩니다.

https://elixir.bootlin.com/linux/v4.19.30/source/include/linux/kthread.h 
#define kthread_create(threadfn, data, namefmt, arg...) \
kthread_create_on_node(threadfn, data, NUMA_NO_NODE, namefmt, ##arg) 

이어서 kthread_create_on_node() 함수 구현부를 보면 가변 인자를 대입한 후 __kthread_create_on_node() 함수를 호출합니다.
struct task_struct *kthread_create_on_node(int (*threadfn)(void *data),
   void *data, int node,
   const char namefmt[],
   ...)
{
struct task_struct *task;
va_list args;

va_start(args, namefmt);
task = __kthread_create_on_node(threadfn, data, node, namefmt, args);
va_end(args);

return task;
}

위에서 분석한 내용을 조합하면 다음과 같은 사실을 이끌어 낼 수 있습니다. 

    kthread_create() 함수를 호출하면 실제 __kthread_create_on_node() 함수가 
     동작한다.  

이와 같은 이유로 __kthread_create_on_node() 함수에 디버깅 코드를 작성한 것입니다.

__kthread_create_on_node() 함수에 디버깅 코드를 작성한 이유를 살펴봤습니다. 이제 패치 코드를 더 자세히 분석하겠습니다. 

먼저 수정한 4번째 줄 코드부터 보겠습니다.

https://elixir.bootlin.com/linux/v4.19.30/source/kernel/kthread.c 
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”인지 비교하는 코드를 작성한 것입니다.  

https://elixir.bootlin.com/linux/v4.19.30/source/kernel/irq/manage.c 
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, 
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 변수는 어느 조건에서 true일까요? 
 
      irq_thread_enable는 IRQ 스레드를 생성할 때만 true이다.
  
IRQ 스레드를 생성할 때만 14~18번째 줄 코드를 실행하게 됩니다.

irq_thread_enable 변수가 1이면 무엇을 의미할까요? 스레드 이름이 “irq”로 시작하니 IRQ 스레드를 생성하는 조건입니다. 

다음 14번째 줄 코드를 보겠습니다.

14+        void *irq_threadfn = (void*)threadfn;

 IRQ 스레드 핸들 함수 주소를 저장하는 함수 포인터 threadfn을 irq_threadfn 포인터에 캐스팅합니다. 여기서 threadfn인자는 irq_thread() 함수 주소를 저장하고 있습니다. 

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

16+        printk("[+] irq_thread handler: %pS caller:(%pS) \n", 
17+ irq_threadfn, (void *)__builtin_return_address(0));

위 코드는 다음 정보를 커널 로그로 출력합니다.
IRQ 스레드 핸들 함수
자신을 호출한 함수 정보

이제 18번째 줄 코드를 볼 차례입니다.

18+        dump_stack();

dump_stack() 함수를 호출해 콜스택을 커널 로그로 출력합니다.

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

패치 코드 적용 후 커널 로그 분석하기 

IRQ 스레드는 부팅 과정에서 생성하므로 패치 코드가 실행하면서 출력한 로그는 라즈베리파이 부팅 후 확인할 수 있습니다. 이어서 커널 로그에서 출력된 디버깅 정보를 분석해보겠습니다.
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.19.30-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.19.30-v7+ #15
6  [0.722962] Hardware name: BCM2835

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

이번에는 콜스택을 살펴보겠습니다.

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)

platform_drv_probe() 함수에서 bcm2835_mmc_probe() 함수를 호출합니다. 이 정보로 부팅 과정에 IRQ 스레드를 생성한다는 사실을 알 수 있습니다. 보통 드라이버 코드의 함수 이름에 probe가 보이면 부팅 도중 한 번 실행한다고 보면 됩니다.

콜스택을 보면 이번 절에서 분석한 함수를 볼 수 있습니다.

request_threaded_irq() 함수로 출발해서 __kthread_create_on_node() 함수까지 호출  
kthread_create() 함수 대신 실제 kthread_create_on_node() 함수가 실행 


이번 소절에서 다룬 실습으로 다음 내용을 알게 됐습니다.

 첫째, IRQ 스레드는 언제 생성할까?
부팅 과정에서 request_threaded_irq() 함수를 호출하면서 IRQ 스레드가 생성됩니다.

 둘째, 커널 스레드를 생성하는 함수는 무엇인가? 
kthread_create() 함수 대신 실제 kthread_create_on_node() 함수가 실행할 때 커널 스레드를 생성합니다.
 
 셋째, 커널 로그로 함수 콜스택을 보고 싶으면 어떤 코드를 추가하면 될까?
dump_stack() 함수를 추가하면 커널 로그에서 콜스택을 볼 수 있습니다.

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


* 유튜브 강의 동영상도 있으니 같이 들으시면 좋습니다.



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


 # Reference 인터럽트 후반부 처리








6.9 Soft IRQ 서비스는 누가 언제 처리하나?




6.13 Soft IRQ 디버깅
6.13.1 ftrace Soft IRQ 이벤트 분석 방법
6.13.2 /proc/softirqs로 Soft IRQ 서비스 실행 횟수 확인


# Reference: For more information on 'Linux Kernel';

디버깅을 통해 배우는 리눅스 커널의 구조와 원리. 1

디버깅을 통해 배우는 리눅스 커널의 구조와 원리. 2




핑백

덧글

댓글 입력 영역