본문 바로가기

Kernel Crash Case-Studies/커널 크래시 트러블슈팅

[Kernel] memory leak - debug(CONFIG_DEBUG_KMEMLEAK)

가끔 가다가 커널 메모리 누수(memory leak) 이슈가 생길 때가 있어요.
OOM Killer가 메모리가 부족하다고 커널이 메시지를 남기며 스스로 자살을 하거나,
Low Memory Killer가 너무나도 자주 돌아서 락업 현상으로 검출되죠.
 
이런 이슈가 나왔을 때 어떻게 디버깅을 하면 좋을까요?
한번 정리 좀 해볼께요.
 
1. 디버그 정보: contig_page_data.node_zones[0--1].free_area
 
우선 중 High/Low 메모리 Zone 중 어떤 Zone에서 페이지가 부족한 지 점검할 필요가 있어요.
만약에 Low 메모리 존에서 메모리가 부족하면 커널 동작으로 포커스를 맞추어야 하구요,
아래 경우와 같이 High Memory Zone에 Order 별로 free 페이지가 거의 없으면 더 골치 아프죠.
 
이런 때는 mmap으로 유저 공간에서 메모리를 과도하게 할당하려다가 메모리 릭이 일어날 수 있으니까요.
  contig_page_data = (
    node_zones = (
      (watermark = (756, 2005, 2194), lowmem_reserve = (0, 6144, 6144), inactive_ratio = 1, zone_pgdat = 0xC1A866C0
      (
        watermark = (128, 1778, 2028),
        lowmem_reserve = (0, 0, 0),
        inactive_ratio = 1,
        zone_pgdat = 0xC1A866C0,
        pageset = 0xC18D727C,
        dirty_balance_reserve = 2028,
        cma_alloc = FALSE,
        pageblock_flags = 0xEFAFFD80,
        zone_start_pfn = 720896,
        managed_pages = 196608,
        spanned_pages = 262144,
        present_pages = 196608,
        name = 0xC1469F47 -> "HighMem",
        nr_migrate_reserve_block = 1,
        nr_isolate_pageblock = 0,
        wait_table = 0xECF7F000,
        wait_table_hash_nr_entries = 1024,
        wait_table_bits = 10,
        _pad1_ = (x = ".....N..........tr.......k...k..TQ....N..k...k..T.y...y..k...k..y."),
        lock = (rlock = (raw_lock = (slock = 4260691444, tickets = (owner = 65012, next = 65012)), magic = 37358998
        free_area = (
          (
            free_list = ((next = 0xEEA47274, prev = 0xEEA586D4), (next = 0xC1A86B98, prev = 0xC1A86B98), (next = 0x
            nr_free = 0, //<<--
            nr_free_cma = 0),
          (
            free_list = ((next = 0xEED6A014, prev = 0xEED709D4), (next = 0xC1A86BD0, prev = 0xC1A86BD0), (next = 0x
            nr_free = 0, //<<--
            nr_free_cma = 0),
          (
            free_list = ((next = 0xEE98A694, prev = 0xEEF6DD14), (next = 0xC1A86C08, prev = 0xC1A86C08), (next = 0x
            nr_free = 0, //<<--
            nr_free_cma = 0), 
          (
            free_list = ((next = 0xEED6CA14, prev = 0xEF60E514), (next = 0xC1A86C40, prev = 0xC1A86C40), (next = 0x
            nr_free = 0, //<<--
            nr_free_cma = 0),
          (
            free_list = ((next = 0xEE993214, prev = 0xEF5FB614), (next = 0xC1A86C78, prev = 0xC1A86C78), (next = 0x
            nr_free = 0, //<<--
            nr_free_cma = 0),
          (
            free_list = ((next = 0xC1A86CA8, prev = 0xC1A86CA8), (next = 0xC1A86CB0, prev = 0xC1A86CB0), (next = 0x
            nr_free = 0,  //<<--
            nr_free_cma = 0),
          (
            free_list = ((next = 0xEEA59814, prev = 0xEEA59814), (next = 0xC1A86CE8, prev = 0xC1A86CE8), (next = 0x
            nr_free = 3,
            nr_free_cma = 0),
          (free_list = ((next = 0xC1A86D18, prev = 0xC1A86D18), (next = 0xC1A86D20, prev = 0xC1A86D20), (next = 0xE
          (free_list = ((next = 0xC1A86D50, prev = 0xC1A86D50), (next = 0xC1A86D58, prev = 0xC1A86D58), (next = 0xE
          (free_list = ((next = 0xC1A86D88, prev = 0xC1A86D88), (next = 0xC1A86D90, prev = 0xC1A86D90), (next = 0xC
          (free_list = ((next = 0xC1A86DC0, prev = 0xC1A86DC0), (next = 0xC1A86DC8, prev = 0xC1A86DC8), (next = 0xC
        flags = 0,
        _pad2_ = (x = ".^.^.N...........3...7....>..s.......v....L...^...7..q~..G."),
        lru_lock = (rlock = (raw_lock = (slock = 1579114015, tickets = (owner = 24095, next = 24095)), magic = 3735
        lruvec = (lists = ((next = 0xEEFF33F4, prev = 0xEEDE37B4), (next = 0xEF3E8EB4, prev = 0xEEA17394), (next =
        inactive_age = (counter = 193062),
 
2. reclaimable 페이지: vm_stat
direct reclaim 수행 시 회수 가능한 페이지 갯수를 확인할 수가 있는데, 이를 확인할 수 있는 전역 변수가 vm_stat 이에요.
아래 경우 60056+55707 개의 페이지가 reclaimable 가능한 페이지 갯수죠.
  (static atomic_long_t [34]) vm_stat = (
    [0] = ((int) counter = 12193), //<<-- NR_FREE_PAGES
    [1] = ((int) counter = 270),
    [2] = ((int) counter = 60056),  //<<-- NR_INACTIVE_ANON
    [3] = ((int) counter = 55707), // <<- NR_ACTIVE_ANON
    [4] = ((int) counter = 52514),
    [5] = ((int) counter = 52794),
    [6] = ((int) counter = 64),
    [7] = ((int) counter = 64),
    [8] = ((int) counter = 102899),
    [9] = ((int) counter = 63365),
    [10] = ((int) counter = 120639),
    [11] = ((int) counter = 0),
    [12] = ((int) counter = 11),
    [13] = ((int) counter = 14342),
    [14] = ((int) counter = 46446),
    [15] = ((int) counter = 11697),
 
zone_stat_item 선언부는 아래와 같아요.
enum zone_stat_item {
/* First 128 byte cacheline (assuming 64 bit words) */
NR_FREE_PAGES,   // <<- 0
NR_ALLOC_BATCH, // <<- 1
NR_LRU_BASE, // <<- 2
NR_INACTIVE_ANON = NR_LRU_BASE, // <<- 2
NR_ACTIVE_ANON, // <<- 3
NR_INACTIVE_FILE, // <<- 4
NR_ACTIVE_FILE, // <<- 5
NR_UNEVICTABLE, /*  "     "     "   "       "         */
NR_MLOCK, /* mlock()ed pages found and moved off LRU */
NR_ANON_PAGES, /* Mapped anonymous pages */
NR_FILE_MAPPED, /* pagecache pages mapped into pagetables.   
 
그럼 위와 같은 디버깅 정보의 근거는 뭐냐구요? 아래 코드를 보아요.
zone_reclaimable_pages() API는 reclaimable 페이지 갯수를 계산해요.
static unsigned long zone_reclaimable_pages(struct zone *zone)
{
int nr;
 
nr = zone_page_state(zone, NR_ACTIVE_FILE) +
     zone_page_state(zone, NR_INACTIVE_FILE);
 
if (get_nr_swap_pages() > 0)
nr += zone_page_state(zone, NR_ACTIVE_ANON) +
      zone_page_state(zone, NR_INACTIVE_ANON);
 
return nr;
}
 
3. 디버그 피쳐: kmem leak
리눅스 커널에서는 kmem leak이란 디버그 피쳐를 제공합니다.
리눅스 커널 커뮤니티에서는 이 피쳐를 돌려서 Memory Leak을 체크하죠.
 
각각 패치를 안드로이드 디바이스에서 어떻게 설정하는 지 설명할께요
 
1> 커널
CONFIG_DEBUG_KMEMLEAK 컨피그를 키고 CONFIG_DEBUG_KMEMLEAK_DEFAULT_OFF를 꺼야 해요
diff --git a/arch/arm/configs/pompeii_defconfig b/arch/arm/configs/pompeii_defconfig
index 2e97f97..aac678a 100644
--- a/arch/arm/configs/pompeii_defconfig
+++ b/arch/arm/configs/pompeii_defconfig
@@ -754,8 +754,8 @@
 CONFIG_SLUB_DEBUG_PANIC_ON=y
 CONFIG_SLUB_DEBUG_ON=y
 CONFIG_DEBUG_KMEMLEAK=y
-CONFIG_DEBUG_KMEMLEAK_EARLY_LOG_SIZE=4000
-CONFIG_DEBUG_KMEMLEAK_DEFAULT_OFF=y
+CONFIG_DEBUG_KMEMLEAK_EARLY_LOG_SIZE=40000
+# CONFIG_DEBUG_KMEMLEAK_DEFAULT_OFF is not set
 CONFIG_DEBUG_STACK_USAGE=y
 CONFIG_DEBUG_VM=y
 CONFIG_DEBUG_MEMORY_INIT=y
 
2> 커널 로딩 직전(대부분 LK죠), command line(ATAG)로 " kmemleak=on"을 전달해야 해요.
diff --git a/app/aboot/aboot.c b/app/aboot/aboot.c
index a02a85c..04409a3 100644
--- a/app/aboot/aboot.c
+++ b/app/aboot/aboot.c
@@ -304,6 +304,8 @@ struct getvar_partition_info part_info[] =
  { "cache"   , "partition-size:", "partition-type:", "", "ext4" },
 };
 
+static const char *kmem_feature = " kmemleak=on";
+
 char max_download_size[MAX_RSP_SIZE];
 char charger_screen_enabled[MAX_RSP_SIZE];
 #ifdef WITH_POMPEII_EXPORT_MODEL_NAME
@@ -511,6 +513,8 @@ unsigned char *update_cmdline(const char * cmdline)
   }
  }
 
+ cmdline_len += strlen(kmem_feature);
+
  if (target_warm_boot()) {
   warm_boot = true;
   cmdline_len += strlen(warmboot_cmdline);
@@ -688,6 +692,12 @@ unsigned char *update_cmdline(const char * cmdline)
    while ((*dst++ = *src++));
   }
 
+  if (strlen(kmem_feature)) {
+   src = ftrace_event;
+   if (have_cmdline) --dst;
+   while ((*dst++ = *src++));
+  }
+
   if (have_target_boot_params) {
    if (have_cmdline) --dst;
    src = target_boot_params;
 
3> 10초 마다 메모리 정보를 디바이스 파일 시스템(/sdcard)에 저장할 수 있는,
service-kmemleak란 서비스를 하나 만들어요.  
 
핵심 코드는 아래 코드와 같이 /sys/kernel/debug/kmemleak 을 clear 후 scan을 해줘야 해요.
echo clear  > /sys/kernel/debug/kmemleak
echo scan   > /sys/kernel/debug/kmemleak
 
diff --git a/device.mk b/device.mk
index ef6940b..f79383f 100644
--- a/device.mk
+++ b/device.mk
@@ -121,7 +121,8 @@
 
 PRODUCT_COPY_FILES += \
+ device/pompeii/init.kmemleak.sh:root/init.kmemleak.sh
 
diff --git a/init.core.rc b/init.core.rc
index f0dbf37..8472053 100644
--- a/init.core.rc
+++ a/init.core.rc
@@ -141,6 +141,9 @@
     disabled
     oneshot
 
+service service-kmemleak /system/bin/sh /init.kmemleak.sh
+    class main
+
 
diff --git a/init.kmemleak.sh b/init.kmemleak.sh
new file mode 100644
index 0000000..402a6b3
--- /dev/null
+++ b/init.kmemleak.sh
@@ -0,0 +1,17 @@
+#!/system/bin/sh
+test_count=0
+file_name=""
+file_name2=""
+#rm /sdcard/log_kmemleak/kmemleak_log*
+
+while true;do
+    file_name="kmemleak_log_$test_count.txt"
+    cat /sys/kernel/debug/kmemleak > /sdcard/$file_name
+    echo clear  > /sys/kernel/debug/kmemleak
+    echo scan   > /sys/kernel/debug/kmemleak
+    test_count=$(($test_count+1))
+    sleep 600
+done
+echo "end"
 
이 기능의 핵심 함수는 kmemleak_scan()인데요.
object_list란 링크드 리스트를 돌면서 플래그 속성이 OBJECT_ALLOCATED인 kmemleak_object에 대해
콜스택을 찍어주죠.
 
아웃풋 파일은 아래와 같아요. 
이제 덤프한 파일을 해석하는 게 아주 중요한데요.
사실 로그 중에는 false positive라고 정상 동작인데 에러 로그 처럼 보이는게 있는데요.
이런 놈을 잘 필터링하는게 중요해요. 아래는 대표적인 false positive 로그에요.
unreferenced object 0xc413bd00 (size 64):
  comm "swapper/0", pid 1, jiffies 4294938050 (age 652.640s)
  hex dump (first 32 bytes):
    00 00 00 00 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b  ....kkkkkkkkkkkk
    6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b  kkkkkkkkkkkkkkkk
  backtrace:
    [<c0472728>] dma_async_device_register+0x198/0x494
    [<c0473818>] qbam_probe+0x170/0x230
    [<c057ddf0>] platform_drv_probe+0x30/0x78
    [<c057c1e4>] driver_probe_device+0x33c/0x6b40
    [<c057c604>] __driver_attach+0x68/0x8c
    [<c057a5d0>] bus_for_each_dev+0x70/0x84
    [<c057b66c>] bus_add_driver+0x100/0x1f8
    [<c057cf2c>] driver_register+0x9c/0xe0
    [<c01009dc>] do_one_initcall+0x19c/0x1dc
    [<c1900dd0>] kernel_init_freeable+0x108/0x1cc
    [<c0f53e28>] kernel_init+0x8/0xe8
    [<c01068e0>] ret_from_fork+0x14/0x34
    [<ffffffff>] 0xffffffff
 
unreferenced object 0xc413bb00 (size 64):
  comm "swapper/0", pid 1, jiffies 4294938050 (age 652.640s)
  hex dump (first 32 bytes):
    00 00 00 00 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b  ....kkkkkkkkkkkk
    6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b  kkkkkkkkkkkkkkkk
  backtrace:
    [<c0472728>] dma_async_device_register+0x198/0x494
    [<c0473818>] qbam_probe+0x170/0x230
    [<c057ddf0>] platform_drv_probe+0x30/0x78
    [<c057c1e4>] driver_probe_device+0x33c/0x6b0
    [<c057c604>] __driver_attach+0x68/0x8c
    [<c057a5d0>] bus_for_each_dev+0x70/0x84
    [<c057b66c>] bus_add_driver+0x100/0x1f8
    [<c057cf2c>] driver_register+0x9c/0xe0
    [<c01009dc>] do_one_initcall+0x19c/0x1dc
    [<c1900dd0>] kernel_init_freeable+0x108/0x1cc
    [<c0f53e28>] kernel_init+0x8/0xe8
    [<c01068e0>] ret_from_fork+0x14/0x34
    [<ffffffff>] 0xffffffff
 
 
 
# Reference: For more information on 'Linux Kernel';
 
디버깅을 통해 배우는 리눅스 커널의 구조와 원리. 1
 
디버깅을 통해 배우는 리눅스 커널의 구조와 원리. 2