BUG: KASAN: use-after-free in xfs_iflush_cluster+0x9d7/0xaf0

From: Andrea Gelmini
Date: Mon Dec 14 2015 - 13:01:00 EST

Hi everybody,
using dev kernel v4.4, I have this:

[40240.371807] ==================================================================
[40240.371826] BUG: KASAN: use-after-free in xfs_iflush_cluster+0x9d7/0xaf0 at addr ffff88001ed15428
[40240.371832] Read of size 4 by task xfsaild/dm-0/332
[40240.371834] =============================================================================
[40240.371839] BUG xfs_ili (Tainted: G B ): kasan: bad access detected
[40240.371842] -----------------------------------------------------------------------------

[40240.371851] INFO: Allocated in kmem_zone_alloc+0x7c/0x180 age=996 cpu=2 pid=11139
[40240.371858] ___slab_alloc.constprop.27+0x379/0x3a0
[40240.371863] __slab_alloc.isra.24.constprop.26+0x26/0x40
[40240.371867] kmem_cache_alloc+0x111/0x150
[40240.371871] kmem_zone_alloc+0x7c/0x180
[40240.371876] xfs_inode_item_init+0x22/0xb0
[40240.371881] xfs_trans_ijoin+0xa4/0x110
[40240.371885] xfs_rename+0x380/0xe70
[40240.371889] xfs_vn_rename+0x2a8/0x5c0
[40240.371893] vfs_rename+0xa64/0x1310
[40240.371899] SyS_renameat2+0x961/0xa70
[40240.371902] SyS_rename+0x19/0x20
[40240.371906] entry_SYSCALL_64_fastpath+0x16/0x75
[40240.371911] INFO: Freed in xfs_inode_item_destroy+0x39/0x50 age=0 cpu=1 pid=40
[40240.371916] __slab_free+0x292/0x3d0
[40240.371919] kmem_cache_free+0x181/0x190
[40240.371923] xfs_inode_item_destroy+0x39/0x50
[40240.371927] xfs_inode_free+0xcd/0x360
[40240.371930] xfs_reclaim_inode+0x542/0x880
[40240.371933] xfs_reclaim_inodes_ag+0x356/0x710
[40240.371936] xfs_reclaim_inodes_nr+0x49/0x60
[40240.371940] xfs_fs_free_cached_objects+0x55/0x80
[40240.371944] super_cache_scan+0x329/0x410
[40240.371949] shrink_slab.part.7+0x2ee/0x510
[40240.371953] shrink_zone+0x7a0/0xae0
[40240.371956] kswapd+0x931/0x1010
[40240.371961] kthread+0x1c0/0x260
[40240.371964] ret_from_fork+0x3f/0x70
[40240.371968] INFO: Slab 0xffffea00007b4500 objects=17 used=14 fp=0xffff88001ed14c78 flags=0x4000000000004080
[40240.371971] INFO: Object 0xffff88001ed15398 @offset=5016 fp=0xffff88001ed151d0

[40240.371977] Bytes b4 ffff88001ed15388: 01 00 00 00 28 00 00 00 67 72 61 02 01 00 00 00 ....(...gra.....
[40240.371982] Object ffff88001ed15398: d0 51 d1 1e 00 88 ff ff 00 02 00 00 00 00 ad de .Q..............
[40240.371986] Object ffff88001ed153a8: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
[40240.371989] Object ffff88001ed153b8: 20 b7 27 c8 00 88 ff ff 00 80 19 35 00 88 ff ff .'........5....
[40240.371993] Object ffff88001ed153c8: 3b 12 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ;...............
[40240.371996] Object ffff88001ed153d8: 30 d8 82 81 ff ff ff ff c0 26 5b 82 ff ff ff ff 0........&[.....
[40240.371999] Object ffff88001ed153e8: e8 53 d1 1e 00 88 ff ff e8 53 d1 1e 00 88 ff ff .S.......S......
[40240.372003] Object ffff88001ed153f8: 00 00 00 00 00 00 00 00 73 0d 01 00 00 00 00 00 ........s.......
[40240.372006] Object ffff88001ed15408: c0 78 76 c8 00 88 ff ff 6b 2a 00 00 82 00 00 00 .xv.....k*......
[40240.372010] Object ffff88001ed15418: 73 0d 01 00 00 00 00 00 00 00 00 00 00 00 00 00 s...............
[40240.372013] Object ffff88001ed15428: 00 00 00 00 00 00 00 00 ........
[40240.372019] CPU: 2 PID: 332 Comm: xfsaild/dm-0 Tainted: G B 4.4.0-rc4KASan-00110-g35bfb6c #13
[40240.372021] Hardware name: LENOVO 2356LRG/2356LRG, BIOS G7ETA3WW (2.63 ) 04/16/2015
[40240.372024] ffff88001ed14000 ffff880384d679e0 ffffffff819c71d7 ffff880386778000
[40240.372029] ffff880384d67a10 ffffffff813e2504 ffff880386778000 ffffea00007b4500
[40240.372034] ffff88001ed15398 ffff8800c87678c0 ffff880384d67a38 ffffffff813e6bcf
[40240.372038] Call Trace:
[40240.372043] [<ffffffff819c71d7>] dump_stack+0x4b/0x74
[40240.372048] [<ffffffff813e2504>] print_trailer+0xf4/0x150
[40240.372052] [<ffffffff813e6bcf>] object_err+0x2f/0x40
[40240.372058] [<ffffffff813e880c>] kasan_report_error+0x21c/0x540
[40240.372063] [<ffffffff819d3900>] ? radix_tree_next_chunk+0x690/0x690
[40240.372068] [<ffffffff813e8bee>] __asan_report_load4_noabort+0x3e/0x40
[40240.372073] [<ffffffff817f2b47>] ? xfs_iflush_cluster+0x9d7/0xaf0
[40240.372077] [<ffffffff817f2b47>] xfs_iflush_cluster+0x9d7/0xaf0
[40240.372081] [<ffffffff817fb87a>] xfs_iflush+0x37a/0x5b0
[40240.372086] [<ffffffff817fb500>] ? xfs_rename+0xe70/0xe70
[40240.372092] [<ffffffff8120bd94>] ? del_timer_sync+0x64/0x80
[40240.372097] [<ffffffff824cada0>] ? schedule_timeout+0x230/0x3a0
[40240.372102] [<ffffffff8182d5ca>] xfs_inode_item_push+0x25a/0x390
[40240.372106] [<ffffffff8182d370>] ? xfs_inode_item_unlock+0x80/0x80
[40240.372111] [<ffffffff818444a3>] ? xfs_trans_ail_cursor_first+0x23/0x1a0
[40240.372115] [<ffffffff81844d1b>] xfsaild+0x6fb/0x12b0
[40240.372119] [<ffffffff81844620>] ? xfs_trans_ail_cursor_first+0x1a0/0x1a0
[40240.372123] [<ffffffff824c3a92>] ? __schedule+0x642/0x19f0
[40240.372128] [<ffffffff81844620>] ? xfs_trans_ail_cursor_first+0x1a0/0x1a0
[40240.372132] [<ffffffff81844620>] ? xfs_trans_ail_cursor_first+0x1a0/0x1a0
[40240.372137] [<ffffffff81154320>] kthread+0x1c0/0x260
[40240.372141] [<ffffffff81154160>] ? kthread_worker_fn+0x560/0x560
[40240.372146] [<ffffffff81154160>] ? kthread_worker_fn+0x560/0x560
[40240.372150] [<ffffffff824ccf8f>] ret_from_fork+0x3f/0x70
[40240.372154] [<ffffffff81154160>] ? kthread_worker_fn+0x560/0x560
[40240.372157] Memory state around the buggy address:
[40240.372161] ffff88001ed15300: fc fc fc fc fc fc fc fc fc fc fc fc fc fc fc fc
[40240.372164] ffff88001ed15380: fc fc fc fb fb fb fb fb fb fb fb fb fb fb fb fb
[40240.372168] >ffff88001ed15400: fb fb fb fb fb fb fc fc fc fc fc fc fc fc fc fc
[40240.372171] ^
[40240.372174] ffff88001ed15480: fc fc fc fc fc fc fc fc fc fc fc fc fc fc fc fc
[40240.372177] ffff88001ed15500: fc fc fc fc fc fc fc fc fc fc fc fc 00 00 00 00
[40240.372180] ==================================================================

Also with more recent commits, I've got it:
[25886.160963] ==================================================================
[25886.160981] BUG: KASAN: use-after-free in xfs_iflush_cluster+0x9d7/0xaf0 at addr ffff880345ab67b0
[25886.160985] Read of size 4 by task xfsaild/dm-0/339
[25886.160987] =============================================================================
[25886.160991] BUG xfs_ili (Tainted: G OE ): kasan: bad access detected
[25886.160993] -----------------------------------------------------------------------------

[25886.160997] Disabling lock debugging due to kernel taint
[25886.161002] INFO: Allocated in kmem_zone_alloc+0x7c/0x180 age=29338 cpu=2 pid=3748
[25886.161008] ___slab_alloc.constprop.27+0x379/0x3a0
[25886.161012] __slab_alloc.isra.24.constprop.26+0x26/0x40
[25886.161015] kmem_cache_alloc+0x111/0x150
[25886.161019] kmem_zone_alloc+0x7c/0x180
[25886.161023] xfs_inode_item_init+0x22/0xb0
[25886.161027] xfs_trans_ijoin+0xa4/0x110
[25886.161031] xfs_ialloc+0xa1d/0x1470
[25886.161034] xfs_dir_ialloc+0x106/0x670
[25886.161038] xfs_create+0x674/0x1070
[25886.161042] xfs_generic_create+0x375/0x500
[25886.161045] xfs_vn_mknod+0xf/0x20
[25886.161048] xfs_vn_create+0xe/0x10
[25886.161053] vfs_create+0x1ff/0x390
[25886.161057] path_openat+0x2d41/0x3e50
[25886.161061] do_filp_open+0x170/0x230
[25886.161065] do_sys_open+0x198/0x350
[25886.161069] INFO: Freed in xfs_inode_item_destroy+0x39/0x50 age=0 cpu=3 pid=14453
[25886.161073] __slab_free+0x292/0x3d0
[25886.161077] kmem_cache_free+0x181/0x190
[25886.161080] xfs_inode_item_destroy+0x39/0x50
[25886.161083] xfs_inode_free+0xcd/0x360
[25886.161086] xfs_reclaim_inode+0x542/0x880
[25886.161089] xfs_reclaim_inodes_ag+0x356/0x710
[25886.161093] xfs_reclaim_inodes_nr+0x49/0x60
[25886.161097] xfs_fs_free_cached_objects+0x55/0x80
[25886.161101] super_cache_scan+0x329/0x410
[25886.161105] shrink_slab.part.7+0x2ee/0x510
[25886.161110] shrink_zone+0x7a0/0xae0
[25886.161113] do_try_to_free_pages+0x3d7/0xfd0
[25886.161117] try_to_free_pages+0x144/0x1d0
[25886.161120] __alloc_pages_nodemask+0x8dd/0x12b0
[25886.161124] do_huge_pmd_anonymous_page+0x240/0xae0
[25886.161129] handle_mm_fault+0x25fc/0x32f0
[25886.161133] INFO: Slab 0xffffea000d16ad80 objects=17 used=10 fp=0xffff880345ab7c80 flags=0x8000000000004080
[25886.161136] INFO: Object 0xffff880345ab6720 @offset=1824 fp=0xffff880345ab7008

[25886.161142] Bytes b4 ffff880345ab6710: 02 00 00 00 15 2b 00 00 74 5e 7a 01 01 00 00 00 .....+..t^z.....
[25886.161146] Object ffff880345ab6720: 08 70 ab 45 03 88 ff ff 00 02 00 00 00 00 ad de .p.E............
[25886.161150] Object ffff880345ab6730: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
[25886.161153] Object ffff880345ab6740: 10 65 e7 85 03 88 ff ff 00 7b ef 85 03 88 ff ff .e.......{......
[25886.161156] Object ffff880345ab6750: 3b 12 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ;...............
[25886.161159] Object ffff880345ab6760: 00 d9 82 81 ff ff ff ff c0 26 5b 82 ff ff ff ff .........&[.....
[25886.161162] Object ffff880345ab6770: 70 67 ab 45 03 88 ff ff 70 67 ab 45 03 88 ff ff pg.E....pg.E....
[25886.161166] Object ffff880345ab6780: 00 00 00 00 00 00 00 00 aa 83 00 00 00 00 00 00 ................
[25886.161170] Object ffff880345ab6790: c0 e3 a5 8b 03 88 ff ff 0f af 07 00 90 00 00 00 ................
[25886.161172] Object ffff880345ab67a0: c9 83 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
[25886.161174] Object ffff880345ab67b0: 00 00 00 00 00 00 00 00 ........
[25886.161178] CPU: 2 PID: 339 Comm: xfsaild/dm-0 Tainted: G B OE 4.4.0-rc4KASan-00274-g7bb2729 #1
[25886.161180] Hardware name: LENOVO 2356LRG/2356LRG, BIOS G7ETA4WW (2.64 ) 10/08/2015
[25886.161182] ffff880345ab6000 ffff880384f579e0 ffffffff819c7397 ffff8803867a4000
[25886.161185] ffff880384f57a10 ffffffff813e2554 ffff8803867a4000 ffffea000d16ad80
[25886.161187] ffff880345ab6720 ffff88038ba5e3c0 ffff880384f57a38 ffffffff813e6c1f
[25886.161190] Call Trace:
[25886.161194] [<ffffffff819c7397>] dump_stack+0x4b/0x74
[25886.161197] [<ffffffff813e2554>] print_trailer+0xf4/0x150
[25886.161200] [<ffffffff813e6c1f>] object_err+0x2f/0x40
[25886.161203] [<ffffffff813e885c>] kasan_report_error+0x21c/0x540
[25886.161207] [<ffffffff811b39f0>] ? abort_exclusive_wait+0x1c0/0x1c0
[25886.161210] [<ffffffff813e8c3e>] __asan_report_load4_noabort+0x3e/0x40
[25886.161213] [<ffffffff817f2c17>] ? xfs_iflush_cluster+0x9d7/0xaf0
[25886.161215] [<ffffffff817f2c17>] xfs_iflush_cluster+0x9d7/0xaf0
[25886.161218] [<ffffffff817fb94a>] xfs_iflush+0x37a/0x5b0
[25886.161221] [<ffffffff817fb5d0>] ? xfs_rename+0xe70/0xe70
[25886.161225] [<ffffffff8120bd94>] ? del_timer_sync+0x64/0x80
[25886.161228] [<ffffffff824caeb0>] ? schedule_timeout+0x230/0x3a0
[25886.161231] [<ffffffff824cac80>] ? usleep_range+0xe0/0xe0
[25886.161234] [<ffffffff8182d69a>] xfs_inode_item_push+0x25a/0x390
[25886.161237] [<ffffffff8182d440>] ? xfs_inode_item_unlock+0x80/0x80
[25886.161239] [<ffffffff81844573>] ? xfs_trans_ail_cursor_first+0x23/0x1a0
[25886.161241] [<ffffffff81844deb>] xfsaild+0x6fb/0x12b0
[25886.161244] [<ffffffff818446f0>] ? xfs_trans_ail_cursor_first+0x1a0/0x1a0
[25886.161246] [<ffffffff824c3ba2>] ? __schedule+0x642/0x19f0
[25886.161248] [<ffffffff818446f0>] ? xfs_trans_ail_cursor_first+0x1a0/0x1a0
[25886.161251] [<ffffffff818446f0>] ? xfs_trans_ail_cursor_first+0x1a0/0x1a0
[25886.161254] [<ffffffff81154320>] kthread+0x1c0/0x260
[25886.161256] [<ffffffff81154160>] ? kthread_worker_fn+0x560/0x560
[25886.161259] [<ffffffff81154160>] ? kthread_worker_fn+0x560/0x560
[25886.161262] [<ffffffff824cd08f>] ret_from_fork+0x3f/0x70
[25886.161265] [<ffffffff81154160>] ? kthread_worker_fn+0x560/0x560
[25886.161267] Memory state around the buggy address:
[25886.161270] ffff880345ab6680: fc fc fc fc fc fc fc fc fc fc fc fc fc fc fc fc
[25886.161273] ffff880345ab6700: fc fc fc fc fb fb fb fb fb fb fb fb fb fb fb fb
[25886.161276] >ffff880345ab6780: fb fb fb fb fb fb fb fc fc fc fc fc fc fc fc fc
[25886.161278] ^
[25886.161281] ffff880345ab6800: fc fc fc fc fc fc fc fc fc fc fc fc fc fc fc fc
[25886.161284] ffff880345ab6880: fc fc fc fc fc fc fc fc fc fc fc fc fc 00 00 00
[25886.161286] ==================================================================

The compiled kernel is a vanilla one, with a few patches pulled from BTRFS.
The XFS filesystem is running on LUKS, on a SSD.

No corruption or problems found at the moment.

Thanks a lot,
Andrea

Attachment: config.txt.gz
Description: application/gzip

Attachment: dmesg.txt.gz
Description: application/gzip

Attachment: hdparm_sda.txt.gz
Description: application/gzip

Attachment: lspci.txt.gz
Description: application/gzip

Attachment: dmidecode.txt.gz
Description: application/gzip

Attachment: signature.asc
Description: Digital signature