diff options
| author | SulfurNitride <SulfurNitride@users.noreply.github.com> | 2026-04-13 00:09:15 -0500 |
|---|---|---|
| committer | SulfurNitride <SulfurNitride@users.noreply.github.com> | 2026-04-13 00:09:15 -0500 |
| commit | f46fb43659c36b6a7a121e91c4666f488cffa5d7 (patch) | |
| tree | 48937211b44e07260f95936d26e06178c80c8315 /src | |
| parent | 3949dcfce95af4bd305f258ff5b170d7d50435f6 (diff) | |
VFS: log process CPU + RSS alongside op stats
Adds per-tick rusage snapshot (user/sys seconds, delta since last
tick, wall delta, busy%, max RSS) to the [VFS] stats lines so we
can tell CPU-bound from IO-bound slowness without external tools.
Co-Authored-By: Claude Opus 4.6 (1M context) <noreply@anthropic.com>
Diffstat (limited to 'src')
| -rw-r--r-- | src/src/vfs/mo2filesystem.cpp | 41 | ||||
| -rw-r--r-- | src/src/vfs/mo2filesystem.h | 6 |
2 files changed, 47 insertions, 0 deletions
diff --git a/src/src/vfs/mo2filesystem.cpp b/src/src/vfs/mo2filesystem.cpp index ecae325..7dab850 100644 --- a/src/src/vfs/mo2filesystem.cpp +++ b/src/src/vfs/mo2filesystem.cpp @@ -103,6 +103,47 @@ void maybeLogCounters(Mo2FsContext* ctx) ons / 1e6, avgUs(ons, oc), rdns / 1e6, avgUs(rdns, rdc)); + // Process-wide CPU usage + delta since last tick. Lets us tell whether + // high per-op wall time is spent burning CPU (parsing, mutex contention) + // or blocked on disk IO (delta CPU ≪ delta wall). + { + struct rusage ru{}; + if (::getrusage(RUSAGE_SELF, &ru) == 0) { + const uint64_t user_us = + static_cast<uint64_t>(ru.ru_utime.tv_sec) * 1000000ull + + static_cast<uint64_t>(ru.ru_utime.tv_usec); + const uint64_t sys_us = + static_cast<uint64_t>(ru.ru_stime.tv_sec) * 1000000ull + + static_cast<uint64_t>(ru.ru_stime.tv_usec); + const uint64_t now_ns = static_cast<uint64_t>( + std::chrono::duration_cast<std::chrono::nanoseconds>( + std::chrono::steady_clock::now().time_since_epoch()) + .count()); + + const uint64_t prev_user = + ctx->last_cpu_user_us.exchange(user_us, std::memory_order_relaxed); + const uint64_t prev_sys = + ctx->last_cpu_sys_us.exchange(sys_us, std::memory_order_relaxed); + const uint64_t prev_wall = + ctx->last_tick_wall_ns.exchange(now_ns, std::memory_order_relaxed); + + const double d_user_s = + prev_user == 0 ? 0.0 : (user_us - prev_user) / 1e6; + const double d_sys_s = + prev_sys == 0 ? 0.0 : (sys_us - prev_sys) / 1e6; + const double d_wall_s = + prev_wall == 0 ? 0.0 : (now_ns - prev_wall) / 1e9; + const double busy_pct = + d_wall_s > 0.0 ? ((d_user_s + d_sys_s) / d_wall_s) * 100.0 : 0.0; + + const long rss_mb = ru.ru_maxrss / 1024; // ru_maxrss is KB on Linux + std::fprintf( + stderr, + "[VFS] cpu user=%.2fs sys=%.2fs (Δuser=%.2fs Δsys=%.2fs Δwall=%.2fs busy=%.1f%%) rss=%ldMB\n", + user_us / 1e6, sys_us / 1e6, d_user_s, d_sys_s, d_wall_s, busy_pct, rss_mb); + } + } + auto logTop = [](const char* label, const std::unordered_map<std::string, uint64_t>& m) { if (m.empty()) { return; diff --git a/src/src/vfs/mo2filesystem.h b/src/src/vfs/mo2filesystem.h index 624b330..aa248ed 100644 --- a/src/src/vfs/mo2filesystem.h +++ b/src/src/vfs/mo2filesystem.h @@ -122,6 +122,12 @@ struct Mo2FsContext std::atomic<uint64_t> readdir_ns{0}; std::atomic<uint64_t> open_ns{0}; std::atomic<uint64_t> read_ns{0}; + // CPU snapshot from previous stats tick (microseconds, from getrusage). + // Used to compute per-tick CPU delta so we can distinguish disk-bound vs + // CPU-bound slowness in the VFS layer. + std::atomic<uint64_t> last_cpu_user_us{0}; + std::atomic<uint64_t> last_cpu_sys_us{0}; + std::atomic<uint64_t> last_tick_wall_ns{0}; std::unordered_map<std::string, uint64_t> lookup_hit_paths; std::unordered_map<std::string, uint64_t> lookup_miss_paths; std::unordered_map<std::string, uint64_t> getattr_paths; |
