Date:   Tue, 24 Oct 2017 09:12:54 +0800
From:   kernel test robot <xiaolong.ye@...el.com>
To:     "Tobin C. Harding" <me@...in.cc>
Cc:     linux-kernel@...r.kernel.org, lkp@...org
Subject: [lkp-robot] [printk]  7d827b898c: BUG:KASAN:slab-out-of-bounds


FYI, we noticed the following commit (built with gcc-4.9):

commit: 7d827b898c4556a2266e69ba9c6606e7b7342c71 ("printk: hash addresses printed with %p")
url: https://github.com/0day-ci/linux/commits/Tobin-C-Harding/printk-hash-addresses-printed-with-p/20171023-083947


in testcase: trinity
with following parameters:

	runtime: 300s

test-description: Trinity is a linux system call fuzz tester.
test-url: http://codemonkey.org.uk/projects/trinity/


on test machine: qemu-system-x86_64 -enable-kvm -m 420M

caused below changes (please refer to attached dmesg/kmsg for entire log/backtrace):


+------------------------------------------------+------------+------------+
|                                                | 02982f8550 | 7d827b898c |
+------------------------------------------------+------------+------------+
| boot_successes                                 | 12         | 0          |
| boot_failures                                  | 44         | 14         |
| BUG:soft_lockup-CPU##stuck_for#s               | 44         |            |
| Kernel_panic-not_syncing:softlockup:hung_tasks | 44         |            |
| BUG:KASAN:slab-out-of-bounds                   | 0          | 14         |
+------------------------------------------------+------------+------------+



[   29.926664] BUG: KASAN: slab-out-of-bounds in __test+0x163/0x1e2
[   29.928002] Read of size 34 at addr f00af726 by task swapper/0/1
[   29.929317] 
[   29.930024] CPU: 0 PID: 1 Comm: swapper/0 Not tainted 4.14.0-rc5-00299-g7d827b8 #1
[   29.930024] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.10.2-1 04/01/2014
[   29.930024] Call Trace:
[   29.930024]  dump_stack+0x133/0x1c1
[   29.930024]  print_address_description+0xb5/0x39c
[   29.930024]  kasan_report+0x313/0x33f
[   29.930024]  ? __test+0x163/0x1e2
[   29.930024]  check_memory_region+0x2d/0x13e
[   29.930024]  __asan_loadN+0xf/0x11
[   29.930024]  __test+0x163/0x1e2
[   29.930024]  test_printf_init+0x404/0xcb5
[   29.930024]  ? __asan_loadN+0xf/0x11
[   29.930024]  ? ftrace_likely_update+0x90/0xae
[   29.930024]  ? __test+0x1e2/0x1e2
[   29.930024]  do_one_initcall+0xfb/0x268
[   29.930024]  kernel_init_freeable+0x1b0/0x2bb
[   29.930024]  ? rest_init+0x14f/0x14f
[   29.930024]  kernel_init+0x13/0x22e
[   29.930024]  ? rest_init+0x14f/0x14f
[   29.930024]  ret_from_fork+0x2a/0x40
[   29.930024] 
[   29.930024] Allocated by task 1:
[   29.930024]  save_stack_trace+0x1b/0x1d
[   29.930024]  kasan_kmalloc+0x65/0xf1
[   29.930024]  kasan_kmalloc+0x81/0x8d
[   29.930024]  kasan_slab_alloc+0x12/0x14
[   29.930024]  __kmalloc_track_caller+0x2ff/0x4b4
[   29.930024]  kvasprintf+0x4f/0x12c
[   29.930024]  __test+0x113/0x1e2
[   29.930024]  test_printf_init+0x404/0xcb5
[   29.930024]  do_one_initcall+0xfb/0x268
[   29.930024]  kernel_init_freeable+0x1b0/0x2bb
[   29.930024]  kernel_init+0x13/0x22e
[   29.930024]  ret_from_fork+0x2a/0x40
[   29.930024] 
[   29.930024] Freed by task 1:
[   29.930024]  save_stack_trace+0x1b/0x1d
[   29.930024]  kasan_slab_free+0xb0/0x15a
[   29.930024]  kfree+0x3b0/0x50e
[   29.930024]  unpack_to_rootfs+0x470/0x4c6
[   29.930024]  populate_rootfs+0xfe/0x32c
[   29.930024]  do_one_initcall+0xfb/0x268
[   29.930024]  kernel_init_freeable+0x1b0/0x2bb
[   29.930024]  kernel_init+0x13/0x22e
[   29.930024]  ret_from_fork+0x2a/0x40
[   29.930024] 
[   29.930024] The buggy address belongs to the object at f00af726
[   29.930024]  which belongs to the cache kmalloc-32 of size 32
[   29.930024] The buggy address is located 0 bytes inside of
[   29.930024]  32-byte region [f00af726, 9dd2448f)
[   29.930024] The buggy address belongs to the page:
[   29.930024] page:bdfe52f7 count:1 mapcount:0 mapping:          (null) index:0xffff880011c9aa88
[   29.930024] flags: 0x1fffc0000000100(slab)
[   29.930024] raw: 01fffc0000000100 0000000000000000 ffff880011c9aa88 00000001000a0001
[   29.930024] raw: ffffea0000471320 ffff880014801b80 ffff8800148025c0 0000000000000000
[   29.930024] page dumped because: kasan: bad access detected
[   29.930024] 
[   29.930024] Memory state around the buggy address:
[   29.930024]  389611ab: fc fc fc fc fc fc fc fc fc fc fc fc fc fc fc fc
[   29.930024]  adfc03dc: fc fc fc fc fc fc fc fc fc fc fc fc fc fc fc fc
[   29.930024] > e2a2229: fc 00 00 00 00 fc fc fc fc fc fc fc fc fc fc fc
[   29.930024]                                   ^
[   29.930024]  df2336db: fc fc fc fc fc fc fc fc fc fc fc fc fc fc fc fc
[   29.930024]  aa8be421: fc fc fc fc fc fc fc fc fc fc fc fc fc fc fc fc
[   29.930024] ==================================================================
[   29.930024] Disabling lock debugging due to kernel taint
[   29.990099] test_printf: kvasprintf(..., "%p %p", ...) returned ' 558210a 45d5062a', expected '0000000001234567 fffffffffedcba98'
[   29.992729] test_printf: vsnprintf(buf, 256, "|%-*p|%*p|", ...) returned 19, expected 39
[   29.994731] test_printf: vsnprintf(buf, 26, "|%-*p|%*p|", ...) returned 19, expected 39
[   29.996710] test_printf: vsnprintf(buf, 0, "|%-*p|%*p|", ...) returned 19, expected 39
[   29.998722] test_printf: kvasprintf(..., "|%-*p|%*p|", ...) returned '| 558210a| 558210a|', expected '|1234567           |           1234567|'
[   30.001381] test_printf: vsnprintf(buf, 256, "|%-*p|%*p|", ...) returned 19, expected 39
[   30.003364] test_printf: vsnprintf(buf, 35, "|%-*p|%*p|", ...) returned 19, expected 39
[   30.005326] test_printf: vsnprintf(buf, 0, "|%-*p|%*p|", ...) returned 19, expected 39
[   30.007318] test_printf: kvasprintf(..., "|%-*p|%*p|", ...) returned '|45d5062a|45d5062a|', expected '|fffffffffedcba98  |  fffffffffedcba98|'
[   30.009938] test_printf: vsnprintf(buf, 256, "|%p0y|", ...) returned 10, expected 18
[   30.011921] test_printf: vsnprintf(buf, 3, "|%p0y|", ...) returned 10, expected 18
[   30.013828] test_printf: vsnprintf(buf, 0, "|%p0y|", ...) returned 10, expected 18
[   30.015776] test_printf: kvasprintf(..., "|%p0y|", ...) returned '| 558210a|', expected '|0000000001234567|'
[   30.018001] test_printf: vsnprintf(buf, 256, "|%p0y|", ...) returned 10, expected 18
[   30.019935] test_printf: vsnprintf(buf, 7, "|%p0y|", ...) returned 10, expected 18
[   30.021906] test_printf: vsnprintf(buf, 0, "|%p0y|", ...) returned 10, expected 18
[   30.023888] test_printf: kvasprintf(..., "|%p0y|", ...) returned '|45d5062a|', expected '|fffffffffedcba98|'
[   30.028265] test_printf: failed 20 out of 260 tests
[   30.029458] test_uuid: all 18 tests passed
[   30.033620] crc32: CRC_LE_BITS = 32, CRC_BE BITS = 32
[   30.034811] crc32: self tests passed, processed 225944 bytes in 1480295 nsec
[   30.037737] crc32c: CRC_LE_BITS = 32
[   30.038738] crc32c: self tests passed, processed 225944 bytes in 736782 nsec
[   30.106872] crc32_combine: 8373 self tests passed
[   30.151886] crc32c_combine: 8373 self tests passed
[   30.153316] xz_dec_test: module loaded
[   30.153910] xz_dec_test: Create a device node with 'mknod xz_dec_test c 248 0' and write .xz files to it.
[   30.155237] atomic64_test: passed for x86-64 platform with CX8 and with SSE
[   30.156105] glob: 64 self-tests passed, 0 failed

Elapsed time: 30



To reproduce:

        git clone https://github.com/intel/lkp-tests.git
        cd lkp-tests
        bin/lkp qemu -k <bzImage> job-script  # job-script is attached in this email



Thanks,
Xiaolong

View attachment "config-4.14.0-rc5-00299-g7d827b8" of type "text/plain" (106914 bytes)

View attachment "job-script" of type "text/plain" (3703 bytes)

Download attachment "dmesg.xz" of type "application/x-xz" (9444 bytes)

Powered by blists - more mailing lists