INFO: task hung in console_callback

[syzbot]

Hello,

syzbot found the following crash on:

HEAD commit: 01364dad Linux 4.14.174
git tree: linux-4.14.y
console output: https://syzkaller.appspot.com/x/log.txt?x=12facb73e00000
kernel config: https://syzkaller.appspot.com/x/.config?x=664dd71881ab2b2d
dashboard link: https://syzkaller.appspot.com/bug?extid=0ee86d8eca6ece7e1dca
compiler: gcc (GCC) 9.0.0 20181231 (experimental)

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+0ee86d...@syzkaller.appspotmail.com

RDX: 04000000000000d7 RSI: 00000000200002c0 RDI: 0000000000000003
RBP: 000000000076bf00 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000005
R13: 00000000000008d1 R14: 00000000004cb753 R15: 0000000000000009
INFO: task kworker/1:1:23 blocked for more than 140 seconds.
Not tainted 4.14.174-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
kworker/1:1 D26928 23 2 0x80000000
Workqueue: events console_callback
Call Trace:
schedule+0x8d/0x1b0 kernel/sched/core.c:3428
schedule_timeout+0x946/0xe40 kernel/time/timer.c:1723
__down_common kernel/locking/semaphore.c:221 [inline]
__down+0x160/0x290 kernel/locking/semaphore.c:238
down+0x57/0x80 kernel/locking/semaphore.c:62
console_lock+0x24/0x70 kernel/printk/printk.c:2216
console_callback+0x50/0x380 drivers/tty/vt/vt.c:2454
process_one_work+0x813/0x1540 kernel/workqueue.c:2116
worker_thread+0x5d1/0x1070 kernel/workqueue.c:2250
kthread+0x30d/0x420 kernel/kthread.c:232
ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:404
INFO: task kworker/u4:5:7535 blocked for more than 140 seconds.
Not tainted 4.14.174-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
kworker/u4:5 D26432 7535 2 0x80000000
Workqueue: events_unbound flush_to_ldisc
Call Trace:
schedule+0x8d/0x1b0 kernel/sched/core.c:3428
schedule_timeout+0x946/0xe40 kernel/time/timer.c:1723
__down_common kernel/locking/semaphore.c:221 [inline]
__down+0x160/0x290 kernel/locking/semaphore.c:238
down+0x57/0x80 kernel/locking/semaphore.c:62
console_lock+0x24/0x70 kernel/printk/printk.c:2216
do_con_write.part.0+0x8c/0x1a20 drivers/tty/vt/vt.c:2210
do_con_write drivers/tty/vt/vt.c:2796 [inline]
con_put_char+0xb4/0xc0 drivers/tty/vt/vt.c:2795
tty_put_char+0xa3/0x120 drivers/tty/tty_io.c:2879
do_output_char+0x126/0x750 drivers/tty/n_tty.c:488
__process_echoes+0x313/0x8c0 drivers/tty/n_tty.c:739
flush_echoes drivers/tty/n_tty.c:829 [inline]
__receive_buf drivers/tty/n_tty.c:1648 [inline]
n_tty_receive_buf_common+0x8ca/0x2480 drivers/tty/n_tty.c:1742
tty_ldisc_receive_buf+0x9e/0x170 drivers/tty/tty_buffer.c:455
tty_port_default_receive_buf+0x6e/0xa0 drivers/tty/tty_port.c:37
receive_buf drivers/tty/tty_buffer.c:475 [inline]
flush_to_ldisc+0x1dd/0x3f0 drivers/tty/tty_buffer.c:527
process_one_work+0x813/0x1540 kernel/workqueue.c:2116
worker_thread+0x5d1/0x1070 kernel/workqueue.c:2250
kthread+0x30d/0x420 kernel/kthread.c:232
ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:404
INFO: task syz-executor.2:15854 blocked for more than 140 seconds.
Not tainted 4.14.174-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
syz-executor.2 D29072 15854 7370 0x00000004
Call Trace:
schedule+0x8d/0x1b0 kernel/sched/core.c:3428
schedule_timeout+0x946/0xe40 kernel/time/timer.c:1723
__down_common kernel/locking/semaphore.c:221 [inline]
__down+0x160/0x290 kernel/locking/semaphore.c:238
down+0x57/0x80 kernel/locking/semaphore.c:62
console_lock+0x24/0x70 kernel/printk/printk.c:2216
do_fb_ioctl+0x36a/0x940 drivers/video/fbdev/core/fbmem.c:1121
fb_ioctl+0xdd/0x130 drivers/video/fbdev/core/fbmem.c:1242
vfs_ioctl fs/ioctl.c:46 [inline]
file_ioctl fs/ioctl.c:500 [inline]
do_vfs_ioctl+0x75a/0xfe0 fs/ioctl.c:684
SYSC_ioctl fs/ioctl.c:701 [inline]
SyS_ioctl+0x7f/0xb0 fs/ioctl.c:692
do_syscall_64+0x1d5/0x640 arch/x86/entry/common.c:292
entry_SYSCALL_64_after_hwframe+0x42/0xb7
RIP: 0033:0x45c849
RSP: 002b:00007f4a7a68cc78 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
RAX: ffffffffffffffda RBX: 00007f4a7a68d6d4 RCX: 000000000045c849
RDX: 0000000020000000 RSI: 0000000000004601 RDI: 0000000000000003
RBP: 000000000076bf00 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 00000000ffffffff
R13: 00000000000002ee R14: 00000000004c547c R15: 000000000076bf0c
INFO: task syz-executor.4:15859 blocked for more than 140 seconds.
Not tainted 4.14.174-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
syz-executor.4 D29072 15859 7369 0x00000004
Call Trace:
schedule+0x8d/0x1b0 kernel/sched/core.c:3428
schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:3486
__mutex_lock_common kernel/locking/mutex.c:833 [inline]
__mutex_lock+0x73c/0x1470 kernel/locking/mutex.c:893
fb_open+0xb7/0x400 drivers/video/fbdev/core/fbmem.c:1468
chrdev_open+0x1fc/0x540 fs/char_dev.c:423
do_dentry_open+0x732/0xe90 fs/open.c:777
vfs_open+0x105/0x220 fs/open.c:888
do_last fs/namei.c:3428 [inline]
path_openat+0x8ca/0x3c50 fs/namei.c:3569
do_filp_open+0x18e/0x250 fs/namei.c:3603
do_sys_open+0x29d/0x3f0 fs/open.c:1081
do_syscall_64+0x1d5/0x640 arch/x86/entry/common.c:292
entry_SYSCALL_64_after_hwframe+0x42/0xb7
RIP: 0033:0x45c849
RSP: 002b:00007f95bd4c3c78 EFLAGS: 00000246 ORIG_RAX: 0000000000000101
RAX: ffffffffffffffda RBX: 00007f95bd4c46d4 RCX: 000000000045c849
RDX: 0000000000000000 RSI: 0000000020000180 RDI: ffffffffffffff9c
RBP: 000000000076bfa0 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 00000000ffffffff
R13: 0000000000000798 R14: 00000000004ca4b4 R15: 000000000076bfac

Showing all locks held in the system:
2 locks held by kworker/1:1/23:
#0: ("events"){+.+.}, at: [<ffffffff813b67d7>] work_static include/linux/workqueue.h:199 [inline]
#0: ("events"){+.+.}, at: [<ffffffff813b67d7>] set_work_data kernel/workqueue.c:619 [inline]
#0: ("events"){+.+.}, at: [<ffffffff813b67d7>] set_work_pool_and_clear_pending kernel/workqueue.c:646 [inline]
#0: ("events"){+.+.}, at: [<ffffffff813b67d7>] process_one_work+0x727/0x1540 kernel/workqueue.c:2087
#1: (console_work){+.+.}, at: [<ffffffff813b6811>] process_one_work+0x761/0x1540 kernel/workqueue.c:2091
1 lock held by khungtaskd/1056:
#0: (tasklist_lock){.+.+}, at: [<ffffffff81465b93>] debug_show_all_locks+0x7c/0x21a kernel/locking/lockdep.c:4544
1 lock held by rsyslogd/7198:
#0: (&f->f_pos_lock){+.+.}, at: [<ffffffff8191b786>] __fdget_pos+0xa6/0xc0 fs/file.c:769
2 locks held by getty/7320:
#0: (&tty->ldisc_sem){++++}, at: [<ffffffff833adad2>] tty_ldisc_ref_wait+0x22/0x80 drivers/tty/tty_ldisc.c:284
#1: (&ldata->atomic_read_lock){+.+.}, at: [<ffffffff833a1714>] n_tty_read+0x1e4/0x16f0 drivers/tty/n_tty.c:2156
2 locks held by getty/7321:
#0: (&tty->ldisc_sem){++++}, at: [<ffffffff833adad2>] tty_ldisc_ref_wait+0x22/0x80 drivers/tty/tty_ldisc.c:284
#1: (&ldata->atomic_read_lock){+.+.}, at: [<ffffffff833a1714>] n_tty_read+0x1e4/0x16f0 drivers/tty/n_tty.c:2156
2 locks held by getty/7322:
#0: (&tty->ldisc_sem){++++}, at: [<ffffffff833adad2>] tty_ldisc_ref_wait+0x22/0x80 drivers/tty/tty_ldisc.c:284
#1: (&ldata->atomic_read_lock){+.+.}, at: [<ffffffff833a1714>] n_tty_read+0x1e4/0x16f0 drivers/tty/n_tty.c:2156
2 locks held by getty/7323:
#0: (&tty->ldisc_sem){++++}, at: [<ffffffff833adad2>] tty_ldisc_ref_wait+0x22/0x80 drivers/tty/tty_ldisc.c:284
#1: (&ldata->atomic_read_lock){+.+.}, at: [<ffffffff833a1714>] n_tty_read+0x1e4/0x16f0 drivers/tty/n_tty.c:2156
2 locks held by getty/7324:
#0: (&tty->ldisc_sem){++++}, at: [<ffffffff833adad2>] tty_ldisc_ref_wait+0x22/0x80 drivers/tty/tty_ldisc.c:284
#1: (&ldata->atomic_read_lock){+.+.}, at: [<ffffffff833a1714>] n_tty_read+0x1e4/0x16f0 drivers/tty/n_tty.c:2156
2 locks held by getty/7325:
#0: (&tty->ldisc_sem){++++}, at: [<ffffffff833adad2>] tty_ldisc_ref_wait+0x22/0x80 drivers/tty/tty_ldisc.c:284
#1: (&ldata->atomic_read_lock){+.+.}, at: [<ffffffff833a1714>] n_tty_read+0x1e4/0x16f0 drivers/tty/n_tty.c:2156
2 locks held by getty/7326:
#0: (&tty->ldisc_sem){++++}, at: [<ffffffff833adad2>] tty_ldisc_ref_wait+0x22/0x80 drivers/tty/tty_ldisc.c:284
#1: (&ldata->atomic_read_lock){+.+.}, at: [<ffffffff833a1714>] n_tty_read+0x1e4/0x16f0 drivers/tty/n_tty.c:2156
6 locks held by kworker/u4:5/7535:
#0: ("events_unbound"){+.+.}, at: [<ffffffff813b67d7>] work_static include/linux/workqueue.h:199 [inline]
#0: ("events_unbound"){+.+.}, at: [<ffffffff813b67d7>] set_work_data kernel/workqueue.c:619 [inline]
#0: ("events_unbound"){+.+.}, at: [<ffffffff813b67d7>] set_work_pool_and_clear_pending kernel/workqueue.c:646 [inline]
#0: ("events_unbound"){+.+.}, at: [<ffffffff813b67d7>] process_one_work+0x727/0x1540 kernel/workqueue.c:2087
#1: ((&buf->work)){+.+.}, at: [<ffffffff813b6811>] process_one_work+0x761/0x1540 kernel/workqueue.c:2091
#2: (&buf->lock){+.+.}, at: [<ffffffff833b01e5>] flush_to_ldisc+0x35/0x3f0 drivers/tty/tty_buffer.c:499
#3: (&tty->ldisc_sem){++++}, at: [<ffffffff833adb8b>] tty_ldisc_ref+0x1b/0x80 drivers/tty/tty_ldisc.c:305
#4: (&tty->termios_rwsem){++++}, at: [<ffffffff833a8201>] n_tty_receive_buf_common+0x81/0x2480 drivers/tty/n_tty.c:1705
#5: (&ldata->output_lock){+.+.}, at: [<ffffffff833a8a0c>] flush_echoes drivers/tty/n_tty.c:827 [inline]
#5: (&ldata->output_lock){+.+.}, at: [<ffffffff833a8a0c>] __receive_buf drivers/tty/n_tty.c:1648 [inline]
#5: (&ldata->output_lock){+.+.}, at: [<ffffffff833a8a0c>] n_tty_receive_buf_common+0x88c/0x2480 drivers/tty/n_tty.c:1742
1 lock held by syz-executor.4/15859:
#0: (&fb_info->lock){+.+.}, at: [<ffffffff831708b7>] fb_open+0xb7/0x400 drivers/video/fbdev/core/fbmem.c:1468

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

NMI backtrace for cpu 1
CPU: 1 PID: 1056 Comm: khungtaskd Not tainted 4.14.174-syzkaller #0
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+0x13e/0x194 lib/dump_stack.c:58
nmi_cpu_backtrace.cold+0x57/0x93 lib/nmi_backtrace.c:101
nmi_trigger_cpumask_backtrace+0x139/0x17e lib/nmi_backtrace.c:62
trigger_all_cpu_backtrace include/linux/nmi.h:140 [inline]
check_hung_uninterruptible_tasks kernel/hung_task.c:195 [inline]
watchdog+0x5e2/0xb80 kernel/hung_task.c:274
kthread+0x30d/0x420 kernel/kthread.c:232
ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:404
Sending NMI from CPU 1 to CPUs 0:
NMI backtrace for cpu 0
CPU: 0 PID: 15853 Comm: syz-executor.4 Not tainted 4.14.174-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
task: ffff8880566a6680 task.stack: ffff888086190000
RIP: 0010:__sanitizer_cov_trace_pc+0x3d/0x50 kernel/kcov.c:87
RSP: 0018:ffff8880861973c8 EFLAGS: 00000246
RAX: 0000000000040000 RBX: ffff8880000a000a RCX: ffffc9000842f000
RDX: 000000000003ffff RSI: ffffffff831e90e3 RDI: ffff888086197480
RBP: 000000000000000a R08: 000000000000ffff R09: ffffed104324d354
R10: ffffed104324d353 R11: ffff888219269a9f R12: ffff8880000a0001
R13: 0000000000000000 R14: 000000003f970159 R15: 0000000000000009
FS: 00007f95bd4e5700(0000) GS:ffff8880aea00000(0000) knlGS:0000000000000000
CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 000000c432ff8e80 CR3: 000000008151a000 CR4: 00000000001406f0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Call Trace:
writeb arch/x86/include/asm/io.h:65 [inline]
vga16fb_fillrect+0x943/0x1880 drivers/video/fbdev/vga16fb.c:923
bit_clear_margins+0x2a4/0x480 drivers/video/fbdev/core/bitblit.c:232
fbcon_clear_margins+0x285/0x310 drivers/video/fbdev/core/fbcon.c:1317
fbcon_switch+0xcdf/0x1780 drivers/video/fbdev/core/fbcon.c:2299
redraw_screen+0x331/0x770 drivers/tty/vt/vt.c:688
fbcon_modechanged+0x59d/0x890 drivers/video/fbdev/core/fbcon.c:2946
fbcon_event_notify+0x11a/0x1746 drivers/video/fbdev/core/fbcon.c:3299
notifier_call_chain+0x107/0x1a0 kernel/notifier.c:93
__blocking_notifier_call_chain kernel/notifier.c:317 [inline]
__blocking_notifier_call_chain kernel/notifier.c:304 [inline]
blocking_notifier_call_chain kernel/notifier.c:328 [inline]
blocking_notifier_call_chain+0x79/0x90 kernel/notifier.c:325
fb_set_var+0xaad/0xc70 drivers/video/fbdev/core/fbmem.c:1054
do_fb_ioctl+0x3cc/0x940 drivers/video/fbdev/core/fbmem.c:1127
fb_ioctl+0xdd/0x130 drivers/video/fbdev/core/fbmem.c:1242
vfs_ioctl fs/ioctl.c:46 [inline]
file_ioctl fs/ioctl.c:500 [inline]
do_vfs_ioctl+0x75a/0xfe0 fs/ioctl.c:684
SYSC_ioctl fs/ioctl.c:701 [inline]
SyS_ioctl+0x7f/0xb0 fs/ioctl.c:692
do_syscall_64+0x1d5/0x640 arch/x86/entry/common.c:292
entry_SYSCALL_64_after_hwframe+0x42/0xb7
RIP: 0033:0x45c849
RSP: 002b:00007f95bd4e4c78 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
RAX: ffffffffffffffda RBX: 00007f95bd4e56d4 RCX: 000000000045c849
RDX: 0000000020000000 RSI: 0000000000004601 RDI: 0000000000000004
RBP: 000000000076bf00 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 00000000ffffffff
R13: 00000000000002ee R14: 00000000004c547c R15: 000000000076bf0c
Code: a6 a7 7e 81 e2 00 01 1f 00 75 0b 8b 90 50 13 00 00 83 fa 01 74 01 c3 48 8b 34 24 48 8b 88 58 13 00 00 8b 80 54 13 00 00 48 8b 11 <48> 83 c2 01 48 39 d0 76 e2 48 89 34 d1 48 89 11 c3 66 90 41 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#status 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.