Is ext4_dio_read_iter() broken?

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

 



Hi Matthew,

Is ext4_dio_read_iter() broken?  It calls:

	file_accessed(iocb->ki_filp);

at the end of the function - but surely iocb should be expected to have been
freed when iocb->ki_complete() was called?

In my cachefiles rewrite, I'm seeing the attached kasan dump.  The offending
RIP, ext4_file_read_iter+0x12b is at the above line, where it is trying to
read iocb->ki_filp.

Here's an excerpt of the relevant bits from my code:

	static void cachefiles_read_complete(struct kiocb *iocb, long ret, long ret2)
	{
		struct cachefiles_kiocb *ki =
			container_of(iocb, struct cachefiles_kiocb, iocb);
		struct fscache_io_request *req = ki->req;
	...
		fput(ki->iocb.ki_filp);
		kfree(ki);
		fscache_end_io_operation(req->cookie);
	...
	}

	int cachefiles_read(struct fscache_object *obj,
			    struct fscache_io_request *req,
			    struct iov_iter *iter)
	{
		struct cachefiles_object *object =
			container_of(obj, struct cachefiles_object, fscache);
		struct cachefiles_kiocb *ki;
		struct file *file = object->backing_file;
		ssize_t ret = -ENOBUFS;
	...
		ki = kzalloc(sizeof(struct cachefiles_kiocb), GFP_KERNEL);
		if (!ki)
			goto presubmission_error;

		ki->iocb.ki_filp	= get_file(file);
		ki->iocb.ki_pos		= req->pos;
		ki->iocb.ki_flags	= IOCB_DIRECT;
		ki->iocb.ki_hint	= ki_hint_validate(file_write_hint(file));
		ki->iocb.ki_ioprio	= get_current_ioprio();
		ki->req			= req;

		if (req->io_done)
			ki->iocb.ki_complete = cachefiles_read_complete;

		ret = rw_verify_area(READ, file, &ki->iocb.ki_pos, iov_iter_count(iter));
		if (ret < 0)
			goto presubmission_error_free;

		fscache_get_io_request(req);
		trace_cachefiles_read(object, file_inode(file), req);
		ret = call_read_iter(file, &ki->iocb, iter);
		...
	}

The allocation point, cachefiles_read+0xd0, is the kzalloc() you can see and
the free point, cachefiles_read_complete+0x86, is the kfree() in the callback
function.

Most of the time it works, but just occasionally the callback happens first.

David
---
EXT4-fs (sda3): mounted filesystem with ordered data mode. Opts: user_xattr
FS-Cache: Cache "mycache" added (type cachefiles)
CacheFiles: File cache on sda3 registered
CacheFiles: Dirty object in cache
==================================================================
BUG: KASAN: use-after-free in ext4_file_read_iter+0x12b/0x181
Read of size 8 at addr ffff8883577d7700 by task bash/5140

CPU: 0 PID: 5140 Comm: bash Not tainted 5.6.0-rc1-fscache+ #1285
Hardware name: ASUS All Series/H97-PLUS, BIOS 2306 10/09/2014
Call Trace:
 dump_stack+0x97/0xd3
 print_address_description.constprop.0+0x1c/0x2b5
 ? ext4_file_read_iter+0x12b/0x181
 __kasan_report+0x144/0x189
 ? ext4_file_read_iter+0x12b/0x181
 kasan_report+0xe/0x12
 ext4_file_read_iter+0x12b/0x181
 cachefiles_read+0x381/0x459
 ? trace_event_raw_event_cachefiles_map+0x14d/0x14d
 fscache_read_helper+0x9a6/0xa5f
 ? fscache_read_helper_single+0x387/0x387
 ? kmem_cache_alloc_trace+0x13f/0x167
 ? test_bit+0x1d/0x27
 afs_prefetch_for_write+0x2d4/0x397
 ? afs_req_issue_op+0x9d/0x9d
 ? hlock_class+0x27/0x86
 ? mark_lock+0x97/0x2d5
 ? timestamp_truncate+0xda/0x175
 ? inode_init_owner+0x114/0x114
 afs_write_begin+0xc8/0x354
 generic_perform_write+0x154/0x29c
 ? filemap_range_has_page+0x171/0x171
 ? file_update_time+0x11e/0x1c0
 ? alloc_inode+0xbf/0xbf
 ? generic_write_checks+0x139/0x17c
 __generic_file_write_iter+0x16e/0x1c3
 generic_file_write_iter+0x62/0xc6
 afs_file_write+0xdc/0x125
 ? new_sync_write+0xfc/0x186
 new_sync_write+0x10c/0x186
 ? __lock_is_held+0x2a/0x87
 ? new_sync_read+0x17e/0x17e
 ? rcu_read_lock_any_held+0xa5/0xe8
 ? rcu_read_lock_sched_held+0xc5/0xc5
 ? vfs_write+0xd1/0x144
 ? rcu_sync_is_idle+0x46/0x4f
 ? __sb_start_write+0xc1/0x162
 ? vfs_write+0xd1/0x144
 vfs_write+0xef/0x144
 ksys_write+0xd2/0x147
 ? __ia32_sys_read+0x41/0x41
 ? get_vtime_delta+0x9c/0xaa
 ? mark_held_locks+0x1f/0x78
 do_syscall_64+0x6e/0x8a
 entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x7fe0ecdc0ff8
Code: 89 02 48 c7 c0 ff ff ff ff eb b3 0f 1f 80 00 00 00 00 f3 0f 1e fa 48 8d 05 25 77 0d 00 8b 00 85 c0 75 17 b8 01 00 00 00 0f 05 <48> 3d 00 f0 ff ff 77 58 c3 0f 1f 80 00 00 00 00 41 54 49 89 d4 55
RSP: 002b:00007ffd5f2ca6f8 EFLAGS: 00000246 ORIG_RAX: 0000000000000001
RAX: ffffffffffffffda RBX: 000000000000000b RCX: 00007fe0ecdc0ff8
RDX: 000000000000000b RSI: 0000564008fe1b30 RDI: 0000000000000001
RBP: 0000564008fe1b30 R08: 000000000000000a R09: 00007fe0ece52e80
R10: 000000000000000a R11: 0000000000000246 R12: 00007fe0ece94780
R13: 000000000000000b R14: 00007fe0ece8f740 R15: 000000000000000b

Allocated by task 5140:
 save_stack+0x1b/0x6a
 __kasan_kmalloc.constprop.0+0x84/0x95
 kmem_cache_alloc_trace+0x124/0x167
 cachefiles_read+0xd0/0x459
 fscache_read_helper+0x9a6/0xa5f
 afs_prefetch_for_write+0x2d4/0x397
 afs_write_begin+0xc8/0x354
 generic_perform_write+0x154/0x29c
 __generic_file_write_iter+0x16e/0x1c3
 generic_file_write_iter+0x62/0xc6
 afs_file_write+0xdc/0x125
 new_sync_write+0x10c/0x186
 vfs_write+0xef/0x144
 ksys_write+0xd2/0x147
 do_syscall_64+0x6e/0x8a
 entry_SYSCALL_64_after_hwframe+0x49/0xbe

Freed by task 19100:
 save_stack+0x1b/0x6a
 __kasan_slab_free+0xd9/0xf9
 kfree+0x10d/0x140
 cachefiles_read_complete+0x86/0x111
 iomap_dio_bio_end_io+0x1b2/0x1e5
 blk_update_request+0x335/0x45b
 scsi_end_request+0x4f/0x27d
 scsi_io_completion+0x22e/0x5a7
 blk_done_softirq+0x142/0x17a
 __do_softirq+0x22b/0x492

The buggy address belongs to the object at ffff8883577d7700
 which belongs to the cache kmalloc-64 of size 64
The buggy address is located 0 bytes inside of
 64-byte region [ffff8883577d7700, ffff8883577d7740)
The buggy address belongs to the page:
page:ffffea000d5df5c0 refcount:1 mapcount:0 mapping:ffff8883ce400380 index:0xffff8883577d7000
flags: 0x200000000000200(slab)
raw: 0200000000000200 ffffea000d8cdd08 ffffea000dc0af88 ffff8883ce400380
raw: ffff8883577d7000 ffff8883577d7000 0000000100000013 0000000000000000
page dumped because: kasan: bad access detected

Memory state around the buggy address:
 ffff8883577d7600: fb fb fb fb fb fb fb fb fc fc fc fc fc fc fc fc
 ffff8883577d7680: fb fb fb fb fb fb fb fb fc fc fc fc fc fc fc fc
>ffff8883577d7700: fb fb fb fb fb fb fb fb fc fc fc fc fc fc fc fc
                   ^
 ffff8883577d7780: fb fb fb fb fb fb fb fb fc fc fc fc fc fc fc fc
 ffff8883577d7800: fb fb fb fb fb fb fb fb fc fc fc fc fc fc fc fc
==================================================================
Disabling lock debugging due to kernel taint
BUG: unable to handle page fault for address: 0000000100000058
#PF: supervisor read access in kernel mode
#PF: error_code(0x0000) - not-present page
PGD 0 P4D 0 
Oops: 0000 [#1] SMP KASAN PTI
CPU: 0 PID: 5140 Comm: bash Tainted: G    B             5.6.0-rc1-fscache+ #1285
Hardware name: ASUS All Series/H97-PLUS, BIOS 2306 10/09/2014
RIP: 0010:touch_atime+0x82/0x137
Code: 00 00 48 89 44 24 58 31 c0 e8 8a bf fb ff 49 8d 7c 24 08 4d 8b 34 24 e8 7c bf fb ff 49 8b 5c 24 08 48 8d 7b 58 e8 6e bf fb ff <48> 8b 5b 58 4c 89 e7 48 89 de e8 b4 fd ff ff 84 c0 74 6e 4c 8d 63
RSP: 0018:ffff8883c8617800 EFLAGS: 00010282
RAX: 0000000000000000 RBX: 0000000100000000 RCX: ffffffff812f3d9f
RDX: 0000000000000000 RSI: 0000000000000008 RDI: 0000000100000058
RBP: ffff8883c8617880 R08: 0000000000000003 R09: 0000000000000001
R10: fffffbfff05f7dc5 R11: 0000000000000000 R12: ffff8883679d5010
R13: 1ffff110790c2f00 R14: 0000100000000000 R15: ffff8883577d7720
FS:  00007fe0eccd0740(0000) GS:ffff8883d0200000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 0000000100000058 CR3: 000000037201c002 CR4: 00000000001606f0
Call Trace:
 ? atime_needs_update+0x1bb/0x1bb
 ? __kasan_report+0x169/0x189
 ? ext4_file_read_iter+0x12b/0x181
 ext4_file_read_iter+0x147/0x181
 cachefiles_read+0x381/0x459
 ? trace_event_raw_event_cachefiles_map+0x14d/0x14d
 fscache_read_helper+0x9a6/0xa5f
 ? fscache_read_helper_single+0x387/0x387
 ? kmem_cache_alloc_trace+0x13f/0x167
 ? test_bit+0x1d/0x27
 afs_prefetch_for_write+0x2d4/0x397
 ? afs_req_issue_op+0x9d/0x9d
 ? hlock_class+0x27/0x86
 ? mark_lock+0x97/0x2d5
 ? timestamp_truncate+0xda/0x175
 ? inode_init_owner+0x114/0x114
 afs_write_begin+0xc8/0x354
 generic_perform_write+0x154/0x29c
 ? filemap_range_has_page+0x171/0x171
 ? file_update_time+0x11e/0x1c0
 ? alloc_inode+0xbf/0xbf
 ? generic_write_checks+0x139/0x17c
 __generic_file_write_iter+0x16e/0x1c3
 generic_file_write_iter+0x62/0xc6
 afs_file_write+0xdc/0x125
 ? new_sync_write+0xfc/0x186
 new_sync_write+0x10c/0x186
 ? __lock_is_held+0x2a/0x87
 ? new_sync_read+0x17e/0x17e
 ? rcu_read_lock_any_held+0xa5/0xe8
 ? rcu_read_lock_sched_held+0xc5/0xc5
 ? vfs_write+0xd1/0x144
 ? rcu_sync_is_idle+0x46/0x4f
 ? __sb_start_write+0xc1/0x162
 ? vfs_write+0xd1/0x144
 vfs_write+0xef/0x144
 ksys_write+0xd2/0x147
 ? __ia32_sys_read+0x41/0x41
 ? get_vtime_delta+0x9c/0xaa
 ? mark_held_locks+0x1f/0x78
 do_syscall_64+0x6e/0x8a
 entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x7fe0ecdc0ff8
Code: 89 02 48 c7 c0 ff ff ff ff eb b3 0f 1f 80 00 00 00 00 f3 0f 1e fa 48 8d 05 25 77 0d 00 8b 00 85 c0 75 17 b8 01 00 00 00 0f 05 <48> 3d 00 f0 ff ff 77 58 c3 0f 1f 80 00 00 00 00 41 54 49 89 d4 55
RSP: 002b:00007ffd5f2ca6f8 EFLAGS: 00000246 ORIG_RAX: 0000000000000001
RAX: ffffffffffffffda RBX: 000000000000000b RCX: 00007fe0ecdc0ff8
RDX: 000000000000000b RSI: 0000564008fe1b30 RDI: 0000000000000001
RBP: 0000564008fe1b30 R08: 000000000000000a R09: 00007fe0ece52e80
R10: 000000000000000a R11: 0000000000000246 R12: 00007fe0ece94780
R13: 000000000000000b R14: 00007fe0ece8f740 R15: 000000000000000b
Modules linked in:
CR2: 0000000100000058
---[ end trace 051c3ce276c972cc ]---
RIP: 0010:touch_atime+0x82/0x137
Code: 00 00 48 89 44 24 58 31 c0 e8 8a bf fb ff 49 8d 7c 24 08 4d 8b 34 24 e8 7c bf fb ff 49 8b 5c 24 08 48 8d 7b 58 e8 6e bf fb ff <48> 8b 5b 58 4c 89 e7 48 89 de e8 b4 fd ff ff 84 c0 74 6e 4c 8d 63
RSP: 0018:ffff8883c8617800 EFLAGS: 00010282
RAX: 0000000000000000 RBX: 0000000100000000 RCX: ffffffff812f3d9f
RDX: 0000000000000000 RSI: 0000000000000008 RDI: 0000000100000058
RBP: ffff8883c8617880 R08: 0000000000000003 R09: 0000000000000001
R10: fffffbfff05f7dc5 R11: 0000000000000000 R12: ffff8883679d5010
R13: 1ffff110790c2f00 R14: 0000100000000000 R15: ffff8883577d7720
FS:  00007fe0eccd0740(0000) GS:ffff8883d0200000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 0000000100000058 CR3: 000000037201c002 CR4: 00000000001606f0





[Index of Archives]     [Reiser Filesystem Development]     [Ceph FS]     [Kernel Newbies]     [Security]     [Netfilter]     [Bugtraq]     [Linux FS]     [Yosemite National Park]     [MIPS Linux]     [ARM Linux]     [Linux Security]     [Linux RAID]     [Samba]     [Device Mapper]     [Linux Media]

  Powered by Linux