Sometime I noticed that system does not crash when the call to BUG() is made in the kernel driver. I just observed the stack trace from the kernel log and then find that target is running rather than entering crash mode.
 
To make the target crash when BUG() is called, the following config should be present;
 
CONFIG_PANIC_ON_OOPS=y
CONFIG_PANIC_ON_OOPS_VALUE=1
 
Let's look at kernel die() function which is called from BUG() function.
 
void die(const char *str, struct pt_regs *regs, int err)
{
...
 
if (in_interrupt())
panic("%s: Fatal exception in interrupt", str);
if (panic_on_oops)
panic("%s: Fatal exception", str);
 
If panic_on_oops is true, the panic() is called with "Fatal exception message". How panic_on_oops is specified? Is it configured during run-time?
 
Let's take a look at below statement;
 
int panic_on_oops = CONFIG_PANIC_ON_OOPS_VALUE;
 
panic_on_oops depends on CONFIG_PANIC_ON_OOPS_VALUE.
Now is time to check the definition of CONFIG_PANIC_ON_OOPS_VALUE.
 
config PANIC_ON_OOPS_VALUE
int
range 0 1
default 0 if !PANIC_ON_OOPS
default 1 if PANIC_ON_OOPS
 
CONFIG_PANIC_ON_OOPS_VALUE can be configured by PANIC_ON_OOPS.
 
Conclusion
 
PANIC_ON_OOPS should be enabled to make the target crash when BUG() is called.
가끔 가다가 커널 메모리 누수(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
 
 
 
 
 
 
#커널 크래시 디버깅 및 TroubleShooting
커널 패닉이 났어요.
네트워크 드라이버 리눅스 커널 코드에서 발생한 것 같은데요. 음.
일단 당황하지 마시구요. 차근 차근 커널 로그와 코어 덤프를 살펴보면, 정답이 나와요.
 
일단 커널 로그를 보면, 프로그램 카운터가 0x0을 가르키고 있네요.
음... 그리고
링크 레지스터(R14)가 0xc0adc274(LR is at xfrm_local_error+0x4c/0x58) 을 가르키고 있습니다.
[  262.401303] Unable to handle kernel NULL pointer dereference at virtual address 00000000
[  262.401365] pgd = dbdc4000
[  262.401389] [00000000] *pgd=00000000
[  262.401433] Internal error: Oops: 80000005 [#1] PREEMPT SMP ARM
[  262.401459] Modules linked in:
[  262.401495] CPU: 0 PID: 7107 Comm: Framework Tainted: G        W    3.10.49-g356bd9f-00007-gadca646 #1
[  262.401522] task: da6b0540 ti: d9412000 task.ti: d9412000
[  262.401549] PC is at 0x0
[  262.401590] LR is at xfrm_local_error+0x4c/0x58
[  262.401619] pc : [<00000000>]    lr : [<c0adc274>]    psr: a00f0013
[  262.401619] sp : d9413c68  ip : c0ac6c20  fp : 0000dd86
[  262.401654] r10: 0000010e  r9 : 0000010a  r8 : de0ddc20
[  262.401678] r7 : c13ddf00  r6 : 00000500  r5 : d9094540  r4 : c13e3780
[  262.401703] r3 : 00000000  r2 : 00000001  r1 : 00000500  r0 : d9094540
 
일단 커널 로그에서 R14가 가르키는(커널 패닉이 발생한 함수를 호출한) 주소로 가보면요. 
R3를 branch instruction으로 수행하고 있었습니다. 이런 Instruction은 함수 포인터로 함수를 호출할 때 쓰이죠.
그런데 커널 로그에서 R3이 0x0이라고 하네요.
   NSR:C0ADC264|E1A00005            cpy     r0,r5            ; proto,skb
   NSR:C0ADC268|E594344C            ldr     r3,[r4,#0x44C]
   NSR:C0ADC26C|E1A01006            cpy     r1,r6            ; r1,mtu
   NSR:C0ADC270|E12FFF33            blx     r3  //<<--
   
아 이제, 커널 로그가 가르키는 스택 주소 0xd9413c68로 좀 가볼까요?
d.v %y.l 0xD9413C68
______address|_data________|value_____________|symbol
NSD:D9413C60| 13 00 0F A0  0xA00F0013
NSD:D9413C64| FF FF FF FF  0xFFFFFFFF
NSD:D9413C68| 40 45 09 D9  0xD9094540    // <<-R4 
NSD:D9413C6C| 00 0C 42 DC  0xDC420C00   //<<--R5 
NSD:D9413C70| 40 45 09 D9  0xD9094540     //<<-- R6
NSD:D9413C74| 0C 11 AD C0  0xC0AD110C         \vmlinuxxfrm4_output__xfrm4_output+0xE4  //<<--R14
NSD:D9413C78| 00 00 00 00  0x0
NSD:D9413C7C| 01 00 00 00  0x1
NSD:D9413C80| 00 0C 42 DC  0xDC420C00
NSD:D9413C84| 6C C0 AD C0  0xC0ADC06C         \vmlinuxxfrm_outputxfrm_output_resume+0x41C
 
@D9413C74 스택 주소를 보니, 0xC0AD110C 즉 __xfrm4_output+0xE4 주소를 볼 수 있는데요.
0xC0AD110C 주소를 가보니, xfrm_local_error란 함수를 branch operation으로 수행을 하네요.
______addr/line|code_____|label____|mnemonic________________|comment
    NSR:C0AD1104|E1A00004            cpy     r0,r4            ; r0,skb
   NSR:C0AD1108|EB002C46            bl      0xC0ADC228       ; xfrm_local_error
 
xfrm_local_error() 함수 초반 ARM Instruction을 보면, R14, R6, R5, R4 순으로 스택에 Push를 하네요.   
   NSR:C0ADC228|E92D4070  xfrm_local_error:    push    {r4-r6,r14}
   NSR:C0ADC22C|E1A05000                       cpy     r5,r0            ; skb,pr
   
예를 들면, 이런 거죠. 스택에 이렇게 Push를 하고나면 새로운 스택 주소는 D9413C68(<-D9413C74)가 되는거죠.
stack 주소
D9413C68  R4을 스택에 Push       =>> 0xD9094540
D9413C6C  R5을 스택에 Push       =>> 0xDC420C00
D9413C70  R6을 스택에 Push       =>> 0xD9094540
D9413C74  R14 주소 스택에 Push =>>  0xC0AD110C
 
이렇게 새로운 함수가 호출될 때 스택에 파라미터를 Push하는 규칙은 CPU 아키텍쳐마다 다르거든요.
위의 경우에는 ARM32 아키텍처 Calling Convention에 따른 거에요.
 
ARM 스팩 문서를 보시면 위 내용이 자세히 나와 있어요.
 
자 다시 커널 로그로 돌아가 봅시다.
[  262.401495] CPU: 0 PID: 7107 Comm: BaldTainted: G        W    3.10.49-g356bd9f-00007-gadca646 #1
[  262.401522] task: da6b0540 ti: d9412000 task.ti: d9412000
[  262.401549] PC is at 0x0
[  262.401590] LR is at xfrm_local_error+0x4c/0x58
[  262.401619] pc : [<00000000>]    lr : [<c0adc274>]    psr: a00f0013
[  262.401619] sp : d9413c68  ip : c0ac6c20  fp : 0000dd86
 
T32 프로그램으로, 
커널 로그에서 찍힌 LR을 프로그램 카운터로 설정하고, 스택 주소는 그대로 설정 그리고 위 스택 정보에서 살펴본 0xC0AD110C(__xfrm4_output+0xE4) 주소를
설정하면. 이렇게 이쁘게 콜 스택이 보이네요.
 
-000|xfrm_local_error(skb = 0xDCD376C0, mtu = -611987776)
-001|__xfrm4_output(skb = 0xD9094540)
-002|xfrm_output_resume(skb = 0xD9094540, err = 1)
-003|__xfrm4_output(skb = 0xD9094540)
-004|ip_local_out(skb = 0xD9094540)
-005|ip_send_skb(net = 0xC13DDF00, ?)
-006|udp_send_skb(skb = 0xD9094540, ?)
-007|udp_sendmsg(?, sk = 0xDE0F1680, msg = 0xD9413EE0, len = 1300)
-008|inet_sendmsg(iocb = 0xD9413E58, ?, msg = 0xD9413EE0, size = 1300)
-009|sock_sendmsg(sock = 0xDA9A5500, msg = 0xD9413EE0, size = 1300)
-010|SYSC_sendto(inline)
-010|sys_sendto(?, buff = -1997588480, ?, ?, addr = -1985806992, addr_len = 16)
-011|ret_fast_syscall(asm)
 
T32 명령어는 아래와 같아요.
r.s R13  0xD9413C68
r.s R14 0xC0AD110C
r.s PC   0xC0ADC270
   
0xC0ADC270 주소에 다시 가볼까요? R3가 어떻게 0x0으로 업데이트되는지 봐야겠죠.  
확인해보니, ldr     r3,[r4,#0x44C] 명령어로 업데이트 되네요. 
   NSR:C0ADC264|E1A00005                        cpy     r0,r5            ; proto,skb
   NSR:C0ADC268|E594344C                        ldr     r3,[r4,#0x44C]
   NSR:C0ADC26C|E1A01006                        cpy     r1,r6            ; r1,mtu
   NSR:C0ADC270|E12FFF33                        blx     r3
   
0xC0ADC270 주소로 실제 소스 코드 위치를 알면 좋을 상황인데요. T32에서 이런 상황에서 아주 유용한 커맨드를 제공해요.
y.l.line 0xC0ADC270   
__________address________|module__________________________________|source________|line______|o
     P:C0ADC25C--C0ADC263|\vmlinuxxfrm_output                   |.1/android/kernel/net/xfrm/xfrm_output.c|247--247          |
     P:C0ADC264--C0ADC273|\vmlinuxxfrm_output                   |.1/android/kernel/net/xfrm/xfrm_output.c|248--250          |
    
음, kernel/net/xfrm/xfrm_output.c의 248--250  라인인 것 같네요. 
역시나, 실제 소스 코드를 보면 함수 포인터(콜백 함수 형태)로 함수를 호출하고 있네요.
234void xfrm_local_error(struct sk_buff *skb, int mtu)
235{
236 unsigned int proto;
237 struct xfrm_state_afinfo *afinfo;
238
// ...생략...
245
246 afinfo = xfrm_state_get_afinfo(proto);
247 if (!afinfo)
248 return;
249
250 afinfo->local_error(skb, mtu);  //<<--
251 xfrm_state_put_afinfo(afinfo);   
 
struct xfrm_state_afinfo란 구조체에서 local_error란 멤버의 오프셋 주소가 얼마인지 알아볼까요?
예를 들어서, bald_manager란 구조체가 있으면, issue 멤버는 0x4, issue_list 멤버는 0x8 오프셋이라고 볼 수 있어요.
struct bald_manager {
int phone;
int issue;
struct list_head issue_list;
}; 
 
음, 이럴 때 커널 패닉을 디버깅하는 Crash Tool이란 좋은 툴에서 아주 유용한 기능을 제공하거든요.
아래와 같은 명령어를 입력하면, local_error 멤버의 오프셋이 0x44c임을 알 수 있어요.
crash> struct -o xfrm_state_afinfo.local_error
struct xfrm_state_afinfo {
  [0x44c] void (*local_error)(struct sk_buff *, u32);
}
 
어떤 T32 매니아가 저에게 질문을 던지네요.
음 T32로는 확인할 수 없냐구요? 아래 매크로 기능으로 확인 가능해요.
 
T32로 아래 명령어를 입력하면 되요.
sYmbol.NEW.MACRO offsetof(type,member) ((int)(&((type*)0)->member))
 
이게 제가 뚝딱만든 코드는 아니구요. 이미 리눅스 커널 코드에 있는 매크로를 그대로 가져온 거거든요.
[android/kernel/include/linux/stddef.h]
#define offsetof(TYPE, MEMBER) ((size_t) &((TYPE *)0)->MEMBER)
 
요렇게 입력하면 똑같은 0x044C 오프셋 주소를 확인할 수 있어요. T32로 디버깅할 때 자주 쓰면 좋아요.
v.v %h offsetof(struct xfrm_state_afinfo,local_error)
  offsetof(struct xfrm_state_afinfo,local_error) = 0x044C
 
자, 이제 0xC0ADC270 주소에 다시 가보면 [1] instruction이 afinfo->local_error(skb, mtu); 함수 라인에 매핑되는 걸 알 수 있어요.
   NSR:C0ADC264|E1A00005                        cpy     r0,r5            ; proto,skb
   NSR:C0ADC268|E594344C                        ldr     r3,[r4,#0x44C]  //<<--[1]
   250 afinfo->local_error(skb, mtu);  //<<--[1]
   NSR:C0ADC26C|E1A01006                        cpy     r1,r6            ; r1,mtu
   NSR:C0ADC270|E12FFF33                        blx     r3
 
커널 패닉 시 로그를 다시 보면, R4가 0xc13e3780이거든요.
이 값을 T32로 (struct xfrm_state_afinfo *) 타입으로 캐스팅해서 올려보면,  local_error값이 0x0이네요.
어라, 그리고 0xC13E3780 주소의 정체가 xfrm4_state_afinfo란 전역 벼수라는 것도 알 수 있네요.
v.v %all (struct xfrm_state_afinfo *)0xc13e3780
  (struct xfrm_state_afinfo *) (struct xfrm_state_afinfo *)0xc13e3780 = 0xC13E3780 = xfrm4_state_afinfo -> (
    (unsigned int) family = 2 = 0x2 = '....',
    (unsigned int) proto = 4 = 0x4 = '....',
    (__be16) eth_proto = 8 = 0x8 = '..',
    (struct module *) owner = 0x0 =  -> NULL,
    (struct xfrm_type * [256]) type_map = ([0] = 0x0 =  -> NULL, [1] = 0x0 =  -> NULL, [2] = 0x0 =  -> NULL, [3] = 0
    (struct xfrm_mode * [5]) mode_map = ([0] = 0xC13E31D8 = xfrm4_transport_mode -> ((int (*)()) input2 = 0x0 = , (i
    (int (*)()) init_flags = 0xC0AD0AD0 = xfrm4_init_flags -> ,
    (void (*)()) init_tempsel = 0xC0AD0B6C = __xfrm4_init_tempsel -> ,
    (void (*)()) init_temprop = 0xC0AD0AF4 = xfrm4_init_temprop -> ,
    (int (*)()) tmpl_sort = 0x0 =  -> NULL,
    (int (*)()) state_sort = 0x0 =  -> NULL,
    (int (*)()) output = 0xC0AD12E4 = xfrm4_output -> ,
    (int (*)()) output_finish = 0xC0AD129C = xfrm4_output_finish -> ,
    (int (*)()) extract_input = 0xC0AD0D8C = xfrm4_extract_input -> ,
    (int (*)()) extract_output = 0xC0AD11E0 = xfrm4_extract_output -> ,
    (int (*)()) transport_finish = 0xC0AD0D94 = xfrm4_transport_finish -> ,
    (void (*)()) local_error = 0x0 =  -> NULL)  //<<--
 
    
이제 정리 좀 하면.
afinfo->local_error(skb, mtu); 주소가 0x0이라서 커널 패닉으로 타겟이 크래시가 난 거에요.
참, 결론은 허무하죠. 대부분의 커널 패닉 문제는 허무하게 끝납니다.     
 
아 이제, 코드 리뷰를 해볼 시간인데. xfrm4_state_afinfo란 변수 선언문을 가보았더니 에서 local_error 멤버를 초기화하지 않고 있네요.
[kernel/net/ipv4/xfrm4_state.c]
static struct xfrm_state_afinfo xfrm4_state_afinfo = {
        .family                 = AF_INET,
        .proto                  = IPPROTO_IPIP,
        .eth_proto              = htons(ETH_P_IP),
        .owner                  = THIS_MODULE,
        .init_flags             = xfrm4_init_flags,
        .init_tempsel           = __xfrm4_init_tempsel,
        .init_temprop           = xfrm4_init_temprop,
        .output                 = xfrm4_output,
        .output_finish          = xfrm4_output_finish,
        .extract_input          = xfrm4_extract_input,
        .extract_output         = xfrm4_extract_output,
        .transport_finish       = xfrm4_transport_finish,
}; 
 
아래와 같이 local_error 멤버에 대한 콜백 함수를 추가하는 코드를 추가하니 커널 패닉 증상은 사라졌습니다.
diff --git a/net/ipv4/xfrm4_state.c b/net/ipv4/xfrm4_state.c
index 9258e75..0b2a064 100644
--- a/net/ipv4/xfrm4_state.c
+++ b/net/ipv4/xfrm4_state.c
@@ -83,6 +83,7 @@ static struct xfrm_state_afinfo xfrm4_state_afinfo = {
        .extract_input          = xfrm4_extract_input,
        .extract_output         = xfrm4_extract_output,
        .transport_finish       = xfrm4_transport_finish,
+       .local_error            = xfrm4_local_error,
 };
 
# Reference: For more information on 'Linux Kernel';
 
디버깅을 통해 배우는 리눅스 커널의 구조와 원리. 1
 
디버깅을 통해 배우는 리눅스 커널의 구조와 원리. 2
 
 
 

+ Recent posts