#커널 크래시 디버깅 및 TroubleShooting
- Race로 mmc_wait_data_done() 함수에서 커널 패닉
- "cat /d/shrinker" 입력 시 커널 패닉
- 함수 포인터 미지정으로 xfrm_local_error() 커널 패닉
- preempt 조건으로 ___might_sleep() 함수 크래시
- 스택 카나리: __stack_chk_fail() 함수 크래시
- 스택 카나리: tcp_v4_rcv -> __stack_chk_fail 크래시
- 뮤텍스 데드락(Mutex Deadlock)으로 락업(lockup)
- 디바이스 드라이버 Signature 문제로 커널 크래시
- 메모리 불량 커널 크래시 @find_vma_links()
- 메모리 불량 커널 크래시 @ttwu_do_activate()
- Race로 ipv6_ifa_notify() Stuck - watchdog reset
- tty_wakeup() 함수 Data Abort
- irq_affinity_notify() 함수 Data Abort
- cpuacct_charge() 함수 Data Abort
- 워크큐(workqueue) 락업(1)
- 워크큐(workqueue) 락업(2)
- 워크큐(workqueue) 락업(3)
특정 디바이스가 부팅 후 5분 이내에 커널 패닉이 발생하는 현상을 리포트 받았는데요.
참 신기하죠? 특정 디바이스만 커널 패닉이라.
이럴 때 너무 긴장할 필요 없어요. 논리적인 오류로 발생한 커널 패닉인지 정확히 분석한 후,
논리적인 문제가 아니라면 하드웨어 담당자에게 메모리 불량이 아닌 지 테스트(보통 정상 메모리와 스왑하죠)을 요청하면 되요.
커널 패닉 시 로그는 아래와 같아요.
CPU5에서 돌던 find_vma_links() 함수의 find_vma_links+0x1c 코드에서 데이터 오버트가(Data Abort) 발생했네요. 프로세스 이름은 "sensorservice" 이구요.
[ 2107.239317 / 01-01 11:11:03.809][5] Unable to handle kernel NULL pointer dereference at virtual address 00000028
[ 2107.239351 / 01-01 11:11:03.809][5] pgd = e37ec000
[ 2107.239366 / 01-01 11:11:03.809][0] [00000028] *pgd=00000000
[ 2107.239388 / 01-01 11:11:03.809][5] Internal error: Oops: 5 [#1] PREEMPT SMP ARM
[ 2107.239405 / 01-01 11:11:03.809][0] Modules linked in: texfat(PO)
[ 2107.239433 / 01-01 11:11:03.809][5] CPU: 5 PID: 2803 Comm: sensorservice Tainted: P W O 3.18.31-perf-gd069b48-00001-g8a6d6e5 #1
[ 2107.239452 / 01-01 11:11:03.809][5] task: e3ffb700 ti: e37f4000 task.ti: e37f4000
[ 2107.239479 / 01-01 11:11:03.809][5] PC is at find_vma_links+0x1c/0x78
[ 2107.239499 / 01-01 11:11:03.809][5] LR is at vma_adjust+0x3a0/0x574
find_vma_links() 함수를 잠깐 보면 struct task_struct->mm에 위치한 메모리 디스크립터를 통해
특정 조건으로 &mm->mm_rb.rb_node rbtree를 검색하는 루틴으로 보이는데요.
static int find_vma_links(struct mm_struct *mm, unsigned long addr,
unsigned long end, struct vm_area_struct **pprev,
struct rb_node ***rb_link, struct rb_node **rb_parent)
{
struct rb_node **__rb_link, *__rb_parent, *rb_prev;
__rb_link = &mm->mm_rb.rb_node; //<<--
우선 crash-utility(crash too)로 콜스택을 잡아 봤어요.
crash> bt -I C01002D8 -S E37F5DD0 0xE3FFB700
PID: 2803 TASK: e3ffb700 CPU: 5 COMMAND: "sensorservice"
#0 [<c01002d8>] (do_DataAbort) from [<c010ad58>]
pc : [<c01f980c>] lr : [<c01fa708>] psr: 200f0013
sp : e37f5ec4 ip : 00000034 fp : e8236d9c
r10: 00000000 r9 : 00000000 r8 : b2c99000
r7 : c4616c80 r6 : e8236d68 r5 : 7f555034 r4 : 7f555034
r3 : e37f5f04 r2 : b2c97000 r1 : b2c95000 r0 : 7f555038
Flags: nzCv IRQs on FIQs on Mode SVC_32 ISA ARM
#1 [<c010ad58>] (__dabt_svc) from [<c01fa708>]
#2 [<c01f980c>] (find_vma_links) from [<c01fa708>]
#3 [<c01fa708>] (vma_adjust) from [<c01fa9e4>]
#4 [<c01fa9e4>] (__split_vma) from [<c01fb364>]
#5 [<c01fb364>] (do_munmap) from [<c01fb558>]
#6 [<c01fb558>] (vm_munmap) from [<c0106820>]
그럼 Data Abort가 어떻게 일어났는지 좀 더 세밀하게 디버깅해볼까요?
Data Abort가 발생한 코드가 0xc01f980c이고 해당 Instrution이 "ldr r0, [r12, #-12]" 이네요.
즉 R12에서 -0xC 만큼 떨어진 메모리에 위치한 값을 로딩하다가 Data Abort가 발생했네요.
이 때, Data Abort가 발생할 시점에 R12가 0x34이거든요. (ip : 00000034)
이럴 때는 R12 레지스터을 좀 더 세밀하게 트레이싱할 필요가 있어요. 어떻게 R12값이 바뀌었는지 점검해야 하는 거죠.
[1]: R0가 0x7f555038이구요. 0x7f555038 메모리 공간에 있는 값이 0x34이니 R12는 0x34가 되네요.
[2]: ARM 프로세스가 "ldr r0, [r12, #-12]" 명령어를 수행하기 위해 ldr의 Base Address인 R12에 접근하다가,
Data Abort를 발생시켰어요. 왜냐면요, ldr란 명령어를 수행할 때 반드시 MMU이 개입하는데, 0x34란 주소는
MMU Page table에 없는 주소거든요. 도대체 global page directory에 접근할 수 없는 쓰레기 주소라 판단하여 Data abort를 유발시키는 거죠.
0xc01f97f0 <find_vma_links>: push {r4, r5, lr}
0xc01f97f4 <find_vma_links+0x4>: add r0, r0, #4
0xc01f97f8 <find_vma_links+0x8>: mov r4, #0
0xc01f97fc <find_vma_links+0xc>: mov r5, r4
0xc01f9800 <find_vma_links+0x10>: ldr r12, [r0] //<<--[1]
0xc01f9804 <find_vma_links+0x14>: cmp r12, #0
0xc01f9808 <find_vma_links+0x18>: beq 0xc01f983c <find_vma_links+76>
0xc01f980c <find_vma_links+0x1c>: ldr r0, [r12, #-12] //<<--[2]
커널 패닉이 발생한 C 코드와 함께 비교하면서 분석해볼까요?
[1]: 코드에서 Data abort가 발생한 건데요, 이 코드를 어셈블 코드와 비교해볼께요.
static int find_vma_links(struct mm_struct *mm, unsigned long addr,
unsigned long end, struct vm_area_struct **pprev,
struct rb_node ***rb_link, struct rb_node **rb_parent)
{
struct rb_node **__rb_link, *__rb_parent, *rb_prev;
__rb_link = &mm->mm_rb.rb_node; //<<--[1]
&mm->mm_rb.rb_node이 코드를 어셈블 코드에서 어떻게 돌아가는 지 점검하면요.
1> &mm->mm_rb.rb_node
이 포인터 연산을 위해서 우선 &mm->mm_rb 주소에 접근을 해야 하거든요.
이 동작을 아래 명령어에서 수행하죠.
0xc01f97f4 <find_vma_links+0x4>: add r0, r0, #4
struct mm_struct 구조체를 살펴보면 아래와 같이, 0x4 오프셋만큼 떨어진 멤버 변수가 mm_rb이거든요.
그래서 "add r0, r0, #4" 명령어에서 0x4만큼 더하는 거에요.
struct mm_struct {
[0x0] struct vm_area_struct *mmap;
[0x4] struct rb_root mm_rb;
2> &mm->mm_rb.rb_node
R0가 &mm->mm_rb 주소를 가르키고 있으니 이제 rb_node 주소에 접근하네요.
0xc01f9800 <find_vma_links+0x10>: ldr r12, [r0]
&mm->mm_rb 타입이 struct rb_root이구 이 구조체의 0x0 오프셋 멤버가 rb_node이라 위 명령어가 수행된 거랍니다.
crash> struct -o rb_root
struct rb_root {
[0x0] struct rb_node *rb_node;
}
그런데, find_vma_links() 함수의 선언부는 보면 첫 번째 파라미터가 "struct mm_struct *mm"이거든요.
이 소리는 find_vma_links() 함수가 호출될 때 R0에 "struct mm_struct *mm" 주소를 전달했다는 건데요.
static int find_vma_links(struct mm_struct *mm, unsigned long addr,
unsigned long end, struct vm_area_struct **pprev,
struct rb_node ***rb_link, struct rb_node **rb_parent)
코드 리뷰를 좀 해보면, find_vma_links() 함수의 첫 번째 파라미터로 전달되는 "struct mm_struct *mm"는
해당 프로세스의 struct task_struct.mm 멤버임을 알 수 있구요.
커널 패닉이 발생한 프로세스의 task descriptor(struct task_struct)의 주소가 e3ffb700이니,
"struct mm_struct *mm"은 0xc4616d80 주소가 되어야 하네요.
crash> struct task_struct.mm e3ffb700
mm = 0xc4616d80
이 값을 Trace32로 올려서 주소 오프셋값 까지 함께 살펴보니 아래와 같네요. 다들 정상적인 값을 갖고 있어요..
v.v %t %l (struct mm_struct*)0xc4616d80
(struct mm_struct *) [-] (struct mm_struct*)0xc4616d80 = 0xC4616D80 -> (
(struct vm_area_struct *) [D:0xC4616D80] mmap = 0xE6FB7E18,
(struct rb_root) [D:0xC4616D84] mm_rb = (
(struct rb_node *) [D:0xC4616D84] rb_node = 0xE7D259B0),
(u32) [D:0xC4616D88] vmacache_seqnum = 22,
정리하면, Data Abort가 발생한 이유는 R0가 0xC4616D84(0xC4616D80+0x4) 대신 0x7f555038값이기 때문이구요. 구지 Trace32로 문제 발생 시의 레지스터를 표현하면 아래와 같아요. 정말 이상하죠?
v.v %t %l (struct mm_struct*)0xc4616d80
(struct mm_struct *) [-] (struct mm_struct*)0xc4616d80 = 0xC4616D80 -> (
(struct vm_area_struct *) [D:0xC4616D80] mmap = 0xE6FB7E18,
(struct rb_root) [D:0x7f555038] mm_rb = (
(struct rb_node *) [D:0x7f555038] rb_node = 0x34),
(u32) [D:0xC4616D88] vmacache_seqnum = 22,
SW 로직 문제로 보이는 문제가 보이지 않아서, HW팀에게 메모리 점검을 요청했더니
메모리 스왑 후 커널 크래시가 발생하지 않았다고 하네요.
역시, 끝은 허무하네요.
# Reference: For more information on 'Linux Kernel';
디버깅을 통해 배우는 리눅스 커널의 구조와 원리. 1
디버깅을 통해 배우는 리눅스 커널의 구조와 원리. 2
'Core BSP 분석 > 커널 트러블슈팅' 카테고리의 다른 글
| watchdog reset - race in ipv6_ifa_notify() - 리눅스 커널 (0) | 2023.05.07 |
|---|---|
| tombstone - __strlen_chk (0) | 2023.05.07 |
| [Kernel][Panic] crash due to "signature and/or required key missing" (0) | 2023.05.07 |
| [Linux][Kernel]뮤텍스 데드락(Mutex Deadlock) 락업(lockup) - "simpleperf" 디버깅 (0) | 2023.05.07 |
| [Linux][Kernel] Kernel Panic @__stack_chk_fail - 스택 카나리 (Stack canary Feature) (0) | 2023.05.07 |
