# 리눅스 커널 Memory Management
난이도: 하
이제 커널 로그부터 볼게요. 이전과 비슷한 패턴인데 약간 다른 것 같네요.
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로 메모리를 해제하는군요.
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);
# Reference: For more information on 'Linux Kernel';
디버깅을 통해 배우는 리눅스 커널의 구조와 원리. 1
디버깅을 통해 배우는 리눅스 커널의 구조와 원리. 2
최근 덧글