INFO: task can't die in nbd

INFO: task can't die in nbd_ioctl
Status: upstream: reported C repro on 2020/10/05 07:20
Reported-by: syzbot+69a90a5e8f6b59086b2a@syzkaller.appspotmail.com
First crash: 379d, last: 6d19h

Cause bisection: introduced by (bisect log) :
commit e9e006f5fcf2bab59149cb38a48a4817c1b538b4
Author: Mike Christie <mchristi@redhat.com>
Date: Sun Aug 4 19:10:06 2019 +0000

nbd: fix max number of supported devs

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

similar bugs (3):
Kernel	Title	Repro	Cause bisect	Fix bisect	Count	Last	Reported	Patched	Status
linux-4.19	INFO: task hung in nbd_ioctl	C			56	17d	734d	0/1	upstream: reported C repro on 2019/10/12 13:11
upstream	INFO: task hung in nbd_ioctl (3)	C	done	unreliable	11	34d	382d	0/22	upstream: reported C repro on 2020/09/28 07:17
linux-4.14	INFO: task hung in nbd_ioctl (3)	C			7	2d23h	336d	0/1	upstream: reported C repro on 2020/11/13 07:37

Patch testing requests:
Created	Duration	User	Patch	Repo	Result
2020/11/13 12:10	21m	dvyukov@google.com		git://git.kernel.org/pub/scm/linux/kernel/git/next/linux-next-history.git 4e78c578	report log

Sample crash report:

INFO: task syz-executor308:6544 can't die for more than 143 seconds.
task:syz-executor308 state:D stack:26784 pid: 6544 ppid:  6543 flags:0x00004004
Call Trace:
 <TASK>
 context_switch kernel/sched/core.c:4953 [inline]
 __schedule+0x940/0x26f0 kernel/sched/core.c:6234
 schedule+0xd2/0x260 kernel/sched/core.c:6307
 schedule_timeout+0x1db/0x2a0 kernel/time/timer.c:1857
 do_wait_for_common kernel/sched/completion.c:85 [inline]
 __wait_for_common kernel/sched/completion.c:106 [inline]
 wait_for_common kernel/sched/completion.c:117 [inline]
 wait_for_completion+0x174/0x270 kernel/sched/completion.c:138
 flush_workqueue+0x3ed/0x15b0 kernel/workqueue.c:2869
 nbd_start_device_ioctl drivers/block/nbd.c:1364 [inline]
 __nbd_ioctl drivers/block/nbd.c:1427 [inline]
 nbd_ioctl+0x6d8/0xb10 drivers/block/nbd.c:1467
 blkdev_ioctl+0x2a1/0x700 block/ioctl.c:589
 block_ioctl+0xfa/0x140 block/fops.c:478
 vfs_ioctl fs/ioctl.c:51 [inline]
 __do_sys_ioctl fs/ioctl.c:874 [inline]
 __se_sys_ioctl fs/ioctl.c:860 [inline]
 __x64_sys_ioctl+0x193/0x200 fs/ioctl.c:860
 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:0x7fd8d39a4389
RSP: 002b:00007ffcce3d0ae8 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
RAX: ffffffffffffffda RBX: 0000000000000000 RCX: 00007fd8d39a4389
RDX: 0000000000000000 RSI: 000000000000ab03 RDI: 0000000000000003
RBP: 0000000000000000 R08: 00007ffcce3d0c88 R09: 00007ffcce3d0c88
R10: 00007ffcce3d0c88 R11: 0000000000000246 R12: 00007fd8d39636a0
R13: 431bde82d7b634db R14: 0000000000000000 R15: 0000000000000000
 </TASK>
INFO: task syz-executor308:6544 blocked for more than 143 seconds.
      Not tainted 5.15.0-rc4-next-20211008-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:syz-executor308 state:D stack:26784 pid: 6544 ppid:  6543 flags:0x00004004
Call Trace:
 <TASK>
 context_switch kernel/sched/core.c:4953 [inline]
 __schedule+0x940/0x26f0 kernel/sched/core.c:6234
 schedule+0xd2/0x260 kernel/sched/core.c:6307
 schedule_timeout+0x1db/0x2a0 kernel/time/timer.c:1857
 do_wait_for_common kernel/sched/completion.c:85 [inline]
 __wait_for_common kernel/sched/completion.c:106 [inline]
 wait_for_common kernel/sched/completion.c:117 [inline]
 wait_for_completion+0x174/0x270 kernel/sched/completion.c:138
 flush_workqueue+0x3ed/0x15b0 kernel/workqueue.c:2869
 nbd_start_device_ioctl drivers/block/nbd.c:1364 [inline]
 __nbd_ioctl drivers/block/nbd.c:1427 [inline]
 nbd_ioctl+0x6d8/0xb10 drivers/block/nbd.c:1467
 blkdev_ioctl+0x2a1/0x700 block/ioctl.c:589
 block_ioctl+0xfa/0x140 block/fops.c:478
 vfs_ioctl fs/ioctl.c:51 [inline]
 __do_sys_ioctl fs/ioctl.c:874 [inline]
 __se_sys_ioctl fs/ioctl.c:860 [inline]
 __x64_sys_ioctl+0x193/0x200 fs/ioctl.c:860
 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:0x7fd8d39a4389
RSP: 002b:00007ffcce3d0ae8 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
RAX: ffffffffffffffda RBX: 0000000000000000 RCX: 00007fd8d39a4389
RDX: 0000000000000000 RSI: 000000000000ab03 RDI: 0000000000000003
RBP: 0000000000000000 R08: 00007ffcce3d0c88 R09: 00007ffcce3d0c88
R10: 00007ffcce3d0c88 R11: 0000000000000246 R12: 00007fd8d39636a0
R13: 431bde82d7b634db R14: 0000000000000000 R15: 0000000000000000
 </TASK>

Showing all locks held in the system:
1 lock held by khungtaskd/27:
 #0: ffffffff8bb813a0 (rcu_read_lock){....}-{1:2}, at: debug_show_all_locks+0x53/0x260 kernel/locking/lockdep.c:6458
3 locks held by kworker/u4:2/44:
 #0: ffff8880b9c39a58 (&rq->__lock){-.-.}-{2:2}, at: raw_spin_rq_lock_nested+0x1e/0x30 kernel/sched/core.c:478
 #1: ffff8880b9c279c8 (&per_cpu_ptr(group->pcpu, cpu)->seq){-.-.}-{0:0}, at: psi_task_switch+0x173/0x490 kernel/sched/psi.c:871
 #2: ffff8880b9c28258 (&base->lock){..-.}-{2:2}, at: lock_timer_base+0x5a/0x1f0 kernel/time/timer.c:946
3 locks held by kworker/u5:0/46:
 #0: ffff88807be8b138 ((wq_completion)knbd0-recv){+.+.}-{0:0}, at: arch_atomic64_set arch/x86/include/asm/atomic64_64.h:34 [inline]
 #0: ffff88807be8b138 ((wq_completion)knbd0-recv){+.+.}-{0:0}, at: arch_atomic_long_set include/linux/atomic/atomic-long.h:41 [inline]
 #0: ffff88807be8b138 ((wq_completion)knbd0-recv){+.+.}-{0:0}, at: atomic_long_set include/linux/atomic/atomic-instrumented.h:1198 [inline]
 #0: ffff88807be8b138 ((wq_completion)knbd0-recv){+.+.}-{0:0}, at: set_work_data kernel/workqueue.c:634 [inline]
 #0: ffff88807be8b138 ((wq_completion)knbd0-recv){+.+.}-{0:0}, at: set_work_pool_and_clear_pending kernel/workqueue.c:661 [inline]
 #0: ffff88807be8b138 ((wq_completion)knbd0-recv){+.+.}-{0:0}, at: process_one_work+0x896/0x1690 kernel/workqueue.c:2268
 #1: ffffc9000116fdb0 ((work_completion)(&args->work)){+.+.}-{0:0}, at: process_one_work+0x8ca/0x1690 kernel/workqueue.c:2272
 #2: ffff88801c1a4120 (sk_lock-AF_AX25){+.+.}-{0:0}, at: lock_sock include/net/sock.h:1637 [inline]
 #2: ffff88801c1a4120 (sk_lock-AF_AX25){+.+.}-{0:0}, at: ax25_recvmsg+0xbc/0x850 net/ax25/af_ax25.c:1627

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

NMI backtrace for cpu 1
CPU: 1 PID: 27 Comm: khungtaskd Not tainted 5.15.0-rc4-next-20211008-syzkaller #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:105
 nmi_trigger_cpumask_backtrace+0x1ae/0x220 lib/nmi_backtrace.c:62
 trigger_all_cpu_backtrace include/linux/nmi.h:146 [inline]
 check_hung_uninterruptible_tasks kernel/hung_task.c:254 [inline]
 watchdog+0xcb7/0xed0 kernel/hung_task.c:339
 kthread+0x405/0x4f0 kernel/kthread.c:327
 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: 44 Comm: kworker/u4:2 Not tainted 5.15.0-rc4-next-20211008-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
Workqueue: events_unbound toggle_allocation_gate
RIP: 0010:pv_queued_spin_unlock arch/x86/include/asm/paravirt.h:590 [inline]
RIP: 0010:queued_spin_unlock arch/x86/include/asm/qspinlock.h:56 [inline]
RIP: 0010:do_raw_spin_unlock+0x147/0x230 kernel/locking/spinlock_debug.c:141
Code: c1 ea 03 0f b6 14 02 4c 89 e0 83 e0 07 83 c0 03 38 d0 7c 08 84 d2 0f 85 92 00 00 00 48 c7 c0 20 6e 9f 8b c7 45 08 ff ff ff ff <48> ba 00 00 00 00 00 fc ff df 48 c1 e8 03 80 3c 10 00 0f 85 b7 00
RSP: 0018:ffffc9000114f9d0 EFLAGS: 00000246
RAX: ffffffff8b9f6e20 RBX: 0000000000000007 RCX: ffffffff815c2670
RDX: 0000000000000000 RSI: 0000000000000004 RDI: ffff888010db8120
RBP: ffff888010db8120 R08: 0000000000000000 R09: ffff888010db8123
R10: ffffed10021b7024 R11: 000000000000003f R12: ffff888010db8128
R13: ffff888010db8130 R14: 0000000000000f8a R15: ffffffff8bcac5c0
FS:  0000000000000000(0000) GS:ffff8880b9c00000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 00007f7372c12020 CR3: 000000000b88e000 CR4: 00000000003506f0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Call Trace:
 <TASK>
 __raw_spin_unlock include/linux/spinlock_api_smp.h:151 [inline]
 _raw_spin_unlock+0x1a/0x40 kernel/locking/spinlock.c:186
 spin_unlock include/linux/spinlock.h:408 [inline]
 __text_poke+0x5d4/0x8c0 arch/x86/kernel/alternative.c:876
 text_poke_bp_batch+0x3d7/0x560 arch/x86/kernel/alternative.c:1178
 text_poke_flush arch/x86/kernel/alternative.c:1268 [inline]
 text_poke_flush arch/x86/kernel/alternative.c:1265 [inline]
 text_poke_finish+0x16/0x30 arch/x86/kernel/alternative.c:1275
 arch_jump_label_transform_apply+0x13/0x20 arch/x86/kernel/jump_label.c:146
 jump_label_update+0x1d5/0x430 kernel/jump_label.c:830
 static_key_enable_cpuslocked+0x1b1/0x260 kernel/jump_label.c:177
 static_key_enable+0x16/0x20 kernel/jump_label.c:190
 toggle_allocation_gate mm/kfence/core.c:731 [inline]
 toggle_allocation_gate+0x100/0x390 mm/kfence/core.c:723
 process_one_work+0x9b2/0x1690 kernel/workqueue.c:2297
 worker_thread+0x658/0x11f0 kernel/workqueue.c:2444
 kthread+0x405/0x4f0 kernel/kthread.c:327
 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.161 msecs
----------------
Code disassembly (best guess):
   0:	c1 ea 03             	shr    $0x3,%edx
   3:	0f b6 14 02          	movzbl (%rdx,%rax,1),%edx
   7:	4c 89 e0             	mov    %r12,%rax
   a:	83 e0 07             	and    $0x7,%eax
   d:	83 c0 03             	add    $0x3,%eax
  10:	38 d0                	cmp    %dl,%al
  12:	7c 08                	jl     0x1c
  14:	84 d2                	test   %dl,%dl
  16:	0f 85 92 00 00 00    	jne    0xae
  1c:	48 c7 c0 20 6e 9f 8b 	mov    $0xffffffff8b9f6e20,%rax
  23:	c7 45 08 ff ff ff ff 	movl   $0xffffffff,0x8(%rbp)
* 2a:	48 ba 00 00 00 00 00 	movabs $0xdffffc0000000000,%rdx <-- trapping instruction
  31:	fc ff df
  34:	48 c1 e8 03          	shr    $0x3,%rax
  38:	80 3c 10 00          	cmpb   $0x0,(%rax,%rdx,1)
  3c:	0f                   	.byte 0xf
  3d:	85                   	.byte 0x85
  3e:	b7 00                	mov    $0x0,%bh

Crashes (6):
Manager	Time	Kernel	Commit	Syzkaller	Config	Log	Report	Syz repro	C repro	VM info	Title
ci-upstream-linux-next-kasan-gce-root	2021/10/09 04:53	linux-next	683f29b781ae	efe0f24d	.config	log	report	syz	C		INFO: task can't die in nbd_ioctl
ci-upstream-linux-next-kasan-gce-root	2021/09/01 08:03	linux-next	52c7b727581f	7eb7e152	.config	log	report	syz	C		INFO: task can't die in nbd_ioctl
ci-upstream-linux-next-kasan-gce-root	2020/10/30 19:57	linux-next	4e78c578cb98	a6e3ac3b	.config	log	report	syz	C
ci-upstream-linux-next-kasan-gce-root	2021/09/17 07:17	linux-next	368847b165bb	5b989942	.config	log	report			info	INFO: task can't die in nbd_ioctl
ci-upstream-linux-next-kasan-gce-root	2021/04/12 12:52	linux-next	e99d8a849517	bfeda1b1	.config	log	report			info	INFO: task can't die in nbd_ioctl
ci-upstream-linux-next-kasan-gce-root	2020/10/01 04:26	linux-next	de69ee6df1cf	8516f6d3	.config	log	report			info