INFO: task hung in perf_tp_event_init

[syzbot]

Hello,

syzbot found the following crash on:

HEAD commit: 291d0e5d81e1 Merge tag 'for-linus-20180929' of git://git.k..
git tree: upstream
console output: https://syzkaller.appspot.com/x/log.txt?x=13f45ac9400000
kernel config: https://syzkaller.appspot.com/x/.config?x=a8212f992609a887
dashboard link: https://syzkaller.appspot.com/bug?extid=c8494e02352841cd0395
compiler: gcc (GCC) 8.0.1 20180413 (experimental)
CC: [linux-...@vger.kernel.org mi...@redhat.com
ros...@goodmis.org]

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

IMPORTANT: if you fix the bug, please add the following tag to the commit:
Reported-by: syzbot+c8494e...@syzkaller.appspotmail.com

IPv6: ADDRCONF(NETDEV_UP): veth0: link is not ready
IPv6: ADDRCONF(NETDEV_UP): veth1: link is not ready
IPv6: ADDRCONF(NETDEV_CHANGE): veth1: link becomes ready
IPv6: ADDRCONF(NETDEV_CHANGE): veth0: link becomes ready
8021q: adding VLAN 0 to HW filter on device team0
INFO: task syz-executor3:30050 blocked for more than 140 seconds.
Not tainted 4.19.0-rc5+ #261
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
syz-executor3 D23488 30050 28171 0x00000004
Call Trace:
context_switch kernel/sched/core.c:2825 [inline]
__schedule+0x86c/0x1ed0 kernel/sched/core.c:3473
schedule+0xfe/0x460 kernel/sched/core.c:3517
schedule_preempt_disabled+0x13/0x20 kernel/sched/core.c:3575
__mutex_lock_common kernel/locking/mutex.c:1002 [inline]
__mutex_lock+0xbe7/0x1700 kernel/locking/mutex.c:1072
mutex_lock_nested+0x16/0x20 kernel/locking/mutex.c:1087
perf_trace_init+0x58/0x250 kernel/trace/trace_event_perf.c:218
perf_tp_event_init+0xa6/0x120 kernel/events/core.c:8350
perf_try_init_event+0x137/0x2f0 kernel/events/core.c:9744
perf_init_event kernel/events/core.c:9782 [inline]
perf_event_alloc.part.93+0x1b5b/0x35f0 kernel/events/core.c:10048
perf_event_alloc kernel/events/core.c:10404 [inline]
__do_sys_perf_event_open+0xa9c/0x2f30 kernel/events/core.c:10505
__se_sys_perf_event_open kernel/events/core.c:10394 [inline]
__x64_sys_perf_event_open+0xbe/0x150 kernel/events/core.c:10394
do_syscall_64+0x1b9/0x820 arch/x86/entry/common.c:290
entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x457579
Code: 24 08 48 89 01 e8 d7 2d fc ff e8 22 7a fc ff b8 02 00 00 00 48 8d 0d
6a 60 09 01 87 01 8b 05 62 60 09 01 83 f8 01 0f 85 8a 00 <00> 00 b8 01 00
00 00 88 05 9e 65 09 01 84 c0 74 72 b8 01 00 00 00
RSP: 002b:00007ff8bac4cc78 EFLAGS: 00000246 ORIG_RAX: 000000000000012a
RAX: ffffffffffffffda RBX: 0000000000000005 RCX: 0000000000457579
RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000020940000
RBP: 000000000072bf00 R08: 0000000000000000 R09: 0000000000000000
R10: ffffffffffffffff R11: 0000000000000246 R12: 00007ff8bac4d6d4
R13: 00000000004c2f90 R14: 00000000004d4818 R15: 00000000ffffffff
INFO: task syz-executor1:30052 blocked for more than 140 seconds.
Not tainted 4.19.0-rc5+ #261
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
syz-executor1 D24648 30052 28509 0x00000004
Call Trace:
context_switch kernel/sched/core.c:2825 [inline]
__schedule+0x86c/0x1ed0 kernel/sched/core.c:3473
schedule+0xfe/0x460 kernel/sched/core.c:3517
schedule_preempt_disabled+0x13/0x20 kernel/sched/core.c:3575
__mutex_lock_common kernel/locking/mutex.c:1002 [inline]
__mutex_lock+0xbe7/0x1700 kernel/locking/mutex.c:1072
mutex_lock_nested+0x16/0x20 kernel/locking/mutex.c:1087
perf_trace_init+0x58/0x250 kernel/trace/trace_event_perf.c:218
perf_tp_event_init+0xa6/0x120 kernel/events/core.c:8350
perf_try_init_event+0x137/0x2f0 kernel/events/core.c:9744
perf_init_event kernel/events/core.c:9782 [inline]
perf_event_alloc.part.93+0x1b5b/0x35f0 kernel/events/core.c:10048
perf_event_alloc kernel/events/core.c:10404 [inline]
__do_sys_perf_event_open+0xa9c/0x2f30 kernel/events/core.c:10505
__se_sys_perf_event_open kernel/events/core.c:10394 [inline]
__x64_sys_perf_event_open+0xbe/0x150 kernel/events/core.c:10394
do_syscall_64+0x1b9/0x820 arch/x86/entry/common.c:290
entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x457579
Code: 24 08 48 89 01 e8 d7 2d fc ff e8 22 7a fc ff b8 02 00 00 00 48 8d 0d
6a 60 09 01 87 01 8b 05 62 60 09 01 83 f8 01 0f 85 8a 00 <00> 00 b8 01 00
00 00 88 05 9e 65 09 01 84 c0 74 72 b8 01 00 00 00
RSP: 002b:00007f25af16dc78 EFLAGS: 00000246 ORIG_RAX: 000000000000012a
RAX: ffffffffffffffda RBX: 0000000000000005 RCX: 0000000000457579
RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000020940000
RBP: 000000000072bf00 R08: 0000000000000000 R09: 0000000000000000
R10: ffffffffffffffff R11: 0000000000000246 R12: 00007f25af16e6d4
R13: 00000000004c2f90 R14: 00000000004d4818 R15: 00000000ffffffff
INFO: task syz-executor4:30609 blocked for more than 140 seconds.
Not tainted 4.19.0-rc5+ #261
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
syz-executor4 D23488 30609 30119 0x00000004
Call Trace:
context_switch kernel/sched/core.c:2825 [inline]
__schedule+0x86c/0x1ed0 kernel/sched/core.c:3473
schedule+0xfe/0x460 kernel/sched/core.c:3517
schedule_preempt_disabled+0x13/0x20 kernel/sched/core.c:3575
__mutex_lock_common kernel/locking/mutex.c:1002 [inline]
__mutex_lock+0xbe7/0x1700 kernel/locking/mutex.c:1072
mutex_lock_nested+0x16/0x20 kernel/locking/mutex.c:1087
perf_trace_init+0x58/0x250 kernel/trace/trace_event_perf.c:218
perf_tp_event_init+0xa6/0x120 kernel/events/core.c:8350
perf_try_init_event+0x137/0x2f0 kernel/events/core.c:9744
perf_init_event kernel/events/core.c:9782 [inline]
perf_event_alloc.part.93+0x1b5b/0x35f0 kernel/events/core.c:10048
perf_event_alloc kernel/events/core.c:10404 [inline]
__do_sys_perf_event_open+0xa9c/0x2f30 kernel/events/core.c:10505
__se_sys_perf_event_open kernel/events/core.c:10394 [inline]
__x64_sys_perf_event_open+0xbe/0x150 kernel/events/core.c:10394
do_syscall_64+0x1b9/0x820 arch/x86/entry/common.c:290
entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x457579
Code: Bad RIP value.
RSP: 002b:00007f49f0817c78 EFLAGS: 00000246 ORIG_RAX: 000000000000012a
RAX: ffffffffffffffda RBX: 0000000000000005 RCX: 0000000000457579
RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000020940000
RBP: 000000000072bf00 R08: 0000000000000000 R09: 0000000000000000
R10: ffffffffffffffff R11: 0000000000000246 R12: 00007f49f08186d4
R13: 00000000004c2f90 R14: 00000000004d4818 R15: 00000000ffffffff

Showing all locks held in the system:
1 lock held by khungtaskd/982:
#0: 000000003b1a80ab (rcu_read_lock){....}, at:
debug_show_all_locks+0xd0/0x424 kernel/locking/lockdep.c:4435
1 lock held by rsyslogd/5219:
#0: 00000000b89cc390 (&f->f_pos_lock){+.+.}, at: __fdget_pos+0x1bb/0x200
fs/file.c:766
2 locks held by getty/5309:
#0: 0000000053b6e7ac (&tty->ldisc_sem){++++}, at:
ldsem_down_read+0x32/0x40 drivers/tty/tty_ldsem.c:353
#1: 00000000ad1f4a22 (&ldata->atomic_read_lock){+.+.}, at:
n_tty_read+0x335/0x1ce0 drivers/tty/n_tty.c:2140
2 locks held by getty/5310:
#0: 00000000fd4a344e (&tty->ldisc_sem){++++}, at:
ldsem_down_read+0x32/0x40 drivers/tty/tty_ldsem.c:353
#1: 00000000cb5a1c54 (&ldata->atomic_read_lock){+.+.}, at:
n_tty_read+0x335/0x1ce0 drivers/tty/n_tty.c:2140
2 locks held by getty/5311:
#0: 00000000ff82801e (&tty->ldisc_sem){++++}, at:
ldsem_down_read+0x32/0x40 drivers/tty/tty_ldsem.c:353
#1: 000000009def3ab9 (&ldata->atomic_read_lock){+.+.}, at:
n_tty_read+0x335/0x1ce0 drivers/tty/n_tty.c:2140
2 locks held by getty/5312:
#0: 00000000251539b9 (&tty->ldisc_sem){++++}, at:
ldsem_down_read+0x32/0x40 drivers/tty/tty_ldsem.c:353
#1: 00000000ed6459da (&ldata->atomic_read_lock){+.+.}, at:
n_tty_read+0x335/0x1ce0 drivers/tty/n_tty.c:2140
2 locks held by getty/5313:
#0: 000000002bd6f157 (&tty->ldisc_sem){++++}, at:
ldsem_down_read+0x32/0x40 drivers/tty/tty_ldsem.c:353
#1: 000000001b0781ca (&ldata->atomic_read_lock){+.+.}, at:
n_tty_read+0x335/0x1ce0 drivers/tty/n_tty.c:2140
2 locks held by getty/5314:
#0: 000000009f933a00 (&tty->ldisc_sem){++++}, at:
ldsem_down_read+0x32/0x40 drivers/tty/tty_ldsem.c:353
#1: 00000000ed0aac57 (&ldata->atomic_read_lock){+.+.}, at:
n_tty_read+0x335/0x1ce0 drivers/tty/n_tty.c:2140
2 locks held by getty/5315:
#0: 000000005148e0de (&tty->ldisc_sem){++++}, at:
ldsem_down_read+0x32/0x40 drivers/tty/tty_ldsem.c:353
#1: 0000000024b971d7 (&ldata->atomic_read_lock){+.+.}, at:
n_tty_read+0x335/0x1ce0 drivers/tty/n_tty.c:2140
1 lock held by syz-executor4/30038:
3 locks held by syz-executor3/30050:
#0: 00000000e5534a0e (&sig->cred_guard_mutex){+.+.}, at:
__do_sys_perf_event_open+0x12fe/0x2f30 kernel/events/core.c:10485
#1: 000000004e676723 (&pmus_srcu){....}, at: fdput include/linux/file.h:42
[inline]
#1: 000000004e676723 (&pmus_srcu){....}, at: perf_cgroup_connect
kernel/events/core.c:925 [inline]
#1: 000000004e676723 (&pmus_srcu){....}, at:
perf_event_alloc.part.93+0x18a1/0x35f0 kernel/events/core.c:10043
#2: 00000000b42faba7 (event_mutex){+.+.}, at: perf_trace_init+0x58/0x250
kernel/trace/trace_event_perf.c:218
3 locks held by syz-executor1/30052:
#0: 00000000fd4697c4 (&sig->cred_guard_mutex){+.+.}, at:
__do_sys_perf_event_open+0x12fe/0x2f30 kernel/events/core.c:10485
#1: 000000004e676723 (&pmus_srcu){....}, at: fdput include/linux/file.h:42
[inline]
#1: 000000004e676723 (&pmus_srcu){....}, at: perf_cgroup_connect
kernel/events/core.c:925 [inline]
#1: 000000004e676723 (&pmus_srcu){....}, at:
perf_event_alloc.part.93+0x18a1/0x35f0 kernel/events/core.c:10043
#2: 00000000b42faba7 (event_mutex){+.+.}, at: perf_trace_init+0x58/0x250
kernel/trace/trace_event_perf.c:218
3 locks held by syz-executor4/30609:
#0: 0000000072804231 (&sig->cred_guard_mutex){+.+.}, at:
__do_sys_perf_event_open+0x12fe/0x2f30 kernel/events/core.c:10485
#1: 000000004e676723 (&pmus_srcu){....}, at: fdput include/linux/file.h:42
[inline]
#1: 000000004e676723 (&pmus_srcu){....}, at: perf_cgroup_connect
kernel/events/core.c:925 [inline]
#1: 000000004e676723 (&pmus_srcu){....}, at:
perf_event_alloc.part.93+0x18a1/0x35f0 kernel/events/core.c:10043
#2: 00000000b42faba7 (event_mutex){+.+.}, at: perf_trace_init+0x58/0x250
kernel/trace/trace_event_perf.c:218

=============================================

NMI backtrace for cpu 1
CPU: 1 PID: 982 Comm: khungtaskd Not tainted 4.19.0-rc5+ #261
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS
Google 01/01/2011
Call Trace:
__dump_stack lib/dump_stack.c:77 [inline]
dump_stack+0x1c4/0x2b4 lib/dump_stack.c:113
nmi_cpu_backtrace.cold.3+0x63/0xa2 lib/nmi_backtrace.c:101
nmi_trigger_cpumask_backtrace+0x1b3/0x1ed lib/nmi_backtrace.c:62
arch_trigger_cpumask_backtrace+0x14/0x20 arch/x86/kernel/apic/hw_nmi.c:38
trigger_all_cpu_backtrace include/linux/nmi.h:144 [inline]
check_hung_uninterruptible_tasks kernel/hung_task.c:204 [inline]
watchdog+0xb3e/0x1050 kernel/hung_task.c:265
kthread+0x35a/0x420 kernel/kthread.c:246
ret_from_fork+0x3a/0x50 arch/x86/entry/entry_64.S:413
Sending NMI from CPU 1 to CPUs 0:
NMI backtrace for cpu 0 skipped: idling at native_safe_halt+0x6/0x10
arch/x86/include/asm/irqflags.h:57


---
This bug is generated by a bot. It may contain errors.
See https://goo.gl/tpsmEJ for more information about syzbot.
syzbot engineers can be reached at syzk...@googlegroups.com.

syzbot will keep track of this bug report. See:
https://goo.gl/tpsmEJ#bug-status-tracking for how to communicate with
syzbot.

[syzbot]

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