Linux Kernel(4.14) Hacks

rousalome.egloos.com

포토로그 Kernel Crash




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


난이도: 하

이제 커널 로그부터 볼게요. 이전과 비슷한 패턴인데 약간 다른 것 같네요.
1  [ 2551.510956 / 04-07 15:43:12.844][3] =============================================================================
2  [ 2551.510994 / 04-07 15:43:12.844][3] BUG kmalloc-256 (Tainted: G        W     ): Invalid object pointer 0xe216ce10
3  [ 2551.511015 / 04-07 15:43:12.844][3] -----------------------------------------------------------------------------
4  [ 2551.511015 / 04-07 15:43:12.844][3] 
5  [ 2551.511047 / 04-07 15:43:12.844][3] INFO: Slab 0xec69a600 objects=36 used=20 fp=0xe216d500 flags=0x4081
6  [ 2551.511550 / 04-07 15:43:12.844][3] Kernel panic - not syncing: slab error
7  [ 2551.511550 / 04-07 15:43:12.844][3] 
8  [ 2551.511631 / 04-07 15:43:12.844][3] CPU: 3 PID: 585 Comm: surfaceflinger Tainted: G    B   W      3.18.31-g6258e9b-dirty #35
9  [ 2551.511699 / 04-07 15:43:12.844][3] [<c0016fb8>] (unwind_backtrace) from [<c0013760>] (show_stack+0x20/0x24)
10 [ 2551.511761 / 04-07 15:43:12.844][3] [<c0013760>] (show_stack) from [<c0f6408c>] (dump_stack+0x9c/0xd4)
11 [ 2551.511796 / 04-07 15:43:12.844][3] [<c0f6408c>] (dump_stack) from [<c0f5f7cc>] (panic+0x120/0x388)
12 [ 2551.511847 / 04-07 15:43:12.844][3] [<c0f5f7cc>] (panic) from [<c014d950>] (slab_err+0x90/0xa4)
13 [ 2551.511915 / 04-07 15:43:12.844][3] [<c014d950>] (slab_err) from [<c0f61fec>] (free_debug_processing+0x1d8/0x300)
14 [ 2551.511981 / 04-07 15:43:12.844][3] [<c0f61fec>] (free_debug_processing) from [<c0f62158>] (__slab_free+0x44/0x3a8)
15 [ 2551.512047 / 04-07 15:43:12.844][3] [<c0f62158>] (__slab_free) from [<c014fa40>] (kfree+0x238/0x28c)
16 [ 2551.512112 / 04-07 15:43:12.844][3] [<c014fa40>] (kfree) from [<c0372810>] (mdss_rotator_ioctl+0x8d4/0x1b70)
18 [ 2551.512213 / 04-07 15:43:12.844][3] [<c0372810>] (mdss_rotator_ioctl) from [<c016b5fc>] (do_vfs_ioctl+0x500/0x5bc)
19 [ 2551.512240 / 04-07 15:43:12.844][3] [<c016b5fc>] (do_vfs_ioctl) from [<c016b714>] (SyS_ioctl+0x5c/0x84)
20 [ 2551.512268 / 04-07 15:43:12.844][3] [<c016b714>] (SyS_ioctl) from [<c000f300>] (ret_fast_syscall+0x0/0x50)

위 로그를 보면 메모리를 해제하는 콜스택을 볼 수 있습니다. mdss_rotator_ioctl -> kfree 순서로 말이죠.
1  [ 2551.510956 / 04-07 15:43:12.844][3] ================================================ 
2  [ 2551.510994 / 04-07 15:43:12.844][3] BUG kmalloc-256 (Tainted: G        W     ): Invalid object pointer 0xe216ce10
3  [ 2551.511015 / 04-07 15:43:12.844][3] -----------------------------------------------------------------------------
 
그런데 0xe216ce10란 오브젝트 주소에 뭔가 문제가 있다고 알려주는 것 같습니다.
참고로 위 로그는 다음 free_debug_processing 함수에서 slab_err 함수를 출력할 때 뿌려줍니다. 이 점 참고하세요.
static noinline struct kmem_cache_node *free_debug_processing(
struct kmem_cache *s, struct page *page, void *object,
unsigned long addr, unsigned long *flags)
{
struct kmem_cache_node *n = get_node(s, page_to_nid(page));

spin_lock_irqsave(&n->list_lock, *flags);
slab_lock(page);

if (!check_slab(s, page))
goto fail;

if (!check_valid_pointer(s, page, object)) {
slab_err(s, page, "Invalid object pointer 0x%p", object);
goto fail;
}
 
그럼 다시 디버깅으로 돌아갈께요.  이번에는 0xe216ce10 주소가 어떤 타입인지 알아볼 차례군요..
crash> kmem 0xe216ce10
CACHE    NAME                 OBJSIZE  ALLOCATED     TOTAL  SLABS  SSIZE
eac03b80 kmalloc-256              256       2017      2556     71    16k
  SLAB      MEMORY    NODE  TOTAL  ALLOCATED  FREE
  ec69a600  e216c000     0     36         20    16
  FREE / [ALLOCATED]
  [e216ce00]

위 명령어로 확인하니 e216ce00 주소에서 시작하는 kmalloc-256 타입 슬랩입니다.
그럼 e216ce00 메모리 주소 근처 메모리 덤프를 볼까요?
d.v %y.l 0xE216CE00
_____address|_data________|value_____________|symbol
NSD:E216CDF8| 5A 5A 5A 5A  0x5A5A5A5A
NSD:E216CDFC| 5A 5A 5A 5A  0x5A5A5A5A
NSD:E216CE00| 40 A1 E2 E4  0xE4E2A140
NSD:E216CE04| 00 8A 35 D6  0xD6358A00                                                   
NSD:E216CE08| 38 A3 4E C0  0xC04EA338         \\vmlinux\base/devres\devm_kmalloc_release
NSD:E216CE0C| 00 00 00 00  0x0                                                   
NSD:E216CE10| 08 00 00 00  0x8                               
NSD:E216CE14| 00 00 00 00  0x0  

E216CE00 주소에서 0x4만큼 떨어진 E216CDFC 주소를 보면 0x5A5A5A5A 값을 담고 있습니다.
슬랩 오브젝트 패딩 값이군요. 슬랩 오브젝트 경계 주소에 0x5A5A5A5A 이란 패딩 매직값을 써준 다는 점 기억하세요.

여기까지 확인한 정보로 다음과 같이 정리할 수 있습니다.
1. 슬랩 오브젝트를 해제하는 과정
2. 0xe216ce10이란 메모리를 해제하려 하는데 이 메모리는 슬랩 오브젝트 시작 주소가 아님
 
그럼 e216ce00 메모리 주소 근처 메모리 덤프를 볼까요?
d.v %y.l 0xE216CE00
_____address|_data________|value_____________|symbol
NSD:E216CDF8| 5A 5A 5A 5A  0x5A5A5A5A
NSD:E216CDFC| 5A 5A 5A 5A  0x5A5A5A5A
NSD:E216CE00| 40 A1 E2 E4  0xE4E2A140
NSD:E216CE04| 00 8A 35 D6  0xD6358A00                                                   
NSD:E216CE08| 38 A3 4E C0  0xC04EA338         \\vmlinux\base/devres\devm_kmalloc_release
NSD:E216CE0C| 00 00 00 00  0x0                                                   
NSD:E216CE10| 08 00 00 00  0x8                               
NSD:E216CE14| 00 00 00 00  0x0                                                   
NSD:E216CE18| 00 00 00 00  0x0                                                   
NSD:E216CE1C| 38 04 00 00  0x438              
NSD:E216CE20| 38 04 00 00  0x438                   
NSD:E216CE24| 00 00 00 00  0x0                                                   
NSD:E216CE28| 00 00 00 00  0x0
//...
NSD:E216CEFC|0x0
NSD:E216CF00|0xCCCCCCCC
NSD:E216CF04|0xE216DC00
NSD:E216CF08|0xC03721AC         \\vmlinux\mdss_rotator\mdss_rotator_ioctl+0x270
NSD:E216CF0C|0xC0150C8C         \\vmlinux\slub\__kmalloc_track_caller+0xE8
NSD:E216CF10|0xC04EA748         \\vmlinux\base/devres\devm_kmalloc+0x28
NSD:E216CF14|0xC03721AC         \\vmlinux\mdss_rotator\mdss_rotator_ioctl+0x270
NSD:E216CF18|0xC016B5FC         \\vmlinux\fs/ioctl\do_vfs_ioctl+0x500
NSD:E216CF1C|0xC016B714         \\vmlinux\fs/ioctl\sys_ioctl+0x5C
NSD:E216CF20|0xC000F300         \\vmlinux\Global\ret_fast_syscall
NSD:E216CF24|0x0
NSD:E216CF28|0x0
NSD:E216CF2C|0x0
NSD:E216CF30|0x0
NSD:E216CF34|0x0
NSD:E216CF38|0x0
NSD:E216CF3C|0x0
NSD:E216CF40|0x0
NSD:E216CF44|0x0
NSD:E216CF48|0x0
 
위 메모리 덤프에서 매우 중요한 정보만 모아서 보여드릴게요. 
NSD:E216CE00| 40 A1 E2 E4  0xE4E2A140
NSD:E216CE04| 00 8A 35 D6  0xD6358A00                                                   
NSD:E216CE08| 38 A3 4E C0  0xC04EA338         \\vmlinux\base/devres\devm_kmalloc_release
NSD:E216CE0C| 00 00 00 00  0x0   
NSD:E216CE10| 08 00 00 00  0x8                               
NSD:E216CE14| 00 00 00 00  0x0                                                   
NSD:E216CE18| 00 00 00 00  0x0                                                  
//...
NSD:E216CF08|0xC03721AC         \\vmlinux\mdss_rotator\mdss_rotator_ioctl+0x270
NSD:E216CF0C|0xC0150C8C         \\vmlinux\slub\__kmalloc_track_caller+0xE8
NSD:E216CF10|0xC04EA748         \\vmlinux\base/devres\devm_kmalloc+0x28
NSD:E216CF14|0xC03721AC         \\vmlinux\mdss_rotator\mdss_rotator_ioctl+0x270

이 슬랩 메모리는 devm_kmalloc로 할당했습니다. 
왜냐면 슬랩 오브젝트에서 0x8 만큼 떨어진 주소에 devm_kmalloc_release 심볼이 있기 때문이죠.
또한 0xE216CF10 주소에도 devm_kmalloc+0x28 심볼이 있습니다.

그래서 devm_kmalloc로 슬랩 메모리를 할당했을 경우 반드시 아래 형식으로 메모리를 해제해야 합니다.
devm_kfree(0xE94AF6D0, 0xE216CE10)

그런데 아래 코드로 메모리를 해제하니 리눅스 커널에선 0xE216CE10 메모리 주소는 슬랩 시작 주소가 아니라고 식별하는 겁니다. 
kfree(0xE216CE10)

실제 코드를 열어보니 kfree로 메모리를 해제하는군요.
static int mdss_rotator_handle_request(struct mdss_rot_mgr *mgr,
        struct mdss_rot_file_private *private, unsigned long arg)
{
        struct mdp_rotation_request user_req;
        struct mdp_rotation_item *items = NULL;
//..

 handle_request_err1:
         mutex_unlock(&mgr->lock);
 handle_request_err:
         kfree(items);  //<<--

커널 크래시 발생할 때도 mdss_rotator_ioctl 심볼에서 kfree 함수를 호출하는 디버깅 정보를 담고 있습니다. 
참고로 위 mdss_rotator_handle_request 함수는 static 타입으로 선언해서 커널이 심볼을 식별하지 못하고 있다는 점 기억하세요.
1 [ 2551.512047 / 04-07 15:43:12.844][3] [<c0f62158>] (__slab_free) from [<c014fa40>] (kfree+0x238/0x28c)
2 [ 2551.512112 / 04-07 15:43:12.844][3] [<c014fa40>] (kfree) from [<c0372810>] (mdss_rotator_ioctl+0x8d4/0x1b70)
3 [ 2551.512213 / 04-07 15:43:12.844][3] [<c0372810>] (mdss_rotator_ioctl) from [<c016b5fc>] (do_vfs_ioctl+0x500/0x5bc)
4 [ 2551.512240 / 04-07 15:43:12.844][3] [<c016b5fc>] (do_vfs_ioctl) from [<c016b714>] (SyS_ioctl+0x5c/0x84)
5 [ 2551.512268 / 04-07 15:43:12.844][3] [<c016b714>] (SyS_ioctl) from [<c000f300>] (ret_fast_syscall+0x0/0x50)

다음과 같이 코드를 수정했더니 이런 문제는 발생하지 않았습니다.
diff --git a/drivers/video/msm/mdss/mdss_rotator.c b/drivers/video/msm/mdss/mdss_rotator.c
index 019621b..4f2262b 100644
--- a/drivers/video/msm/mdss/mdss_rotator.c
+++ b/drivers/video/msm/mdss/mdss_rotator.c
@@ -2244,7 +2244,7 @@ static int mdss_rotator_handle_request(struct mdss_rot_mgr *mgr,
 handle_request_err1:
        mutex_unlock(&mgr->lock);
 handle_request_err:
-       kfree(items);
+       devm_kfree(&mgr->pdev->dev, items);
        devm_kfree(&mgr->pdev->dev, req);
        return ret;
 }

[Appendix 1] 디버깅 
mdss_rotator_handle_request 함수에서 devm_kfree(&mgr->pdev->dev, items); 함수를 호출할 때 어떤 방식으로 파라미터를 전달하는지 확인했습니다.
static int mdss_rotator_handle_request(struct mdss_rot_mgr *mgr,
struct mdss_rot_file_private *private, unsigned long arg)
{
struct mdp_rotation_request user_req;
struct mdp_rotation_item *items = NULL;
struct mdss_rot_entry_container *req = NULL;
//...
handle_request_err:
devm_kfree(&mgr->pdev->dev, items);  //<<--

R0 (struct device*): 0xE94AF6D0 =  &mgr->pdev->dev
R1 (struct mdp_rotation_item *): 0xE216CE10 where "ldr     r1,[r11,#-0x9C]" r1 = 0xDD095E60

devm_kfree 함수 호출 직전 어셈블리 코드를 열어서 어떤 파라미터를 전달했는지 확인하니 다음과 같군요.
1 NSR:C0372800|E5950034  ldr     r0,[r5,#0x34]  // r0 = 0xE94AF6C0 =  *(0xE81E2110 + 0x34) =  *(r5 + 0x34) 
2 NSR:C0372804|E51B109C  ldr     r1,[r11,#-0x9C]
3 NSR:C0372808|E2800010  add     r0,r0,#0x10      ; r0,r0,#16  // r0 = 0xE94AF6D0 = 0xE94AF6C0 + 0x10 = R0 + 0x10
4 NSR:C037280C|EB05E0FD  bl      0xC04EAC08       ; devm_kfree
d.dump 0xDD095EFC-0x9c
_____address|________0________4________8________C
NSD:DD095E60|>E216CE10 C0047703 DD095E84 DD095E78

[Appendix 2] 다음과 같이 코드를 반영해도 비슷한 유형의 커널 크래시를 유발시킬 수 있습니다.
diff --git a/drivers/base/devres.c b/drivers/base/devres.c
index 8754646..6ba967d 100644
--- a/drivers/base/devres.c
+++ b/drivers/base/devres.c
@@ -872,6 +872,8 @@ char *devm_kasprintf(struct device *dev, gfp_t gfp, const char *fmt, ...)
 }
 EXPORT_SYMBOL_GPL(devm_kasprintf);

+extern uint32_t kernel_bsp_debug_level;
+
 /**
  * devm_kfree - Resource-managed kfree
  * @dev: Device this memory belongs to
@@ -883,8 +885,13 @@ void devm_kfree(struct device *dev, void *p)
 {
        int rc;

-       rc = devres_destroy(dev, devm_kmalloc_release, devm_kmalloc_match, p);
-       WARN_ON(rc);
+       if (kernel_bsp_debug_level == 4066) {
+               kfree(p);
+       }
+        else {
+               rc = devres_destroy(dev, devm_kmalloc_release, devm_kmalloc_match, p);
+               WARN_ON(rc);
+       }
 }
 EXPORT_SYMBOL_GPL(devm_kfree);


핑백

덧글

댓글 입력 영역