FYI, we noticed the following commit: commit: ddb06e08fa10ed5030285267a9b1e25d40c337c8 ("perf: Grab event_mutex before taking get_online_cpus()") https://git.kernel.org/cgit/linux/kernel/git/rostedt/linux-trace.git tip/cpuhotplug in testcase: trinity with following parameters: runtime: 300s test-description: Trinity is a linux system call fuzz tester. test-url: http://codemonkey.org.uk/projects/trinity/ on test machine: qemu-system-x86_64 -enable-kvm -cpu Westmere -m 512M caused below changes (please refer to attached dmesg/kmsg for entire log/backtrace): +-----------------------------------------------------------------------------------------------------+------------+------------+ | | db4d3deeb5 | ddb06e08fa | +-----------------------------------------------------------------------------------------------------+------------+------------+ | boot_successes | 0 | 1 | | boot_failures | 2 | 16 | | invoked_oom-killer:gfp_mask=0x | 2 | | | Mem-Info | 2 | | | Out_of_memory:Kill_process | 2 | | | page_allocation_failure:order:#,mode:#(GFP_KERNEL_ACCOUNT|__GFP_ZERO|__GFP_NOTRACK),nodemask=(null) | 2 | | | page_allocation_failure:order:#,mode:#(GFP_KERNEL|__GFP_COMP|__GFP_NOTRACK),nodemask=(null) | 1 | | | Kernel_panic-not_syncing:Out_of_memory_and_no_killable_processes | 1 | | | INFO:possible_recursive_locking_detected | 0 | 16 | | calltrace:SyS_perf_event_open | 0 | 16 | | INFO:task_blocked_for_more_than#seconds | 0 | 16 | | INFO:lockdep_is_turned_off | 0 | 16 | | Kernel_panic-not_syncing:hung_task:blocked_tasks | 0 | 16 | +-----------------------------------------------------------------------------------------------------+------------+------------+ [ 21.793133] [ INFO: possible recursive locking detected ] [ 21.794139] 4.11.0-07685-gddb06e0 #1 Not tainted [ 21.795057] --------------------------------------------- [ 21.796115] trinity-main/2199 is trying to acquire lock: [ 21.797136] (event_mutex){+.+.+.}, at: [] SyS_perf_event_open+0xb13/0xe0e [ 21.798848] [ 21.798848] but task is already holding lock: [ 21.800353] (event_mutex){+.+.+.}, at: [] SyS_perf_event_open+0x545/0xe0e [ 21.802157] [ 21.802157] other info that might help us debug this: [ 21.803713] Possible unsafe locking scenario: [ 21.803713] [ 21.805310] CPU0 [ 21.806041] ---- [ 21.806760] lock(event_mutex); [ 21.807563] lock(event_mutex); [ 21.808424] [ 21.808424] *** DEADLOCK *** [ 21.808424] [ 21.810301] May be due to missing lock nesting notation [ 21.810301] [ 21.811959] 1 lock held by trinity-main/2199: [ 21.813040] #0: (event_mutex){+.+.+.}, at: [] SyS_perf_event_open+0x545/0xe0e [ 21.814896] [ 21.814896] stack backtrace: [ 21.816338] CPU: 0 PID: 2199 Comm: trinity-main Not tainted 4.11.0-07685-gddb06e0 #1 [ 21.817983] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.9.3-20161025_171302-gandalf 04/01/2014 [ 21.819938] Call Trace: [ 21.820740] dump_stack+0x86/0xc0 [ 21.821555] __lock_acquire+0x86b/0xe43 [ 21.822396] lock_acquire+0x142/0x1dd [ 21.823258] ? SyS_perf_event_open+0xb13/0xe0e [ 21.824238] __mutex_lock+0x8a/0x815 [ 21.825120] ? SyS_perf_event_open+0xb13/0xe0e [ 21.826105] ? __lock_acquire+0xd44/0xe43 [ 21.826960] ? SyS_perf_event_open+0xb13/0xe0e [ 21.827914] ? kvm_sched_clock_read+0x9/0x12 [ 21.828852] ? SyS_perf_event_open+0xb05/0xe0e [ 21.829795] mutex_lock_nested+0x1b/0x1d [ 21.830713] ? mutex_lock_nested+0x1b/0x1d [ 21.831672] SyS_perf_event_open+0xb13/0xe0e [ 21.832789] do_int80_syscall_32+0x66/0x113 [ 21.833801] entry_INT80_compat+0x38/0x50 [ 21.834730] RIP: 0023:0x8090aa2 [ 21.835690] RSP: 002b:00000000ffd91718 EFLAGS: 00000282 ORIG_RAX: 0000000000000150 [ 21.837569] RAX: ffffffffffffffda RBX: 0000000008b46258 RCX: 00000000ffffffff [ 21.838823] RDX: 00000000ffffffff RSI: 00000000ffffffff RDI: 0000000000000000 [ 21.840184] RBP: 000000006d656d0c R08: 0000000000000000 R09: 0000000000000000 [ 21.841573] R10: 0000000000000000 R11: 0000000000000000 R12: 0000000000000000 [ 21.842948] R13: 0000000000000000 R14: 0000000000000000 R15: 0000000000000000 [ 246.812621] INFO: task trinity-main:2199 blocked for more than 120 seconds. [ 246.814685] Not tainted 4.11.0-07685-gddb06e0 #1 [ 246.816679] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [ 246.819759] trinity-main D12856 2199 2196 0x20020000 [ 246.821837] Call Trace: [ 246.823075] __schedule+0x8cd/0xa60 [ 246.824563] schedule+0x89/0x9a [ 246.825840] schedule_preempt_disabled+0x15/0x1e [ 246.827417] __mutex_lock+0x595/0x815 [ 246.832245] ? __lock_acquire+0xd44/0xe43 [ 246.833692] ? SyS_perf_event_open+0xb13/0xe0e [ 246.835159] mutex_lock_nested+0x1b/0x1d [ 246.836516] ? mutex_lock_nested+0x1b/0x1d [ 246.837905] SyS_perf_event_open+0xb13/0xe0e [ 246.839346] do_int80_syscall_32+0x66/0x113 [ 246.840747] entry_INT80_compat+0x38/0x50 [ 246.842185] RIP: 0023:0x8090aa2 [ 246.843460] RSP: 002b:00000000ffd91718 EFLAGS: 00000282 ORIG_RAX: 0000000000000150 [ 246.846051] RAX: ffffffffffffffda RBX: 0000000008b46258 RCX: 00000000ffffffff [ 246.847941] RDX: 00000000ffffffff RSI: 00000000ffffffff RDI: 0000000000000000 [ 246.849835] RBP: 000000006d656d0c R08: 0000000000000000 R09: 0000000000000000 [ 246.851757] R10: 0000000000000000 R11: 0000000000000000 R12: 0000000000000000 [ 246.853668] R13: 0000000000000000 R14: 0000000000000000 R15: 0000000000000000 [ 246.855639] INFO: lockdep is turned off. [ 246.857038] NMI backtrace for cpu 0 [ 246.858324] CPU: 0 PID: 642 Comm: khungtaskd Not tainted 4.11.0-07685-gddb06e0 #1 [ 246.860829] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.9.3-20161025_171302-gandalf 04/01/2014 [ 246.863767] Call Trace: [ 246.864863] dump_stack+0x86/0xc0 [ 246.866310] nmi_cpu_backtrace+0x7f/0x9c [ 246.867641] ? irq_force_complete_move+0xeb/0xeb [ 246.869144] nmi_trigger_cpumask_backtrace+0x62/0xc6 [ 246.870701] arch_trigger_cpumask_backtrace+0x19/0x1b [ 246.872273] watchdog+0x46f/0x538 [ 246.873497] ? reset_hung_task_detector+0x15/0x15 [ 246.874953] kthread+0x134/0x13c [ 246.876174] ? kthread_create_on_node+0x3f/0x3f [ 246.877605] ret_from_fork+0x31/0x40 [ 246.878918] Kernel panic - not syncing: hung_task: blocked tasks [ 246.880620] CPU: 0 PID: 642 Comm: khungtaskd Not tainted 4.11.0-07685-gddb06e0 #1 [ 246.883126] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.9.3-20161025_171302-gandalf 04/01/2014 [ 246.886076] Call Trace: [ 246.887174] dump_stack+0x86/0xc0 [ 246.888404] panic+0xdd/0x221 [ 246.889614] watchdog+0x47b/0x538 [ 246.890891] ? reset_hung_task_detector+0x15/0x15 [ 246.892398] kthread+0x134/0x13c [ 246.893606] ? kthread_create_on_node+0x3f/0x3f [ 246.895029] ret_from_fork+0x31/0x40 [ 246.896365] Kernel Offset: 0x1b000000 from 0xffffffff81000000 (relocation range: 0xffffffff80000000-0xffffffffbfffffff) Elapsed time: 250 initrds=( /osimage/yocto/yocto-tiny-i386-2016-04-22.cgz /lkp/scheduled/vm-kbuild-yocto-ia32-4/trinity-300s-yocto-tiny-i386-2016-04-22.cgz-ddb06e08fa10ed5030285267a9b1e25d40c337c8-20170515-76824-r0qdn3-0.cgz /lkp/lkp/lkp-i386.cgz /osimage/deps/debian-x86_64-2016-08-31.cgz/run-ipconfig.i386_2016-09-03.cgz /osimage/pkg/static/trinity-i386.cgz /pkg/linux/x86_64-nfsroot+CONFIG_DEBUG_INFO_REDUCED/gcc-6/ddb06e08fa10ed5030285267a9b1e25d40c337c8/modules.cgz ) cat "${initrds[@]}" > /fs/sdd1/initrd-vm-kbuild-yocto-ia32-4 kvm=( qemu-system-x86_64 -enable-kvm -cpu Westmere -kernel /pkg/linux/x86_64-nfsroot+CONFIG_DEBUG_INFO_REDUCED/gcc-6/ddb06e08fa10ed5030285267a9b1e25d40c337c8/vmlinuz-4.11.0-07685-gddb06e0 -initrd /fs/sdd1/initrd-vm-kbuild-yocto-ia32-4 -m 512 -smp 1 -device e1000,netdev=net0 -netdev user,id=net0 -boot order=nc -no-reboot -watchdog i6300esb -watchdog-action debug -rtc base=localtime -drive file=/fs/sdd1/disk0-vm-kbuild-yocto-ia32-4,media=disk,if=virtio -pidfile /dev/shm/kboot/pid-vm-kbuild-yocto-ia32-4 -serial file:/dev/shm/kboot/vm-kbuild-yocto-ia32-4/serial -serial file:/dev/shm/kboot/vm-kbuild-yocto-ia32-4/kmsg -daemonize -display none -monitor null ) append=( ip=::::vm-kbuild-yocto-ia32-4::dhcp root=/dev/ram0 user=lkp job=/lkp/scheduled/vm-kbuild-yocto-ia32-4/trinity-300s-yocto-tiny-i386-2016-04-22.cgz-ddb06e08fa10ed5030285267a9b1e25d40c337c8-20170515-76824-r0qdn3-0.yaml ARCH=x86_64 kconfig=x86_64-nfsroot+CONFIG_DEBUG_INFO_REDUCED branch=trace/tip/cpuhotplug commit=ddb06e08fa10ed5030285267a9b1e25d40c337c8 BOOT_IMAGE=/pkg/linux/x86_64-nfsroot+CONFIG_DEBUG_INFO_REDUCED/gcc-6/ddb06e08fa10ed5030285267a9b1e25d40c337c8/vmlinuz-4.11.0-07685-gddb06e0 max_uptime=1500 RESULT_ROOT=/result/trinity/300s/vm-kbuild-yocto-ia32/yocto-tiny-i386-2016-04-22.cgz/x86_64-nfsroot+CONFIG_DEBUG_INFO_REDUCED/gcc-6/ddb06e08fa10ed5030285267a9b1e25d40c337c8/0 LKP_SERVER=inn debug apic=debug sysrq_always_enabled rcupdate.rcu_cpu_stall_timeout=100 net.ifnames=0 printk.devkmsg=on panic=-1 softlockup_panic=1 nmi_watchdog=panic oops=panic load_ramdisk=2 prompt_ramdisk=0 drbd.minor_count=8 systemd.log_level=err ignore_loglevel earlyprintk=ttyS0,115200 console=ttyS0,115200 console=tty0 vga=normal rw drbd.minor_count=8 ) To reproduce: git clone https://github.com/01org/lkp-tests.git cd lkp-tests bin/lkp qemu -k job-script # job-script is attached in this email Thanks, Kernel Test Robot