syzbot


INFO: task hung in trace_mm_filemap_add_to_page_cache

Status: auto-closed as invalid on 2020/08/21 13:07
Subsystems: block
[Documentation on labels]
First crash: 1483d, last: 1432d

Sample crash report:
INFO: task systemd-udevd:9012 blocked for more than 143 seconds.
      Not tainted 5.7.0-rc6-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
systemd-udevd   D27456  9012   4120 0x00004100
Call Trace:
 context_switch kernel/sched/core.c:3367 [inline]
 __schedule+0x805/0xc90 kernel/sched/core.c:4083
 schedule+0x188/0x220 kernel/sched/core.c:4158
 io_schedule+0x86/0xf0 kernel/sched/core.c:5801
 wait_on_page_bit_common+0x8c8/0xdc0 mm/filemap.c:1153
 trace_mm_filemap_add_to_page_cache+0x280/0x280 include/trace/events/filemap.h:52
 wait_on_page_bit mm/filemap.c:1202 [inline]
 wait_on_page_locked include/linux/pagemap.h:528 [inline]
 wait_on_page_read+0x191/0x410 mm/filemap.c:2732
 do_read_cache_page+0xa46/0xd00 mm/filemap.c:2775
 read_mapping_page include/linux/pagemap.h:397 [inline]
 read_part_sector+0xd8/0x2d0 block/partitions/core.c:643
 vsnprintf+0x1a12/0x1aa0 lib/vsprintf.c:2665
 adfspart_check_ICS+0x45/0x640 block/partitions/acorn.c:360
 snprintf+0x6f/0x90 lib/vsprintf.c:2726
 vsnprintf+0x1a08/0x1aa0 lib/vsprintf.c:2664
 vsnprintf+0x142/0x1aa0 lib/vsprintf.c:2549
 check_partition block/partitions/core.c:140 [inline]
 blk_add_partitions+0x3ce/0x1240 block/partitions/core.c:571
 bdev_disk_changed+0x446/0x5d0 fs/block_dev.c:1543
 __blkdev_get+0xf0f/0x13d0 fs/block_dev.c:1681
 bd_acquire+0x30d/0x340 fs/block_dev.c:999
 errseq_sample+0x3b/0x60 lib/errseq.c:127
 block_ioctl+0x100/0x100 fs/block_dev.c:2000
 do_dentry_open+0x82e/0x10b0 fs/open.c:797
 do_open fs/namei.c:3229 [inline]
 path_openat+0x2790/0x38b0 fs/namei.c:3346
 do_filp_open+0x191/0x3a0 fs/namei.c:3373
 __raw_spin_unlock include/linux/spinlock_api_smp.h:152 [inline]
 _raw_spin_unlock+0x24/0x40 kernel/locking/spinlock.c:183
 spin_unlock include/linux/spinlock.h:393 [inline]
 __alloc_fd+0x566/0x600 fs/file.c:534
 do_sys_openat2+0x463/0x770 fs/open.c:1148
 do_sys_open fs/open.c:1164 [inline]
 ksys_open include/linux/syscalls.h:1386 [inline]
 __do_sys_open fs/open.c:1170 [inline]
 __se_sys_open fs/open.c:1168 [inline]
 __x64_sys_open+0x1af/0x1e0 fs/open.c:1168
 do_syscall_64+0xf3/0x1b0 arch/x86/entry/common.c:295
 entry_SYSCALL_64_after_hwframe+0x49/0xb3
INFO: task syz-executor.2:9102 blocked for more than 143 seconds.
      Not tainted 5.7.0-rc6-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
syz-executor.2  D28512  9102   7214 0x00004004
Call Trace:
 context_switch kernel/sched/core.c:3367 [inline]
 __schedule+0x805/0xc90 kernel/sched/core.c:4083
 schedule+0x188/0x220 kernel/sched/core.c:4158
 schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:4217
 __mutex_lock_common+0x129f/0x2fc0 kernel/locking/mutex.c:1033
 blkdev_put+0x31/0x3d0 fs/block_dev.c:1938
 __mutex_lock kernel/locking/mutex.c:1103 [inline]
 mutex_lock_nested+0x1a/0x20 kernel/locking/mutex.c:1118
 blkdev_put+0x31/0x3d0 fs/block_dev.c:1938
 blkdev_open+0x2a0/0x2a0 fs/block_dev.c:1878
 blkdev_close+0x7a/0xa0 fs/block_dev.c:1987
 __fput+0x2ed/0x750 fs/file_table.c:280
 task_work_run+0x147/0x1d0 kernel/task_work.c:123
 tracehook_notify_resume include/linux/tracehook.h:188 [inline]
 exit_to_usermode_loop arch/x86/entry/common.c:165 [inline]
 prepare_exit_to_usermode+0x48e/0x600 arch/x86/entry/common.c:196
 syscall_return_slowpath+0xf9/0x420 arch/x86/entry/common.c:278
 entry_SYSCALL_64_after_hwframe+0x49/0xb3

Showing all locks held in the system:
3 locks held by kworker/u4:6/310:
 #0: ffff8880ae837518 (&rq->lock){-.-.}-{2:2}, at: newidle_balance+0x664/0xb20 kernel/sched/fair.c:10512
 #1: ffffffff892e85d0 (rcu_read_lock){....}-{1:2}, at: rcu_lock_acquire+0x0/0x30 net/mptcp/pm_netlink.c:860
 #2: ffff8880ae827458 (&base->lock){..-.}-{2:2}, at: lock_timer_base kernel/time/timer.c:936 [inline]
 #2: ffff8880ae827458 (&base->lock){..-.}-{2:2}, at: __mod_timer+0x1e3/0x15e0 kernel/time/timer.c:1009
1 lock held by khungtaskd/1145:
 #0: ffffffff892e85d0 (rcu_read_lock){....}-{1:2}, at: rcu_lock_acquire+0x0/0x30 net/mptcp/pm_netlink.c:860
1 lock held by in:imklog/6710:
 #0: ffff888091e90370 (&f->f_pos_lock){+.+.}-{3:3}, at: __fdget_pos+0x25d/0x2f0 fs/file.c:826
1 lock held by systemd-udevd/9012:
 #0: ffff88808a64c740 (&bdev->bd_mutex){+.+.}-{3:3}, at: __blkdev_get+0x1de/0x13d0 fs/block_dev.c:1600
1 lock held by syz-executor.2/9102:
 #0: ffff88808a64c740 (&bdev->bd_mutex){+.+.}-{3:3}, at: blkdev_put+0x31/0x3d0 fs/block_dev.c:1938

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

NMI backtrace for cpu 1
CPU: 1 PID: 1145 Comm: khungtaskd Not tainted 5.7.0-rc6-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+0x1e9/0x30e lib/dump_stack.c:118
 nmi_cpu_backtrace+0x9f/0x180 lib/nmi_backtrace.c:101
 arch_trigger_cpumask_backtrace+0x10/0x10 arch/x86/kernel/apic/hw_nmi.c:38
 nmi_trigger_cpumask_backtrace+0x16a/0x280 lib/nmi_backtrace.c:62
 check_hung_uninterruptible_tasks kernel/hung_task.c:205 [inline]
 watchdog+0xd2a/0xd40 kernel/hung_task.c:289
 kthread+0x353/0x380 kernel/kthread.c:268
 hungtask_pm_notify+0x50/0x50 kernel/hung_task.c:265
 kthread_blkcg+0xd0/0xd0 kernel/kthread.c:1247
 ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:351
Sending NMI from CPU 1 to CPUs 0:
NMI backtrace for cpu 0
CPU: 0 PID: 4103 Comm: systemd-journal Not tainted 5.7.0-rc6-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
RIP: 0010:__lock_release kernel/locking/lockdep.c:4628 [inline]
RIP: 0010:lock_release+0x144/0x760 kernel/locking/lockdep.c:4952
Code: f1 51 13 08 00 0f 84 66 02 00 00 48 8d 95 c0 08 00 00 48 89 d0 48 c1 e8 03 48 89 44 24 48 42 8a 04 28 84 c0 0f 85 a8 04 00 00 <8b> 02 85 c0 0f 84 46 01 00 00 48 89 14 24 4c 89 64 24 10 48 89 5c
RSP: 0018:ffffc90000007cb8 EFLAGS: 00000046
RAX: 1ffff11012699100 RBX: 1ffff11012699130 RCX: ffffffff8158cf19
RDX: ffff8880934c8980 RSI: 0000000000000008 RDI: ffffffff896be7e0
RBP: ffff8880934c80c0 R08: dffffc0000000000 R09: fffffbfff12d7cfd
R10: fffffbfff12d7cfd R11: 0000000000000000 R12: 0000000000000082
R13: dffffc0000000000 R14: ffffffff814b8040 R15: ffff8880934c8984
FS:  00007fd30322d8c0(0000) GS:ffff8880ae800000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 00007fd30061b020 CR3: 00000000935be000 CR4: 00000000001406f0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Call Trace:
 <IRQ>
 rcu_lock_release+0x5/0x20 include/linux/rcupdate.h:212
 queue_work_node+0x320/0x320 arch/x86/include/asm/paravirt.h:759
 call_timer_fn+0x91/0x160 kernel/time/timer.c:1405
 queue_work_node+0x320/0x320 arch/x86/include/asm/paravirt.h:759
 expire_timers kernel/time/timer.c:1445 [inline]
 __run_timers+0x7cf/0x970 kernel/time/timer.c:1774
 check_preemption_disabled+0x40/0x240 lib/smp_processor_id.c:16
 debug_smp_processor_id+0x5/0x20 lib/smp_processor_id.c:56
 run_timer_softirq+0x46/0x80 kernel/time/timer.c:1787
 __do_softirq+0x268/0x80c kernel/softirq.c:292
 invoke_softirq kernel/softirq.c:373 [inline]
 irq_exit+0x223/0x230 kernel/softirq.c:413
 invoke_softirq kernel/softirq.c:373 [inline]
 irq_exit+0x223/0x230 kernel/softirq.c:413
 exiting_irq arch/x86/include/asm/apic.h:546 [inline]
 smp_apic_timer_interrupt+0x113/0x280 arch/x86/kernel/apic/apic.c:1140
 apic_timer_interrupt+0xf/0x20 arch/x86/entry/entry_64.S:829
 </IRQ>
RIP: 0010:arch_local_irq_restore arch/x86/include/asm/paravirt.h:759 [inline]
RIP: 0010:lock_acquire+0x1c7/0x480 kernel/locking/lockdep.c:4937
Code: c1 e8 03 80 3c 10 00 74 0c 48 c7 c7 b0 b9 2b 89 e8 9e da 58 00 48 83 3d d6 23 d3 07 00 0f 84 8e 02 00 00 48 8b 7c 24 20 57 9d <0f> 1f 44 00 00 65 48 8b 04 25 28 00 00 00 48 3b 44 24 58 0f 85 70
RSP: 0018:ffffc9000206f890 EFLAGS: 00000282 ORIG_RAX: ffffffffffffff13
RAX: 1ffffffff1257736 RBX: 1ffff11012699130 RCX: ffffffff81597f94
RDX: dffffc0000000000 RSI: 0000000000000008 RDI: 0000000000000282
RBP: 0000000000000000 R08: dffffc0000000000 R09: fffffbfff162a2a0
R10: fffffbfff162a2a0 R11: 0000000000000000 R12: 0000000000000000
R13: 0000000000000000 R14: ffff8880934c8984 R15: ffff888097a040a0
 test_bit include/asm-generic/bitops/instrumented-non-atomic.h:110 [inline]
 hlock_class kernel/locking/lockdep.c:179 [inline]
 lookup_chain_cache_add kernel/locking/lockdep.c:3146 [inline]
 validate_chain+0x94/0x8920 kernel/locking/lockdep.c:3202
 check_preemption_disabled+0x40/0x240 lib/smp_processor_id.c:16
 debug_smp_processor_id+0x5/0x20 lib/smp_processor_id.c:56
 __raw_spin_lock include/linux/spinlock_api_smp.h:142 [inline]
 _raw_spin_lock+0x2a/0x40 kernel/locking/spinlock.c:151
 spin_lock include/linux/spinlock.h:353 [inline]
 fast_dput fs/dcache.c:742 [inline]
 dput+0x323/0x710 fs/dcache.c:846
 spin_lock include/linux/spinlock.h:353 [inline]
 fast_dput fs/dcache.c:742 [inline]
 dput+0x323/0x710 fs/dcache.c:846
 handle_mounts fs/namei.c:1375 [inline]
 step_into+0x769/0x1c70 fs/namei.c:1676
 smack_inode_permission+0x241/0x2b0 security/smack/smack_lsm.c:1188
 walk_component+0x295/0x680 fs/namei.c:1852
 link_path_walk+0x66d/0xba0 fs/namei.c:2165
 path_openat+0x21d/0x38b0 fs/namei.c:3342
 do_filp_open+0x191/0x3a0 fs/namei.c:3373
 __raw_spin_unlock include/linux/spinlock_api_smp.h:152 [inline]
 _raw_spin_unlock+0x24/0x40 kernel/locking/spinlock.c:183
 spin_unlock include/linux/spinlock.h:393 [inline]
 __alloc_fd+0x566/0x600 fs/file.c:534
 do_sys_openat2+0x463/0x770 fs/open.c:1148
 do_sys_open fs/open.c:1164 [inline]
 ksys_open include/linux/syscalls.h:1386 [inline]
 __do_sys_open fs/open.c:1170 [inline]
 __se_sys_open fs/open.c:1168 [inline]
 __x64_sys_open+0x1af/0x1e0 fs/open.c:1168
 do_syscall_64+0xf3/0x1b0 arch/x86/entry/common.c:295
 entry_SYSCALL_64_after_hwframe+0x49/0xb3
RIP: 0033:0x7fd3027bd840
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:00007ffd27b15538 EFLAGS: 00000246 ORIG_RAX: 0000000000000002
RAX: ffffffffffffffda RBX: 00007ffd27b15840 RCX: 00007fd3027bd840
RDX: 00000000000001a0 RSI: 0000000000080042 RDI: 000056494baf8fa0
RBP: 000000000000000d R08: 000000000000ffc0 R09: 00000000ffffffff
R10: 0000000000000069 R11: 0000000000000246 R12: 00000000ffffffff
R13: 000056494baeb040 R14: 00007ffd27b15800 R15: 000056494baf8dc0

Crashes (2):
Time Kernel Commit Syzkaller Config Log Report Syz repro C repro VM info Assets (help?) Manager Title
2020/05/23 13:05 upstream 444565650a5f 9682898d .config console log report ci-upstream-kasan-gce-smack-root
2020/04/02 19:47 upstream 919dce24701f a34e2c33 .config console log report ci-upstream-kasan-gce-smack-root
* Struck through repros no longer work on HEAD.