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>] [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

Powered by Openwall GNU/*/Linux Powered by OpenVZ