possible deadlock in ftrace_profile_set_filter (2)

14 views
Skip to first unread message

syzbot

unread,
Dec 3, 2017, 9:28:04ā€ÆAM12/3/17
to linux-...@vger.kernel.org, mi...@redhat.com, ros...@goodmis.org, syzkall...@googlegroups.com
Hello,

syzkaller hit the following crash on
d127129e85a020879f334154300ddd3f7ec21c1e
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.

Unfortunately, I don't have any reproducer for this bug yet.



======================================================
WARNING: possible circular locking dependency detected
4.15.0-rc1-next-20171129+ #55 Not tainted
------------------------------------------------------
syz-executor6/4011 is trying to acquire lock:
(event_mutex){+.+.}, at: [<ffffffff8178e86a>]
ftrace_profile_set_filter+0x7a/0x270 kernel/trace/trace_events_filter.c:2266

but task is already holding lock:
(&ctx->mutex){+.+.}, at: [<ffffffff81844e3b>]
perf_event_ctx_lock_nested+0x21b/0x450 kernel/events/core.c:1249

which lock already depends on the new lock.


the existing dependency chain (in reverse order) is:

-> #8 (&ctx->mutex){+.+.}:
lock_acquire+0x1d5/0x580 kernel/locking/lockdep.c:4004
__mutex_lock_common kernel/locking/mutex.c:756 [inline]
__mutex_lock+0x16f/0x1a80 kernel/locking/mutex.c:893
mutex_lock_nested+0x16/0x20 kernel/locking/mutex.c:908
perf_event_ctx_lock_nested+0x21b/0x450 kernel/events/core.c:1249
perf_event_ctx_lock kernel/events/core.c:1262 [inline]
perf_read+0xb9/0x970 kernel/events/core.c:4507
do_loop_readv_writev fs/read_write.c:673 [inline]
do_iter_read+0x3db/0x5b0 fs/read_write.c:897
vfs_readv+0x121/0x1c0 fs/read_write.c:959
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/0x96

-> #7 (&pipe->mutex/1){+.+.}:
lock_acquire+0x1d5/0x580 kernel/locking/lockdep.c:4004
__mutex_lock_common kernel/locking/mutex.c:756 [inline]
__mutex_lock+0x16f/0x1a80 kernel/locking/mutex.c:893
mutex_lock_nested+0x16/0x20 kernel/locking/mutex.c:908
pipe_lock_nested fs/pipe.c:67 [inline]
pipe_lock+0x56/0x70 fs/pipe.c:75
iter_file_splice_write+0x264/0xf30 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/0x96

-> #6 (sb_writers){.+.+}:
spin_lock include/linux/spinlock.h:315 [inline]
d_instantiate+0x66/0xa0 fs/dcache.c:1851

-> #5 ((completion)&req.done){+.+.}:
lock_acquire+0x1d5/0x580 kernel/locking/lockdep.c:4004
complete_acquire include/linux/completion.h:40 [inline]
__wait_for_common kernel/sched/completion.c:109 [inline]
wait_for_common kernel/sched/completion.c:123 [inline]
wait_for_completion+0xcb/0x7b0 kernel/sched/completion.c:144
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+0x2ea/0x1d20 kernel/cpu.c:182
cpuhp_thread_fun+0x48e/0x7e0 kernel/cpu.c:571
smpboot_thread_fn+0x450/0x7c0 kernel/smpboot.c:164
kthread+0x37a/0x440 kernel/kthread.c:238
ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:517

-> #4 (cpuhp_state-up){+.+.}:
lock_acquire+0x1d5/0x580 kernel/locking/lockdep.c:4004
cpuhp_lock_acquire kernel/cpu.c:85 [inline]
cpuhp_invoke_ap_callback kernel/cpu.c:605 [inline]
cpuhp_issue_call+0x1e5/0x520 kernel/cpu.c:1495
__cpuhp_setup_state_cpuslocked+0x282/0x600 kernel/cpu.c:1642
__cpuhp_setup_state+0xb0/0x140 kernel/cpu.c:1671
cpuhp_setup_state include/linux/cpuhotplug.h:201 [inline]
page_writeback_init+0x4d/0x71 mm/page-writeback.c:2081
pagecache_init+0x48/0x4f mm/filemap.c:976
start_kernel+0x6bc/0x74f init/main.c:698
x86_64_start_reservations+0x2a/0x2c arch/x86/kernel/head64.c:378
x86_64_start_kernel+0x77/0x7a arch/x86/kernel/head64.c:359
secondary_startup_64+0xa5/0xb0 arch/x86/kernel/head_64.S:237

-> #3 (cpuhp_state_mutex){+.+.}:
lock_acquire+0x1d5/0x580 kernel/locking/lockdep.c:4004
__mutex_lock_common kernel/locking/mutex.c:756 [inline]
__mutex_lock+0x16f/0x1a80 kernel/locking/mutex.c:893
mutex_lock_nested+0x16/0x20 kernel/locking/mutex.c:908
__cpuhp_setup_state_cpuslocked+0x5b/0x600 kernel/cpu.c:1617
__cpuhp_setup_state+0xb0/0x140 kernel/cpu.c:1671
cpuhp_setup_state_nocalls include/linux/cpuhotplug.h:229 [inline]
kvm_guest_init+0x1f3/0x20f arch/x86/kernel/kvm.c:528
setup_arch+0x17e8/0x1a02 arch/x86/kernel/setup.c:1266
start_kernel+0xa5/0x74f init/main.c:533
x86_64_start_reservations+0x2a/0x2c arch/x86/kernel/head64.c:378
x86_64_start_kernel+0x77/0x7a arch/x86/kernel/head64.c:359
secondary_startup_64+0xa5/0xb0 arch/x86/kernel/head_64.S:237

-> #2 (cpu_hotplug_lock.rw_sem){++++}:
lock_acquire+0x1d5/0x580 kernel/locking/lockdep.c:4004
percpu_down_read_preempt_disable include/linux/percpu-rwsem.h:36
[inline]
percpu_down_read include/linux/percpu-rwsem.h:59 [inline]
cpus_read_lock+0x42/0x90 kernel/cpu.c:293
static_key_slow_inc+0x9d/0x3c0 kernel/jump_label.c:123
tracepoint_add_func kernel/tracepoint.c:222 [inline]
tracepoint_probe_register_prio+0x80d/0x9a0 kernel/tracepoint.c:282
tracepoint_probe_register+0x2a/0x40 kernel/tracepoint.c:303
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+0x4ef/0xab0 kernel/trace/trace_event_perf.c:221
perf_tp_event_init+0x7d/0xf0 kernel/events/core.c:7956
perf_try_init_event+0xc9/0x1f0 kernel/events/core.c:9189
perf_init_event kernel/events/core.c:9227 [inline]
perf_event_alloc+0x1cc6/0x2b00 kernel/events/core.c:9491
SYSC_perf_event_open+0x84e/0x2e00 kernel/events/core.c:9946
SyS_perf_event_open+0x39/0x50 kernel/events/core.c:9832
entry_SYSCALL_64_fastpath+0x1f/0x96

-> #1 (tracepoints_mutex){+.+.}:
lock_acquire+0x1d5/0x580 kernel/locking/lockdep.c:4004
__mutex_lock_common kernel/locking/mutex.c:756 [inline]
__mutex_lock+0x16f/0x1a80 kernel/locking/mutex.c:893
mutex_lock_nested+0x16/0x20 kernel/locking/mutex.c:908
tracepoint_probe_register_prio+0xa0/0x9a0 kernel/tracepoint.c:278
tracepoint_probe_register+0x2a/0x40 kernel/tracepoint.c:303
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+0x4ef/0xab0 kernel/trace/trace_event_perf.c:221
perf_tp_event_init+0x7d/0xf0 kernel/events/core.c:7956
perf_try_init_event+0xc9/0x1f0 kernel/events/core.c:9189
perf_init_event kernel/events/core.c:9227 [inline]
perf_event_alloc+0x1cc6/0x2b00 kernel/events/core.c:9491
SYSC_perf_event_open+0x84e/0x2e00 kernel/events/core.c:9946
SyS_perf_event_open+0x39/0x50 kernel/events/core.c:9832
entry_SYSCALL_64_fastpath+0x1f/0x96

-> #0 (event_mutex){+.+.}:
check_prevs_add kernel/locking/lockdep.c:2031 [inline]
validate_chain kernel/locking/lockdep.c:2473 [inline]
__lock_acquire+0x3498/0x47f0 kernel/locking/lockdep.c:3500
lock_acquire+0x1d5/0x580 kernel/locking/lockdep.c:4004
__mutex_lock_common kernel/locking/mutex.c:756 [inline]
__mutex_lock+0x16f/0x1a80 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:8542 [inline]
_perf_ioctl kernel/events/core.c:4708 [inline]
perf_ioctl+0x1090/0x1400 kernel/events/core.c:4745
vfs_ioctl fs/ioctl.c:46 [inline]
do_vfs_ioctl+0x1b1/0x1530 fs/ioctl.c:686
SYSC_ioctl fs/ioctl.c:701 [inline]
SyS_ioctl+0x8f/0xc0 fs/ioctl.c:692
entry_SYSCALL_64_fastpath+0x1f/0x96

other info that might help us debug this:

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

Possible unsafe locking scenario:

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

*** DEADLOCK ***

1 lock held by syz-executor6/4011:
#0: (&ctx->mutex){+.+.}, at: [<ffffffff81844e3b>]
perf_event_ctx_lock_nested+0x21b/0x450 kernel/events/core.c:1249

stack backtrace:
CPU: 0 PID: 4011 Comm: syz-executor6 Not tainted 4.15.0-rc1-next-20171129+
#55
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS
Google 01/01/2011
Call Trace:
__dump_stack lib/dump_stack.c:17 [inline]
dump_stack+0x194/0x257 lib/dump_stack.c:53
print_circular_bug+0x42d/0x610 kernel/locking/lockdep.c:1271
check_prev_add+0x666/0x15f0 kernel/locking/lockdep.c:1914
check_prevs_add kernel/locking/lockdep.c:2031 [inline]
validate_chain kernel/locking/lockdep.c:2473 [inline]
__lock_acquire+0x3498/0x47f0 kernel/locking/lockdep.c:3500
lock_acquire+0x1d5/0x580 kernel/locking/lockdep.c:4004
__mutex_lock_common kernel/locking/mutex.c:756 [inline]
__mutex_lock+0x16f/0x1a80 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:8542 [inline]
_perf_ioctl kernel/events/core.c:4708 [inline]
perf_ioctl+0x1090/0x1400 kernel/events/core.c:4745
vfs_ioctl fs/ioctl.c:46 [inline]
do_vfs_ioctl+0x1b1/0x1530 fs/ioctl.c:686
SYSC_ioctl fs/ioctl.c:701 [inline]
SyS_ioctl+0x8f/0xc0 fs/ioctl.c:692
entry_SYSCALL_64_fastpath+0x1f/0x96
RIP: 0033:0x4529d9
RSP: 002b:00007fcca1818c58 EFLAGS: 00000212 ORIG_RAX: 0000000000000010
RAX: ffffffffffffffda RBX: 0000000000758020 RCX: 00000000004529d9
RDX: 0000000020114000 RSI: 0000000040082406 RDI: 0000000000000018
RBP: 0000000000000152 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000212 R12: 00000000006ef050
R13: 00000000ffffffff R14: 00007fcca18196d4 R15: 0000000000000000
device gre0 entered promiscuous mode
device gre0 entered promiscuous mode
device gre0 entered promiscuous mode
RDS: rds_bind could not find a transport for 172.20.6.170, load rds_tcp or
rds_rdma?
device gre0 entered promiscuous mode
RDS: rds_bind could not find a transport for 172.20.6.170, load rds_tcp or
rds_rdma?
device gre0 entered promiscuous mode
device gre0 entered promiscuous mode
device gre0 entered promiscuous mode
device gre0 entered promiscuous mode
device gre0 entered promiscuous mode
device gre0 entered promiscuous mode
device gre0 entered promiscuous mode
device gre0 entered promiscuous mode
device gre0 entered promiscuous mode
FAULT_INJECTION: forcing a failure.
name failslab, interval 1, probability 0, space 0, times 1
CPU: 0 PID: 4433 Comm: syz-executor4 Not tainted 4.15.0-rc1-next-20171129+
#55
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS
Google 01/01/2011
Call Trace:
__dump_stack lib/dump_stack.c:17 [inline]
dump_stack+0x194/0x257 lib/dump_stack.c:53
fail_dump lib/fault-inject.c:51 [inline]
should_fail+0x8c0/0xa40 lib/fault-inject.c:149
should_failslab+0xec/0x120 mm/failslab.c:32
slab_pre_alloc_hook mm/slab.h:425 [inline]
slab_alloc_node mm/slab.c:3293 [inline]
kmem_cache_alloc_node_trace+0x5a/0x760 mm/slab.c:3655
__do_kmalloc_node mm/slab.c:3675 [inline]
__kmalloc_node+0x33/0x70 mm/slab.c:3683
kmalloc_node include/linux/slab.h:556 [inline]
kvmalloc_node+0x99/0xd0 mm/util.c:397
kvmalloc include/linux/mm.h:541 [inline]
seq_buf_alloc fs/seq_file.c:29 [inline]
seq_read+0x7cd/0x13d0 fs/seq_file.c:205
proc_reg_read+0xef/0x170 fs/proc/inode.c:217
__vfs_read+0xef/0xa00 fs/read_write.c:411
vfs_read+0x124/0x360 fs/read_write.c:447
SYSC_pread64 fs/read_write.c:611 [inline]
SyS_pread64+0x161/0x190 fs/read_write.c:598
entry_SYSCALL_64_fastpath+0x1f/0x96
RIP: 0033:0x4529d9
RSP: 002b:00007f81c9755c58 EFLAGS: 00000212 ORIG_RAX: 0000000000000011
RAX: ffffffffffffffda RBX: 0000000000758020 RCX: 00000000004529d9
RDX: 0000000000000000 RSI: 0000000020015000 RDI: 0000000000000013
RBP: 00000000000005ab R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000212 R12: 00000000006f58a8
R13: 00000000ffffffff R14: 00007f81c97566d4 R15: 0000000000000000
FAULT_INJECTION: forcing a failure.
name fail_page_alloc, interval 1, probability 0, space 0, times 1
CPU: 0 PID: 4444 Comm: syz-executor4 Not tainted 4.15.0-rc1-next-20171129+
#55
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS
Google 01/01/2011
Call Trace:
__dump_stack lib/dump_stack.c:17 [inline]
dump_stack+0x194/0x257 lib/dump_stack.c:53
fail_dump lib/fault-inject.c:51 [inline]
should_fail+0x8c0/0xa40 lib/fault-inject.c:149
should_fail_alloc_page mm/page_alloc.c:2943 [inline]
prepare_alloc_pages mm/page_alloc.c:4196 [inline]
__alloc_pages_nodemask+0x338/0xd80 mm/page_alloc.c:4235
__alloc_pages include/linux/gfp.h:456 [inline]
__alloc_pages_node include/linux/gfp.h:469 [inline]
kmem_getpages mm/slab.c:1414 [inline]
cache_grow_begin+0x72/0x570 mm/slab.c:2672
cache_alloc_refill mm/slab.c:3039 [inline]
____cache_alloc mm/slab.c:3121 [inline]
slab_alloc_node mm/slab.c:3316 [inline]
kmem_cache_alloc_node_trace+0x438/0x760 mm/slab.c:3655
__do_kmalloc_node mm/slab.c:3675 [inline]
__kmalloc_node+0x33/0x70 mm/slab.c:3683
kmalloc_node include/linux/slab.h:556 [inline]
kvmalloc_node+0x99/0xd0 mm/util.c:397
kvmalloc include/linux/mm.h:541 [inline]
seq_buf_alloc fs/seq_file.c:29 [inline]
seq_read+0x7cd/0x13d0 fs/seq_file.c:205
proc_reg_read+0xef/0x170 fs/proc/inode.c:217
__vfs_read+0xef/0xa00 fs/read_write.c:411
vfs_read+0x124/0x360 fs/read_write.c:447
SYSC_pread64 fs/read_write.c:611 [inline]
SyS_pread64+0x161/0x190 fs/read_write.c:598
entry_SYSCALL_64_fastpath+0x1f/0x96
RIP: 0033:0x4529d9
RSP: 002b:00007f81c9755c58 EFLAGS: 00000212 ORIG_RAX: 0000000000000011
RAX: ffffffffffffffda RBX: 0000000000758020 RCX: 00000000004529d9
RDX: 0000000000000000 RSI: 0000000020015000 RDI: 0000000000000013
RBP: 00000000000005ab R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000212 R12: 00000000006f58a8
R13: 00000000ffffffff R14: 00007f81c97566d4 R15: 0000000000000000
device gre0 entered promiscuous mode
device gre0 entered promiscuous mode
netlink: 21 bytes leftover after parsing attributes in process
`syz-executor0'.
device gre0 entered promiscuous mode
netlink: 21 bytes leftover after parsing attributes in process
`syz-executor0'.
device gre0 entered promiscuous mode
device gre0 entered promiscuous mode
device gre0 entered promiscuous mode
device gre0 entered promiscuous mode
device gre0 entered promiscuous mode
device gre0 entered promiscuous mode
device gre0 entered promiscuous mode
device gre0 entered promiscuous mode
device gre0 entered promiscuous mode
device gre0 entered promiscuous mode
device gre0 entered promiscuous mode
device gre0 entered promiscuous mode
device gre0 entered promiscuous mode
device gre0 entered promiscuous mode
device gre0 entered promiscuous mode
device gre0 entered promiscuous mode
netlink: 2 bytes leftover after parsing attributes in process
`syz-executor4'.
netlink: 2 bytes leftover after parsing attributes in process
`syz-executor4'.
device gre0 entered promiscuous mode
netlink: 2 bytes leftover after parsing attributes in process
`syz-executor4'.
netlink: 2 bytes leftover after parsing attributes in process
`syz-executor4'.
device gre0 entered promiscuous mode
device gre0 entered promiscuous mode
device gre0 entered promiscuous mode
device gre0 entered promiscuous mode
device gre0 entered promiscuous mode
device gre0 entered promiscuous mode
kauditd_printk_skb: 388 callbacks suppressed
audit: type=1326 audit(1511934952.475:400): auid=4294967295 uid=0 gid=0
ses=4294967295 subj=kernel pid=5121 comm="syz-executor0"
exe="/root/syz-executor0" sig=31 arch=c000003e syscall=202 compat=0
ip=0x4529d9 code=0xffff0000
device gre0 entered promiscuous mode
device gre0 entered promiscuous mode
device gre0 entered promiscuous mode
device gre0 entered promiscuous mode
device gre0 entered promiscuous mode
device gre0 entered promiscuous mode
device gre0 entered promiscuous mode
device gre0 entered promiscuous mode
device gre0 entered promiscuous mode
device gre0 entered promiscuous mode
QAT: Invalid ioctl
device gre0 entered promiscuous mode
device gre0 entered promiscuous mode
device gre0 entered promiscuous mode
device gre0 entered promiscuous mode
device gre0 entered promiscuous mode
device gre0 entered promiscuous mode
device gre0 entered promiscuous mode
device gre0 entered promiscuous mode
device gre0 entered promiscuous mode
device gre0 entered promiscuous mode
QAT: Invalid ioctl
QAT: Invalid ioctl
device gre0 entered promiscuous mode
device gre0 entered promiscuous mode
device gre0 entered promiscuous mode
FAULT_INJECTION: forcing a failure.
name failslab, interval 1, probability 0, space 0, times 0
CPU: 1 PID: 6020 Comm: syz-executor5 Not tainted 4.15.0-rc1-next-20171129+
#55
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS
Google 01/01/2011
Call Trace:
__dump_stack lib/dump_stack.c:17 [inline]
dump_stack+0x194/0x257 lib/dump_stack.c:53
fail_dump lib/fault-inject.c:51 [inline]
should_fail+0x8c0/0xa40 lib/fault-inject.c:149
should_failslab+0xec/0x120 mm/failslab.c:32
slab_pre_alloc_hook mm/slab.h:425 [inline]
slab_alloc mm/slab.c:3372 [inline]
kmem_cache_alloc+0x47/0x760 mm/slab.c:3546
sctp_bucket_create net/sctp/socket.c:7564 [inline]
sctp_get_port_local+0x9d6/0x13c0 net/sctp/socket.c:7323
sctp_get_port+0x127/0x190 net/sctp/socket.c:7372
inet_autobind+0xaa/0x180 net/ipv4/af_inet.c:181
inet_sendmsg+0x4de/0x5e0 net/ipv4/af_inet.c:760
sock_sendmsg_nosec net/socket.c:632 [inline]
sock_sendmsg+0xca/0x110 net/socket.c:642
SYSC_sendto+0x358/0x5a0 net/socket.c:1749
SyS_sendto+0x40/0x50 net/socket.c:1717
entry_SYSCALL_64_fastpath+0x1f/0x96
RIP: 0033:0x4529d9
RSP: 002b:00007f6fe298ac58 EFLAGS: 00000212 ORIG_RAX: 000000000000002c
RAX: ffffffffffffffda RBX: 00007f6fe298aaa0 RCX: 00000000004529d9
RDX: 0000000000000001 RSI: 00000000207c9ffe RDI: 0000000000000013
RBP: 00007f6fe298aa90 R08: 0000000020fec000 R09: 000000000000001c
R10: 0000000000040042 R11: 0000000000000212 R12: 00000000004b759b
R13: 00007f6fe298abc8 R14: 00000000004b759b R15: 0000000000000000
device gre0 entered promiscuous mode
device gre0 entered promiscuous mode
device gre0 entered promiscuous mode
device gre0 entered promiscuous mode
device gre0 entered promiscuous mode
device gre0 left promiscuous mode
device gre0 entered promiscuous mode
device gre0 entered promiscuous mode
device gre0 entered promiscuous mode
device gre0 entered promiscuous mode
device gre0 entered promiscuous mode
device gre0 entered promiscuous mode
QAT: Invalid ioctl
QAT: Invalid ioctl
device gre0 entered promiscuous mode
device gre0 entered promiscuous mode
device gre0 entered promiscuous mode
FAULT_INJECTION: forcing a failure.
name failslab, interval 1, probability 0, space 0, times 0
CPU: 0 PID: 6389 Comm: syz-executor1 Not tainted 4.15.0-rc1-next-20171129+
#55
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS
Google 01/01/2011
Call Trace:
__dump_stack lib/dump_stack.c:17 [inline]
dump_stack+0x194/0x257 lib/dump_stack.c:53
fail_dump lib/fault-inject.c:51 [inline]
should_fail+0x8c0/0xa40 lib/fault-inject.c:149
should_failslab+0xec/0x120 mm/failslab.c:32
slab_pre_alloc_hook mm/slab.h:425 [inline]
slab_alloc_node mm/slab.c:3293 [inline]
kmem_cache_alloc_node+0x56/0x760 mm/slab.c:3636
__alloc_skb+0xf1/0x780 net/core/skbuff.c:193
alloc_skb include/linux/skbuff.h:983 [inline]
alloc_skb_with_frags+0x10d/0x750 net/core/skbuff.c:5142
sock_alloc_send_pskb+0x787/0x9b0 net/core/sock.c:2078
tun_alloc_skb drivers/net/tun.c:1355 [inline]
tun_get_user+0x91c/0x36d0 drivers/net/tun.c:1644
tun_chr_write_iter+0xbf/0x160 drivers/net/tun.c:1800
call_write_iter include/linux/fs.h:1772 [inline]
new_sync_write fs/read_write.c:469 [inline]
__vfs_write+0x68a/0x970 fs/read_write.c:482
vfs_write+0x18f/0x510 fs/read_write.c:544
SYSC_write fs/read_write.c:589 [inline]
SyS_write+0xef/0x220 fs/read_write.c:581
entry_SYSCALL_64_fastpath+0x1f/0x96
RIP: 0033:0x4529d9
RSP: 002b:00007f323b4d0c58 EFLAGS: 00000212 ORIG_RAX: 0000000000000001
RAX: ffffffffffffffda RBX: 00007f323b4d0aa0 RCX: 00000000004529d9
RDX: 000000000000006b RSI: 0000000020ef3000 RDI: 0000000000000015
RBP: 00007f323b4d0a90 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000212 R12: 00000000004b759b
R13: 00007f323b4d0bc8 R14: 00000000004b759b R15: 0000000000000000
device gre0 entered promiscuous mode
device gre0 entered promiscuous mode
device gre0 entered promiscuous mode


---
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.
Please credit me with: Reported-by: syzbot <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.
Note: all commands must start from beginning of the line in the email body.
config.txt
raw.log

syzbot

unread,
Jan 22, 2018, 12:49:02ā€ÆPM1/22/18
to linux-...@vger.kernel.org, mi...@redhat.com, ros...@goodmis.org, syzkall...@googlegroups.com
syzbot has found reproducer for the following crash on
git://git.kernel.org/pub/scm/linux/kernel/git/bpf/bpf-next.git/master commit
ebdd7b491b8a65d65936e07004caabca4a3c94a0 (Sun Jan 21 23:21:31 2018 +0000)
Merge branch 'mlxsw-Add-support-for-mirror-action-with-flower'

So far this crash happened 3 times on
git://git.kernel.org/pub/scm/linux/kernel/git/bpf/bpf-next.git/master,
linux-next.
C reproducer is attached.
syzkaller reproducer is attached.
Raw console output is attached.
compiler: gcc (GCC) 7.1.1 20170620
.config is attached.

IMPORTANT: if you fix the bug, please add the following tag to the commit:
Reported-by:
syzbot+7b44b47914a5b3dc...@syzkaller.appspotmail.com
It will help syzbot understand when the bug is fixed.


======================================================
WARNING: possible circular locking dependency detected
4.15.0-rc8+ #1 Not tainted
------------------------------------------------------
syzkaller301315/3887 is trying to acquire lock:
(event_mutex){+.+.}, at: [<00000000dfa1326b>]
ftrace_profile_set_filter+0x7a/0x270 kernel/trace/trace_events_filter.c:2266

but task is already holding lock:
(&cpuctx_mutex){+.+.}, at: [<00000000e276bad6>]
perf_event_ctx_lock_nested+0x21b/0x450 kernel/events/core.c:1249

which lock already depends on the new lock.


the existing dependency chain (in reverse order) is:

-> #4 (&cpuctx_mutex){+.+.}:
__mutex_lock_common kernel/locking/mutex.c:756 [inline]
__mutex_lock+0x16f/0x1a80 kernel/locking/mutex.c:893
mutex_lock_nested+0x16/0x20 kernel/locking/mutex.c:908
perf_event_init_cpu+0xb6/0x160 kernel/events/core.c:11076
perf_event_init+0x4e9/0x549 kernel/events/core.c:11123
start_kernel+0x4cc/0x819 init/main.c:627
x86_64_start_reservations+0x2a/0x2c arch/x86/kernel/head64.c:378
x86_64_start_kernel+0x77/0x7a arch/x86/kernel/head64.c:359
secondary_startup_64+0xa5/0xb0 arch/x86/kernel/head_64.S:237

-> #3 (pmus_lock){+.+.}:
__mutex_lock_common kernel/locking/mutex.c:756 [inline]
__mutex_lock+0x16f/0x1a80 kernel/locking/mutex.c:893
mutex_lock_nested+0x16/0x20 kernel/locking/mutex.c:908
perf_event_init_cpu+0x2f/0x160 kernel/events/core.c:11070
cpuhp_invoke_callback+0x2ea/0x1d20 kernel/cpu.c:182
cpuhp_up_callbacks kernel/cpu.c:477 [inline]
_cpu_up+0x216/0x510 kernel/cpu.c:1036
do_cpu_up+0x73/0xa0 kernel/cpu.c:1066
cpu_up+0x18/0x20 kernel/cpu.c:1074
smp_init+0x13a/0x152 kernel/smp.c:578
kernel_init_freeable+0x2fe/0x521 init/main.c:1067
kernel_init+0x13/0x180 init/main.c:999
ret_from_fork+0x3a/0x50 arch/x86/entry/entry_64.S:541

-> #2 (cpu_hotplug_lock.rw_sem){++++}:
percpu_down_read_preempt_disable include/linux/percpu-rwsem.h:36
[inline]
percpu_down_read include/linux/percpu-rwsem.h:59 [inline]
cpus_read_lock+0x42/0x90 kernel/cpu.c:293
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+0x4ef/0xab0 kernel/trace/trace_event_perf.c:221
perf_tp_event_init+0x7d/0xf0 kernel/events/core.c:7959
perf_try_init_event+0xc9/0x1f0 kernel/events/core.c:9192
perf_init_event kernel/events/core.c:9230 [inline]
perf_event_alloc+0x1cc6/0x2b00 kernel/events/core.c:9494
SYSC_perf_event_open+0x84e/0x2e00 kernel/events/core.c:9949

raw.log.txt
repro.syz.txt
repro.c.txt
config.txt

Eric Biggers

unread,
Apr 21, 2018, 2:27:58ā€ÆPM4/21/18
to syzbot, linux-...@vger.kernel.org, mi...@redhat.com, ros...@goodmis.org, syzkall...@googlegroups.com, Peter Zijlstra
No longer occurring, fix was commit 43fa87f7deed52e8c8:

#syz fix: perf/core: Fix another perf,trace,cpuhp lock inversion

- Eric
Reply all
Reply to author
Forward
0 new messages