[<prev] [next>] [day] [month] [year] [list]
Message-ID: <55e2dbc1.3mVencIc6V8ACiGU%fengguang.wu@intel.com>
Date: Sun, 30 Aug 2015 18:32:33 +0800
From: kernel test robot <fengguang.wu@...el.com>
To: Phil Sutter <phil@....cc>
Cc: LKP <lkp@...org>, linux-kernel@...r.kernel.org, wfg@...ux.intel.com
Subject: [rhashtable-test] f4a3e90ba5: EIP is at __rcu_is_watching
Greetings,
0day kernel testing robot got the below dmesg and the first bad commit is
git://git.kernel.org/pub/scm/linux/kernel/git/bluetooth/bluetooth-next.git master
commit f4a3e90ba5739cfd761b6befadae9728bd3641ed
Author: Phil Sutter <phil@....cc>
AuthorDate: Sat Aug 15 00:37:15 2015 +0200
Commit: David S. Miller <davem@...emloft.net>
CommitDate: Mon Aug 17 14:33:47 2015 -0700
rhashtable-test: extend to test concurrency
After having tested insertion, lookup, table walk and removal, spawn a
number of threads running operations on the same rhashtable. Each of
them will:
1) insert it's own set of objects,
2) lookup every successfully inserted object and finally
3) remove objects in several rounds until all of them have been removed,
making sure the remaining ones are still found after each round.
This should put a good amount of load onto the system and due to
synchronising thread startup via two semaphores also extensive
concurrent table access.
The default number of ten threads returned within half a second on my
local VM with two cores. Running 200 threads took about four seconds. If
slow systems suffer too much from this though, the default could be
lowered or even set to zero so this extended test does not run at all by
default.
Signed-off-by: Phil Sutter <phil@....cc>
Acked-by: Thomas Graf <tgraf@...g.ch>
Signed-off-by: David S. Miller <davem@...emloft.net>
+------------------------------------------------------+------------+------------+------------+
| | c1f066d4ee | f4a3e90ba5 | f51955394f |
+------------------------------------------------------+------------+------------+------------+
| boot_successes | 1009 | 844 | 104 |
| boot_failures | 0 | 66 | 9 |
| EIP_is_at_lock_is_held | 0 | 27 | 4 |
| Kernel_panic-not_syncing:softlockup:hung_tasks | 0 | 63 | 7 |
| backtrace:threadfunc | 0 | 65 | 7 |
| EIP_is_at_lock_acquire | 0 | 4 | 1 |
| EIP_is_at__rcu_is_watching | 0 | 3 | |
| EIP_is_at_debug_lockdep_rcu_enabled | 0 | 6 | 2 |
| EIP_is_at_rcu_lockdep_current_cpu_online | 0 | 5 | 1 |
| EIP_is_at_thread_lookup_test | 0 | 5 | 1 |
| EIP_is_at_lockdep_rht_bucket_is_held | 0 | 3 | |
| EIP_is_at_jhash | 0 | 2 | |
| EIP_is_at_rcu_read_lock_held | 0 | 7 | 1 |
| EIP_is_at_lock_release | 0 | 1 | |
| EIP_is_at_rcu_is_watching | 0 | 3 | 1 |
| INFO:rcu_sched_detected_stalls_on_CPUs/tasks | 0 | 2 | |
| WARNING:at_mm/page_alloc.c:#__alloc_pages_nodemask() | 0 | 1 | |
| backtrace:packet_setsockopt | 0 | 1 | |
| backtrace:SyS_setsockopt | 0 | 1 | |
| backtrace:SyS_socketcall | 0 | 1 | |
| IP-Config:Auto-configuration_of_network_failed | 0 | 0 | 2 |
+------------------------------------------------------+------------+------------+------------+
[ 31.548753] Testing concurrent rhashtable access from 10 threads
[ 52.242900] NMI watchdog: BUG: soft lockup - CPU#1 stuck for 22s! [rhashtable_thra:88]
[ 52.242900] NMI watchdog: BUG: soft lockup - CPU#1 stuck for 22s! [rhashtable_thra:88]
[ 52.242900] Modules linked in:
[ 52.242900] Modules linked in:
[ 52.242900] irq event stamp: 1845856
[ 52.242900] irq event stamp: 1845856
[ 52.242900] hardirqs last enabled at (1845855):
[ 52.242900] hardirqs last enabled at (1845855): [<c1b71e6c>] restore_all_notrace+0x0/0x18
[<c1b71e6c>] restore_all_notrace+0x0/0x18
[ 52.242900] hardirqs last disabled at (1845856):
[ 52.242900] hardirqs last disabled at (1845856): [<c1b7290c>] apic_timer_interrupt+0x28/0x34
[<c1b7290c>] apic_timer_interrupt+0x28/0x34
[ 52.242900] softirqs last enabled at (1845854):
[ 52.242900] softirqs last enabled at (1845854): [<c1076b9c>] __do_softirq+0x70b/0xb0a
[<c1076b9c>] __do_softirq+0x70b/0xb0a
[ 52.242900] softirqs last disabled at (1845851):
[ 52.242900] softirqs last disabled at (1845851): [<c100790b>] do_softirq_own_stack+0x3e/0x60
[<c100790b>] do_softirq_own_stack+0x3e/0x60
[ 52.242900] CPU: 1 PID: 88 Comm: rhashtable_thra Not tainted 4.2.0-rc6-00979-gf4a3e90 #1
[ 52.242900] CPU: 1 PID: 88 Comm: rhashtable_thra Not tainted 4.2.0-rc6-00979-gf4a3e90 #1
[ 52.242900] task: d22b0000 ti: d22b2000 task.ti: d22b2000
[ 52.242900] task: d22b0000 ti: d22b2000 task.ti: d22b2000
[ 52.242900] EIP: 0060:[<c112260e>] EFLAGS: 00000246 CPU: 1
[ 52.242900] EIP: 0060:[<c112260e>] EFLAGS: 00000246 CPU: 1
[ 52.242900] EIP is at __rcu_is_watching+0x0/0x32
[ 52.242900] EIP is at __rcu_is_watching+0x0/0x32
[ 52.242900] EAX: 00000001 EBX: 30000053 ECX: 00000000 EDX: 00000001
[ 52.242900] EAX: 00000001 EBX: 30000053 ECX: 00000000 EDX: 00000001
[ 52.242900] ESI: d22af618 EDI: d35f3000 EBP: d22b3eb8 ESP: d22b3eb4
[ 52.242900] ESI: d22af618 EDI: d35f3000 EBP: d22b3eb8 ESP: d22b3eb4
[ 52.242900] DS: 007b ES: 007b FS: 00d8 GS: 0000 SS: 0068
[ 52.242900] DS: 007b ES: 007b FS: 00d8 GS: 0000 SS: 0068
[ 52.242900] CR0: 8005003b CR2: 00000000 CR3: 02247000 CR4: 000006b0
[ 52.242900] CR0: 8005003b CR2: 00000000 CR3: 02247000 CR4: 000006b0
[ 52.242900] Stack:
[ 52.242900] Stack:
[ 52.242900] c112266b
[ 52.242900] c112266b d22b3ec0 d22b3ec0 c111f492 c111f492 d22b3ef0 d22b3ef0 c14ebf56 c14ebf56 00000029 00000029 00000000 00000000 00000000 00000000
[ 52.242900] 0000b430
[ 52.242900] 0000b430 0000b430 0000b430 c2bdbfc0 c2bdbfc0 d22b3ed8 d22b3ed8 00000000 00000000 00000003 00000003 d35f3000 d35f3000 d22b3f34 d22b3f34
[ 52.242900] c14ed0cf
[ 52.242900] c14ed0cf 00000000 00000000 d1c02e84 d1c02e84 d2313220 d2313220 00000000 00000000 00000004 00000004 d3656a2c d3656a2c 00000003 00000003
[ 52.242900] Call Trace:
[ 52.242900] Call Trace:
[ 52.242900] [<c112266b>] ? rcu_is_watching+0x2b/0x50
[ 52.242900] [<c112266b>] ? rcu_is_watching+0x2b/0x50
[ 52.242900] [<c111f492>] rcu_read_lock_held+0x47/0xaa
[ 52.242900] [<c111f492>] rcu_read_lock_held+0x47/0xaa
[ 52.242900] [<c14ebf56>] thread_lookup_test+0x4d8/0x6ea
[ 52.242900] [<c14ebf56>] thread_lookup_test+0x4d8/0x6ea
[ 52.242900] [<c14ed0cf>] threadfunc+0xf67/0x1380
[ 52.242900] [<c14ed0cf>] threadfunc+0xf67/0x1380
[ 52.242900] [<c14ec168>] ? thread_lookup_test+0x6ea/0x6ea
[ 52.242900] [<c14ec168>] ? thread_lookup_test+0x6ea/0x6ea
[ 52.242900] [<c14ec168>] ? thread_lookup_test+0x6ea/0x6ea
[ 52.242900] [<c14ec168>] ? thread_lookup_test+0x6ea/0x6ea
[ 52.242900] [<c10a928f>] kthread+0x151/0x164
[ 52.242900] [<c10a928f>] kthread+0x151/0x164
[ 52.242900] [<c1b70da1>] ? _raw_spin_unlock_irq+0x5f/0x99
[ 52.242900] [<c1b70da1>] ? _raw_spin_unlock_irq+0x5f/0x99
[ 52.242900] [<c1b71cc1>] ret_from_kernel_thread+0x21/0x30
[ 52.242900] [<c1b71cc1>] ret_from_kernel_thread+0x21/0x30
[ 52.242900] [<c10a913e>] ? kthread_stop+0x8db/0x8db
[ 52.242900] [<c10a913e>] ? kthread_stop+0x8db/0x8db
[ 52.242900] Code:
[ 52.242900] Code: 0c 0c 86 86 a5 a5 c2 c2 00 00 eb eb 21 21 83 83 05 05 b8 b8 85 85 a5 a5 c2 c2 01 01 83 83 15 15 bc bc 85 85 a5 a5 c2 c2 00 00 e9 e9 37 37 ff ff ff ff ff ff 83 83 05 05 00 00 86 86 a5 a5 c2 c2 01 01 83 83 15 15 04 04 86 86 a5 a5 c2 c2 00 00 5b 5b 5d 5d c3 c3 <55> <55> 83 83 05 05 10 10 86 86 a5 a5 c2 c2 01 01 b8 b8 0c 0c 6d 6d 23 23 c2 c2 83 83 15 15 14 14 86 86 a5 a5 c2 c2 00 00 89 89
[ 52.242900] Kernel panic - not syncing: softlockup: hung tasks
[ 52.242900] Kernel panic - not syncing: softlockup: hung tasks
[ 52.242900] CPU: 1 PID: 88 Comm: rhashtable_thra Tainted: G L 4.2.0-rc6-00979-gf4a3e90 #1
[ 52.242900] CPU: 1 PID: 88 Comm: rhashtable_thra Tainted: G L 4.2.0-rc6-00979-gf4a3e90 #1
[ 52.242900] 00000000
[ 52.242900] 00000000 00000000 00000000 d22b3da0 d22b3da0 c1b5d1fe c1b5d1fe 00000016 00000016 d22b3db8 d22b3db8 c1b57e97 c1b57e97 00000000 00000000
[ 52.242900] 00000016
[ 52.242900] 00000016 00000000 00000000 d0f80980 d0f80980 d22b3ddc d22b3ddc c11922d4 c11922d4 c1eb9c6c c1eb9c6c ee6b2800 ee6b2800 00000000 00000000
[ 52.242900] d22b3e78
[ 52.242900] d22b3e78 d0f80980 d0f80980 d0f80580 d0f80580 00000001 00000001 d22b3df8 d22b3df8 c1144e59 c1144e59 c1191f59 c1191f59 d0f805e0 d0f805e0
[ 52.242900] Call Trace:
[ 52.242900] Call Trace:
[ 52.242900] [<c1b5d1fe>] dump_stack+0xb8/0x108
[ 52.242900] [<c1b5d1fe>] dump_stack+0xb8/0x108
[ 52.242900] [<c1b57e97>] panic+0x143/0x404
[ 52.242900] [<c1b57e97>] panic+0x143/0x404
[ 52.242900] [<c11922d4>] watchdog_timer_fn+0x37b/0x3ce
[ 52.242900] [<c11922d4>] watchdog_timer_fn+0x37b/0x3ce
[ 52.242900] [<c1144e59>] __run_hrtimer+0x53b/0xdb8
[ 52.242900] [<c1144e59>] __run_hrtimer+0x53b/0xdb8
[ 52.242900] [<c1191f59>] ? watchdog+0x6a/0x6a
[ 52.242900] [<c1191f59>] ? watchdog+0x6a/0x6a
[ 52.242900] [<c1146477>] hrtimer_run_queues+0x103/0x157
[ 52.242900] [<c1146477>] hrtimer_run_queues+0x103/0x157
[ 52.242900] [<c11430db>] run_local_timers+0x1b/0x43
[ 52.242900] [<c11430db>] run_local_timers+0x1b/0x43
[ 52.242900] [<c1143140>] update_process_times+0x3d/0xba
[ 52.242900] [<c1143140>] update_process_times+0x3d/0xba
[ 52.242900] [<c115c050>] tick_periodic+0x148/0x170
[ 52.242900] [<c115c050>] tick_periodic+0x148/0x170
[ 52.242900] [<c115c277>] tick_handle_periodic+0x30/0xd7
[ 52.242900] [<c115c277>] tick_handle_periodic+0x30/0xd7
[ 52.242900] [<c10410a9>] local_apic_timer_interrupt+0x7e/0x91
[ 52.242900] [<c10410a9>] local_apic_timer_interrupt+0x7e/0x91
[ 52.242900] [<c1041b25>] smp_apic_timer_interrupt+0x5d/0x88
[ 52.242900] [<c1041b25>] smp_apic_timer_interrupt+0x5d/0x88
[ 52.242900] [<c1b72913>] apic_timer_interrupt+0x2f/0x34
[ 52.242900] [<c1b72913>] apic_timer_interrupt+0x2f/0x34
[ 52.242900] [<c10e007b>] ? nsec_high+0x82/0xa8
[ 52.242900] [<c10e007b>] ? nsec_high+0x82/0xa8
[ 52.242900] [<c112260e>] ? rcu_nmi_exit+0x1ae/0x1ae
[ 52.242900] [<c112260e>] ? rcu_nmi_exit+0x1ae/0x1ae
[ 52.242900] [<c112266b>] ? rcu_is_watching+0x2b/0x50
[ 52.242900] [<c112266b>] ? rcu_is_watching+0x2b/0x50
[ 52.242900] [<c111f492>] rcu_read_lock_held+0x47/0xaa
[ 52.242900] [<c111f492>] rcu_read_lock_held+0x47/0xaa
[ 52.242900] [<c14ebf56>] thread_lookup_test+0x4d8/0x6ea
[ 52.242900] [<c14ebf56>] thread_lookup_test+0x4d8/0x6ea
[ 52.242900] [<c14ed0cf>] threadfunc+0xf67/0x1380
[ 52.242900] [<c14ed0cf>] threadfunc+0xf67/0x1380
[ 52.242900] [<c14ec168>] ? thread_lookup_test+0x6ea/0x6ea
[ 52.242900] [<c14ec168>] ? thread_lookup_test+0x6ea/0x6ea
[ 52.242900] [<c14ec168>] ? thread_lookup_test+0x6ea/0x6ea
[ 52.242900] [<c14ec168>] ? thread_lookup_test+0x6ea/0x6ea
[ 52.242900] [<c10a928f>] kthread+0x151/0x164
[ 52.242900] [<c10a928f>] kthread+0x151/0x164
[ 52.242900] [<c1b70da1>] ? _raw_spin_unlock_irq+0x5f/0x99
[ 52.242900] [<c1b70da1>] ? _raw_spin_unlock_irq+0x5f/0x99
[ 52.242900] [<c1b71cc1>] ret_from_kernel_thread+0x21/0x30
[ 52.242900] [<c1b71cc1>] ret_from_kernel_thread+0x21/0x30
[ 52.242900] [<c10a913e>] ? kthread_stop+0x8db/0x8db
[ 52.242900] [<c10a913e>] ? kthread_stop+0x8db/0x8db
[ 52.242900] Kernel Offset: disabled
[ 52.242900] Kernel Offset: disabled
git bisect start f51955394f18bb091cf4381e77094d97d1ba6cce c13dcf9f2d6f5f06ef1bf79ec456df614c5e058b --
git bisect bad 7417d6ced7c8176546d076c8c411cce6c5466f01 # 14:33 0- 9 Merge 'arm-soc/next/soc' into devel-spot-201508271354
git bisect bad 56765655282f225f6602464632009c7f4ba9941d # 14:34 0- 4 Merge 'dledford/applied/mlx4-for-4.3' into devel-spot-201508271354
git bisect bad 2721a327a10e8dcafe0b148648158744f0a6d366 # 14:34 0- 5 Merge 'cgroup/for-4.3' into devel-spot-201508271354
git bisect bad 591c1cae093a84f34af29db68d0273e6724560fe # 14:34 0- 4 Merge 'amirv/for-upstream' into devel-spot-201508271354
git bisect good 185891c7f048c39abc6335b00b27e12d68feed65 # 14:34 910+ 0 Merge 'pm/bleeding-edge' into devel-spot-201508271354
git bisect bad 4afd181cb81fb1b788ad352156822128876b5921 # 14:34 0- 3 Merge 'tj-libata/for-next' into devel-spot-201508271354
git bisect bad 40e118d8076713b7886d3e06caf035f008fcb16c # 14:34 0- 5 Merge 'jkirsher-next-queue/dev-queue' into devel-spot-201508271354
git bisect good 0208bc8803918d7e84f247f1d4f1730171a24c16 # 14:34 910+ 0 Bluetooth: Fix breakage in amp_write_rem_assoc_frag()
git bisect bad e01286ef03a9c7b1d4937309f923c226ab05bc4d # 14:34 0- 2 ipv4: Make fib_encap_match static
git bisect good 2bd736fa0d8a1da90e6ccaa6a79e56a8d2ae60c4 # 14:34 910+ 0 Merge tag 'mac80211-next-for-davem-2015-08-14' of git://git.kernel.org/pub/scm/linux/kernel/git/jberg/mac80211-next
git bisect bad abc5d1ff3e8f9b4a9d274818459b123e31981dc9 # 14:34 0- 4 net: Add inet_proto_csum_replace_by_diff utility function
git bisect good c0015bf3a34961342a27b021672049e535ab36a1 # 14:34 910+ 0 ieee802154: 6lowpan: fix non-lowpan wpan interfaces
git bisect bad 863960b4c5c564819b153d53cffdf3f68283eaa2 # 14:34 0- 36 Merge branch 'enic-devcmd2'
git bisect good 3f1e08d0ae6746379b9e21264dae52f4f35c7ad2 # 14:34 910+ 0 batman-adv: remove broadcast packets scheduled for purged outgoing if
git bisect bad 2ea273d76a4869c097c6b1a1070162add2f66a6e # 14:34 0- 45 net: Export bpf_prog_create_from_user().
git bisect good c1f066d4ee0bde4bb0ff4ac295218b631729e0de # 14:34 1009+ 0 Merge tag 'batman-adv-for-davem' of git://git.open-mesh.org/linux-merge
git bisect bad ec120da6f0fe59f175c2a8faa0a7700280c39644 # 14:34 0- 56 ipv6: trivial whitespace fix
git bisect bad f4a3e90ba5739cfd761b6befadae9728bd3641ed # 14:34 0- 66 rhashtable-test: extend to test concurrency
# first bad commit: [f4a3e90ba5739cfd761b6befadae9728bd3641ed] rhashtable-test: extend to test concurrency
git bisect good c1f066d4ee0bde4bb0ff4ac295218b631729e0de # 14:35 1009+ 0 Merge tag 'batman-adv-for-davem' of git://git.open-mesh.org/linux-merge
# extra tests with DEBUG_INFO
git bisect bad f4a3e90ba5739cfd761b6befadae9728bd3641ed # 14:35 0- 103 rhashtable-test: extend to test concurrency
# extra tests on HEAD of linux-devel/devel-spot-201508271354
git bisect bad f51955394f18bb091cf4381e77094d97d1ba6cce # 14:35 0- 9 0day head guard for 'devel-spot-201508271354'
# extra tests on tree/branch bluetooth/master
git bisect bad 2573d78872f242a05b842e9c553da45a3d9924e5 # 14:44 62- 1 Merge branch 'ovs-vport-cleanup'
# extra tests with first bad commit reverted
git bisect good bd0944fd8c9b40317add8cd18d7515c43abc7a7c # 16:49 910+ 0 Revert "rhashtable-test: extend to test concurrency"
# extra tests on tree/branch linus/master
git bisect good 9751a9e449da2a7749d89968039d532c615beeaa # 18:32 910+ 0 thermal: power_allocator: allocate with kcalloc what you free with kfree
# extra tests on tree/branch linux-next/master
git bisect bad d1c9b4e0a86149145e56e3f65a4287a2397ea028 # 18:32 0- 110 Add linux-next specific files for 20150828
This script may reproduce the error.
----------------------------------------------------------------------------
#!/bin/bash
kernel=$1
initrd=quantal-core-i386.cgz
wget --no-clobber https://github.com/fengguang/reproduce-kernel-bug/raw/master/initrd/$initrd
kvm=(
qemu-system-x86_64
-enable-kvm
-cpu kvm64
-kernel $kernel
-initrd $initrd
-m 300
-smp 2
-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
systemd.log_level=err
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[*]}"
----------------------------------------------------------------------------
---
0-DAY kernel test infrastructure Open Source Technology Center
https://lists.01.org/pipermail/lkp Intel Corporation
View attachment "dmesg-quantal-intel12-23:20150829023830:i386-randconfig-c0-08271836:4.2.0-rc6-00979-gf4a3e90:1" of type "text/plain" (80154 bytes)
View attachment "config-4.2.0-rc6-00979-gf4a3e90" of type "text/plain" (81095 bytes)
Powered by blists - more mailing lists