Arm Linux Kernel Hacks : [Linux][Kernel] 슬랩 Slab Memory 소개

리눅스 커널 Memory Management의 꽃 슬랩(Slub)을 소개합니다.

슬럽이 소개 되기 전 리눅스 커널 메모리는 모두 동적 할당을 했습니다. 한참 이 방식으로 메모리 할당을 하다 메모리 성능을 높이기 위한 과제를 리눅스 커널 전문가들이 진행했습니다. 메모리 할당 성능 개선 작업을 진행하다가, 어떤 타입의 메모리를 커널 코드에서 할당하는지 조사 했습니다. 그런데 재미있게도 메모리를 할당하는 패턴이 어느 정도 정해져 있다는 사실을 확인했습니다.

평범한 서민들이 먹는 식단을 몇 가지가 될까요? 아마 전 먹는 메뉴가 20여 가지로 정해져 있습니다. 비빔밥, 짜장면, 고구마(저녁으로 먹죠), 스타벅스, 삽겹살, 순대… (저 같은 경우는 5가지도 안됩니다.)

그래서 메모리를 할당하는 패턴을 정리하고 이 메모리를 슬럽 메모리라고 정의를 내렸습니다. 이후 슬럽 메모리 할당자를 구현했습니다. 가장 유명한 슬랩 메모리 타입은 kmalloc-32, kmalloc-64, kmalloc-128, kmalloc-256, ….., kmalloc-2048 이구요. Task descriptor (struct task_struct*)도 슬랩으로 쓰고 있습니다. 프로세스를 할당하고 해제할 때 많이 쓰는 것 같습니다.

이렇게 부팅할 때 슬랩 할당자를 초기화하고 각 슬랩에 대해 메모리를 미리 준비합니다. 바로 메모리 할당 요청이 오면 할당할 수 있기 위해서입니다. 이런 구조를 슬랩 캐시라고 하며 per-cpu 구조체로 선언되어 있습니다.

만약, 어떤 프로세스가 CPU1에서 구동 중이다가 kmalloc-64 슬랩 메모리 할당 요청을 하면 CPU1의 슬랩 캐시에서 슬랩 메모리를 전달합니다.

Page descriptor도 슬랩 메모리일 경우에 관리를 다르게 합니다. 1024 바이트 사이즈의 페이지 디스크립터는 이를 각각 짤라서 슬랩 메모리를 관리합니다. 그리고 쓰이는 구조체도 다릅니다.

아래 page descriptor 선언부를 보면 알 수 있듯 struct page->freelist는 슬랩 메모리의 가장 첫 번째 메모리를 가르킵니다.

[https://elixir.bootlin.com/linux/v4.14.43/source/include/linux/mm_types.h#L42]

struct page {

/* First double word block */

unsigned long flags; /* Atomic flags, some possibly

* updated asynchronously */

union {

struct address_space *mapping; /* If low bit clear, points to

* inode address_space, or NULL.

* If page mapped as anonymous

* memory, low bit is set, and

* it points to anon_vma object:

* see PAGE_MAPPING_ANON below.

void *s_mem; /* slab first object */

atomic_t compound_mapcount; /* first tail page */

/* page_deferred_list().next -- second tail page */

};

/* Second double word */

union {

pgoff_t index; /* Our offset within mapping. */

void *freelist; /* sl[aou]b first free object */

/* page_deferred_list().prev -- second tail page */

};

각 freelist는 아래 구조로 서로 연결되어 있습니다.

만약 page.freelist가 아래와 같이 슬랩 오브젝트를 연결하고 있다고 가정했을 때 슬랩 메모리를 할당하면 어떻게 될까요? 대략 아래와 같이 확인할 수 있습니다.

freelist -> A -> B -> C -> D -> E // 메모리 할당 전

freelist -> B -> C -> D -> E // 메모리 할당 후

알고리즘에 대해서 조금 공부하신 분들은 아마 느끼실 껍니다. 힙 알고리즘과 비슷하네? 맞아요. 슬랩 메모리 할당 원리는 힙 알고리즘를 쓰고 있습니다.

슬랩 메모리 Corruption

리눅스 커널 크래시 이슈 중 가장 디버깅 하기 어려운 문제가 슬랩 힙 Corruption입니다. 슬랩 힙 Corruption으로 몇 주 동안 집에 못 가고 디버깅을 하는 경우도 있습니다. 또한, 리눅스 커널 커뮤니티에서도 보름 동안 디버깅으로 씨름하는 걸 본 적도 있어요.

그럼 슬랩 메모리는 왜 깨질까요? 누가 깰 까요? 이런 질문을 한 문장으로 대답하기 힘들지만, 슬랩 메모리가 깨지는 패턴을 몇 가지로 좁힐 수는 있습니다.

use-after-free

논리적 오류로 인해 메모리를 해제한 다음에 그 포인터에 어떤 값을 쓰는 경우입니다. 그러니까 메모리를 해제하면 다시 접근하면 안되는데 논리적 오류로 다시 접근하는 겁니다. 그럼 어떻게 될까요? 슬랩 메모리를 해제하면 슬랩 메모리 할당자에 의해 바로 다른 프로세스가 그 슬랩 메모리를 쓸 가능성이 매우 높습니다. 아래 시나리오를 생각해볼까요?

1>[A 프로세스]슬랩 메모리 0xD000C000 해제(사실 해제한지 자신은 모름: 논리적 오류)

2>[B 프로세스]다른 프로세스가 해제한 메모리 0xD000C000 접근해서 특정 값을 Write

3>[A 프로세스]슬랩 메모리 0xD000C000에 접근하여 어떤 동작(값을 읽고 쓰는 동작)

4> 보통 커널 패닉(아주 다양한 랜덤 크래시)

리눅스 커널 커뮤니티에 가면 use-after-free란 문구가 포함된 제목의 패치를 많이 볼 수 있습니다. use-after-free 이슈는 모든 SW의 공통 문제인 것 같지만 보통 race때문에 많이 발생합니다.

그런데 이런 문제는 그리 어렵지 않게 잡을 수 있습니다.

아래 커널 컨피그를 켜주면,

+CONFIG_LKDTM=y

+CONFIG_SLUB_DEBUG=y

+CONFIG_SLUB_DEBUG_ON=y

+CONFIG_PAGE_POISONING=y

아주 친절하게 커널이 패닉을 유발시킵니다. 아래는 커널 패닉 로그의 예시 중 하나입니다.

[ 202.292579] lkdtm: Performing direct entry WRITE_AFTER_FREE

[ 202.293587] BUG kmalloc-1024 (Not tainted): Poison overwritten

[ 202.293620] Disabling lock debugging due to kernel taint

[ 202.293634] INFO: 0xd5885a40-0xd5885e3e. First byte 0x78 instead of 0x6b

[ 202.293659] INFO: Allocated in lkdtm_do_action+0xd0/0x1a8 age=0 cpu=0 pid=7421

[ 202.293674] lkdtm_do_action+0xd0/0x1a8

[ 202.293689] direct_entry+0xe4/0x110

[ 202.293705] vfs_write+0xd0/0x180

[ 202.293719] SyS_write+0x38/0x68

[ 202.293735] __sys_trace_return+0x0/0x18

[ 202.293752] INFO: Freed in lkdtm_do_action+0xd8/0x1a8 age=0 cpu=0 pid=7421

[ 202.293766] direct_entry+0xe4/0x110

[ 202.293779] vfs_write+0xd0/0x180

[ 202.293793] SyS_write+0x38/0x68

[ 202.293808] __sys_trace_return+0x0/0x18

[ 202.293823] INFO: Slab 0xc3d07200 objects=26 used=26 fp=0x (null) flags=0x4080

[ 202.293837] INFO: Object 0xd5885a40 @offset=23104 fp=0xd5882f80

[ 202.293837]

[ 202.293858] Bytes b4 d5885a30: 5a 5a 5a 5a 5a 5a 5a 5a 5a 5a 5a 5a 5a 5a 5a 5a ZZZZZZZZZZZZZZZZ

[ 202.293874] Object d5885a40: 78 78 78 78 78 78 78 78 78 78 78 78 78 78 78 78 xxxxxxxxxxxxxxxx

[ 202.293888] Object d5885a50: 78 78 78 78 78 78 78 78 78 78 78 78 78 78 78 78 xxxxxxxxxxxxxxxx

위 로그는 어떻게 해석해야 할까요?

실제 슬럽 메모리가 깨지는 이슈를 분석하면서 슬럽 메모리 구조를 알아보겠습니다.

슬랩 메모리 Corruption Cast Study: 난이도 최하

이번에는 슬랩 오브젝트가 메모리를 깨면 어떤 방식으로 커널 크래시가 발생하는지 알아볼게요.

이로 슬랩 오브젝트의 실제 자료 구조를 알 수 있습니다.

아 그럼 우선 커널 로그 부터 볼게요. 음 평소에는 볼 수 없는 요상한 로그를 출력하고 있군요.

그럼 각각 로그가 어떤 의미인지 천천히 살펴볼까요?

[701.043443][7] =============================================================================

[701.043491][7] BUG kmalloc-512 (Tainted: G W ): Poison overwritten

[701.043515][7] -----------------------------------------------------------------------------

[701.043515][7]

[701.043550][7] INFO: 0xe411ec00-0xe411ec92. First byte 0x87 instead of 0x6b

[701.043588][7] INFO: Allocated in alloc_buffer+0x28/0x14c age=31044 cpu=4 pid=103

[701.043617][7] __kmalloc+0xe8/0x2b8

[701.043644][7] alloc_buffer+0x28/0x14c

[701.043669][7] __bufio_new+0x74/0x24c

[701.043693][7] dm_bufio_prefetch+0x94/0x140

[701.043720][7] verity_prefetch_io+0x140/0x158

[701.043747][7] process_one_work+0x260/0x478

[701.043772][7] worker_thread+0x2c4/0x408

[701.043798][7] kthread+0xf8/0x10c

[701.043825][7] ret_from_fork+0x14/0x20

[701.043854][7] INFO: Freed in free_buffer+0xa4/0xb0 age=24255 cpu=6 pid=80

[701.043880][7] kfree+0x238/0x28c

[701.043906][7] free_buffer+0xa4/0xb0

[701.043930][7] __free_buffer_wake+0x28/0x60

[701.043954][7] __cleanup_old_buffer+0x80/0x9c

[701.043979][7] work_fn+0x80/0xcc

[701.044004][7] process_one_work+0x260/0x478

[701.044029][7] worker_thread+0x2c4/0x408

[701.044054][7] kthread+0xf8/0x10c

[701.044079][7] ret_from_fork+0x14/0x20

[701.044104][7] INFO: Slab 0xec797e00 objects=23 used=23 fp=0x (null) flags=0x4080

[701.044129][7] INFO: Object 0xe411ec00 @offset=11264 fp=0xe411c580

[701.044129][7]

[701.044165][7] Bytes b4 e411ebf0: 87 87 87 87 87 87 87 87 87 87 87 87 87 87 87 87 ................

[701.044190][7] Object e411ec00: 87 87 87 87 87 87 87 87 87 87 87 87 87 87 87 87 ................

[701.044215][7] Object e411ec10: 87 87 87 87 87 87 87 87 87 87 87 87 87 87 87 87 ................

[701.044239][7] Object e411ec20: 87 87 87 87 87 87 87 87 87 87 87 87 87 87 87 87 ................

[701.044264][7] Object e411ec30: 87 87 87 87 87 87 87 87 87 87 87 87 87 87 87 87 ................

[701.044288][7] Object e411ec40: 87 87 87 87 87 87 87 87 87 87 87 87 87 87 87 87 ................

[701.044313][7] Object e411ec50: 87 87 87 87 87 87 87 87 87 87 87 87 87 87 87 87 ................

[701.044338][7] Object e411ec60: 87 87 87 87 87 87 87 87 87 87 87 87 87 87 87 87 ................

[701.044363][7] Object e411ec70: 87 87 87 87 87 87 87 87 87 87 87 87 87 87 87 87 ................

[701.044388][7] Object e411ec80: 87 87 87 87 87 87 87 87 87 87 87 87 87 87 87 87 ................

[701.044412][7] Object e411ec90: 87 87 87 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b ...kkkkkkkkkkkkk

[701.044437][7] Object e411eca0: 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b kkkkkkkkkkkkkkkk

[701.044462][7] Object e411ecb0: 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b kkkkkkkkkkkkkkkk

[701.044487][7] Object e411ecc0: 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b kkkkkkkkkkkkkkkk

[701.044511][7] Object e411ecd0: 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b kkkkkkkkkkkkkkkk

[701.044536][7] Object e411ece0: 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b kkkkkkkkkkkkkkkk

[701.044561][7] Object e411ecf0: 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b kkkkkkkkkkkkkkkk

[701.044585][7] Object e411ed00: 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b kkkkkkkkkkkkkkkk

[701.044610][7] Object e411ed10: 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b kkkkkkkkkkkkkkkk

[701.044634][7] Object e411ed20: 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b kkkkkkkkkkkkkkkk

[701.044659][7] Object e411ed30: 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b kkkkkkkkkkkkkkkk

[701.044684][7] Object e411ed40: 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b kkkkkkkkkkkkkkkk

[701.044709][7] Object e411ed50: 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b kkkkkkkkkkkkkkkk

[701.044733][7] Object e411ed60: 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b kkkkkkkkkkkkkkkk

[701.044758][7] Object e411ed70: 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b kkkkkkkkkkkkkkkk

[701.044783][7] Object e411ed80: 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b kkkkkkkkkkkkkkkk

[701.044807][7] Object e411ed90: 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b kkkkkkkkkkkkkkkk

[701.044831][7] Object e411eda0: 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b kkkkkkkkkkkkkkkk

[701.044856][7] Object e411edb0: 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b kkkkkkkkkkkkkkkk

[701.044881][7] Object e411edc0: 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b kkkkkkkkkkkkkkkk

[701.044906][7] Object e411edd0: 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b kkkkkkkkkkkkkkkk

[701.044930][7] Object e411ede0: 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b kkkkkkkkkkkkkkkk

[701.044955][7] Object e411edf0: 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b a5 kkkkkkkkkkkkkkk.

[701.044980][7] Redzone e411ee00: bb bb bb bb ....

[701.045005][7] Padding e411eea8: 5a 5a 5a 5a 5a 5a 5a 5a 5a 5a 5a 5a 5a 5a 5a 5a ZZZZZZZZZZZZZZZZ

[701.045030][7] Padding e411eeb8: 5a 5a 5a 5a 5a 5a 5a 5a ZZZZZZZZ

[701.045505][7] Kernel panic - not syncing: object poison overwritten

[701.045505][7]

[701.045540][7] CPU: 7 PID: 6578 Comm: sh Tainted: G B W 3.18.31-g6258e9b-dirty #34

[701.045572][7] [<c0016fb8>] (unwind_backtrace) from [<c0013760>] (show_stack+0x20/0x24)

[701.045603][7] [<c0013760>] (show_stack) from [<c0f64068>] (dump_stack+0x9c/0xd4)

[701.045635][7] [<c0f64068>] (dump_stack) from [<c0f5f7a8>] (panic+0x120/0x388)

[701.045668][7] [<c0f5f7a8>] (panic) from [<c014d410>] (check_bytes_and_report+0x98/0xc8)

[701.045700][7] [<c014d410>] (check_bytes_and_report) from [<c014dc88>] (check_object+0x134/0x218)

[701.045733][7] [<c014dc88>] (check_object) from [<c0f618c8>] (alloc_debug_processing+0x8c/0x15c)

[701.045765][7] [<c0f618c8>] (alloc_debug_processing) from [<c0f61d94>] (__slab_alloc.constprop.8+0x3fc/0x458)

[701.045797][7] [<c0f61d94>] (__slab_alloc.constprop.8) from [<c014e968>] (__kmalloc+0xe8/0x2b8)

[701.045829][7] [<c014e968>] (__kmalloc) from [<c01a305c>] (load_elf_binary+0xf8/0x101c)

[701.045860][7] [<c01a305c>] (load_elf_binary) from [<c01603d0>] (search_binary_handler+0x84/0x1cc)

[701.045892][7] [<c01603d0>] (search_binary_handler) from [<c0160c14>] (do_execve+0x360/0x5bc)

[701.045922][7] [<c0160c14>] (do_execve) from [<c0161080>] (SyS_execve+0x2c/0x30)

[701.045953][7] [<c0161080>] (SyS_execve) from [<c000f300>] (ret_fast_syscall+0x0/0x50)

우선 가장 먼저 찍히는 로그부터 봅시다. 첫번째 로그 메시지는 "kmalloc-512" 슬랩 오브젝트가 오염됐다는 표시입니다.

1 [701.043491][7] BUG kmalloc-512 (Tainted: G W ): Poison overwritten

2 [701.043515][7] -----------------------------------------------------------------------------

3 [701.043515][7]

4 [701.043550][7] INFO: 0xe411ec00-0xe411ec92. First byte 0x87 instead of 0x6b

4번째 메시지는 현재 할당하려는 슬랩 오브젝트 메모리 공간이 0xe411ec00-0xe411ec92인데,

몇 바이트가 0x6b 이어야 하는데, 0x87이란 메시지입니다.

슬랩 오브젝트 디버그 옵션을 키면 메모리 속성에 따라 메모리 포이즌 값을 써줍니다. 그런데

슬랩 오브젝트 메모리를 해제할 때 슬랩 오브젝트 패이로드 주소에 0x6b이란 포이즌 값을 써 줍니다. 메모리를 해제한다는 뜻입니다.

이미 해제한 메모리 슬랩 오브젝트 공간이라 0x6b 값일 줄 알았는데 0x87이라고 출력합니다.

0x87 덤프가 이 메모리 공간을 오염시키고 있다는 의미입니다.

그럼 다음 에러 메시지를 볼까요?

1 [701.043588][7] INFO: Allocated in alloc_buffer+0x28/0x14c age=31044 cpu=4 pid=103

2 [701.043617][7] __kmalloc+0xe8/0x2b8

3 [701.043644][7] alloc_buffer+0x28/0x14c

4 [701.043669][7] __bufio_new+0x74/0x24c

5 [701.043693][7] dm_bufio_prefetch+0x94/0x140

6 [701.043720][7] verity_prefetch_io+0x140/0x158

7 [701.043747][7] process_one_work+0x260/0x478

8 [701.043772][7] worker_thread+0x2c4/0x408

9 [701.043798][7] kthread+0xf8/0x10c

10 [701.043825][7] ret_from_fork+0x14/0x20

11 [701.043854][7] INFO: Freed in free_buffer+0xa4/0xb0 age=24255 cpu=6 pid=80

12 [701.043880][7] kfree+0x238/0x28c

13 [701.043906][7] free_buffer+0xa4/0xb0

14 [701.043930][7] __free_buffer_wake+0x28/0x60

15 [701.043954][7] __cleanup_old_buffer+0x80/0x9c

16 [701.043979][7] work_fn+0x80/0xcc

17 [701.044004][7] process_one_work+0x260/0x478

18 [701.044029][7] worker_thread+0x2c4/0x408

19 [701.044054][7] kthread+0xf8/0x10c

20 [701.044079][7] ret_from_fork+0x14/0x20

1번부터 10번째 줄 메시지는 이 슬랩 오브젝트를 할당했을 때 프로파일 정보입니다.

슬랩 오브젝트를 할당한 주소: alloc_buffer+0x28/0x14c

CPU번호: CPU4에서 돌던 프로세스

pid: 103

age: 슬랩 오브젝트를 할당한 시간 31044

그리고 콜스택을 뿌려줍니다.

이 디버깅 정보는 슬랩 오브젝트 메모리 0xE411EE08 공간에서 출력하는데, 다음과 같이 똑같은 콜스택 정보를 볼 수 있습니다.

d.v %y.l 0xE411EE08

_____address|_data________|value______|symbol

NSD:E411EE04| 80 C5 11 E4 0xE411C580

NSD:E411EE08| 90 0D 8A C0 0xC08A0D90 \\vmlinux\dm-bufio\alloc_buffer+0x28

NSD:E411EE0C| 68 E9 14 C0 0xC014E968 \\vmlinux\slub\__kmalloc+0xE8

NSD:E411EE10| 90 0D 8A C0 0xC08A0D90 \\vmlinux\dm-bufio\alloc_buffer+0x28

NSD:E411EE14| EC 21 8A C0 0xC08A21EC \\vmlinux\dm-bufio\__bufio_new+0x74

NSD:E411EE18| 7C 25 8A C0 0xC08A257C \\vmlinux\dm-bufio\dm_bufio_prefetch+0x94

NSD:E411EE1C| 80 77 8A C0 0xC08A7780 \\vmlinux\dm-verity-target\verity_prefetch_io\no_prefetch_cluster+0x20

NSD:E411EE20| 48 5A 04 C0 0xC0045A48 \\vmlinux\workqueue\process_one_work+0x260

NSD:E411EE24| 98 68 04 C0 0xC0046898 \\vmlinux\workqueue\worker_thread\recheck+0x284

NSD:E411EE28| 48 AA 04 C0 0xC004AA48 \\vmlinux\kernel/kthread\kthread+0xF8

NSD:E411EE2C| D0 F3 00 C0 0xC000F3D0 \\vmlinux\Global\ret_from_fork+0x14

0xE411EE08 주소부터 슬랩 오브젝트를 프로파일링 구조체인 (struct track *)이 시작한다는 것 아시죠?

저번 세미나 때 슬랩 오브젝트 자료 구조에 대해서 설명을 드렸습니다.

Trace32 프로그램으로 확인해도 똑같은 디버깅 정보를 볼 수 있습니다.

v.v %t %d %h %i (struct track*)0xE411EE08

(struct track *) (struct track*)0xE411EE08 = 0xE411EE08 -> (

(long unsigned int) addr = 3230272912 = 0xC08A0D90,

(long unsigned int [16]) addrs = (

[0] = 3222595944 = 0xC014E968,

[1] = 3230272912 = 0xC08A0D90,

[2] = 3230278124 = 0xC08A21EC,

[3] = 3230279036 = 0xC08A257C,

[4] = 3230300032 = 0xC08A7780,

[5] = 3221510728 = 0xC0045A48,

[6] = 3221514392 = 0xC0046898,

[7] = 3221531208 = 0xC004AA48,

[8] = 3221287888 = 0xC000F3D0,

[9] = 0 = 0x0,

[10] = 0 = 0x0,

[11] = 0 = 0x0,

[12] = 0 = 0x0,

[13] = 0 = 0x0,

[14] = 0 = 0x0,

[15] = 0 = 0x0),

(int) cpu = 4 = 0x4,

(int) pid = 103 = 0x67,

(long unsigned int) when = 9060 = 0x2364)

그럼 다음 커널 로그를 참고해서 이 슬랩 오브젝트를 할당한 0xC08A0D90 주소를 한번 가볼까요?

[701.043588][7] INFO: Allocated in alloc_buffer+0x28/0x14c age=31044 cpu=4 pid=103

[701.043617][7] __kmalloc+0xe8/0x2b8

[701.043644][7] alloc_buffer+0x28/0x14c

다음 명령어를 입력하니 drivers\md\dm-bufio.c 파일에 397 라인에 alloc_buffer() 이란 함수가 있다는 사실을 알 수 있습니다.

y.l.line 0xC08A0D90

_____address________|source_______________________|line_______________|offset____|

P:C08A0D90--C08A0D97|kernel\drivers\md\dm-bufio.c|\397--0 dm-bufio\alloc_buffer+0x28

P:C08A0D98--C08A0D9B|kernel\drivers\md\dm-bufio.c|\400--0 dm-bufio\alloc_buffer+0x30

해당 코드를 열어보니 이 슬랩 오브젝트는 (struct dm_buffer *) 란 구조체로 쓰고 있었습니다.

https://elixir.bootlin.com/linux/v3.18.104/source/drivers/md/dm-bufio.c#L393

393 static struct dm_buffer *alloc_buffer(struct dm_bufio_client *c, gfp_t gfp_mask)

394 {

395 struct dm_buffer *b = kmalloc(sizeof(struct dm_buffer) + c->aux_size,

396 gfp_mask);

여기서 주의 깊게 봐야할 점은 이 슬랩 오브젝트를 할당했던 정보는 별 의미가 없다는 겁니다.

왜냐면 이 슬랩 오브젝트는 이미 해제됐던 메모리이기 때문입니다.

11번부터 20번째 줄 메시지는 이 슬랩 오브젝트를 해제했을 때 프로파일 정보입니다.

이 프로파일 정보가 그래도 주의 깊게 봐야할 정보입니다.

자 다시 로그를 함께 볼까요?

11 [701.043854][7] INFO: Freed in free_buffer+0xa4/0xb0 age=24255 cpu=6 pid=80

12 [701.043880][7] kfree+0x238/0x28c

13 [701.043906][7] free_buffer+0xa4/0xb0

14 [701.043930][7] __free_buffer_wake+0x28/0x60

15 [701.043954][7] __cleanup_old_buffer+0x80/0x9c

16 [701.043979][7] work_fn+0x80/0xcc

17 [701.044004][7] process_one_work+0x260/0x478

18 [701.044029][7] worker_thread+0x2c4/0x408

19 [701.044054][7] kthread+0xf8/0x10c

20 [701.044079][7] ret_from_fork+0x14/0x20

해당 슬랩 오브젝트를 해제한 프로파일 정보는 다음과 같습니다.

CPU번호: CPU6에서 돌던 프로세스

pid: 80

age: 슬랩 오브젝트를 할당한 시간 24255

해당 정보는 E411EE58 메모리 공간에서 확인할 수 있습니다.

________address|_data________|value______|symbol

NSD:E411EE58| F8 0F 8A C0 0xC08A0FF8 \\vmlinux\dm-bufio\free_buffer+0xA4

NSD:E411EE5C| 40 FA 14 C0 0xC014FA40 \\vmlinux\slub\kfree+0x238

NSD:E411EE60| F8 0F 8A C0 0xC08A0FF8 \\vmlinux\dm-bufio\free_buffer+0xA4

NSD:E411EE64| 2C 10 8A C0 0xC08A102C \\vmlinux\dm-bufio\__free_buffer_wake+0x28

NSD:E411EE68| 20 1F 8A C0 0xC08A1F20 \\vmlinux\dm-bufio\__cleanup_old_buffer+0x80

NSD:E411EE6C| 8C 20 8A C0 0xC08A208C \\vmlinux\dm-bufio\work_fn+0x80

NSD:E411EE70| 48 5A 04 C0 0xC0045A48 \\vmlinux\workqueue\process_one_work+0x260

NSD:E411EE74| 98 68 04 C0 0xC0046898 \\vmlinux\workqueue\worker_thread\recheck+0x284

NSD:E411EE78| 48 AA 04 C0 0xC004AA48 \\vmlinux\kernel/kthread\kthread+0xF8

NSD:E411EE7C| D0 F3 00 C0 0xC000F3D0 \\vmlinux\Global\ret_from_fork+0x14

NSD:E411EE80| 00 00 00 00 0x0

NSD:E411EE84| 00 00 00 00 0x0

NSD:E411EE88| 00 00 00 00 0x0

NSD:E411EE8C| 00 00 00 00 0x0

NSD:E411EE90| 00 00 00 00 0x0

NSD:E411EE94| 00 00 00 00 0x0

NSD:E411EE98| 00 00 00 00 0x0

NSD:E411EE9C| 06 00 00 00 0x6

NSD:E411EEA0| 50 00 00 00 0x50

NSD:E411EEA4| E9 3D 00 00 0x3DE9

NSD:E411EEA8| 5A 5A 5A 5A 0x5A5A5A5A

NSD:E411EEAC| 5A 5A 5A 5A 0x5A5A5A5A

NSD:E411EEB0| 5A 5A 5A 5A 0x5A5A5A5A

NSD:E411EEB4| 5A 5A 5A 5A 0x5A5A5A5A

Trace32 프로그램으로 확인해도 똑같은 디버깅 정보를 볼 수 있습니다.

v.v %t %d %h %i (struct track*)0xE411EE58

(struct track *) (struct track*)0xE411EE58 = 0xE411EE58 -> (

(long unsigned int) addr = 3230273528 = 0xC08A0FF8,

(long unsigned int [16]) addrs = (

[0] = 3222600256 = 0xC014FA40,

[1] = 3230273528 = 0xC08A0FF8,

[2] = 3230273580 = 0xC08A102C,

[3] = 3230277408 = 0xC08A1F20,

[4] = 3230277772 = 0xC08A208C,

[5] = 3221510728 = 0xC0045A48,

[6] = 3221514392 = 0xC0046898,

[7] = 3221531208 = 0xC004AA48,

[8] = 3221287888 = 0xC000F3D0,

[9] = 0 = 0x0,

[10] = 0 = 0x0,

[11] = 0 = 0x0,

[12] = 0 = 0x0,

[13] = 0 = 0x0,

[14] = 0 = 0x0,

[15] = 0 = 0x0),

(int) cpu = 6 = 0x6,

(int) pid = 80 = 0x50,

(long unsigned int) when = 15849 = 0x3DE9)

그럼 다음 커널 로그를 참고해서 이 슬랩 오브젝트를 할당한 0xC08A0D90 주소를 한번 가볼까요?

11 [701.043854][7] INFO: Freed in free_buffer+0xa4/0xb0 age=24255 cpu=6 pid=80

12 [701.043880][7] kfree+0x238/0x28c

13 [701.043906][7] free_buffer+0xa4/0xb0

y.l.line 0xC08A0FF8

P:C08A0FF0--C08A1003|\\vmlinux\dm-bufio|kernel\drivers\md\dm-bufio.c|\385--0 dm-bufio\free_buffer+0x9C

이번에는 0xC08A0FF8 주소를 어셈블리 코드로 보니 kfree로 메모리를 해제합니다.

___addr/line|code_____|mnemonic________________|comment______|

NSR:C08A0FE0|E1A01003 cpy r1,r3

NSR:C08A0FE4|E59F0014 ldr r0,0xC08A1000

NSR:C08A0FE8|EB1AFC24 bl 0xC0F60080 ; printk

NSP:C08A0FEC|E7F001F2 dcd 0xE7F001F2

NSR:C08A0FF0|E1A00004 cpy r0,r4 ; r0,b

NSR:C08A0FF4|EBE2BA03 bl 0xC014F808 ; kfree

다음 에러 메시지는 커널 크래시가 발생한 콜스택 정보입니다. 별 의미 있는 디버깅 정보는 보이지 않습니다.