printk 외에도 커널에서는 커널 로그를 통해 커널 동작을 보여주는 기능을 제공합니다. 즉, 커널에서 지원하는 dump_stack() 함수를 호출하면 콜스택을 커널 로그로 볼 수 있습니다.
dump_stack() 함수의 사용법은 간단합니다. 커널 로그로 콜스택을 보고 싶은 코드에 dump_stack() 함수를 추가하기만 하면 됩니다.
dump_stack() 함수를 호출하려면 코드의 윗부분에 다음과 같이 "linux/kernel.h" 헤더 파일을 추가해야 합니다.
#include <linux/kernel.h>
이어서 dump_stack() 함수의 선언부를 봅시다.
asmlinkage __visible void dump_stack(void);
인자와 반환값 타입이 모두 void입니다. 커널 소스코드의 어디든 dump_stack() 함수만 추가하면 됩니다.
dump_stack() 함수로 커널 로그에서 콜스택 확인하기
이번에는 앞에서 설명한 dump_stack() 함수를 써서 커널 로그로 콜스택을 볼 수 있는 방법을 알아보겠습니다. 다음 패치 코드를 봅시다.
diff --git a/kernel/fork.c b/kernel/fork.c
index 6a219fea4926..cdc5d9ff0900
--- a/kernel/fork.c
+++ b/kernel/fork.c
1 @@ -2017,6 +2017,8 @@ struct task_struct *fork_idle(int cpu)
2 * It copies the process, and if successful kick-starts
3 * it and waits for it to finish using the VM if required.
4 */
5 +
6 +static int debug_kernel_thread = 1;
7 long _do_fork(unsigned long clone_flags,
8 unsigned long stack_start,
9 unsigned long stack_size,
10 @@ -2049,6 +2051,11 @@ long _do_fork(unsigned long clone_flags,
11 p = copy_process(clone_flags, stack_start, stack_size,
12 child_tidptr, NULL, trace, tls, NUMA_NO_NODE);
13 add_latent_entropy();
14 +
15 + if (debug_kernel_thread) {
16 + printk("[+][%s] process n", current->comm);
17 + dump_stack();
18 + }
먼저 패치 코드를 입력하는 방법을 소개하겠습니다. 6 번째 줄의 코드와 같이 _do_fork() 함수 바로 위에 debug_kernel_thread 전역 변수를 선언하고 _do_fork() 함수에서 add_latent_entropy(); 다음에 보이는 15~18 번째 줄 코드를 입력하면 됩니다.
이어서 패치 코드의 의미를 알아보자면 프로세스를 생성할 때 _do_fork() 함수가 호출되는데, 이때 함수 콜스택을 확인하기 위한 코드입니다.
_do_fork() 함수는 프로세스를 생성할 때만 호출됩니다. 자주 호출되는 함수는 아니니 안심하고 패치 코드를 입력합시다.
위와 같은 패치 코드를 입력한 다음 커널 이미지를 빌드하고 시스템에 설치합시다. 부팅 후 커널 로그에서 다음과 같은 메시지를 볼 수 있습니다.
1 [ 3.819188] CPU: 1 PID: 149 Comm: systemd-udevd Not tainted 4.19.30-v7+ #3
2 [ 3.819196] Hardware name: BCM2835
3 [ 3.819237] [<8010ffc0>] (unwind_backtrace) from [<8010c1fc>] (show_stack+0x20/0x24)
4 [ 3.819257] [<8010c1fc>] (show_stack) from [<80789dfc>] (dump_stack+0xc8/0x10c)
5 [ 3.819282] [<80789dfc>] (dump_stack) from [<8011c8ec>] (_do_fork+0xdc/0x43c)
6 [ 3.819301] [<8011c8ec>] (_do_fork) from [<8011cd68>] (sys_clone+0x30/0x38)
7 [ 3.819320] [<8011cd68>] (sys_clone) from [<80108180>] (__sys_trace_return+0x0/0x10)
그럼 커널 로그를 분석해볼까요? 1번째 줄을 봅시다.
1 [ 3.819188] CPU: 1 PID: 149 Comm: systemd-udevd Not tainted 4.19.30-v7+ #3
콜스택을 실행한 프로세스 정보입니다. PID가 149인 systemd-udevd 프로세스가 CPU1에서 실행 중입니다.
02~07번째 줄은 콜스택입니다. 함수 호출은 07번째 줄에서 03번째 줄 방향으로 이뤄집니다.
_do_fork() 함수 위에 보이는 함수들은 dump_stack() 함수에서 콜스택을 출력할 때마다 보이는 함수로서 무시해도 되는 함수 호출 정보입니다.
6번째 줄의 메시지는 sys_clone() 함수에서 _do_fork() 함수를 호출한다고 알려줍니다.
6 [ 3.819301] [<8011c8ec>] (_do_fork) from [<8011cd68>] (sys_clone+0x30/0x38)
dump_stack() 함수를 사용할 때의 주의사항
1초에 100번 이상 호출되는 함수에서 dump_stack() 함수 호출을 추가하면 시스템 응답 속도가 매우 느려질 수 있습니다. 따라서 dump_stack() 함수를 호출해서 콜스택을 보려는 코드가 자주 호출되는지 반드시 점검할 필요가 있습니다.
그런데 dump_stack() 함수 내부에서는 printk보다 훨씬 많은 일을 합니다. dump_stack() 함수를 실행하면 내부에서 현재 실행 중인 프로세스 스택 주소를 읽어서 스택에 푸시된 프레임 포인터(Frame Pointer) 레지스터를 읽습니다. ARM 함수 호출 규약에 따라 프레임 포인터 레지스터를 읽어서 함수 호출 내역을 추적하는 동작을 반복합니다. 따라서 커널 입장에서 printk보다 dump_stack() 함수를 호출할 때 더 많은 일을 합니다.
이처럼 dump_stack() 함수는 다음과 같은 불편함이 있습니다.
함수 실행 빈도를 몰라 dump_stack() 함수를 쓰려고 하니 조금은 두렵기도 하다.
또한 커널 코드에 dump_stack() 함수를 추가하고 커널 빌드를 해야 한다.
커널에서는 이 같은 불편함을 해소할 수 있는 강력한 디버깅 기능을 지원합니다. 그 주인공인 ftrace에 대해 이어지는 절에서 살펴보겠습니다.
* 유튜브 강의 동영상도 있으니 같이 들으시면 좋습니다.
"혹시 궁금한 점이 있으면 댓글로 질문 남겨주세요. 아는 한 성실히 답변 올려드리겠습니다!"
Thanks,
Austin Kim(austindh.kim@gmail.com)
커널 디버깅과 코드 학습
# Reference: For more information on 'Linux Kernel';
디버깅을 통해 배우는 리눅스 커널의 구조와 원리. 1
디버깅을 통해 배우는 리눅스 커널의 구조와 원리. 2
최근 덧글