Re: [PATCH 0/5] SMB cached directory fixes around reconnection/unmounting

[Paul Aurich <paul@darkrain42.org>]

I'm working on a v2 set of patches that I hope would address this (I'm 
guessing it's somehow caused by the flush_workqueue() call, although to be 
honest, I have no idea).

My testing has also turned up another issue that needs fixing (the laundromat 
thread can also race with cifs_kill_sb, resulting in yet another 'Dentry still 
in use' oops).

~Paul

On 2024-11-09 18:49:54 -0600, Steve French wrote:
>Running the buildbot on these against Windows with directory leases
>enabled (ie not using "nohandlecache") I see a crash in generic/246 in
>cifs_mount (see call trace at end of the email for more details). The
>series does improve things, it fixes the oops that would cause e.g.
>generic/048 to crash e.g. it fixes this one
>
>[ 2039.224037] BUG: Dentry 00000000114e5018{i=6000000019c6c,n=/}
>still in use (2) [unmount of cifs cifs]
>[ 2039.224086] WARNING: CPU: 1 PID: 123637 at fs/dcache.c:1536
>umount_check+0xc3/0xf0
>[ 2039.224112] Modules linked in: cifs ccm cmac nls_utf8 cifs_arc4
>nls_ucs2_utils cifs_md4 rpcsec_gss_krb5 auth_rpcgss nfsv4 dns_resolver
>nfs lockd grace netfs nf_conntrack_netbios_ns nf_conntrack_broadcast
>nft_fib_inet nft_fib_ipv4 nft_fib_ipv6 nft_fib nft_reject_inet
>nf_reject_ipv4 nf_reject_ipv6 nft_reject nft_ct nft_chain_nat
>nf_tables ebtable_nat ebtable_broute ip6table_nat ip6table_mangle
>ip6table_raw ip6table_security iptable_nat nf_nat nf_conntrack
>nf_defrag_ipv6 nf_defrag_ipv4 iptable_mangle iptable_raw
>iptable_security ip_set ebtable_filter ebtables ip6table_filter
>ip6_tables iptable_filter ip_tables sunrpc kvm_intel kvm virtio_net
>net_failover failover virtio_balloon loop fuse dm_multipath nfnetlink
>zram xfs bochs drm_vram_helper drm_ttm_helper ttm drm_kms_helper
>crct10dif_pclmul crc32_pclmul crc32c_intel drm ghash_clmulni_intel
>sha512_ssse3 sha256_ssse3 floppy virtio_blk sha1_ssse3 qemu_fw_cfg
>virtio_console [last unloaded: cifs]
>[ 2039.224382] CPU: 1 UID: 0 PID: 123637 Comm: rm Not tainted 6.12.0-rc6 #1
>[ 2039.224390] Hardware name: Red Hat KVM, BIOS 1.16.3-2.el9 04/01/2014
>[ 2039.224395] RIP: 0010:umount_check+0xc3/0xf0
>[ 2039.224401] Code: db 74 0d 48 8d 7b 40 e8 9b e3 f5 ff 48 8b 53 40
>41 55 4d 89 f1 45 89 e0 48 89 e9 48 89 ee 48 c7 c7 80 74 ba a2 e8 dd
>e8 a2 ff <0f> 0b 58 31 c0 5b 5d 41 5c 41 5d 41 5e c3 cc cc cc cc 41 83
>fc 01
>[ 2039.224408] RSP: 0018:ff11000128bcf968 EFLAGS: 00010282
>[ 2039.224416] RAX: dffffc0000000000 RBX: ff11000110ba3d80 RCX: 0000000000000027
>[ 2039.224422] RDX: 0000000000000027 RSI: 0000000000000004 RDI: ff110004cb0b1a08
>[ 2039.224427] RBP: ff11000112ebb8f8 R08: ffffffffa13f759e R09: ffe21c0099616341
>[ 2039.224432] R10: ff110004cb0b1a0b R11: 0000000000000001 R12: 0000000000000002
>[ 2039.224437] R13: ff1100013fe0c668 R14: ffffffffc1dee340 R15: ffffffffc2094200
>[ 2039.224442] FS:  00007fdc92c66740(0000) GS:ff110004cb080000(0000)
>knlGS:0000000000000000
>[ 2039.224447] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
>[ 2039.224452] CR2: 0000556c6a58d488 CR3: 00000001229ec006 CR4: 0000000000373ef0
>[ 2039.224465] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
>[ 2039.224470] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
>[ 2039.224475] Call Trace:
>[ 2039.224479]  <TASK>
>[ 2039.224485]  ? __warn+0xa9/0x220
>[ 2039.224497]  ? umount_check+0xc3/0xf0
>[ 2039.224506]  ? report_bug+0x1d4/0x1e0
>[ 2039.224521]  ? handle_bug+0x5b/0xa0
>[ 2039.224529]  ? exc_invalid_op+0x18/0x50
>[ 2039.224537]  ? asm_exc_invalid_op+0x1a/0x20
>[ 2039.224556]  ? irq_work_claim+0x1e/0x40
>[ 2039.224568]  ? umount_check+0xc3/0xf0
>[ 2039.224577]  ? umount_check+0xc3/0xf0
>[ 2039.224586]  ? __pfx_umount_check+0x10/0x10
>[ 2039.224594]  d_walk+0x71/0x4e0
>[ 2039.224604]  ? d_walk+0x4b/0x4e0
>[ 2039.224616]  shrink_dcache_for_umount+0x6d/0x220
>[ 2039.224629]  generic_shutdown_super+0x4a/0x1c0
>[ 2039.224640]  kill_anon_super+0x22/0x40
>[ 2039.224649]  cifs_kill_sb+0x78/0x90 [cifs]
>[ 2039.224848]  deactivate_locked_super+0x69/0xf0
>[ 2039.224858]  cifsFileInfo_put_final+0x25a/0x290 [cifs]
>[ 2039.225019]  _cifsFileInfo_put+0x5f9/0x770 [cifs]
>[ 2039.225172]  ? __pfx__cifsFileInfo_put+0x10/0x10 [cifs]
>[ 2039.225319]  ? mark_held_locks+0x65/0x90
>[ 2039.225339]  ? kfree+0x1e5/0x490
>[ 2039.225349]  ? cifs_close_deferred_file_under_dentry+0x2e5/0x350 [cifs]
>[ 2039.225494]  cifs_close_deferred_file_under_dentry+0x26d/0x350 [cifs]
>[ 2039.225639]  ? __pfx_cifs_close_deferred_file_under_dentry+0x10/0x10 [cifs]
>[ 2039.225821]  ? cifs_sb_master_tcon+0x23/0x30 [cifs]
>[ 2039.225970]  cifs_unlink+0x21d/0x7b0 [cifs]
>[ 2039.226121]  vfs_unlink+0x1bf/0x4a0
>[ 2039.226131]  ? lookup_one_qstr_excl+0x24/0xd0
>[ 2039.226143]  do_unlinkat+0x380/0x450
>[ 2039.226154]  ? __pfx_do_unlinkat+0x10/0x10
>[ 2039.226161]  ? kasan_save_track+0x14/0x30
>[ 2039.226171]  ? rcu_is_watching+0x20/0x50
>[ 2039.226180]  ? strncpy_from_user+0x126/0x180
>[ 2039.226201]  __x64_sys_unlinkat+0x5e/0xa0
>[ 2039.226211]  do_syscall_64+0x75/0x180
>[ 2039.226222]  entry_SYSCALL_64_after_hwframe+0x76/0x7e
>[ 2039.226230] RIP: 0033:0x7fdc92d7784b
>[ 2039.226237] Code: 77 05 c3 0f 1f 40 00 48 8b 15 c9 85 0d 00 f7 d8
>64 89 02 b8 ff ff ff ff c3 66 0f 1f 44 00 00 f3 0f 1e fa b8 07 01 00
>00 0f 05 <48> 3d 01 f0 ff ff 73 01 c3 48 8b 0d 9d 85 0d 00 f7 d8 64 89
>01 48
>[ 2039.226244] RSP: 002b:00007ffd51debe58 EFLAGS: 00000206 ORIG_RAX:
>0000000000000107
>[ 2039.226253] RAX: ffffffffffffffda RBX: 0000556c6a58d5a0 RCX: 00007fdc92d7784b
>[ 2039.226258] RDX: 0000000000000000 RSI: 0000556c6a58c380 RDI: 00000000ffffff9c
>[ 2039.226263] RBP: 00007ffd51debf20 R08: 0000556c6a58c380 R09: 00007ffd51debf7c
>[ 2039.226268] R10: 0000556c6a58d7d0 R11: 0000000000000206 R12: 0000556c6a58c2f0
>[ 2039.226273] R13: 0000000000000000 R14: 00007ffd51debf80 R15: 0000000000000000
>[ 2039.226297]  </TASK>
>[ 2039.226301] irq event stamp: 5933
>[ 2039.226305] hardirqs last  enabled at (5939): [<ffffffffa122e2de>]
>__up_console_sem+0x5e/0x70
>[ 2039.226314] hardirqs last disabled at (5944): [<ffffffffa122e2c3>]
>__up_console_sem+0x43/0x70
>[ 2039.226320] softirqs last  enabled at (3096): [<ffffffffa11340ce>]
>__irq_exit_rcu+0xfe/0x120
>[ 2039.226327] softirqs last disabled at (2941): [<ffffffffa11340ce>]
>__irq_exit_rcu+0xfe/0x120
>[ 2039.226333] ---[ end trace 0000000000000000 ]---
>[ 2040.931627] VFS: Busy inodes after unmount of cifs (cifs)
>[ 2040.931693] ------------[ cut here ]------------
>[ 2040.931699] kernel BUG at fs/super.c:650!
>[ 2040.932770] Oops: invalid opcode: 0000 [#1] PREEMPT SMP KASAN NOPTI
>[ 2040.932846] CPU: 1 UID: 0 PID: 123637 Comm: rm Tainted: G        W
>        6.12.0-rc6 #1
>[ 2040.932936] Tainted: [W]=WARN
>[ 2040.932969] Hardware name: Red Hat KVM, BIOS 1.16.3-2.el9 04/01/2014
>[ 2040.933028] RIP: 0010:generic_shutdown_super+0x1b7/0x1c0
>[ 2040.933086] Code: 7b 28 e8 cc ca f8 ff 48 8b 6b 28 48 89 ef e8 c0
>ca f8 ff 48 8b 55 00 48 8d b3 68 06 00 00 48 c7 c7 60 14 ba a2 e8 d9
>6c b6 ff <0f> 0b 0f 1f 80 00 00 00 00 90 90 90 90 90 90 90 90 90 90 90
>90 90
>[ 2040.933252] RSP: 0018:ff11000128bcfa38 EFLAGS: 00010282
>[ 2040.933305] RAX: 000000000000002d RBX: ff1100013fe0c000 RCX: ffffffffa12c915e
>[ 2040.933370] RDX: dffffc0000000000 RSI: 0000000000000008 RDI: ff110004cb0b7080
>[ 2040.933436] RBP: ffffffffc20529a0 R08: 0000000000000001 R09: ffe21c0025179f0f
>[ 2040.933500] R10: ff11000128bcf87f R11: 0000000000000001 R12: ff1100013fe0c9c0
>[ 2040.933565] R13: ff1100013fe0c780 R14: ff11000168113378 R15: ffffffffc2094200
>[ 2040.933630] FS:  00007fdc92c66740(0000) GS:ff110004cb080000(0000)
>knlGS:0000000000000000
>[ 2040.933703] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
>[ 2040.933757] CR2: 0000556c6a58d488 CR3: 00000001229ec006 CR4: 0000000000373ef0
>[ 2040.933828] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
>[ 2040.933905] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
>[ 2040.933972] Call Trace:
>[ 2040.934000]  <TASK>
>[ 2040.934024]  ? die+0x37/0x90
>[ 2040.934058]  ? do_trap+0x133/0x230
>[ 2040.934094]  ? generic_shutdown_super+0x1b7/0x1c0
>[ 2040.934144]  ? do_error_trap+0x94/0x130
>[ 2040.934182]  ? generic_shutdown_super+0x1b7/0x1c0
>[ 2040.934229]  ? generic_shutdown_super+0x1b7/0x1c0
>[ 2040.934277]  ? handle_invalid_op+0x2c/0x40
>[ 2040.934318]  ? generic_shutdown_super+0x1b7/0x1c0
>[ 2040.934364]  ? exc_invalid_op+0x2f/0x50
>[ 2040.934405]  ? asm_exc_invalid_op+0x1a/0x20
>[ 2040.934453]  ? tick_nohz_tick_stopped+0x1e/0x40
>[ 2040.934502]  ? generic_shutdown_super+0x1b7/0x1c0
>[ 2040.934551]  ? generic_shutdown_super+0x1b7/0x1c0
>[ 2040.934600]  kill_anon_super+0x22/0x40
>[ 2040.934641]  cifs_kill_sb+0x78/0x90 [cifs]
>[ 2040.934851]  deactivate_locked_super+0x69/0xf0
>[ 2040.934915]  cifsFileInfo_put_final+0x25a/0x290 [cifs]
>[ 2040.935125]  _cifsFileInfo_put+0x5f9/0x770 [cifs]
>[ 2040.935331]  ? __pfx__cifsFileInfo_put+0x10/0x10 [cifs]
>[ 2040.935537]  ? mark_held_locks+0x65/0x90
>[ 2040.935581]  ? kfree+0x1e5/0x490
>[ 2040.937096]  ? cifs_close_deferred_file_under_dentry+0x2e5/0x350 [cifs]
>[ 2040.938778]  cifs_close_deferred_file_under_dentry+0x26d/0x350 [cifs]
>[ 2040.940478]  ? __pfx_cifs_close_deferred_file_under_dentry+0x10/0x10 [cifs]
>[ 2040.942193]  ? cifs_sb_master_tcon+0x23/0x30 [cifs]
>[ 2040.943865]  cifs_unlink+0x21d/0x7b0 [cifs]
>[ 2040.945527]  vfs_unlink+0x1bf/0x4a0
>[ 2040.947008]  ? lookup_one_qstr_excl+0x24/0xd0
>[ 2040.948451]  do_unlinkat+0x380/0x450
>[ 2040.949889]  ? __pfx_do_unlinkat+0x10/0x10
>[ 2040.951306]  ? kasan_save_track+0x14/0x30
>[ 2040.952708]  ? rcu_is_watching+0x20/0x50
>[ 2040.954135]  ? strncpy_from_user+0x126/0x180
>[ 2040.955494]  __x64_sys_unlinkat+0x5e/0xa0
>[ 2040.956779]  do_syscall_64+0x75/0x180
>[ 2040.958053]  entry_SYSCALL_64_after_hwframe+0x76/0x7e
>
>
>
>but I did see a crash in generic/246 with current mainline + the five
>directory lease patches (see below).  Any ideas?
>
>[ 4315.917270] CIFS: Attempting to mount //win16.vm.test/Share
>[ 4315.928088] ==================================================================
>[ 4315.930402] BUG: KASAN: slab-use-after-free in
>rwsem_down_write_slowpath+0xa34/0xaf0
>[ 4315.932655] Read of size 4 at addr ff1100012ad38034 by task mount.cifs/340968
>
>[ 4315.937119] CPU: 2 UID: 0 PID: 340968 Comm: mount.cifs Tainted: G
>   D W          6.12.0-rc6 #1
>[ 4315.939454] Tainted: [D]=DIE, [W]=WARN
>[ 4315.941747] Hardware name: Red Hat KVM, BIOS 1.16.3-2.el9 04/01/2014
>[ 4315.944094] Call Trace:
>[ 4315.946425]  <TASK>
>[ 4315.948724]  dump_stack_lvl+0x79/0xb0
>[ 4315.951046]  print_report+0xcb/0x620
>[ 4315.953359]  ? __virt_addr_valid+0x19a/0x300
>[ 4315.955682]  ? rwsem_down_write_slowpath+0xa34/0xaf0
>[ 4315.957994]  kasan_report+0xbd/0xf0
>[ 4315.960317]  ? rwsem_down_write_slowpath+0xa34/0xaf0
>[ 4315.962610]  rwsem_down_write_slowpath+0xa34/0xaf0
>[ 4315.964835]  ? kasan_save_stack+0x34/0x50
>[ 4315.967030]  ? __pfx_rwsem_down_write_slowpath+0x10/0x10
>[ 4315.969221]  ? cifs_mount+0xfb/0x3b0 [cifs]
>[ 4315.971586]  ? cifs_smb3_do_mount+0x1a5/0xc10 [cifs]
>[ 4315.974108]  ? smb3_get_tree+0x1f0/0x430 [cifs]
>[ 4315.976511]  ? rcu_is_watching+0x20/0x50
>[ 4315.978712]  ? trace_lock_acquire+0x116/0x150
>[ 4315.980884]  ? lock_acquire+0x40/0x90
>[ 4315.982989]  ? super_lock+0xea/0x1d0
>[ 4315.985036]  ? super_lock+0xea/0x1d0
>[ 4315.986997]  down_write+0x15b/0x160
>[ 4315.988893]  ? __pfx_down_write+0x10/0x10
>[ 4315.990751]  ? __mod_timer+0x407/0x590
>[ 4315.992531]  super_lock+0xea/0x1d0
>[ 4315.994231]  ? __pfx_super_lock+0x10/0x10
>[ 4315.995891]  ? __pfx_lock_release+0x10/0x10
>[ 4315.997528]  ? rcu_is_watching+0x20/0x50
>[ 4315.999137]  ? lock_release+0xa5/0x3d0
>[ 4316.000705]  ? cifs_match_super+0x177/0x650 [cifs]
>[ 4316.002385]  grab_super+0x80/0x1e0
>[ 4316.003884]  ? __pfx_grab_super+0x10/0x10
>[ 4316.005351]  ? cifs_put_tlink+0xa1/0xc0 [cifs]
>[ 4316.006990]  ? cifs_match_super+0x17f/0x650 [cifs]
>[ 4316.008620]  ? __pfx_cifs_match_super+0x10/0x10 [cifs]
>[ 4316.010236]  sget+0x121/0x350
>[ 4316.011694]  ? __pfx_cifs_set_super+0x10/0x10 [cifs]
>[ 4316.013293]  cifs_smb3_do_mount+0x293/0xc10 [cifs]
>[ 4316.014933]  ? __pfx___mutex_lock+0x10/0x10
>[ 4316.016333]  ? cred_has_capability.isra.0+0xd4/0x1a0
>[ 4316.017752]  ? __pfx_cifs_smb3_do_mount+0x10/0x10 [cifs]
>[ 4316.019338]  smb3_get_tree+0x1f0/0x430 [cifs]
>[ 4316.020910]  vfs_get_tree+0x50/0x180
>[ 4316.022292]  path_mount+0x5d6/0xf20
>[ 4316.023668]  ? __pfx_path_mount+0x10/0x10
>[ 4316.024983]  ? user_path_at+0x45/0x60
>[ 4316.026275]  __x64_sys_mount+0x174/0x1b0
>[ 4316.027552]  ? __pfx___x64_sys_mount+0x10/0x10
>[ 4316.028794]  ? rcu_is_watching+0x20/0x50
>[ 4316.030021]  do_syscall_64+0x75/0x180
>[ 4316.031226]  entry_SYSCALL_64_after_hwframe+0x76/0x7e
>[ 4316.032476] RIP: 0033:0x7f979fa7b8fe
>[ 4316.033742] Code: 48 8b 0d 1d a5 0c 00 f7 d8 64 89 01 48 83 c8 ff
>c3 66 2e 0f 1f 84 00 00 00 00 00 90 f3 0f 1e fa 49 89 ca b8 a5 00 00
>00 0f 05 <48> 3d 01 f0 ff ff 73 01 c3 48 8b 0d ea a4 0c 00 f7 d8 64 89
>01 48
>[ 4316.036462] RSP: 002b:00007fffbaa4f598 EFLAGS: 00000246 ORIG_RAX:
>00000000000000a5
>[ 4316.037874] RAX: ffffffffffffffda RBX: 0000557684547471 RCX: 00007f979fa7b8fe
>[ 4316.039284] RDX: 0000557684547471 RSI: 00005576845474d7 RDI: 00007fffbaa50caf
>[ 4316.040701] RBP: 000000000000000a R08: 00005576847deeb0 R09: 0000000000000000
>[ 4316.042106] R10: 0000000000000000 R11: 0000000000000246 R12: 00007fffbaa50caf
>[ 4316.043522] R13: 00005576847dff20 R14: 00005576847deeb0 R15: 00007f979fb75000
>[ 4316.044928]  </TASK>
>
>[ 4316.047670] Allocated by task 340820:
>[ 4316.049036]  kasan_save_stack+0x24/0x50
>[ 4316.050414]  kasan_save_track+0x14/0x30
>[ 4316.051771]  __kasan_slab_alloc+0x59/0x70
>[ 4316.053139]  kmem_cache_alloc_node_noprof+0x116/0x330
>[ 4316.054529]  copy_process+0x299/0x45e0
>[ 4316.055915]  kernel_clone+0xf2/0x4b0
>[ 4316.057299]  __do_sys_clone+0x90/0xb0
>[ 4316.058708]  do_syscall_64+0x75/0x180
>[ 4316.060095]  entry_SYSCALL_64_after_hwframe+0x76/0x7e
>
>[ 4316.062893] Freed by task 0:
>[ 4316.064283]  kasan_save_stack+0x24/0x50
>[ 4316.065695]  kasan_save_track+0x14/0x30
>[ 4316.067076]  kasan_save_free_info+0x3b/0x60
>[ 4316.068462]  __kasan_slab_free+0x38/0x50
>[ 4316.069841]  kmem_cache_free+0x239/0x5a0
>[ 4316.071213]  delayed_put_task_struct+0x149/0x1b0
>[ 4316.072608]  rcu_do_batch+0x2f4/0x880
>[ 4316.073979]  rcu_core+0x3d6/0x510
>[ 4316.075340]  handle_softirqs+0x10f/0x580
>[ 4316.076708]  __irq_exit_rcu+0xfe/0x120
>[ 4316.078052]  irq_exit_rcu+0xe/0x20
>[ 4316.079400]  sysvec_apic_timer_interrupt+0x76/0x90
>[ 4316.080747]  asm_sysvec_apic_timer_interrupt+0x1a/0x20
>
>[ 4316.083488] Last potentially related work creation:
>[ 4316.084845]  kasan_save_stack+0x24/0x50
>[ 4316.086188]  __kasan_record_aux_stack+0x8e/0xa0
>[ 4316.087564]  __call_rcu_common.constprop.0+0x87/0x920
>[ 4316.088932]  release_task+0x836/0xc60
>[ 4316.090296]  wait_consider_task+0x9db/0x19c0
>[ 4316.091682]  __do_wait+0xe9/0x390
>[ 4316.093046]  do_wait+0xcb/0x230
>[ 4316.094412]  kernel_wait4+0xe4/0x1a0
>[ 4316.095767]  __do_sys_wait4+0xce/0xe0
>[ 4316.097110]  do_syscall_64+0x75/0x180
>[ 4316.098455]  entry_SYSCALL_64_after_hwframe+0x76/0x7e
>
>[ 4316.100994] The buggy address belongs to the object at ff1100012ad38000
>                which belongs to the cache task_struct of size 14656
>[ 4316.103497] The buggy address is located 52 bytes inside of
>                freed 14656-byte region [ff1100012ad38000, ff1100012ad3b940)
>
>[ 4316.107248] The buggy address belongs to the physical page:
>[ 4316.108537] page: refcount:1 mapcount:0 mapping:0000000000000000
>index:0x0 pfn:0x12ad38
>[ 4316.109846] head: order:3 mapcount:0 entire_mapcount:0
>nr_pages_mapped:0 pincount:0
>[ 4316.111193] memcg:ff11000100d2c6c1
>[ 4316.112543] anon flags:
>0x17ffffc0000040(head|node=0|zone=2|lastcpupid=0x1fffff)
>[ 4316.113945] page_type: f5(slab)
>[ 4316.115364] raw: 0017ffffc0000040 ff11000100280a00 0000000000000000
>0000000000000001
>[ 4316.116852] raw: 0000000000000000 0000000000020002 00000001f5000000
>ff11000100d2c6c1
>[ 4316.118329] head: 0017ffffc0000040 ff11000100280a00
>0000000000000000 0000000000000001
>[ 4316.119818] head: 0000000000000000 0000000000020002
>00000001f5000000 ff11000100d2c6c1
>[ 4316.121302] head: 0017ffffc0000003 ffd4000004ab4e01
>ffffffffffffffff 0000000000000000
>[ 4316.122818] head: 0000000000000008 0000000000000000
>00000000ffffffff 0000000000000000
>[ 4316.124323] page dumped because: kasan: bad access detected
>
>[ 4316.127318] Memory state around the buggy address:
>[ 4316.128847]  ff1100012ad37f00: ff ff ff ff ff ff ff ff ff ff ff ff
>ff ff ff ff
>[ 4316.130427]  ff1100012ad37f80: ff ff ff ff ff ff ff ff ff ff ff ff
>ff ff ff ff
>[ 4316.132006] >ff1100012ad38000: fa fb fb fb fb fb fb fb fb fb fb fb
>fb fb fb fb
>[ 4316.133594]                                      ^
>[ 4316.135170]  ff1100012ad38080: fb fb fb fb fb fb fb fb fb fb fb fb
>fb fb fb fb
>[ 4316.136796]  ff1100012ad38100: fb fb fb fb fb fb fb fb fb fb fb fb
>fb fb fb fb
>[ 4316.138399] ==================================================================
>
>
>On Fri, Nov 8, 2024 at 5:12 PM Enzo Matsumiya <ematsumiya@suse.de> wrote:
>>
>> On 11/08, Paul Aurich wrote:
>> >No, this series doesn't try to address that. I was just focused on the
>> >issues around the lifecycle of the cfids and the dentry:s.
>>
>> I'll be reviewing the patches next week, but for now I can say +1.
>>
>> We've been debugging this issue for the past month or so, and it's been
>> quite hard to understand/debug who was racing who.
>>
>> The 'dentry still in use' bug seems to appear only for the root dentry,
>> whereas cached_fids for subdirectories sometimes can get duplicates, and
>> thus one dangling, where in the end an underflow + double list_del()
>> happens to it, e.g.:
>>
>> (this is coming from cifs_readdir())
>> crash> cached_fid.entry,cfids,path,has_lease,is_open,on_list,time,tcon,refcount 0xffff892f4b5b3e00
>>    entry = {
>>      next = 0xffff892e053ed400,
>>      prev = 0xffff892d8e3ecb88
>>    },
>>    cfids = 0xffff892d8e3ecb80,
>>    path = 0xffff892f48b7b3b0 "\\dir1\\dir2\\dir3",
>>    has_lease = 0x0,
>>    is_open = 0x0,
>>    on_list = 0x1,
>>    time = 0x0,
>>    tcon = 0x0,
>>    refcount = { ... counter = 0x2 ... }
>>
>> (this is at the crashing frame on smb2_close_cached_fid())
>> crash> cached_fid.entry,cfids,path,has_lease,is_open,on_list,time,tcon,refcount ffff892e053ee000
>>    entry = {
>>      next = 0xdead000000000100,
>>      prev = 0xdead000000000122
>>    },
>>    cfids = 0xffff892d8e3ecb80,
>>    path = 0xffff892f825ced30 "\\dir1\\dir2\\dir3",
>>    has_lease = 0x0,
>>    is_open = 0x1,
>>    on_list = 0x1,
>>    time = 0x1040998fc,
>>    tcon = 0xffff892fe0b4d000,
>>    refcount = { ... counter = 0x0 ... }
>>
>> You can see that the second one had already been deleted (refcount=0,
>> ->entry is poisoned), but the first one hasn't been filled in by
>> open_cached_dir() yet, but already has 2 references to it.
>>
>> A reliable reproducer I found for this was running xfstests '-g
>> generic/dir' in one terminal, and generic/072 some seconds later.
>>
>> (in the beginning I thought that a reconnect was required to trigger
>> this bug, but any kind of interruption (I could trigger it with ctrl-c
>> mid-xfstests a few times) should trigger it)
>>
>> actimeo >= 0 seems to play a role as well, because things can get quite
>> complicated (unsure if problematic though) with a callchain such as:
>>
>> open_cached_dir
>>    -> path_to_dentry
>>      -> lookup_positive_unlocked
>>        -> lookup_dcache
>>          -> cifs_d_revalidate (dentry->d_op->d_revalidate)
>>            -> cifs_revalidate_dentry
>>              -> cifs_revalidate_dentry_attr
>>                -> cifs_dentry_needs_reval
>>                  -> open_cached_dir_by_dentry
>>
>>
>> Anyway, thanks a lot for you patches, Paul.  Like I said, I'll be
>> testing + reviewing them soon.
>>
>>
>> Cheers,
>>
>> Enzo
>>
>> >On 2024-11-08 16:39:03 -0600, Steve French wrote:
>> >>The perf improvement allowing caching of directories (helping "ls"
>> >>then "ls" again for same dir) not just the perf improvement with "ls
>> >>"then "stat" could be very important.
>> >>
>> >>Did this series also address Ralph's point about missing requesting
>> >>"H" (handle caching) flag when requesting directory leases from the
>> >>server?
>> >>
>> >>On Fri, Nov 8, 2024 at 4:35 PM Paul Aurich <paul@darkrain42.org> wrote:
>> >>>
>> >>>The SMB client cached directory functionality has a few problems around
>> >>>flaky/lost server connections, which manifest as a pair of BUGs when
>> >>>eventually unmounting the server connection:
>> >>>
>> >>>    [18645.013550] BUG: Dentry ffff888140590ba0{i=1000000000080,n=/}  still in use (2) [unmount of cifs cifs]
>> >>>    [18645.789274] VFS: Busy inodes after unmount of cifs (cifs)
>> >>>
>> >>>Based on bisection, these issues started with the lease directory cache
>> >>>handling introduced in commit ebe98f1447bb ("cifs: enable caching of
>> >>>directories for which a lease is held"), and go away if I mount with
>> >>>'nohandlecache'.  I started seeing these on Debian Bookworm stable kernel
>> >>>(v6.1.x), but the issues persist even in current git versions.  I think the
>> >>>situation was improved (occurrence frequency went down) with
>> >>>commit 5c86919455c1 ("smb: client: fix use-after-free in
>> >>>smb2_query_info_compound()").
>> >>>
>> >>>
>> >>>I'm able to reproduce the "Dentry still in use" errors by connecting to an
>> >>>actively-used SMB share (the server organically generates lease breaks) and
>> >>>leaving these running for 'a while':
>> >>>
>> >>>- while true; do cd ~; sleep 1; for i in {1..3}; do cd /mnt/test/subdir; echo $PWD; sleep 1; cd ..; echo $PWD; sleep 1; done; echo ...; done
>> >>>- while true; do iptables -F OUTPUT; mount -t cifs -a; for _ in {0..2}; do ls /mnt/test/subdir/ | wc -l; done; iptables -I OUTPUT -p tcp --dport 445 -j DROP; sleep 10; echo "unmounting"; umount -l -t cifs -a; echo "done unmounting"; sleep 20; echo "recovering"; iptables -F OUTPUT; sleep 10; done
>> >>>
>> >>>('a while' is anywhere from 10 minutes to overnight. Also, it's not the
>> >>>cleanest reproducer, but I stopped iterating once I had something that was
>> >>>even remotely reliable for me...)
>> >>>
>> >>>This series attempts to fix these, as well as a use-after-free that could
>> >>>occur because open_cached_dir() explicitly frees the cached_fid, rather than
>> >>>relying on reference counting.
>> >>>
>> >>>
>> >>>The last patch in this series (smb: During umount, flush any pending lease
>> >>>breaks for cached dirs) is a work-in-progress, and should not be taken as-is.
>> >>>The issue there:
>> >>>
>> >>>Unmounting an SMB share (cifs_kill_sb) can race with a queued lease break from
>> >>>the server for a cached directory.  When this happens, the cfid is removed
>> >>>from the linked list, so close_all_cached_dirs() cannot drop the dentry.  If
>> >>>cifs_kill_sb continues on before the queued work puts the dentry, we trigger
>> >>>the "Dentry still in use" BUG splat.  Flushing the cifsiod_wq seems to help
>> >>>this, but some thoughts:
>> >>>
>> >>>1. cifsiod_wq is a global workqueue, rather than per-mount.  Flushing the
>> >>>   entire workqueue is potentially doing more work that necessary.  Should
>> >>>   there be a workqueue that's more appropriately scoped?
>> >>>2. With an unresponsive server, this causes umount (even umount -l) to hang
>> >>>   (waiting for SMB2_close calls), and when I test with backports on a 6.1
>> >>>   kernel, appears to cause a deadlock between kill_sb and some cifs
>> >>>   reconnection code calling iterate_supers_type.  (Pretty sure the deadlock
>> >>>   was addressed by changes to fs/super.c, so not really an SMB problem, but
>> >>>   just an indication that flush_waitqueue isn't the right solution).
>> >>>3. Should cached_dir_lease_break() drop the dentry before queueing work
>> >>>   (and if so, is it OK to do this under the spinlock, or should the spinlock
>> >>>   be dropped first)?
>> >>>4. Related to #3 -- shouldn't close_all_cached_dirs() be holding the spinlock
>> >>>   while looping?
>> >>>
>> >>>
>> >>>Lastly, patches 2, 3, and 5 (in its final form) are beneficial going back to
>> >>>v6.1 for stable, but it's not a clean backport because some other important
>> >>>fixes (commit 5c86919455c1 ("smb: client: fix use-after-free in
>> >>>smb2_query_info_compound()") weren't picked up.
>> >>>
>> >>>Paul Aurich (5):
>> >>>  smb: cached directories can be more than root file handle
>> >>>  smb: Don't leak cfid when reconnect races with open_cached_dir
>> >>>  smb: prevent use-after-free due to open_cached_dir error paths
>> >>>  smb: No need to wait for work when cleaning up cached directories
>> >>>  smb: During umount, flush any pending lease breaks for cached dirs
>> >>>
>> >>> fs/smb/client/cached_dir.c | 106 ++++++++++++++++---------------------
>> >>> 1 file changed, 47 insertions(+), 59 deletions(-)
>> >>>
>> >>>--
>> >>>2.45.2
>> >>>
>> >>>
>> >>
>> >>
>> >>--
>> >>Thanks,
>> >>
>> >>Steve
>> >
>> >
>
>
>
>--
>Thanks,
>
>Steve
>