On Wed, Jun 29, 2022 at 05:46:52PM -0700, Darrick J. Wong wrote: > Hi all, > > I turned on KASAN and my test rig tripped over generic/475. I've not > added Dave's log scalability patchset to my test systems yet, so I know > that's /not/ to blame. I'll take a further look in the morning, but if > this looks familiar to anyone, let me know? > > (Yes, this is djwong-dev, but I don't have any log changes in my > development tree right now...) Aha, I think there's a race between the ioend worker shutting down the log, and log unmount freeing the CIL. Patches soon. --D > --D > > XFS (dm-0): Mounting V5 Filesystem > XFS (dm-0): Starting recovery (logdev: internal) > XFS (dm-0): Ending recovery (logdev: internal) > Buffer I/O error on dev dm-0, logical block 20639616, async page read > Buffer I/O error on dev dm-0, logical block 20639617, async page read > XFS (dm-0): log I/O error -5 > XFS (dm-0): Filesystem has been shut down due to log error (0x2). > XFS (dm-0): Unmounting Filesystem > XFS (dm-0): Please unmount the filesystem and rectify the problem(s). > ================================================================== > BUG: KASAN: use-after-free in do_raw_spin_lock+0x246/0x270 > Read of size 4 at addr ffff888109dd84c4 by task 3:1H/136 > > CPU: 3 PID: 136 Comm: 3:1H Not tainted 5.19.0-rc4-xfsx #rc4 8e53ab5ad0fddeb31cee5e7063ff9c361915a9c4 > Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS 1.15.0-1 04/01/2014 > Workqueue: xfs-log/dm-0 xlog_ioend_work [xfs] > Call Trace: > <TASK> > dump_stack_lvl+0x34/0x44 > print_report.cold+0x2b8/0x661 > ? do_raw_spin_lock+0x246/0x270 > kasan_report+0xab/0x120 > ? do_raw_spin_lock+0x246/0x270 > do_raw_spin_lock+0x246/0x270 > ? rwlock_bug.part.0+0x90/0x90 > xlog_force_shutdown+0xf6/0x370 [xfs 4ad76ae0d6add7e8183a553e624c31e9ed567318] > xlog_ioend_work+0x100/0x190 [xfs 4ad76ae0d6add7e8183a553e624c31e9ed567318] > process_one_work+0x672/0x1040 > worker_thread+0x59b/0xec0 > ? __kthread_parkme+0xc6/0x1f0 > ? process_one_work+0x1040/0x1040 > ? process_one_work+0x1040/0x1040 > kthread+0x29e/0x340 > ? kthread_complete_and_exit+0x20/0x20 > ret_from_fork+0x1f/0x30 > </TASK> > > Allocated by task 154099: > kasan_save_stack+0x1e/0x40 > __kasan_kmalloc+0x81/0xa0 > kmem_alloc+0x8d/0x2e0 [xfs] > xlog_cil_init+0x1f/0x540 [xfs] > xlog_alloc_log+0xd1e/0x1260 [xfs] > xfs_log_mount+0xba/0x640 [xfs] > xfs_mountfs+0xf2b/0x1d00 [xfs] > xfs_fs_fill_super+0x10af/0x1910 [xfs] > get_tree_bdev+0x383/0x670 > vfs_get_tree+0x7d/0x240 > path_mount+0xdb7/0x1890 > __x64_sys_mount+0x1fa/0x270 > do_syscall_64+0x2b/0x80 > entry_SYSCALL_64_after_hwframe+0x46/0xb0 > > Freed by task 154151: > kasan_save_stack+0x1e/0x40 > kasan_set_track+0x21/0x30 > kasan_set_free_info+0x20/0x30 > ____kasan_slab_free+0x110/0x190 > slab_free_freelist_hook+0xab/0x180 > kfree+0xbc/0x310 > xlog_dealloc_log+0x1b/0x2b0 [xfs] > xfs_unmountfs+0x119/0x200 [xfs] > xfs_fs_put_super+0x6e/0x2e0 [xfs] > generic_shutdown_super+0x12b/0x3a0 > kill_block_super+0x95/0xd0 > deactivate_locked_super+0x80/0x130 > cleanup_mnt+0x329/0x4d0 > task_work_run+0xc5/0x160 > exit_to_user_mode_prepare+0xd4/0xe0 > syscall_exit_to_user_mode+0x1d/0x40 > entry_SYSCALL_64_after_hwframe+0x46/0xb0 > > Last potentially related work creation: > kasan_save_stack+0x1e/0x40 > __kasan_record_aux_stack+0x9f/0xb0 > call_rcu+0x6f/0x700 > xfs_destroy_mount_workqueues+0x37/0x150 [xfs] > xfs_fs_put_super+0x201/0x2e0 [xfs] > generic_shutdown_super+0x12b/0x3a0 > kill_block_super+0x95/0xd0 > deactivate_locked_super+0x80/0x130 > cleanup_mnt+0x329/0x4d0 > task_work_run+0xc5/0x160 > exit_to_user_mode_prepare+0xd4/0xe0 > syscall_exit_to_user_mode+0x1d/0x40 > entry_SYSCALL_64_after_hwframe+0x46/0xb0 > > Second to last potentially related work creation: > kasan_save_stack+0x1e/0x40 > __kasan_record_aux_stack+0x9f/0xb0 > call_rcu+0x6f/0x700 > xfs_destroy_mount_workqueues+0x93/0x150 [xfs] > xfs_fs_put_super+0x201/0x2e0 [xfs] > generic_shutdown_super+0x12b/0x3a0 > kill_block_super+0x95/0xd0 > deactivate_locked_super+0x80/0x130 > cleanup_mnt+0x329/0x4d0 > task_work_run+0xc5/0x160 > exit_to_user_mode_prepare+0xd4/0xe0 > syscall_exit_to_user_mode+0x1d/0x40 > entry_SYSCALL_64_after_hwframe+0x46/0xb0 > > The buggy address belongs to the object at ffff888109dd8400 > which belongs to the cache kmalloc-512 of size 512 > The buggy address is located 196 bytes inside of > 512-byte region [ffff888109dd8400, ffff888109dd8600) > > The buggy address belongs to the physical page: > page:ffffea0004277600 refcount:1 mapcount:0 mapping:0000000000000000 index:0x0 pfn:0x109dd8 > head:ffffea0004277600 order:2 compound_mapcount:0 compound_pincount:0 > flags: 0x17ff80000010200(slab|head|node=0|zone=2|lastcpupid=0xfff) > raw: 017ff80000010200 ffffea00043cba00 dead000000000002 ffff888100042c80 > raw: 0000000000000000 0000000000100010 00000001ffffffff 0000000000000000 > page dumped because: kasan: bad access detected > > Memory state around the buggy address: > ffff888109dd8380: fc fc fc fc fc fc fc fc fc fc fc fc fc fc fc fc > ffff888109dd8400: fa fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb > >ffff888109dd8480: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb > ^ > ffff888109dd8500: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb > ffff888109dd8580: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb > ================================================================== > Disabling lock debugging due to kernel taint
