INFO: task hung in do_read_cache_page

Status: fixed on 2021/01/13 11:08
Reported-by: syzbot+12c04f947c76f780d488@syzkaller.appspotmail.com
Fix commit: 8d1ddb5e7937 fcntl: Fix potential deadlock in send_sig{io, urg}()
First crash: 2128d, last: 2067d
Fix bisection: fixed by (bisect log) :
commit 8e63266b0d42a2dc233cfc468636889b5b3ba1cf
Author: Boqun Feng <boqun.feng@gmail.com>
Date: Thu Nov 5 06:23:51 2020 +0000

  fcntl: Fix potential deadlock in send_sig{io, urg}()

  
▶ ▼ Similar bugs (7)
Kernel Title Rank 🛈 Repro Cause bisect Fix bisect Count Last Reported Patched Status
linux-4.19 INFO: task hung in do_read_cache_page (2) 1 syz, C error 26 1292d 2010d 0/1 upstream: reported C repro on 2021/02/09 08:22
upstream INFO: task hung in do_read_cache_page block 1 10 2956d 3059d 0/29 auto-closed as invalid on 2019/02/22 10:09
linux-4.14 INFO: task hung in do_read_cache_page 1 2 1488d 1524d 0/1 auto-obsoleted due to no activity on 2022/11/13 17:53
linux-5.15 INFO: task hung in do_read_cache_page origin:upstream 1 syz, C error 9 1136d 1214d 0/3 upstream: reported C repro on 2023/04/16 18:09
upstream INFO: task hung in do_read_cache_page (3) fs mm 1 syz, C done inconclusive 88 1491d 2389d 0/29 upstream: reported C repro on 2020/01/27 06:32
android-49 INFO: task hung in do_read_cache_page 1 1 3000d 3000d 0/3 auto-closed as invalid on 2019/02/22 13:59
upstream INFO: task hung in do_read_cache_page (2) block 1 1 2526d 2526d 0/29 auto-closed as invalid on 2019/11/11 08:43
▶ ▼ Fix bisection attempts (3)
Created Duration User Patch Repo Result
2021/01/12 21:04 3h49m bisect fix linux-4.19.y OK (1) job log
2020/12/13 20:32 31m bisect fix linux-4.19.y OK (0) job log log
2020/11/13 16:41 33m bisect fix linux-4.19.y OK (0) job log log

Sample crash report:
 nbd0: unable to read partition table
ldm_validate_partition_table(): Disk read failed.
Dev nbd0: unable to read RDB block 0
 nbd0: unable to read partition table
block nbd0: shutting down sockets
INFO: task systemd-udevd:8130 blocked for more than 140 seconds.
      Not tainted 4.19.157-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
systemd-udevd   D26224  8130   4699 0x00000100
Call Trace:
 context_switch kernel/sched/core.c:2828 [inline]
 __schedule+0x887/0x2040 kernel/sched/core.c:3517
 schedule+0x8d/0x1b0 kernel/sched/core.c:3561
 io_schedule+0xb5/0x120 kernel/sched/core.c:5185
 wait_on_page_bit_common mm/filemap.c:1123 [inline]
 wait_on_page_bit+0x2c5/0x3f0 mm/filemap.c:1156
 wait_on_page_locked include/linux/pagemap.h:530 [inline]
 wait_on_page_read mm/filemap.c:2795 [inline]
 do_read_cache_page+0x8ed/0x1170 mm/filemap.c:2834
 read_mapping_page include/linux/pagemap.h:402 [inline]
 read_dev_sector+0xbf/0x500 block/partition-generic.c:671
 read_part_sector block/partitions/check.h:38 [inline]
 adfspart_check_ICS+0x114/0xe70 block/partitions/acorn.c:366
 check_partition+0x390/0x68e block/partitions/check.c:167
 rescan_partitions+0x1b5/0x970 block/partition-generic.c:535
 bdev_disk_changed+0x179/0x1b0 fs/block_dev.c:1435
 __blkdev_get+0x1282/0x1480 fs/block_dev.c:1561
 blkdev_get+0xb0/0x940 fs/block_dev.c:1627
 blkdev_open+0x202/0x290 fs/block_dev.c:1788
 do_dentry_open+0x4aa/0x1160 fs/open.c:796
 do_last fs/namei.c:3421 [inline]
 path_openat+0x793/0x2df0 fs/namei.c:3537
 do_filp_open+0x18c/0x3f0 fs/namei.c:3567
 do_sys_open+0x3b3/0x520 fs/open.c:1085
 do_syscall_64+0xf9/0x620 arch/x86/entry/common.c:293
 entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x7f1022416840
Code: Bad RIP value.
RSP: 002b:00007ffc647be578 EFLAGS: 00000246 ORIG_RAX: 0000000000000002
RAX: ffffffffffffffda RBX: 000055c7f6f22430 RCX: 00007f1022416840
RDX: 000055c7f551dfe3 RSI: 0000000000080000 RDI: 000055c7f6f11400
RBP: 0000000000000001 R08: 000055c7f551d670 R09: 0000000000000110
R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000000
R13: 0000000000000000 R14: 000055c7f6f11240 R15: 00000000ffffffff
INFO: task syz-executor054:8134 blocked for more than 140 seconds.
      Not tainted 4.19.157-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
syz-executor054 D27664  8134   8126 0x80000006
Call Trace:
 context_switch kernel/sched/core.c:2828 [inline]
 __schedule+0x887/0x2040 kernel/sched/core.c:3517
 schedule+0x8d/0x1b0 kernel/sched/core.c:3561
 schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:3619
 __mutex_lock_common kernel/locking/mutex.c:1002 [inline]
 __mutex_lock+0x647/0x1260 kernel/locking/mutex.c:1072
 blkdev_put+0x30/0x520 fs/block_dev.c:1839
 blkdev_close+0x86/0xb0 fs/block_dev.c:1888
 __fput+0x2ce/0x890 fs/file_table.c:278
 task_work_run+0x148/0x1c0 kernel/task_work.c:113
 exit_task_work include/linux/task_work.h:22 [inline]
 do_exit+0xbb2/0x2b70 kernel/exit.c:887
 do_group_exit+0x125/0x310 kernel/exit.c:990
 get_signal+0x3f2/0x1f70 kernel/signal.c:2589
 do_signal+0x8f/0x1670 arch/x86/kernel/signal.c:821
 exit_to_usermode_loop+0x204/0x2a0 arch/x86/entry/common.c:163
 prepare_exit_to_usermode arch/x86/entry/common.c:198 [inline]
 syscall_return_slowpath arch/x86/entry/common.c:271 [inline]
 do_syscall_64+0x538/0x620 arch/x86/entry/common.c:296
 entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x445039
Code: Bad RIP value.
RSP: 002b:00007ffd7d6bb898 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
RAX: fffffffffffffe00 RBX: 0000000000000000 RCX: 0000000000445039
RDX: 0000000000000000 RSI: 000000000000ab03 RDI: 0000000000000006
RBP: 000000000008aab5 R08: 00000000004002e0 R09: 00000000004002e0
R10: 000000000000000f R11: 0000000000000246 R12: 0000000000402200
R13: 0000000000402290 R14: 0000000000000000 R15: 0000000000000000

Showing all locks held in the system:
1 lock held by khungtaskd/1564:
 #0: 00000000719f7878 (rcu_read_lock){....}, at: debug_show_all_locks+0x53/0x265 kernel/locking/lockdep.c:4440
2 locks held by in:imklog/8005:
 #0: 00000000fd2e1896 (&f->f_pos_lock){+.+.}, at: __fdget_pos+0x26f/0x310 fs/file.c:767
 #1: 00000000d03ffc2c (&rq->lock){-.-.}, at: rq_lock kernel/sched/sched.h:1830 [inline]
 #1: 00000000d03ffc2c (&rq->lock){-.-.}, at: __schedule+0x1f9/0x2040 kernel/sched/core.c:3455
1 lock held by systemd-udevd/8130:
 #0: 0000000094477ea0 (&bdev->bd_mutex){+.+.}, at: __blkdev_get+0x1d0/0x1480 fs/block_dev.c:1478
1 lock held by syz-executor054/8134:
 #0: 0000000094477ea0 (&bdev->bd_mutex){+.+.}, at: blkdev_put+0x30/0x520 fs/block_dev.c:1839

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

NMI backtrace for cpu 1
CPU: 1 PID: 1564 Comm: khungtaskd Not tainted 4.19.157-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
Call Trace:
 __dump_stack lib/dump_stack.c:77 [inline]
 dump_stack+0x1fc/0x2fe lib/dump_stack.c:118
 nmi_cpu_backtrace.cold+0x63/0xa2 lib/nmi_backtrace.c:101
 nmi_trigger_cpumask_backtrace+0x1a6/0x1eb lib/nmi_backtrace.c:62
 trigger_all_cpu_backtrace include/linux/nmi.h:146 [inline]
 check_hung_uninterruptible_tasks kernel/hung_task.c:203 [inline]
 watchdog+0x991/0xe60 kernel/hung_task.c:287
 kthread+0x33f/0x460 kernel/kthread.c:259
 ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:415
Sending NMI from CPU 1 to CPUs 0:
NMI backtrace for cpu 0
CPU: 0 PID: 4694 Comm: systemd-journal Not tainted 4.19.157-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
RIP: 0033:0x7fc44a58b160
Code: 68 26 00 00 00 e9 80 fd ff ff ff 25 92 f8 1d 00 68 27 00 00 00 e9 70 fd ff ff ff 25 8a f8 1d 00 68 28 00 00 00 e9 60 fd ff ff <ff> 25 82 f8 1d 00 68 29 00 00 00 e9 50 fd ff ff ff 25 7a f8 1d 00
RSP: 002b:00007ffd6bd8e4d8 EFLAGS: 00000293
RAX: 00007fc44a9846c0 RBX: 00007ffd6bd8e7e0 RCX: fffffffffffffe00
RDX: 00000000000001a0 RSI: 0000000000080042 RDI: 000055b239f45a40
RBP: 000000000000000d R08: 000000000000c0c1 R09: 00000000ffffffff
R10: 0000000000000069 R11: 0000000000000246 R12: 00000000ffffffff
R13: 00000000fffffffe R14: 00007ffd6bd8e7a0 R15: 000055b239f45a40
FS:  00007fc44a9848c0 GS:  0000000000000000

Crashes (2):
Time Kernel Commit Syzkaller Config Log Report Syz repro C repro VM info Assets (help?) Manager Title
2020/11/13 20:26 linux-4.19.y 31acccdc8774 4a7fa9b4 .config console log report syz C ci2-linux-4-19
2020/10/14 16:40 linux-4.19.y a1b977b49b66 fc7735a2 .config console log report syz C ci2-linux-4-19
* Struck through repros no longer work on HEAD.