[Bug 276660] vnode_init can take several minutes to complete

https://bugs.freebsd.org/bugzilla/show_bug.cgi?id=276660

            Bug ID: 276660
           Summary: vnode_init can take several minutes to complete
           Product: Base System
           Version: 13.2-STABLE
          Hardware: amd64
                OS: Any
            Status: New
          Severity: Affects Only Me
          Priority: ---
         Component: kern
          Assignee: bugs@FreeBSD.org
          Reporter: jfc@mit.edu

Occasionally a process on my 13.2 server will get stuck in vnode_init for 5-15
minutes.

^T says the stack trace is constant but the process is accumulating CPU time:

load: 28.91  cmd: git 7038 [running] 430.92r 0.00u 425.79s 100% 6908k
__mtx_lock_sleep+0xf8 __mtx_lock_flags+0x9d vnode_init+0xc3
keg_alloc_slab+0x277 zone_import+0x143 cache_alloc+0x3ed cache_alloc_retry+0x23
getnewvnode_reserve+0x20 zfs_zget+0x1f zfs_dirent_lookup+0x16d zfs_dirlook+0x7f
zfs_lookup+0x3e0 zfs_freebsd_cachedlookup+0x74 vfs_cache_lookup+0xa7
cache_fplookup_noentry+0x23e cache_fplookup+0x565 namei+0x1e9
kern_accessat+0x195 

This is the context of the mtx_lock call from vnode_init:

        vp->v_holdcnt = VHOLD_NO_SMR;
        vp->v_type = VNON;
        mtx_lock(&vnode_list_mtx);
        TAILQ_INSERT_BEFORE(vnode_list_free_marker, vp, v_vnodelist);
        mtx_unlock(&vnode_list_mtx);
        return (0);

When this happened last October I posted to the freebsd-fs list[1].  Mateusz
Guzik[2] described the root cause: "That codepath which appeared stalled may
very well have been making
progress.  There is an API deficiency in UMA where it calls the
constructor/destructor for each object separately."

[1]https://lists.freebsd.org/archives/freebsd-fs/2023-October/002693.html
[2]https://lists.freebsd.org/archives/freebsd-fs/2023-October/002701.html

My system is a 24 core / 48 thread AMD EPYC 7402P.  Memory stats reported by
top are

Mem: 3784M Active, 79G Inact, 15G Laundry, 47G Wired, 739M Buf, 12G Free
ARC: 34G Total, 19G MFU, 11G MRU, 3584K Anon, 3870M Header, 239M Other
     28G Compressed, 33G Uncompressed, 1.19:1 Ratio
Swap: 64G Total, 3439M Used, 61G Free, 5% Inuse

There are also two find processes started by cron apparently exhibiting the
same behavior, runnable with large CPU time instead of waiting on I/O.

Interesting sysctl values are:

vm.uma.VNODE.bucket_size: 121
vfs.vnode.vnlru.uma_reclaim_calls: 0
vfs.vnode.vnlru.kicks: 0
vfs.vnode.vnlru.max_free_per_call: 10000
vfs.vnode.vnlru.failed_runs: 0
vfs.vnode.vnlru.direct_recycles_free: 74572815
vfs.vnode.vnlru.recycles_free: 37066685
vfs.vnode.vnlru.recycles: 0
vfs.vnode.stats.alloc_sleeps: 0
vfs.vnode.stats.free: 648453
vfs.vnode.stats.skipped_requeues: 6851950
vfs.vnode.stats.created: 116854230
vfs.vnode.stats.count: 973318
vfs.vnode.param.wantfree: 681059
vfs.vnode.param.limit: 2724237

-- 
You are receiving this mail because:
You are the assignee for the bug.