possible deadlock in perf_event_ctx_lock_nested

[syzbot]

Hello,

syzkaller hit the following crash on
a31cc455c512f3f1dd5f79cac8e29a7c8a617af8
git://git.kernel.org/pub/scm/linux/kernel/git/next/linux-next.git/master
compiler: gcc (GCC) 7.1.1 20170620
.config is attached
Raw console output is attached.





======================================================
WARNING: possible circular locking dependency detected
4.13.0-next-20170911+ #19 Not tainted
------------------------------------------------------
syz-executor2/12380 is trying to acquire lock:
(&ctx->mutex){+.+.}, at: [<ffffffff8180923c>]
perf_event_ctx_lock_nested+0x1dc/0x3c0 kernel/events/core.c:1210

but task is already holding lock:
(&pipe->mutex/1){+.+.}, at: [<ffffffff81ac0fa6>] pipe_lock_nested
fs/pipe.c:66 [inline]
(&pipe->mutex/1){+.+.}, at: [<ffffffff81ac0fa6>] pipe_lock+0x56/0x70
fs/pipe.c:74

which lock already depends on the new lock.


the existing dependency chain (in reverse order) is:

-> #8 (&pipe->mutex/1){+.+.}:
check_prevs_add kernel/locking/lockdep.c:2020 [inline]
validate_chain kernel/locking/lockdep.c:2469 [inline]
__lock_acquire+0x328f/0x4620 kernel/locking/lockdep.c:3498
lock_acquire+0x1d5/0x580 kernel/locking/lockdep.c:4002
__mutex_lock_common kernel/locking/mutex.c:756 [inline]
__mutex_lock+0x16f/0x1870 kernel/locking/mutex.c:893
mutex_lock_nested+0x16/0x20 kernel/locking/mutex.c:908
pipe_lock_nested fs/pipe.c:66 [inline]
pipe_lock+0x56/0x70 fs/pipe.c:74
iter_file_splice_write+0x264/0xf50 fs/splice.c:699
do_splice_from fs/splice.c:851 [inline]
do_splice fs/splice.c:1147 [inline]
SYSC_splice fs/splice.c:1402 [inline]
SyS_splice+0x7d5/0x1630 fs/splice.c:1382
entry_SYSCALL_64_fastpath+0x1f/0xbe

-> #7 (sb_writers){.+.+}:
percpu_down_read_preempt_disable include/linux/percpu-rwsem.h:35
[inline]
percpu_down_read include/linux/percpu-rwsem.h:58 [inline]
__sb_start_write+0x18f/0x290 fs/super.c:1341
sb_start_write include/linux/fs.h:1541 [inline]
mnt_want_write+0x3f/0xb0 fs/namespace.c:387
filename_create+0x12b/0x520 fs/namei.c:3628
kern_path_create+0x33/0x40 fs/namei.c:3674
handle_create+0xc0/0x760 drivers/base/devtmpfs.c:203

-> #6 ((complete)&req.done){+.+.}:
check_prevs_add kernel/locking/lockdep.c:2020 [inline]
validate_chain kernel/locking/lockdep.c:2469 [inline]
__lock_acquire+0x328f/0x4620 kernel/locking/lockdep.c:3498
lock_acquire+0x1d5/0x580 kernel/locking/lockdep.c:4002
complete_acquire include/linux/completion.h:39 [inline]
__wait_for_common kernel/sched/completion.c:108 [inline]
wait_for_common kernel/sched/completion.c:122 [inline]
wait_for_completion+0xc8/0x770 kernel/sched/completion.c:143
devtmpfs_create_node+0x32b/0x4a0 drivers/base/devtmpfs.c:115
device_add+0x120f/0x1640 drivers/base/core.c:1824
device_create_groups_vargs+0x1f3/0x250 drivers/base/core.c:2430
device_create_vargs drivers/base/core.c:2470 [inline]
device_create+0xda/0x110 drivers/base/core.c:2506
msr_device_create+0x26/0x40 arch/x86/kernel/msr.c:188
cpuhp_invoke_callback+0x256/0x14d0 kernel/cpu.c:145
cpuhp_thread_fun+0x265/0x520 kernel/cpu.c:434
smpboot_thread_fn+0x489/0x850 kernel/smpboot.c:164
kthread+0x39c/0x470 kernel/kthread.c:231
ret_from_fork+0x2a/0x40 arch/x86/entry/entry_64.S:431

-> #5 (cpuhp_state){+.+.}:
check_prevs_add kernel/locking/lockdep.c:2020 [inline]
validate_chain kernel/locking/lockdep.c:2469 [inline]
__lock_acquire+0x328f/0x4620 kernel/locking/lockdep.c:3498
lock_acquire+0x1d5/0x580 kernel/locking/lockdep.c:4002
cpuhp_invoke_ap_callback kernel/cpu.c:467 [inline]
cpuhp_issue_call+0x1a2/0x3e0 kernel/cpu.c:1308
__cpuhp_setup_state_cpuslocked+0x2d6/0x5f0 kernel/cpu.c:1455
__cpuhp_setup_state+0xb0/0x140 kernel/cpu.c:1484
cpuhp_setup_state include/linux/cpuhotplug.h:177 [inline]
page_writeback_init+0x4d/0x71 mm/page-writeback.c:2082
pagecache_init+0x48/0x4f mm/filemap.c:871
start_kernel+0x6c1/0x754 init/main.c:690
x86_64_start_reservations+0x2a/0x2c arch/x86/kernel/head64.c:377
x86_64_start_kernel+0x87/0x8a arch/x86/kernel/head64.c:358
verify_cpu+0x0/0xfb

-> #4 (cpuhp_state_mutex){+.+.}:
check_prevs_add kernel/locking/lockdep.c:2020 [inline]
validate_chain kernel/locking/lockdep.c:2469 [inline]
__lock_acquire+0x328f/0x4620 kernel/locking/lockdep.c:3498
lock_acquire+0x1d5/0x580 kernel/locking/lockdep.c:4002
__mutex_lock_common kernel/locking/mutex.c:756 [inline]
__mutex_lock+0x16f/0x1870 kernel/locking/mutex.c:893
mutex_lock_nested+0x16/0x20 kernel/locking/mutex.c:908
__cpuhp_setup_state_cpuslocked+0x5b/0x5f0 kernel/cpu.c:1430
__cpuhp_setup_state+0xb0/0x140 kernel/cpu.c:1484
cpuhp_setup_state_nocalls include/linux/cpuhotplug.h:205 [inline]
kvm_guest_init+0x1f3/0x20f arch/x86/kernel/kvm.c:488
setup_arch+0x1899/0x1ab3 arch/x86/kernel/setup.c:1295
start_kernel+0xa5/0x754 init/main.c:530
x86_64_start_reservations+0x2a/0x2c arch/x86/kernel/head64.c:377
x86_64_start_kernel+0x87/0x8a arch/x86/kernel/head64.c:358
verify_cpu+0x0/0xfb

-> #3 (cpu_hotplug_lock.rw_sem){++++}:
check_prevs_add kernel/locking/lockdep.c:2020 [inline]
validate_chain kernel/locking/lockdep.c:2469 [inline]
__lock_acquire+0x328f/0x4620 kernel/locking/lockdep.c:3498
lock_acquire+0x1d5/0x580 kernel/locking/lockdep.c:4002
percpu_down_read_preempt_disable include/linux/percpu-rwsem.h:35
[inline]
percpu_down_read include/linux/percpu-rwsem.h:58 [inline]
cpus_read_lock+0x42/0x90 kernel/cpu.c:218
static_key_slow_inc+0x9d/0x3c0 kernel/jump_label.c:123
tracepoint_add_func kernel/tracepoint.c:223 [inline]
tracepoint_probe_register_prio+0x80d/0x9a0 kernel/tracepoint.c:283
tracepoint_probe_register+0x2a/0x40 kernel/tracepoint.c:304
trace_event_reg+0x167/0x320 kernel/trace/trace_events.c:305
perf_trace_event_reg kernel/trace/trace_event_perf.c:122 [inline]
perf_trace_event_init kernel/trace/trace_event_perf.c:197 [inline]
perf_trace_init+0x4f9/0xab0 kernel/trace/trace_event_perf.c:221
perf_tp_event_init+0x7d/0xf0 kernel/events/core.c:8037
perf_try_init_event+0xc9/0x1f0 kernel/events/core.c:9261
perf_init_event kernel/events/core.c:9299 [inline]
perf_event_alloc+0x1c5b/0x2a00 kernel/events/core.c:9558
SYSC_perf_event_open+0x84e/0x2e00 kernel/events/core.c:10013
SyS_perf_event_open+0x39/0x50 kernel/events/core.c:9899
entry_SYSCALL_64_fastpath+0x1f/0xbe

-> #2 (tracepoints_mutex){+.+.}:
check_prevs_add kernel/locking/lockdep.c:2020 [inline]
validate_chain kernel/locking/lockdep.c:2469 [inline]
__lock_acquire+0x328f/0x4620 kernel/locking/lockdep.c:3498
lock_acquire+0x1d5/0x580 kernel/locking/lockdep.c:4002
__mutex_lock_common kernel/locking/mutex.c:756 [inline]
__mutex_lock+0x16f/0x1870 kernel/locking/mutex.c:893
mutex_lock_nested+0x16/0x20 kernel/locking/mutex.c:908
tracepoint_probe_register_prio+0xa0/0x9a0 kernel/tracepoint.c:279
tracepoint_probe_register+0x2a/0x40 kernel/tracepoint.c:304
trace_event_reg+0x167/0x320 kernel/trace/trace_events.c:305
perf_trace_event_reg kernel/trace/trace_event_perf.c:122 [inline]
perf_trace_event_init kernel/trace/trace_event_perf.c:197 [inline]
perf_trace_init+0x4f9/0xab0 kernel/trace/trace_event_perf.c:221
perf_tp_event_init+0x7d/0xf0 kernel/events/core.c:8037
perf_try_init_event+0xc9/0x1f0 kernel/events/core.c:9261
perf_init_event kernel/events/core.c:9299 [inline]
perf_event_alloc+0x1c5b/0x2a00 kernel/events/core.c:9558
SYSC_perf_event_open+0x84e/0x2e00 kernel/events/core.c:10013
SyS_perf_event_open+0x39/0x50 kernel/events/core.c:9899
entry_SYSCALL_64_fastpath+0x1f/0xbe

-> #1 (event_mutex){+.+.}:
check_prevs_add kernel/locking/lockdep.c:2020 [inline]
validate_chain kernel/locking/lockdep.c:2469 [inline]
__lock_acquire+0x328f/0x4620 kernel/locking/lockdep.c:3498
lock_acquire+0x1d5/0x580 kernel/locking/lockdep.c:4002
__mutex_lock_common kernel/locking/mutex.c:756 [inline]
__mutex_lock+0x16f/0x1870 kernel/locking/mutex.c:893
mutex_lock_nested+0x16/0x20 kernel/locking/mutex.c:908
ftrace_profile_set_filter+0x7a/0x270
kernel/trace/trace_events_filter.c:2266
perf_event_set_filter kernel/events/core.c:8622 [inline]
_perf_ioctl kernel/events/core.c:4785 [inline]
perf_ioctl+0x1026/0x1360 kernel/events/core.c:4822
vfs_ioctl fs/ioctl.c:45 [inline]
do_vfs_ioctl+0x1b1/0x1530 fs/ioctl.c:685
SYSC_ioctl fs/ioctl.c:700 [inline]
SyS_ioctl+0x8f/0xc0 fs/ioctl.c:691
entry_SYSCALL_64_fastpath+0x1f/0xbe

-> #0 (&ctx->mutex){+.+.}:
check_prev_add+0x865/0x1520 kernel/locking/lockdep.c:1894
check_prevs_add kernel/locking/lockdep.c:2020 [inline]
validate_chain kernel/locking/lockdep.c:2469 [inline]
__lock_acquire+0x328f/0x4620 kernel/locking/lockdep.c:3498
lock_acquire+0x1d5/0x580 kernel/locking/lockdep.c:4002
__mutex_lock_common kernel/locking/mutex.c:756 [inline]
__mutex_lock+0x16f/0x1870 kernel/locking/mutex.c:893
mutex_lock_nested+0x16/0x20 kernel/locking/mutex.c:908
perf_event_ctx_lock_nested+0x1dc/0x3c0 kernel/events/core.c:1210
perf_event_ctx_lock kernel/events/core.c:1223 [inline]
perf_read+0xb9/0x970 kernel/events/core.c:4584
do_loop_readv_writev fs/read_write.c:693 [inline]
do_iter_read+0x3db/0x5b0 fs/read_write.c:917
vfs_readv+0x121/0x1c0 fs/read_write.c:979
kernel_readv fs/splice.c:361 [inline]
default_file_splice_read+0x508/0xae0 fs/splice.c:416
do_splice_to+0x110/0x170 fs/splice.c:880
do_splice fs/splice.c:1173 [inline]
SYSC_splice fs/splice.c:1402 [inline]
SyS_splice+0x11a8/0x1630 fs/splice.c:1382
entry_SYSCALL_64_fastpath+0x1f/0xbe

other info that might help us debug this:

Chain exists of:
&ctx->mutex --> sb_writers --> &pipe->mutex/1

Possible unsafe locking scenario:

CPU0 CPU1
---- ----
lock(&pipe->mutex/1);
lock(sb_writers);
lock(&pipe->mutex/1);
lock(&ctx->mutex);

*** DEADLOCK ***

1 lock held by syz-executor2/12380:
#0: (&pipe->mutex/1){+.+.}, at: [<ffffffff81ac0fa6>] pipe_lock_nested
fs/pipe.c:66 [inline]
#0: (&pipe->mutex/1){+.+.}, at: [<ffffffff81ac0fa6>] pipe_lock+0x56/0x70
fs/pipe.c:74

stack backtrace:
CPU: 1 PID: 12380 Comm: syz-executor2 Not tainted 4.13.0-next-20170911+ #19
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS
Google 01/01/2011
Call Trace:
__dump_stack lib/dump_stack.c:16 [inline]
dump_stack+0x194/0x257 lib/dump_stack.c:52
print_circular_bug+0x503/0x710 kernel/locking/lockdep.c:1259
check_prev_add+0x865/0x1520 kernel/locking/lockdep.c:1894
check_prevs_add kernel/locking/lockdep.c:2020 [inline]
validate_chain kernel/locking/lockdep.c:2469 [inline]
__lock_acquire+0x328f/0x4620 kernel/locking/lockdep.c:3498
lock_acquire+0x1d5/0x580 kernel/locking/lockdep.c:4002
__mutex_lock_common kernel/locking/mutex.c:756 [inline]
__mutex_lock+0x16f/0x1870 kernel/locking/mutex.c:893
mutex_lock_nested+0x16/0x20 kernel/locking/mutex.c:908
perf_event_ctx_lock_nested+0x1dc/0x3c0 kernel/events/core.c:1210
perf_event_ctx_lock kernel/events/core.c:1223 [inline]
perf_read+0xb9/0x970 kernel/events/core.c:4584
do_loop_readv_writev fs/read_write.c:693 [inline]
do_iter_read+0x3db/0x5b0 fs/read_write.c:917
vfs_readv+0x121/0x1c0 fs/read_write.c:979
kernel_readv fs/splice.c:361 [inline]
default_file_splice_read+0x508/0xae0 fs/splice.c:416
do_splice_to+0x110/0x170 fs/splice.c:880
do_splice fs/splice.c:1173 [inline]
SYSC_splice fs/splice.c:1402 [inline]
SyS_splice+0x11a8/0x1630 fs/splice.c:1382
entry_SYSCALL_64_fastpath+0x1f/0xbe
RIP: 0033:0x451e59
RSP: 002b:00007ff32dce9c08 EFLAGS: 00000216 ORIG_RAX: 0000000000000113
RAX: ffffffffffffffda RBX: 0000000000718000 RCX: 0000000000451e59
RDX: 000000000000001b RSI: 0000000000000000 RDI: 000000000000001c
RBP: 0000000000000082 R08: 0000000200000005 R09: 0000000000000009
R10: 0000000000000000 R11: 0000000000000216 R12: 0000000000000000
R13: 0000000000a6f7ef R14: 00007ff32dcea9c0 R15: 0000000000000000
sctp: [Deprecated]: syz-executor1 (pid 12436) Use of struct
sctp_assoc_value in delayed_ack socket option.
Use struct sctp_sack_info instead
sctp: [Deprecated]: syz-executor1 (pid 12439) Use of struct
sctp_assoc_value in delayed_ack socket option.
Use struct sctp_sack_info instead
loop_reread_partitions: partition scan of loop0
(- \� t�@�� r�9h �x G�Q:[��i�l �
�L�*� �@� ���R�-�T�r-�x�� ) failed (rc=-13)
QAT: Invalid ioctl
QAT: Invalid ioctl
QAT: Invalid ioctl
QAT: Invalid ioctl
sctp: [Deprecated]: syz-executor0 (pid 12525) Use of struct
sctp_assoc_value in delayed_ack socket option.
Use struct sctp_sack_info instead
sctp: [Deprecated]: syz-executor0 (pid 12525) Use of struct
sctp_assoc_value in delayed_ack socket option.
Use struct sctp_sack_info instead
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
xs_tcp_setup_socket: connect returned unhandled error -113
IPv6: ADDRCONF(NETDEV_CHANGE): lo: link becomes ready
kvm: pic: non byte write
kvm: pic: single mode not supported
QAT: Invalid ioctl
QAT: Invalid ioctl
pit: kvm: requested 2514 ns i8254 timer period limited to 500000 ns
sctp: [Deprecated]: syz-executor2 (pid 12946) Use of int in maxseg socket
option.
Use struct sctp_assoc_value instead
sctp: [Deprecated]: syz-executor2 (pid 12946) Use of int in maxseg socket
option.
Use struct sctp_assoc_value instead
nla_parse: 6 callbacks suppressed
netlink: 5 bytes leftover after parsing attributes in process
`syz-executor5'.
netlink: 5 bytes leftover after parsing attributes in process
`syz-executor5'.
pit: kvm: requested 2514 ns i8254 timer period limited to 500000 ns
pit: kvm: requested 2514 ns i8254 timer period limited to 500000 ns
kauditd_printk_skb: 65 callbacks suppressed
audit: type=1326 audit(1505176342.033:940): auid=4294967295 uid=0 gid=0
ses=4294967295 subj=kernel pid=13113 comm="" exe="/root/syz-executor1"
sig=0 arch=c000003e syscall=202 compat=0 ip=0x451e59 code=0x50000
audit: type=1326 audit(1505176342.059:941): auid=4294967295 uid=0 gid=0
ses=4294967295 subj=kernel pid=13113 comm="" exe="/root/syz-executor1"
sig=0 arch=c000003e syscall=2 compat=0 ip=0x40c3e1 code=0x50000
audit: type=1326 audit(1505176342.059:942): auid=4294967295 uid=0 gid=0
ses=4294967295 subj=kernel pid=13113 comm="" exe="/root/syz-executor1"
sig=0 arch=c000003e syscall=202 compat=0 ip=0x451e59 code=0x50000
audit: type=1326 audit(1505176342.059:943): auid=4294967295 uid=0 gid=0
ses=4294967295 subj=kernel pid=13113 comm="" exe="/root/syz-executor1"
sig=0 arch=c000003e syscall=202 compat=0 ip=0x451e59 code=0x50000
audit: type=1326 audit(1505176342.060:944): auid=4294967295 uid=0 gid=0
ses=4294967295 subj=kernel pid=13113 comm="" exe="/root/syz-executor1"
sig=0 arch=c000003e syscall=202 compat=0 ip=0x451e59 code=0x50000
audit: type=1326 audit(1505176342.060:945): auid=4294967295 uid=0 gid=0
ses=4294967295 subj=kernel pid=13113 comm="" exe="/root/syz-executor1"
sig=0 arch=c000003e syscall=202 compat=0 ip=0x451e59 code=0x50000
audit: type=1326 audit(1505176342.060:946): auid=4294967295 uid=0 gid=0
ses=4294967295 subj=kernel pid=13113 comm="" exe="/root/syz-executor1"
sig=0 arch=c000003e syscall=202 compat=0 ip=0x451e59 code=0x50000
audit: type=1326 audit(1505176342.060:947): auid=4294967295 uid=0 gid=0
ses=4294967295 subj=kernel pid=13113 comm="" exe="/root/syz-executor1"
sig=0 arch=c000003e syscall=202 compat=0 ip=0x451e59 code=0x50000
audit: type=1326 audit(1505176342.060:948): auid=4294967295 uid=0 gid=0
ses=4294967295 subj=kernel pid=13113 comm="" exe="/root/syz-executor1"
sig=0 arch=c000003e syscall=202 compat=0 ip=0x451e59 code=0x50000
audit: type=1326 audit(1505176342.061:949): auid=4294967295 uid=0 gid=0
ses=4294967295 subj=kernel pid=13113 comm="" exe="/root/syz-executor1"
sig=0 arch=c000003e syscall=202 compat=0 ip=0x451e59 code=0x50000
pit: kvm: requested 2514 ns i8254 timer period limited to 500000 ns
pit: kvm: requested 2514 ns i8254 timer period limited to 500000 ns
pit: kvm: requested 2514 ns i8254 timer period limited to 500000 ns
pit: kvm: requested 2514 ns i8254 timer period limited to 500000 ns
pit: kvm: requested 2514 ns i8254 timer period limited to 500000 ns
pit: kvm: requested 2514 ns i8254 timer period limited to 500000 ns
QAT: Invalid ioctl
device syz5 entered promiscuous mode
QAT: Invalid ioctl
device syz5 left promiscuous mode
device syz5 entered promiscuous mode
pit: kvm: requested 2514 ns i8254 timer period limited to 500000 ns
do_dccp_getsockopt: sockopt(PACKET_SIZE) is deprecated: fix your app
do_dccp_getsockopt: sockopt(PACKET_SIZE) is deprecated: fix your app
device syz2 entered promiscuous mode
device syz2 left promiscuous mode
device syz2 entered promiscuous mode
netlink: 5 bytes leftover after parsing attributes in process
`syz-executor2'.
SELinux: unrecognized netlink message: protocol=0 nlmsg_type=0
sclass=netlink_route_socket pig=13714 comm=syz-executor2
FAULT_INJECTION: forcing a failure.
name failslab, interval 1, probability 0, space 0, times 1
sctp: [Deprecated]: syz-executor1 (pid 13806) Use of int in max_burst
socket option.
Use struct sctp_assoc_value instead
CPU: 0 PID: 13805 Comm: syz-executor6 Not tainted 4.13.0-next-20170911+ #19
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS
Google 01/01/2011
Call Trace:
__dump_stack lib/dump_stack.c:16 [inline]
dump_stack+0x194/0x257 lib/dump_stack.c:52
fail_dump lib/fault-inject.c:51 [inline]
should_fail+0x8c0/0xa40 lib/fault-inject.c:149
should_failslab+0xec/0x120 mm/failslab.c:31
slab_pre_alloc_hook mm/slab.h:422 [inline]
slab_alloc mm/slab.c:3383 [inline]
__do_kmalloc mm/slab.c:3723 [inline]
__kmalloc_track_caller+0x5f/0x760 mm/slab.c:3740
memdup_user+0x2c/0x90 mm/util.c:164
map_lookup_elem+0x21c/0xb30 kernel/bpf/syscall.c:461
SYSC_bpf kernel/bpf/syscall.c:1473 [inline]
SyS_bpf+0x1070/0x46a0 kernel/bpf/syscall.c:1451
entry_SYSCALL_64_fastpath+0x1f/0xbe
RIP: 0033:0x451e59
RSP: 002b:00007f75f19e1c08 EFLAGS: 00000216 ORIG_RAX: 0000000000000141
RAX: ffffffffffffffda RBX: 0000000000718000 RCX: 0000000000451e59
RDX: 0000000000000018 RSI: 00000000204a2fe8 RDI: 0000000000000001
RBP: 00007f75f19e1a10 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000216 R12: 00000000004b69f7
R13: 00007f75f19e1b48 R14: 00000000004b6a07 R15: 0000000000000000
sctp: [Deprecated]: syz-executor1 (pid 13814) Use of int in max_burst
socket option.
Use struct sctp_assoc_value instead
sctp: [Deprecated]: syz-executor1 (pid 13873) Use of int in max_burst
socket option.
Use struct sctp_assoc_value instead
sctp: [Deprecated]: syz-executor1 (pid 13895) Use of int in max_burst
socket option.
Use struct sctp_assoc_value instead
FAULT_INJECTION: forcing a failure.
name failslab, interval 1, probability 0, space 0, times 0
CPU: 1 PID: 14039 Comm: syz-executor3 Not tainted 4.13.0-next-20170911+ #19
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS
Google 01/01/2011
Call Trace:
__dump_stack lib/dump_stack.c:16 [inline]
dump_stack+0x194/0x257 lib/dump_stack.c:52
fail_dump lib/fault-inject.c:51 [inline]
should_fail+0x8c0/0xa40 lib/fault-inject.c:149
should_failslab+0xec/0x120 mm/failslab.c:31
slab_pre_alloc_hook mm/slab.h:422 [inline]
slab_alloc_node mm/slab.c:3304 [inline]
kmem_cache_alloc_node+0x56/0x760 mm/slab.c:3649
__alloc_skb+0xf1/0x740 net/core/skbuff.c:194
alloc_skb include/linux/skbuff.h:976 [inline]
tcp_xmit_probe_skb+0x67/0x360 net/ipv4/tcp_output.c:3599
tcp_send_window_probe+0x11d/0x150 net/ipv4/tcp_output.c:3621
do_tcp_setsockopt.isra.35+0xca7/0x1fd0 net/ipv4/tcp.c:2586
tcp_setsockopt+0xb0/0xd0 net/ipv4/tcp.c:2801
sock_common_setsockopt+0x95/0xd0 net/core/sock.c:2960
SYSC_setsockopt net/socket.c:1852 [inline]
SyS_setsockopt+0x189/0x360 net/socket.c:1831
entry_SYSCALL_64_fastpath+0x1f/0xbe
RIP: 0033:0x451e59
RSP: 002b:00007f1f8ae1bc08 EFLAGS: 00000216 ORIG_RAX: 0000000000000036
RAX: ffffffffffffffda RBX: 0000000000718000 RCX: 0000000000451e59
RDX: 0000000000000013 RSI: 0000000000000006 RDI: 0000000000000005
RBP: 00007f1f8ae1ba10 R08: 0000000000000004 R09: 0000000000000000
R10: 0000000020d15000 R11: 0000000000000216 R12: 00000000004b69f7
R13: 00007f1f8ae1bb48 R14: 00000000004b6a07 R15: 0000000000000000
sg_write: data in/out 3171656/194 bytes for SCSI command 0x2a-- guessing
data in;
program syz-executor2 not setting count and/or reply_len properly
sg_write: data in/out 3171656/194 bytes for SCSI command 0x2a-- guessing
data in;
program syz-executor2 not setting count and/or reply_len properly
create_pit_timer: 19 callbacks suppressed
pit: kvm: requested 2514 ns i8254 timer period limited to 500000 ns
pit: kvm: requested 2514 ns i8254 timer period limited to 500000 ns


---
This bug is generated by a dumb bot. It may contain errors.
See https://goo.gl/tpsmEJ for details.
Direct all questions to syzk...@googlegroups.com.

syzbot will keep track of this bug report.
Once a fix for this bug is committed, please reply to this email with:
#syz fix: exact-commit-title
To mark this as a duplicate of another syzbot report, please reply with:
#syz dup: exact-subject-of-another-report
If it's a one-off invalid bug report, please reply with:
#syz invalid
Note: if the crash happens again, it will cause creation of a new bug
report.

[Dmitry Vyukov]

On Fri, Oct 27, 2017 at 10:30 AM, syzbot
<bot+f67ad450a4bd1e42a7...@syzkaller.appspotmail.com>
wrote:

> Hello,
>
> syzkaller hit the following crash on
> a31cc455c512f3f1dd5f79cac8e29a7c8a617af8
> git://git.kernel.org/pub/scm/linux/kernel/git/next/linux-next.git/master
> compiler: gcc (GCC) 7.1.1 20170620
> .config is attached
> Raw console output is attached.

Last happened on upstream 68ebe3cbe786a954481d6ded0dc83f7d551640bf (Oct 9).

> --
> You received this message because you are subscribed to the Google Groups
> "syzkaller-bugs" group.
> To unsubscribe from this group and stop receiving emails from it, send an
> email to syzkaller-bug...@googlegroups.com.
> To view this discussion on the web visit
> https://groups.google.com/d/msgid/syzkaller-bugs/001a11448f6c0346ec055c831a71%40google.com.
> For more options, visit https://groups.google.com/d/optout.

[Peter Zijlstra]

On Fri, Oct 27, 2017 at 01:30:30AM -0700, syzbot wrote:

> ======================================================
> WARNING: possible circular locking dependency detected
> 4.13.0-next-20170911+ #19 Not tainted
> ------------------------------------------------------
> syz-executor2/12380 is trying to acquire lock:
> (&ctx->mutex){+.+.}, at: [<ffffffff8180923c>]
> perf_event_ctx_lock_nested+0x1dc/0x3c0 kernel/events/core.c:1210
>
> but task is already holding lock:
> (&pipe->mutex/1){+.+.}, at: [<ffffffff81ac0fa6>] pipe_lock_nested
> fs/pipe.c:66 [inline]
> (&pipe->mutex/1){+.+.}, at: [<ffffffff81ac0fa6>] pipe_lock+0x56/0x70
> fs/pipe.c:74
>
> which lock already depends on the new lock.

ARRGH!!

that translates like the below, which is an absolute maze and requires
at least 5 concurrent callstacks, possibly more.

We already had a lot of fun with hotplug-perf-ftrace, but the below
contains more. Let me try and page that previous crap back.



perf_ioctl()
#0 perf_event_ctx_lock() [ctx->mutex]
perf_event_set_filter
#1 ftrace_profile_set_filter [event_mutex]




sys_perf_event_open
...
perf_trace_init
#1 mutex_lock [event_mutex]
trace_event_reg
tracepoint_probe_register
#2 mutex_lock() [tracepoints_mutex]
tracepoint_add_func()
#3 static_key_slow_inc() [cpuhotplug_lock]





cpuhp_setup_state_nocalls
#3 cpus_read_lock [cpuhotplug_lock]
__cpuhp_setup_state_cpuslocked
#4 mutex_lock [cpuhp_state_mutex]
cpuhp_issue_call
#5 cpuhp_invoke_ap_callback() [cpuhp_state]


#5 cpuhp_invoke_callback [cpuhp_state]
...
devtmpfs_create_node
#6 wait_for_completion() [&req.done]

devtmpfsd
handle_create
#7 filename_create [sb_writers]
#6 complete [&req.done]






do_splice
#7 file_start_write() [sb_writers]
do_splice_from
iter_file_splice_write
#8 pipe_lock [pipe->mutex]





do_splice
#8 pipe_lock [pipe->mutex]
do_splice_to
...
#0 perf_read() [ctx->mutex]

[Peter Zijlstra]

So arguably that last op, splice_read from a perf fd is fairly
pointless and we could dis-allow that. How about something like the
below?

---
kernel/events/core.c | 8 ++++++++
1 file changed, 8 insertions(+)

diff --git a/kernel/events/core.c b/kernel/events/core.c
index 04989fb769f0..fd03f3082ee3 100644
--- a/kernel/events/core.c
+++ b/kernel/events/core.c
@@ -5468,6 +5468,13 @@ static int perf_fasync(int fd, struct file *filp, int on)
return 0;
}

+static ssize_t perf_splice_read(struct file *file, loff_t *ppos,
+ struct pipe_inode_info *pope, size_t len,
+ unsigned int flags)
+{
+ return -EOPNOTSUPP;
+}
+
static const struct file_operations perf_fops = {
.llseek = no_llseek,
.release = perf_release,
@@ -5477,6 +5484,7 @@ static int perf_fasync(int fd, struct file *filp, int on)
.compat_ioctl = perf_compat_ioctl,
.mmap = perf_mmap,
.fasync = perf_fasync,
+ .splice_read = perf_splice_read,
};

/*

[Dmitry Vyukov]

Another perf deadlock that involves splice:
https://groups.google.com/d/msg/syzkaller-bugs/vVy6Zj3wPxo/6oj5U6WiAwAJ

[Dmitry Vyukov]

Peter,

What's the status of this? Is your patch still relevant?

[syzbot]

Auto-closing this bug as obsolete.
Crashes did not happen for a while, no reproducer and no activity.