syzbot


INFO: task hung in paste_selection
Status: fixed on 2020/03/27 08:38
Reported-by: syzbot+7a3d898477ca5e9e9c26@syzkaller.appspotmail.com
Fix commit: 7c315855c6f4 ipvlan: do not use cond_resched_rcu() in ipvlan_process_multicast()
First crash: 897d, last: 822d

Fix bisection: fixed by (bisect log) :
commit 7c315855c6f490d0bb70bc38a85b536011b9bd82
Author: Eric Dumazet <edumazet@google.com>
Date: Tue Mar 10 01:22:58 2020 +0000

  ipvlan: do not use cond_resched_rcu() in ipvlan_process_multicast()

similar bugs (5):
Kernel Title Repro Cause bisect Fix bisect Count Last Reported Patched Status
linux-4.19 INFO: task hung in paste_selection C done 10 822d 897d 1/1 fixed on 2020/03/26 13:10
upstream INFO: task hung in paste_selection (2) C inconclusive error 6 149d 281d 0/22 upstream: reported C repro on 2021/08/19 03:38
upstream INFO: task hung in paste_selection C inconclusive done 8 838d 903d 17/22 fixed on 2020/04/15 17:19
linux-4.14 INFO: task hung in paste_selection (3) 1 488d 488d 0/1 auto-closed as invalid on 2021/05/24 08:55
linux-4.14 INFO: task hung in paste_selection (2) 1 680d 680d 0/1 auto-closed as invalid on 2020/11/12 23:24

Sample crash report:
INFO: task syz-executor862:15496 blocked for more than 140 seconds.
      Not tainted 4.14.158-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
syz-executor862 D28528 15496   7131 0x00000004
Call Trace:
 context_switch kernel/sched/core.c:2808 [inline]
 __schedule+0x7b8/0x1cd0 kernel/sched/core.c:3384
 schedule+0x92/0x1c0 kernel/sched/core.c:3428
 schedule_preempt_disabled+0x13/0x20 kernel/sched/core.c:3486
 __mutex_lock_common kernel/locking/mutex.c:833 [inline]
 __mutex_lock+0x73c/0x1470 kernel/locking/mutex.c:893
 mutex_lock_nested+0x16/0x20 kernel/locking/mutex.c:908
 tty_buffer_lock_exclusive+0x1f/0x30 drivers/tty/tty_buffer.c:60
 paste_selection+0x106/0x3f2 drivers/tty/vt/selection.c:349
 tioclinux+0x10e/0x400 drivers/tty/vt/vt.c:2696
 vt_ioctl+0x180c/0x2170 drivers/tty/vt/vt_ioctl.c:364
 tty_ioctl+0x841/0x1320 drivers/tty/tty_io.c:2661
 vfs_ioctl fs/ioctl.c:46 [inline]
 file_ioctl fs/ioctl.c:500 [inline]
 do_vfs_ioctl+0x7ae/0x1060 fs/ioctl.c:684
 SYSC_ioctl fs/ioctl.c:701 [inline]
 SyS_ioctl+0x8f/0xc0 fs/ioctl.c:692
 do_syscall_64+0x1e8/0x640 arch/x86/entry/common.c:292
 entry_SYSCALL_64_after_hwframe+0x42/0xb7
RIP: 0033:0x441319
RSP: 002b:00007ffce96f8578 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
RAX: ffffffffffffffda RBX: 0000000000000000 RCX: 0000000000441319
RDX: 0000000020000040 RSI: 000000000000541c RDI: 0000000000000004
RBP: 00000000000a7ee4 R08: 000000000000000d R09: 00000000004002c8
R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000402090
R13: 0000000000402120 R14: 0000000000000000 R15: 0000000000000000
INFO: task syz-executor862:15497 blocked for more than 140 seconds.
      Not tainted 4.14.158-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
syz-executor862 D28528 15497   7130 0x00000004
Call Trace:
 context_switch kernel/sched/core.c:2808 [inline]
 __schedule+0x7b8/0x1cd0 kernel/sched/core.c:3384
 schedule+0x92/0x1c0 kernel/sched/core.c:3428
 schedule_preempt_disabled+0x13/0x20 kernel/sched/core.c:3486
 __mutex_lock_common kernel/locking/mutex.c:833 [inline]
 __mutex_lock+0x73c/0x1470 kernel/locking/mutex.c:893
 mutex_lock_nested+0x16/0x20 kernel/locking/mutex.c:908
 tty_buffer_lock_exclusive+0x1f/0x30 drivers/tty/tty_buffer.c:60
 paste_selection+0x106/0x3f2 drivers/tty/vt/selection.c:349
 tioclinux+0x10e/0x400 drivers/tty/vt/vt.c:2696
 vt_ioctl+0x180c/0x2170 drivers/tty/vt/vt_ioctl.c:364
 tty_ioctl+0x841/0x1320 drivers/tty/tty_io.c:2661
 vfs_ioctl fs/ioctl.c:46 [inline]
 file_ioctl fs/ioctl.c:500 [inline]
 do_vfs_ioctl+0x7ae/0x1060 fs/ioctl.c:684
 SYSC_ioctl fs/ioctl.c:701 [inline]
 SyS_ioctl+0x8f/0xc0 fs/ioctl.c:692
 do_syscall_64+0x1e8/0x640 arch/x86/entry/common.c:292
 entry_SYSCALL_64_after_hwframe+0x42/0xb7
RIP: 0033:0x441319
RSP: 002b:00007ffce96f8578 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
RAX: ffffffffffffffda RBX: 0000000000000000 RCX: 0000000000441319
RDX: 0000000020000040 RSI: 000000000000541c RDI: 0000000000000004
RBP: 00000000000a7ef3 R08: 000000000000000d R09: 00000000004002c8
R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000402090
R13: 0000000000402120 R14: 0000000000000000 R15: 0000000000000000
INFO: task syz-executor862:15498 blocked for more than 140 seconds.
      Not tainted 4.14.158-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
syz-executor862 D28528 15498   7133 0x00000004
Call Trace:
 context_switch kernel/sched/core.c:2808 [inline]
 __schedule+0x7b8/0x1cd0 kernel/sched/core.c:3384
 schedule+0x92/0x1c0 kernel/sched/core.c:3428
 schedule_preempt_disabled+0x13/0x20 kernel/sched/core.c:3486
 __mutex_lock_common kernel/locking/mutex.c:833 [inline]
 __mutex_lock+0x73c/0x1470 kernel/locking/mutex.c:893
 mutex_lock_nested+0x16/0x20 kernel/locking/mutex.c:908
 tty_buffer_lock_exclusive+0x1f/0x30 drivers/tty/tty_buffer.c:60
 paste_selection+0x106/0x3f2 drivers/tty/vt/selection.c:349
 tioclinux+0x10e/0x400 drivers/tty/vt/vt.c:2696
 vt_ioctl+0x180c/0x2170 drivers/tty/vt/vt_ioctl.c:364
 tty_ioctl+0x841/0x1320 drivers/tty/tty_io.c:2661
 vfs_ioctl fs/ioctl.c:46 [inline]
 file_ioctl fs/ioctl.c:500 [inline]
 do_vfs_ioctl+0x7ae/0x1060 fs/ioctl.c:684
 SYSC_ioctl fs/ioctl.c:701 [inline]
 SyS_ioctl+0x8f/0xc0 fs/ioctl.c:692
 do_syscall_64+0x1e8/0x640 arch/x86/entry/common.c:292
 entry_SYSCALL_64_after_hwframe+0x42/0xb7
RIP: 0033:0x441319
RSP: 002b:00007ffce96f8578 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
RAX: ffffffffffffffda RBX: 0000000000000000 RCX: 0000000000441319
RDX: 0000000020000040 RSI: 000000000000541c RDI: 0000000000000004
RBP: 00000000000a7f02 R08: 000000000000000d R09: 00000000004002c8
R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000402090
R13: 0000000000402120 R14: 0000000000000000 R15: 0000000000000000
INFO: task syz-executor862:15500 blocked for more than 140 seconds.
      Not tainted 4.14.158-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
syz-executor862 D28528 15500   7129 0x00000004
Call Trace:
 context_switch kernel/sched/core.c:2808 [inline]
 __schedule+0x7b8/0x1cd0 kernel/sched/core.c:3384
 schedule+0x92/0x1c0 kernel/sched/core.c:3428
 schedule_preempt_disabled+0x13/0x20 kernel/sched/core.c:3486
 __mutex_lock_common kernel/locking/mutex.c:833 [inline]
 __mutex_lock+0x73c/0x1470 kernel/locking/mutex.c:893
 mutex_lock_nested+0x16/0x20 kernel/locking/mutex.c:908
 tty_buffer_lock_exclusive+0x1f/0x30 drivers/tty/tty_buffer.c:60
 paste_selection+0x106/0x3f2 drivers/tty/vt/selection.c:349
 tioclinux+0x10e/0x400 drivers/tty/vt/vt.c:2696
 vt_ioctl+0x180c/0x2170 drivers/tty/vt/vt_ioctl.c:364
 tty_ioctl+0x841/0x1320 drivers/tty/tty_io.c:2661
 vfs_ioctl fs/ioctl.c:46 [inline]
 file_ioctl fs/ioctl.c:500 [inline]
 do_vfs_ioctl+0x7ae/0x1060 fs/ioctl.c:684
 SYSC_ioctl fs/ioctl.c:701 [inline]
 SyS_ioctl+0x8f/0xc0 fs/ioctl.c:692
 do_syscall_64+0x1e8/0x640 arch/x86/entry/common.c:292
 entry_SYSCALL_64_after_hwframe+0x42/0xb7
RIP: 0033:0x441319
RSP: 002b:00007ffce96f8578 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
RAX: ffffffffffffffda RBX: 0000000000000000 RCX: 0000000000441319
RDX: 0000000020000040 RSI: 000000000000541c RDI: 0000000000000004
RBP: 00000000000a7f03 R08: 000000000000000d R09: 00000000004002c8
R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000402090
R13: 0000000000402120 R14: 0000000000000000 R15: 0000000000000000
INFO: task syz-executor862:15501 blocked for more than 140 seconds.
      Not tainted 4.14.158-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
syz-executor862 D28528 15501   7132 0x00000004
Call Trace:
 context_switch kernel/sched/core.c:2808 [inline]
 __schedule+0x7b8/0x1cd0 kernel/sched/core.c:3384
 schedule+0x92/0x1c0 kernel/sched/core.c:3428
 schedule_preempt_disabled+0x13/0x20 kernel/sched/core.c:3486
 __mutex_lock_common kernel/locking/mutex.c:833 [inline]
 __mutex_lock+0x73c/0x1470 kernel/locking/mutex.c:893
 mutex_lock_nested+0x16/0x20 kernel/locking/mutex.c:908
 tty_buffer_lock_exclusive+0x1f/0x30 drivers/tty/tty_buffer.c:60
 paste_selection+0x106/0x3f2 drivers/tty/vt/selection.c:349
 tioclinux+0x10e/0x400 drivers/tty/vt/vt.c:2696
 vt_ioctl+0x180c/0x2170 drivers/tty/vt/vt_ioctl.c:364
 tty_ioctl+0x841/0x1320 drivers/tty/tty_io.c:2661
 vfs_ioctl fs/ioctl.c:46 [inline]
 file_ioctl fs/ioctl.c:500 [inline]
 do_vfs_ioctl+0x7ae/0x1060 fs/ioctl.c:684
 SYSC_ioctl fs/ioctl.c:701 [inline]
 SyS_ioctl+0x8f/0xc0 fs/ioctl.c:692
 do_syscall_64+0x1e8/0x640 arch/x86/entry/common.c:292
 entry_SYSCALL_64_after_hwframe+0x42/0xb7
RIP: 0033:0x441319
RSP: 002b:00007ffce96f8578 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
RAX: ffffffffffffffda RBX: 0000000000000000 RCX: 0000000000441319
RDX: 0000000020000040 RSI: 000000000000541c RDI: 0000000000000004
RBP: 00000000000a7f0b R08: 000000000000000d R09: 00000000004002c8
R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000402090
R13: 0000000000402120 R14: 0000000000000000 R15: 0000000000000000

Showing all locks held in the system:
1 lock held by khungtaskd/1045:
 #0:  (tasklist_lock){.+.+}, at: [<ffffffff8148c8a8>] debug_show_all_locks+0x7f/0x21f kernel/locking/lockdep.c:4544
1 lock held by rsyslogd/6979:
 #0:  (&f->f_pos_lock){+.+.}, at: [<ffffffff81966a1b>] __fdget_pos+0xab/0xd0 fs/file.c:769
2 locks held by getty/7103:
 #0:  (&tty->ldisc_sem){++++}, at: [<ffffffff866549c3>] ldsem_down_read+0x33/0x40 drivers/tty/tty_ldsem.c:376
 #1:  (&ldata->atomic_read_lock){+.+.}, at: [<ffffffff83490d76>] n_tty_read+0x1e6/0x17b0 drivers/tty/n_tty.c:2156
2 locks held by getty/7104:
 #0:  (&tty->ldisc_sem){++++}, at: [<ffffffff866549c3>] ldsem_down_read+0x33/0x40 drivers/tty/tty_ldsem.c:376
 #1:  (&ldata->atomic_read_lock){+.+.}, at: [<ffffffff83490d76>] n_tty_read+0x1e6/0x17b0 drivers/tty/n_tty.c:2156
2 locks held by getty/7105:
 #0:  (&tty->ldisc_sem){++++}, at: [<ffffffff866549c3>] ldsem_down_read+0x33/0x40 drivers/tty/tty_ldsem.c:376
 #1:  (&ldata->atomic_read_lock){+.+.}, at: [<ffffffff83490d76>] n_tty_read+0x1e6/0x17b0 drivers/tty/n_tty.c:2156
2 locks held by getty/7106:
 #0:  (&tty->ldisc_sem){++++}, at: [<ffffffff866549c3>] ldsem_down_read+0x33/0x40 drivers/tty/tty_ldsem.c:376
 #1:  (&ldata->atomic_read_lock){+.+.}, at: [<ffffffff83490d76>] n_tty_read+0x1e6/0x17b0 drivers/tty/n_tty.c:2156
2 locks held by getty/7107:
 #0:  (&tty->ldisc_sem){++++}, at: [<ffffffff866549c3>] ldsem_down_read+0x33/0x40 drivers/tty/tty_ldsem.c:376
 #1:  (&ldata->atomic_read_lock){+.+.}, at: [<ffffffff83490d76>] n_tty_read+0x1e6/0x17b0 drivers/tty/n_tty.c:2156
2 locks held by getty/7108:
 #0:  (&tty->ldisc_sem){++++}, at: [<ffffffff866549c3>] ldsem_down_read+0x33/0x40 drivers/tty/tty_ldsem.c:376
 #1:  (&ldata->atomic_read_lock){+.+.}, at: [<ffffffff83490d76>] n_tty_read+0x1e6/0x17b0 drivers/tty/n_tty.c:2156
2 locks held by syz-executor862/15496:
 #0:  (&tty->ldisc_sem){++++}, at: [<ffffffff866549c3>] ldsem_down_read+0x33/0x40 drivers/tty/tty_ldsem.c:376
 #1:  (&buf->lock){+.+.}, at: [<ffffffff8349f39f>] tty_buffer_lock_exclusive+0x1f/0x30 drivers/tty/tty_buffer.c:60
2 locks held by syz-executor862/15497:
 #0:  (&tty->ldisc_sem){++++}, at: [<ffffffff866549c3>] ldsem_down_read+0x33/0x40 drivers/tty/tty_ldsem.c:376
 #1:  (&buf->lock){+.+.}, at: [<ffffffff8349f39f>] tty_buffer_lock_exclusive+0x1f/0x30 drivers/tty/tty_buffer.c:60
2 locks held by syz-executor862/15498:
 #0:  (&tty->ldisc_sem){++++}, at: [<ffffffff866549c3>] ldsem_down_read+0x33/0x40 drivers/tty/tty_ldsem.c:376
 #1:  (&buf->lock){+.+.}, at: [<ffffffff8349f39f>] tty_buffer_lock_exclusive+0x1f/0x30 drivers/tty/tty_buffer.c:60
2 locks held by syz-executor862/15499:
 #0:  (&tty->ldisc_sem){++++}, at: [<ffffffff866549c3>] ldsem_down_read+0x33/0x40 drivers/tty/tty_ldsem.c:376
 #1:  (&buf->lock){+.+.}, at: [<ffffffff8349f39f>] tty_buffer_lock_exclusive+0x1f/0x30 drivers/tty/tty_buffer.c:60
2 locks held by syz-executor862/15500:
 #0:  (&tty->ldisc_sem){++++}, at: [<ffffffff866549c3>] ldsem_down_read+0x33/0x40 drivers/tty/tty_ldsem.c:376
 #1:  (&buf->lock){+.+.}, at: [<ffffffff8349f39f>] tty_buffer_lock_exclusive+0x1f/0x30 drivers/tty/tty_buffer.c:60
2 locks held by syz-executor862/15501:
 #0:  (&tty->ldisc_sem){++++}, at: [<ffffffff866549c3>] ldsem_down_read+0x33/0x40 drivers/tty/tty_ldsem.c:376
 #1:  (&buf->lock){+.+.}, at: [<ffffffff8349f39f>] tty_buffer_lock_exclusive+0x1f/0x30 drivers/tty/tty_buffer.c:60

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

NMI backtrace for cpu 0
CPU: 0 PID: 1045 Comm: khungtaskd Not tainted 4.14.158-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+0x142/0x197 lib/dump_stack.c:58
 nmi_cpu_backtrace.cold+0x57/0x94 lib/nmi_backtrace.c:101
 nmi_trigger_cpumask_backtrace+0x141/0x189 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:140 [inline]
 check_hung_uninterruptible_tasks kernel/hung_task.c:195 [inline]
 watchdog+0x5e7/0xb90 kernel/hung_task.c:274
 kthread+0x319/0x430 kernel/kthread.c:232
 ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:404
Sending NMI from CPU 0 to CPUs 1:
NMI backtrace for cpu 1
CPU: 1 PID: 15499 Comm: syz-executor862 Not tainted 4.14.158-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
task: ffff888093c62600 task.stack: ffff888097c98000
RIP: 0010:rcu_dynticks_curr_cpu_in_eqs kernel/rcu/tree.c:360 [inline]
RIP: 0010:rcu_is_watching+0x10/0xb0 kernel/rcu/tree.c:1130
RSP: 0018:ffff888097c9f760 EFLAGS: 00000082
RAX: 0000000000000001 RBX: ffffffff88337c00 RCX: 0000000000000002
RDX: 0000000000000000 RSI: ffff8880aed2b558 RDI: ffff888093c62e7c
RBP: ffff888097c9f770 R08: 000000c91a25ed84 R09: 0000000000000001
R10: 0000000000000001 R11: 0000000000000001 R12: ffff8880aed2b5e0
R13: ffff888093c62600 R14: ffff888093c626d0 R15: 00000000000009d0
FS:  00000000019ee880(0000) GS:ffff8880aed00000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 00007f7107eeb000 CR3: 00000000967e6000 CR4: 00000000001406e0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Call Trace:
 rcu_read_lock_sched_held+0x8e/0x130 kernel/rcu/update.c:111
 trace_sched_stat_runtime include/trace/events/sched.h:428 [inline]
 update_curr+0x53c/0x6a0 kernel/sched/fair.c:855
 pick_next_task_fair+0x661/0x1430 kernel/sched/fair.c:6295
 pick_next_task kernel/sched/core.c:3232 [inline]
 __schedule+0x43e/0x1cd0 kernel/sched/core.c:3357
 schedule+0x92/0x1c0 kernel/sched/core.c:3428
 paste_selection+0x293/0x3f2 drivers/tty/vt/selection.c:355
 tioclinux+0x10e/0x400 drivers/tty/vt/vt.c:2696
 vt_ioctl+0x180c/0x2170 drivers/tty/vt/vt_ioctl.c:364
 tty_ioctl+0x841/0x1320 drivers/tty/tty_io.c:2661
 vfs_ioctl fs/ioctl.c:46 [inline]
 file_ioctl fs/ioctl.c:500 [inline]
 do_vfs_ioctl+0x7ae/0x1060 fs/ioctl.c:684
 SYSC_ioctl fs/ioctl.c:701 [inline]
 SyS_ioctl+0x8f/0xc0 fs/ioctl.c:692
 do_syscall_64+0x1e8/0x640 arch/x86/entry/common.c:292
 entry_SYSCALL_64_after_hwframe+0x42/0xb7
RIP: 0033:0x441319
RSP: 002b:00007ffce96f8578 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
RAX: ffffffffffffffda RBX: 0000000000000000 RCX: 0000000000441319
RDX: 0000000020000040 RSI: 000000000000541c RDI: 0000000000000004
RBP: 00000000000a7f00 R08: 000000000000000d R09: 00000000004002c8
R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000402090
R13: 0000000000402120 R14: 0000000000000000 R15: 0000000000000000
Code: 48 83 c4 08 5b 5d c3 48 89 45 f0 e8 db e0 39 00 48 8b 45 f0 eb cb 0f 1f 44 00 00 55 48 89 e5 53 48 83 ec 08 65 ff 05 e0 f1 b3 7e <e8> bb f5 bc 01 48 c7 c3 40 39 02 00 48 ba 00 00 00 00 00 fc ff 

Crashes (8):
Manager Time Kernel Commit Syzkaller Config Log Report Syz repro C repro VM info Title
ci2-linux-4-14 2019/12/12 10:41 linux-4.14.y a844dc4c5442 d973f528 .config log report syz C
ci2-linux-4-14 2020/02/25 15:03 linux-4.14.y 98db2bf27b9e 4c886d6a .config log report
ci2-linux-4-14 2020/02/04 09:07 linux-4.14.y 9fa690a2a016 93e5e335 .config log report
ci2-linux-4-14 2020/02/02 22:15 linux-4.14.y 9fa690a2a016 93e5e335 .config log report
ci2-linux-4-14 2020/01/22 00:49 linux-4.14.y c1141b3aab36 8eda0b95 .config log report
ci2-linux-4-14 2019/12/20 19:44 linux-4.14.y bfb9e5c03076 34011c05 .config log report
ci2-linux-4-14 2019/12/18 19:50 linux-4.14.y bfb9e5c03076 79b211f7 .config log report
ci2-linux-4-14 2019/12/13 16:13 linux-4.14.y a844dc4c5442 2a752b7c .config log report