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] 
Date:	Mon, 14 Sep 2015 14:45:57 +0800
From:	Fengguang Wu <fengguang.wu@...el.com>
To:	Phil Sutter <phil@....cc>
Cc:	linux-kernel@...r.kernel.org, LKP <lkp@...org>
Subject: [rhashtable-test] RIP: 0010:[<ffffffff89b0bd65>]
 [<ffffffff89b0bd65>] arch_local_irq_save

Greetings,

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

https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.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 | v4.2_091304 |
+------------------------------------------------+------------+------------+-------------+
| boot_successes                                 | 1009       | 695        | 115         |
| boot_failures                                  | 0          | 215        | 30          |
| RIP:arch_local_irq_save                        | 0          | 22         | 2           |
| Kernel_panic-not_syncing:softlockup:hung_tasks | 0          | 215        | 30          |
| backtrace:threadfunc                           | 0          | 215        | 30          |
| RIP:arch_local_irq_restore                     | 0          | 103        | 15          |
| RIP:__rcu_is_watching                          | 0          | 2          |             |
| RIP:rht_key_hashfn                             | 0          | 6          |             |
| RIP:__local_bh_disable_ip                      | 0          | 1          |             |
| RIP:debug_lockdep_rcu_enabled                  | 0          | 16         | 1           |
| RIP:rhashtable_lookup_fast                     | 0          | 15         | 1           |
| RIP:arch_local_save_flags                      | 0          | 8          | 1           |
| RIP:rcu_read_unlock                            | 0          | 2          |             |
| RIP:arch_local_irq_enable                      | 0          | 2          | 1           |
| RIP:rcu_is_watching                            | 0          | 13         | 1           |
| RIP:jhash                                      | 0          | 2          | 1           |
| RIP:lock_is_held                               | 0          | 23         | 5           |
| RIP:lockdep_rht_mutex_is_held                  | 0          | 5          | 2           |
| RIP:rcu_lockdep_current_cpu_online             | 0          | 12         | 3           |
| RIP:rcu_read_lock_held                         | 0          | 24         | 3           |
| RIP:lock_release                               | 0          | 2          |             |
| RIP:rht_head_hashfn                            | 0          | 2          |             |
| RIP:thread_lookup_test                         | 0          | 1          |             |
| RIP:do_raw_spin_lock                           | 0          | 1          |             |
| RIP:_raw_spin_unlock_bh                        | 0          | 1          |             |
| RIP:lockdep_rht_bucket_is_held                 | 0          | 1          | 1           |
| RIP:lock_acquire                               | 0          | 2          |             |
| backtrace:ret_from_fork                        | 0          | 3          | 1           |
| RIP:rhashtable_remove_fast                     | 0          | 2          |             |
| RIP:do_raw_spin_unlock                         | 0          | 0          | 1           |
+------------------------------------------------+------------+------------+-------------+

[   15.813271] Average test time: 2387686602
[   15.817585] Testing concurrent rhashtable access from 10 threads
[   36.086756] NMI watchdog: BUG: soft lockup - CPU#0 stuck for 22s! [rhashtable_thra:61]
[   36.090052] Modules linked in:
[   36.090052] irq event stamp: 1904398
[   36.090052] hardirqs last  enabled at (1904397): [<ffffffff8a01982f>] restore_c_regs_and_iret+0x0/0x41
[   36.090052] hardirqs last disabled at (1904398): [<ffffffff8a019aab>] apic_timer_interrupt+0x6b/0x80
[   36.090052] softirqs last  enabled at (1904396): [<ffffffff89ac7ff0>] __do_softirq+0x2a7/0x335
[   36.090052] softirqs last disabled at (1904391): [<ffffffff89ac8409>] irq_exit+0x6a/0xaa
[   36.090052] CPU: 0 PID: 61 Comm: rhashtable_thra Not tainted 4.2.0-rc6-00979-gf4a3e90 #1
[   36.090052] task: ffff8800081ae000 ti: ffff880011dc0000 task.ti: ffff880011dc0000
[   36.090052] RIP: 0010:[<ffffffff89b0bd65>]  [<ffffffff89b0bd65>] arch_local_irq_save+0x8/0x3b
[   36.090052] RSP: 0000:ffff880011dc3d38  EFLAGS: 00000206
[   36.090052] RAX: 0000000000000001 RBX: 0000000000000206 RCX: 0000000000000003
[   36.090052] RDX: ffff8800081ae000 RSI: ffffffff8baa7110 RDI: ffffffff8a8c4630
[   36.090052] RBP: ffff880011dc3d58 R08: 000000000a8483c9 R09: 0000000000000000
[   36.090052] R10: 00000000003c61e5 R11: 00000000000000b1 R12: ffff8800081ae678
[   36.090052] R13: 0000000000000000 R14: ffff880011dc3cc8 R15: ffffffffffff650d
[   36.090052] FS:  0000000000000000(0000) GS:ffff880011200000(0000) knlGS:0000000000000000
[   36.090052] CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
[   36.090052] CR2: 00000000ffffffff CR3: 000000000a816000 CR4: 00000000000006b0
[   36.090052] Stack:
[   36.090052]  ffff880011dc3d58 ffffffff89b10c58 0000000030005c67 0000000000000000
[   36.090052]  ffff880011dc3d68 ffffffff89b29e32 ffff880011dc3dc8 ffffffff89cecc87
[   36.090052]  00002e3389cecce2 0000000000000004 ffffffff8baa7000 ffff880011dc3de4
[   36.090052] Call Trace:
[   36.090052]  [<ffffffff89b10c58>] ? lock_is_held+0x34/0x9a
[   36.090052]  [<ffffffff89b29e32>] rcu_read_lock_held+0x67/0x70
[   36.090052]  [<ffffffff89cecc87>] rhashtable_lookup_fast+0x274/0x2da
[   36.090052]  [<ffffffff89cecd41>] thread_lookup_test+0x54/0x11e
[   36.090052]  [<ffffffff89ced06d>] threadfunc+0x262/0x2e9
[   36.090052]  [<ffffffff89cece0b>] ? thread_lookup_test+0x11e/0x11e
[   36.090052]  [<ffffffff89ae8ddf>] kthread+0x133/0x142
[   36.090052]  [<ffffffff89ae8cac>] ? __kthread_parkme+0x102/0x102
[   36.090052]  [<ffffffff8a01908f>] ret_from_fork+0x3f/0x70
[   36.090052]  [<ffffffff89ae8cac>] ? __kthread_parkme+0x102/0x102
[   36.090052] Code: ff 05 48 6f 3c 01 5d c3 55 48 ff 05 46 6f 3c 01 48 89 e5 57 9d 66 66 90 66 90 48 ff 05 3d 6f 3c 01 5d c3 55 48 ff 05 4b 6f 3c 01 <48> 89 e5 e8 ba ff ff ff 48 ff 05 44 6f 3c 01 48 89 c2 48 ff 05 
[   36.090052] Kernel panic - not syncing: softlockup: hung tasks
[   36.090052] CPU: 0 PID: 61 Comm: rhashtable_thra Tainted: G             L  4.2.0-rc6-00979-gf4a3e90 #1
[   36.090052]  0000000000000000 ffff880011203e18 ffffffff8a00f297 ffffffff89b1d179
[   36.090052]  ffffffff8a5dac29 ffff880011203e98 ffffffff8a00c84e 0000000000000001
[   36.090052]  0000000000000008 ffff880011203ea8 ffff880011203e48 ffffffffffffffff
[   36.090052] Call Trace:
[   36.090052]  <IRQ>  [<ffffffff8a00f297>] dump_stack+0x92/0xc7
[   36.090052]  [<ffffffff89b1d179>] ? console_unlock+0x548/0x5a1
[   36.090052]  [<ffffffff8a00c84e>] panic+0x134/0x35b
[   36.090052]  [<ffffffff89b1d179>] ? console_unlock+0x548/0x5a1
[   36.090052]  [<ffffffff89b0af52>] ? up+0x50/0x5c
[   36.090052]  [<ffffffff89b714fc>] watchdog_timer_fn+0x2ee/0x31f
[   36.090052]  [<ffffffff89b33628>] __hrtimer_run_queues+0x106/0x200
[   36.090052]  [<ffffffff89b7120e>] ? watchdog_enable+0xa9/0xa9
[   36.090052]  [<ffffffff89cebcdd>] ? _kstrtol+0x40/0x40
[   36.090052]  [<ffffffff89b33980>] hrtimer_interrupt+0x99/0x1c2
[   36.090052]  [<ffffffff89a7bfac>] local_apic_timer_interrupt+0x6a/0x75
[   36.090052]  [<ffffffff89a7c7a9>] smp_apic_timer_interrupt+0x2e/0x4d
[   36.090052]  [<ffffffff8a019ab0>] apic_timer_interrupt+0x70/0x80
[   36.090052]  <EOI>  [<ffffffff89b0bd65>] ? arch_local_irq_save+0x8/0x3b
[   36.090052]  [<ffffffff89b10c58>] ? lock_is_held+0x34/0x9a
[   36.090052]  [<ffffffff89b29e32>] rcu_read_lock_held+0x67/0x70
[   36.090052]  [<ffffffff89cecc87>] rhashtable_lookup_fast+0x274/0x2da
[   36.090052]  [<ffffffff89cecd41>] thread_lookup_test+0x54/0x11e
[   36.090052]  [<ffffffff89ced06d>] threadfunc+0x262/0x2e9
[   36.090052]  [<ffffffff89cece0b>] ? thread_lookup_test+0x11e/0x11e
[   36.090052]  [<ffffffff89ae8ddf>] kthread+0x133/0x142
[   36.090052]  [<ffffffff89ae8cac>] ? __kthread_parkme+0x102/0x102
[   36.090052]  [<ffffffff8a01908f>] ret_from_fork+0x3f/0x70
[   36.090052]  [<ffffffff89ae8cac>] ? __kthread_parkme+0x102/0x102
[   36.090052] Kernel Offset: 0x8a00000 from 0xffffffff81000000 (relocation range: 0xffffffff80000000-0xffffffffbfffffff)

Elapsed time: 60

git bisect start f866fb40f30c1d8872455ad7a56121bbbb6c68c5 64291f7db5bd8150a74ad2036f1037e6a0428df2 --
git bisect  bad 5ab8261014a672f29b113527302e670bbc1dac96  # 16:49      0-     45  Merge 'linux-gfs2/for-next' into devel-hourly-2015091304
git bisect  bad d58baa095cf7c80027abd1eb7d2b6de81cb16ecb  # 16:49      0-     95  Merge 'jpirko-mlxsw/master' into devel-hourly-2015091304
git bisect  bad 64a079c15ed426ffbd644f7ccb31247207108b26  # 16:50      0-    282  Merge 'pinctrl/devel' into devel-hourly-2015091304
git bisect good 20e1aa8dd2a86889dddf1796b1860fce17c7cc8d  # 17:28    901+      0  Merge 'asoc/topic/spear' into devel-hourly-2015091304
git bisect good 30a8d6905d0997115c817d51424e9d5907502925  # 18:04    910+      3  Merge 'asoc/topic/sti' into devel-hourly-2015091304
git bisect good 51784c9e4e5604717640734b0744549a40f8a1ce  # 18:39    910+      2  Merge 'robh/for-next' into devel-hourly-2015091304
git bisect  bad cdac1ec2fb4203061af7a87d5fb9812905d4e44f  # 18:53    108-     37  Merge 'bluetooth/master' into devel-hourly-2015091304
git bisect good f2e520956a1ab636698f8160194c9b8ac0989aab  # 19:36    909+      0  packet: add extended BPF fanout mode
git bisect  bad 705cc62f6728c5a23e3c82465aa94e652e0b50e4  # 19:50    193-     46  vxlan: provide access function for vxlan socket address family
git bisect good bf27cea49502799be15beab3567ea2bd9901ad2f  # 20:31    909+      0  rtlwifi: rtl8192cu: remove duplicated routine in hw.c and mac.c
git bisect  bad 61ed713bbb043f333ca9576c79a3d33d2ad17438  # 20:38     21-      8  Merge branch 'drivers_iff_no_queue'
git bisect  bad 0aa65cc0c2ca7e3908b1e4ae7946d909a4882249  # 20:54      8-      9  Merge branch 'for-upstream' of git://git.kernel.org/pub/scm/linux/kernel/git/bluetooth/bluetooth-next
git bisect good 62aaefa7d03804aef30639ab362f845b1f3e92ed  # 21:45    903+      0  Bluetooth: hci_bcm: improve use of gpios API
git bisect good c1f066d4ee0bde4bb0ff4ac295218b631729e0de  # 22:26    910+      0  Merge tag 'batman-adv-for-davem' of git://git.open-mesh.org/linux-merge
git bisect  bad 373fb0873d4325a7afa04aec29ced0c122d1f8a9  # 22:33     46-     23  enic: add devcmd2
git bisect  bad 2ea273d76a4869c097c6b1a1070162add2f66a6e  # 22:50     13-      8  net: Export bpf_prog_create_from_user().
git bisect  bad ec120da6f0fe59f175c2a8faa0a7700280c39644  # 23:12     51-     33  ipv6: trivial whitespace fix
git bisect  bad f4a3e90ba5739cfd761b6befadae9728bd3641ed  # 23:37    168-     71  rhashtable-test: extend to test concurrency
# first bad commit: [f4a3e90ba5739cfd761b6befadae9728bd3641ed] rhashtable-test: extend to test concurrency
git bisect good c1f066d4ee0bde4bb0ff4ac295218b631729e0de  # 23:52   1000+      0  Merge tag 'batman-adv-for-davem' of git://git.open-mesh.org/linux-merge
# extra tests with DEBUG_INFO
git bisect  bad f4a3e90ba5739cfd761b6befadae9728bd3641ed  # 00:03     20-     20  rhashtable-test: extend to test concurrency
# extra tests on HEAD of linux-devel/devel-hourly-2015091304
git bisect  bad f866fb40f30c1d8872455ad7a56121bbbb6c68c5  # 00:04      0-     30  0day head guard for 'devel-hourly-2015091304'
# extra tests on tree/branch linus/master
git bisect  bad 6ff33f3902c3b1c5d0db6b1e2c70b6d76fba357f  # 00:26     22-     18  Linux 4.3-rc1
# extra tests with first bad commit reverted
git bisect good 54c6f214f6b64a5d6e895f1f9a71f9ae6d1bbf56  # 01:11   1010+      2  Revert "rhashtable-test: extend to test concurrency"
# extra tests on tree/branch linus/master
git bisect  bad 6ff33f3902c3b1c5d0db6b1e2c70b6d76fba357f  # 01:11      0-    201  Linux 4.3-rc1
# extra tests on tree/branch linux-next/master
git bisect  bad 851a02c2dfa2b3ed55a8027a1955e737d670d42c  # 01:21    100-     42  Add linux-next specific files for 20150912


This script may reproduce the error.

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

kernel=$1
initrd=quantal-core-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 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-2:20150913234234:x86_64-randconfig-n0-09130458:4.2.0-rc6-00979-gf4a3e90:1" of type "text/plain" (32553 bytes)

View attachment "config-4.2.0-rc6-00979-gf4a3e90" of type "text/plain" (89163 bytes)

Powered by blists - more mailing lists