http://thinkiii.blogspot.jp/2014/02/debug-with-slub-allocator.html

The slub allocator in Linux has useful debug features. Such as poisoning, readzone checking, and allocate/free traces with timestamps. It's very useful during product developing stage. Let's create a kernel module and test the debug features.

Make sure slub allocator is built in your kernel.

CONFIG_SLUB_DEBUG=y

CONFIG_SLUB=y

The slub allocator creates additional meta data to store allocate/free traces and timestamps. Everytime slub allocator allocate/free an object, it do poison check (data area) and redzone check  (boundry).

The module shows how it happens. It allocates 32 bytes from kernel and we overwrite the redzone by memset 36 bytes.

void try_to_corrupt_redzone(void)

{

        void *p = kmalloc(32, GFP_KERNEL);

        if (p) {

                pr_alert("p: 0x%p\n", p);

                memset(p, 0x12, 36);    /* write too much */

                print_hex_dump(KERN_ALERT, "mem: ", DUMP_PREFIX_ADDRESS,

                                16, 1, p, 512, 1);

                kfree(p);       /* slub.c should catch this error */

        }

}

static int mymodule_init(void)

{

        pr_alert("%s init\n", __FUNCTION__);

        try_to_corrupt_redzone();

        return 0;

}

static void mymodule_exit(void)

{

        pr_alert("%s exit\n", __FUNCTION__);

}

module_init(mymodule_init);

module_exit(mymodule_exit);

After freeing the object, the kernel checks the object and find that the redzone is overwritten and says:

[ 2050.630002] mymodule_init init

[ 2050.630565] p: 0xddc86680

[ 2050.630653] mem: ddc86680: 12 12 12 12 12 12 12 12 12 12 12 12 12 12 12 12  ................

[ 2050.630779] mem: ddc86690: 12 12 12 12 12 12 12 12 12 12 12 12 12 12 12 12  ................

[ 2050.630897] mem: ddc866a0: 12 12 12 12 60 6b c8 dd 16 80 99 e0 fa 8e 2a c1  ....`k........*.

[ 2050.631014] mem: ddc866b0: 16 80 99 e0 ce 92 2a c1 16 80 99 e0 f2 c1 1b c1  ......*.........

[ 2050.631130] mem: ddc866c0: 16 80 99 e0 4c 8b 0a c1 4c 8b 0a c1 61 80 99 e0  ....L...L...a...

[ 2050.631248] mem: ddc866d0: 16 80 99 e0 61 80 99 e0 16 80 99 e0 61 80 99 e0  ....a.......a...

[ 2050.631365] mem: ddc866e0: 75 80 99 e0 48 01 00 c1 2b 36 05 c1 00 00 00 00  u...H...+6......

[ 2050.631483] mem: ddc866f0: 4a 0c 00 00 99 ad 06 00 6d 35 05 c1 9e 8b 2a c1  J.......m5....*.

[ 2050.631599] mem: ddc86700: 6d 35 05 c1 48 8c 2a c1 6d 35 05 c1 ee 89 0a c1  m5..H.*.m5......

[ 2050.631716] mem: ddc86710: ee 89 0a c1 e4 0a 14 c1 e4 0a 14 c1 ee 89 0a c1  ................

[ 2050.631832] mem: ddc86720: ee 89 0a c1 6d 35 05 c1 6d 35 05 c1 6d 35 05 c1  ....m5..m5..m5..

[ 2050.631948] mem: ddc86730: a7 39 05 c1 ef b8 2a c1 00 00 00 00 00 00 00 00  .9....*.........

[ 2050.633948] mem: ddc86740: 4a 0c 00 00 97 ad 06 00 5a 5a 5a 5a 5a 5a 5a 5a  J.......ZZZZZZZZ

[ 2050.634095] mem: ddc86750: 14 dc 46 dd 14 dc 46 dd 00 00 00 00 6b 6b 6b 6b  ..F...F.....kkkk

[ 2050.634236] mem: ddc86760: 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b a5  kkkkkkkkkkkkkkk.

[ 2050.634378] mem: ddc86770: cc cc cc cc c0 69 c8 dd a0 83 20 c1 fa 8e 2a c1  .....i.... ...*.

[ 2050.634629] =============================================================================

[ 2050.634750] BUG kmalloc-32 (Tainted: P    B      O): Redzone overwritten

[ 2050.634828] -----------------------------------------------------------------------------

[ 2050.634828]

[ 2050.634967] INFO: 0xddc866a0-0xddc866a3. First byte 0x12 instead of 0xcc

[ 2050.635123] INFO: Allocated in try_to_corrupt_redzone+0x16/0x61 [mymodule] age=1 cpu=0 pid=3146

[ 2050.635255]  alloc_debug_processing+0x63/0xd1

[ 2050.635337]  try_to_corrupt_redzone+0x16/0x61 [mymodule]

[ 2050.635423]  __slab_alloc.constprop.73+0x366/0x384

[ 2050.635506]  try_to_corrupt_redzone+0x16/0x61 [mymodule]

[ 2050.635594]  vt_console_print+0x21e/0x226

[ 2050.635672]  try_to_corrupt_redzone+0x16/0x61 [mymodule]

[ 2050.635758]  kmem_cache_alloc_trace+0x43/0xd7

[ 2050.635832]  kmem_cache_alloc_trace+0x43/0xd7

[ 2050.635909]  mymodule_init+0x0/0x19 [mymodule]

[ 2050.635992]  try_to_corrupt_redzone+0x16/0x61 [mymodule]

[ 2050.636003]  mymodule_init+0x0/0x19 [mymodule]

[ 2050.636092]  try_to_corrupt_redzone+0x16/0x61 [mymodule]

[ 2050.636179]  mymodule_init+0x0/0x19 [mymodule]

[ 2050.636261]  mymodule_init+0x14/0x19 [mymodule]

[ 2050.636343]  do_one_initcall+0x6c/0xf4

[ 2050.636428]  load_module+0x1690/0x199a

[ 2050.636508] INFO: Freed in load_module+0x15d2/0x199a age=3 cpu=0 pid=3146

[ 2050.636598]  free_debug_processing+0xd6/0x142

[ 2050.636676]  load_module+0x15d2/0x199a

[ 2050.636749]  __slab_free+0x3e/0x28d

[ 2050.636819]  load_module+0x15d2/0x199a

[ 2050.636888]  kfree+0xe4/0x102

[ 2050.636953]  kfree+0xe4/0x102

[ 2050.637020]  kobject_uevent_env+0x361/0x39a

[ 2050.637091]  kobject_uevent_env+0x361/0x39a

[ 2050.637163]  kfree+0xe4/0x102

[ 2050.637227]  kfree+0xe4/0x102

[ 2050.637294]  load_module+0x15d2/0x199a

[ 2050.637366]  load_module+0x15d2/0x199a

[ 2050.637438]  load_module+0x15d2/0x199a

[ 2050.637509]  SyS_init_module+0x72/0x8a

[ 2050.637581]  syscall_call+0x7/0xb

[ 2050.637649] INFO: Slab 0xdffa90c0 objects=19 used=8 fp=0xddc86000 flags=0x40000080

[ 2050.637749] INFO: Object 0xddc86680 @offset=1664 fp=0xddc86b60

[ 2050.637749]

[ 2050.637875] Bytes b4 ddc86670: 14 01 00 00 95 ad 06 00 5a 5a 5a 5a 5a 5a 5a 5a  ........ZZZZZZZZ

[ 2050.637875] Object ddc86680: 12 12 12 12 12 12 12 12 12 12 12 12 12 12 12 12  ................

[ 2050.637875] Object ddc86690: 12 12 12 12 12 12 12 12 12 12 12 12 12 12 12 12  ................

[ 2050.637875] Redzone ddc866a0: 12 12 12 12                                      ....

[ 2050.637875] Padding ddc86748: 5a 5a 5a 5a 5a 5a 5a 5a                          ZZZZZZZZ

[ 2050.637875] CPU: 0 PID: 3146 Comm: insmod Tainted: P    B      O 3.10.17 #1

[ 2050.637875] Hardware name: innotek GmbH VirtualBox/VirtualBox, BIOS VirtualBox 12/01/2006

[ 2050.637875]  00000000 c10a7b59 c10941c5 dffa90c0 ddc86680 de8012cc de801280 ddc86680

[ 2050.637875]  dffa90c0 c10a7bd3 c13689a5 ddc866a0 000000cc 00000004 de801280 ddc86680

[ 2050.637875]  dffa90c0 de800e00 c12a8b2f 000000cc ddc86680 de801280 dffa90c0 dd407e50

[ 2050.637875] Call Trace:

[ 2050.637875]  [&ltc10a7b59&gt] ? check_bytes_and_report+0x6d/0xb0

[ 2050.637875]  [&ltc10941c5&gt] ? page_address+0x1a/0x79

[ 2050.637875]  [&ltc10a7bd3&gt] ? check_object+0x37/0x149

[ 2050.637875]  [&ltc12a8b2f&gt] ? free_debug_processing+0x67/0x142

[ 2050.637875]  [&ltc12a8c48&gt] ? __slab_free+0x3e/0x28d

[ 2050.637875]  [&lte0998075&gt] ? mymodule_init+0x14/0x19 [mymodule]

[ 2050.637875]  [&ltc102063d&gt] ? wake_up_klogd+0x1d/0x1e

[ 2050.637875]  [&ltc10a89ee&gt] ? kfree+0xe4/0x102

[ 2050.637875]  [&ltc10a89ee&gt] ? kfree+0xe4/0x102

[ 2050.637875]  [&lte0998075&gt] ? mymodule_init+0x14/0x19 [mymodule]

[ 2050.637875]  [&lte0998075&gt] ? mymodule_init+0x14/0x19 [mymodule]

[ 2050.637875]  [&lte0998061&gt] ? try_to_corrupt_redzone+0x61/0x61 [mymodule]

[ 2050.637875]  [&lte0998075&gt] ? mymodule_init+0x14/0x19 [mymodule]

[ 2050.637875]  [&ltc1000148&gt] ? do_one_initcall+0x6c/0xf4

[ 2050.637875]  [&ltc105362b&gt] ? load_module+0x1690/0x199a

[ 2050.637875]  [&ltc10539a7&gt] ? SyS_init_module+0x72/0x8a

[ 2050.637875]  [&ltc12ab8ef&gt] ? syscall_call+0x7/0xb

[ 2050.637875] FIX kmalloc-32: Restoring 0xddc866a0-0xddc866a3=0xcc

[ 2050.637875]

[ 2051.232817] mymodule_exit exit

First the slub allocator print the error type "redzone overwritten"

[ 2050.634629] =============================================================================

[ 2050.634750] BUG kmalloc-32 (Tainted: P    B      O): Redzone overwritten

[ 2050.634828] -----------------------------------------------------------------------------

[ 2050.634828]

[ 2050.634967] INFO: 0xddc866a0-0xddc866a3. First byte 0x12 instead of 0xcc

To understand what readzone is, take a look at the memory content around the object:

[ 2050.637875] Bytes b4 ddc86670: 14 01 00 00 95 ad 06 00 5a 5a 5a 5a 5a 5a 5a 5a  ........ZZZZZZZZ

[ 2050.637875] Object ddc86680: 12 12 12 12 12 12 12 12 12 12 12 12 12 12 12 12  ................

[ 2050.637875] Object ddc86690: 12 12 12 12 12 12 12 12 12 12 12 12 12 12 12 12  ................

[ 2050.637875] Redzone ddc866a0: 12 12 12 12                                      ....

[ 2050.637875] Padding ddc86748: 5a 5a 5a 5a 5a 5a 5a 5a                          ZZZZZZZZ

We fill 38 bytes of 0x12 from the start of the 36-bytes object (0xddc86680 - 0xddc8669f) and 4 more 0x12 on the redzone (normal 0xbb or 0xcc). When the object is returned to the kernel, kernel finds that the redzone is neither 0xcc or 0xbb and reports this as a BUG.

The slub allocator reports the latest allocate/free history of this object. You can see the object is just allocated by our kernel module function 'try_to_corrup_redzone'.

Sometime the traces of the object are more useful than function backtrace. For example, if there exists an use-after-free case:  function A allocates an object and writes if after freeing the object. If the object is allocated by another function B. In this case, function B has a corrupted object, and if we have the free trace of this object, we can trace back to the previous owner of the object, function A.

[ 2050.635123] INFO: Allocated in try_to_corrupt_redzone+0x16/0x61 [mymodule] age=1 cpu=0 pid=3146

[ 2050.635255]  alloc_debug_processing+0x63/0xd1

[ 2050.635337]  try_to_corrupt_redzone+0x16/0x61 [mymodule]

[ 2050.635423]  __slab_alloc.constprop.73+0x366/0x384

[ 2050.635506]  try_to_corrupt_redzone+0x16/0x61 [mymodule]

[ 2050.635594]  vt_console_print+0x21e/0x226

[ 2050.635672]  try_to_corrupt_redzone+0x16/0x61 [mymodule]

[ 2050.635758]  kmem_cache_alloc_trace+0x43/0xd7

[ 2050.635832]  kmem_cache_alloc_trace+0x43/0xd7

[ 2050.635909]  mymodule_init+0x0/0x19 [mymodule]

[ 2050.635992]  try_to_corrupt_redzone+0x16/0x61 [mymodule]

[ 2050.636003]  mymodule_init+0x0/0x19 [mymodule]

[ 2050.636092]  try_to_corrupt_redzone+0x16/0x61 [mymodule]

[ 2050.636179]  mymodule_init+0x0/0x19 [mymodule]

[ 2050.636261]  mymodule_init+0x14/0x19 [mymodule]

[ 2050.636343]  do_one_initcall+0x6c/0xf4

[ 2050.636428]  load_module+0x1690/0x199a

[ 2050.636508] INFO: Freed in load_module+0x15d2/0x199a age=3 cpu=0 pid=3146

[ 2050.636598]  free_debug_processing+0xd6/0x142

[ 2050.636676]  load_module+0x15d2/0x199a

[ 2050.636749]  __slab_free+0x3e/0x28d

[ 2050.636819]  load_module+0x15d2/0x199a

[ 2050.636888]  kfree+0xe4/0x102

[ 2050.636953]  kfree+0xe4/0x102

[ 2050.637020]  kobject_uevent_env+0x361/0x39a

[ 2050.637091]  kobject_uevent_env+0x361/0x39a

[ 2050.637163]  kfree+0xe4/0x102

[ 2050.637227]  kfree+0xe4/0x102

[ 2050.637294]  load_module+0x15d2/0x199a

[ 2050.637366]  load_module+0x15d2/0x199a

[ 2050.637438]  load_module+0x15d2/0x199a

[ 2050.637509]  SyS_init_module+0x72/0x8a
 
Posted by Miles MH Chen at 7:34 AM 
Labels: linux

最新文章

  1. spring mvc 和spring security配置 spring-servlet.xml和spring-security.xml设置
  2. javascript 中的location.href 并不是立即执行的，是在所在function 执行完之后执行的。
  3. kafka模块概述
  4. [转]五种开源协议的比较(BSD，Apache，GPL，LGPL，MIT)
  5. Java native关键字
  6. Linux线程属性总结
  7. My安装Eclipse三种方法插件
  8. Java面向对象的概念以及OOP思想的优点
  9. 左右推拽显示对比图 - jQyery封装 - 附源文件
  10. [转]UIWebView的Javascript运行时对象
  11. 关于IMP由拥有DBA权限的用户EXP数据时，数据存放表空间的几种情况(IMP-00013) -1
  12. 一个基于JRTPLIB的轻量级RTSP客户端(myRTSPClient)——实现篇：（四）用户接口层之处理SDP报文
  13. Dockerfile构建容器---语法高亮
  14. ActiveMQ的发布者/订阅者模型示例
  15. Codeforces Round #368 (Div. 2) E. Garlands 二维树状数组 暴力
  16. Gson 解析教程
  17. idea中创建多module的maven工程
  18. Mycat常见错误
  19. 【8.23校内测试】【贪心】【线段树优化DP】
  20. MVC4 WebApi开发中如果想支持Session请做好如下几个方面的问题

热门文章

  1. css深入理解padding
  2. [译]如何将docker日志重定向到单个文件里
  3. C++ 虚继承内存分配
  4. 《R语言实战》读书笔记--第三章 图形初阶（二）
  5. Codeforces Round #522 (Div. 2) C. Playing Piano
  6. idea创建maven项目需要注意的问题
  7. Windows2008下RDP采用私有CA服务器证书搭建文档
  8. hdu 4305 概率dp
  9. POJ1163 The Triangle
  10. QT5.3 杂记（转）