2015-12-14 18:00:57

by Andrea Gelmini

[permalink] [raw]
Subject: BUG: KASAN: use-after-free in xfs_iflush_cluster+0x9d7/0xaf0

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


Attachments:
(No filename) (0.00 B)
signature.asc (949.00 B)
Digital signature
Download all attachments

2015-12-14 19:54:39

by Dave Chinner

[permalink] [raw]
Subject: Re: BUG: KASAN: use-after-free in xfs_iflush_cluster+0x9d7/0xaf0

On Mon, Dec 14, 2015 at 07:00:48PM +0100, Andrea Gelmini wrote:
> 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] -----------------------------------------------------------------------------
.....

What line of code does this address correspond to in your kernel?

xfs_iflush_cluster+0x9d7

Cheers,

Dave.
--
Dave Chinner
[email protected]

2015-12-14 20:15:33

by Andrea Gelmini

[permalink] [raw]
Subject: Re: BUG: KASAN: use-after-free in xfs_iflush_cluster+0x9d7/0xaf0

On Tue, Dec 15, 2015 at 06:54:22AM +1100, Dave Chinner wrote:
> What line of code does this address correspond to in your kernel?
>
> xfs_iflush_cluster+0x9d7

gelma@glen:~/dev/kernel/v4.4.x$ git grep -Iin xfs_iflush_cluster
fs/xfs/xfs_inode.c:3179:xfs_iflush_cluster(
fs/xfs/xfs_inode.c:3414: error = xfs_iflush_cluster(ip, bp);


Thanks a lot for your quick answer,
Andrea


Attachments:
(No filename) (377.00 B)
signature.asc (949.00 B)
Digital signature
Download all attachments

2015-12-14 21:22:38

by Dave Chinner

[permalink] [raw]
Subject: Re: BUG: KASAN: use-after-free in xfs_iflush_cluster+0x9d7/0xaf0

On Mon, Dec 14, 2015 at 09:15:26PM +0100, Andrea Gelmini wrote:
> On Tue, Dec 15, 2015 at 06:54:22AM +1100, Dave Chinner wrote:
> > What line of code does this address correspond to in your kernel?
> >
> > xfs_iflush_cluster+0x9d7
>
> gelma@glen:~/dev/kernel/v4.4.x$ git grep -Iin xfs_iflush_cluster
> fs/xfs/xfs_inode.c:3179:xfs_iflush_cluster(
> fs/xfs/xfs_inode.c:3414: error = xfs_iflush_cluster(ip, bp);

If that was what I needed, I wouldn't have needed to ask. :/

I need the translation of the memory address to line number, not the
line number of function call. This requires translation from your
built kernel object file. e.g. on a kernel I just built:

$ gdb vmlinux
....
(gdb) l *(xfs_iflush_cluster+0x9d7)
0xffffffff814df647 is in xfs_bulkstat_one_int (fs/xfs/xfs_itable.c:110).
105 buf->bs_dmevmask = dic->di_dmevmask;
106 buf->bs_dmstate = dic->di_dmstate;
107 buf->bs_aextents = dic->di_anextents;
108 buf->bs_forkoff = XFS_IFORK_BOFF(ip);
109
110 switch (dic->di_format) {
111 case XFS_DINODE_FMT_DEV:
112 buf->bs_rdev = ip->i_df.if_u2.if_rdev;
113 buf->bs_blksize = BLKDEV_IOSIZE;
114 buf->bs_blocks = 0;

That's clearly not code in xfs_iflush_cluster() or any function that
xfs_iflush_cluster() calls. Indeed, xfs_iflush_cluster() is only
0x411 bytes long on that kernel, so there's more than 2x the amount
of code in that function in your instrumented kernel than mine.

Hence I need the address-to-line number translation from your kernel
to tell me what line of code is being tripped over.

Cheers,

Dave.
--
Dave Chinner
[email protected]

2015-12-15 09:11:53

by Andrea Gelmini

[permalink] [raw]
Subject: Re: BUG: KASAN: use-after-free in xfs_iflush_cluster+0x9d7/0xaf0

On Tue, Dec 15, 2015 at 08:22:20AM +1100, Dave Chinner wrote:
> $ gdb vmlinux
> ....
> (gdb) l *(xfs_iflush_cluster+0x9d7)

It's not working. Shame on me, I forgot to set "Compile the kernel with debug info".

I'm recompiling, to try it again.
Maybe, in the meanwhile, you can do something with my files. You can find 'em here:
http://mail.gelma.net/xfs_kasan

Thanks a lot,
Andrea


Attachments:
(No filename) (382.00 B)
signature.asc (949.00 B)
Digital signature
Download all attachments