Linux Kernel(4.19) Hacks

rousalome.egloos.com

포토로그 Kernel Crash


통계 위젯 (화이트)

230224
1178
109352


Kernel][Panic] 메모리 불량 커널 크래시@find_vma_links - 1 [Crash]Troubleshooting!!

#커널 크래시 디버깅 및 TroubleShooting

특정 디바이스가 부팅 후 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(프로세스 관리)
4.9 프로세스 컨택스트 정보는 어떻게 저장할까?
 4.9.1 컨택스트 소개
 4.9.2 인터럽트 컨택스트 정보 확인하기
 4.9.3 Soft IRQ 컨택스트 정보 확인하기
 4.9.4 선점 스케줄링 여부 정보 저장
4.10 프로세스 디스크립터 접근 매크로 함수
 4.10.1 current_thread_info()
 4.10.2 current 매크로란
4.11 프로세스 디버깅
 4.11.1 glibc fork 함수 gdb 디버깅
 4.11.2 유저 프로그램 실행 추적 

핑백

덧글

댓글 입력 영역