Re: [PATCH v12 00/10] NTFS read-write driver GPL implementation by Paragon Software

From: Aurélien Aptel
Date: Tue Nov 10 2020 - 08:09:09 EST


Hi Konstantin,

Have you looked at Eric Biggers last comments regarding KASAN and
lockdep? You can enable KASAN in menuconfig in Kernel hacking > Memory
debugging > KASAN.

With v12 I'm still seeing the out-of-bound read and potential deadlock.


The bad read:

[ 69.496132] BUG: KASAN: stack-out-of-bounds in hdr_insert_de+0x130/0x1b0
[ 69.496137] Read of size 32 at addr ffff88800b4ffb48 by task ln/1246

[ 69.496146] CPU: 0 PID: 1246 Comm: ln Not tainted 5.10.0-rc3+ #8
[ 69.496150] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS rel-1.13.0-48-gd9c812d-rebuilt.opensuse.org 04/01/2014
[ 69.496154] Call Trace:
[ 69.496161] dump_stack+0x9a/0xcc
[ 69.496168] ? hdr_insert_de+0x130/0x1b0
[ 69.496173] print_address_description.constprop.0+0x1c/0x210
[ 69.496179] ? memcmp+0x38/0x60
[ 69.496193] ? hdr_insert_de+0x130/0x1b0
[ 69.496198] ? hdr_insert_de+0x130/0x1b0
[ 69.496203] kasan_report.cold+0x37/0x7c
[ 69.496211] ? mark_lock+0x13d0/0x1450
[ 69.496216] ? hdr_insert_de+0x130/0x1b0
[ 69.496224] check_memory_region+0xf9/0x1e0
[ 69.496231] memcpy+0x20/0x60
[ 69.496238] hdr_insert_de+0x130/0x1b0
[ 69.496247] ? hdr_find_e+0x3b0/0x3b0
[ 69.496251] ? lockdep_hardirqs_on_prepare+0x13d/0x200
[ 69.496256] ? quarantine_put+0x7d/0x190
[ 69.496261] ? trace_hardirqs_on+0x1c/0x100
[ 69.496274] indx_insert_into_root+0x398/0xdb0
[ 69.496295] ? indx_insert_entry+0x300/0x300
[ 69.496299] ? get_order+0x20/0x20
[ 69.496305] ? fnd_clear+0x133/0x190
[ 69.496316] ? indx_find+0x1ac/0x470
[ 69.496329] ? indx_free_children.isra.0+0x300/0x300
[ 69.496335] ? indx_init+0x210/0x210
[ 69.496342] ? kasan_unpoison_shadow+0x33/0x40
[ 69.496354] indx_insert_entry+0x1ab/0x300
[ 69.496364] ? indx_find_raw+0x880/0x880
[ 69.496371] ? down_write+0xd7/0x130
[ 69.496381] ? ktime_get_coarse_real_ts64+0xf6/0x120
[ 69.496385] ? trace_hardirqs_on+0x1c/0x100
[ 69.496395] ntfs_insert_reparse+0xf7/0x160
[ 69.496401] ? ntfs_objid_remove+0x90/0x90
[ 69.496412] ? kasan_unpoison_shadow+0x33/0x40
[ 69.496418] ? __kasan_kmalloc.constprop.0+0xc2/0xd0
[ 69.496428] ntfs_create_inode+0x177d/0x1af0
[ 69.496454] ? inode_write_data+0x280/0x280
[ 69.496459] ? inode_security+0x6b/0x90
[ 69.496472] ? may_create+0x203/0x210
[ 69.496484] ? ntfs_symlink+0xa7/0xf0
[ 69.496488] ntfs_symlink+0xa7/0xf0
[ 69.496497] ? ntfs_unlink+0x40/0x40
[ 69.496513] vfs_symlink+0x175/0x280
[ 69.496522] do_symlinkat+0xe1/0x190
[ 69.496530] ? __ia32_sys_mknod+0xa0/0xa0
[ 69.496538] ? lockdep_hardirqs_on_prepare+0x13d/0x200
[ 69.496544] ? syscall_enter_from_user_mode+0x1d/0x50
[ 69.496553] do_syscall_64+0x33/0x40
[ 69.496559] entry_SYSCALL_64_after_hwframe+0x44/0xa9
[ 69.496564] RIP: 0033:0x7f1436b4ed07
[ 69.496569] Code: 73 01 c3 48 8b 0d 91 51 2c 00 f7 d8 64 89 01 48 83 c8 ff c3 66 2e 0f 1f 84 00 00 00 00 00 0f 1f 44 00 00 b8 0a 01 00 00 0f 05 <48> 3d 01 f0 ff ff 73 01 c3 48 8b 0d 61 51 2c 00 f7 d8 64 89 01 48
[ 69.496573] RSP: 002b:00007ffc280c9af8 EFLAGS: 00000202 ORIG_RAX: 000000000000010a
[ 69.496581] RAX: ffffffffffffffda RBX: 0000000000000000 RCX: 00007f1436b4ed07
[ 69.496585] RDX: 00007ffc280cb7b2 RSI: 00000000ffffff9c RDI: 00007ffc280cb7ab
[ 69.496589] RBP: 00000000ffffff9c R08: 0000000000000001 R09: 0000000000000000
[ 69.496593] R10: 0000000000000496 R11: 0000000000000202 R12: 00007ffc280cb7b2
[ 69.496597] R13: 00007ffc280cb7ab R14: 0000000000000000 R15: 0000000000000000

[ 69.496619] The buggy address belongs to the page:
[ 69.496624] page:00000000167d0d9a refcount:0 mapcount:0 mapping:0000000000000000 index:0x0 pfn:0xb4ff
[ 69.496628] flags: 0x100000000000000()
[ 69.496634] raw: 0100000000000000 0000000000000000 ffffea00002d3fc8 0000000000000000
[ 69.496639] raw: 0000000000000000 0000000000000000 00000000ffffffff 0000000000000000
[ 69.496643] page dumped because: kasan: bad access detected

[ 69.496650] addr ffff88800b4ffb48 is located in stack of task ln/1246 at offset 32 in frame:
[ 69.496654] ntfs_insert_reparse+0x0/0x160

[ 69.496662] this frame has 1 object:
[ 69.496666] [32, 60) 're'

[ 69.496672] Memory state around the buggy address:
[ 69.496677] ffff88800b4ffa00: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 f1 f1
[ 69.496681] ffff88800b4ffa80: f1 f1 f1 f1 04 f2 00 f3 f3 f3 00 00 00 00 00 00
[ 69.496685] >ffff88800b4ffb00: 00 00 00 00 00 f1 f1 f1 f1 00 00 00 04 f3 f3 f3
[ 69.496689] ^
[ 69.496693] ffff88800b4ffb80: f3 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
[ 69.496697] ffff88800b4ffc00: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
[ 69.496701] ==================================================================


That's in hdr_insert_de() when doing

memcpy(before, de, de_size);

* * *

Then the lockdep splat:

[ 166.670709] ======================================================
[ 166.671122] WARNING: possible circular locking dependency detected
[ 166.671509] 5.10.0-rc3+ #7 Not tainted
[ 166.671509] ------------------------------------------------------
[ 166.671509] bash/1134 is trying to acquire lock:
[ 166.671509] ffff96854bd78108 (&ni->ni_lock){+.+.}-{3:3}, at: ntfs_set_size+0x53/0xd0
[ 166.671509]
but task is already holding lock:
[ 166.671509] ffff96854bd78378 (&sb->s_type->i_mutex_key#12){+.+.}-{3:3}, at: ntfs_file_write_iter+0x8a/0xb40
[ 166.671509]
which lock already depends on the new lock.

[ 166.671509]
the existing dependency chain (in reverse order) is:
[ 166.671509]
-> #1 (&sb->s_type->i_mutex_key#12){+.+.}-{3:3}:
[ 166.671509] down_write+0x2a/0x60
[ 166.671509] ntfs_set_state+0x8c/0x1a0
[ 166.671509] ntfs_create_inode+0x19e/0x1040
[ 166.671509] ntfs_atomic_open+0x1a3/0x210
[ 166.671509] lookup_open+0x383/0x600
[ 166.671509] path_openat+0x2b3/0xa20
[ 166.671509] do_filp_open+0x88/0x130
[ 166.671509] do_sys_openat2+0x97/0x150
[ 166.671509] __x64_sys_openat+0x54/0x90
[ 166.671509] do_syscall_64+0x33/0x40
[ 166.671509] entry_SYSCALL_64_after_hwframe+0x44/0xa9
[ 166.671509]
-> #0 (&ni->ni_lock){+.+.}-{3:3}:
[ 166.671509] __lock_acquire+0x1452/0x2a20
[ 166.671509] lock_acquire+0x132/0x420
[ 166.671509] __mutex_lock+0x85/0x9e0
[ 166.671509] ntfs_set_size+0x53/0xd0
[ 166.671509] ntfs_extend_ex+0x176/0x1c0
[ 166.671509] ntfs_file_write_iter+0xc9/0xb40
[ 166.671509] new_sync_write+0x11f/0x1c0
[ 166.671509] vfs_write+0x1b2/0x230
[ 166.671509] ksys_write+0x68/0xe0
[ 166.671509] do_syscall_64+0x33/0x40
[ 166.671509] entry_SYSCALL_64_after_hwframe+0x44/0xa9
[ 166.671509]
other info that might help us debug this:

[ 166.671509] Possible unsafe locking scenario:

[ 166.671509] CPU0 CPU1
[ 166.671509] ---- ----
[ 166.671509] lock(&sb->s_type->i_mutex_key#12);
[ 166.671509] lock(&ni->ni_lock);
[ 166.671509] lock(&sb->s_type->i_mutex_key#12);
[ 166.671509] lock(&ni->ni_lock);
[ 166.671509]
*** DEADLOCK ***

[ 166.671509] 2 locks held by bash/1134:
[ 166.671509] #0: ffff968547b54438 (sb_writers#10){.+.+}-{0:0}, at: vfs_write+0x17e/0x230
[ 166.671509] #1: ffff96854bd78378 (&sb->s_type->i_mutex_key#12){+.+.}-{3:3}, at: ntfs_file_write_iter+0x8a/0xb40
[ 166.671509]
stack backtrace:
[ 166.671509] CPU: 1 PID: 1134 Comm: bash Not tainted 5.10.0-rc3+ #7
[ 166.671509] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS rel-1.13.0-48-gd9c812d-rebuilt.opensuse.org 04/01/2014
[ 166.671509] Call Trace:
[ 166.671509] dump_stack+0x77/0x97
[ 166.671509] check_noncircular+0xf2/0x110
[ 166.671509] __lock_acquire+0x1452/0x2a20
[ 166.671509] lock_acquire+0x132/0x420
[ 166.671509] ? ntfs_set_size+0x53/0xd0
[ 166.671509] ? __lock_acquire+0x39d/0x2a20
[ 166.671509] __mutex_lock+0x85/0x9e0
[ 166.671509] ? ntfs_set_size+0x53/0xd0
[ 166.671509] ? ntfs_set_size+0x53/0xd0
[ 166.671509] ? lock_acquire+0x132/0x420
[ 166.671509] ntfs_set_size+0x53/0xd0
[ 166.671509] ntfs_extend_ex+0x176/0x1c0
[ 166.671509] ntfs_file_write_iter+0xc9/0xb40
[ 166.671509] ? lock_acquire+0x132/0x420
[ 166.671509] new_sync_write+0x11f/0x1c0
[ 166.671509] vfs_write+0x1b2/0x230
[ 166.671509] ksys_write+0x68/0xe0
[ 166.671509] do_syscall_64+0x33/0x40
[ 166.671509] entry_SYSCALL_64_after_hwframe+0x44/0xa9
[ 166.671509] RIP: 0033:0x7fe486a68204
[ 166.671509] Code: 00 f7 d8 64 89 02 48 c7 c0 ff ff ff ff eb b7 0f 1f 80 00 00 00 00 8b 05 aa d1 2c 00 48 63 ff 85 c0 75 13 b8 01 00 00 00 0f 05 <48> 3d 00 f0 ff ff 77 54 f3 c3 66 90 55 53 48 89 d5 48 89 f3 48 83
[ 166.671509] RSP: 002b:00007ffd4b76fee8 EFLAGS: 00000246 ORIG_RAX: 0000000000000001
[ 166.671509] RAX: ffffffffffffffda RBX: 0000000000000004 RCX: 00007fe486a68204
[ 166.671509] RDX: 0000000000000004 RSI: 000055b1dd9bb7a0 RDI: 0000000000000001
[ 166.671509] RBP: 000055b1dd9bb7a0 R08: 000000000000000a R09: 0000000000000000
[ 166.671509] R10: 000000000000000a R11: 0000000000000246 R12: 0000000000000004

Cheers,
--
Aurélien Aptel / SUSE Labs Samba Team
GPG: 1839 CB5F 9F5B FB9B AA97 8C99 03C8 A49B 521B D5D3
SUSE Software Solutions Germany GmbH, Maxfeldstr. 5, 90409 Nürnberg, DE
GF: Felix Imendörffer, Mary Higgins, Sri Rasiah HRB 247165 (AG München)