Hello,
FYI this happens in mainline kernel 4.17.0-rc1.
It at least dates back to v4.1 .
[ 7.767898] test if its possible to exceed max_size 8192: no, ok
[ 7.768365] Average test time: 234002708
[ 7.768638] test inserting duplicates
[ 7.768907]
[ 7.769018] =============================
[ 7.769297] WARNING: suspicious RCU usage
[ 7.769576] 4.17.0-rc1 #46 Not tainted
[ 7.769836] -----------------------------
[ 7.770129] lib/test_rhashtable.c:502 suspicious rcu_dereference_protected() usage!
[ 7.770752]
[ 7.770752] other info that might help us debug this:
[ 7.770752]
[ 7.771298]
[ 7.771298] rcu_scheduler_active = 2, debug_locks = 1
[ 7.771743] no locks held by swapper/1.
[ 7.772011]
[ 7.772011] stack backtrace:
[ 7.772319] CPU: 0 PID: 1 Comm: swapper Not tainted 4.17.0-rc1 #46
[ 7.772739] Call Trace:
[ 7.772925] ? print_ht+0x66/0x25c:
print_ht at lib/test_rhashtable.c:502 (discriminator 7)
[ 7.773167] ? test_insert_dup+0x565/0x5d7:
test_insert_dup at lib/test_rhashtable.c:570
[ 7.773462] ? my_hashfn+0x10/0x10:
my_cmpfn at lib/test_rhashtable.c:94
[ 7.773706] ? kstrtoll_from_user+0x69/0x69:
jhash at include/linux/jhash.h:76
[ 7.773999] ? jhash+0x125/0x125:
jhash2 at include/linux/jhash.h:121
(inlined by) rhashtable_jhash2 at lib/rhashtable.c:932
jhash+0x125/0x125:
my_hashfn at lib/test_rhashtable.c:86
[ 7.774224] ? my_hashfn+0x10/0x10:
my_cmpfn at lib/test_rhashtable.c:94
[ 7.774462] ? rhashtable_rehash_alloc+0x63/0x63:
rht_deferred_worker at lib/rhashtable.c:413
[ 7.774780] ? test_rht_init+0x2ae/0x561:
test_insert_duplicates_run at lib/test_rhashtable.c:593 (discriminator 260)
(inlined by) test_rht_init at lib/test_rhashtable.c:748 (discriminator 260)
[ 7.775060] ? test_rhashtable+0x634/0x634
[ 7.775413] ? do_one_initcall+0x66/0x14f:
do_trace_initcall_finish at init/main.c:867
(inlined by) do_one_initcall at init/main.c:884
[ 7.775691] ? do_early_param+0x70/0x70:
repair_env_string at init/main.c:251
[ 7.775980] ? kernel_init_freeable+0xd6/0x173:
do_initcall_level at init/main.c:950
(inlined by) do_initcalls at init/main.c:959
(inlined by) do_basic_setup at init/main.c:977
(inlined by) kernel_init_freeable at init/main.c:1127
[ 7.776287] ? kernel_init_freeable+0xec/0x173:
do_initcall_level at init/main.c:950
(inlined by) do_initcalls at init/main.c:959
(inlined by) do_basic_setup at init/main.c:977
(inlined by) kernel_init_freeable at init/main.c:1127
[ 7.776595] ? rest_init+0x107/0x107:
kernel_init at init/main.c:1053
[ 7.776853] ? kernel_init+0x5/0xc7:
kernel_init at init/main.c:1055
[ 7.777104] ? ret_from_fork+0x2e/0x38:
ret_from_fork at arch/x86/entry/entry_32.S:311
[ 7.777364]
[ 7.777474] =============================
[ 7.777750] WARNING: suspicious RCU usage
[ 7.778031] 4.17.0-rc1 #46 Not tainted
[ 7.778290] -----------------------------
[ 7.778566] lib/test_rhashtable.c:507 suspicious rcu_dereference_protected() usage!
[ 7.779191]
[ 7.779191] other info that might help us debug this:
[ 7.779191]
[ 7.779732]
[ 7.779732] rcu_scheduler_active = 2, debug_locks = 1
[ 7.780190] no locks held by swapper/1.
[ 7.780456]
[ 7.780456] stack backtrace:
[ 7.780756] CPU: 0 PID: 1 Comm: swapper Not tainted 4.17.0-rc1 #46
[ 7.781179] Call Trace:
[ 7.781355] ? print_ht+0xb2/0x25c:
print_ht at lib/test_rhashtable.c:507 (discriminator 7)
[ 7.781595] ? test_insert_dup+0x565/0x5d7:
test_insert_dup at lib/test_rhashtable.c:570
[ 7.781878] ? my_hashfn+0x10/0x10:
my_cmpfn at lib/test_rhashtable.c:94
[ 7.782120] ? kstrtoll_from_user+0x69/0x69:
jhash at include/linux/jhash.h:76
[ 7.782409] ? jhash+0x125/0x125:
jhash2 at include/linux/jhash.h:121
(inlined by) rhashtable_jhash2 at lib/rhashtable.c:932
jhash+0x125/0x125:
my_hashfn at lib/test_rhashtable.c:86
[ 7.782633] ? my_hashfn+0x10/0x10:
my_cmpfn at lib/test_rhashtable.c:94
[ 7.782871] ? rhashtable_rehash_alloc+0x63/0x63:
rht_deferred_worker at lib/rhashtable.c:413
[ 7.783192] ? test_rht_init+0x2ae/0x561:
test_insert_duplicates_run at lib/test_rhashtable.c:593 (discriminator 260)
(inlined by) test_rht_init at lib/test_rhashtable.c:748 (discriminator 260)
[ 7.783472] ? test_rhashtable+0x634/0x634
[ 7.783824] ? do_one_initcall+0x66/0x14f:
do_trace_initcall_finish at init/main.c:867
(inlined by) do_one_initcall at init/main.c:884
[ 7.784105] ? do_early_param+0x70/0x70:
repair_env_string at init/main.c:251
[ 7.784371] ? kernel_init_freeable+0xd6/0x173:
do_initcall_level at init/main.c:950
(inlined by) do_initcalls at init/main.c:959
(inlined by) do_basic_setup at init/main.c:977
(inlined by) kernel_init_freeable at init/main.c:1127
[ 7.784677] ? kernel_init_freeable+0xec/0x173:
do_initcall_level at init/main.c:950
(inlined by) do_initcalls at init/main.c:959
(inlined by) do_basic_setup at init/main.c:977
(inlined by) kernel_init_freeable at init/main.c:1127
[ 7.784988] ? rest_init+0x107/0x107:
kernel_init at init/main.c:1053
[ 7.785237] ? kernel_init+0x5/0xc7:
kernel_init at init/main.c:1055
[ 7.785480] ? ret_from_fork+0x2e/0x38:
ret_from_fork at arch/x86/entry/entry_32.S:311
[ 7.785739]
[ 7.785849] =============================
[ 7.786129] WARNING: suspicious RCU usage
[ 7.786406] 4.17.0-rc1 #46 Not tainted
[ 7.786664] -----------------------------
[ 7.786950] lib/test_rhashtable.c:508 suspicious rcu_dereference_protected() usage!
[ 7.787570]
[ 7.787570] other info that might help us debug this:
[ 7.787570]
[ 7.788114]
[ 7.788114] rcu_scheduler_active = 2, debug_locks = 1
[ 7.788555] no locks held by swapper/1.
[ 7.788820]
[ 7.788820] stack backtrace:
[ 7.789126] CPU: 0 PID: 1 Comm: swapper Not tainted 4.17.0-rc1 #46
[ 7.789544] Call Trace:
[ 7.789718] ? print_ht+0xfa/0x25c:
print_ht at lib/test_rhashtable.c:508 (discriminator 9)
[ 7.789962] ? test_insert_dup+0x565/0x5d7:
test_insert_dup at lib/test_rhashtable.c:570
[ 7.790250] ? my_hashfn+0x10/0x10:
my_cmpfn at lib/test_rhashtable.c:94
[ 7.790494] ? kstrtoll_from_user+0x69/0x69:
jhash at include/linux/jhash.h:76
[ 7.790781] ? jhash+0x125/0x125:
jhash2 at include/linux/jhash.h:121
(inlined by) rhashtable_jhash2 at lib/rhashtable.c:932
jhash+0x125/0x125:
my_hashfn at lib/test_rhashtable.c:86
[ 7.791008] ? my_hashfn+0x10/0x10:
my_cmpfn at lib/test_rhashtable.c:94
[ 7.791245] ? rhashtable_rehash_alloc+0x63/0x63:
rht_deferred_worker at lib/rhashtable.c:413
[ 7.791568] ? test_rht_init+0x2ae/0x561:
test_insert_duplicates_run at lib/test_rhashtable.c:593 (discriminator 260)
(inlined by) test_rht_init at lib/test_rhashtable.c:748 (discriminator 260)
[ 7.791839] ? test_rhashtable+0x634/0x634
[ 7.792196] ? do_one_initcall+0x66/0x14f:
do_trace_initcall_finish at init/main.c:867
(inlined by) do_one_initcall at init/main.c:884
[ 7.792472] ? do_early_param+0x70/0x70:
repair_env_string at init/main.c:251
[ 7.792736] ? kernel_init_freeable+0xd6/0x173:
do_initcall_level at init/main.c:950
(inlined by) do_initcalls at init/main.c:959
(inlined by) do_basic_setup at init/main.c:977
(inlined by) kernel_init_freeable at init/main.c:1127
[ 7.793045] ? kernel_init_freeable+0xec/0x173:
do_initcall_level at init/main.c:950
(inlined by) do_initcalls at init/main.c:959
(inlined by) do_basic_setup at init/main.c:977
(inlined by) kernel_init_freeable at init/main.c:1127
[ 7.793359] ? rest_init+0x107/0x107:
kernel_init at init/main.c:1053
[ 7.793608] ? kernel_init+0x5/0xc7:
kernel_init at init/main.c:1055
[ 7.793851] ? ret_from_fork+0x2e/0x38:
ret_from_fork at arch/x86/entry/entry_32.S:311
[ 7.794115]
[ 7.794225] =============================
[ 7.794502] WARNING: suspicious RCU usage
[ 7.794779] 4.17.0-rc1 #46 Not tainted
[ 7.795043] -----------------------------
[ 7.795320] lib/test_rhashtable.c:519 suspicious rcu_dereference_protected() usage!
[ 7.795944]
[ 7.795944] other info that might help us debug this:
[ 7.795944]
[ 7.796487]
[ 7.796487] rcu_scheduler_active = 2, debug_locks = 1
[ 7.796942] no locks held by swapper/1.
[ 7.797208]
[ 7.797208] stack backtrace:
[ 7.797509] CPU: 0 PID: 1 Comm: swapper Not tainted 4.17.0-rc1 #46
[ 7.797934] Call Trace:
[ 7.798109] ? print_ht+0x164/0x25c:
rht_obj at include/linux/rhashtable.h:234 (discriminator 7)
(inlined by) print_ht at lib/test_rhashtable.c:520 (discriminator 7)
[ 7.798356] ? test_insert_dup+0x565/0x5d7:
test_insert_dup at lib/test_rhashtable.c:570
[ 7.798639] ? my_hashfn+0x10/0x10:
my_cmpfn at lib/test_rhashtable.c:94
[ 7.798878] ? kstrtoll_from_user+0x69/0x69:
jhash at include/linux/jhash.h:76
[ 7.799176] ? jhash+0x125/0x125:
jhash2 at include/linux/jhash.h:121
(inlined by) rhashtable_jhash2 at lib/rhashtable.c:932
jhash+0x125/0x125:
my_hashfn at lib/test_rhashtable.c:86
[ 7.799402] ? my_hashfn+0x10/0x10:
my_cmpfn at lib/test_rhashtable.c:94
[ 7.799641] ? rhashtable_rehash_alloc+0x63/0x63:
rht_deferred_worker at lib/rhashtable.c:413
[ 7.799963] ? test_rht_init+0x2ae/0x561:
test_insert_duplicates_run at lib/test_rhashtable.c:593 (discriminator 260)
(inlined by) test_rht_init at lib/test_rhashtable.c:748 (discriminator 260)
[ 7.800248] ? test_rhashtable+0x634/0x634
[ 7.800601] ? do_one_initcall+0x66/0x14f:
do_trace_initcall_finish at init/main.c:867
(inlined by) do_one_initcall at init/main.c:884
[ 7.800878] ? do_early_param+0x70/0x70:
repair_env_string at init/main.c:251
[ 7.801147] ? kernel_init_freeable+0xd6/0x173:
do_initcall_level at init/main.c:950
(inlined by) do_initcalls at init/main.c:959
(inlined by) do_basic_setup at init/main.c:977
(inlined by) kernel_init_freeable at init/main.c:1127
[ 7.801452] ? kernel_init_freeable+0xec/0x173:
do_initcall_level at init/main.c:950
(inlined by) do_initcalls at init/main.c:959
(inlined by) do_basic_setup at init/main.c:977
(inlined by) kernel_init_freeable at init/main.c:1127
[ 7.801758] ? rest_init+0x107/0x107:
kernel_init at init/main.c:1053
[ 7.802010] ? kernel_init+0x5/0xc7:
kernel_init at init/main.c:1055
[ 7.802254] ? ret_from_fork+0x2e/0x38:
ret_from_fork at arch/x86/entry/entry_32.S:311
[ 7.802515]
[ 7.802625] =============================
[ 7.802904] WARNING: suspicious RCU usage
[ 7.803181] 4.17.0-rc1 #46 Not tainted
[ 7.803448] -----------------------------
[ 7.803725] lib/test_rhashtable.c:529 suspicious rcu_dereference_protected() usage!
[ 7.804349]
[ 7.804349] other info that might help us debug this:
[ 7.804349]
[ 7.804892]
[ 7.804892] rcu_scheduler_active = 2, debug_locks = 1
[ 7.805336] no locks held by swapper/1.
[ 7.805601]
[ 7.805601] stack backtrace:
[ 7.805904] CPU: 0 PID: 1 Comm: swapper Not tainted 4.17.0-rc1 #46
[ 7.806324] Call Trace:
[ 7.806499] ? print_ht+0x1e1/0x25c:
print_ht at lib/test_rhashtable.c:529 (discriminator 9)
[ 7.806753] ? test_insert_dup+0x565/0x5d7:
test_insert_dup at lib/test_rhashtable.c:570
[ 7.807040] ? my_hashfn+0x10/0x10:
my_cmpfn at lib/test_rhashtable.c:94
[ 7.807278] ? kstrtoll_from_user+0x69/0x69:
jhash at include/linux/jhash.h:76
[ 7.807567] ? jhash+0x125/0x125:
jhash2 at include/linux/jhash.h:121
(inlined by) rhashtable_jhash2 at lib/rhashtable.c:932
jhash+0x125/0x125:
my_hashfn at lib/test_rhashtable.c:86
[ 7.807792] ? my_hashfn+0x10/0x10:
my_cmpfn at lib/test_rhashtable.c:94
[ 7.808033] ? rhashtable_rehash_alloc+0x63/0x63:
rht_deferred_worker at lib/rhashtable.c:413
[ 7.808352] ? test_rht_init+0x2ae/0x561:
test_insert_duplicates_run at lib/test_rhashtable.c:593 (discriminator 260)
(inlined by) test_rht_init at lib/test_rhashtable.c:748 (discriminator 260)
[ 7.808625] ? test_rhashtable+0x634/0x634
[ 7.808983] ? do_one_initcall+0x66/0x14f:
do_trace_initcall_finish at init/main.c:867
(inlined by) do_one_initcall at init/main.c:884
[ 7.809260] ? do_early_param+0x70/0x70:
repair_env_string at init/main.c:251
[ 7.809525] ? kernel_init_freeable+0xd6/0x173:
do_initcall_level at init/main.c:950
(inlined by) do_initcalls at init/main.c:959
(inlined by) do_basic_setup at init/main.c:977
(inlined by) kernel_init_freeable at init/main.c:1127
[ 7.809831] ? kernel_init_freeable+0xec/0x173:
do_initcall_level at init/main.c:950
(inlined by) do_initcalls at init/main.c:959
(inlined by) do_basic_setup at init/main.c:977
(inlined by) kernel_init_freeable at init/main.c:1127
[ 7.810149] ? rest_init+0x107/0x107:
kernel_init at init/main.c:1053
[ 7.810399] ? kernel_init+0x5/0xc7:
kernel_init at init/main.c:1055
[ 7.810642] ? ret_from_fork+0x2e/0x38:
ret_from_fork at arch/x86/entry/entry_32.S:311
[ 7.810913]
[ 7.810913] ---- ht: ----
[ 7.810913] bucket[1] -> [[ val 1 (tid=0) ]] -> [[ val 21 (tid=1) ]]
[ 7.810913] -------------
[ 7.813358]
Attached the full dmesg, kconfig and reproduce scripts.
Thanks,
Fengguang
Hello,
FYI this happens in mainline kernel 4.17.0-rc1.
It at least dates back to v4.16 .
It occurs in 2 out of 2 boots.
[ 121.028717] Duration of test: 9447209905 ns
[ 122.205613] test if its possible to exceed max_size 8192: no, ok
[ 122.256212] Average test time: 10330673927
[ 122.258500] test inserting duplicates
[ 122.260166] ODEBUG: object is on stack, but not annotated
[ 122.261095] WARNING: CPU: 0 PID: 1 at lib/debugobjects.c:366 __debug_object_init+0x273/0x320:
debug_object_is_on_stack at include/linux/sched/task_stack.h:85
(inlined by) __debug_object_init at lib/debugobjects.c:392
[ 122.261095] CPU: 0 PID: 1 Comm: swapper Tainted: G T 4.17.0-rc1 #9
[ 122.261095] EIP: __debug_object_init+0x273/0x320:
debug_object_is_on_stack at include/linux/sched/task_stack.h:85
(inlined by) __debug_object_init at lib/debugobjects.c:392
[ 122.261095] EFLAGS: 00200002 CPU: 0
[ 122.261095] EAX: 41e68f0e EBX: 4011bd60 ECX: 00000001 EDX: 9810de96
[ 122.261095] ESI: 41fa8e40 EDI: 5701e6a8 EBP: 4011bcdc ESP: 4011bcb8
[ 122.261095] DS: 007b ES: 007b FS: 0000 GS: 00e0 SS: 0068
[ 122.261095] CR0: 80050033 CR2: 00000000 CR3: 021b4000 CR4: 00000690
[ 122.261095] Call Trace:
[ 122.261095] ? debug_object_init+0x13/0x16:
debug_object_init at lib/debugobjects.c:430
[ 122.261095] ? __init_work+0x18/0x1a:
__init_work at kernel/workqueue.c:505
[ 122.261095] ? rhashtable_init+0x186/0x1be:
rhashtable_init at lib/rhashtable.c:1038
[ 122.261095] ? rhltable_init+0x11/0x1e:
rhltable_init at lib/rhashtable.c:1062
[ 122.261095] ? test_insert_dup+0x47/0x239:
test_insert_dup at lib/test_rhashtable.c:547
[ 122.261095] ? ___siphash_aligned+0x11/0x11
[ 122.261095] ? jhash+0x11d/0x11d:
jhash2 at include/linux/jhash.h:117
jhash+0x11d/0x11d:
jhash2 at include/linux/jhash.h:117
jhash+0x11d/0x11d:
my_hashfn at lib/test_rhashtable.c:83
jhash+0x11d/0x11d:
jhash2 at include/linux/jhash.h:117
jhash+0x11d/0x11d:
fl_set_masked_key at net/sched/cls_flower.c:127
jhash+0x11d/0x11d:
jhash2 at include/linux/jhash.h:117
jhash+0x11d/0x11d:
inet_frag_destroy_rcu at net/ipv4/inet_fragment.c:115
[ 122.261095] ? my_hashfn+0x14/0x14:
my_cmpfn at lib/test_rhashtable.c:90
[ 122.261095] ? test_rht_init+0x7b8/0x14a8:
test_insert_duplicates_run at lib/test_rhashtable.c:593 (discriminator 260)
(inlined by) test_rht_init at lib/test_rhashtable.c:748 (discriminator 260)
[ 122.261095] ? sched_clock_local+0xe/0x13b
[ 122.261095] ? ___siphash_aligned+0x11/0x11
[ 122.261095] ? check_chain_key+0x9a/0xef:
check_chain_key at kernel/locking/lockdep.c:2450 (discriminator 2)
[ 122.261095] ? __lock_acquire+0x487/0x4f8
[ 122.261095] ? lock_release+0x15f/0x178:
lock_release at kernel/locking/lockdep.c:3943
[ 122.261095] ? add_device_randomness+0x74/0x8c:
add_device_randomness at drivers/char/random.c:994
[ 122.261095] ? test_insert_dup+0x239/0x239:
test_rht_init at lib/test_rhashtable.c:693
[ 122.261095] ? do_one_initcall+0x8c/0x1d6:
do_one_initcall at init/main.c:883
[ 122.261095] ? do_early_param+0xf1/0xf1:
repair_env_string at init/main.c:250
[ 122.261095] ? kernel_init_freeable+0x11b/0x1fc:
do_initcall_level at init/main.c:950
(inlined by) do_initcalls at init/main.c:959
(inlined by) do_basic_setup at init/main.c:977
(inlined by) kernel_init_freeable at init/main.c:1127
[ 122.261095] ? rest_init+0xbb/0xbb:
kernel_init at init/main.c:1050
[ 122.261095] ? kernel_init+0x8/0xd0:
kernel_init at init/main.c:1055
[ 122.261095] ? ret_from_fork+0x19/0x30:
ret_from_fork at arch/x86/entry/entry_32.S:311
[ 122.261095] Code: 7d 42 83 f8 04 7f 26 8b 15 f0 43 fa 41 8b 92 74 02 00 00 39 d3 0f 82 98 00 00 00 81 c2 00 20 00 00 39 d3 0f 83 8a 00 00 00 eb 6a <0f> 0b 8b 47 08 83 f8 03 74 12 72 07 83 f8 04 74 33 eb 3d c7 47
[ 122.261095] ---[ end trace ddc80bc4cbbff90f ]---
[ 122.323276]
Attached the full dmesg, kconfig and reproduce scripts.
Thanks,
Fengguang
Greetings,
0day kernel testing robot got the below dmesg and the first bad commit is
https://git.kernel.org/pub/scm/linux/kernel/git/next/linux-next.git master
commit 499ac3b60f657dae82055fc81c7b01e6242ac9bc
Author: Paul Blakey <[email protected]>
AuthorDate: Sun Mar 4 17:29:49 2018 +0200
Commit: David S. Miller <[email protected]>
CommitDate: Wed Mar 7 10:44:03 2018 -0500
test_rhashtable: add test case for rhltable with duplicate objects
Tries to insert duplicates in the middle of bucket's chain:
bucket 1: [[val 21 (tid=1)]] -> [[ val 1 (tid=2), val 1 (tid=0) ]]
Reuses tid to distinguish the elements insertion order.
Signed-off-by: Paul Blakey <[email protected]>
Acked-by: Herbert Xu <[email protected]>
Signed-off-by: David S. Miller <[email protected]>
d3dcf8eb61 rhashtable: Fix rhlist duplicates insertion
499ac3b60f test_rhashtable: add test case for rhltable with duplicate objects
+----------------------------------------------------+------------+------------+
| | d3dcf8eb61 | 499ac3b60f |
+----------------------------------------------------+------------+------------+
| boot_successes | 28 | 0 |
| boot_failures | 0 | 15 |
| WARNING:at_lib/debugobjects.c:#__debug_object_init | 0 | 15 |
| EIP:__debug_object_init | 0 | 15 |
| Mem-Info | 0 | 2 |
+----------------------------------------------------+------------+------------+
[ 9.724580] Duration of test: 115289366 ns
[ 9.736431] test if its possible to exceed max_size 8192: no, ok
[ 9.737933] Average test time: 118138571
[ 9.738694] test inserting duplicates
[ 9.739384] ODEBUG: object is on stack, but not annotated
[ 9.740024] WARNING: CPU: 0 PID: 1 at lib/debugobjects.c:328 __debug_object_init+0x17b/0x380
[ 9.740024] CPU: 0 PID: 1 Comm: swapper/0 Not tainted 4.16.0-rc4-00130-g499ac3b #1
[ 9.740024] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.10.2-1 04/01/2014
[ 9.740024] EIP: __debug_object_init+0x17b/0x380
[ 9.740024] EFLAGS: 00210096 CPU: 0
[ 9.740024] EAX: 0000002d EBX: c0023e3c ECX: c0080ae0 EDX: 00000000
[ 9.740024] ESI: c2403d14 EDI: c2e99fa0 EBP: c2e99f9c ESP: c0023d90
[ 9.740024] DS: 007b ES: 007b FS: 00d8 GS: 0000 SS: 0068
[ 9.740024] CR0: 80050033 CR2: 00000000 CR3: 02828000 CR4: 00000690
[ 9.740024] Call Trace:
[ 9.740024] ? kstrtos8_from_user+0x50/0x50
[ 9.740024] ? rhashtable_init+0x1ff/0x2d0
[ 9.740024] ? rhltable_init+0xf/0x20
[ 9.740024] ? test_insert_dup+0x38/0x430
[ 9.740024] ? __lock_acquire+0x47c/0x8a0
[ 9.740024] ? kstrtos8_from_user+0x50/0x50
[ 9.740024] ? jhash+0x120/0x120
[ 9.740024] ? my_hashfn+0x30/0x30
[ 9.740024] ? test_rht_init+0x2bd/0x55f
[ 9.740024] ? test_rhashtable+0x40f/0x40f
[ 9.740024] ? do_one_initcall+0x7c/0x120
[ 9.740024] ? kernel_init_freeable+0xcc/0x164
[ 9.740024] ? kernel_init_freeable+0xec/0x164
[ 9.740024] ? rest_init+0x110/0x110
[ 9.740024] ? kernel_init+0x5/0xe0
[ 9.740024] ? ret_from_fork+0x19/0x24
[ 9.740024] Code: 00 39 d3 0f 83 32 01 00 00 83 7c 24 08 01 74 20 89 4c 24 08 68 14 3d 40 c2 83 c0 01 a3 cc a7 e3 c2 e8 7f 90 ab ff 5e 8b 4c 24 08 <0f> 0b 8d 76 00 8b 41 08 83 f8 03 74 48 72 36 83 f8 04 75 0c ba
[ 9.740024] ---[ end trace 0df84646a6fe1676 ]---
[ 9.763142]
# HH:MM RESULT GOOD BAD GOOD_BUT_DIRTY DIRTY_NOT_BAD
git bisect start f495aa00f6e9a7241096abc57c000cf2f98a2a40 661e50bc853209e41a5c14a290ca4decc43cbfd1 --
git bisect good 48d0d60ce4ae55c6e81020c638e4031faf8e8b92 # 04:31 G 11 0 0 0 Merge 'krzk/for-next' into devel-hourly-2018030913
git bisect good 1f5ca3de3b75425387c5fe59906a03e4fa6573ad # 04:49 G 11 0 1 1 Merge 'anholt/for-next' into devel-hourly-2018030913
git bisect bad 7e454c4a43319dd82b50bc7374dff990b51ee05b # 05:04 B 0 1 14 0 Merge 'block/for-next' into devel-hourly-2018030913
git bisect bad 223f4a9a8596ee7d6b4ca78605320f4eba725eb8 # 05:24 B 0 8 21 0 Merge 'jkirsher-net-queue/dev-queue' into devel-hourly-2018030913
git bisect good 3078ca90f959c821b41933bac8bacbf49cdaf624 # 05:50 G 10 0 5 5 Merge 'lpieralisi-pci/pci/rcar' into devel-hourly-2018030913
git bisect bad 89036a2a9852f70dcec97d5962974fe806828382 # 06:04 B 0 7 20 0 Merge branch 'for-upstream' of git://git.kernel.org/pub/scm/linux/kernel/git/bluetooth/bluetooth
git bisect good 25b5cdfcce1b57971840505dfc78556bd12dea6d # 06:19 G 11 0 5 5 dt-bindings: net: renesas-ravb: Make stream buffer optional
git bisect bad 803fafbe0cd522fa6b9e41ca3b96cfb2e2a2222d # 06:35 B 0 5 18 0 fsl/fman: avoid sleeping in atomic context while adding an address
git bisect bad 499ac3b60f657dae82055fc81c7b01e6242ac9bc # 06:53 B 0 2 15 0 test_rhashtable: add test case for rhltable with duplicate objects
git bisect good d3dcf8eb615537526bd42ff27a081d46d337816e # 07:09 G 11 0 2 2 rhashtable: Fix rhlist duplicates insertion
# first bad commit: [499ac3b60f657dae82055fc81c7b01e6242ac9bc] test_rhashtable: add test case for rhltable with duplicate objects
git bisect good d3dcf8eb615537526bd42ff27a081d46d337816e # 07:19 G 30 0 8 10 rhashtable: Fix rhlist duplicates insertion
# extra tests with debug options
git bisect bad 499ac3b60f657dae82055fc81c7b01e6242ac9bc # 07:35 B 0 5 18 0 test_rhashtable: add test case for rhltable with duplicate objects
# extra tests on HEAD of linux-devel/devel-hourly-2018030913
git bisect bad f495aa00f6e9a7241096abc57c000cf2f98a2a40 # 07:40 B 0 57 73 0 0day head guard for 'devel-hourly-2018030913'
# extra tests on tree/branch linux-next/master
# extra tests with first bad commit reverted
---
0-DAY kernel test infrastructure Open Source Technology Center
https://lists.01.org/pipermail/lkp Intel Corporation
Greetings,
0day kernel testing robot got the below dmesg and the first bad commit is
commit 499ac3b60f657dae82055fc81c7b01e6242ac9bc
Author: Paul Blakey <[email protected]>
AuthorDate: Sun Mar 4 17:29:49 2018 +0200
Commit: David S. Miller <[email protected]>
CommitDate: Wed Mar 7 10:44:03 2018 -0500
test_rhashtable: add test case for rhltable with duplicate objects
Tries to insert duplicates in the middle of bucket's chain:
bucket 1: [[val 21 (tid=1)]] -> [[ val 1 (tid=2), val 1 (tid=0) ]]
Reuses tid to distinguish the elements insertion order.
Signed-off-by: Paul Blakey <[email protected]>
Acked-by: Herbert Xu <[email protected]>
Signed-off-by: David S. Miller <[email protected]>
d3dcf8eb61 rhashtable: Fix rhlist duplicates insertion
499ac3b60f test_rhashtable: add test case for rhltable with duplicate objects
+--------------------------------------------------------------------+------------+------------+
| | d3dcf8eb61 | 499ac3b60f |
+--------------------------------------------------------------------+------------+------------+
| boot_successes | 41 | 0 |
| boot_failures | 0 | 21 |
| WARNING:suspicious_RCU_usage | 0 | 21 |
| lib/test_rhashtable.c:#suspicious_rcu_dereference_protected()usage | 0 | 21 |
+--------------------------------------------------------------------+------------+------------+
[ 7.248372] test if its possible to exceed max_size 8192: no, ok
[ 7.249256] Average test time: 464870041
[ 7.249746] test inserting duplicates
[ 7.250234]
[ 7.250425] =============================
[ 7.250900] WARNING: suspicious RCU usage
[ 7.251392] 4.16.0-rc4-00130-g499ac3b #2 Not tainted
[ 7.251971] -----------------------------
[ 7.252469] lib/test_rhashtable.c:502 suspicious rcu_dereference_protected() usage!
[ 7.253574]
[ 7.253574] other info that might help us debug this:
[ 7.253574]
[ 7.254489]
[ 7.254489] rcu_scheduler_active = 2, debug_locks = 1
[ 7.255236] no locks held by swapper/0/1.
[ 7.255700]
[ 7.255700] stack backtrace:
[ 7.256274] CPU: 0 PID: 1 Comm: swapper/0 Not tainted 4.16.0-rc4-00130-g499ac3b #2
[ 7.257148] Call Trace:
[ 7.257478] dump_stack+0xb7/0x107
[ 7.257884] print_ht+0x8f/0x35d
[ 7.258286] test_insert_dup+0x13b/0x1ce
[ 7.258745] ? ___siphash_aligned+0x2b/0x2b
[ 7.259369] ? jhash+0x1bb/0x1bb
[ 7.259769] ? my_hashfn+0x1a/0x1a
[ 7.260199] ? rhashtable_walk_peek+0x78/0x78
[ 7.260217] test_rht_init+0x6f8/0x1212
[ 7.260217] ? ___siphash_aligned+0x2b/0x2b
[ 7.260217] ? initcall_blacklisted+0xb0/0xd3
[ 7.260217] ? kstrtoll+0x9a/0xbc
[ 7.260217] ? kstrtos8+0x69/0x89
[ 7.260217] ? test_insert_dup+0x1ce/0x1ce
[ 7.260217] ? do_early_param+0xb9/0xb9
[ 7.260217] do_one_initcall+0xaa/0x17d
[ 7.260217] ? do_early_param+0xb9/0xb9
[ 7.260217] kernel_init_freeable+0x124/0x1d9
[ 7.260217] ? rest_init+0xc5/0xc5
[ 7.260217] kernel_init+0xb/0x147
[ 7.260217] ? rest_init+0xc5/0xc5
[ 7.260217] ret_from_fork+0x24/0x30
[ 7.267845]
[ 7.268075] =============================
[ 7.268564] WARNING: suspicious RCU usage
[ 7.269031] 4.16.0-rc4-00130-g499ac3b #2 Not tainted
[ 7.269622] -----------------------------
[ 7.270084] lib/test_rhashtable.c:507 suspicious rcu_dereference_protected() usage!
[ 7.271169]
[ 7.271169] other info that might help us debug this:
[ 7.271169]
[ 7.272102]
[ 7.272102] rcu_scheduler_active = 2, debug_locks = 1
[ 7.272851] no locks held by swapper/0/1.
[ 7.273338]
[ 7.273338] stack backtrace:
[ 7.273862] CPU: 0 PID: 1 Comm: swapper/0 Not tainted 4.16.0-rc4-00130-g499ac3b #2
[ 7.274723] Call Trace:
[ 7.275024] dump_stack+0xb7/0x107
[ 7.275452] print_ht+0xf4/0x35d
[ 7.275856] test_insert_dup+0x13b/0x1ce
[ 7.276085] ? ___siphash_aligned+0x2b/0x2b
[ 7.276085] ? jhash+0x1bb/0x1bb
[ 7.276085] ? my_hashfn+0x1a/0x1a
[ 7.276085] ? rhashtable_walk_peek+0x78/0x78
[ 7.276085] test_rht_init+0x6f8/0x1212
[ 7.276085] ? ___siphash_aligned+0x2b/0x2b
[ 7.276085] ? initcall_blacklisted+0xb0/0xd3
[ 7.276085] ? kstrtoll+0x9a/0xbc
[ 7.276085] ? kstrtos8+0x69/0x89
[ 7.276085] ? test_insert_dup+0x1ce/0x1ce
[ 7.276085] ? do_early_param+0xb9/0xb9
[ 7.276085] do_one_initcall+0xaa/0x17d
[ 7.276085] ? do_early_param+0xb9/0xb9
[ 7.276085] kernel_init_freeable+0x124/0x1d9
[ 7.276085] ? rest_init+0xc5/0xc5
[ 7.276085] kernel_init+0xb/0x147
[ 7.276085] ? rest_init+0xc5/0xc5
[ 7.276085] ret_from_fork+0x24/0x30
[ 7.285387]
[ 7.285589] =============================
[ 7.286070] WARNING: suspicious RCU usage
[ 7.286550] 4.16.0-rc4-00130-g499ac3b #2 Not tainted
[ 7.287121] -----------------------------
[ 7.287590] lib/test_rhashtable.c:508 suspicious rcu_dereference_protected() usage!
[ 7.288702]
[ 7.288702] other info that might help us debug this:
[ 7.288702]
[ 7.289617]
[ 7.289617] rcu_scheduler_active = 2, debug_locks = 1
[ 7.290374] no locks held by swapper/0/1.
[ 7.290859]
[ 7.290859] stack backtrace:
[ 7.291375] CPU: 0 PID: 1 Comm: swapper/0 Not tainted 4.16.0-rc4-00130-g499ac3b #2
[ 7.292239] Call Trace:
[ 7.292556] dump_stack+0xb7/0x107
[ 7.292669] print_ht+0x15e/0x35d
[ 7.292669] test_insert_dup+0x13b/0x1ce
[ 7.292669] ? ___siphash_aligned+0x2b/0x2b
[ 7.292669] ? jhash+0x1bb/0x1bb
[ 7.292669] ? my_hashfn+0x1a/0x1a
[ 7.292669] ? rhashtable_walk_peek+0x78/0x78
[ 7.292669] test_rht_init+0x6f8/0x1212
[ 7.292669] ? ___siphash_aligned+0x2b/0x2b
[ 7.292669] ? initcall_blacklisted+0xb0/0xd3
[ 7.292669] ? kstrtoll+0x9a/0xbc
[ 7.292669] ? kstrtos8+0x69/0x89
[ 7.292669] ? test_insert_dup+0x1ce/0x1ce
[ 7.292669] ? do_early_param+0xb9/0xb9
[ 7.292669] do_one_initcall+0xaa/0x17d
[ 7.292669] ? do_early_param+0xb9/0xb9
[ 7.292669] kernel_init_freeable+0x124/0x1d9
[ 7.292669] ? rest_init+0xc5/0xc5
[ 7.292669] kernel_init+0xb/0x147
[ 7.292669] ? rest_init+0xc5/0xc5
[ 7.292669] ret_from_fork+0x24/0x30
[ 7.302814]
[ 7.303002] =============================
[ 7.303480] WARNING: suspicious RCU usage
[ 7.303942] 4.16.0-rc4-00130-g499ac3b #2 Not tainted
[ 7.304550] -----------------------------
[ 7.305015] lib/test_rhashtable.c:519 suspicious rcu_dereference_protected() usage!
[ 7.306095]
[ 7.306095] other info that might help us debug this:
[ 7.306095]
[ 7.306995]
[ 7.306995] rcu_scheduler_active = 2, debug_locks = 1
[ 7.307755] no locks held by swapper/0/1.
[ 7.308242]
[ 7.308242] stack backtrace:
[ 7.308762] CPU: 0 PID: 1 Comm: swapper/0 Not tainted 4.16.0-rc4-00130-g499ac3b #2
[ 7.309626] Call Trace:
[ 7.309945] dump_stack+0xb7/0x107
[ 7.310367] print_ht+0x1f0/0x35d
[ 7.310762] test_insert_dup+0x13b/0x1ce
[ 7.311232] ? ___siphash_aligned+0x2b/0x2b
[ 7.311851] ? jhash+0x1bb/0x1bb
[ 7.312228] ? my_hashfn+0x1a/0x1a
[ 7.312228] ? rhashtable_walk_peek+0x78/0x78
[ 7.312228] test_rht_init+0x6f8/0x1212
[ 7.312228] ? ___siphash_aligned+0x2b/0x2b
[ 7.312228] ? initcall_blacklisted+0xb0/0xd3
[ 7.312228] ? kstrtoll+0x9a/0xbc
[ 7.312228] ? kstrtos8+0x69/0x89
[ 7.312228] ? test_insert_dup+0x1ce/0x1ce
[ 7.312228] ? do_early_param+0xb9/0xb9
[ 7.312228] do_one_initcall+0xaa/0x17d
[ 7.312228] ? do_early_param+0xb9/0xb9
[ 7.312228] kernel_init_freeable+0x124/0x1d9
[ 7.312228] ? rest_init+0xc5/0xc5
[ 7.312228] kernel_init+0xb/0x147
[ 7.312228] ? rest_init+0xc5/0xc5
[ 7.312228] ret_from_fork+0x24/0x30
[ 7.320198]
[ 7.320408] =============================
[ 7.320870] WARNING: suspicious RCU usage
[ 7.321361] 4.16.0-rc4-00130-g499ac3b #2 Not tainted
[ 7.321929] -----------------------------
[ 7.322398] lib/test_rhashtable.c:529 suspicious rcu_dereference_protected() usage!
[ 7.323469]
[ 7.323469] other info that might help us debug this:
[ 7.323469]
[ 7.324404]
[ 7.324404] rcu_scheduler_active = 2, debug_locks = 1
[ 7.325157] no locks held by swapper/0/1.
[ 7.325631]
[ 7.325631] stack backtrace:
[ 7.326158] CPU: 0 PID: 1 Comm: swapper/0 Not tainted 4.16.0-rc4-00130-g499ac3b #2
[ 7.326980] Call Trace:
[ 7.327293] dump_stack+0xb7/0x107
[ 7.327707] print_ht+0x2bc/0x35d
[ 7.328129] test_insert_dup+0x13b/0x1ce
[ 7.328380] ? ___siphash_aligned+0x2b/0x2b
[ 7.328380] ? jhash+0x1bb/0x1bb
[ 7.328380] ? my_hashfn+0x1a/0x1a
[ 7.328380] ? rhashtable_walk_peek+0x78/0x78
[ 7.328380] test_rht_init+0x6f8/0x1212
[ 7.328380] ? ___siphash_aligned+0x2b/0x2b
[ 7.328380] ? initcall_blacklisted+0xb0/0xd3
[ 7.328380] ? kstrtoll+0x9a/0xbc
[ 7.328380] ? kstrtos8+0x69/0x89
[ 7.328380] ? test_insert_dup+0x1ce/0x1ce
[ 7.328380] ? do_early_param+0xb9/0xb9
[ 7.328380] do_one_initcall+0xaa/0x17d
[ 7.328380] ? do_early_param+0xb9/0xb9
[ 7.328380] kernel_init_freeable+0x124/0x1d9
[ 7.328380] ? rest_init+0xc5/0xc5
[ 7.328380] kernel_init+0xb/0x147
[ 7.328380] ? rest_init+0xc5/0xc5
[ 7.328380] ret_from_fork+0x24/0x30
[ 7.337480]
[ 7.337480] ---- ht: ----
[ 7.337480] bucket[1] -> [[ val 1 (tid=0) ]] -> [[ val 21 (tid=1) ]]
[ 7.337480] -------------
[ 7.339010]
# HH:MM RESULT GOOD BAD GOOD_BUT_DIRTY DIRTY_NOT_BAD
git bisect start 720b4957c76e21b64ebcfbe2db6628653457a132 661e50bc853209e41a5c14a290ca4decc43cbfd1 --
git bisect bad 2105ee619597aa7c86e54374d7c18ca66d409546 # 05:17 B 0 11 24 0 Merge 'regmap/for-next' into devel-catchup-201803080312
git bisect bad 4f9652fad49d3194174fd861d2ba2a008273380b # 05:27 B 0 2 15 0 Merge 'hid/for-4.16/upstream-fixes' into devel-catchup-201803080312
git bisect bad ee2902aa03dd3b02a8a7f01b4f8fa5b22e854d26 # 05:50 B 0 1 14 0 Merge 'jkirsher-net-queue/master' into devel-catchup-201803080312
git bisect good 08d0c47a51087fe73203e85d2455078bfeec2eeb # 06:05 G 11 0 0 0 Merge 'linux-review/Leon-Romanovsky/RDMA-ucma-Limit-possible-option-size/20180308-012724' into devel-catchup-201803080312
git bisect good 70ccbfde7342e3d79f4fce05da08d1b6002d2492 # 06:19 G 11 0 1 1 Merge 'linux-review/Leon-Romanovsky/RDMA-ucma-Check-that-user-doesn-t-overflow-QP-state/20180308-011932' into devel-catchup-201803080312
git bisect good 7cb0d12201b8971cd91400c59e91743f760e3991 # 06:32 G 11 0 4 4 Merge 'linux-nvme/nvme-4.16-rc5' into devel-catchup-201803080312
git bisect good d69242bf203e3123ab722bdaa95e1bc42472d10b # 06:46 G 11 0 1 1 Merge tag 'mac80211-for-davem-2018-03-02' of git://git.kernel.org/pub/scm/linux/kernel/git/jberg/mac80211
git bisect good b3bf5666a51068ad5ddd89a76ed877101ef3bc16 # 06:55 G 11 0 4 4 hv_netvsc: defer queue selection to VF
git bisect good 25b5cdfcce1b57971840505dfc78556bd12dea6d # 07:07 G 11 0 1 1 dt-bindings: net: renesas-ravb: Make stream buffer optional
git bisect bad 2695578b896aea472b2c0dcbe9d92daa71738484 # 07:16 B 0 4 17 0 net: usbnet: fix potential deadlock on 32bit hosts
git bisect bad 803fafbe0cd522fa6b9e41ca3b96cfb2e2a2222d # 07:34 B 0 1 14 0 fsl/fman: avoid sleeping in atomic context while adding an address
git bisect bad 499ac3b60f657dae82055fc81c7b01e6242ac9bc # 07:50 B 0 11 26 2 test_rhashtable: add test case for rhltable with duplicate objects
git bisect good d3dcf8eb615537526bd42ff27a081d46d337816e # 07:59 G 10 0 1 1 rhashtable: Fix rhlist duplicates insertion
# first bad commit: [499ac3b60f657dae82055fc81c7b01e6242ac9bc] test_rhashtable: add test case for rhltable with duplicate objects
git bisect good d3dcf8eb615537526bd42ff27a081d46d337816e # 08:02 G 32 0 3 4 rhashtable: Fix rhlist duplicates insertion
# extra tests with debug options
git bisect bad 499ac3b60f657dae82055fc81c7b01e6242ac9bc # 08:12 B 0 3 16 0 test_rhashtable: add test case for rhltable with duplicate objects
# extra tests on HEAD of linux-devel/devel-catchup-201803080312
git bisect bad 720b4957c76e21b64ebcfbe2db6628653457a132 # 08:18 B 0 13 29 0 0day head guard for 'devel-catchup-201803080312'
# extra tests on tree/branch linux-devel/devel-catchup-201803080233
# extra tests with first bad commit reverted
git bisect good 7c17a6b5257f54bfeba9868af4a2fbbf0ae73c9f # 15:37 G 11 0 0 0 Revert "test_rhashtable: add test case for rhltable with duplicate objects"
---
0-DAY kernel test infrastructure Open Source Technology Center
https://lists.01.org/pipermail/lkp Intel Corporation