syzbot


INFO: task hung in tty_open (2)

Status: upstream: reported C repro on 2022/02/07 03:39
Reported-by: syzbot+5de910bcf13c72072bed@syzkaller.appspotmail.com
First crash: 253d, last: 11d

Cause bisection: failed (bisect log)

Fix bisection: failed (bisect log)
similar bugs (7):
Kernel Title Repro Cause bisect Fix bisect Count Last Reported Patched Status
upstream INFO: task hung in tty_open 1 364d 364d 0/24 auto-closed as invalid on 2022/01/02 10:09
android-44 INFO: task hung in tty_open C 132 1053d 1269d 0/2 public: reported C repro on 2019/04/13 00:00
linux-4.14 INFO: task hung in tty_open 2 805d 857d 0/1 auto-closed as invalid on 2020/11/17 06:29
android-414 INFO: task hung in tty_open C 152 1249d 1271d 0/1 public: reported C repro on 2019/04/11 00:00
android-49 INFO: task hung in tty_open C 447 1034d 1270d 0/3 public: reported C repro on 2019/04/12 00:00
upstream INFO: task can't die in irqentry_exit (2) C error 22 243d 659d 0/24 upstream: reported C repro on 2020/12/13 03:25
upstream INFO: task can't die in show_free_areas C error 11 241d 252d 0/24 upstream: reported C repro on 2022/01/24 13:23

Sample crash report:
INFO: task syz-executor631:3666 blocked for more than 143 seconds.
      Not tainted 5.17.0-rc2-syzkaller-00054-g27bb0b18c208 #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:syz-executor631 state:D stack:27752 pid: 3666 ppid:  3655 flags:0x00004004
Call Trace:
 <TASK>
 context_switch kernel/sched/core.c:4986 [inline]
 __schedule+0xab2/0x4db0 kernel/sched/core.c:6295
 schedule+0xd2/0x260 kernel/sched/core.c:6368
 schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6427
 __mutex_lock_common kernel/locking/mutex.c:673 [inline]
 __mutex_lock+0xa32/0x12f0 kernel/locking/mutex.c:733
 tty_open_by_driver drivers/tty/tty_io.c:2050 [inline]
 tty_open+0x55e/0x1000 drivers/tty/tty_io.c:2133
 chrdev_open+0x266/0x770 fs/char_dev.c:414
 do_dentry_open+0x4b9/0x1240 fs/open.c:824
 do_open fs/namei.c:3476 [inline]
 path_openat+0x1c9e/0x2940 fs/namei.c:3609
 do_filp_open+0x1aa/0x400 fs/namei.c:3636
 do_sys_openat2+0x16d/0x4d0 fs/open.c:1214
 do_sys_open fs/open.c:1230 [inline]
 __do_sys_openat fs/open.c:1246 [inline]
 __se_sys_openat fs/open.c:1241 [inline]
 __x64_sys_openat+0x13f/0x1f0 fs/open.c:1241
 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:0x7f71597959b7
RSP: 002b:00007ffc011acb00 EFLAGS: 00000246 ORIG_RAX: 0000000000000101
RAX: ffffffffffffffda RBX: 0000000000000003 RCX: 00007f71597959b7
RDX: 0000000000000002 RSI: 00007ffc011acb90 RDI: 00000000ffffff9c
RBP: 00007ffc011acb90 R08: 0000000000000000 R09: 000000000000000e
R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000002
R13: 00007ffc011acc50 R14: 00007ffc011acc90 R15: 0000000000000000
 </TASK>
INFO: task syz-executor631:3668 blocked for more than 143 seconds.
      Not tainted 5.17.0-rc2-syzkaller-00054-g27bb0b18c208 #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:syz-executor631 state:D stack:27952 pid: 3668 ppid:  3654 flags:0x00000004
Call Trace:
 <TASK>
 context_switch kernel/sched/core.c:4986 [inline]
 __schedule+0xab2/0x4db0 kernel/sched/core.c:6295
 schedule+0xd2/0x260 kernel/sched/core.c:6368
 schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6427
 __mutex_lock_common kernel/locking/mutex.c:673 [inline]
 __mutex_lock+0xa32/0x12f0 kernel/locking/mutex.c:733
 tty_open_by_driver drivers/tty/tty_io.c:2050 [inline]
 tty_open+0x55e/0x1000 drivers/tty/tty_io.c:2133
 chrdev_open+0x266/0x770 fs/char_dev.c:414
 do_dentry_open+0x4b9/0x1240 fs/open.c:824
 do_open fs/namei.c:3476 [inline]
 path_openat+0x1c9e/0x2940 fs/namei.c:3609
 do_filp_open+0x1aa/0x400 fs/namei.c:3636
 do_sys_openat2+0x16d/0x4d0 fs/open.c:1214
 do_sys_open fs/open.c:1230 [inline]
 __do_sys_openat fs/open.c:1246 [inline]
 __se_sys_openat fs/open.c:1241 [inline]
 __x64_sys_openat+0x13f/0x1f0 fs/open.c:1241
 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:0x7f71597959b7
RSP: 002b:00007ffc011acb00 EFLAGS: 00000246 ORIG_RAX: 0000000000000101
RAX: ffffffffffffffda RBX: 0000000000000003 RCX: 00007f71597959b7
RDX: 0000000000000002 RSI: 00007ffc011acb90 RDI: 00000000ffffff9c
RBP: 00007ffc011acb90 R08: 0000000000000000 R09: 000000000000000e
R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000002
R13: 00007ffc011acc50 R14: 00007ffc011acc90 R15: 0000000000000000
 </TASK>
INFO: task syz-executor631:3670 blocked for more than 143 seconds.
      Not tainted 5.17.0-rc2-syzkaller-00054-g27bb0b18c208 #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:syz-executor631 state:D stack:28096 pid: 3670 ppid:  3656 flags:0x00000004
Call Trace:
 <TASK>
 context_switch kernel/sched/core.c:4986 [inline]
 __schedule+0xab2/0x4db0 kernel/sched/core.c:6295
 schedule+0xd2/0x260 kernel/sched/core.c:6368
 schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6427
 __mutex_lock_common kernel/locking/mutex.c:673 [inline]
 __mutex_lock+0xa32/0x12f0 kernel/locking/mutex.c:733
 tty_open_by_driver drivers/tty/tty_io.c:2050 [inline]
 tty_open+0x55e/0x1000 drivers/tty/tty_io.c:2133
 chrdev_open+0x266/0x770 fs/char_dev.c:414
 do_dentry_open+0x4b9/0x1240 fs/open.c:824
 do_open fs/namei.c:3476 [inline]
 path_openat+0x1c9e/0x2940 fs/namei.c:3609
 do_filp_open+0x1aa/0x400 fs/namei.c:3636
 do_sys_openat2+0x16d/0x4d0 fs/open.c:1214
 do_sys_open fs/open.c:1230 [inline]
 __do_sys_openat fs/open.c:1246 [inline]
 __se_sys_openat fs/open.c:1241 [inline]
 __x64_sys_openat+0x13f/0x1f0 fs/open.c:1241
 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:0x7f71597959b7
RSP: 002b:00007ffc011acb00 EFLAGS: 00000246 ORIG_RAX: 0000000000000101
RAX: ffffffffffffffda RBX: 0000000000000003 RCX: 00007f71597959b7
RDX: 0000000000000002 RSI: 00007ffc011acb90 RDI: 00000000ffffff9c
RBP: 00007ffc011acb90 R08: 0000000000000000 R09: 000000000000000e
R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000002
R13: 00007ffc011acc50 R14: 00007ffc011acc90 R15: 0000000000000000
 </TASK>
INFO: task syz-executor631:3669 blocked for more than 144 seconds.
      Not tainted 5.17.0-rc2-syzkaller-00054-g27bb0b18c208 #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:syz-executor631 state:D stack:27784 pid: 3669 ppid:  3657 flags:0x00000004
Call Trace:
 <TASK>
 context_switch kernel/sched/core.c:4986 [inline]
 __schedule+0xab2/0x4db0 kernel/sched/core.c:6295
 schedule+0xd2/0x260 kernel/sched/core.c:6368
 schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6427
 __mutex_lock_common kernel/locking/mutex.c:673 [inline]
 __mutex_lock+0xa32/0x12f0 kernel/locking/mutex.c:733
 tty_open_by_driver drivers/tty/tty_io.c:2050 [inline]
 tty_open+0x55e/0x1000 drivers/tty/tty_io.c:2133
 chrdev_open+0x266/0x770 fs/char_dev.c:414
 do_dentry_open+0x4b9/0x1240 fs/open.c:824
 do_open fs/namei.c:3476 [inline]
 path_openat+0x1c9e/0x2940 fs/namei.c:3609
 do_filp_open+0x1aa/0x400 fs/namei.c:3636
 do_sys_openat2+0x16d/0x4d0 fs/open.c:1214
 do_sys_open fs/open.c:1230 [inline]
 __do_sys_openat fs/open.c:1246 [inline]
 __se_sys_openat fs/open.c:1241 [inline]
 __x64_sys_openat+0x13f/0x1f0 fs/open.c:1241
 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:0x7f71597959b7
RSP: 002b:00007ffc011acb00 EFLAGS: 00000246 ORIG_RAX: 0000000000000101
RAX: ffffffffffffffda RBX: 0000000000000003 RCX: 00007f71597959b7
RDX: 0000000000000002 RSI: 00007ffc011acb90 RDI: 00000000ffffff9c
RBP: 00007ffc011acb90 R08: 0000000000000000 R09: 000000000000000e
R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000002
R13: 00007ffc011acc50 R14: 00007ffc011acc90 R15: 0000000000000000
 </TASK>

Showing all locks held in the system:
1 lock held by khungtaskd/27:
 #0: ffffffff8bb83c20 (rcu_read_lock){....}-{1:2}, at: debug_show_all_locks+0x53/0x260 kernel/locking/lockdep.c:6460
4 locks held by klogd/2955:
 #0: ffff8880b9c39c58 (&rq->__lock){-.-.}-{2:2}, at: raw_spin_rq_lock_nested+0x2b/0x120 kernel/sched/core.c:489
 #1: ffff8880b9c27948 (&per_cpu_ptr(group->pcpu, cpu)->seq){-.-.}-{0:0}, at: psi_task_switch+0x3e7/0x4e0 kernel/sched/psi.c:891
 #2: ffff88807f104398 (&p->pi_lock){-.-.}-{2:2}, at: try_to_wake_up+0xab/0x1510 kernel/sched/core.c:4017
 #3: ffff8880b9c39c58 (&rq->__lock){-.-.}-{2:2}, at: raw_spin_rq_lock_nested+0x2b/0x120 kernel/sched/core.c:489
2 locks held by getty/3275:
 #0: ffff88814abe3098 (&tty->ldisc_sem){++++}-{0:0}, at: tty_ldisc_ref_wait+0x22/0x80 drivers/tty/tty_ldisc.c:244
 #1: ffffc90002b632e8 (&ldata->atomic_read_lock){+.+.}-{3:3}, at: n_tty_read+0xcf0/0x1230 drivers/tty/n_tty.c:2077
5 locks held by kworker/u4:2/3661:
 #0: ffff8880b9c39c58 (&rq->__lock){-.-.}-{2:2}, at: raw_spin_rq_lock_nested+0x2b/0x120 kernel/sched/core.c:489
 #1: ffff8880b9c27948 (&per_cpu_ptr(group->pcpu, cpu)->seq){-.-.}-{0:0}, at: psi_task_switch+0x176/0x4e0 kernel/sched/psi.c:882
 #2: ffff8880b9c28498 (&base->lock){-.-.}-{2:2}, at: lock_timer_base+0x5a/0x1f0 kernel/time/timer.c:946
 #3: ffffffff907727a8 (&obj_hash[i].lock){-.-.}-{2:2}, at: debug_object_activate+0x12e/0x3e0 lib/debugobjects.c:661
 #4: ffffffff8ba4c3c8 (text_mutex){+.+.}-{3:3}, at: arch_jump_label_transform_apply+0xe/0x20 arch/x86/kernel/jump_label.c:145
3 locks held by syz-executor631/3665:
1 lock held by syz-executor631/3666:
 #0: ffffffff8c5aeba8 (tty_mutex){+.+.}-{3:3}, at: tty_open_by_driver drivers/tty/tty_io.c:2050 [inline]
 #0: ffffffff8c5aeba8 (tty_mutex){+.+.}-{3:3}, at: tty_open+0x55e/0x1000 drivers/tty/tty_io.c:2133
1 lock held by syz-executor631/3668:
 #0: ffffffff8c5aeba8 (tty_mutex){+.+.}-{3:3}, at: tty_open_by_driver drivers/tty/tty_io.c:2050 [inline]
 #0: ffffffff8c5aeba8 (tty_mutex){+.+.}-{3:3}, at: tty_open+0x55e/0x1000 drivers/tty/tty_io.c:2133
1 lock held by syz-executor631/3670:
 #0: ffffffff8c5aeba8 (tty_mutex){+.+.}-{3:3}, at: tty_open_by_driver drivers/tty/tty_io.c:2050 [inline]
 #0: ffffffff8c5aeba8 (tty_mutex){+.+.}-{3:3}, at: tty_open+0x55e/0x1000 drivers/tty/tty_io.c:2133
1 lock held by syz-executor631/3669:
 #0: ffffffff8c5aeba8 (tty_mutex){+.+.}-{3:3}, at: tty_open_by_driver drivers/tty/tty_io.c:2050 [inline]
 #0: ffffffff8c5aeba8 (tty_mutex){+.+.}-{3:3}, at: tty_open+0x55e/0x1000 drivers/tty/tty_io.c:2133
1 lock held by syz-executor631/3681:
 #0: ffffffff8c5aeba8 (tty_mutex){+.+.}-{3:3}, at: tty_open_by_driver drivers/tty/tty_io.c:2050 [inline]
 #0: ffffffff8c5aeba8 (tty_mutex){+.+.}-{3:3}, at: tty_open+0x55e/0x1000 drivers/tty/tty_io.c:2133

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

NMI backtrace for cpu 1
CPU: 1 PID: 27 Comm: khungtaskd Not tainted 5.17.0-rc2-syzkaller-00054-g27bb0b18c208 #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
Call Trace:
 <TASK>
 __dump_stack lib/dump_stack.c:88 [inline]
 dump_stack_lvl+0xcd/0x134 lib/dump_stack.c:106
 nmi_cpu_backtrace.cold+0x47/0x144 lib/nmi_backtrace.c:111
 nmi_trigger_cpumask_backtrace+0x1b3/0x230 lib/nmi_backtrace.c:62
 trigger_all_cpu_backtrace include/linux/nmi.h:146 [inline]
 check_hung_uninterruptible_tasks kernel/hung_task.c:212 [inline]
 watchdog+0xc1d/0xf50 kernel/hung_task.c:369
 kthread+0x2e9/0x3a0 kernel/kthread.c:377
 ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:295
 </TASK>
Sending NMI from CPU 1 to CPUs 0:
NMI backtrace for cpu 0
CPU: 0 PID: 5 Comm: kworker/0:0 Not tainted 5.17.0-rc2-syzkaller-00054-g27bb0b18c208 #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
Workqueue: events kfree_rcu_work
RIP: 0010:mark_lock+0x151/0x17b0 kernel/locking/lockdep.c:4566
Code: 12 00 00 48 89 ee 48 23 70 50 41 ba 01 00 00 00 0f 84 79 01 00 00 48 b8 00 00 00 00 00 fc ff df 48 01 c3 48 c7 03 00 00 00 00 <c7> 43 08 00 00 00 00 48 c7 43 10 00 00 00 00 48 8b 84 24 10 01 00
RSP: 0018:ffffc90000ca78e0 EFLAGS: 00000082
RAX: dffffc0000000000 RBX: fffff52000194f23 RCX: 1ffffffff1ff8bee
RDX: dffffc0000000000 RSI: 0000000000000040 RDI: ffffffff8ffc5f70
RBP: 0000000000000040 R08: 0000000000000000 R09: ffffffff8ffbd957
R10: 0000000000000001 R11: 0000000000000001 R12: 0000000000000006
R13: ffff888011920a60 R14: 00000000000000ad R15: ffff888011920a80
FS:  0000000000000000(0000) GS:ffff8880b9c00000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 00007fef09f19600 CR3: 000000007f8f6000 CR4: 00000000003506f0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Call Trace:
 <TASK>
 mark_held_locks+0x9f/0xe0 kernel/locking/lockdep.c:4206
 __trace_hardirqs_on_caller kernel/locking/lockdep.c:4232 [inline]
 lockdep_hardirqs_on_prepare kernel/locking/lockdep.c:4292 [inline]
 lockdep_hardirqs_on_prepare+0x28b/0x400 kernel/locking/lockdep.c:4244
 trace_hardirqs_on+0x5b/0x1c0 kernel/trace/trace_preemptirq.c:49
 __raw_spin_unlock_irqrestore include/linux/spinlock_api_smp.h:151 [inline]
 _raw_spin_unlock_irqrestore+0x50/0x70 kernel/locking/spinlock.c:194
 __debug_check_no_obj_freed lib/debugobjects.c:1002 [inline]
 debug_check_no_obj_freed+0x20c/0x420 lib/debugobjects.c:1023
 slab_free_hook mm/slub.c:1703 [inline]
 slab_free_freelist_hook+0xeb/0x1c0 mm/slub.c:1754
 slab_free mm/slub.c:3509 [inline]
 kmem_cache_free_bulk mm/slub.c:3656 [inline]
 kmem_cache_free_bulk+0x2b0/0xa40 mm/slub.c:3643
 kfree_bulk include/linux/slab.h:437 [inline]
 kfree_rcu_work+0x51c/0xa10 kernel/rcu/tree.c:3314
 process_one_work+0x9ac/0x1650 kernel/workqueue.c:2307
 worker_thread+0x657/0x1110 kernel/workqueue.c:2454
 kthread+0x2e9/0x3a0 kernel/kthread.c:377
 ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:295
 </TASK>
INFO: NMI handler (nmi_cpu_backtrace_handler) took too long to run: 1.090 msecs
----------------
Code disassembly (best guess):
   0:	12 00                	adc    (%rax),%al
   2:	00 48 89             	add    %cl,-0x77(%rax)
   5:	ee                   	out    %al,(%dx)
   6:	48 23 70 50          	and    0x50(%rax),%rsi
   a:	41 ba 01 00 00 00    	mov    $0x1,%r10d
  10:	0f 84 79 01 00 00    	je     0x18f
  16:	48 b8 00 00 00 00 00 	movabs $0xdffffc0000000000,%rax
  1d:	fc ff df
  20:	48 01 c3             	add    %rax,%rbx
  23:	48 c7 03 00 00 00 00 	movq   $0x0,(%rbx)
* 2a:	c7 43 08 00 00 00 00 	movl   $0x0,0x8(%rbx) <-- trapping instruction
  31:	48 c7 43 10 00 00 00 	movq   $0x0,0x10(%rbx)
  38:	00
  39:	48                   	rex.W
  3a:	8b                   	.byte 0x8b
  3b:	84 24 10             	test   %ah,(%rax,%rdx,1)
  3e:	01 00                	add    %eax,(%rax)

Crashes (17):
Manager Time Kernel Commit Syzkaller Config Log Report Syz repro C repro VM info Title
ci-upstream-kasan-gce 2022/02/03 03:32 upstream 27bb0b18c208 4ebb2798 .config log report syz C INFO: task hung in tty_open
ci-upstream-kasan-gce 2022/09/21 20:57 upstream 06f7db949993 380f82fb .config log report info INFO: task hung in tty_open
ci-upstream-kasan-gce 2022/08/09 19:22 upstream 200e340f2196 c2a623d6 .config log report info INFO: task hung in tty_open
ci-upstream-kasan-gce 2022/07/20 03:47 upstream ca85855bdcae 775344bc .config log report info INFO: task hung in tty_open
ci-upstream-kasan-gce 2022/03/16 16:05 upstream 56e337f2cf13 dfa9a8ed .config log report info INFO: task hung in tty_open
ci-upstream-kasan-gce 2022/03/06 23:38 upstream ffb217a13a2e 7bdd8b2c .config log report info INFO: task hung in tty_open
ci-upstream-kasan-gce-smack-root 2022/02/05 23:06 upstream 90c9e950c0de a7dab638 .config log report info INFO: task hung in tty_open
ci-upstream-kasan-gce-root 2022/02/04 11:35 upstream dcb85f85fa6f a3e470b2 .config log report info INFO: task hung in tty_open
ci-upstream-kasan-gce-selinux-root 2022/02/03 12:09 upstream 88808fbbead4 4ebb2798 .config log report info INFO: task hung in tty_open
ci-upstream-kasan-gce-root 2022/02/01 15:11 upstream 26291c54e111 c1c1631d .config log report info INFO: task hung in tty_open
ci-upstream-kasan-gce-root 2022/01/31 09:12 upstream 26291c54e111 6b7c57fe .config log report info INFO: task hung in tty_open
ci-upstream-kasan-gce-root 2022/01/31 08:30 upstream 26291c54e111 6b7c57fe .config log report info INFO: task hung in tty_open
ci-upstream-kasan-gce 2022/01/28 05:30 upstream 23a46422c561 495e00c5 .config log report info INFO: task hung in tty_open
ci-upstream-kasan-gce 2022/01/27 11:31 upstream 626b2dda7651 2cbffd88 .config log report info INFO: task hung in tty_open
ci-upstream-kasan-gce-selinux-root 2022/01/25 09:23 upstream a08b41ab9e2e 2cbffd88 .config log report info INFO: task hung in tty_open
ci-upstream-kasan-gce-root 2022/01/23 13:59 upstream 1c52283265a4 214351e1 .config log report info INFO: task hung in tty_open
ci-upstream-kasan-gce-386 2022/01/23 18:00 upstream dd81e1c7d5fb 214351e1 .config log report info INFO: task hung in tty_open
* Struck through repros no longer work on HEAD.