리눅스 커널 printk 디버깅 방법

 1. printk 란?

printk는 커널 디버깅 및 로깅 목적으로 사용되는 중요한 함수이다. 이 함수를 사용하면 커널 내에 발생하는 이벤트 및 정보를 기록하고 원하는 변수의 값 또는 주소, printk가 포함된 함수를 누가 호출했는지 등의 내용을 디버깅 할 수 있습니다.

 

 

 2. printk 사용 팁

printk는 전달하는 인자를 잘 활용하면 커널 디버깅에 많은 도움이 된다. 아래는 디버깅을 위해 printk에서 사용되는 인자를 정리한 내용이다. 

#include <linux/init.h>
#include <linux/module.h>
#include <linux/kernel.h>

#include <linux/sched.h>

void test_func2(void) 
{
	printk(KERN_INFO "Caller:%pS\n", (void *)__builtin_return_address(0));
	printk(KERN_INFO "Process:%s\n", current->comm);
}

void test_func1(void) 
{
	printk(KERN_INFO "File Name:%s, Func Name:%s, Line:%d\n",
					__FILE__, __func__, __LINE__);
	test_func2();
}

static int __init hello_init(void)
{
	printk(KERN_ALERT "Hello, world!\n");
	
	test_func1();

	return 0;
}

static void __exit hello_exit(void)
{
	printk(KERN_ALERT "Bye, World!\n");
}

module_init(hello_init);
module_exit(hello_exit);

MODULE_LICENSE("GPL");
MODULE_AUTHOR("khd0801");
MODULE_DESCRIPTION("Hello World program");

 

출력 결과

[  626.232544] Hello, world!

[  626.232552] File Name:/home/driver/hello_world/hello_world.c, Func Name:test_func1, Line:15

[  626.232553] Caller:test_func1+0x2d/0x33 [hello_world]

[  626.232557] Process:insmod

• __FILE__ : printk 함수가 쓰여진 파일 경로와 파일명을 출력
• __func__  : printk 함수가 포함되어있는 함수 명 출력
• __LINE__ : printk 함수가 실행된 코드 라인
• (void *)__builtin_return_address(0) : 현재 실행 중인 함수를 호출한 함수의 주소를 출력한다.
  - %pS 서식 지정자를 이용하면 아규먼트로 지정한 주소를 심벌로 변화해 출력한다.
• current->comm : 드라이버를 호출한 프로세스의 이름을 출력한다.
  - #include <linux/sched.h> 헤더파일이 포함되어 있어야 한다.. 

 

 3. printk 변수 출력을 위한 서식 지정

printk는 전달하는 인자와 서식 지정자가 일치해야 커널을 빌드 할 때 컴파일 에러가 발생하지 않는다.

아래 표는 변수 타입과 서식 지정자를 정리한 표이다. 변수에 맞는 서식 지정자를 사용 할 수 있도록 한다.

 

변수 타입	서식 지정자
int	%d 또는 %x
unsigned int	%u 또는 %x
long	%ld 또는 %lx
unsigned long	%lu 또는 %lx
long long	%lld 또는 %llx
unsigned long long	%llu 또는 %llx
size_t	%zu 또는 %zx
ssize_t	%zd 또는 %zx
s32	%d 또는 %x
u32	%u 또는 %x
s64	%lld 또는 %llx
u64	%llu 또는 %llx

 

 4. printk 로그 레벨 지정.

printk에는 아래 표와 같이 로그 레벨이 존재하며, 각 로그 레벨은 다른 우선 순위와 중요도를 나타낸다.

Log Level의 숫자가 작을 수록 중요도 및 우선 순위가 높다. 

Log Level	Define	의미
<0>	KERN_EMERG	시스템이 EMERGENCY 상황
<1>	KERN_ALERT	즉시 출력 메세지
<2>	KERN_CRIT	CRITICAL 에러 메세지
<3>	KERN_ERR	에러 메세지
<4>	KERN_WARNING	WARNING 메세지
<5>	KERN_NOTICE	정상 메세지
<6>	KERN_INFO	시스템 정보 메세지
<7>	KERN_DEBUG	디버깅 정보

현재 리눅스 시스템에 적용되어진 로그 레벨을 확인 하기 위해서는 아래와 같은 명령어로 확인 할 수 있다.

# cat /proc/sys/kernel/printk

4 4 1 7

# echo '1 1 1 1' > /proc/sys/kernel/printk

# cat /proc/sys/kernel/printk

1 1 1 1

또한 아래와 같이 /etc/sysctl.conf 파일을 열어서 kernel.printk의 주석을 해제하고 수정해도 된다. 수정 후에는 수정 값을 적용하기 위해 재부팅 또는 "sysctl -p" 명령어로 값을 다시 로드해 줘야 된다.

 

 

 5. printk 사용시 주의점.

printk 함수는 커널 입장에서 비용이 많이 드는 함수이다. 따라서 printk의 호출 빈도가 많아지면(1초에 수백번 이상) 시스템이 락업(LockUp)되거나 커널 패닉으로 오동작을 할 수가 있습니다. 여기서 락업은 리눅스에서 마우스를 움직이거나 키보드를 입력해도 아무런 반응이 없는 현상을 말합니다. 

그럼 호출이 많은 함수를 디버깅 하고 싶다면 어떻게 해야 될까요?? 이러한 환경에서 디버깅을 지원하기 위해 ftrace라는 디버깅 기능이 있습니다. ftrace를 쓰면 커널 함수의 흐름과 커널의 세부 동작등을 커널 코드를 수정하지 않고 파악 할 수 있습니다.