syzbot


INFO: task can't die in blkdev_put

Status: auto-closed as invalid on 2021/01/19 09:44
Subsystems: ext4
[Documentation on labels]
Reported-by: syzbot+8c02745ed3190be1fe0f@syzkaller.appspotmail.com
First crash: 1285d, last: 1243d
Similar bugs (1)
Kernel Title Repro Cause bisect Fix bisect Count Last Reported Patched Status
upstream INFO: task hung in blkdev_put (4) block C done 486 34d 1291d 0/26 upstream: reported C repro on 2020/10/03 13:09

Sample crash report:
INFO: task syz-executor.3:10725 can't die for more than 143 seconds.
task:syz-executor.3  state:D stack:26816 pid:10725 ppid:  8499 flags:0x00004004
Call Trace:
 context_switch kernel/sched/core.c:4269 [inline]
 __schedule+0x890/0x2030 kernel/sched/core.c:5019
 schedule+0xcf/0x270 kernel/sched/core.c:5098
 schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:5157
 __mutex_lock_common kernel/locking/mutex.c:1033 [inline]
 __mutex_lock+0x81a/0x1110 kernel/locking/mutex.c:1103
 blkdev_put+0x30/0x520 fs/block_dev.c:1795
 blkdev_close+0x8c/0xb0 fs/block_dev.c:1844
 __fput+0x283/0x920 fs/file_table.c:280
 task_work_run+0xdd/0x190 kernel/task_work.c:140
 tracehook_notify_resume include/linux/tracehook.h:188 [inline]
 exit_to_user_mode_loop kernel/entry/common.c:172 [inline]
 exit_to_user_mode_prepare+0x1f0/0x200 kernel/entry/common.c:199
 syscall_exit_to_user_mode+0x38/0x260 kernel/entry/common.c:274
 entry_SYSCALL_64_after_hwframe+0x44/0xa9
RIP: 0033:0x45deb9
Code: Unable to access opcode bytes at RIP 0x45de8f.
RSP: 002b:00007f40ea27fc78 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
RAX: 0000000000000000 RBX: 0000000000012f00 RCX: 000000000045deb9
RDX: 0000000000000000 RSI: 000000000000ab03 RDI: 0000000000000003
RBP: 000000000118bf58 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 000000000118bf2c
R13: 00007fffcb2c237f R14: 00007f40ea2809c0 R15: 000000000118bf2c
INFO: task syz-executor.3:10725 blocked for more than 143 seconds.
      Not tainted 5.10.0-rc4-next-20201120-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:syz-executor.3  state:D stack:26816 pid:10725 ppid:  8499 flags:0x00004004
Call Trace:
 context_switch kernel/sched/core.c:4269 [inline]
 __schedule+0x890/0x2030 kernel/sched/core.c:5019
 schedule+0xcf/0x270 kernel/sched/core.c:5098
 schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:5157
 __mutex_lock_common kernel/locking/mutex.c:1033 [inline]
 __mutex_lock+0x81a/0x1110 kernel/locking/mutex.c:1103
 blkdev_put+0x30/0x520 fs/block_dev.c:1795
 blkdev_close+0x8c/0xb0 fs/block_dev.c:1844
 __fput+0x283/0x920 fs/file_table.c:280
 task_work_run+0xdd/0x190 kernel/task_work.c:140
 tracehook_notify_resume include/linux/tracehook.h:188 [inline]
 exit_to_user_mode_loop kernel/entry/common.c:172 [inline]
 exit_to_user_mode_prepare+0x1f0/0x200 kernel/entry/common.c:199
 syscall_exit_to_user_mode+0x38/0x260 kernel/entry/common.c:274
 entry_SYSCALL_64_after_hwframe+0x44/0xa9
RIP: 0033:0x45deb9
Code: Unable to access opcode bytes at RIP 0x45de8f.
RSP: 002b:00007f40ea27fc78 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
RAX: 0000000000000000 RBX: 0000000000012f00 RCX: 000000000045deb9
RDX: 0000000000000000 RSI: 000000000000ab03 RDI: 0000000000000003
RBP: 000000000118bf58 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 000000000118bf2c
R13: 00007fffcb2c237f R14: 00007f40ea2809c0 R15: 000000000118bf2c
INFO: task syz-executor.3:10746 can't die for more than 143 seconds.
task:syz-executor.3  state:D stack:28536 pid:10746 ppid:  8499 flags:0x00000004
Call Trace:
 context_switch kernel/sched/core.c:4269 [inline]
 __schedule+0x890/0x2030 kernel/sched/core.c:5019
 schedule+0xcf/0x270 kernel/sched/core.c:5098
 schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:5157
 __mutex_lock_common kernel/locking/mutex.c:1033 [inline]
 __mutex_lock+0x81a/0x1110 kernel/locking/mutex.c:1103
 __blkdev_get+0x457/0x1870 fs/block_dev.c:1472
 blkdev_get+0xd1/0x240 fs/block_dev.c:1627
 blkdev_open+0x21d/0x2b0 fs/block_dev.c:1744
 do_dentry_open+0x4b9/0x11b0 fs/open.c:817
 do_open fs/namei.c:3252 [inline]
 path_openat+0x1b9a/0x2730 fs/namei.c:3369
 do_filp_open+0x17e/0x3c0 fs/namei.c:3396
 do_sys_openat2+0x16d/0x420 fs/open.c:1168
 do_sys_open fs/open.c:1184 [inline]
 __do_sys_open fs/open.c:1192 [inline]
 __se_sys_open fs/open.c:1188 [inline]
 __x64_sys_open+0x119/0x1c0 fs/open.c:1188
 do_syscall_64+0x2d/0x70 arch/x86/entry/common.c:46
 entry_SYSCALL_64_after_hwframe+0x44/0xa9
RIP: 0033:0x4179b1
Code: Unable to access opcode bytes at RIP 0x417987.
RSP: 002b:00007f40ea25e820 EFLAGS: 00000293 ORIG_RAX: 0000000000000002
RAX: ffffffffffffffda RBX: 6666666666666667 RCX: 00000000004179b1
RDX: 0000000000000000 RSI: 0000000000000000 RDI: 00007f40ea25e850
RBP: 000000000118c008 R08: 000000000000000f R09: 0000000000000000
R10: 00007f40ea25f9d0 R11: 0000000000000293 R12: 000000000118bfd4
R13: 00007fffcb2c237f R14: 00007f40ea25f9c0 R15: 000000000118bfd4
INFO: task syz-executor.3:10746 blocked for more than 144 seconds.
      Not tainted 5.10.0-rc4-next-20201120-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:syz-executor.3  state:D stack:28536 pid:10746 ppid:  8499 flags:0x00000004
Call Trace:
 context_switch kernel/sched/core.c:4269 [inline]
 __schedule+0x890/0x2030 kernel/sched/core.c:5019
 schedule+0xcf/0x270 kernel/sched/core.c:5098
 schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:5157
 __mutex_lock_common kernel/locking/mutex.c:1033 [inline]
 __mutex_lock+0x81a/0x1110 kernel/locking/mutex.c:1103
 __blkdev_get+0x457/0x1870 fs/block_dev.c:1472
 blkdev_get+0xd1/0x240 fs/block_dev.c:1627
 blkdev_open+0x21d/0x2b0 fs/block_dev.c:1744
 do_dentry_open+0x4b9/0x11b0 fs/open.c:817
 do_open fs/namei.c:3252 [inline]
 path_openat+0x1b9a/0x2730 fs/namei.c:3369
 do_filp_open+0x17e/0x3c0 fs/namei.c:3396
 do_sys_openat2+0x16d/0x420 fs/open.c:1168
 do_sys_open fs/open.c:1184 [inline]
 __do_sys_open fs/open.c:1192 [inline]
 __se_sys_open fs/open.c:1188 [inline]
 __x64_sys_open+0x119/0x1c0 fs/open.c:1188
 do_syscall_64+0x2d/0x70 arch/x86/entry/common.c:46
 entry_SYSCALL_64_after_hwframe+0x44/0xa9
RIP: 0033:0x4179b1
Code: Unable to access opcode bytes at RIP 0x417987.
RSP: 002b:00007f40ea25e820 EFLAGS: 00000293 ORIG_RAX: 0000000000000002
RAX: ffffffffffffffda RBX: 6666666666666667 RCX: 00000000004179b1
RDX: 0000000000000000 RSI: 0000000000000000 RDI: 00007f40ea25e850
RBP: 000000000118c008 R08: 000000000000000f R09: 0000000000000000
R10: 00007f40ea25f9d0 R11: 0000000000000293 R12: 000000000118bfd4
R13: 00007fffcb2c237f R14: 00007f40ea25f9c0 R15: 000000000118bfd4
INFO: task systemd-udevd:10743 blocked for more than 144 seconds.
      Not tainted 5.10.0-rc4-next-20201120-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:systemd-udevd   state:D stack:26488 pid:10743 ppid:  4901 flags:0x00004100
Call Trace:
 context_switch kernel/sched/core.c:4269 [inline]
 __schedule+0x890/0x2030 kernel/sched/core.c:5019
 schedule+0xcf/0x270 kernel/sched/core.c:5098
 io_schedule+0xb5/0x120 kernel/sched/core.c:6792
 wait_on_page_bit_common+0x424/0xeb0 mm/filemap.c:1273
 wait_on_page_bit mm/filemap.c:1334 [inline]
 wait_on_page_locked include/linux/pagemap.h:670 [inline]
 wait_on_page_read mm/filemap.c:3148 [inline]
 do_read_cache_page+0x957/0x1390 mm/filemap.c:3191
 read_mapping_page include/linux/pagemap.h:496 [inline]
 read_part_sector+0xf6/0x5b0 block/partitions/core.c:780
 adfspart_check_ICS+0x9d/0xc90 block/partitions/acorn.c:360
 check_partition block/partitions/core.c:140 [inline]
 blk_add_partitions+0x456/0xe40 block/partitions/core.c:708
 bdev_disk_changed+0x288/0x580 fs/block_dev.c:1410
 __blkdev_get+0xee4/0x1870 fs/block_dev.c:1539
 blkdev_get+0xd1/0x240 fs/block_dev.c:1627
 blkdev_open+0x21d/0x2b0 fs/block_dev.c:1744
 do_dentry_open+0x4b9/0x11b0 fs/open.c:817
 do_open fs/namei.c:3252 [inline]
 path_openat+0x1b9a/0x2730 fs/namei.c:3369
 do_filp_open+0x17e/0x3c0 fs/namei.c:3396
 do_sys_openat2+0x16d/0x420 fs/open.c:1168
 do_sys_open fs/open.c:1184 [inline]
 __do_sys_open fs/open.c:1192 [inline]
 __se_sys_open fs/open.c:1188 [inline]
 __x64_sys_open+0x119/0x1c0 fs/open.c:1188
 do_syscall_64+0x2d/0x70 arch/x86/entry/common.c:46
 entry_SYSCALL_64_after_hwframe+0x44/0xa9
RIP: 0033:0x7fc97c554840
Code: Unable to access opcode bytes at RIP 0x7fc97c554816.
RSP: 002b:00007ffe2612a0a8 EFLAGS: 00000246 ORIG_RAX: 0000000000000002
RAX: ffffffffffffffda RBX: 000055d3a57240c0 RCX: 00007fc97c554840
RDX: 000055d3a4a69fe3 RSI: 00000000000a0800 RDI: 000055d3a5714670
RBP: 00007ffe2612a220 R08: 000055d3a4a69670 R09: 0000000000000010
R10: 000055d3a4a69d0c R11: 0000000000000246 R12: 00007ffe2612a170
R13: 000055d3a5714690 R14: 0000000000000003 R15: 000000000000000e

Showing all locks held in the system:
1 lock held by ksoftirqd/0/10:
 #0: ffff8880b9e34f98 (&rq->lock){-.-.}-{2:2}, at: rq_lock kernel/sched/sched.h:1318 [inline]
 #0: ffff8880b9e34f98 (&rq->lock){-.-.}-{2:2}, at: __schedule+0x217/0x2030 kernel/sched/core.c:4936
1 lock held by khungtaskd/1657:
 #0: ffffffff8b339ca0 (rcu_read_lock){....}-{1:2}, at: debug_show_all_locks+0x53/0x260 kernel/locking/lockdep.c:6252
1 lock held by in:imklog/8190:
 #0: ffff88801ddd2870 (&f->f_pos_lock){+.+.}-{3:3}, at: __fdget_pos+0xe9/0x100 fs/file.c:932
1 lock held by syz-executor.3/10725:
 #0: ffff88814801db80 (&bdev->bd_mutex){+.+.}-{3:3}, at: blkdev_put+0x30/0x520 fs/block_dev.c:1795
1 lock held by syz-executor.3/10746:
 #0: ffff88814801db80 (&bdev->bd_mutex){+.+.}-{3:3}, at: __blkdev_get+0x457/0x1870 fs/block_dev.c:1472
1 lock held by systemd-udevd/10743:
 #0: ffff88814801db80 (&bdev->bd_mutex){+.+.}-{3:3}, at: __blkdev_get+0x457/0x1870 fs/block_dev.c:1472

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

NMI backtrace for cpu 1
CPU: 1 PID: 1657 Comm: khungtaskd Not tainted 5.10.0-rc4-next-20201120-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+0x107/0x163 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:147 [inline]
 check_hung_uninterruptible_tasks kernel/hung_task.c:253 [inline]
 watchdog+0xd89/0xf30 kernel/hung_task.c:338
 kthread+0x3af/0x4a0 kernel/kthread.c:292
 ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:296
Sending NMI from CPU 1 to CPUs 0:
NMI backtrace for cpu 0
CPU: 0 PID: 8191 Comm: rs:main Q:Reg Not tainted 5.10.0-rc4-next-20201120-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
RIP: 0010:__lock_acquire+0x231/0x5c00 kernel/locking/lockdep.c:4764
Code: 7c 24 18 00 0f 85 b6 0c 00 00 48 8b 44 24 30 0f b7 4c 24 08 4e 8d 24 10 49 8d 44 24 20 66 81 e1 ff 1f 48 89 c2 48 89 44 24 28 <48> b8 00 00 00 00 00 fc ff df 48 c1 ea 03 0f b6 14 02 84 d2 74 09
RSP: 0018:ffffc90003a7f368 EFLAGS: 00000002
RAX: ffff8880208a5940 RBX: 0000000000000000 RCX: 000000000000002c
RDX: ffff8880208a5940 RSI: 1ffff11004114b23 RDI: ffff8880208a5918
RBP: ffff8880208a4f80 R08: 0000000000000001 R09: 0000000000000000
R10: 0000000000000078 R11: 0000000000000000 R12: ffff8880208a5920
R13: 0000000000000000 R14: ffffffff8b339ca0 R15: 0000000000000002
FS:  00007f2cdbf30700(0000) GS:ffff8880b9e00000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 00007f5526c73000 CR3: 000000002554d000 CR4: 00000000001506f0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Call Trace:
 lock_acquire kernel/locking/lockdep.c:5435 [inline]
 lock_acquire+0x2a3/0x8c0 kernel/locking/lockdep.c:5400
 rcu_lock_acquire include/linux/rcupdate.h:255 [inline]
 rcu_read_lock include/linux/rcupdate.h:644 [inline]
 ext4_get_group_desc+0x11c/0x4e0 fs/ext4/balloc.c:284
 __ext4_get_inode_loc+0x1b3/0x1130 fs/ext4/inode.c:4309
 ext4_get_inode_loc+0xf3/0x1b0 fs/ext4/inode.c:4448
 ext4_reserve_inode_write+0xc6/0x230 fs/ext4/inode.c:5731
 __ext4_mark_inode_dirty+0x178/0x8a0 fs/ext4/inode.c:5898
 ext4_dirty_inode+0xf3/0x130 fs/ext4/inode.c:5942
 __mark_inode_dirty+0x888/0x1190 fs/fs-writeback.c:2260
 mark_inode_dirty include/linux/fs.h:2182 [inline]
 generic_write_end+0x316/0x4f0 fs/buffer.c:2239
 ext4_da_write_end+0x20f/0xb20 fs/ext4/inode.c:3102
 generic_perform_write+0x2c0/0x4f0 mm/filemap.c:3507
 ext4_buffered_write_iter+0x244/0x4d0 fs/ext4/file.c:270
 ext4_file_write_iter+0x422/0x1400 fs/ext4/file.c:664
 call_write_iter include/linux/fs.h:1902 [inline]
 new_sync_write+0x426/0x650 fs/read_write.c:518
 vfs_write+0x791/0xa30 fs/read_write.c:605
 ksys_write+0x12d/0x250 fs/read_write.c:658
 do_syscall_64+0x2d/0x70 arch/x86/entry/common.c:46
 entry_SYSCALL_64_after_hwframe+0x44/0xa9
RIP: 0033:0x7f2cde9741cd
Code: c2 20 00 00 75 10 b8 01 00 00 00 0f 05 48 3d 01 f0 ff ff 73 31 c3 48 83 ec 08 e8 ae fc ff ff 48 89 04 24 b8 01 00 00 00 0f 05 <48> 8b 3c 24 48 89 c2 e8 f7 fc ff ff 48 89 d0 48 83 c4 08 48 3d 01
RSP: 002b:00007f2cdbf2f590 EFLAGS: 00000293 ORIG_RAX: 0000000000000001
RAX: ffffffffffffffda RBX: 00007f2cd0029710 RCX: 00007f2cde9741cd
RDX: 0000000000000451 RSI: 00007f2cd0029710 RDI: 0000000000000009
RBP: 0000000000000000 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000293 R12: 00007f2cd0029490
R13: 00007f2cdbf2f5b0 R14: 000055d298a737c0 R15: 0000000000000451

Crashes (3):
Time Kernel Commit Syzkaller Config Log Report Syz repro C repro VM info Assets (help?) Manager Title
2020/11/20 09:44 linux-next 95065cb54210 0767f13f .config console log report info ci-upstream-linux-next-kasan-gce-root
2020/10/23 10:47 linux-next 9695c4ff2645 4e740c00 .config console log report info ci-upstream-linux-next-kasan-gce-root
2020/10/09 10:48 linux-next e4fb79c771fb 92390980 .config console log report info ci-upstream-linux-next-kasan-gce-root
* Struck through repros no longer work on HEAD.