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: 379d, last: 5d23h

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	458d	458d	0/22	auto-closed as invalid on 2020/06/25 13:28
android-49	INFO: task hung in blkdev_put (2)		3	622d	641d	0/3	auto-closed as invalid on 2020/03/14 12:22
linux-4.19	INFO: task hung in blkdev_put	C	14	11d	370d	0/1	upstream: reported C repro on 2020/07/23 21:33
upstream	INFO: task hung in blkdev_put		320	900d	1326d	0/22	closed as dup on 2018/11/11 08:29
linux-4.14	INFO: task hung in blkdev_put		2	684d	833d	0/1	auto-closed as invalid on 2020/01/12 01:56
linux-4.14	INFO: task hung in blkdev_put (3)	C	11	16d	332d	0/1	upstream: reported C repro on 2020/08/30 21:52
android-49	INFO: task hung in blkdev_put		220	820d	837d	0/3	auto-closed as invalid on 2019/10/25 08:47
linux-4.14	INFO: task hung in blkdev_put (2)		2	487d	526d	0/1	auto-closed as invalid on 2020/07/26 14:38
android-414	INFO: task hung in blkdev_put		119	606d	838d	0/1	auto-closed as invalid on 2020/03/30 04:06
android-44	INFO: task hung in blkdev_put		26	906d	837d	0/2	auto-closed as invalid on 2019/08/03 02:42
android-44	INFO: task hung in blkdev_put (2)		3	617d	694d	0/2	auto-closed as invalid on 2020/03/18 19:27
upstream	INFO: task hung in blkdev_put (2)		2	613d	659d	0/22	auto-closed as invalid on 2020/02/22 04:07
upstream	INFO: task can't die in blkdev_put		3	251d	289d	0/22	auto-closed as invalid on 2021/01/19 09:44

Sample crash report:

INFO: task syz-executor201:8425 blocked for more than 143 seconds.
      Not tainted 5.13.0-rc7-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:syz-executor201 state:D stack:25264 pid: 8425 ppid:  8424 flags:0x00004006
Call Trace:
 context_switch kernel/sched/core.c:4339 [inline]
 __schedule+0xb98/0x1120 kernel/sched/core.c:5147
 schedule+0x14b/0x200 kernel/sched/core.c:5226
 schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:5285
 __mutex_lock_common+0x118f/0x3100 kernel/locking/mutex.c:1036
 __mutex_lock kernel/locking/mutex.c:1104 [inline]
 mutex_lock_nested+0x1a/0x20 kernel/locking/mutex.c:1119
 blkdev_put+0x5c/0x440 fs/block_dev.c:1595
 blkdev_close+0x7a/0xa0 fs/block_dev.c:1644
 __fput+0x352/0x7b0 fs/file_table.c:280
 task_work_run+0x146/0x1c0 kernel/task_work.c:164
 exit_task_work include/linux/task_work.h:32 [inline]
 do_exit+0x736/0x23d0 kernel/exit.c:826
 do_group_exit+0x168/0x2d0 kernel/exit.c:923
 get_signal+0x1770/0x2180 kernel/signal.c:2850
 arch_do_signal_or_restart+0x8e/0x6c0 arch/x86/kernel/signal.c:789
 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+0x191/0x220 kernel/entry/common.c:209
 __syscall_exit_to_user_mode_work kernel/entry/common.c:291 [inline]
 syscall_exit_to_user_mode+0x26/0x70 kernel/entry/common.c:302
 do_syscall_64+0x4b/0xb0 arch/x86/entry/common.c:57
 entry_SYSCALL_64_after_hwframe+0x44/0xae
RIP: 0033:0x444569
RSP: 002b:00007fff5f5d1528 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
RAX: fffffffffffffe00 RBX: 00000000004004a0 RCX: 0000000000444569
RDX: 0000000000000000 RSI: 000000000000ab03 RDI: 0000000000000007
RBP: 0000000000000000 R08: 002364626e2f7665 R09: 00007fff5f5d16c8
R10: 000000000000000f R11: 0000000000000246 R12: 00000000004035f0
R13: 431bde82d7b634db R14: 00000000004b2018 R15: 00000000004004a0
INFO: task systemd-udevd:8429 blocked for more than 143 seconds.
      Not tainted 5.13.0-rc7-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:systemd-udevd   state:D stack:23184 pid: 8429 ppid:  4850 flags:0x00004004
Call Trace:
 context_switch kernel/sched/core.c:4339 [inline]
 __schedule+0xb98/0x1120 kernel/sched/core.c:5147
 schedule+0x14b/0x200 kernel/sched/core.c:5226
 io_schedule+0x83/0x100 kernel/sched/core.c:7214
 wait_on_page_bit_common+0x97a/0x1030 mm/filemap.c:1301
 wait_on_page_bit mm/filemap.c:1362 [inline]
 wait_on_page_locked include/linux/pagemap.h:688 [inline]
 wait_on_page_read+0x19d/0x430 mm/filemap.c:3312
 do_read_cache_page+0xb1b/0xe10 mm/filemap.c:3355
 read_mapping_page include/linux/pagemap.h:515 [inline]
 read_part_sector+0x11f/0x310 block/partitions/core.c:672
 adfspart_check_ICS+0xa7/0x6d0 block/partitions/acorn.c:360
 check_partition block/partitions/core.c:148 [inline]
 blk_add_partitions+0x420/0x11c0 block/partitions/core.c:609
 bdev_disk_changed+0x47e/0x5b0 fs/block_dev.c:1274
 __blkdev_get+0x4e6/0xa50 fs/block_dev.c:1358
 blkdev_get_by_dev+0xf9/0x640 fs/block_dev.c:1451
 blkdev_open+0x132/0x2c0 fs/block_dev.c:1546
 do_dentry_open+0x7cb/0x1010 fs/open.c:826
 do_open fs/namei.c:3361 [inline]
 path_openat+0x28e6/0x39b0 fs/namei.c:3494
 do_filp_open+0x221/0x460 fs/namei.c:3521
 do_sys_openat2+0x124/0x460 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+0x221/0x270 fs/open.c:1207
 do_syscall_64+0x3f/0xb0 arch/x86/entry/common.c:47
 entry_SYSCALL_64_after_hwframe+0x44/0xae
RIP: 0033:0x7f08383a7840
RSP: 002b:00007ffcf4458658 EFLAGS: 00000246 ORIG_RAX: 0000000000000002
RAX: ffffffffffffffda RBX: 0000558c7ac05810 RCX: 00007f08383a7840
RDX: 0000558c7975bfe3 RSI: 00000000000a0800 RDI: 0000558c7ac0da10
RBP: 00007ffcf44587d0 R08: 0000558c7975b670 R09: 0000000000000010
R10: 0000558c7975bd0c R11: 0000000000000246 R12: 00007ffcf4458720
R13: 0000558c7ac0b680 R14: 0000000000000003 R15: 000000000000000e

Showing all locks held in the system:
1 lock held by khungtaskd/1632:
 #0: ffffffff8cf15d00 (rcu_read_lock){....}-{1:2}, at: rcu_lock_acquire+0x0/0x30 arch/x86/pci/mmconfig_64.c:151
1 lock held by systemd-journal/4844:
1 lock held by in:imklog/8125:
 #0: ffff888020f0a870 (&f->f_pos_lock){+.+.}-{3:3}, at: __fdget_pos+0x24e/0x2f0 fs/file.c:974
1 lock held by syz-executor201/8425:
 #0: ffff8881453c00a0 (&bdev->bd_mutex){+.+.}-{3:3}, at: blkdev_put+0x5c/0x440 fs/block_dev.c:1595
1 lock held by systemd-udevd/8429:
 #0: ffff8881453c00a0 (&bdev->bd_mutex){+.+.}-{3:3}, at: blkdev_get_by_dev+0xee/0x640 fs/block_dev.c:1450

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

NMI backtrace for cpu 0
CPU: 0 PID: 1632 Comm: khungtaskd Not tainted 5.13.0-rc7-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+0x202/0x31e lib/dump_stack.c:120
 nmi_cpu_backtrace+0x16c/0x190 lib/nmi_backtrace.c:105
 nmi_trigger_cpumask_backtrace+0x191/0x2f0 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+0xcfb/0xd40 kernel/hung_task.c:294
 kthread+0x39a/0x3c0 kernel/kthread.c:313
 ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:294
Sending NMI from CPU 0 to CPUs 1:
NMI backtrace for cpu 1
CPU: 1 PID: 4844 Comm: systemd-journal Not tainted 5.13.0-rc7-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
RIP: 0010:lock_is_held_type+0x13d/0x180 kernel/locking/lockdep.c:5562
Code: 00 75 46 41 f7 c4 00 02 00 00 74 01 fb 65 48 8b 04 25 28 00 00 00 48 3b 44 24 08 75 3c 89 d8 48 83 c4 10 5b 41 5c 41 5d 41 5e <41> 5f 5d c3 0f 0b 48 c7 c7 00 96 2e 8a e8 f1 10 00 00 65 c7 05 c6
RSP: 0018:ffffc9000116f648 EFLAGS: 00000286
RAX: 0000000000000000 RBX: 1ffff9200022decc RCX: 0000000080000001
RDX: 0000000000000000 RSI: 0000000000000001 RDI: 0000000000000000
RBP: 0000000000000001 R08: dffffc0000000000 R09: fffffbfff1c70666
R10: fffffbfff1c70666 R11: 0000000000000000 R12: ffffffff818bb6a5
R13: ffffffff816cf510 R14: dffffc0000000000 R15: ffffffff8cf15c60
FS:  00007fcda25cd8c0(0000) GS:ffff8880b9b00000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 00007fcd9f9a9000 CR3: 0000000016bcc000 CR4: 00000000001506e0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Call Trace:
 lock_is_held include/linux/lockdep.h:283 [inline]
 rcu_read_lock_sched_held+0x87/0x110 kernel/rcu/update.c:125
 trace_lock_release+0x61/0x140 include/trace/events/lock.h:58
 lock_release+0x81/0x7b0 kernel/locking/lockdep.c:5525
 rcu_read_unlock include/linux/rcupdate.h:711 [inline]
 is_bpf_text_address+0x253/0x270 kernel/bpf/core.c:706
 kernel_text_address kernel/extable.c:151 [inline]
 __kernel_text_address+0x93/0x100 kernel/extable.c:105
 unwind_get_return_address+0x48/0x80 arch/x86/kernel/unwind_orc.c:318
 arch_stack_walk+0x98/0xe0 arch/x86/kernel/stacktrace.c:26
 stack_trace_save+0x104/0x1e0 kernel/stacktrace.c:121
 kasan_save_stack mm/kasan/common.c:38 [inline]
 kasan_set_track mm/kasan/common.c:46 [inline]
 set_alloc_info mm/kasan/common.c:428 [inline]
 __kasan_slab_alloc+0x96/0xd0 mm/kasan/common.c:461
 kasan_slab_alloc include/linux/kasan.h:236 [inline]
 slab_post_alloc_hook mm/slab.h:524 [inline]
 slab_alloc_node mm/slub.c:2914 [inline]
 slab_alloc mm/slub.c:2922 [inline]
 kmem_cache_alloc+0x1d7/0x340 mm/slub.c:2927
 getname_flags+0xba/0x640 fs/namei.c:138
 do_sys_openat2+0xba/0x460 fs/open.c:1181
 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+0x221/0x270 fs/open.c:1207
 do_syscall_64+0x3f/0xb0 arch/x86/entry/common.c:47
 entry_SYSCALL_64_after_hwframe+0x44/0xae
RIP: 0033:0x7fcda1b5c840
Code: 73 01 c3 48 8b 0d 68 77 20 00 f7 d8 64 89 01 48 83 c8 ff c3 66 0f 1f 44 00 00 83 3d 89 bb 20 00 00 75 10 b8 02 00 00 00 0f 05 <48> 3d 01 f0 ff ff 73 31 c3 48 83 ec 08 e8 1e f6 ff ff 48 89 04 24
RSP: 002b:00007ffe19467998 EFLAGS: 00000246 ORIG_RAX: 0000000000000002
RAX: ffffffffffffffda RBX: 00007ffe19467ca0 RCX: 00007fcda1b5c840
RDX: 00000000000001a0 RSI: 0000000000080042 RDI: 000055c12b001600
RBP: 000000000000000d R08: 000000000000c0ff R09: 00000000ffffffff
R10: 0000000000000069 R11: 0000000000000246 R12: 00000000ffffffff
R13: 000055c12aff4040 R14: 00007ffe19467c60 R15: 000055c12b001420

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	1e2a199f6ccd	1b88c6d5	.config	log	report	syz	C
ci-upstream-kasan-gce-selinux-root	2020/12/20 13:50	upstream	467f8165a2b0	1b88c6d5	.config	log	report	syz	C

Crashes (41):
Manager	Time	Kernel	Commit	Syzkaller	Config	Log	Report	Syz repro	C repro	VM info	Title
ci-upstream-kasan-gce-smack-root	2021/06/25 07:10	upstream	4a09d388f2ab	0edbbe31	.config	log	report	syz	C		INFO: task hung in blkdev_put
ci-upstream-kasan-gce-selinux-root	2021/05/29 06:06	upstream	5ff2756afde0	858ea628	.config	log	report	syz	C		INFO: task hung in blkdev_put
ci-upstream-kasan-gce-root	2021/04/26 04:44	upstream	9f4ad9e425a1	2a82f1b3	.config	log	report	syz	C		INFO: task hung in blkdev_put
ci-upstream-kasan-gce-selinux-root	2021/02/19 12:37	upstream	f40ddce88593	14052202	.config	log	report	syz	C		INFO: task hung in blkdev_put
ci-upstream-kasan-gce-smack-root	2021/02/15 14:00	upstream	f40ddce88593	98682e5e	.config	log	report	syz	C		INFO: task hung in blkdev_put
ci-upstream-kasan-gce-root	2021/02/09 10:07	upstream	e0756cfc7d7c	2bd9619f	.config	log	report	syz	C		INFO: task hung in blkdev_put
ci-upstream-linux-next-kasan-gce-root	2021/07/18 21:02	linux-next	c1a6d08348fc	f115ae98	.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	454c576c3f5e	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	bc085f8fc88f	d4f4eca5	.config	log	report	syz	C		INFO: task hung in blkdev_put
ci-upstream-kasan-gce-selinux-root	2020/09/29 13:03	upstream	fb0155a09b02	1b88c6d5	.config	log	report	syz	C
ci-upstream-linux-next-kasan-gce-root	2020/10/30 23:57	linux-next	4e78c578cb98	a6e3ac3b	.config	log	report	syz	C
ci-upstream-kasan-gce-root	2021/07/17 15:54	upstream	d980cc0620ae	f115ae98	.config	log	report			info	INFO: task hung in blkdev_put
ci-upstream-kasan-gce-selinux-root	2021/07/13 20:52	upstream	40226a3d96ef	fa0594c3	.config	log	report			info	INFO: task hung in blkdev_put
ci-upstream-kasan-gce-smack-root	2021/07/04 02:55	upstream	3dbdb38e2869	55aa55c2	.config	log	report			info	INFO: task hung in blkdev_put
ci-upstream-kasan-gce-smack-root	2021/06/28 18:22	upstream	62fb9874f5da	9d2ab5df	.config	log	report			info	INFO: task hung in blkdev_put
ci-upstream-kasan-gce-smack-root	2021/06/15 02:44	upstream	009c9aa5be65	1ba81399	.config	log	report			info	INFO: task hung in blkdev_put
ci-upstream-kasan-gce-root	2021/06/02 15:04	upstream	231bc5390667	0740de69	.config	log	report			info	INFO: task hung in blkdev_put
ci-upstream-kasan-gce-root	2021/05/31 10:48	upstream	8124c8a6b353	325a8dab	.config	log	report			info	INFO: task hung in blkdev_put
ci-upstream-kasan-gce-root	2021/04/30 07:43	upstream	d2b6f8a17919	77e2b668	.config	log	report			info	INFO: task hung in blkdev_put
ci-upstream-kasan-gce-root	2021/04/20 19:20	upstream	7af08140979a	c0ced557	.config	log	report			info	INFO: task hung in blkdev_put
ci-upstream-kasan-gce-selinux-root	2021/03/22 11:20	upstream	0d02ec6b3136	bea32f74	.config	log	report			info	INFO: task hung in blkdev_put
ci-upstream-kasan-gce-root	2021/03/11 12:29	upstream	a74e6a014c9d	c2ca1f2a	.config	log	report			info	INFO: task hung in blkdev_put
ci-upstream-kasan-gce-root	2021/02/24 02:32	upstream	3b9cdafb5358	fcc6d71b	.config	log	report			info	INFO: task hung in blkdev_put
ci-upstream-kasan-gce-smack-root	2021/02/19 12:57	upstream	f40ddce88593	14052202	.config	log	report			info	INFO: task hung in blkdev_put
ci-upstream-kasan-gce-smack-root	2021/01/21 01:31	upstream	75439bc439e0	d4f4eca5	.config	log	report			info	INFO: task hung in blkdev_put
ci-upstream-kasan-gce-selinux-root	2020/11/20 05:59	upstream	131ad0b6f529	0767f13f	.config	log	report			info
ci-upstream-kasan-gce-selinux-root	2020/11/20 05:59	upstream	131ad0b6f529	0767f13f	.config	log	report			info
ci-upstream-kasan-gce-selinux-root	2020/11/20 05:58	upstream	131ad0b6f529	0767f13f	.config	log	report			info
ci-upstream-kasan-gce-root	2020/11/20 05:58	upstream	3494d58865ad	0767f13f	.config	log	report			info
ci-upstream-kasan-gce-selinux-root	2020/10/10 21:49	upstream	6f2f486d57c4	4a77ae0b	.config	log	report			info
ci-upstream-kasan-gce-root	2020/10/09 10:33	upstream	3d006ee42dde	92390980	.config	log	report			info
ci-upstream-kasan-gce-root	2020/07/19 03:32	upstream	6a70f89cc58f	9c812472	.config	log	report
ci-upstream-kasan-gce-root	2020/07/14 17:36	upstream	0dc589da873b	ce4c95b3	.config	log	report
ci-upstream-linux-next-kasan-gce-root	2021/07/23 13:50	linux-next	90d856e71443	bc5f1d88	.config	log	report			info	INFO: task can't die in blkdev_put
ci-upstream-linux-next-kasan-gce-root	2021/06/06 14:07	linux-next	a1f92694393a	500c2339	.config	log	report			info	INFO: task can't die in blkdev_put
ci-upstream-linux-next-kasan-gce-root	2021/04/01 03:40	linux-next	931294922e65	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	931294922e65	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	931294922e65	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	e3128d2f068e	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	0f4b0bb396f6	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	95065cb54210	0767f13f	.config	log	report			info