Arm Linux Kernel Hacks

rousalome.egloos.com

포토로그 Kernel Crash


통계 위젯 (화이트)

92107
469
422724


[0410] Slab Memory Corruption Case Study#3 - 디버깅 [Linux][Kernel] MM


난이도: 최하

커널 로그를 보니 Binder:1887_12란 프로세스가  7676767e 란 가상 주소를 처리 못해 데이터 어보트가 발생했습니다.
[  970.135274 / 04-07 17:58:32.685][7] Unable to handle kernel paging request at virtual address 7676767e
[  970.135315 / 04-07 17:58:32.685][7] pgd = d549c000
[  970.135339 / 04-07 17:58:32.685][0] [7676767e] *pgd=91d26831, *pte=00000000, *ppte=00000000
[  970.135392 / 04-07 17:58:32.685][7] Internal error: Oops: 17 [#1] PREEMPT SMP ARM
[  970.135414 / 04-07 17:58:32.685][0] Modules linked in:
[  970.135446 / 04-07 17:58:32.685][7] CPU: 7 PID: 3186 Comm: Binder:1887_12 Tainted: G        W      3.18.31-g6258e9b-dirty #36
[  970.135470 / 04-07 17:58:32.685][7] task: c327be00 ti: c2cb0000 task.ti: c2cb0000
[  970.135502 / 04-07 17:58:32.685][7] PC is at binder_thread_read+0x750/0x10b8
[  970.135530 / 04-07 17:58:32.685][7] LR is at __mutex_lock_slowpath+0x3bc/0x3fc
[  970.135555 / 04-07 17:58:32.685][7] pc : [<c0955364>]    lr : [<c0f71fd8>]    psr: 200f0013
[  970.135555 / 04-07 17:58:32.685][7] sp : c2cb1dd0  ip : c2cb1d70  fp : c2cb1e84
[  970.135586 / 04-07 17:58:32.685][7] r10: 81db0204  r9 : d7c91080  r8 : d7c91080
[  970.135633 / 04-07 17:58:32.685][7] r7 : e2ff63c0  r6 : 76767676  r5 : d7c910e0  r4 : c2cb0000
[  970.135704 / 04-07 17:58:32.685][7] r3 : 000000fc  r2 : e2ff63dc  r1 : 81db0300  r0 : 00000000

콜스택을 잡아 보니 다음과 같습니다.
-000|do_DataAbort(?)
-001|__dabt_svc(asm)
 -->|exception
-002|binder_thread_read(proc = 0xD7C91080, thread = 0xE2FF63C0, ?, ?, consumed = 0xC2CB1EC8, non_block = 0)
-003|static_key_count(inline)
-003|static_key_false(inline)
-003|trace_binder_read_done(inline)
-003|binder_ioctl_write_read(inline)
-003|binder_ioctl(?, cmd = 3222823425, arg = 2081806376)
-004|vfs_ioctl(inline)
-004|do_vfs_ioctl(filp = 0xD5539A40, fd = 37, ?, ?)
-005|SYSC_ioctl(inline)
-005|sys_ioctl(fd = 37, cmd = -1072143871, arg = 2081806376)
-006|ret_fast_syscall(asm)
 
그럼 data abort가 발생한 직접적인 이유를 알아볼까요?
0xc095535c <binder_thread_read+0x748>:  cmp     r3, #43 ; 0x2b
0xc0955360 <binder_thread_read+0x74c>:  bls     0xc0955904 <binder_thread_read+3312>
0xc0955364 <binder_thread_read+0x750>:  ldr     r3, [r6, #8]

0xc0955364 코드에서 데이터 어보트가 발생했습니다. 
그 이유는 r6가 0x76767676 값을 담고 있어 MMU가 물리주소로 Translation을 못하기 때문입니다.

그럼 r6의 정체는 뭘까요? 이 정보를 알기 위해 데이터 어보트가 발생한 코드를 볼까요?
crash> sym 0xc0955364
c0955364 (t) binder_thread_read+0x750 /home001/austindh.kim/src/drivers/staging/android/binder.c: 2262

C 코드를 열어보면 2262 라인 w->type 코드에서 뭔가 문제가 있는 것 같습니다. w는 (struct binder_work *) 구조체인데요.
2239         while (1) {
2240                 uint32_t cmd;
2241                 struct binder_transaction_data tr;
2242                 struct binder_work *w;
2243                 struct binder_transaction *t = NULL;
2244
2245                 if (!list_empty(&thread->todo)) {
2246                         w = list_first_entry(&thread->todo, struct binder_work,
2247                                              entry);
2248                 } else if (!list_empty(&proc->todo) && wait_for_proc_work) {
2249                         w = list_first_entry(&proc->todo, struct binder_work,
2250                                              entry);
2251                 } else {
2252                         /* no data added */
2253                         if (ptr - buffer == 4 &&
2254                             !(thread->looper & BINDER_LOOPER_STATE_NEED_RETURN))
2255                                 goto retry;
2256                         break;
2257                 }
2258
2259                 if (end - ptr < sizeof(tr) + 4)
2260                         break;
2261
2262                 switch (w->type) {
2263                 case BINDER_WORK_TRANSACTION: {

struct binder_work.type은 0x8 오프셋입니다.
struct binder_work {
  [0x0] struct list_head entry;
  [0x8] enum {BINDER_WORK_TRANSACTION = 1, BINDER_WORK_TRANSACTION_COMPLETE, BINDER_WORK_NODE, BINDER_WORK_DEAD_BINDER, BINDER_WORK_DEAD_BINDER_AND_CLEAR, BINDER_WORK_CLEAR_DEATH_NOTIFICATION} type;
}

그럼 r6의 정체에 대해서 알아봐야 하는데요. w는 아래 코드로 인스턴스를 전달 받습니다.
2245                 if (!list_empty(&thread->todo)) {
2246                         w = list_first_entry(&thread->todo, struct binder_work,
2247                                              entry);

해당 변수는 다음과 같습니다.
binder_thread_read(
    (register struct binder_proc *) proc = 0xD7C91080,
    (register struct binder_thread *) thread = 0xE2FF63C0 -> (
      (struct binder_proc *) proc = 0x76767676,
      (struct rb_node) rb_node = ((long unsigned int) __rb_parent_color = 0x76767676, (struct rb_nod
      (int) pid = 0x76767676,
      (int) looper = 0x76767666,
      (struct binder_transaction *) transaction_stack = 0x76767676,
      (struct list_head) todo = (
        (struct list_head *) next = 0x76767676,
        (struct list_head *) prev = 0x76767676),
      (uint32_t) return_error = 0x76767676,
      (uint32_t) return_error2 = 0x76767676,

다음과 같이 캐스팅되는 군요.
  (struct binder_work *) container_of(0x76767676,struct binder_work,entry) = 0x76767676 = NMRR+0x35963596 -> (
    (struct list_head) entry = ((struct list_head *) next = 0x0 =  -> NULL, (struct list_head *) prev = 0x0 =  -> NULL),
    (enum) type = 0 = 0x0 = '....')

그런데 0xE2FF63C0 메모리 주소를 보면 0x76767676와 같이 쓰레기 값이 채워져 있는데, 이 정체가 뭔지 알아볼까요?
_____address|________0________4________8________C
NSD:E2FF63A0| 76767676 76767676 76767676 76767676
NSD:E2FF63B0| 76767676 76767676 76767676 76767676
NSD:E2FF63C0|>76767676 76767676 76767676 76767676
NSD:E2FF63D0| 76767676 76767666 76767676 76767676
NSD:E2FF63E0| 76767676 76767676 76767676 76767676
NSD:E2FF63F0| 76767676 76767676 76767676 76767676
NSD:E2FF6400| 76767676 76767676 76767676 76767676
NSD:E2FF6410| 76767676 76767676 76767676 76767676
NSD:E2FF6420| 76767676 76767676 76767676 00000015
NSD:E2FF6430| 00000015 00000000 00000000 00000001
NSD:E2FF6440| 00000000 00000016 0000003A 00000000

E2FF63C0 메모리는 "kmalloc-512" 타입 슬랩 오브젝트인데 시작 주소가 e2ff63c0이군요.
crash> kmem E2FF63C0
CACHE    NAME                 OBJSIZE  ALLOCATED     TOTAL  SLABS  SSIZE
eac023c0 kmalloc-512              512       3506      4048    176    16k
  SLAB      MEMORY    NODE  TOTAL  ALLOCATED  FREE
  ec70ea00  e2ff4000     0     23         15     8
  FREE / [ALLOCATED]
  [e2ff63c0]

  PAGE    PHYSICAL   MAPPING    INDEX CNT FLAGS
ec70eb00  a2ff6000         0         0  0 8000 tail

그런데 E2FF63C0 주소를 가봐도 0x76767676란 이상한 값이 써져 있습니다. E2FF63C0 하위 주소에서 쓰레기 값을 복사하는 것 같은데요.
_____address|_data________|value_____________|symbol
NSD:E2FF63A8| 76 76 76 76  0x76767676
NSD:E2FF63AC| 76 76 76 76  0x76767676
NSD:E2FF63B0| 76 76 76 76  0x76767676
NSD:E2FF63B4| 76 76 76 76  0x76767676
NSD:E2FF63B8| 76 76 76 76  0x76767676
NSD:E2FF63BC| 76 76 76 76  0x76767676
NSD:E2FF63C0| 76 76 76 76  0x76767676
NSD:E2FF63C4| 76 76 76 76  0x76767676
NSD:E2FF63C8| 76 76 76 76  0x76767676
NSD:E2FF63CC| 76 76 76 76  0x76767676
NSD:E2FF63D0| 76 76 76 76  0x76767676

그럼 E2FF63C0 메모리에서 0x4바이트 떨어진 E2FF63BC 메모리 속성에 대해 알아볼까요?
crash> kmem E2FF63BC
CACHE    NAME                 OBJSIZE  ALLOCATED     TOTAL  SLABS  SSIZE
eac023c0 kmalloc-512              512       3506      4048    176    16k
  SLAB      MEMORY    NODE  TOTAL  ALLOCATED  FREE
  ec70ea00  e2ff4000     0     23         15     8
  FREE / [ALLOCATED]
  [e2ff6100]

  PAGE    PHYSICAL   MAPPING    INDEX CNT FLAGS
ec70eb00  a2ff6000         0         0  0 8000 tail

역시나 이 오브젝트는 kmalloc-512 타입에 시작 주소는 e2ff6100이군요. 그리고 메모리를 누군가가 할당해서 쓰고 있다고 합니다.

E2FF6100 주소를 가보면 이 주소부터 0x76767676 값이 채워져 있음을 알 수 있습니다.
_____address|_data________|value_____________|symbol
NSD:E2FF60D0| 00 00 00 00  0x0
NSD:E2FF60D4| 00 00 00 00  0x0
NSD:E2FF60D8| 00 00 00 00  0x0
NSD:E2FF60DC| 06 00 00 00  0x6                 
NSD:E2FF60E0| DB 03 00 00  0x3DB             
NSD:E2FF60E4| 74 FC 00 00  0xFC74
NSD:E2FF60E8| 5A 5A 5A 5A  0x5A5A5A5A
NSD:E2FF60EC| 5A 5A 5A 5A  0x5A5A5A5A
NSD:E2FF60F0| 5A 5A 5A 5A  0x5A5A5A5A
NSD:E2FF60F4| 5A 5A 5A 5A  0x5A5A5A5A
NSD:E2FF60F8| 5A 5A 5A 5A  0x5A5A5A5A
NSD:E2FF60FC| 5A 5A 5A 5A  0x5A5A5A5A
NSD:E2FF6100| 76 76 76 76  0x76767676
NSD:E2FF6104| 76 76 76 76  0x76767676
NSD:E2FF6108| 76 76 76 76  0x76767676
NSD:E2FF610C| 76 76 76 76  0x76767676
NSD:E2FF6110| 76 76 76 76  0x76767676

E2FF6100 메모리를 누가 가르키고 있는지 알아볼 차례입니다.
crash> search E2FF6100
c1c7d2c0: e2ff6100
d5e519a4: e2ff6100
d5e519ec: e2ff6100
d5e519f4: e2ff6100
e358bbd4: e2ff6100

c1c7d2c0 메모리 정체를 살펴보니 austin_debug_mem_data_cor2란 포인터 변수가 이 메모리 주소를 가르키고 있군요.
crash> kmem c1c7d2c0
c1c7d2c0 (B) austin_debug_mem_data_cor2

  PAGE    PHYSICAL   MAPPING    INDEX CNT FLAGS
eb672e80  81c7d000         0         0  1 400 reserved
 
나머지 d5e519a4/d5e519ec/d5e519f4/e358bbd4 메모리는 모두 프로세스 스택 안에서 돌고 있는 메모리라 큰 의미가 있는 디버깅 정보는 아닙니다.
(ex)
crash> kmem e358bbd4
    PID: 7502
COMMAND: "sh"
   TASK: e5585540  [THREAD_INFO: e358a000]
    CPU: 7
  STATE: TASK_INTERRUPTIBLE

  PAGE    PHYSICAL   MAPPING    INDEX CNT FLAGS
ec73b580  a358b000         0         0  0 0

역시나 austin_debug_mem_data_cor2 변수는 포인터 타입으로 0xE2FF6100 주소를 가르키고 있군요.
crash> whatis austin_debug_mem_data_cor2
u32 *austin_debug_mem_data_cor2;

crash> p austin_debug_mem_data_cor2
austin_debug_mem_data_cor2 = $1 = (u32 *) 0xe2ff6100

해당 코드를 살펴보니, 512 바이트 만큼 메모리를 할당하고 메모리를 300 바이트 만큼 Overflow해서 0x76값을 메모리를 설정하고 있군요. 다음 코드가 범인이었습니다.
 95         austin_debug_mem_data_cor2 = kmalloc(512, GFP_KERNEL);
 96         memset(austin_debug_mem_data_cor2, 0x76, 512+300);

# Reference: For more information on 'Linux Kernel';

디버깅을 통해 배우는 리눅스 커널의 구조와 원리. 1

디버깅을 통해 배우는 리눅스 커널의 구조와 원리. 2




핑백

덧글

댓글 입력 영역