2014-06-13 08:15:15

by Jet Chen

[permalink] [raw]
Subject: [idr] WARNING: at lib/idr.c:669 idr_find_slowpath()

Hi Tejun,

0day kernel testing robot got the below dmesg and the first bad commit is

git://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git master
commit 0ffc2a9c8072969253a20821c2c733a2cbb4c7c7
Author: Tejun Heo <[email protected]>
AuthorDate: Wed Feb 27 17:05:08 2013 -0800
Commit: Linus Torvalds <[email protected]>
CommitDate: Wed Feb 27 19:10:21 2013 -0800

idr: implement lookup hint
While idr lookup isn't a particularly heavy operation, it still is too
substantial to use in hot paths without worrying about the performance
implications. With recent changes, each idr_layer covers 256 slots
which should be enough to cover most use cases with single idr_layer
making lookup hint very attractive.
This patch adds idr->hint which points to the idr_layer which
allocated an ID most recently and the fast path lookup becomes
if (look up target's prefix matches that of the hinted layer)
return hint->ary[ID's offset in the leaf layer];
which can be inlined.
idr->hint is set to the leaf node on idr_fill_slot() and cleared from
free_layer().
[[email protected]: always do slow path when hint is uninitialized]
Signed-off-by: Tejun Heo <[email protected]>
Cc: Kirill A. Shutemov <[email protected]>
Cc: Sasha Levin <[email protected]>
Signed-off-by: Andrew Morton <[email protected]>
Signed-off-by: Linus Torvalds <[email protected]>


+--------------------------------------------------------------------------+------------+------------+
| | 54616283c2 | 0ffc2a9c80 |
+--------------------------------------------------------------------------+------------+------------+
| boot_successes | 140 | 31 |
| boot_failures | 320 | 84 |
| BUG:soft_lockup-CPU_stuck_for_s | 128 | 40 |
| EIP_is_at_stop_machine_cpu_stop | 128 | 40 |
| Kernel_panic-not_syncing:softlockup:hung_tasks | 128 | 40 |
| backtrace:smpboot_thread_fn | 128 | 40 |
| BUG:unable_to_handle_kernel_paging_request | 67 | 18 |
| Oops | 40 | 12 |
| EIP_is_at_static_key_slow_inc | 35 | 10 |
| Kernel_panic-not_syncing:Fatal_exception | 39 | 12 |
| backtrace:perf_swevent_init | 37 | 10 |
| backtrace:perf_init_event | 144 | 35 |
| BUG:unable_to_handle_kernel_NULL_pointer_dereference | 2 | |
| EIP_is_at_jump_label_update | 2 | |
| backtrace:static_key_slow_inc | 2 | |
| WARNING:at_lib/idr.c:idr_find() | 119 | |
| EIP_is_at_atomic_dec_and_mutex_lock | 2 | 2 |
| backtrace:idr_find | 111 | |
| WARNING:at_kernel/jump_label.c:__static_key_slow_dec() | 3 | 1 |
| BUG:kernel_test_crashed | 18 | 4 |
| WARNING:at_kernel/lockdep.c:__bfs() | 1 | |
| EIP_is_at__bfs | 1 | |
| WARNING:at_arch/x86/kernel/hw_breakpoint.c:arch_install_hw_breakpoint() | 1 | |
| BUG:sleeping_function_called_from_invalid_context_at_arch/x86/mm/fault.c | 1 | |
| WARNING:at_lib/idr.c:idr_find_slowpath() | 0 | 27 |
| backtrace:idr_find_slowpath | 0 | 26 |
| WARNING:at_drivers/tty/tty_buffer.c:flush_to_ldisc() | 0 | 1 |
| backtrace:flush_to_ldisc | 0 | 1 |
+--------------------------------------------------------------------------+------------+------------+


Kernel tests: Boot OK!
[ 17.603698] sock: process `trinity-main' is using obsolete setsockopt SO_BSDCOMPAT
[ 17.798944] ------------[ cut here ]------------
[ 17.798972] WARNING: at lib/idr.c:669 idr_find_slowpath+0x28/0xca()
[ 17.798973] Hardware name: Bochs
[ 17.798976] Pid: 655, comm: trinity-main Not tainted 3.8.0-06482-g0ffc2a9 #68
[ 17.798976] Call Trace:
[ 17.798989] [<c022ace6>] warn_slowpath_common+0x72/0x89
[ 17.798992] [<c051f001>] ? idr_find_slowpath+0x28/0xca
[ 17.798994] [<c051f001>] ? idr_find_slowpath+0x28/0xca
[ 17.798997] [<c022ad9b>] warn_slowpath_null+0x1d/0x1f
[ 17.798999] [<c051f001>] idr_find_slowpath+0x28/0xca
[ 17.799007] [<c027fab7>] perf_init_event+0x82/0x124
[ 17.799013] [<c024321f>] ? __mutex_init+0x3f/0x44
[ 17.799015] [<c027fda9>] perf_event_alloc+0x250/0x360
[ 17.799018] [<c028040e>] sys_perf_event_open+0x336/0x664
[ 17.799036] [<c0944280>] syscall_call+0x7/0xb
[ 17.799042] [<c0940000>] ? SetAgcIf.isra.6+0x156/0x290
[ 17.799043] ---[ end trace 8e00e88be2b81021 ]---
[ 76.161086] Unregister pv shared memory for cpu 0


Attached dmesg for the parent commit, too, to help confirm whether it is a noise error.

git bisect start 6dbe51c251a327e012439c4772097a13df43c5b8 v3.8 --
git bisect good d414c104e26fd3b597f855cc29473a8b1527fb4c # 02:41 35+ 35 Merge tag 'please-pull-vm_unwrapped' of git://git.kernel.org/pub/scm/linux/kernel/git/aegl/linux
git bisect bad ee89f81252179dcbf6cd65bd48299f5e52292d88 # 02:46 10- 14 Merge branch 'for-3.9/core' of git://git.kernel.dk/linux-block
git bisect good a6590b9f01dca2d45a38b8387f59812c44f68a2f # 03:05 40+ 40 Merge tag 'upstream-3.9-rc1' of git://git.infradead.org/linux-ubifs
git bisect good 09884964335e85e897876d17783c2ad33cf8a2e0 # 03:13 40+ 40 mm: do not grow the stack vma just because of an overrun on preceding vma
git bisect good ad60a9333035f2323840b71ab8ad07bbab728faf # 03:29 40+ 17 Merge branch 'misc' of git://git.kernel.org/pub/scm/linux/kernel/git/mmarek/kbuild
git bisect good e3c4877de8b9d93bd47b6ee88eb594b1c1e10da5 # 04:16 40+ 15 Merge branch 'x86-efi-for-linus' of git://git.kernel.org/pub/scm/linux/kernel/git/tip/tip
git bisect bad 2a7d2b96d5cba7568139d9ab157a0e97ab32440f # 04:29 1- 3 Merge branch 'akpm' (final batch from Andrew)
git bisect good 6fa780095f058f0960f220754217701a53a9e403 # 05:44 40+ 19 IB/cxgb3: convert to idr_alloc()
git bisect good 050a6b47d98e2bcea909c1129111e721668aaa2c # 06:06 40+ 36 idr: make idr_layer larger
git bisect bad 459a86d83dce6641f66311d37fbfe1419c477a5a # 06:28 19- 21 mtd: mtd_nandecctest: use prandom_bytes instead of get_random_bytes()
git bisect bad 06004e6eebdaf101a0f9b533fac77b5768d2c09c # 06:40 5- 6 block/partitions/mac.c: obey the state->limit constraint
git bisect bad d941aeae42942c2ef61ed5e05cc1ad0428085704 # 06:52 0- 1 ipmi: add new kernel options to prevent automatic ipmi init
git bisect bad 0ffc2a9c8072969253a20821c2c733a2cbb4c7c7 # 07:00 9- 10 idr: implement lookup hint
git bisect good 54616283c2948812a44240858ced610e7cacbde1 # 07:06 115+ 73 idr: add idr_layer->prefix
# first bad commit: [0ffc2a9c8072969253a20821c2c733a2cbb4c7c7] idr: implement lookup hint
git bisect good 54616283c2948812a44240858ced610e7cacbde1 # 07:15 345+ 320 idr: add idr_layer->prefix
git bisect good d67a0e110187abd560a1de63fa172894a52839d5 # 07:30 345+ 11 morphologies: Enable CONFIG_FHANDLE
git bisect good 0e04c641b199435f3779454055f6a7de258ecdfc # 07:45 345+ 22 Merge tag 'dm-3.16-changes' of git://git.kernel.org/pub/scm/linux/kernel/git/device-mapper/linux-dm
git bisect good b1cce620fd4b6864c92e7307be7839789f9c8be0 # 08:03 345+ 18 Add linux-next specific files for 20140612


This script may reproduce the error.

-----------------------------------------------------------------------------
#!/bin/bash

kernel=$1
initrd=yocto-minimal-i386.cgz

wget --no-clobber https://github.com/fengguang/reproduce-kernel-bug/blob/master/initrd/$initrd

kvm=(
qemu-system-x86_64 -cpu kvm64 -enable-kvm
-kernel $kernel
-initrd $initrd
-smp 2
-m 256M
-net nic,vlan=0,macaddr=00:00:00:00:00:00,model=virtio
-net user,vlan=0
-net nic,vlan=1,model=e1000
-net user,vlan=1
-boot order=nc
-no-reboot
-watchdog i6300esb
-serial stdio
-display none
-monitor null
)

append=(
debug
sched_debug
apic=debug
ignore_loglevel
sysrq_always_enabled
panic=10
prompt_ramdisk=0
earlyprintk=ttyS0,115200
console=ttyS0,115200
console=tty0
vga=normal
root=/dev/ram0
rw
)

"${kvm[@]}" --append "${append[*]}"
-----------------------------------------------------------------------------

Thanks,
Jet


Attachments:
dmesg-yocto-ivb41-19:20140613070119:i386-randconfig-ha3-0612:3.8.0-06482-g0ffc2a9:68 (60.42 kB)
dmesg-quantal-ivb41-100:20140613071446:i386-randconfig-ha3-0612:3.8.0-06481-g5461628:69 (30.57 kB)
i386-randconfig-ha3-0612-6dbe51c251a327e012439c4772097a13df43c5b8-WARNING:---at----idr_find_slowpath+-x-109888.log (39.62 kB)
config-3.8.0-06482-g0ffc2a9 (77.21 kB)
Attached Message Part (86.00 B)
Download all attachments

2014-06-17 19:09:00

by Tejun Heo

[permalink] [raw]
Subject: Re: [idr] WARNING: at lib/idr.c:669 idr_find_slowpath()

On Fri, Jun 13, 2014 at 04:14:44PM +0800, Jet Chen wrote:
> Hi Tejun,
>
> 0day kernel testing robot got the below dmesg and the first bad commit is
>
> git://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git master
> commit 0ffc2a9c8072969253a20821c2c733a2cbb4c7c7
> Author: Tejun Heo <[email protected]>
> AuthorDate: Wed Feb 27 17:05:08 2013 -0800
> Commit: Linus Torvalds <[email protected]>
> CommitDate: Wed Feb 27 19:10:21 2013 -0800
>
> idr: implement lookup hint
...
> [ 17.603698] sock: process `trinity-main' is using obsolete setsockopt SO_BSDCOMPAT
> [ 17.798944] ------------[ cut here ]------------
> [ 17.798972] WARNING: at lib/idr.c:669 idr_find_slowpath+0x28/0xca()
> [ 17.798973] Hardware name: Bochs
> [ 17.798976] Pid: 655, comm: trinity-main Not tainted 3.8.0-06482-g0ffc2a9 #68
> [ 17.798976] Call Trace:
> [ 17.798989] [<c022ace6>] warn_slowpath_common+0x72/0x89
> [ 17.798992] [<c051f001>] ? idr_find_slowpath+0x28/0xca
> [ 17.798994] [<c051f001>] ? idr_find_slowpath+0x28/0xca
> [ 17.798997] [<c022ad9b>] warn_slowpath_null+0x1d/0x1f
> [ 17.798999] [<c051f001>] idr_find_slowpath+0x28/0xca
> [ 17.799007] [<c027fab7>] perf_init_event+0x82/0x124
> [ 17.799013] [<c024321f>] ? __mutex_init+0x3f/0x44
> [ 17.799015] [<c027fda9>] perf_event_alloc+0x250/0x360
> [ 17.799018] [<c028040e>] sys_perf_event_open+0x336/0x664
> [ 17.799036] [<c0944280>] syscall_call+0x7/0xb
> [ 17.799042] [<c0940000>] ? SetAgcIf.isra.6+0x156/0x290
> [ 17.799043] ---[ end trace 8e00e88be2b81021 ]---
> [ 76.161086] Unregister pv shared memory for cpu 0

This is perf_init_event() invoking idr_find() with negative ID
triggering the warning. The warning was removed quite some time ago.

Thanks.

--
tejun