syzbot


INFO: task hung in do_con_write (2)

Status: auto-closed as invalid on 2021/12/25 05:43
Reported-by: syzbot+@syzkaller.appspotmail.com
First crash: 438d, last: 428d
similar bugs (4):
Kernel Title Repro Cause bisect Fix bisect Count Last Reported Patched Status
upstream INFO: task hung in do_con_write 4 872d 1040d 0/24 auto-closed as invalid on 2020/10/06 18:58
linux-4.14 INFO: task hung in do_con_write 9 852d 1069d 0/1 auto-closed as invalid on 2020/11/25 15:01
upstream INFO: task hung in do_con_write (3) 1 92d 92d 0/24 auto-obsoleted due to no activity on 2022/11/25 16:33
linux-4.19 INFO: task hung in do_con_write 3 853d 910d 0/1 auto-closed as invalid on 2020/11/25 06:45

Sample crash report:
INFO: task kworker/u4:2:16778 blocked for more than 143 seconds.
      Not tainted 5.15.0-rc1-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:kworker/u4:2    state:D stack:24176 pid:16778 ppid:     2 flags:0x00004000
Workqueue: events_unbound flush_to_ldisc
Call Trace:
 context_switch kernel/sched/core.c:4940 [inline]
 __schedule+0x947/0x22b0 kernel/sched/core.c:6287
 schedule+0xcf/0x270 kernel/sched/core.c:6366
 schedule_timeout+0x1db/0x2a0 kernel/time/timer.c:1857
 __down_common+0x2e0/0x420 kernel/locking/semaphore.c:224
 down+0x72/0xa0 kernel/locking/semaphore.c:62
 console_lock+0x2a/0x80 kernel/printk/printk.c:2523
 do_con_write+0x10f/0x1e40 drivers/tty/vt/vt.c:2908
 con_put_char+0x70/0xa0 drivers/tty/vt/vt.c:3303
 tty_put_char+0xb7/0x150 drivers/tty/tty_io.c:3173
 __process_echoes+0x583/0x9f0 drivers/tty/n_tty.c:726
 flush_echoes drivers/tty/n_tty.c:826 [inline]
 __receive_buf drivers/tty/n_tty.c:1579 [inline]
 n_tty_receive_buf_common+0x1699/0x4780 drivers/tty/n_tty.c:1674
 tty_ldisc_receive_buf+0xa3/0x190 drivers/tty/tty_buffer.c:471
 tty_port_default_receive_buf+0x6e/0xa0 drivers/tty/tty_port.c:39
 receive_buf drivers/tty/tty_buffer.c:491 [inline]
 flush_to_ldisc+0x20d/0x380 drivers/tty/tty_buffer.c:543
 process_one_work+0x9bf/0x1620 kernel/workqueue.c:2297
 worker_thread+0x658/0x11f0 kernel/workqueue.c:2444
 kthread+0x3c2/0x4a0 kernel/kthread.c:319
 ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:295
INFO: task syz-executor.5:13843 blocked for more than 143 seconds.
      Not tainted 5.15.0-rc1-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:syz-executor.5  state:D stack:28656 pid:13843 ppid:  3709 flags:0x00004006
Call Trace:
 context_switch kernel/sched/core.c:4940 [inline]
 __schedule+0x947/0x22b0 kernel/sched/core.c:6287
 schedule+0xcf/0x270 kernel/sched/core.c:6366
 synchronize_rcu_expedited+0x499/0x640 kernel/rcu/tree_exp.h:853
 synchronize_rcu+0x154/0x1b0 kernel/rcu/tree.c:3746
 evdev_detach_client drivers/input/evdev.c:386 [inline]
 evdev_release+0x23f/0x410 drivers/input/evdev.c:449
 __fput+0x288/0x9f0 fs/file_table.c:280
 task_work_run+0xdd/0x1a0 kernel/task_work.c:164
 exit_task_work include/linux/task_work.h:32 [inline]
 do_exit+0xbae/0x2890 kernel/exit.c:825
 do_group_exit+0x125/0x310 kernel/exit.c:922
 get_signal+0x47f/0x2170 kernel/signal.c:2868
 arch_do_signal_or_restart+0x2a9/0x1c10 arch/x86/kernel/signal.c:865
 handle_signal_work kernel/entry/common.c:148 [inline]
 exit_to_user_mode_loop kernel/entry/common.c:172 [inline]
 exit_to_user_mode_prepare+0x15d/0x220 kernel/entry/common.c:209
 __syscall_exit_to_user_mode_work kernel/entry/common.c:291 [inline]
 syscall_exit_to_user_mode+0x19/0x60 kernel/entry/common.c:302
 do_syscall_64+0x42/0xb0 arch/x86/entry/common.c:86
 entry_SYSCALL_64_after_hwframe+0x44/0xae
RIP: 0033:0x7f45196944c7
RSP: 002b:00007f45173e90b8 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
RAX: fffffffffffffffc RBX: 00007f45173ea130 RCX: 00007f45196944c7
RDX: 00007f45173ea130 RSI: 0000000080085502 RDI: 0000000000000005
RBP: 0000000000000005 R08: 000000000000ffff R09: 000000000000000b
R10: 00007f45173e9180 R11: 0000000000000246 R12: 0000000800000000
R13: 0000000000000000 R14: 0000000020000180 R15: 00007f45196fa0b6

Showing all locks held in the system:
6 locks held by kworker/1:0/17:
 #0: ffff8881035fcd38 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: arch_atomic64_set arch/x86/include/asm/atomic64_64.h:34 [inline]
 #0: ffff8881035fcd38 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: arch_atomic_long_set include/linux/atomic/atomic-long.h:41 [inline]
 #0: ffff8881035fcd38 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: atomic_long_set include/linux/atomic/atomic-instrumented.h:1198 [inline]
 #0: ffff8881035fcd38 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: set_work_data kernel/workqueue.c:634 [inline]
 #0: ffff8881035fcd38 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: set_work_pool_and_clear_pending kernel/workqueue.c:661 [inline]
 #0: ffff8881035fcd38 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: process_one_work+0x8a3/0x1620 kernel/workqueue.c:2268
 #1: ffffc9000012fdb0 ((work_completion)(&hub->events)){+.+.}-{0:0}, at: process_one_work+0x8d7/0x1620 kernel/workqueue.c:2272
 #2: ffff88810cde5220 (&dev->mutex){....}-{3:3}, at: device_lock include/linux/device.h:760 [inline]
 #2: ffff88810cde5220 (&dev->mutex){....}-{3:3}, at: hub_event+0x1c1/0x4330 drivers/usb/core/hub.c:5662
 #3: ffff88811f26e220 (&dev->mutex){....}-{3:3}, at: device_lock include/linux/device.h:760 [inline]
 #3: ffff88811f26e220 (&dev->mutex){....}-{3:3}, at: __device_attach+0x7a/0x4a0 drivers/base/dd.c:944
 #4: ffff8881143ae1a8 (&dev->mutex){....}-{3:3}, at: device_lock include/linux/device.h:760 [inline]
 #4: ffff8881143ae1a8 (&dev->mutex){....}-{3:3}, at: __device_attach+0x7a/0x4a0 drivers/base/dd.c:944
 #5: ffff8881128d0ce0 (&dev->phy_mutex){+.+.}-{3:3}, at: asix_mdio_read+0x86/0x220 drivers/net/usb/asix_common.c:495
1 lock held by khungtaskd/24:
 #0: ffffffff87681ea0 (rcu_read_lock){....}-{1:2}, at: debug_show_all_locks+0x53/0x269 kernel/locking/lockdep.c:6446
1 lock held by in:imklog/2808:
 #0: ffff88811706fc70 (&f->f_pos_lock){+.+.}-{3:3}, at: __fdget_pos+0xe9/0x100 fs/file.c:990
1 lock held by syz-executor.5/3709:
 #0: ffffffff876889e8 (rcu_state.exp_mutex){+.+.}-{3:3}, at: exp_funnel_lock kernel/rcu/tree_exp.h:322 [inline]
 #0: ffffffff876889e8 (rcu_state.exp_mutex){+.+.}-{3:3}, at: synchronize_rcu_expedited+0x2fb/0x640 kernel/rcu/tree_exp.h:837
6 locks held by kworker/1:6/5797:
 #0: ffff8881035fcd38 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: arch_atomic64_set arch/x86/include/asm/atomic64_64.h:34 [inline]
 #0: ffff8881035fcd38 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: arch_atomic_long_set include/linux/atomic/atomic-long.h:41 [inline]
 #0: ffff8881035fcd38 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: atomic_long_set include/linux/atomic/atomic-instrumented.h:1198 [inline]
 #0: ffff8881035fcd38 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: set_work_data kernel/workqueue.c:634 [inline]
 #0: ffff8881035fcd38 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: set_work_pool_and_clear_pending kernel/workqueue.c:661 [inline]
 #0: ffff8881035fcd38 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: process_one_work+0x8a3/0x1620 kernel/workqueue.c:2268
 #1: ffffc900030c7db0 ((work_completion)(&hub->events)){+.+.}-{0:0}, at: process_one_work+0x8d7/0x1620 kernel/workqueue.c:2272
 #2: ffff88810cc5d220 (&dev->mutex){....}-{3:3}, at: device_lock include/linux/device.h:760 [inline]
 #2: ffff88810cc5d220 (&dev->mutex){....}-{3:3}, at: hub_event+0x1c1/0x4330 drivers/usb/core/hub.c:5662
 #3: ffff88811d384220 (&dev->mutex){....}-{3:3}, at: device_lock include/linux/device.h:760 [inline]
 #3: ffff88811d384220 (&dev->mutex){....}-{3:3}, at: __device_attach+0x7a/0x4a0 drivers/base/dd.c:944
 #4: ffff888118def1a8 (&dev->mutex){....}-{3:3}, at: device_lock include/linux/device.h:760 [inline]
 #4: ffff888118def1a8 (&dev->mutex){....}-{3:3}, at: __device_attach+0x7a/0x4a0 drivers/base/dd.c:944
 #5: ffff8881065b4ce0 (&dev->phy_mutex){+.+.}-{3:3}, at: asix_mdio_read+0x86/0x220 drivers/net/usb/asix_common.c:495
3 locks held by kworker/1:2/21761:
2 locks held by agetty/8480:
 #0: ffff88811d43f098 (&tty->ldisc_sem){++++}-{0:0}, at: tty_ldisc_ref_wait+0x22/0x80 drivers/tty/tty_ldisc.c:252
 #1: ffffc9000209b2e8 (&ldata->atomic_read_lock){+.+.}-{3:3}, at: n_tty_read+0xcf0/0x1230 drivers/tty/n_tty.c:2113
6 locks held by kworker/u4:2/16778:
 #0: ffff888100069138 ((wq_completion)events_unbound){+.+.}-{0:0}, at: arch_atomic64_set arch/x86/include/asm/atomic64_64.h:34 [inline]
 #0: ffff888100069138 ((wq_completion)events_unbound){+.+.}-{0:0}, at: arch_atomic_long_set include/linux/atomic/atomic-long.h:41 [inline]
 #0: ffff888100069138 ((wq_completion)events_unbound){+.+.}-{0:0}, at: atomic_long_set include/linux/atomic/atomic-instrumented.h:1198 [inline]
 #0: ffff888100069138 ((wq_completion)events_unbound){+.+.}-{0:0}, at: set_work_data kernel/workqueue.c:634 [inline]
 #0: ffff888100069138 ((wq_completion)events_unbound){+.+.}-{0:0}, at: set_work_pool_and_clear_pending kernel/workqueue.c:661 [inline]
 #0: ffff888100069138 ((wq_completion)events_unbound){+.+.}-{0:0}, at: process_one_work+0x8a3/0x1620 kernel/workqueue.c:2268
 #1: ffffc90012ba7db0 ((work_completion)(&buf->work)){+.+.}-{0:0}, at: process_one_work+0x8d7/0x1620 kernel/workqueue.c:2272
 #2: ffff88811608d0b8 (&buf->lock){+.+.}-{3:3}, at: flush_to_ldisc+0x3e/0x380 drivers/tty/tty_buffer.c:515
 #3: ffff8881169e9098 (&tty->ldisc_sem){++++}-{0:0}, at: tty_ldisc_ref+0x1d/0x80 drivers/tty/tty_ldisc.c:273
 #4: ffff8881169e92e8 (&tty->termios_rwsem){++++}-{3:3}, at: n_tty_receive_buf_common+0x84/0x4780 drivers/tty/n_tty.c:1637
 #5: ffffc9000182b378 (&ldata->output_lock){+.+.}-{3:3}, at: flush_echoes drivers/tty/n_tty.c:824 [inline]
 #5: ffffc9000182b378 (&ldata->output_lock){+.+.}-{3:3}, at: __receive_buf drivers/tty/n_tty.c:1579 [inline]
 #5: ffffc9000182b378 (&ldata->output_lock){+.+.}-{3:3}, at: n_tty_receive_buf_common+0x1663/0x4780 drivers/tty/n_tty.c:1674
2 locks held by agetty/353:
 #0: ffff8881169e9098 (&tty->ldisc_sem){++++}-{0:0}, at: tty_ldisc_ref_wait+0x22/0x80 drivers/tty/tty_ldisc.c:252
 #1: ffffc9000182b2e8 (&ldata->atomic_read_lock){+.+.}-{3:3}, at: n_tty_read+0xcf0/0x1230 drivers/tty/n_tty.c:2113
1 lock held by syz-executor.5/13843:
 #0: ffffffff876889e8 (rcu_state.exp_mutex){+.+.}-{3:3}, at: exp_funnel_lock kernel/rcu/tree_exp.h:290 [inline]
 #0: ffffffff876889e8 (rcu_state.exp_mutex){+.+.}-{3:3}, at: synchronize_rcu_expedited+0x522/0x640 kernel/rcu/tree_exp.h:837

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

NMI backtrace for cpu 1
CPU: 1 PID: 24 Comm: khungtaskd Not tainted 5.15.0-rc1-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
Call Trace:
 __dump_stack lib/dump_stack.c:88 [inline]
 dump_stack_lvl+0xcd/0x134 lib/dump_stack.c:106
 nmi_cpu_backtrace.cold+0x49/0x148 lib/nmi_backtrace.c:105
 nmi_trigger_cpumask_backtrace+0x1d5/0x1f0 lib/nmi_backtrace.c:62
 trigger_all_cpu_backtrace include/linux/nmi.h:146 [inline]
 check_hung_uninterruptible_tasks kernel/hung_task.c:210 [inline]
 watchdog+0xc0f/0xf20 kernel/hung_task.c:295
 kthread+0x3c2/0x4a0 kernel/kthread.c:319
 ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:295
Sending NMI from CPU 1 to CPUs 0:
NMI backtrace for cpu 0
CPU: 0 PID: 1154 Comm: systemd-journal Not tainted 5.15.0-rc1-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
RIP: 0010:number+0x16a/0xae0 lib/vsprintf.c:465
Code: 30 89 d8 83 e0 20 88 44 24 37 89 d8 83 e0 02 89 c5 89 c6 88 44 24 34 e8 74 79 31 ff 40 84 ed 0f 85 c7 06 00 00 e8 36 72 31 ff <83> e3 12 88 5c 24 36 e8 2a 72 31 ff 0f b6 5c 24 04 31 ff 83 e3 01
RSP: 0018:ffffc90000267730 EFLAGS: 00000293
RAX: 0000000000000000 RBX: 0000000000000020 RCX: 0000000000000000
RDX: ffff88811285d1c0 RSI: ffffffff8210467a RDI: 0000000000000003
RBP: 0000000000000000 R08: 000000000000002f R09: 0000000000000000
R10: ffffffff8210466c R11: 0000000000000000 R12: ffff888114c6e24a
R13: ffffffff8684e22d R14: ffff888114c6ea1c R15: ffff888114c6e24a
FS:  00007f34db4248c0(0000) GS:ffff8881f6800000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 00007f34d676e008 CR3: 000000010d239000 CR4: 00000000001506f0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Call Trace:
 vsnprintf+0xf09/0x14f0 lib/vsprintf.c:2863
 add_uevent_var+0x15d/0x380 lib/kobject_uevent.c:665
 usb_uevent+0x1b7/0x490 drivers/usb/core/driver.c:926
 dev_uevent+0x202/0x780 drivers/base/core.c:2294
 uevent_show+0x1bb/0x390 drivers/base/core.c:2358
 dev_attr_show+0x4b/0x90 drivers/base/core.c:2060
 sysfs_kf_seq_show+0x1f8/0x400 fs/sysfs/file.c:61
 seq_read_iter+0x4f6/0x1240 fs/seq_file.c:230
 kernfs_fop_read_iter+0x44f/0x5f0 fs/kernfs/file.c:241
 call_read_iter include/linux/fs.h:2157 [inline]
 new_sync_read+0x400/0x6b0 fs/read_write.c:404
 vfs_read+0x35c/0x600 fs/read_write.c:485
 ksys_read+0x12d/0x250 fs/read_write.c:623
 do_syscall_x64 arch/x86/entry/common.c:50 [inline]
 do_syscall_64+0x35/0xb0 arch/x86/entry/common.c:80
 entry_SYSCALL_64_after_hwframe+0x44/0xae
RIP: 0033:0x7f34da6df92d
Code: 2d 2c 00 00 75 10 b8 00 00 00 00 0f 05 48 3d 01 f0 ff ff 73 31 c3 48 83 ec 08 e8 de 9b 01 00 48 89 04 24 b8 00 00 00 00 0f 05 <48> 8b 3c 24 48 89 c2 e8 27 9c 01 00 48 89 d0 48 83 c4 08 48 3d 01
RSP: 002b:00007ffed5155f80 EFLAGS: 00000293 ORIG_RAX: 0000000000000000
RAX: ffffffffffffffda RBX: 000055be22c64c70 RCX: 00007f34da6df92d
RDX: 0000000000001000 RSI: 000055be22c66800 RDI: 0000000000000010
RBP: 00007f34da99a440 R08: 0000000000000003 R09: 0000000000001010
R10: 000055be22c64c70 R11: 0000000000000293 R12: 0000000000001000
R13: 0000000000000d68 R14: 000055be22c66800 R15: 00007f34da999900
----------------
Code disassembly (best guess):
   0:	30 89 d8 83 e0 20    	xor    %cl,0x20e083d8(%rcx)
   6:	88 44 24 37          	mov    %al,0x37(%rsp)
   a:	89 d8                	mov    %ebx,%eax
   c:	83 e0 02             	and    $0x2,%eax
   f:	89 c5                	mov    %eax,%ebp
  11:	89 c6                	mov    %eax,%esi
  13:	88 44 24 34          	mov    %al,0x34(%rsp)
  17:	e8 74 79 31 ff       	callq  0xff317990
  1c:	40 84 ed             	test   %bpl,%bpl
  1f:	0f 85 c7 06 00 00    	jne    0x6ec
  25:	e8 36 72 31 ff       	callq  0xff317260
* 2a:	83 e3 12             	and    $0x12,%ebx <-- trapping instruction
  2d:	88 5c 24 36          	mov    %bl,0x36(%rsp)
  31:	e8 2a 72 31 ff       	callq  0xff317260
  36:	0f b6 5c 24 04       	movzbl 0x4(%rsp),%ebx
  3b:	31 ff                	xor    %edi,%edi
  3d:	83 e3 01             	and    $0x1,%ebx

Crashes (2):
Manager Time Kernel Commit Syzkaller Config Log Report Syz repro C repro VM info Title
ci2-upstream-usb 2021/09/26 05:38 https://git.kernel.org/pub/scm/linux/kernel/git/gregkh/usb.git usb-testing 8217f07a5023 8cac236e .config log report info INFO: task hung in do_con_write
ci2-upstream-usb 2021/09/16 11:17 https://git.kernel.org/pub/scm/linux/kernel/git/gregkh/usb.git usb-testing ae8709b296d8 07e953c1 .config log report info INFO: task hung in do_con_write
* Struck through repros no longer work on HEAD.