Re: events: possible deadlock in __perf_event_task_sched_out
On Mon, Aug 21, 2017 at 01:58:13PM +0530, Shubham Bansal wrote: > > This is a WARN, printk is a pig. > > So, its not a bug? No, triggering the WARN is the problem, this is just fallout after that.
Re: events: possible deadlock in __perf_event_task_sched_out
On Mon, Aug 21, 2017 at 01:58:13PM +0530, Shubham Bansal wrote: > > This is a WARN, printk is a pig. > > So, its not a bug? No, triggering the WARN is the problem, this is just fallout after that.
Re: events: possible deadlock in __perf_event_task_sched_out
> This is a WARN, printk is a pig. So, its not a bug?
Re: events: possible deadlock in __perf_event_task_sched_out
> This is a WARN, printk is a pig. So, its not a bug?
Re: events: possible deadlock in __perf_event_task_sched_out
On Mon, Aug 21, 2017 at 01:56:27AM +0530, Shubham Bansal wrote:
> -> #1 ((console_sem).lock){..}:
>lock_acquire+0x173/0x470
>_raw_spin_lock_irqsave+0x42/0x60
>down_trylock+0x13/0x70
>__down_trylock_console_sem+0x38/0xc0
>console_trylock+0x17/0xb0
>vprintk_emit+0x410/0x480
>vprintk_default+0x28/0x30
>vprintk_func+0x57/0xbe
>printk+0x9f/0xbb
>ex_handler_wrmsr_unsafe.cold.1+0xca/0xe2
>fixup_exception+0x8b/0xb3
>do_general_protection+0x18f/0x2b0
>general_protection+0x28/0x30
>native_write_msr+0x4/0x30
>x86_pmu_enable+0x347/0xab0
>ctx_resched+0x1e6/0x2b0
>__perf_install_in_context+0x244/0x2c0
>remote_function+0x8e/0x190
>generic_exec_single+0x292/0x410
>smp_call_function_single+0x339/0x510
>task_function_call+0x162/0x220
>perf_install_in_context+0x247/0x460
>SYSC_perf_event_open+0x207c/0x2ea0
>SyS_perf_event_open+0x39/0x50
>entry_SYSCALL_64_fastpath+0x1f/0xbe
This is a WARN, printk is a pig.
Re: events: possible deadlock in __perf_event_task_sched_out
On Mon, Aug 21, 2017 at 01:56:27AM +0530, Shubham Bansal wrote:
> -> #1 ((console_sem).lock){..}:
>lock_acquire+0x173/0x470
>_raw_spin_lock_irqsave+0x42/0x60
>down_trylock+0x13/0x70
>__down_trylock_console_sem+0x38/0xc0
>console_trylock+0x17/0xb0
>vprintk_emit+0x410/0x480
>vprintk_default+0x28/0x30
>vprintk_func+0x57/0xbe
>printk+0x9f/0xbb
>ex_handler_wrmsr_unsafe.cold.1+0xca/0xe2
>fixup_exception+0x8b/0xb3
>do_general_protection+0x18f/0x2b0
>general_protection+0x28/0x30
>native_write_msr+0x4/0x30
>x86_pmu_enable+0x347/0xab0
>ctx_resched+0x1e6/0x2b0
>__perf_install_in_context+0x244/0x2c0
>remote_function+0x8e/0x190
>generic_exec_single+0x292/0x410
>smp_call_function_single+0x339/0x510
>task_function_call+0x162/0x220
>perf_install_in_context+0x247/0x460
>SYSC_perf_event_open+0x207c/0x2ea0
>SyS_perf_event_open+0x39/0x50
>entry_SYSCALL_64_fastpath+0x1f/0xbe
This is a WARN, printk is a pig.
events: possible deadlock in __perf_event_task_sched_out
Hi all,
While fuzzing with syzkaller inside Qemu I've stumbled on the
following warning which is reproducible with
==
// autogenerated by syzkaller (http://github.com/google/syzkaller)
#define _GNU_SOURCE
#include
#include
#include
#include
static void test();
void loop()
{
while (1) {
test();
}
}
long r[29];
void test()
{
memset(r, -1, sizeof(r));
r[0] = syscall(__NR_mmap, 0x2000ul, 0x1d000ul, 0x3ul, 0x32ul,
0xul, 0x0ul);
*(uint32_t*)0x2001bf88 = (uint32_t)0x0;
*(uint32_t*)0x2001bf8c = (uint32_t)0x78;
*(uint8_t*)0x2001bf90 = (uint8_t)0x0;
*(uint8_t*)0x2001bf91 = (uint8_t)0x0;
*(uint8_t*)0x2001bf92 = (uint8_t)0x0;
*(uint8_t*)0x2001bf93 = (uint8_t)0x0;
*(uint32_t*)0x2001bf94 = (uint32_t)0x0;
*(uint64_t*)0x2001bf98 = (uint64_t)0x9;
*(uint64_t*)0x2001bfa0 = (uint64_t)0x0;
*(uint64_t*)0x2001bfa8 = (uint64_t)0x0;
*(uint8_t*)0x2001bfb0 = (uint8_t)0x3fe;
*(uint8_t*)0x2001bfb1 = (uint8_t)0x0;
*(uint8_t*)0x2001bfb2 = (uint8_t)0x8;
*(uint8_t*)0x2001bfb3 = (uint8_t)0x0;
*(uint32_t*)0x2001bfb4 = (uint32_t)0x0;
*(uint32_t*)0x2001bfb8 = (uint32_t)0x0;
*(uint32_t*)0x2001bfbc = (uint32_t)0x0;
*(uint64_t*)0x2001bfc0 = (uint64_t)0x0;
*(uint64_t*)0x2001bfc8 = (uint64_t)0x0;
*(uint64_t*)0x2001bfd0 = (uint64_t)0x0;
*(uint64_t*)0x2001bfd8 = (uint64_t)0x0;
*(uint64_t*)0x2001bfe0 = (uint64_t)0x2;
*(uint32_t*)0x2001bfe8 = (uint32_t)0x0;
*(uint64_t*)0x2001bff0 = (uint64_t)0x0;
*(uint32_t*)0x2001bff8 = (uint32_t)0x0;
*(uint16_t*)0x2001bffc = (uint16_t)0x0;
*(uint16_t*)0x2001bffe = (uint16_t)0x0;
r[28] = syscall(__NR_perf_event_open, 0x2001bf88ul, 0x0ul,
0xfffeul, 0xul, 0x2ul);
}
int main()
{
int i; for (i = 0; i < 2; i++) {
if (fork() == 0) {
loop();
return 0;
}
}
sleep(100);
return 0;
}
==
WARNING: possible circular locking dependency detected
4.13.0-rc4+ #1 Not tainted
--
syz-executor0/2793 is trying to acquire lock:
(>lock){..}, at: []
__perf_event_task_sched_out+0x639/0x1000
but task is already holding lock:
(>lock){-.-.-.}, at: [] __schedule+0x1d3/0x1ea0
which lock already depends on the new lock.
the existing dependency chain (in reverse order) is:
-> #3 (>lock){-.-.-.}:
lock_acquire+0x173/0x470
_raw_spin_lock+0x2a/0x40
task_fork_fair+0x7a/0x760
sched_fork+0x43e/0xf60
copy_process.part.43+0x18a5/0x26a0
_do_fork+0x1ea/0x1030
kernel_thread+0x34/0x40
rest_init+0x22/0xfe
start_kernel+0x71e/0x744
x86_64_start_reservations+0x24/0x26
x86_64_start_kernel+0x134/0x143
verify_cpu+0x0/0xf1
-> #2 (>pi_lock){-.-.-.}:
lock_acquire+0x173/0x470
_raw_spin_lock_irqsave+0x42/0x60
try_to_wake_up+0xc0/0x14c0
wake_up_process+0x10/0x20
__up.isra.2+0x1a1/0x290
up+0x12f/0x1b0
__up_console_sem+0x48/0x90
console_unlock+0x61a/0xc20
do_con_write+0xfb3/0x1f20
con_write+0x25/0xb0
n_tty_write+0x5fc/0xed0
tty_write+0x3be/0x800
__vfs_write+0x10d/0x820
vfs_write+0x189/0x510
SyS_write+0xef/0x220
entry_SYSCALL_64_fastpath+0x1f/0xbe
-> #1 ((console_sem).lock){..}:
lock_acquire+0x173/0x470
_raw_spin_lock_irqsave+0x42/0x60
down_trylock+0x13/0x70
__down_trylock_console_sem+0x38/0xc0
console_trylock+0x17/0xb0
vprintk_emit+0x410/0x480
vprintk_default+0x28/0x30
vprintk_func+0x57/0xbe
printk+0x9f/0xbb
ex_handler_wrmsr_unsafe.cold.1+0xca/0xe2
fixup_exception+0x8b/0xb3
do_general_protection+0x18f/0x2b0
general_protection+0x28/0x30
native_write_msr+0x4/0x30
x86_pmu_enable+0x347/0xab0
ctx_resched+0x1e6/0x2b0
__perf_install_in_context+0x244/0x2c0
remote_function+0x8e/0x190
generic_exec_single+0x292/0x410
smp_call_function_single+0x339/0x510
task_function_call+0x162/0x220
perf_install_in_context+0x247/0x460
SYSC_perf_event_open+0x207c/0x2ea0
SyS_perf_event_open+0x39/0x50
entry_SYSCALL_64_fastpath+0x1f/0xbe
-> #0 (>lock){..}:
__lock_acquire+0x2926/0x4120
lock_acquire+0x173/0x470
_raw_spin_lock+0x2a/0x40
__perf_event_task_sched_out+0x639/0x1000
__schedule+0xec3/0x1ea0
preempt_schedule_common+0x35/0x60
_cond_resched+0x17/0x20
__mutex_lock+0x143/0x17f0
mutex_lock_nested+0x16/0x20
SYSC_perf_event_open+0x2123/0x2ea0
SyS_perf_event_open+0x39/0x50
entry_SYSCALL_64_fastpath+0x1f/0xbe
other info that might help us debug this:
Chain exists of:
>lock --> >pi_lock --> >lock
Possible unsafe locking scenario:
CPU0CPU1
lock(>lock);
events: possible deadlock in __perf_event_task_sched_out
Hi all,
While fuzzing with syzkaller inside Qemu I've stumbled on the
following warning which is reproducible with
==
// autogenerated by syzkaller (http://github.com/google/syzkaller)
#define _GNU_SOURCE
#include
#include
#include
#include
static void test();
void loop()
{
while (1) {
test();
}
}
long r[29];
void test()
{
memset(r, -1, sizeof(r));
r[0] = syscall(__NR_mmap, 0x2000ul, 0x1d000ul, 0x3ul, 0x32ul,
0xul, 0x0ul);
*(uint32_t*)0x2001bf88 = (uint32_t)0x0;
*(uint32_t*)0x2001bf8c = (uint32_t)0x78;
*(uint8_t*)0x2001bf90 = (uint8_t)0x0;
*(uint8_t*)0x2001bf91 = (uint8_t)0x0;
*(uint8_t*)0x2001bf92 = (uint8_t)0x0;
*(uint8_t*)0x2001bf93 = (uint8_t)0x0;
*(uint32_t*)0x2001bf94 = (uint32_t)0x0;
*(uint64_t*)0x2001bf98 = (uint64_t)0x9;
*(uint64_t*)0x2001bfa0 = (uint64_t)0x0;
*(uint64_t*)0x2001bfa8 = (uint64_t)0x0;
*(uint8_t*)0x2001bfb0 = (uint8_t)0x3fe;
*(uint8_t*)0x2001bfb1 = (uint8_t)0x0;
*(uint8_t*)0x2001bfb2 = (uint8_t)0x8;
*(uint8_t*)0x2001bfb3 = (uint8_t)0x0;
*(uint32_t*)0x2001bfb4 = (uint32_t)0x0;
*(uint32_t*)0x2001bfb8 = (uint32_t)0x0;
*(uint32_t*)0x2001bfbc = (uint32_t)0x0;
*(uint64_t*)0x2001bfc0 = (uint64_t)0x0;
*(uint64_t*)0x2001bfc8 = (uint64_t)0x0;
*(uint64_t*)0x2001bfd0 = (uint64_t)0x0;
*(uint64_t*)0x2001bfd8 = (uint64_t)0x0;
*(uint64_t*)0x2001bfe0 = (uint64_t)0x2;
*(uint32_t*)0x2001bfe8 = (uint32_t)0x0;
*(uint64_t*)0x2001bff0 = (uint64_t)0x0;
*(uint32_t*)0x2001bff8 = (uint32_t)0x0;
*(uint16_t*)0x2001bffc = (uint16_t)0x0;
*(uint16_t*)0x2001bffe = (uint16_t)0x0;
r[28] = syscall(__NR_perf_event_open, 0x2001bf88ul, 0x0ul,
0xfffeul, 0xul, 0x2ul);
}
int main()
{
int i; for (i = 0; i < 2; i++) {
if (fork() == 0) {
loop();
return 0;
}
}
sleep(100);
return 0;
}
==
WARNING: possible circular locking dependency detected
4.13.0-rc4+ #1 Not tainted
--
syz-executor0/2793 is trying to acquire lock:
(>lock){..}, at: []
__perf_event_task_sched_out+0x639/0x1000
but task is already holding lock:
(>lock){-.-.-.}, at: [] __schedule+0x1d3/0x1ea0
which lock already depends on the new lock.
the existing dependency chain (in reverse order) is:
-> #3 (>lock){-.-.-.}:
lock_acquire+0x173/0x470
_raw_spin_lock+0x2a/0x40
task_fork_fair+0x7a/0x760
sched_fork+0x43e/0xf60
copy_process.part.43+0x18a5/0x26a0
_do_fork+0x1ea/0x1030
kernel_thread+0x34/0x40
rest_init+0x22/0xfe
start_kernel+0x71e/0x744
x86_64_start_reservations+0x24/0x26
x86_64_start_kernel+0x134/0x143
verify_cpu+0x0/0xf1
-> #2 (>pi_lock){-.-.-.}:
lock_acquire+0x173/0x470
_raw_spin_lock_irqsave+0x42/0x60
try_to_wake_up+0xc0/0x14c0
wake_up_process+0x10/0x20
__up.isra.2+0x1a1/0x290
up+0x12f/0x1b0
__up_console_sem+0x48/0x90
console_unlock+0x61a/0xc20
do_con_write+0xfb3/0x1f20
con_write+0x25/0xb0
n_tty_write+0x5fc/0xed0
tty_write+0x3be/0x800
__vfs_write+0x10d/0x820
vfs_write+0x189/0x510
SyS_write+0xef/0x220
entry_SYSCALL_64_fastpath+0x1f/0xbe
-> #1 ((console_sem).lock){..}:
lock_acquire+0x173/0x470
_raw_spin_lock_irqsave+0x42/0x60
down_trylock+0x13/0x70
__down_trylock_console_sem+0x38/0xc0
console_trylock+0x17/0xb0
vprintk_emit+0x410/0x480
vprintk_default+0x28/0x30
vprintk_func+0x57/0xbe
printk+0x9f/0xbb
ex_handler_wrmsr_unsafe.cold.1+0xca/0xe2
fixup_exception+0x8b/0xb3
do_general_protection+0x18f/0x2b0
general_protection+0x28/0x30
native_write_msr+0x4/0x30
x86_pmu_enable+0x347/0xab0
ctx_resched+0x1e6/0x2b0
__perf_install_in_context+0x244/0x2c0
remote_function+0x8e/0x190
generic_exec_single+0x292/0x410
smp_call_function_single+0x339/0x510
task_function_call+0x162/0x220
perf_install_in_context+0x247/0x460
SYSC_perf_event_open+0x207c/0x2ea0
SyS_perf_event_open+0x39/0x50
entry_SYSCALL_64_fastpath+0x1f/0xbe
-> #0 (>lock){..}:
__lock_acquire+0x2926/0x4120
lock_acquire+0x173/0x470
_raw_spin_lock+0x2a/0x40
__perf_event_task_sched_out+0x639/0x1000
__schedule+0xec3/0x1ea0
preempt_schedule_common+0x35/0x60
_cond_resched+0x17/0x20
__mutex_lock+0x143/0x17f0
mutex_lock_nested+0x16/0x20
SYSC_perf_event_open+0x2123/0x2ea0
SyS_perf_event_open+0x39/0x50
entry_SYSCALL_64_fastpath+0x1f/0xbe
other info that might help us debug this:
Chain exists of:
>lock --> >pi_lock --> >lock
Possible unsafe locking scenario:
CPU0CPU1
lock(>lock);
