lists.openwall.net   lists  /  announce  owl-users  owl-dev  john-users  john-dev  passwdqc-users  yescrypt  popa3d-users  /  oss-security  kernel-hardening  musl  sabotage  tlsify  passwords  /  crypt-dev  xvendor  /  Bugtraq  Full-Disclosure  linux-kernel  linux-netdev  linux-ext4  linux-hardening  linux-cve-announce  PHC 
Open Source and information security mailing list archives
 
Hash Suite: Windows password security audit tool. GUI, reports in PDF.
[<prev] [next>] [thread-next>] [day] [month] [year] [list]
Message-ID: <20180419030329.mvt3nhq263be4xtp@wfg-t540p.sh.intel.com>
Date:   Thu, 19 Apr 2018 11:03:29 +0800
From:   Fengguang Wu <fengguang.wu@...el.com>
To:     Phil Sutter <phil@....cc>
Cc:     Thomas Graf <tgraf@...g.ch>,
        Daniel Borkmann <daniel@...earbox.net>,
        Florian Westphal <fw@...len.de>,
        Herbert Xu <herbert@...dor.apana.org.au>,
        linux-kernel@...r.kernel.org, lkp@...org
Subject: [test_rhashtable] WARNING: suspicious RCU usage

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

View attachment "dmesg-openwrt-lkp-hsw01-15:20180418191103:i386-randconfig-c0-04181855:4.17.0-rc1:46" of type "text/plain" (41712 bytes)

View attachment ".config" of type "text/plain" (97476 bytes)

View attachment "reproduce-openwrt-lkp-hsw01-15:20180418191103:i386-randconfig-c0-04181855:4.17.0-rc1:46" of type "text/plain" (919 bytes)

Powered by blists - more mailing lists

Powered by Openwall GNU/*/Linux Powered by OpenVZ