Message-ID: <20150402005211.GC12979@wfg-t540p.sh.intel.com>
Date:	Thu, 2 Apr 2015 08:52:11 +0800
From:	Fengguang Wu <fengguang.wu@...el.com>
To:	Herbert Xu <herbert@...dor.apana.org.au>
Cc:	fengguang.wu@...el.com, LKP <lkp@...org>, netdev@...r.kernel.org,
	linux-kernel@...r.kernel.org
Subject: [rhashtable] [ INFO: suspicious RCU usage. ]

Hi Herbert,

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

git://git.kernel.org/pub/scm/linux/kernel/git/next/linux-next.git master

commit ccd57b1bd32460d27bbb9c599e795628a3c66983
Author:     Herbert Xu <herbert@...dor.apana.org.au>
AuthorDate: Tue Mar 24 00:50:28 2015 +1100
Commit:     David S. Miller <davem@...emloft.net>
CommitDate: Mon Mar 23 22:07:52 2015 -0400

    rhashtable: Add immediate rehash during insertion
    
    This patch reintroduces immediate rehash during insertion.  If
    we find during insertion that the table is full or the chain
    length exceeds a set limit (currently 16 but may be disabled
    with insecure_elasticity) then we will force an immediate rehash.
    The rehash will contain an expansion if the table utilisation
    exceeds 75%.
    
    If this rehash fails then the insertion will fail.  Otherwise the
    insertion will be reattempted in the new hash table.
    
    Signed-off-by: Herbert Xu <herbert@...dor.apana.org.au>
    Acked-by: Thomas Graf <tgraf@...g.ch>
    Signed-off-by: David S. Miller <davem@...emloft.net>

[    0.552992]   Adding 2048 keys
[    0.553792] 
[    0.554400] ===============================
[    0.555285] [ INFO: suspicious RCU usage. ]
[    0.556176] 4.0.0-rc4-01225-gccd57b1 #171 Not tainted
[    0.557156] -------------------------------
[    0.558044] lib/rhashtable.c:400 suspicious rcu_dereference_check() usage!
[    0.559741] 
[    0.559741] other info that might help us debug this:
[    0.559741] 
[    0.561764] 
[    0.561764] rcu_scheduler_active = 1, debug_locks = 0
[    0.563254] no locks held by swapper/0/1.
[    0.564124] 
[    0.564124] stack backtrace:
[    0.565394] CPU: 0 PID: 1 Comm: swapper/0 Not tainted 4.0.0-rc4-01225-gccd57b1 #171
[    0.567017] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.7.5-20140531_083030-gandalf 04/01/2014
[    0.568898]  0000000000000001 ffff88000f563d38 ffffffff8182e695 0000000000000011
[    0.570775]  ffff88000f558000 ffff88000f563d68 ffffffff810ffce7 ffffffff831fc340
[    0.572637]  ffff88000e874d10 000000000000000d ffff88000e199e40 ffff88000f563da8
[    0.574519] Call Trace:
[    0.575219]  [<ffffffff8182e695>] dump_stack+0x4c/0x65
[    0.576210]  [<ffffffff810ffce7>] lockdep_rcu_suspicious+0xe7/0x120
[    0.577314]  [<ffffffff8142d0fe>] rhashtable_insert_rehash+0x18e/0x1d0
[    0.578443]  [<ffffffff8221814c>] test_rht_init+0x38f/0x12bd
[    0.579483]  [<ffffffff810002c0>] ? do_one_initcall+0x80/0x200
[    0.580542]  [<ffffffff82217dbd>] ? test_firmware_init+0x79/0x79
[    0.581615]  [<ffffffff810002d0>] do_one_initcall+0x90/0x200
[    0.582651]  [<ffffffff821e2212>] kernel_init_freeable+0x22d/0x2b5
[    0.583743]  [<ffffffff81829160>] ? rest_init+0x140/0x140
[    0.584755]  [<ffffffff8182916e>] kernel_init+0xe/0xf0
[    0.585743]  [<ffffffff81839318>] ret_from_fork+0x58/0x90
[    0.586756]  [<ffffffff81829160>] ? rest_init+0x140/0x140
[    0.587778] ------------[ cut here ]------------
[    0.588715] WARNING: CPU: 0 PID: 1 at lib/rhashtable.c:408 rhashtable_insert_rehash+0x95/0x1d0()
[    0.590608] Modules linked in:
[    0.591439] CPU: 0 PID: 1 Comm: swapper/0 Not tainted 4.0.0-rc4-01225-gccd57b1 #171
[    0.593058] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.7.5-20140531_083030-gandalf 04/01/2014
[    0.594929]  ffffffff81d08b58 ffff88000f563d18 ffffffff8182e695 0000000000000000
[    0.596809]  0000000000000000 ffff88000f563d58 ffffffff810af7fa 00000000fffffe00
[    0.598682]  ffffffff831fc340 0000000000000010 ffff88000e199840 0000000000000001
[    0.600558] Call Trace:
[    0.601259]  [<ffffffff8182e695>] dump_stack+0x4c/0x65
[    0.602238]  [<ffffffff810af7fa>] warn_slowpath_common+0x8a/0xc0
[    0.603310]  [<ffffffff810af8ea>] warn_slowpath_null+0x1a/0x20
[    0.604366]  [<ffffffff8142d005>] rhashtable_insert_rehash+0x95/0x1d0
[    0.605495]  [<ffffffff8221814c>] test_rht_init+0x38f/0x12bd
[    0.606536]  [<ffffffff810002c0>] ? do_one_initcall+0x80/0x200
[    0.607589]  [<ffffffff82217dbd>] ? test_firmware_init+0x79/0x79
[    0.608664]  [<ffffffff810002d0>] do_one_initcall+0x90/0x200
[    0.609704]  [<ffffffff821e2212>] kernel_init_freeable+0x22d/0x2b5
[    0.610797]  [<ffffffff81829160>] ? rest_init+0x140/0x140
[    0.611808]  [<ffffffff8182916e>] kernel_init+0xe/0xf0
[    0.612792]  [<ffffffff81839318>] ret_from_fork+0x58/0x90
[    0.613801]  [<ffffffff81829160>] ? rest_init+0x140/0x140
[    0.614808] ---[ end trace b5aa4dbce5f556f0 ]---
[    0.615763] glob: 64 self-tests passed, 0 failed

git bisect start 4fab6501bb2945a0c0c9045c059ac342147856fd e42391cd048809d903291d07f86ed3934ce138e9 --
git bisect  bad 92d9ebca6ac4759827ea9785ace3aecba37e78ad  # 19:58      0-     20  Merge 'devfreq/for-rafael' into devel-hourly-2015033101
git bisect  bad 18dd8e1456f801932f2e75e636d9132297e402d5  # 19:58      0-     20  Merge 'peterhuewe-tpmdd/for-current' into devel-hourly-2015033101
git bisect good 49e34ea97b39e88623b1c0e658ba0cf27034150e  # 19:58     20+      0  Merge 'tegra/for-4.1/dt' into devel-hourly-2015033101
git bisect good f81c2b2a8cf42ef78cd7e0aa08d880eec7e0787a  # 20:02     20+      1  Merge 'tegra/for-next' into devel-hourly-2015033101
git bisect  bad e0ac3b3842ecc894c7fa5d0a02596f15875f89eb  # 20:02      0-     20  Merge 'lunn/v4.0-rc5-groeck-dsa-next-cleanup' into devel-hourly-2015033101
git bisect good 749e956cfcc62b4ca948e6fb40c06d412e1d75c6  # 20:02     20+      0  Merge 'mvebu/for-next' into devel-hourly-2015033101
git bisect good 0f7bbd5805e3d32e3ee58d1a802a8404a724f2fc  # 20:05     20+     40  mpls: Better error code for unsupported option.
git bisect good 6eada0110c8984477f5f1e57a0b7f7b2fc841e30  # 20:11     20+     40  netns: constify net_hash_mix() and various callers
git bisect good c637aab05c9dd0894832a7c542a1553b2815b9ef  # 20:11     20+      0  can: kvaser_usb: Use can-dev unregistration mechanism
git bisect  bad ce046c568cbfb4734583131086f88cfe993c01d0  # 20:11      0-     20  Merge branch 'ipv6_stable_privacy_address'
git bisect good 40451fd013878b005ccae767dfebc07dfecf85d9  # 20:11     20+      0  Merge git://git.kernel.org/pub/scm/linux/kernel/git/pablo/nf-next
git bisect  bad ca8cf341903f90070e191cc8be8f705ab7af2d4a  # 20:11      0-     20  net: bcmgenet: propagate errors from bcmgenet_power_down
git bisect good 31ccde2dacea8375c3a7d6fffbf0060ee0d40214  # 20:14     20+      2  rhashtable: Allow hashfn to be unset
git bisect good b824478b2145be78ac19e1cf44e2b9036c7a9608  # 20:14     20+      0  rhashtable: Add multiple rehash support
git bisect  bad ccd57b1bd32460d27bbb9c599e795628a3c66983  # 20:14      0-     20  rhashtable: Add immediate rehash during insertion
git bisect good b9ecfdaa1090b5988422eaf5348ea1954d2d7219  # 20:18     20+      1  rhashtable: Allow GFP_ATOMIC bucket table allocation
# first bad commit: [ccd57b1bd32460d27bbb9c599e795628a3c66983] rhashtable: Add immediate rehash during insertion
git bisect good b9ecfdaa1090b5988422eaf5348ea1954d2d7219  # 20:24     60+      1  rhashtable: Allow GFP_ATOMIC bucket table allocation
# extra tests with DEBUG_INFO
git bisect  bad ccd57b1bd32460d27bbb9c599e795628a3c66983  # 20:24      0-     60  rhashtable: Add immediate rehash during insertion
# extra tests on HEAD of linux-devel/devel-hourly-2015033101
git bisect  bad 4fab6501bb2945a0c0c9045c059ac342147856fd  # 20:24      0-     22  0day head guard for 'devel-hourly-2015033101'
# extra tests on tree/branch next/master
git bisect  bad e954104e2b634b42811dad8d502cbf240f206df2  # 20:35      0-      1  Add linux-next specific files for 20150401
# extra tests on tree/branch linus/master
git bisect good 6c310bc1acdd02110182a2ec6efa3e7571a3b80c  # 21:22     60+      1  Merge tag 'locks-v4.0-5' of git://git.samba.org/jlayton/linux
# extra tests on tree/branch next/master
git bisect  bad e954104e2b634b42811dad8d502cbf240f206df2  # 21:22      0-     60  Add linux-next specific files for 20150401


This script may reproduce the error.

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

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

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

kvm=(
	qemu-system-x86_64
	-enable-kvm
	-cpu Haswell,+smep,+smap
	-kernel $kernel
	-initrd $initrd
	-m 256
	-smp 1
	-device e1000,netdev=net0
	-netdev user,id=net0
	-boot order=nc
	-no-reboot
	-watchdog i6300esb
	-rtc base=localtime
	-serial stdio
	-display none
	-monitor null 
)

append=(
	hung_task_panic=1
	earlyprintk=ttyS0,115200
	rd.udev.log-priority=err
	systemd.log_target=journal
	systemd.log_level=warning
	debug
	apic=debug
	sysrq_always_enabled
	rcupdate.rcu_cpu_stall_timeout=100
	panic=-1
	softlockup_panic=1
	nmi_watchdog=panic
	oops=panic
	load_ramdisk=2
	prompt_ramdisk=0
	console=ttyS0,115200
	console=tty0
	vga=normal
	root=/dev/ram0
	rw
	drbd.minor_count=8
)

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

Thanks,
Fengguang

View attachment "dmesg-yocto-ivb41-3:20150331113735:x86_64-randconfig-n0-03310731:4.0.0-rc4-01225-gccd57b1:171" of type "text/plain" (50797 bytes)

Powered by blists - more mailing lists