MORI-IO: CPU hot-path improvements (profile-guided)

[pemeliya]

Summary

Profile-guided reduction of per-operation CPU overhead on the RDMA IO path. A
CPU flame-graph of the completion/submission path surfaced several avoidable
costs on the busy-poll and submit hot paths: per-poll locking, per-spin heap
allocation + snapshot rebuilds, per-op hash-map churn in the submission ledger,
and always-on telemetry timing. This change removes all of them with no change
to the public API, ABI, or wire protocol.

The net effect is lower CPU cost per transfer, which shows up as higher
throughput (and correspondingly lower latency) in the CPU-overhead-bound
regimes, with no regressions elsewhere.

Extracted from #506 with minor adaptions

What changed

1. Lockless notif-context resolution in the CQ poller.
   ProcessOneCqe() previously took NotifManager::mu on every poll just to
   look up the endpoint's QpNotifContext. The context is now published once at
   registration (EndpointRuntime::notifCtx, an atomic<void*> with
   release/acquire) and read locklessly in the poll loop. The backing map is
   node-based, so the cached pointer stays valid across rehashes.

2. Epoch-gated endpoint snapshot (no per-spin lock/alloc).
   The POLLING MainLoop rebuilt the endpoint snapshot every spin — taking a
   shared_lock and heap-allocating a vector on each iteration of a tight
   busy-poll. A monotonic endpointsEpoch_ counter is bumped when the endpoint
   set changes; the loop now caches the snapshot and only rebuilds when the
   epoch moves. SnapshotEndpointRuntimes() fills a caller-owned vector to
   avoid the per-call allocation.

3. Allocation-free submission ledger (ring instead of hash map).
   SubmissionLedger replaced its std::unordered_map<uint64_t, SubmissionRecord> — which allocated/erased a node per WR — with a fixed
   power-of-two ring indexed by recordId & capMask_. Admission control bounds
   live records by maxSqDepth, and the ring is sized strictly above that (with
   slack + floor), so a slot never aliases a live record.
   Insert/ReleaseByCqe/ReleaseOrphaned* are now allocation-free; the
   sqDepth atomic update was also moved outside the lock.

4. Sampled (near-zero-cost when off) telemetry timers.
   ScopedTimer / MORI_TIMER / MORI_FUNCTION_TIMER now capture timestamps
   only when the module's debug logging is actually enabled, gated with
   MORI_UNLIKELY. When telemetry is off the timers compile down to a
   predicted-not-taken branch, so they no longer cost anything on the hot path.

5. MORI_LIKELY / MORI_UNLIKELY branch hints.
   Added portable __builtin_expect wrappers
   (include/mori/core/utils/utils.hpp) used on the cold paths above. Also
   fixed a warpSize macro collision so the header parses under host
   compilation.

Benchmark setup

• Two-node RoCE cluster: p20-05 (initiator) ↔ p20-14 (target).
• 8 initiator ranks, telemetry OFF, 5 repetitions (metrics averaged
  across all ranks and reps).
• Baseline = 34f17d69, "improved" = this change (13f6fcd9).
• avgBW / maxBW in GB/s (higher is better); avgLat in µs (lower is
  better). ΔBW% positive = faster; ΔLat% negative = faster.

Preset configurations

All presets are driven through tools/run_telemetry_ab_cluster.sh →
tests/python/io/benchmark.py. Common to all three: --op-type write,
--enable-sess, --enable-batch-transfer, --num-initiator-dev 8,
--num-target-dev 8, telemetry OFF, 8 initiator ranks.

Parameter	mw-chunkoff	mw-chunkon	hi-iops
Chunking	OFF (--disable-chunking)	ON (default)	OFF (--disable-chunking)
Worker threads (--num-worker-threads)	2	4	8
QPs per transfer (--num-qp-per-transfer)	4	4	8
Transfer batch size (--transfer-batch-size)	64	64	256
Message size	sweep --all	sweep --all	fixed --buffer-size 512
Sweep range	1 KB – 16 MB	1 KB – 16 MB	(no sweep)
Iterations (--iters)	128	256	512

What each stresses:

• mw-chunkoff — chunking off means every transfer is its own signaled WR,
  maximizing per-signaled-WR ledger-mutex round-trips and record churn.
• mw-chunkon — 4 workers × 4 QP is the highest cross-thread contention on
  the shared ledger/telemetry state; the most CPU-overhead-sensitive regime.
• hi-iops — tiny fixed 512 B messages, batch 256, chunking off ⇒ ~256 CQEs
  per transfer batch, maximizing completions/sec (completion-bound peak IOPS).

Exact benchmark argument vectors used for this dataset:

mw-chunkoff:
  --op-type write --disable-chunking --transfer-batch-size 64 --all \
  --sweep-start-size 1024 --sweep-max-size 16777216 --iters 128 \
  --enable-sess --enable-batch-transfer \
  --num-qp-per-transfer 4 --num-worker-threads 2 \
  --num-initiator-dev 8 --num-target-dev 8

mw-chunkon:
  --op-type write --transfer-batch-size 64 --all \
  --sweep-start-size 1024 --sweep-max-size 16777216 --iters 256 \
  --enable-sess --enable-batch-transfer \
  --num-qp-per-transfer 4 --num-worker-threads 4 \
  --num-initiator-dev 8 --num-target-dev 8

hi-iops:
  --op-type write --disable-chunking --buffer-size 512 \
  --transfer-batch-size 256 --iters 512 \
  --enable-sess --enable-batch-transfer \
  --num-qp-per-transfer 8 --num-worker-threads 8 \
  --num-initiator-dev 8 --num-target-dev 8

---

mw-chunkoff

2 workers, 4 QP, chunking OFF, --iters 128. Less CPU-bound; results are within
run-to-run noise — marginally positive at small sizes, flat elsewhere.

MsgSize (B)	avgBW base	avgBW impr	ΔBW%	maxBW base	maxBW impr	avgLat base (µs)	avgLat impr (µs)	ΔLat%
1024	1.78	1.85	+3.9	2.56	2.63	37.39	35.81	-4.2
2048	4.45	4.55	+2.2	5.18	5.42	29.99	29.44	-1.8
4096	8.35	8.42	+0.8	9.51	9.74	31.72	31.68	-0.1
8192	13.05	13.29	+1.8	15.73	15.65	40.62	39.81	-2.0
16384	17.95	18.14	+1.1	22.06	21.99	58.71	58.09	-1.1
32768	18.73	18.75	+0.1	24.55	24.14	112.07	112.00	-0.1
65536	18.70	18.64	-0.3	25.02	24.98	224.47	225.16	+0.3
131072	18.77	18.64	-0.7	25.57	25.37	447.20	450.29	+0.7
262144	18.54	18.44	-0.5	25.99	25.34	905.08	910.12	+0.6
524288	19.05	19.00	-0.3	26.25	25.94	1761.70	1766.53	+0.3
1048576	20.89	21.17	+1.3	26.31	26.34	3214.10	3172.37	-1.3
2097152	20.39	20.71	+1.6	26.64	26.69	6585.92	6487.49	-1.5
4194304	19.53	19.57	+0.2	25.99	25.93	13759.00	13724.53	-0.3
8388608	19.38	19.35	-0.2	26.31	26.24	27702.51	27755.53	+0.2
16777216	19.54	19.67	+0.7	26.46	26.40	54962.87	54621.20	-0.6

mw-chunkon

4 workers, 4 QP, chunking ON, --iters 256. The CPU-overhead-bound regime and
the clearest win: +2–7% throughput (and matching latency reduction) across
almost all sizes; converges to the network limit only at the largest sizes.

MsgSize (B)	avgBW base	avgBW impr	ΔBW%	maxBW base	maxBW impr	avgLat base (µs)	avgLat impr (µs)	ΔLat%
1024	1.74	1.81	+4.0	2.33	2.41	38.13	36.77	-3.6
2048	3.85	4.03	+4.7	4.64	4.86	34.66	33.17	-4.3
4096	7.47	7.82	+4.7	8.79	9.07	35.66	34.07	-4.5
8192	13.64	14.01	+2.7	15.72	16.14	38.79	37.77	-2.6
16384	18.13	18.51	+2.1	22.91	23.01	58.11	56.93	-2.0
32768	22.54	23.54	+4.4	30.43	30.86	93.98	89.81	-4.4
65536	26.70	28.29	+6.0	38.08	38.38	158.38	149.38	-5.7
131072	27.59	28.76	+4.2	42.20	42.61	307.17	294.08	-4.3
262144	29.71	30.90	+4.0	44.87	45.02	575.32	553.31	-3.8
524288	27.74	29.76	+7.3	46.37	46.17	1223.29	1145.98	-6.3
1048576	26.98	28.52	+5.7	47.55	47.16	2511.93	2389.17	-4.9
2097152	24.87	25.59	+2.9	47.88	47.80	5453.42	5294.91	-2.9
4194304	20.31	20.28	-0.1	43.55	38.16	13221.64	13242.75	+0.2
8388608	20.07	20.08	+0.0	34.36	34.92	26755.41	26741.47	-0.1
16777216	20.05	20.07	+0.1	26.93	27.08	53566.64	53504.56	-0.1

hi-iops

512 B messages, 8 workers, 8 QP, batch 256, chunking OFF, --iters 512.
Completion-bound peak-IOPS probe; flat (within noise).

MsgSize (B)	avgBW base	avgBW impr	ΔBW%	maxBW base	maxBW impr	avgLat base (µs)	avgLat impr (µs)	ΔLat%
512	2.07	2.06	-0.5	2.52	2.52	64.03	64.50	+0.7

---

Takeaways

• mw-chunkon (the CPU-overhead-bound regime) is the headline: consistent
  +2–7% bandwidth and a matching ~2–6% average-latency reduction across
  the mid-size band the workload spends most time in.
• mw-chunkoff and hi-iops are flat / within noise — expected, as those
  regimes are less gated on host-CPU overhead.
• No regressions in any preset.

Testing

• tests/cpp/io/test_engine.cpp: added coverage for the ledger ring behavior.
• tests/cpp/utils/test_logging.cpp: new tests for the sampled ScopedTimer.
• Full two-node RDMA benchmark sweep above (5 reps × 3 presets, telemetry OFF).

Risk / compatibility

• No public API, ABI, or wire-protocol changes.
• Ledger ring uses more memory per QP than the old map (capacity ≈ maxSqDepth
  rounded up to a power of two, min 256 slots); relevant only with very large
  maxSqDepth × many QPs.
• Lockless notif-context read relies on the node-based map keeping pointers
  stable across rehash (documented at the publish site).

https://cursor.com/dashboard/shared-canvases?shareId=canvas-eghrnfdog48yKE5SGxxfUXeM

[Copilot]

Pull request overview

This PR reduces CPU overhead in MORI’s RDMA I/O hot paths (CQ polling, submission tracking, and telemetry) by removing per-iteration locking/allocations and making logging/timing near-zero-cost when disabled.

Changes:

• Replaces the RDMA submission ledger’s per-WR unordered_map churn with a fixed-size ring buffer keyed by recordId.
• Avoids per-spin endpoint snapshot rebuilds by caching the snapshot and refreshing only when an epoch counter changes; also removes per-poll notif-context locking by publishing a stable pointer once.
• Makes logging macros and ScopedTimer faster on hot paths via call-site logger caching and conditional timestamp sampling; adds MORI_LIKELY / MORI_UNLIKELY helpers and new C++ tests.

Reviewed changes

Copilot reviewed 10 out of 10 changed files in this pull request and generated 1 comment.

Show a summary per file

File	Description
include/mori/utils/mori_log.hpp	Adds ModuleLogger locking, call-site logger caching, and sampled ScopedTimer behavior.
include/mori/core/utils/utils.hpp	Fixes warpSize macro collision under host compilation; adds MORI_LIKELY/UNLIKELY.
src/io/rdma/ledger.cpp	Implements allocation-free ring-based SubmissionLedger.
src/io/rdma/common.hpp	Updates SubmissionLedger API/storage and adds EndpointRuntime::notifCtx cache.
src/io/rdma/backend_impl.hpp	Adds snapshot type, epoch accessor, and epoch counter declaration.
src/io/rdma/backend_impl.cpp	Publishes notif context pointer, implements epoch-gated snapshot rebuild, wires maxSqDepth into ledger.
tests/cpp/utils/test_logging.cpp	Adds multithreaded stress tests for logging/thread-safety and first-touch behavior.
tests/cpp/io/test_engine.cpp	Adds wraparound/reuse coverage for the ledger ring behavior.
tests/cpp/CMakeLists.txt	Adds test_logging target and CTest registration.
CMakeLists.txt	Adds compiler-flag probing and warning suppression for deprecated fmt literal operator in spdlog consumers.

Suppressed comments (1)

include/mori/utils/mori_log.hpp:430

• ScopedTimer::ElapsedSeconds() now uses start_ even when the timer is disabled; since start_ is only set when enabled_, this can return a huge nonsensical duration if ElapsedSeconds() is called while DEBUG logging is off.

  double ElapsedSeconds() const {
    return std::chrono::duration<double>(Clock::now() - start_).count();
  }

---

💡 Add Copilot custom instructions for smarter, more guided reviews. Learn how to get started.

[Copilot]

Pull request overview

Copilot reviewed 10 out of 10 changed files in this pull request and generated no new comments.

Suppressed comments (2)

src/io/rdma/ledger.cpp:25

• std::abort() is used in this file, but <cstdlib> is not included. Relying on indirect includes for std::abort is non-portable and can break builds depending on header ordering/toolchain.

#include <algorithm>

#include "mori/io/logging.hpp"
#include "src/io/rdma/common.hpp"

include/mori/utils/mori_log.hpp:450

• MORI_TIMER / MORI_FUNCTION_TIMER currently expand to multiple top-level statements and inject _mori_timer_logger into the caller scope. This is fragile (e.g., breaks if (...) MORI_TIMER(...); else ... and can cause redeclaration errors if used more than once in a scope). Consider making each macro a single declaration statement and avoid introducing extra identifiers.

#define MORI_TIMER(name, module)                                    \
  static const std::shared_ptr<spdlog::logger> _mori_timer_logger = \
      ::mori::ModuleLogger::GetInstance().GetLogger(module);        \
  ::mori::ScopedTimer timer_instance(name, _mori_timer_logger.get())
#define MORI_FUNCTION_TIMER(module)                                 \
  static const std::shared_ptr<spdlog::logger> _mori_timer_logger = \
      ::mori::ModuleLogger::GetInstance().GetLogger(module);        \
  ::mori::ScopedTimer timer_instance(__PRETTY_FUNCTION__, _mori_timer_logger.get())

[maning00]

Thanks for the profiling and optimization work. I'm requesting changes because I don't think the current end-to-end evidence justifies the scope and risk of this hot-path rewrite.

At the moment, only mw-chunkon shows a measurable improvement (~2-7% in parts of the sweep). mw-chunkoff is mostly within noise, while hi-iops is slightly worse. Since the stated goal is reducing CPU overhead, bandwidth/latency alone are also insufficient: the PR does not report CPU utilization, cycles/op, or how much CPU capacity is actually released, and there is no per-change ablation.

There are also correctness/build blockers that must be addressed independently of performance:

• The ledger ring's capacity argument is invalid and can abort while the live-record count remains below maxSqDepth.
• Including utils.hpp from mori_log.hpp leaks the warpSize macro into HIP translation units and breaks valid header/include orders.
• The logger synchronization work conflicts with and partially duplicates the fix already merged in #528.

Before reconsidering this PR, please:

1. Rebase onto the latest main and retain the logger fix already merged there.
2. Fix the correctness/build blockers above.
3. Preferably drop the ring rewrite and narrow the PR to the low-risk snapshot/notif-context/timer changes.
4. Provide an ablation against the latest main, including direct CPU-overhead metrics and repeated results on pre-selected representative workloads.

For the full hot-path rewrite, I would expect a material and repeatable benefit—roughly >=10% end-to-end improvement on a representative workload, or >=20% lower CPU cost at equal throughput—with no meaningful regressions elsewhere. If that cannot be demonstrated, I would prefer closing this PR rather than merging additional hot-path complexity for a marginal gain. A smaller follow-up PR containing only independently justified changes would be welcome.