INFO: task hung in evdev

INFO: task hung in evdev_release
Status: upstream: reported syz repro on 2018/10/16 06:02
Reported-by: syzbot+a979743610b4755d4d57@syzkaller.appspotmail.com
First crash: 916d, last: 904d

Cause bisection: introduced by (bisect log) :
commit e32d99af6830c9a8f37b4f2637ef0cdc60fa79fb
Author: Jerome Brunet <jbrunet@baylibre.com>
Date: Tue Jul 17 15:42:50 2018 +0000

ASoC: meson: add axg fifos DT binding documentation

Crash: INFO: task hung in evdev_release (log)
Repro: syz .config

Fix bisection: failed (bisect log)
similar bugs (1):
Kernel	Title	Repro	Cause bisect	Fix bisect	Count	Last	Reported	Patched	Status
android-414	INFO: task hung in evdev_release				1	713d	713d	0/1	auto-closed as invalid on 2019/10/25 08:43
Sample crash report:
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-executor5:12980 blocked for more than 140 seconds.
      Not tainted 4.19.0+ #299
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
syz-executor5   D23160 12980  10554 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
 evdev_close_device drivers/input/evdev.c:447 [inline]
 evdev_release+0xfe/0x1e0 drivers/input/evdev.c:488
 __fput+0x385/0xa30 fs/file_table.c:278
 ____fput+0x15/0x20 fs/file_table.c:309
 task_work_run+0x1e8/0x2a0 kernel/task_work.c:113
 tracehook_notify_resume include/linux/tracehook.h:193 [inline]
 exit_to_usermode_loop+0x318/0x380 arch/x86/entry/common.c:166
 prepare_exit_to_usermode arch/x86/entry/common.c:197 [inline]
 syscall_return_slowpath arch/x86/entry/common.c:268 [inline]
 do_syscall_64+0x6be/0x820 arch/x86/entry/common.c:293
 entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x411021
Code: cc cc cc cc cc cc cc cc cc 64 48 8b 0c 25 f8 ff ff ff 48 3b 61 10 0f 86 b1 00 00 00 48 83 ec 30 48 89 6c 24 28 48 8d 6c 24 28 <48> 8b 44 24 38 84 00 48 8b 4c 24 40 48 2b 0d b4 d2 c2 00 48 c1 e9
RSP: 002b:0000000000a3fd90 EFLAGS: 00000293 ORIG_RAX: 0000000000000003
RAX: 0000000000000000 RBX: 0000000000000009 RCX: 0000000000411021
RDX: 0000000000000000 RSI: 00000000007304e8 RDI: 0000000000000008
RBP: 0000000000000000 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000a3fcb0 R11: 0000000000000293 R12: 0000000000000000
R13: 0000000000000001 R14: 000000000000001e R15: 0000000000000005
INFO: task syz-executor1:12985 blocked for more than 140 seconds.
      Not tainted 4.19.0+ #299
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
syz-executor1   D23160 12985  11080 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
 evdev_close_device drivers/input/evdev.c:447 [inline]
 evdev_release+0xfe/0x1e0 drivers/input/evdev.c:488
 __fput+0x385/0xa30 fs/file_table.c:278
 ____fput+0x15/0x20 fs/file_table.c:309
 task_work_run+0x1e8/0x2a0 kernel/task_work.c:113
 tracehook_notify_resume include/linux/tracehook.h:193 [inline]
 exit_to_usermode_loop+0x318/0x380 arch/x86/entry/common.c:166
 prepare_exit_to_usermode arch/x86/entry/common.c:197 [inline]
 syscall_return_slowpath arch/x86/entry/common.c:268 [inline]
 do_syscall_64+0x6be/0x820 arch/x86/entry/common.c:293
 entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x411021
Code: cc cc cc cc cc cc cc cc cc 64 48 8b 0c 25 f8 ff ff ff 48 3b 61 10 0f 86 b1 00 00 00 48 83 ec 30 48 89 6c 24 28 48 8d 6c 24 28 <48> 8b 44 24 38 84 00 48 8b 4c 24 40 48 2b 0d b4 d2 c2 00 48 c1 e9
RSP: 002b:0000000000a3fd90 EFLAGS: 00000293 ORIG_RAX: 0000000000000003
RAX: 0000000000000000 RBX: 0000000000000006 RCX: 0000000000411021
RDX: 0000000000000000 RSI: 00000000007304e8 RDI: 0000000000000005
RBP: 0000000000000000 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000a3fcb0 R11: 0000000000000293 R12: 0000000000000000
R13: 0000000000000001 R14: 0000000000000016 R15: 0000000000000001
INFO: task syz-executor4:12987 blocked for more than 140 seconds.
      Not tainted 4.19.0+ #299
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
syz-executor4   D23216 12987  11513 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
 evdev_close_device drivers/input/evdev.c:447 [inline]
 evdev_release+0xfe/0x1e0 drivers/input/evdev.c:488
 __fput+0x385/0xa30 fs/file_table.c:278
 ____fput+0x15/0x20 fs/file_table.c:309
 task_work_run+0x1e8/0x2a0 kernel/task_work.c:113
 tracehook_notify_resume include/linux/tracehook.h:193 [inline]
 exit_to_usermode_loop+0x318/0x380 arch/x86/entry/common.c:166
 prepare_exit_to_usermode arch/x86/entry/common.c:197 [inline]
 syscall_return_slowpath arch/x86/entry/common.c:268 [inline]
 do_syscall_64+0x6be/0x820 arch/x86/entry/common.c:293
 entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x411021
Code: Bad RIP value.
RSP: 002b:0000000000a3fd90 EFLAGS: 00000293 ORIG_RAX: 0000000000000003
RAX: 0000000000000000 RBX: 0000000000000009 RCX: 0000000000411021
RDX: 0000000000000000 RSI: 00000000007304e8 RDI: 0000000000000008
RBP: 0000000000000000 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000a3fcb0 R11: 0000000000000293 R12: 0000000000000000
R13: 0000000000000001 R14: 0000000000000011 R15: 0000000000000004
INFO: task syz-executor4:12995 blocked for more than 140 seconds.
      Not tainted 4.19.0+ #299
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
syz-executor4   D22744 12995  11513 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
 evdev_close_device drivers/input/evdev.c:447 [inline]
 evdev_release+0xfe/0x1e0 drivers/input/evdev.c:488
 __fput+0x385/0xa30 fs/file_table.c:278
 ____fput+0x15/0x20 fs/file_table.c:309
 task_work_run+0x1e8/0x2a0 kernel/task_work.c:113
 tracehook_notify_resume include/linux/tracehook.h:193 [inline]
 exit_to_usermode_loop+0x318/0x380 arch/x86/entry/common.c:166
 prepare_exit_to_usermode arch/x86/entry/common.c:197 [inline]
 syscall_return_slowpath arch/x86/entry/common.c:268 [inline]
 do_syscall_64+0x6be/0x820 arch/x86/entry/common.c:293
 entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x457569
Code: Bad RIP value.
RSP: 002b:00007f635fc72c78 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
RAX: ffffffffffffffea RBX: 0000000000000003 RCX: 0000000000457569
RDX: 0000000020013000 RSI: 000000008040450a RDI: 0000000000000005
RBP: 000000000072bfa0 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 00007f635fc736d4
R13: 00000000004bf3dd R14: 00000000004cf1f0 R15: 00000000ffffffff
INFO: task syz-executor0:13002 blocked for more than 140 seconds.
      Not tainted 4.19.0+ #299
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
syz-executor0   D22376 13002   5387 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
 evdev_flush+0x74/0x150 drivers/input/evdev.c:356
 filp_close+0x154/0x250 fs/open.c:1140
 __close_fd+0x245/0x3a0 fs/file.c:635
 __do_sys_close fs/open.c:1159 [inline]
 __se_sys_close fs/open.c:1157 [inline]
 __x64_sys_close+0x72/0xf0 fs/open.c:1157
 do_syscall_64+0x1b9/0x820 arch/x86/entry/common.c:290
 entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x411021
Code: Bad RIP value.
RSP: 002b:0000000000a3fd90 EFLAGS: 00000293 ORIG_RAX: 0000000000000003
RAX: ffffffffffffffda RBX: 0000000000000006 RCX: 0000000000411021
RDX: 0000000000000000 RSI: 00000000007304e8 RDI: 0000000000000005
RBP: 0000000000000000 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000a3fcb0 R11: 0000000000000293 R12: 0000000000000000
R13: 0000000000000001 R14: 000000000000007c R15: 0000000000000000

Showing all locks held in the system:
1 lock held by khungtaskd/982:
 #0: 00000000e885ab38 (rcu_read_lock){....}, at: debug_show_all_locks+0xd0/0x424 kernel/locking/lockdep.c:4435
1 lock held by rsyslogd/5243:
 #0: 00000000bcfa78cd (&f->f_pos_lock){+.+.}, at: __fdget_pos+0x1bb/0x200 fs/file.c:766
2 locks held by getty/5333:
 #0: 000000001b637479 (&tty->ldisc_sem){++++}, at: ldsem_down_read+0x32/0x40 drivers/tty/tty_ldsem.c:353
 #1: 0000000031a98370 (&ldata->atomic_read_lock){+.+.}, at: n_tty_read+0x335/0x1ce0 drivers/tty/n_tty.c:2140
2 locks held by getty/5334:
 #0: 00000000450dc828 (&tty->ldisc_sem){++++}, at: ldsem_down_read+0x32/0x40 drivers/tty/tty_ldsem.c:353
 #1: 00000000e0686f14 (&ldata->atomic_read_lock){+.+.}, at: n_tty_read+0x335/0x1ce0 drivers/tty/n_tty.c:2140
2 locks held by getty/5335:
 #0: 00000000c299a1cd (&tty->ldisc_sem){++++}, at: ldsem_down_read+0x32/0x40 drivers/tty/tty_ldsem.c:353
 #1: 0000000082ed2e2c (&ldata->atomic_read_lock){+.+.}, at: n_tty_read+0x335/0x1ce0 drivers/tty/n_tty.c:2140
2 locks held by getty/5336:
 #0: 00000000804dcc7a (&tty->ldisc_sem){++++}, at: ldsem_down_read+0x32/0x40 drivers/tty/tty_ldsem.c:353
 #1: 00000000b6debe93 (&ldata->atomic_read_lock){+.+.}, at: n_tty_read+0x335/0x1ce0 drivers/tty/n_tty.c:2140
2 locks held by getty/5337:
 #0: 00000000e3823348 (&tty->ldisc_sem){++++}, at: ldsem_down_read+0x32/0x40 drivers/tty/tty_ldsem.c:353
 #1: 00000000d2a0da45 (&ldata->atomic_read_lock){+.+.}, at: n_tty_read+0x335/0x1ce0 drivers/tty/n_tty.c:2140
2 locks held by getty/5338:
 #0: 00000000d7822200 (&tty->ldisc_sem){++++}, at: ldsem_down_read+0x32/0x40 drivers/tty/tty_ldsem.c:353
 #1: 000000002a682487 (&ldata->atomic_read_lock){+.+.}, at: n_tty_read+0x335/0x1ce0 drivers/tty/n_tty.c:2140
2 locks held by getty/5339:
 #0: 000000004f3d2e8a (&tty->ldisc_sem){++++}, at: ldsem_down_read+0x32/0x40 drivers/tty/tty_ldsem.c:353
 #1: 000000001e78ccaf (&ldata->atomic_read_lock){+.+.}, at: n_tty_read+0x335/0x1ce0 drivers/tty/n_tty.c:2140
1 lock held by syz-executor0/7083:
 #0: 00000000fe88cf06 (&evdev->mutex){+.+.}, at: evdev_flush+0x74/0x150 drivers/input/evdev.c:356
1 lock held by syz-executor0/8343:
 #0: 00000000fe88cf06 (&evdev->mutex){+.+.}, at: evdev_flush+0x74/0x150 drivers/input/evdev.c:356
1 lock held by syz-executor0/8428:
 #0: 00000000fe88cf06 (&evdev->mutex){+.+.}, at: evdev_flush+0x74/0x150 drivers/input/evdev.c:356
1 lock held by syz-executor0/8807:
 #0: 00000000fe88cf06 (&evdev->mutex){+.+.}, at: evdev_flush+0x74/0x150 drivers/input/evdev.c:356
1 lock held by syz-executor0/8927:
 #0: 00000000fe88cf06 (&evdev->mutex){+.+.}, at: evdev_flush+0x74/0x150 drivers/input/evdev.c:356
1 lock held by syz-executor0/9044:
 #0: 00000000fe88cf06 (&evdev->mutex){+.+.}, at: evdev_flush+0x74/0x150 drivers/input/evdev.c:356
1 lock held by syz-executor0/10122:
 #0: 00000000fe88cf06 (&evdev->mutex){+.+.}, at: evdev_flush+0x74/0x150 drivers/input/evdev.c:356
1 lock held by syz-executor0/10264:
 #0: 00000000fe88cf06 (&evdev->mutex){+.+.}, at: evdev_flush+0x74/0x150 drivers/input/evdev.c:356
1 lock held by syz-executor0/10694:
 #0: 00000000fe88cf06 (&evdev->mutex){+.+.}, at: evdev_flush+0x74/0x150 drivers/input/evdev.c:356
1 lock held by syz-executor5/11083:
 #0: 00000000fe88cf06 (&evdev->mutex){+.+.}, at: evdev_flush+0x74/0x150 drivers/input/evdev.c:356
1 lock held by syz-executor5/11180:
 #0: 00000000fe88cf06 (&evdev->mutex){+.+.}, at: evdev_flush+0x74/0x150 drivers/input/evdev.c:356
1 lock held by syz-executor1/11413:
 #0: 00000000fe88cf06 (&evdev->mutex){+.+.}, at: evdev_flush+0x74/0x150 drivers/input/evdev.c:356
1 lock held by syz-executor0/12382:
 #0: 00000000fe88cf06 (&evdev->mutex){+.+.}, at: evdev_flush+0x74/0x150 drivers/input/evdev.c:356
1 lock held by syz-executor0/12411:
 #0: 00000000fe88cf06 (&evdev->mutex){+.+.}, at: evdev_flush+0x74/0x150 drivers/input/evdev.c:356
1 lock held by syz-executor5/12463:
 #0: 00000000fe88cf06 (&evdev->mutex){+.+.}, at: evdev_flush+0x74/0x150 drivers/input/evdev.c:356
1 lock held by syz-executor1/12526:
 #0: 00000000fe88cf06 (&evdev->mutex){+.+.}, at: evdev_flush+0x74/0x150 drivers/input/evdev.c:356
1 lock held by syz-executor1/12595:
 #0: 00000000fe88cf06 (&evdev->mutex){+.+.}, at: evdev_flush+0x74/0x150 drivers/input/evdev.c:356
1 lock held by syz-executor0/12805:
 #0: 00000000fe88cf06 (&evdev->mutex){+.+.}, at: evdev_flush+0x74/0x150 drivers/input/evdev.c:356
1 lock held by syz-executor5/12836:
 #0: 00000000fe88cf06 (&evdev->mutex){+.+.}, at: evdev_flush+0x74/0x150 drivers/input/evdev.c:356
1 lock held by syz-executor4/12935:
 #0: 00000000fe88cf06 (&evdev->mutex){+.+.}, at: evdev_flush+0x74/0x150 drivers/input/evdev.c:356
1 lock held by syz-executor5/12980:
 #0: 00000000fe88cf06 (&evdev->mutex){+.+.}, at: evdev_close_device drivers/input/evdev.c:447 [inline]
 #0: 00000000fe88cf06 (&evdev->mutex){+.+.}, at: evdev_release+0xfe/0x1e0 drivers/input/evdev.c:488
1 lock held by syz-executor1/12985:
 #0: 00000000fe88cf06 (&evdev->mutex){+.+.}, at: evdev_close_device drivers/input/evdev.c:447 [inline]
 #0: 00000000fe88cf06 (&evdev->mutex){+.+.}, at: evdev_release+0xfe/0x1e0 drivers/input/evdev.c:488
1 lock held by syz-executor4/12987:
 #0: 00000000fe88cf06 (&evdev->mutex){+.+.}, at: evdev_close_device drivers/input/evdev.c:447 [inline]
 #0: 00000000fe88cf06 (&evdev->mutex){+.+.}, at: evdev_release+0xfe/0x1e0 drivers/input/evdev.c:488
1 lock held by syz-executor4/12995:
 #0: 00000000fe88cf06 (&evdev->mutex){+.+.}, at: evdev_close_device drivers/input/evdev.c:447 [inline]
 #0: 00000000fe88cf06 (&evdev->mutex){+.+.}, at: evdev_release+0xfe/0x1e0 drivers/input/evdev.c:488
1 lock held by syz-executor0/13002:
 #0: 00000000fe88cf06 (&evdev->mutex){+.+.}, at: evdev_flush+0x74/0x150 drivers/input/evdev.c:356
1 lock held by syz-executor3/13004:
 #0: 00000000fe88cf06 (&evdev->mutex){+.+.}, at: evdev_ioctl_handler+0x82/0x1a0 drivers/input/evdev.c:1298

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

NMI backtrace for cpu 0
CPU: 0 PID: 982 Comm: khungtaskd Not tainted 4.19.0+ #299
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/0x2b6 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 0 to CPUs 1:
NMI backtrace for cpu 1 skipped: idling at native_safe_halt+0x6/0x10 arch/x86/include/asm/irqflags.h:57
Crashes (7):
Manager	Time	Kernel	Commit	Syzkaller	Config	Log	Report	Syz repro
ci-upstream-kasan-gce	2018/10/23 15:00	upstream	58a02287	24fa2ad8	.config	log	report	syz
ci-upstream-kasan-gce-smack-root	2018/10/12 07:02	upstream	9dcd936c	ba6ddb43	.config	log	report	syz
ci-upstream-kasan-gce-selinux-root	2018/10/12 06:29	upstream	0778a9f2	ba6ddb43	.config	log	report	syz
ci-upstream-kasan-gce	2018/10/12 00:55	upstream	9dcd936c	ba6ddb43	.config	log	report	syz
ci-upstream-kasan-gce-386	2018/10/12 02:02	upstream	9dcd936c	ba6ddb43	.config	log	report	syz
ci-upstream-linux-next-kasan-gce-root	2018/10/11 22:47	linux-next	771b65e8	ba6ddb43	.config	log	report	syz
ci-upstream-linux-next-kasan-gce-root	2018/10/11 20:27	linux-next	771b65e8	ba6ddb43	.config	log	report