INFO: task hung in blkdev

INFO: task hung in blkdev_put (4)
Status: upstream: reported C repro on 2020/10/03 13:09
Reported-by: syzbot+9a29d5e745bd7523c851@syzkaller.appspotmail.com
First crash: 300d, last: 10d

Cause bisection: introduced by (bisect log) :
commit 2da22da573481cc4837e246d0eee4d518b3f715e
Author: Mike Christie <mchristi@redhat.com>
Date: Tue Aug 13 16:39:52 2019 +0000

nbd: fix zero cmd timeout handling v2

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

similar bugs (13):
Kernel	Title	Repro	Count	Last	Reported	Patched	Status
upstream	INFO: task hung in blkdev_put (3)		1	379d	379d	0/22	auto-closed as invalid on 2020/06/25 13:28
android-49	INFO: task hung in blkdev_put (2)		3	542d	561d	0/3	auto-closed as invalid on 2020/03/14 12:22
linux-4.19	INFO: task hung in blkdev_put	C	13	10h47m	290d	0/1	upstream: reported C repro on 2020/07/23 21:33
upstream	INFO: task hung in blkdev_put		320	820d	1247d	0/22	closed as dup on 2018/11/11 08:29
linux-4.14	INFO: task hung in blkdev_put		2	604d	754d	0/1	auto-closed as invalid on 2020/01/12 01:56
linux-4.14	INFO: task hung in blkdev_put (3)	C	10	9d06h	252d	0/1	upstream: reported C repro on 2020/08/30 21:52
android-49	INFO: task hung in blkdev_put		220	740d	757d	0/3	auto-closed as invalid on 2019/10/25 08:47
linux-4.14	INFO: task hung in blkdev_put (2)		2	408d	446d	0/1	auto-closed as invalid on 2020/07/26 14:38
android-414	INFO: task hung in blkdev_put		119	526d	758d	0/1	auto-closed as invalid on 2020/03/30 04:06
android-44	INFO: task hung in blkdev_put		26	826d	757d	0/2	auto-closed as invalid on 2019/08/03 02:42
android-44	INFO: task hung in blkdev_put (2)		3	538d	615d	0/2	auto-closed as invalid on 2020/03/18 19:27
upstream	INFO: task hung in blkdev_put (2)		2	533d	579d	0/22	auto-closed as invalid on 2020/02/22 04:07
upstream	INFO: task can't die in blkdev_put		3	171d	209d	0/22	auto-closed as invalid on 2021/01/19 09:44

Sample crash report:

INFO: task syz-executor039:8406 blocked for more than 143 seconds.
      Not tainted 5.12.0-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:syz-executor039 state:D stack:27536 pid: 8406 ppid:  8404 flags:0x00004002
Call Trace:
 context_switch kernel/sched/core.c:4322 [inline]
 __schedule+0x911/0x21b0 kernel/sched/core.c:5073
 schedule+0xcf/0x270 kernel/sched/core.c:5152
 schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:5211
 __mutex_lock_common kernel/locking/mutex.c:1026 [inline]
 __mutex_lock+0x81f/0x1120 kernel/locking/mutex.c:1096
 blkdev_put+0x59/0x580 fs/block_dev.c:1604
 blkdev_close+0x8c/0xb0 fs/block_dev.c:1653
 __fput+0x288/0x920 fs/file_table.c:280
 task_work_run+0xdd/0x1a0 kernel/task_work.c:140
 exit_task_work include/linux/task_work.h:30 [inline]
 do_exit+0xbfc/0x2a60 kernel/exit.c:825
 do_group_exit+0x125/0x310 kernel/exit.c:922
 get_signal+0x47f/0x2150 kernel/signal.c:2781
 arch_do_signal_or_restart+0x2a8/0x1eb0 arch/x86/kernel/signal.c:789
 handle_signal_work kernel/entry/common.c:147 [inline]
 exit_to_user_mode_loop kernel/entry/common.c:171 [inline]
 exit_to_user_mode_prepare+0x148/0x250 kernel/entry/common.c:208
 __syscall_exit_to_user_mode_work kernel/entry/common.c:290 [inline]
 syscall_exit_to_user_mode+0x19/0x60 kernel/entry/common.c:301
 entry_SYSCALL_64_after_hwframe+0x44/0xae
RIP: 0033:0x44a129
RSP: 002b:00007f9dd3ca6308 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
RAX: fffffffffffffe00 RBX: 00000000004cb4e8 RCX: 000000000044a129
RDX: 00000000ffffffff RSI: 000000000000ab03 RDI: 0000000000000006
RBP: 00000000004cb4e0 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 00000000004cb4ec
R13: 000000000049b08c R14: 64626e2f7665642f R15: 0000000000022000
INFO: task systemd-udevd:8413 blocked for more than 143 seconds.
      Not tainted 5.12.0-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:systemd-udevd   state:D stack:26312 pid: 8413 ppid:  4829 flags:0x00004004
Call Trace:
 context_switch kernel/sched/core.c:4322 [inline]
 __schedule+0x911/0x21b0 kernel/sched/core.c:5073
 schedule+0xcf/0x270 kernel/sched/core.c:5152
 io_schedule+0xba/0x130 kernel/sched/core.c:7209
 wait_on_page_bit_common+0x571/0xe90 mm/filemap.c:1274
 wait_on_page_bit mm/filemap.c:1335 [inline]
 wait_on_page_locked include/linux/pagemap.h:673 [inline]
 wait_on_page_read mm/filemap.c:3234 [inline]
 do_read_cache_page+0x95c/0x1390 mm/filemap.c:3277
 read_mapping_page include/linux/pagemap.h:500 [inline]
 read_part_sector+0x146/0x620 block/partitions/core.c:680
 adfspart_check_ICS+0x9d/0xc90 block/partitions/acorn.c:360
 check_partition block/partitions/core.c:148 [inline]
 blk_add_partitions+0x585/0xe00 block/partitions/core.c:617
 bdev_disk_changed+0x1eb/0x3c0 fs/block_dev.c:1272
 __blkdev_get+0x86c/0xa30 fs/block_dev.c:1354
 blkdev_get_by_dev fs/block_dev.c:1458 [inline]
 blkdev_get_by_dev+0x26c/0x600 fs/block_dev.c:1426
 blkdev_open+0x154/0x2b0 fs/block_dev.c:1555
 do_dentry_open+0x4b9/0x11b0 fs/open.c:826
 do_open fs/namei.c:3367 [inline]
 path_openat+0x1c0e/0x27e0 fs/namei.c:3500
 do_filp_open+0x190/0x3d0 fs/namei.c:3527
 do_sys_openat2+0x16d/0x420 fs/open.c:1187
 do_sys_open fs/open.c:1203 [inline]
 __do_sys_open fs/open.c:1211 [inline]
 __se_sys_open fs/open.c:1207 [inline]
 __x64_sys_open+0x119/0x1c0 fs/open.c:1207
 do_syscall_64+0x2d/0x70 arch/x86/entry/common.c:46
 entry_SYSCALL_64_after_hwframe+0x44/0xae
RIP: 0033:0x7ffb20c55840
RSP: 002b:00007ffffc5f5d68 EFLAGS: 00000246 ORIG_RAX: 0000000000000002
RAX: ffffffffffffffda RBX: 000055d1c329f780 RCX: 00007ffb20c55840
RDX: 000055d1c2d9bfe3 RSI: 00000000000a0800 RDI: 000055d1c3290ea0
RBP: 00007ffffc5f5ee0 R08: 000055d1c2d9b670 R09: 0000000000000010
R10: 00007ffb209cfd70 R11: 0000000000000246 R12: 00007ffffc5f5e30
R13: 000055d1c32a2920 R14: 0000000000000003 R15: 000000000000000e

Showing all locks held in the system:
1 lock held by khungtaskd/1632:
 #0: ffffffff8bf74360 (rcu_read_lock){....}-{1:2}, at: debug_show_all_locks+0x53/0x260 kernel/locking/lockdep.c:6328
1 lock held by in:imklog/8094:
1 lock held by syz-executor039/8406:
 #0: ffff8880198400a0 (&bdev->bd_mutex){+.+.}-{3:3}, at: blkdev_put+0x59/0x580 fs/block_dev.c:1604
1 lock held by systemd-udevd/8413:
 #0: ffff8880198400a0 (&bdev->bd_mutex){+.+.}-{3:3}, at: blkdev_get_by_dev fs/block_dev.c:1457 [inline]
 #0: ffff8880198400a0 (&bdev->bd_mutex){+.+.}-{3:3}, at: blkdev_get_by_dev+0x261/0x600 fs/block_dev.c:1426

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

NMI backtrace for cpu 1
CPU: 1 PID: 1632 Comm: khungtaskd Not tainted 5.12.0-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
Call Trace:
 __dump_stack lib/dump_stack.c:79 [inline]
 dump_stack+0x141/0x1d7 lib/dump_stack.c:120
 nmi_cpu_backtrace.cold+0x44/0xd7 lib/nmi_backtrace.c:105
 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:209 [inline]
 watchdog+0xd48/0xfb0 kernel/hung_task.c:294
 kthread+0x3b1/0x4a0 kernel/kthread.c:292
 ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:294
Sending NMI from CPU 1 to CPUs 0:
NMI backtrace for cpu 0
CPU: 0 PID: 3149 Comm: kworker/0:3 Not tainted 5.12.0-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
Workqueue: events toggle_allocation_gate
RIP: 0010:lockdep_enabled kernel/locking/lockdep.c:87 [inline]
RIP: 0010:lock_is_held_type+0x29/0x140 kernel/locking/lockdep.c:5543
Code: ff 41 57 41 56 41 55 41 bd 01 00 00 00 41 54 55 53 48 83 ec 08 8b 0d d2 1f c2 04 85 c9 0f 84 d7 00 00 00 65 8b 05 b7 bd fe 76 <85> c0 0f 85 c8 00 00 00 65 4c 8b 24 25 00 f0 01 00 41 8b 94 24 ec
RSP: 0018:ffffc9000245f920 EFLAGS: 00000202
RAX: 0000000000000000 RBX: 0000000000000000 RCX: 0000000000000001
RDX: 1ffffffff17ef92e RSI: 00000000ffffffff RDI: ffffffff8bf742a0
RBP: 1ffff9200048bf30 R08: 0000000000000000 R09: ffffffff8dc52b0f
R10: fffffbfff1b8a561 R11: 000000000000003f R12: 0000000000000001
R13: 0000000000000001 R14: 0000000000000902 R15: ffffffff8c0948a0
FS:  0000000000000000(0000) GS:ffff8880b9c00000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 00007f420cb2e000 CR3: 000000000bc8e000 CR4: 0000000000350ef0
Call Trace:
 lock_is_held include/linux/lockdep.h:278 [inline]
 rcu_read_lock_sched_held+0x3a/0x70 kernel/rcu/update.c:125
 trace_lock_release include/trace/events/lock.h:58 [inline]
 lock_release+0x5d3/0x720 kernel/locking/lockdep.c:5522
 __raw_spin_unlock include/linux/spinlock_api_smp.h:150 [inline]
 _raw_spin_unlock+0x12/0x40 kernel/locking/spinlock.c:183
 spin_unlock include/linux/spinlock.h:394 [inline]
 __text_poke+0x5d1/0x8c0 arch/x86/kernel/alternative.c:955
 text_poke_bp_batch+0x3c5/0x550 arch/x86/kernel/alternative.c:1257
 text_poke_flush arch/x86/kernel/alternative.c:1347 [inline]
 text_poke_flush arch/x86/kernel/alternative.c:1344 [inline]
 text_poke_finish+0x16/0x30 arch/x86/kernel/alternative.c:1354
 arch_jump_label_transform_apply+0x13/0x20 arch/x86/kernel/jump_label.c:126
 jump_label_update+0x1da/0x400 kernel/jump_label.c:825
 static_key_disable_cpuslocked+0x152/0x1b0 kernel/jump_label.c:207
 static_key_disable+0x16/0x20 kernel/jump_label.c:215
 toggle_allocation_gate mm/kfence/core.c:626 [inline]
 toggle_allocation_gate+0x23a/0x2e0 mm/kfence/core.c:601
 process_one_work+0x98d/0x1600 kernel/workqueue.c:2275
 worker_thread+0x64c/0x1120 kernel/workqueue.c:2421
 kthread+0x3b1/0x4a0 kernel/kthread.c:292
 ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:294

Fix bisection attempts:
Manager	Time	Kernel	Commit	Syzkaller	Config	Log	Report	Syz repro	C repro	VM info	Title
ci-upstream-kasan-gce-selinux-root	2021/01/19 15:55	upstream	1e2a199f	1b88c6d5	.config	log	report	syz	C
ci-upstream-kasan-gce-selinux-root	2020/12/20 13:50	upstream	467f8165	1b88c6d5	.config	log	report	syz	C

Crashes (29):
Manager	Time	Kernel	Commit	Syzkaller	Config	Log	Report	Syz repro	C repro	VM info	Title
ci-upstream-kasan-gce-root	2021/04/26 04:44	upstream	9f4ad9e4	2a82f1b3	.config	log	report	syz	C		INFO: task hung in blkdev_put
ci-upstream-kasan-gce-selinux-root	2021/02/19 12:37	upstream	f40ddce8	14052202	.config	log	report	syz	C		INFO: task hung in blkdev_put
ci-upstream-kasan-gce-smack-root	2021/02/15 14:00	upstream	f40ddce8	98682e5e	.config	log	report	syz	C		INFO: task hung in blkdev_put
ci-upstream-kasan-gce-root	2021/02/09 10:07	upstream	e0756cfc	2bd9619f	.config	log	report	syz	C		INFO: task hung in blkdev_put
ci-upstream-linux-next-kasan-gce-root	2021/04/02 23:22	linux-next	454c576c	6a81331a	.config	log	report	syz	C		INFO: task hung in blkdev_put
ci-upstream-linux-next-kasan-gce-root	2021/01/21 20:42	linux-next	bc085f8f	d4f4eca5	.config	log	report	syz	C		INFO: task hung in blkdev_put
ci-upstream-kasan-gce-selinux-root	2020/09/29 13:03	upstream	fb0155a0	1b88c6d5	.config	log	report	syz	C
ci-upstream-linux-next-kasan-gce-root	2020/10/30 23:57	linux-next	4e78c578	a6e3ac3b	.config	log	report	syz	C
ci-upstream-kasan-gce-root	2021/04/30 07:43	upstream	d2b6f8a1	77e2b668	.config	log	report			info	INFO: task hung in blkdev_put
ci-upstream-kasan-gce-root	2021/04/20 19:20	upstream	7af08140	c0ced557	.config	log	report			info	INFO: task hung in blkdev_put
ci-upstream-kasan-gce-selinux-root	2021/03/22 11:20	upstream	0d02ec6b	bea32f74	.config	log	report			info	INFO: task hung in blkdev_put
ci-upstream-kasan-gce-root	2021/03/11 12:29	upstream	a74e6a01	c2ca1f2a	.config	log	report			info	INFO: task hung in blkdev_put
ci-upstream-kasan-gce-root	2021/02/24 02:32	upstream	3b9cdafb	fcc6d71b	.config	log	report			info	INFO: task hung in blkdev_put
ci-upstream-kasan-gce-smack-root	2021/02/19 12:57	upstream	f40ddce8	14052202	.config	log	report			info	INFO: task hung in blkdev_put
ci-upstream-kasan-gce-smack-root	2021/01/21 01:31	upstream	75439bc4	d4f4eca5	.config	log	report			info	INFO: task hung in blkdev_put
ci-upstream-kasan-gce-selinux-root	2020/11/20 05:59	upstream	131ad0b6	0767f13f	.config	log	report			info
ci-upstream-kasan-gce-selinux-root	2020/11/20 05:59	upstream	131ad0b6	0767f13f	.config	log	report			info
ci-upstream-kasan-gce-selinux-root	2020/11/20 05:58	upstream	131ad0b6	0767f13f	.config	log	report			info
ci-upstream-kasan-gce-root	2020/11/20 05:58	upstream	3494d588	0767f13f	.config	log	report			info
ci-upstream-kasan-gce-selinux-root	2020/10/10 21:49	upstream	6f2f486d	4a77ae0b	.config	log	report			info
ci-upstream-kasan-gce-root	2020/10/09 10:33	upstream	3d006ee4	92390980	.config	log	report			info
ci-upstream-kasan-gce-root	2020/07/19 03:32	upstream	6a70f89c	9c812472	.config	log	report
ci-upstream-kasan-gce-root	2020/07/14 17:36	upstream	0dc589da	ce4c95b3	.config	log	report
ci-upstream-linux-next-kasan-gce-root	2021/04/01 03:40	linux-next	93129492	6a81331a	.config	log	report			info	INFO: task can't die in blkdev_put
ci-upstream-linux-next-kasan-gce-root	2021/03/29 10:28	linux-next	93129492	a8529b82	.config	log	report			info	INFO: task can't die in blkdev_put
ci-upstream-linux-next-kasan-gce-root	2021/03/27 10:33	linux-next	93129492	a8529b82	.config	log	report			info	INFO: task can't die in blkdev_put
ci-upstream-linux-next-kasan-gce-root	2021/03/22 18:12	linux-next	e3128d2f	8092f30d	.config	log	report			info	INFO: task can't die in blkdev_put
ci-upstream-linux-next-kasan-gce-root	2021/03/17 02:10	linux-next	0f4b0bb3	fdb2bb2c	.config	log	report			info	INFO: task can't die in blkdev_put
ci-upstream-linux-next-kasan-gce-root	2020/11/20 08:20	linux-next	95065cb5	0767f13f	.config	log	report			info