Linux Kernel(4.19) Hacks

rousalome.egloos.com

포토로그 Kernel Crash


통계 위젯 (화이트)

136199
1107
135864


[Linux][Kernel] WARN 매크로 부록

WARN 매크로는 코드 흐름에 소프트웨어적인 오류가 있을 때 실행합니다. 그래서 소스 코드를 보다가 WARN() 매크로를 보면 뭔가 논리적인 오류가 있는 조건이라고 봐야겠죠.

WARN 매크로를 어떤 함수에서 실행되면 시스템 정보를 커널 로그로 출력합니다.
1. 콜스택
2. 현재 수행 중인 프로세스 정보: CPU번호, 프로세스 이름, pid
3. 함수 이름과 라인 정보

하지만 커널 시스템에 심각한 오류가 있는 상태가 아니라 판단해서 에러 메시지만 출력하고 시스템을 계속 구동시킵니다.

그럼 새로운 드라이버 코드를 짰는데 WARN 매크로가 실행되면 어떻게 해야 할까요? 시스템에 치명적인 에러는 아니라 그냥 둬야 할까요? 그렇지 않습니다. WARN 매크로는 시스템에 뭔가 논리적인 오류가 있는 상태이므로 반드시 잡아야 합니다.

그럼 WARN 매크로가 어떤 에러 메시지를 출력하는지 하나 예를 들어볼까요? 다음은 리눅스 커널 커뮤니티에서 자주 볼 수 있는 에러 메시지입니다. 물론 WARN 매크로가 실행된 후 출력하는 에러 메시지죠.
[출처: https://www.unix.com/programming/148285-what-unbalanced-irq.html
https://www.linuxquestions.org/questions/programming-9/problem-with-interrupt-handle-770992/]

WARNING: at kernel/irq/manage.c:225 __enable_irq+0x3b/0x57()
Unbalanced enable for IRQ 4
Modules linked in: svsknfdrvr [last unloaded: osal_linux]
Pid: 634, comm: ash Tainted: G W 2.6.28 #1
Call Trace:
[<c011a7f9>] warn_slowpath+0x76/0x8d
[<c012fac8>] profile_tick+0x2d/0x57
[<c011ed72>] irq_exit+0x32/0x34
[<c010f22c>] smp_apic_timer_interrupt+0x41/0x71
[<c01039ec>] apic_timer_interrupt+0x28/0x30
[<c011b2b4>] vprintk+0x1d3/0x300
[<c013a2af>] __setup_irq+0x11c/0x1f2
[<c013a177>] __enable_irq+0x3b/0x57
[<c013a506>] enable_irq+0x37/0x54
[<c68c9156>] svsknfdrvr_open+0x5e/0x65 [svsknfdrvr]
[<c016440a>] chrdev_open+0xce/0x1a4
[<c016433c>] chrdev_open+0x0/0x1a4
[<c01602f7>] __dentry_open+0xcc/0x23a
[<c016049a>] nameidata_to_filp+0x35/0x3f
[<c016b3c5>] do_filp_open+0x16f/0x6ef
[<c0278fd5>] tty_write+0x1a2/0x1c9
[<c0160128>] do_sys_open+0x42/0xcb

위 로그는 아래 __enable_irq 함수의 6번째 줄 코드가 실행될 때 출력합니다.
1 void __enable_irq(struct irq_desc *desc)
2 {
3 switch (desc->depth) {
4 case 0:
5 err_out:
6 WARN(1, KERN_WARNING "Unbalanced enable for IRQ %d\n",
7      irq_desc_get_irq(desc));
 
인터럽트 디스크립터의 (struct irq_desc *)desc->depth 멤버는 인터럽트를 enable 할 때 0, disable 할 때 1을 설정하거든요. 그런데 아래 6번째 줄 코드는 인터럽트를 2번 enable 했을 때 실행합니다.

콜스택을 보면 __enable_irq란 함수에서 뭔가 오류가 생긴 것 같습니다. 에러 메세지를 유심히 보면서 어디서 오류가 생겼는지 점검해야겠죠.

그럼 해당 인터럽트를 어떤 이유인지 모르겠지만 두 번 enable했기 때문에 해당 오류 메시지가 출력된 것이죠. 여기서 desc는 인터럽트 디스크립터란 구조체이고요. 인터럽트에 대한 속성을 저장하고 있는 자료구조입니다.

그래서 이런 WARN 매크로가 출력될 때는 다음과 같은 패치 코드를 추가하여 해당 인터럽트를 enable, disable를 언제, 누가 하는지 점검할 필요가 있습니다. 다음 패치를 작성하여 컴파일 후 커널 이미지를 보드에 다운로드하고 실행시키는 것이죠. 참고로, 다음 패치는 enable하려는 IRQ 번호가 35번이라고 가정하고 생성했습니다. 문제 증상이 재현될 때 WARN 매크로가 실행되면서 출력되는 콜스택 정보로 범인을 잡는 것이죠.
diff --git a/kernel/irq/manage.c b/kernel/irq/manage.c
index 2f50d76..1c5e1ea 100644
--- a/kernel/irq/manage.c
+++ b/kernel/irq/manage.c
@@ -388,6 +388,8 @@ setup_affinity(unsigned int irq, struct irq_desc *desc, struct cpumask *mask)

 void __disable_irq(struct irq_desc *desc, unsigned int irq)
 {
+       if ( irq == 35 )
+               WARN(1, KERN_WARNING " irq 35 is disbled %d, desc->depth %d \n", irq, desc->depth);
        if (!desc->depth++)
                irq_disable(desc);
 }
@@ -442,6 +444,9 @@ EXPORT_SYMBOL(disable_irq);

 void __enable_irq(struct irq_desc *desc, unsigned int irq)
 {
+       if ( irq == 35 )
+               WARN(1, KERN_WARNING " irq 35 is enabled %d, desc->depth\n", irq, desc->depth);
+
        switch (desc->depth) {
        case 0:
  err_out:

그럼 이제 WARN 매크로 구현부를 잠깐 살펴볼까요?
WARN 매크로 코드를 열어보면 실제 __WARN_printf 매크로로 치환된다는 사실을 알 수 있습니다.
[include/asm-generic/bug.h]
#ifndef WARN
#define WARN(condition, format...) ({ \
int __ret_warn_on = !!(condition); \
if (unlikely(__ret_warn_on)) \
__WARN_printf(format); \
unlikely(__ret_warn_on); \
})
#endif
 
이후 __WARN_printf 매크로는 warn_slowpath_fmt 함수로 치환되는데 이 함수에서 __warn 함수를 호출합니다.
#define __WARN_printf(arg...) warn_slowpath_fmt(__FILE__, __LINE__, arg)
 
warn_slowpath_fmt 함수에서 __warn 함수를 호출할 때 전달하는 파라미터 조금 눈여겨볼 필요가 있습니다. file과 line에는 각각 __FILE__ , __LINE__ 매크로가 전달되고 세 번째 파라미터로는 __builtin_return_address(0) 매크로를 전달합니다. __FILE__과 __LINE__ C 언어에서 제공하는 매크로로 현재 실행 중인 코드의 파일 이름과 코드 라인을 알려줍니다. __builin_return_address는 역시 GCC에서 제공하는 빌트인 매크로인데 자신을 호출한 함수 주소를 저장하고 있죠. ARM lr(r14) 레지스터를 써서 말이죠. 이 매크로는 다음에 조금 더 자세히 살펴볼 예정이니 조금 기다려주세요.
1 void warn_slowpath_fmt(const char *file, int line, const char *fmt, ...)
2 {
3 struct warn_args args;
4
5 args.fmt = fmt;
6 va_start(args.args, fmt);
7 __warn(file, line, __builtin_return_address(0), TAINT_WARN, NULL,
8        &args);
9 va_end(args.args);
10 }
 
WARN 매크로가 실행하면 WARN 매크로가 실행된 순간의 상세 시스템 정보를 출력하는데 이 정보를 출력하는 함수가 __warn이며 구현부는 다음과 같습니다.
1 void __warn(const char *file, int line, void *caller, unsigned taint,
2     struct pt_regs *regs, struct warn_args *args)
3 {
4 disable_trace_on_warning();
5
6 pr_warn("------------[ cut here ]------------\n");
7
8 if (file)  //<<--[1]
9 pr_warn("WARNING: CPU: %d PID: %d at %s:%d %pS\n",
10 raw_smp_processor_id(), current->pid, file, line,
11 caller);
12 else
13 pr_warn("WARNING: CPU: %d PID: %d at %pS\n",
14 raw_smp_processor_id(), current->pid, caller);
15
16 if (args)
17 vprintk(args->fmt, args->args);
18
19 if (panic_on_warn) {
20 panic_on_warn = 0;
21 panic("panic_on_warn set ...\n");
22 }
23
24 print_modules();//<<--[2]
25
26 if (regs) //<<--[3]
27 show_regs(regs);
28 else
29 dump_stack();
30
30 print_oops_end_marker();
31
32 /* Just a warning, don't kill lockdep. */
33 add_taint(taint, LOCKDEP_STILL_OK);
34 }

그럼 각각 코드를 조금 더 상세히 살펴볼까요?

[1]: 8번째부터 11번째 줄 코드는 CPU번호와 프로세스의 pid 그리고 파일 이름과 코드 라인 정보를 출력합니다. 그리고 caller변수로 __builtin_return_address(0) 매크로가 전달한 해당 코드를 호출한 함수 주소를 출력합니다.
8 if (file)
9 pr_warn("WARNING: CPU: %d PID: %d at %s:%d %pS\n",
10 raw_smp_processor_id(), current->pid, file, line,
11 caller);
 
[2]: 모듈로 로딩된 디바이스 드라이버 정보를 출력합니다.
24 print_modules();
 
[3]: reqs 란 파라미터 상태에 따라 함수 호출이 다른데요. 보통 dump_stack 함수가 호출됩니다. show_regs는 현재 실행 중인 코드의 레지스터 덤프를 출력하고 dump_stack은 콜 스택 정보를 출력합니다.
26 if (regs)
27 show_regs(regs);
28 else
29 dump_stack();
 
여기까지 WARN 매크로가 실행되면 어떤 함수 흐름으로 시스템 정보를 출력하는지 알아봤습니다. WARN 매크로가 실행되면 소프트웨어적인 오류가 있는 상태이니 지나치지 마시고 꼼꼼히 해당 코드 참고해서 코드를 수정해 주세요.

"이 포스팅이 유익하다고 생각되시면 댓글로 응원해주시면 감사하겠습니다.  
혹시 글을 읽고 궁금점이 있으면 댓글로 질문 남겨주세요. 상세한 답글 올려 드리겠습니다!"



핑백

  • Linux Kernel(4.14) Hacks : [Linux][Kernel] 매크로 ##uname 파라미터 전달 기법 2018-06-14 23:29:29 #

    ... container_of 매크로 - current 매크로 (1)- current 매크로 (2)- current 매크로 (3)- BUG 매크로 - WARN 매크로 여러분 리눅스 커널 코드를 자주 보시나요? 그런데 커널 소스를 보다가 막힐 때가 종종 있지 않나요? 함수를 따라 가다 보면 존재하지 않는 함수를 호출해 ... more

  • Linux Kernel(4.14) Hacks : [Linux][Kernel] __init 매크로 (1) 2018-06-14 23:32:38 #

    ... current 매크로 (1) - current 매크로 (2) - current 매크로 (3) - BUG 매크로 - WARN 매크로 코드 리뷰를 하다 보면 함수 앞에 __init 코드를 종종 볼 수 있습니다. 예를 들면 lockup_detector_init란 함수 옆에 보이는 __i ... more

  • Linux Kernel(4.14) Hacks : [Linux][Kernel] container_of 매크로 2018-06-14 23:33:21 #

    ... current 매크로 (1) - current 매크로 (2) - current 매크로 (3) - BUG 매크로 - WARN 매크로 이번에는 container_of란 매크로를 배워볼게요. 커널 코드에서 current 매크로 못지않게 많이 활용하는 매크로이니 잘 알아야겠죠. 그럼 다음 ... more

  • Linux Kernel(4.14) Hacks : [Linux][Kernel] current 매크로 (1) 2018-06-14 23:34:10 #

    ... current 매크로 (1) - current 매크로 (2) - current 매크로 (3) - BUG 매크로 - WARN 매크로 리눅스 커널 코드를 읽다가 current란 매크로를 보신 적이 있나요? 아직 없다고요? 그럼 조금 코드를 읽다 보면 만나게 될 겁니다. 왜냐면 리눅스 ... more

  • Linux Kernel(4.14) Hacks : [Linux][Kernel] current 매크로 (2) 2018-06-14 23:34:34 #

    ... current 매크로 (1) - current 매크로 (2) - current 매크로 (3) - BUG 매크로 - WARN 매크로 그럼 current란 코드의 정체를 조금 더 알아볼까요?이번에도 패치 코드 하나를 소개할게요. 다음 루틴은 Wait Queue 관련 함수들인데요.dif ... more

  • Linux Kernel(4.14) Hacks : [Linux][Kernel] current 매크로 (3) 2018-06-14 23:35:07 #

    ... current 매크로 (1) - current 매크로 (2) - current 매크로 (3) - BUG 매크로 - WARN 매크로 여기까지 처리 과정을 정리하면 current_thread_info 매크로 함수에 접근해서 현재 실행 중인 프로세스의 태스크 디스크립터 정보를 포인터 형 ... more

  • Linux Kernel(4.14) Hacks : [Linux][Kernel] BUG 매크로 2018-06-14 23:35:37 #

    ... current 매크로 (1) - current 매크로 (2) - current 매크로 (3) - BUG 매크로 - WARN 매크로 BUG 매크로는 보통 소프트웨어적으로 심각한 오류 상태라 더는 실행할 수 없다고 판단할 때 호출 합니다. 혹시 소프트웨어 공학에서 ASSERT란 단어 ... more

  • Linux Kernel(4.14) Hacks : [라즈베리파이]리눅스 커널 매크로 분석 방법 2018-06-14 23:42:04 #

    ... current 매크로 (1) - current 매크로 (2) - current 매크로 (3) - BUG 매크로 - WARN 매크로 매크로 분석에 도움 되는 두 가지 방법을 소개합니다. 전처리 파일 추출과 바이너리 유틸리티를 활용해서 어셈블리 코드를 보는 방법입니다. 매크로를 분석할 ... more

  • Linux Kernel(4.14) Hacks : [라즈베리파이] 커널 빌드 & 컴파일 환경 설정 2019-01-11 00:14:38 #

    ... - current 매크로 (3) - BUG 매크로 - WARN 매크로 #Reference 시스템 콜- 시스템 콜 소개- 시스템 콜(시스템 호출)은 왜 ... more

덧글

  • 부끄럼틀 2019/12/23 15:23 # 삭제 답글

    좋은 정보 감사합니다.
  • AustinKim 2019/12/24 08:27 #

    자주 오셔서 좋은 정보 얻어 가셨으면 좋겠습니다.
  • 행크 2020/02/24 10:17 # 삭제 답글

    커널 WARN 분석 중이었는데요...좋은 정보 감사합니다.
  • AustinKim 2020/02/24 10:27 #

    도움이 됐다니 다행이네요.
    즐거운 한 주 되십시오.

    Thanks,
    Austin Kim

댓글 입력 영역