aboutsummaryrefslogtreecommitdiff
path: root/src
diff options
context:
space:
mode:
authorSulfurNitride <SulfurNitride@users.noreply.github.com>2026-04-13 00:09:15 -0500
committerSulfurNitride <SulfurNitride@users.noreply.github.com>2026-04-13 00:09:15 -0500
commitf46fb43659c36b6a7a121e91c4666f488cffa5d7 (patch)
tree48937211b44e07260f95936d26e06178c80c8315 /src
parent3949dcfce95af4bd305f258ff5b170d7d50435f6 (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.cpp41
-rw-r--r--src/src/vfs/mo2filesystem.h6
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;