deadlock in perf_ioctl

84 views
Skip to first unread message

Dmitry Vyukov

unread,
Nov 30, 2015, 4:21:09 AM11/30/15
to Peter Zijlstra, Ingo Molnar, Arnaldo Carvalho de Melo, LKML, syzkaller, Alexander Potapenko, Kostya Serebryany, Eric Dumazet, Sasha Levin
Hello,

The following program deadlocks kernel:

// autogenerated by syzkaller (http://github.com/google/syzkaller)
#include <syscall.h>
#include <string.h>
#include <stdint.h>
#include <pthread.h>

void *thr0(void *arg)
{
syscall(SYS_ioctl, arg, 0x2403ul, 0x5ul, 0, 0, 0);
return 0;
}

void *thr1(void *arg)
{
*(uint64_t*)0x20002000 = 0x8;
syscall(SYS_ioctl, arg, 0x40082404ul, 0x20002000ul, 0, 0, 0);
return 0;
}

int main()
{
long r0 = syscall(SYS_mmap, 0x20000000ul, 0x10000ul, 0x3ul,
0x32ul, 0xfffffffffffffffful, 0x0ul);
*(uint32_t*)0x20000fcd = 0x1;
*(uint32_t*)0x20000fd1 = 0x78;
*(uint64_t*)0x20000fd5 = 0x0;
*(uint64_t*)0x20000fdd = 0x7a;
*(uint64_t*)0x20000fe5 = 0x1a;
*(uint64_t*)0x20000fed = 0x4;
*(uint8_t*)0x20000ff5 = 0x1;
*(uint8_t*)0x20000ff6 = 0x2;
*(uint8_t*)0x20000ff7 = 0xb4;
*(uint8_t*)0x20000ff8 = 0x4;
*(uint32_t*)0x20000ff9 = 0x0;
*(uint32_t*)0x20000ffd = 0x2;
*(uint32_t*)0x20001001 = 0x3;
*(uint64_t*)0x20001005 = 0x6;
*(uint64_t*)0x2000100d = 0xd4d3;
*(uint64_t*)0x20001015 = 0x53;
*(uint64_t*)0x2000101d = 0x8;
*(uint64_t*)0x20001025 = 0x6;
*(uint32_t*)0x2000102d = 0x7;
*(uint32_t*)0x20001031 = 0x0;
*(uint64_t*)0x20001035 = 0x7;
*(uint32_t*)0x2000103d = 0x0;
*(uint32_t*)0x20001041 = 0x0;
long r25 = syscall(SYS_perf_event_open, 0x20000fcdul, 0x0ul,
0x3ul, 0xfffffffffffffffful, 0x1ul, 0);
pthread_t th[4];
pthread_create(&th[0], 0, thr0, (void*)r25);
pthread_create(&th[1], 0, thr1, (void*)r25);
pthread_create(&th[2], 0, thr0, (void*)r25);
pthread_create(&th[3], 0, thr1, (void*)r25);
return 0;
}


It causes possible deadlock message followed by full hang up:

=============================================
[ INFO: possible recursive locking detected ]
4.4.0-rc1+ #129 Not tainted
---------------------------------------------
a.out/6283 is trying to acquire lock:
(&ctx->lock){-.....}, at: [<ffffffff815072ce>]
__perf_event_period+0x8e/0x4b0 kernel/events/core.c:4156

but task is already holding lock:
(&ctx->lock){-.....}, at: [< inline >] perf_event_period
kernel/events/core.c:4212
(&ctx->lock){-.....}, at: [< inline >] _perf_ioctl
kernel/events/core.c:4266
(&ctx->lock){-.....}, at: [<ffffffff8152331c>] perf_ioctl+0x7bc/0xcc0
kernel/events/core.c:4320

other info that might help us debug this:
Possible unsafe locking scenario:

CPU0
----
lock(&ctx->lock);
lock(&ctx->lock);

*** DEADLOCK ***

May be due to missing lock nesting notation

2 locks held by a.out/6283:
#0: (&ctx->mutex){+.+...}, at: [<ffffffff8150b2e8>]
perf_event_ctx_lock_nested+0x148/0x2e0 kernel/events/core.c:961
#1: (&ctx->lock){-.....}, at: [< inline >] perf_event_period
kernel/events/core.c:4212
#1: (&ctx->lock){-.....}, at: [< inline >] _perf_ioctl
kernel/events/core.c:4266
#1: (&ctx->lock){-.....}, at: [<ffffffff8152331c>]
perf_ioctl+0x7bc/0xcc0 kernel/events/core.c:4320

stack backtrace:
CPU: 2 PID: 6283 Comm: a.out Not tainted 4.4.0-rc1+ #129
Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS Bochs 01/01/2011
00000000ffffffff ffff88003a1f7a20 ffffffff82745526 0000000000000000
ffffffff87c63e30 ffffffff87c63e30 ffff88003a1f7bb0 ffffffff81344e93
0000048f00000002 ffffffff8758a920 ffff88003906b588 ffffffff00006700
Call Trace:
[< inline >] __dump_stack lib/dump_stack.c:15
[<ffffffff82745526>] dump_stack+0x68/0x92 lib/dump_stack.c:50
[< inline >] print_deadlock_bug kernel/locking/lockdep.c:1752
[< inline >] check_deadlock kernel/locking/lockdep.c:1796
[< inline >] validate_chain kernel/locking/lockdep.c:2128
[<ffffffff81344e93>] __lock_acquire+0x1c73/0x3f00 kernel/locking/lockdep.c:3206
[<ffffffff8134949d>] lock_acquire+0x16d/0x2f0 kernel/locking/lockdep.c:3585
[< inline >] __raw_spin_lock include/linux/spinlock_api_smp.h:144
[<ffffffff85987aa1>] _raw_spin_lock+0x31/0x40 kernel/locking/spinlock.c:151
[<ffffffff815072ce>] __perf_event_period+0x8e/0x4b0 kernel/events/core.c:4156
[< inline >] perf_event_period kernel/events/core.c:4219
[< inline >] _perf_ioctl kernel/events/core.c:4266
[<ffffffff815234a4>] perf_ioctl+0x944/0xcc0 kernel/events/core.c:4320
[< inline >] vfs_ioctl fs/ioctl.c:43
[<ffffffff816a5be1>] do_vfs_ioctl+0x681/0xe40 fs/ioctl.c:607
[< inline >] SYSC_ioctl fs/ioctl.c:622
[<ffffffff816a642f>] SyS_ioctl+0x8f/0xc0 fs/ioctl.c:613
[<ffffffff85988836>] entry_SYSCALL_64_fastpath+0x16/0x7a
arch/x86/entry/entry_64.S:185




BUG: spinlock lockup suspected on CPU#2, a.out/6283
lock: 0xffff880038de9528, .magic: dead4ead, .owner: a.out/6283, .owner_cpu: 2
CPU: 2 PID: 6283 Comm: a.out Not tainted 4.4.0-rc1+ #129
Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS Bochs 01/01/2011
00000000ffffffff ffff88003a1f7bb8 ffffffff82745526 ffff880038de9528
ffff88003906b380 0000000000000002 ffff88003a1f7be8 ffffffff81352f5d
ffff880038de9528 ffff880038de9530 000000009a9d2d40 ffff880038de9538
Call Trace:
[< inline >] __dump_stack lib/dump_stack.c:15
[<ffffffff82745526>] dump_stack+0x68/0x92 lib/dump_stack.c:50
[<ffffffff81352f5d>] spin_dump+0x16d/0x270
kernel/locking/spinlock_debug.c:67 (discriminator 8)
[< inline >] __spin_lock_debug kernel/locking/spinlock_debug.c:117
[<ffffffff8135328e>] do_raw_spin_lock+0x19e/0x320
kernel/locking/spinlock_debug.c:137
[< inline >] __raw_spin_lock include/linux/spinlock_api_smp.h:145
[<ffffffff85987aa9>] _raw_spin_lock+0x39/0x40 kernel/locking/spinlock.c:151
[<ffffffff815072ce>] ? __perf_event_period+0x8e/0x4b0 kernel/events/core.c:4156
[<ffffffff815072ce>] __perf_event_period+0x8e/0x4b0 kernel/events/core.c:4156
[< inline >] perf_event_period kernel/events/core.c:4219
[< inline >] _perf_ioctl kernel/events/core.c:4266
[<ffffffff815234a4>] perf_ioctl+0x944/0xcc0 kernel/events/core.c:4320
[<ffffffff81522b60>] ? SYSC_perf_event_open+0x2060/0x2060
kernel/events/core.c:8192
[<ffffffff81343220>] ? debug_check_no_locks_freed+0x310/0x310
kernel/locking/lockdep.c:4123
[< inline >] ? arch_local_irq_restore
./arch/x86/include/asm/paravirt.h:806
[<ffffffff81349f9d>] ? lock_release+0x7cd/0xbb0 kernel/locking/lockdep.c:3607
[<ffffffff8133a630>] ? check_chain_key+0x2b0/0x4b0
kernel/locking/lockdep.c:2192 (discriminator 9)
[<ffffffff81522b60>] ? SYSC_perf_event_open+0x2060/0x2060
kernel/events/core.c:8192
[< inline >] vfs_ioctl fs/ioctl.c:43
[<ffffffff816a5be1>] do_vfs_ioctl+0x681/0xe40 fs/ioctl.c:607
[<ffffffff816a5560>] ? ioctl_preallocate+0x1d0/0x1d0 fs/ioctl.c:442
[< inline >] ? rcu_lock_release include/linux/rcupdate.h:482
[< inline >] ? rcu_read_unlock include/linux/rcupdate.h:917
[<ffffffff816c4d92>] ? __fget+0x222/0x3a0 fs/file.c:711
[<ffffffff816c4bb7>] ? __fget+0x47/0x3a0 fs/file.c:695
[< inline >] ? __up_read ./arch/x86/include/asm/rwsem.h:156
[<ffffffff813372e5>] ? up_read+0x35/0x40 kernel/locking/rwsem.c:81
[<ffffffff82537ec9>] ? security_file_ioctl+0x89/0xb0
security/security.c:752 (discriminator 6)
BUG: spinlock lockup suspected on CPU#0, a.out/6281
lock: 0xffff880038de9528, .magic: dead4ead, .owner: a.out/6283, .owner_cpu: 2
[< inline >] SYSC_ioctl fs/ioctl.c:622
[<ffffffff816a642f>] SyS_ioctl+0x8f/0xc0 fs/ioctl.c:613
[<ffffffff85988836>] entry_SYSCALL_64_fastpath+0x16/0x7a
arch/x86/entry/entry_64.S:185
CPU: 0 PID: 6281 Comm: a.out Not tainted 4.4.0-rc1+ #129
Sending NMI to all CPUs:
Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS Bochs 01/01/2011
NMI backtrace for cpu 0
CPU: 0 PID: 6281 Comm: a.out Not tainted 4.4.0-rc1+ #129
Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS Bochs 01/01/2011
task: ffff88003906c440 ti: ffff8800392a0000 task.ti: ffff8800392a0000
RIP: 0010:[<ffffffff82aedbfb>] [<ffffffff82aedbfb>] io_serial_in+0x6b/0x90
RSP: 0018:ffff8800392a7650 EFLAGS: 00000006
RAX: dffffc0000000000 RBX: 00000000000003f9 RCX: 0000000000000000
RDX: 00000000000003f9 RSI: 0000000000000001 RDI: ffffffff8821d378
RBP: ffff8800392a7660 R08: 0000000000000001 R09: 0000000000000000
R10: fffffbfff10297a5 R11: 1ffffffff102979d R12: ffffffff8821d340
R13: 0000000000000001 R14: ffffffff82ae84f0 R15: ffffffff86beb880
FS: 0000000000f11880(0063) GS:ffff88003ec00000(0000) knlGS:0000000000000000
CS: 0010 DS: 0000 ES: 0000 CR0: 000000008005003b
CR2: 00007f371237ed90 CR3: 0000000039046000 CR4: 00000000000006f0
Stack:
ffffffff8821d340 ffffffff8821d560 ffff8800392a7788 ffffffff82af9985
0000000000000046 ffff8800392a7758 ffffffff8821d388 ffffffff8814bce0
1ffff10007254ed4 ffffed0000000048 0000000041b58ab3 ffffffff8673a970
Call Trace:
[< inline >] serial_port_in include/linux/serial_core.h:254
[<ffffffff82af9985>] serial8250_console_write+0x1c5/0x800
drivers/tty/serial/8250/8250_port.c:2862
[<ffffffff82af97c0>] ? exar_handle_irq+0x1a0/0x1a0
include/linux/serial_core.h:254
[<ffffffff8276f5a7>] ? sprintf+0xa7/0xd0 lib/vsprintf.c:2109
[<ffffffff8276f500>] ? scnprintf+0x100/0x100 lib/vsprintf.c:2015
[< inline >] ? arch_local_irq_restore
./arch/x86/include/asm/paravirt.h:806
[<ffffffff81349f9d>] ? lock_release+0x7cd/0xbb0 kernel/locking/lockdep.c:3607
[< inline >] ? arch_local_irq_restore
./arch/x86/include/asm/paravirt.h:806
[<ffffffff81349f9d>] ? lock_release+0x7cd/0xbb0 kernel/locking/lockdep.c:3607
[<ffffffff82ae84f0>] ? univ8250_console_setup+0x100/0x100
drivers/tty/serial/8250/8250_core.c:610
[<ffffffff82ae8554>] univ8250_console_write+0x64/0x80
drivers/tty/serial/8250/8250_core.c:594
[<ffffffff81370751>] call_console_drivers.constprop.26+0x231/0x280
kernel/printk/printk.c:1459
[<ffffffff81372362>] console_unlock+0x502/0x9a0 kernel/printk/printk.c:2311
[<ffffffff81372d33>] vprintk_emit+0x533/0x830 kernel/printk/printk.c:1824
[<ffffffff81373308>] vprintk_default+0x28/0x30 kernel/printk/printk.c:1864
[<ffffffff81534308>] printk+0xb2/0xd2 kernel/printk/printk.c:1914
[<ffffffff81534256>] ? power_down+0x11b/0x11b kernel/power/hibernate.c:642
[<ffffffff8162a836>] ? memcpy+0x36/0x40 mm/kasan/kasan.c:299
[<ffffffff81375d9a>] dump_stack_print_info+0x9a/0x100
kernel/printk/printk.c:3114
[< inline >] __dump_stack lib/dump_stack.c:14
[<ffffffff8274551d>] dump_stack+0x5f/0x92 lib/dump_stack.c:50
[<ffffffff81352f5d>] spin_dump+0x16d/0x270
kernel/locking/spinlock_debug.c:67 (discriminator 8)
[< inline >] __spin_lock_debug kernel/locking/spinlock_debug.c:117
[<ffffffff8135328e>] do_raw_spin_lock+0x19e/0x320
kernel/locking/spinlock_debug.c:137
[< inline >] __raw_spin_lock include/linux/spinlock_api_smp.h:145
[<ffffffff85987aa9>] _raw_spin_lock+0x39/0x40 kernel/locking/spinlock.c:151
[< inline >] ? perf_ctx_lock kernel/events/core.c:351
[<ffffffff8150f75d>] ? perf_event_context_sched_in+0xbd/0x380
kernel/events/core.c:2817
[< inline >] perf_ctx_lock kernel/events/core.c:351
[<ffffffff8150f75d>] perf_event_context_sched_in+0xbd/0x380
kernel/events/core.c:2817
[<ffffffff81519067>] __perf_event_task_sched_in+0x307/0x490
kernel/events/core.c:2857
[<ffffffff81518d60>] ? perf_sched_cb_inc+0x20/0x20 kernel/events/core.c:2607
[< inline >] ? load_sp0 ./arch/x86/include/asm/paravirt.h:25
[<ffffffff8114950d>] ? __switch_to+0x7bd/0xdf0 arch/x86/kernel/process_64.c:405
[< inline >] ? arch_local_irq_restore
./arch/x86/include/asm/paravirt.h:806
[<ffffffff81349f9d>] ? lock_release+0x7cd/0xbb0 kernel/locking/lockdep.c:3607
[< inline >] perf_event_task_sched_in include/linux/perf_event.h:929
[<ffffffff812c42cd>] finish_task_switch+0x3ad/0x5e0 kernel/sched/core.c:2552
[< inline >] context_switch kernel/sched/core.c:2682
[<ffffffff8597941b>] __schedule+0x87b/0x1a00 kernel/sched/core.c:3156
[<ffffffff8597a630>] schedule+0x90/0x1a0 kernel/sched/core.c:3185
(discriminator 1)
[<ffffffff859852fd>] rwsem_down_write_failed+0x3dd/0x950
kernel/locking/rwsem-xadd.c:489
[< inline >] ? rwsem_can_spin_on_owner kernel/locking/rwsem-xadd.c:304
[< inline >] ? rwsem_optimistic_spin kernel/locking/rwsem-xadd.c:373
[<ffffffff85984fdc>] ? rwsem_down_write_failed+0xbc/0x950
kernel/locking/rwsem-xadd.c:447
[<ffffffff85984f20>] ? rwsem_down_read_failed+0x270/0x270
include/linux/list.h:77
[<ffffffff8133a630>] ? check_chain_key+0x2b0/0x4b0
kernel/locking/lockdep.c:2192 (discriminator 9)
[< inline >] ? arch_local_irq_restore
./arch/x86/include/asm/paravirt.h:806
[<ffffffff813494f1>] ? lock_acquire+0x1c1/0x2f0 kernel/locking/lockdep.c:3588
[<ffffffff827762a3>] call_rwsem_down_write_failed+0x13/0x20
arch/x86/lib/rwsem.S:99
[< inline >] ? __down_write_nested ./arch/x86/include/asm/rwsem.h:105
[< inline >] ? __down_write ./arch/x86/include/asm/rwsem.h:121
[<ffffffff85984023>] ? down_write+0x53/0x90 kernel/locking/rwsem.c:51
[< inline >] ? SYSC_mprotect mm/mprotect.c:378
[<ffffffff815dcced>] ? SyS_mprotect+0x15d/0x650 mm/mprotect.c:347
[< inline >] SYSC_mprotect mm/mprotect.c:378
[<ffffffff815dcced>] SyS_mprotect+0x15d/0x650 mm/mprotect.c:347
[<ffffffff815dcb90>] ? mprotect_fixup+0x5b0/0x5b0 include/linux/mman.h:25
[<ffffffff8134284d>] ? trace_hardirqs_on_caller+0x2fd/0x660
kernel/locking/lockdep.c:2613
[<ffffffff81003017>] ? trace_hardirqs_on_thunk+0x17/0x19
arch/x86/entry/thunk_64.S:39
[<ffffffff85988836>] entry_SYSCALL_64_fastpath+0x16/0x7a
arch/x86/entry/entry_64.S:185
Code: 24 c1 00 00 00 49 8d 7c 24 38 48 b8 00 00 00 00 00 fc ff df 48
89 fa 48 c1 ea 03 d3 e3 80 3c 02 00 75 17 41 03 5c 24 38 89 da ec <5b>
0f b6 c0 41 5c 5d c3 e8 78 d6 b3 fe eb c2 e8 31 d7 b3 fe eb
NMI backtrace for cpu 1
CPU: 1 PID: 0 Comm: swapper/1 Not tainted 4.4.0-rc1+ #129
Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS Bochs 01/01/2011
task: ffff88003ebb2d80 ti: ffff88003ebd8000 task.ti: ffff88003ebd8000
RIP: 0010:[<ffffffff8120c596>] [<ffffffff8120c596>] native_safe_halt+0x6/0x10
RSP: 0018:ffff88003ebdfe58 EFLAGS: 00000246
RAX: ffff88003ebb2d80 RBX: ffff88003ebe0000 RCX: 0000000000000001
RDX: 0000000000000000 RSI: 0000000000000000 RDI: ffffffff86b64740
RBP: ffff88003ebdfe58 R08: 0000000000000000 R09: 0000000000000001
R10: ffffed000fffec0b R11: 0000000000000000 R12: ffff88003ebd8000
R13: 0000000000000000 R14: 0000000000000001 R15: 0000000000000000
FS: 0000000000000000(0000) GS:ffff88003ed00000(0000) knlGS:0000000000000000
CS: 0010 DS: 0000 ES: 0000 CR0: 000000008005003b
CR2: ffffffffff600400 CR3: 0000000062542000 CR4: 00000000000006e0
Stack:
ffff88003ebdfe88 ffffffff81165ba2 ffff88003ebe0000 ffff88003ebd8000
0000000000000000 0000000000000000 ffff88003ebdfe98 ffffffff81166d7a
ffff88003ebdfeb0 ffffffff81329a88 dffffc0000000000 ffff88003ebdff18
Call Trace:
[< inline >] arch_safe_halt ./arch/x86/include/asm/paravirt.h:111
[<ffffffff81165ba2>] default_idle+0x22/0x1e0 arch/x86/kernel/process.c:304
[<ffffffff81166d7a>] arch_cpu_idle+0xa/0x10 arch/x86/kernel/process.c:295
[<ffffffff81329a88>] default_idle_call+0x48/0x70 kernel/sched/idle.c:92
[< inline >] cpuidle_idle_call kernel/sched/idle.c:156
[< inline >] cpu_idle_loop kernel/sched/idle.c:251
[<ffffffff81329fad>] cpu_startup_entry+0x41d/0x570 kernel/sched/idle.c:299
[<ffffffff811e9323>] start_secondary+0x243/0x2d0 arch/x86/kernel/smpboot.c:251
Code: 00 00 00 00 00 55 48 89 e5 fa 5d c3 66 0f 1f 84 00 00 00 00 00
55 48 89 e5 fb 5d c3 66 0f 1f 84 00 00 00 00 00 55 48 89 e5 fb f4 <5d>
c3 0f 1f 84 00 00 00 00 00 55 48 89 e5 f4 5d c3 66 0f 1f 84
NMI backtrace for cpu 2
CPU: 2 PID: 6283 Comm: a.out Not tainted 4.4.0-rc1+ #129
Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS Bochs 01/01/2011
task: ffff88003906ad80 ti: ffff88003a1f0000 task.ti: ffff88003a1f0000
RIP: 0010:[<ffffffff811ff7a1>] [<ffffffff811ff7a1>]
flat_send_IPI_mask+0x111/0x1e0
RSP: 0018:ffff88003a1f7b30 EFLAGS: 00000046
RAX: ffff88003906ad80 RBX: ffffffff868aece0 RCX: 0000000000000000
RDX: 0000000000000000 RSI: 0000000000000002 RDI: ffffffffff5fb300
RBP: ffff88003a1f7b58 R08: 0000000000000001 R09: 0000000000000000
R10: fffffbfff0e957f2 R11: ffffed000fffec11 R12: 0000000000000c00
R13: 000000000f000000 R14: 0000000000000046 R15: 0000000000000002
FS: 00007f3712b7f700(0000) GS:ffff88006da00000(0000) knlGS:0000000000000000
CS: 0010 DS: 0000 ES: 0000 CR0: 000000008005003b
CR2: 0000000020002000 CR3: 0000000039046000 CR4: 00000000000006e0
Stack:
ffffffff868aece0 ffffffff8723e740 0000000000000040 fffffbfff0e476f4
ffff88006db19540 ffff88003a1f7b78 ffffffff811f5360 ffffffff85c79560
dffffc0000000000 ffff88003a1f7bd0 ffffffff8275012d 00000000ffffffff
Call Trace:
[<ffffffff811f5360>] nmi_raise_cpu_backtrace+0x60/0x80
arch/x86/kernel/apic/hw_nmi.c:33
[<ffffffff8275012d>] nmi_trigger_all_cpu_backtrace+0x49d/0x530
lib/nmi_backtrace.c:85
[<ffffffff811f5300>] ? irq_force_complete_move+0x70/0x70 ??:?
[<ffffffff811f53bb>] arch_trigger_all_cpu_backtrace+0x1b/0x20
arch/x86/kernel/apic/hw_nmi.c:38
[< inline >] trigger_all_cpu_backtrace include/linux/nmi.h:41
[< inline >] __spin_lock_debug kernel/locking/spinlock_debug.c:119
[<ffffffff81353298>] do_raw_spin_lock+0x1a8/0x320
kernel/locking/spinlock_debug.c:137
[< inline >] __raw_spin_lock include/linux/spinlock_api_smp.h:145
[<ffffffff85987aa9>] _raw_spin_lock+0x39/0x40 kernel/locking/spinlock.c:151
[<ffffffff815072ce>] ? __perf_event_period+0x8e/0x4b0 kernel/events/core.c:4156
[<ffffffff815072ce>] __perf_event_period+0x8e/0x4b0 kernel/events/core.c:4156
[< inline >] perf_event_period kernel/events/core.c:4219
[< inline >] _perf_ioctl kernel/events/core.c:4266
[<ffffffff815234a4>] perf_ioctl+0x944/0xcc0 kernel/events/core.c:4320
[<ffffffff81522b60>] ? SYSC_perf_event_open+0x2060/0x2060
kernel/events/core.c:8192
[<ffffffff81343220>] ? debug_check_no_locks_freed+0x310/0x310
kernel/locking/lockdep.c:4123
[< inline >] ? arch_local_irq_restore
./arch/x86/include/asm/paravirt.h:806
[<ffffffff81349f9d>] ? lock_release+0x7cd/0xbb0 kernel/locking/lockdep.c:3607
[<ffffffff8133a630>] ? check_chain_key+0x2b0/0x4b0
kernel/locking/lockdep.c:2192 (discriminator 9)
[<ffffffff81522b60>] ? SYSC_perf_event_open+0x2060/0x2060
kernel/events/core.c:8192
[< inline >] vfs_ioctl fs/ioctl.c:43
[<ffffffff816a5be1>] do_vfs_ioctl+0x681/0xe40 fs/ioctl.c:607
[<ffffffff816a5560>] ? ioctl_preallocate+0x1d0/0x1d0 fs/ioctl.c:442
[< inline >] ? rcu_lock_release include/linux/rcupdate.h:482
[< inline >] ? rcu_read_unlock include/linux/rcupdate.h:917
[<ffffffff816c4d92>] ? __fget+0x222/0x3a0 fs/file.c:711
[<ffffffff816c4bb7>] ? __fget+0x47/0x3a0 fs/file.c:695
[< inline >] ? __up_read ./arch/x86/include/asm/rwsem.h:156
[<ffffffff813372e5>] ? up_read+0x35/0x40 kernel/locking/rwsem.c:81
[<ffffffff82537ec9>] ? security_file_ioctl+0x89/0xb0
security/security.c:752 (discriminator 6)
[< inline >] SYSC_ioctl fs/ioctl.c:622
[<ffffffff816a642f>] SyS_ioctl+0x8f/0xc0 fs/ioctl.c:613
[<ffffffff85988836>] entry_SYSCALL_64_fastpath+0x16/0x7a
arch/x86/entry/entry_64.S:185
Code: 41 c1 e5 18 44 89 2c 25 10 b3 5f ff 41 83 ff 02 75 6a 41 81 cc
00 04 00 00 e8 bc 1f 26 00 e8 b7 1f 26 00 44 89 24 25 00 b3 5f ff <41>
f7 c6 00 02 00 00 74 24 e8 a1 1f 26 00 e8 fc 33 14 00 4c 89
NMI backtrace for cpu 3
CPU: 3 PID: 0 Comm: swapper/3 Not tainted 4.4.0-rc1+ #129
Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS Bochs 01/01/2011
task: ffff88003ebe5b00 ti: ffff88003ebf0000 task.ti: ffff88003ebf0000
RIP: 0010:[<ffffffff8120c596>] [<ffffffff8120c596>] native_safe_halt+0x6/0x10
RSP: 0018:ffff88003ebf7e58 EFLAGS: 00000246
RAX: ffff88003ebe5b00 RBX: ffff88003ebf8000 RCX: 0000000000000001
RDX: 0000000000000000 RSI: 0000000000000000 RDI: ffffffff86b64740
RBP: ffff88003ebf7e58 R08: 0000000000000000 R09: 0000000000000001
R10: ffffed000fffec1b R11: 0000000000000000 R12: ffff88003ebf0000
R13: 0000000000000000 R14: 0000000000000003 R15: 0000000000000000
FS: 0000000000000000(0000) GS:ffff88006db00000(0000) knlGS:0000000000000000
CS: 0010 DS: 0000 ES: 0000 CR0: 000000008005003b
CR2: 00007f91314b79de CR3: 0000000006836000 CR4: 00000000000006e0
Stack:
ffff88003ebf7e88 ffffffff81165ba2 ffff88003ebf8000 ffff88003ebf0000
0000000000000000 0000000000000000 ffff88003ebf7e98 ffffffff81166d7a
ffff88003ebf7eb0 ffffffff81329a88 dffffc0000000000 ffff88003ebf7f18
Call Trace:
[< inline >] arch_safe_halt ./arch/x86/include/asm/paravirt.h:111
[<ffffffff81165ba2>] default_idle+0x22/0x1e0 arch/x86/kernel/process.c:304
[<ffffffff81166d7a>] arch_cpu_idle+0xa/0x10 arch/x86/kernel/process.c:295
[<ffffffff81329a88>] default_idle_call+0x48/0x70 kernel/sched/idle.c:92
[< inline >] cpuidle_idle_call kernel/sched/idle.c:156
[< inline >] cpu_idle_loop kernel/sched/idle.c:251
[<ffffffff81329fad>] cpu_startup_entry+0x41d/0x570 kernel/sched/idle.c:299
[<ffffffff811e9323>] start_secondary+0x243/0x2d0 arch/x86/kernel/smpboot.c:251
Code: 00 00 00 00 00 55 48 89 e5 fa 5d c3 66 0f 1f 84 00 00 00 00 00
55 48 89 e5 fb 5d c3 66 0f 1f 84 00 00 00 00 00 55 48 89 e5 fb f4 <5d>
c3 0f 1f 84 00 00 00 00 00 55 48 89 e5 f4 5d c3 66 0f 1f 84
00000000ffffffff ffff8800392a7a48 ffffffff82745526 ffff880038de9528
ffff88003906b380 0000000000000002 ffff8800392a7a78 ffffffff81352f5d
ffff880038de9528 ffff880038de9530 000000009a9d2d40 ffff880038de9538
Call Trace:
[< inline >] __dump_stack lib/dump_stack.c:15
[<ffffffff82745526>] dump_stack+0x68/0x92 lib/dump_stack.c:50
[<ffffffff81352f5d>] spin_dump+0x16d/0x270
kernel/locking/spinlock_debug.c:67 (discriminator 8)
[< inline >] __spin_lock_debug kernel/locking/spinlock_debug.c:117
[<ffffffff8135328e>] do_raw_spin_lock+0x19e/0x320
kernel/locking/spinlock_debug.c:137
[< inline >] __raw_spin_lock include/linux/spinlock_api_smp.h:145
[<ffffffff85987aa9>] _raw_spin_lock+0x39/0x40 kernel/locking/spinlock.c:151
[< inline >] ? perf_ctx_lock kernel/events/core.c:351
[<ffffffff8150f75d>] ? perf_event_context_sched_in+0xbd/0x380
kernel/events/core.c:2817
[< inline >] perf_ctx_lock kernel/events/core.c:351
[<ffffffff8150f75d>] perf_event_context_sched_in+0xbd/0x380
kernel/events/core.c:2817
[<ffffffff81519067>] __perf_event_task_sched_in+0x307/0x490
kernel/events/core.c:2857
[<ffffffff81518d60>] ? perf_sched_cb_inc+0x20/0x20 kernel/events/core.c:2607
[< inline >] ? load_sp0 ./arch/x86/include/asm/paravirt.h:25
[<ffffffff8114950d>] ? __switch_to+0x7bd/0xdf0 arch/x86/kernel/process_64.c:405
[< inline >] ? arch_local_irq_restore
./arch/x86/include/asm/paravirt.h:806
[<ffffffff81349f9d>] ? lock_release+0x7cd/0xbb0 kernel/locking/lockdep.c:3607
[< inline >] perf_event_task_sched_in include/linux/perf_event.h:929
[<ffffffff812c42cd>] finish_task_switch+0x3ad/0x5e0 kernel/sched/core.c:2552
[< inline >] context_switch kernel/sched/core.c:2682
[<ffffffff8597941b>] __schedule+0x87b/0x1a00 kernel/sched/core.c:3156
[<ffffffff8597a630>] schedule+0x90/0x1a0 kernel/sched/core.c:3185
(discriminator 1)
[<ffffffff859852fd>] rwsem_down_write_failed+0x3dd/0x950
kernel/locking/rwsem-xadd.c:489
[< inline >] ? rwsem_can_spin_on_owner kernel/locking/rwsem-xadd.c:304
[< inline >] ? rwsem_optimistic_spin kernel/locking/rwsem-xadd.c:373
[<ffffffff85984fdc>] ? rwsem_down_write_failed+0xbc/0x950
kernel/locking/rwsem-xadd.c:447
[<ffffffff85984f20>] ? rwsem_down_read_failed+0x270/0x270
include/linux/list.h:77
[<ffffffff8133a630>] ? check_chain_key+0x2b0/0x4b0
kernel/locking/lockdep.c:2192 (discriminator 9)
[< inline >] ? arch_local_irq_restore
./arch/x86/include/asm/paravirt.h:806
[<ffffffff813494f1>] ? lock_acquire+0x1c1/0x2f0 kernel/locking/lockdep.c:3588
[<ffffffff827762a3>] call_rwsem_down_write_failed+0x13/0x20
arch/x86/lib/rwsem.S:99
[< inline >] ? __down_write_nested ./arch/x86/include/asm/rwsem.h:105
[< inline >] ? __down_write ./arch/x86/include/asm/rwsem.h:121
[<ffffffff85984023>] ? down_write+0x53/0x90 kernel/locking/rwsem.c:51
[< inline >] ? SYSC_mprotect mm/mprotect.c:378
[<ffffffff815dcced>] ? SyS_mprotect+0x15d/0x650 mm/mprotect.c:347
[< inline >] SYSC_mprotect mm/mprotect.c:378
[<ffffffff815dcced>] SyS_mprotect+0x15d/0x650 mm/mprotect.c:347
[<ffffffff815dcb90>] ? mprotect_fixup+0x5b0/0x5b0 include/linux/mman.h:25
[<ffffffff8134284d>] ? trace_hardirqs_on_caller+0x2fd/0x660
kernel/locking/lockdep.c:2613
[<ffffffff81003017>] ? trace_hardirqs_on_thunk+0x17/0x19
arch/x86/entry/thunk_64.S:39
[<ffffffff85988836>] entry_SYSCALL_64_fastpath+0x16/0x7a
arch/x86/entry/entry_64.S:185


On commit 90b55590c43258a157a2a143748455dcc50fbb53 (Nov 25).


Thank you

Peter Zijlstra

unread,
Nov 30, 2015, 6:56:19 AM11/30/15
to Dmitry Vyukov, Ingo Molnar, Arnaldo Carvalho de Melo, LKML, syzkaller, Alexander Potapenko, Kostya Serebryany, Eric Dumazet, Sasha Levin
On Mon, Nov 30, 2015 at 10:20:49AM +0100, Dmitry Vyukov wrote:
> =============================================
> [ INFO: possible recursive locking detected ]
> 4.4.0-rc1+ #129 Not tainted
> ---------------------------------------------
> a.out/6283 is trying to acquire lock:
> (&ctx->lock){-.....}, at: [<ffffffff815072ce>]
> __perf_event_period+0x8e/0x4b0 kernel/events/core.c:4156
>
> but task is already holding lock:
> (&ctx->lock){-.....}, at: [< inline >] perf_event_period
> kernel/events/core.c:4212
> (&ctx->lock){-.....}, at: [< inline >] _perf_ioctl
> kernel/events/core.c:4266
> (&ctx->lock){-.....}, at: [<ffffffff8152331c>] perf_ioctl+0x7bc/0xcc0
> kernel/events/core.c:4320
>

Indeed so. I suppose the below should fix this, I'll go try in a bit.

---
Subject: perf: Fix PERF_EVENT_IOC_PERIOD deadlock

Dmitry reported a fairly silly recursive lock deadlock for
PERF_EVENT_IOC_PERIOD, fix this by explicitly doing the inactive part of
__perf_event_period() instead of calling that function.

Reported-by: Dmitry Vyukov <dvy...@google.com>
Fixes: c7999c6f3fed ("perf: Fix PERF_EVENT_IOC_PERIOD migration race")
Signed-off-by: Peter Zijlstra (Intel) <pet...@infradead.org>
---
kernel/events/core.c | 9 ++++++++-
1 file changed, 8 insertions(+), 1 deletion(-)

diff --git a/kernel/events/core.c b/kernel/events/core.c
index 36babfd20648..a991e12e4d0d 100644
--- a/kernel/events/core.c
+++ b/kernel/events/core.c
@@ -4216,7 +4216,14 @@ static int perf_event_period(struct perf_event *event, u64 __user *arg)
goto retry;
}

- __perf_event_period(&pe);
+ if (event->attr.freq) {
+ event->attr.sample_freq = value;
+ } else {
+ event->attr.sample_period = value;
+ event->hw.sample_period = value;
+ }
+
+ local64_set(&event->hw.period_left, 0);
raw_spin_unlock_irq(&ctx->lock);

return 0;
Reply all
Reply to author
Forward
0 new messages