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: <20180508052947.GA30203@yexl-desktop>
Date:   Tue, 8 May 2018 13:29:47 +0800
From:   kernel test robot <xiaolong.ye@...el.com>
To:     "Paul E. McKenney" <paulmck@...ux.vnet.ibm.com>
Cc:     LKML <linux-kernel@...r.kernel.org>,
        "Paul E. McKenney" <paulmck@...ux.vnet.ibm.com>, lkp@...org
Subject: [lkp-robot] [EXP rcu]  21560e1007:
 WARNING:possible_recursive_locking_detected


FYI, we noticed the following commit (built with gcc-7):

commit: 21560e10077bf9f7baf69aa82527850271173862 ("EXP rcu: Diagnostics for grace-period hangs")
https://git.kernel.org/cgit/linux/kernel/git/paulmck/linux-rcu.git dev.2018.05.01a

in testcase: ebizzy
with following parameters:

	nr_threads: 200%
	iterations: 100x
	duration: 10s

test-description: ebizzy is designed to generate a workload resembling common web application server workloads.
test-url: http://ebizzy.sourceforge.net/


on test machine: qemu-system-x86_64 -enable-kvm -cpu kvm64,+ssse3 -m 1G

caused below changes (please refer to attached dmesg/kmsg for entire log/backtrace):


+---------------------------------------------+------------+------------+
|                                             | ed569311d8 | 21560e1007 |
+---------------------------------------------+------------+------------+
| boot_successes                              | 4          | 4          |
| boot_failures                               | 8          | 8          |
| invoked_oom-killer:gfp_mask=0x              | 8          |            |
| Mem-Info                                    | 8          |            |
| Out_of_memory:Kill_process                  | 8          |            |
| WARNING:possible_recursive_locking_detected | 0          | 8          |
| RIP:arch_local_irq_restore                  | 0          | 5          |
| BUG:kernel_hang_in_boot_stage               | 0          | 8          |
| RIP:__mutex_unlock_slowpath                 | 0          | 1          |
| RIP:kernfs_activate                         | 0          | 1          |
| RIP:debug_lockdep_rcu_enabled               | 0          | 1          |
+---------------------------------------------+------------+------------+



[    2.079791] WARNING: possible recursive locking detected
[    2.080000] 4.17.0-rc1-00048-g21560e1 #1 Not tainted
[    2.080000] --------------------------------------------
[    2.080000] swapper/0/1 is trying to acquire lock:
[    2.080000] 000000007895dd2f (rcu_node_0){..-.}, at: rcu_process_callbacks+0x4b3/0xa28
[    2.080000] 
[    2.080000] but task is already holding lock:
[    2.080000] 000000007895dd2f (rcu_node_0){..-.}, at: rcu_process_callbacks+0x3cf/0xa28
[    2.080000] 
[    2.080000] other info that might help us debug this:
[    2.080000]  Possible unsafe locking scenario:
[    2.080000] 
[    2.080000]        CPU0
[    2.080000]        ----
[    2.080000]   lock(rcu_node_0);
[    2.080000]   lock(rcu_node_0);
[    2.080000] 
[    2.080000]  *** DEADLOCK ***
[    2.080000] 
[    2.080000]  May be due to missing lock nesting notation
[    2.080000] 
[    2.080000] 1 lock held by swapper/0/1:
[    2.080000]  #0: 000000007895dd2f (rcu_node_0){..-.}, at: rcu_process_callbacks+0x3cf/0xa28
[    2.080000] 
[    2.080000] stack backtrace:
[    2.080000] CPU: 0 PID: 1 Comm: swapper/0 Not tainted 4.17.0-rc1-00048-g21560e1 #1
[    2.080000] Call Trace:
[    2.080000]  <IRQ>
[    2.080000]  dump_stack+0x117/0x182
[    2.080000]  validate_chain+0x8d4/0xec0
[    2.080000]  ? lookup_chain_cache+0x4a/0x9c
[    2.080000]  ? validate_chain+0x9e/0xec0
[    2.080000]  ? lookup_chain_cache+0x4a/0x9c
[    2.080000]  ? lookup_chain_cache+0x4a/0x9c
[    2.080000]  ? lookup_chain_cache+0x4a/0x9c
[    2.080000]  ? __lock_acquire+0x8ed/0x9da
[    2.080000]  __lock_acquire+0x8ed/0x9da
[    2.080000]  lock_acquire+0x9e/0xcd
[    2.080000]  ? rcu_process_callbacks+0x4b3/0xa28
[    2.080000]  _raw_spin_lock_irqsave+0x60/0x88
[    2.080000]  ? rcu_process_callbacks+0x4b3/0xa28
[    2.080000]  rcu_process_callbacks+0x4b3/0xa28
[    2.080000]  ? kvm_clock_read+0x2f/0x45
[    2.080000]  ? kvm_sched_clock_read+0xc/0x1b
[    2.080000]  ? paravirt_sched_clock+0xc/0x16
[    2.080000]  ? sched_clock+0xc/0x14
[    2.080000]  ? sched_clock_local+0x10/0xb8
[    2.080000]  __do_softirq+0x134/0x303
[    2.080000]  irq_exit+0x92/0x143
[    2.080000]  smp_apic_timer_interrupt+0xb9/0xcb
[    2.080000]  apic_timer_interrupt+0xf/0x20
[    2.080000]  </IRQ>
[    2.080000] RIP: 0010:arch_local_irq_restore+0x9/0x16
[    2.080000] RSP: 0000:ffff88000fe63ce0 EFLAGS: 00000206 ORIG_RAX: ffffffffffffff13
[    2.080000] RAX: ffff88000fe58040 RBX: 0000000000000206 RCX: ffff88000fe63b1c
[    2.080000] RDX: 0000000000000001 RSI: 0000000000000001 RDI: 0000000000000206
[    2.080000] RBP: ffff8800346be9b8 R08: ffff8800346beba8 R09: 0000000100080005
[    2.080000] R10: ffff88000fe63ce8 R11: 0000000000000000 R12: 00000000014080c0
[    2.080000] R13: ffffffff812c4f20 R14: ffff88000fcac5c0 R15: 0000000000000000
[    2.080000]  ? __kernfs_new_node+0x56/0x177
[    2.080000]  __slab_alloc+0xa1/0xb2
[    2.080000]  ? __kernfs_new_node+0x56/0x177
[    2.080000]  kmem_cache_alloc+0xe6/0x12c
[    2.080000]  __kernfs_new_node+0x56/0x177
[    2.080000]  kernfs_new_node+0x1d/0x4e
[    2.080000]  __kernfs_create_file+0x38/0x11c
[    2.080000]  sysfs_add_file_mode_ns+0x10a/0x238
[    2.080000]  internal_create_group+0x245/0x404
[    2.080000]  sysfs_create_group+0x11/0x19
[    2.080000]  param_sysfs_init+0x479/0x520
[    2.080000]  ? trace_hardirqs_on_caller+0x219/0x2bc
[    2.080000]  ? trace_hardirqs_on+0x17/0x1f
[    2.080000]  ? locate_module_kobject+0x125/0x125
[    2.080000]  do_one_initcall+0xb4/0x214
[    2.080000]  kernel_init_freeable+0x36a/0x480
[    2.080000]  ? rest_init+0x130/0x130
[    2.080000]  kernel_init+0xc/0x1a0
[    2.080000]  ret_from_fork+0x3a/0x50
BUG: kernel hang in boot stage

Elapsed time: 830

#!/bin/bash

# To reproduce,
# 1) save job-script and this script (both are attached in 0day report email)
# 2) run this script with your compiled kernel and optional env $INSTALL_MOD_PATH

kernel=$1

initrds=(
	/osimage/debian/debian-x86_64-2016-08-31.cgz
	/lkp/lkp/lkp-x86_64.cgz
	/osimage/deps/debian-x86_64-2016-08-31.cgz/run-ipconfig_2016-11-15.cgz
	/osimage/deps/debian-x86_64-2016-08-31.cgz/lkp_2018-04-19.cgz
	/osimage/deps/debian-x86_64-2016-08-31.cgz/rsync-rootfs_2016-11-15.cgz
	/osimage/pkg/debian-x86_64-2016-08-31.cgz/ebizzy-x86_64_2016-11-16.cgz
	/osimage/deps/debian-x86_64-2016-08-31.cgz/mpstat_2017-12-25.cgz
	/osimage/deps/debian-x86_64-2016-08-31.cgz/turbostat_2016-11-15.cgz
	/osimage/pkg/debian-x86_64-2016-08-31.cgz/turbostat-x86_64-d5256b2_2017-06-20.cgz
	/osimage/deps/debian-x86_64-2016-08-31.cgz/perf_2018-04-04.cgz


To reproduce:

        git clone https://github.com/intel/lkp-tests.git
        cd lkp-tests
        bin/lkp qemu -k <bzImage> job-script # job-script is attached in this email



Thanks,
Xiaolong

View attachment "config-4.17.0-rc1-00048-g21560e1" of type "text/plain" (123713 bytes)

View attachment "job-script" of type "text/plain" (6439 bytes)

Download attachment "dmesg.xz" of type "application/x-xz" (7072 bytes)

Powered by blists - more mailing lists

Powered by Openwall GNU/*/Linux Powered by OpenVZ