Record the slot path's stages with latrec instead of a per-slot CSV - #6
Draft
Thecave3 wants to merge 1 commit into
Draft
Record the slot path's stages with latrec instead of a per-slot CSV#6Thecave3 wants to merge 1 commit into
Thecave3 wants to merge 1 commit into
Conversation
The per-slot stage CSV opened an ofstream, wrote a row and flushed it,
once per slot, inside the sample handler. A synchronous formatted write
plus a flush on the slot path costs far more than the intervals it was
recording, so every number it produced included the cost of producing
it. Measured: ~1840 ns per slot against ~111 ns for the five records
that replace it, or roughly 17x.
It also documented a mechanism that does not exist: README and two
source comments described downstream send stages as joinable through a
libe3 `--pub-stages-log` option. There is no such option in libe3 on
any branch, so the send side was simply unmeasured.
Stamp the same boundaries into latrec instead - one clock read and four
stores into an mmap-backed ring, no syscall, allocation, formatting,
lock or I/O on the slot path. The mapping onto the shared stage catalog
lives in one header, l1_kpm_trace.h, which the handler and the bench
both use, so what CI measures is the code that runs on the radio:
A1 RECORD_BEGIN -> PROCESS_BEGIN the data recording
A2 PROCESS_BEGIN -> ENCODE_E3SM_BEGIN getting it to the SM
A3 ENCODE_E3SM_BEGIN -> ENCODE_E3SM_DONE E3SM encode
ENCODE_E3SM_DONE -> WAIT_ENTER the emit tail
A1 and A2 are recorded here, and the gNB needs no instrumentation for
it. Both of A1's boundaries are already on the wire when the slot
arrives: gnb_ts_ns is stamped on the last symbol with the grid complete
and nothing copied, and codelet_ts_ns just before the codelet submits.
So the controller back-dates those two stamps rather than the RAN
keeping a ring of its own. That is sound because the whole chain reads
CLOCK_MONOTONIC now - the hook, jbpf_time_get_ns() and the dispatcher
poll - which is latrec's own clock, so there is no domain conversion.
What still has to hold is the ring's own invariant: a single-writer log
whose t_ns ascends, whose one permitted descent libe3's reader treats as
the wrap point and silently rotates at. Program order gives a wide
margin (the jbpf hook is a synchronous inline call, and A1 is tens of
microseconds against a >=500 us slot spacing), but a pipeline stall or
several sectors interleaving on one ring would break it. So the floor is
enforced per thread and the count of enforced stamps is reported, in the
drop CSV and the shutdown summary - a non-zero count means A1 is
understated for that many slots.
Four sub-hops stay recoverable from aux payloads, which is what keeps
jbpf dispatch separable from the data movement, and preserves the
distinction the codelet's entry/exit timestamp split was added for.
Correct the two timestamp comments. codelet_ts_ns was documented as a
"codelet entry timestamp" whose interval with gnb_ts_ns was "jbpf
invocation + verifier path overhead". It is stamped last, not at entry;
the interval is A1, the data recording itself, dominated by the convert
and the row write; and there is no runtime verifier cost at all, since
the gNB loads through ubpf whose JIT emits no bounds checks and
verification is an offline build-time gate. gnb_ts_ns said
CLOCK_REALTIME in three places and no longer is.
Replace the CSV's option with logging.latrec_dir, which is placement
only: whether anything is recorded is decided when libe3 is built, by
-DLIBE3_ENABLE_LATREC (./build.sh --latrec). Keep the throttled
drop-accounting CSV - it is aggregate and <=1/s, so it is not the thing
that perturbed. The legacy eCPRI SM keeps its own stage CSV under its
own key; it is a different data path and has the same problem, to be
fixed when that path is next touched.
Move the libe3 pin to 22f3918 (0.1.2), a fast-forward. Its message-id
work surfaces the assigned id to a dApp calling send_control/send_report
but not on the Service Model emit path, so origin_seq remains the only
cross-component join.
Drop the BOOLEAN skeleton staging from build.sh. It existed to have
libe3 compile asn_DEF_BOOLEAN for Spectrum-ConfigControl; that type is
no longer compiled and nothing references the symbol, so the staging had
nothing left to supply while still aborting the build on any host
without asn1c's reference skeletons.
Add CI, which this repository had none of. It builds both ways, asserts
that an untraced binary links no latrec symbols and carries no ring
registry, runs the recording-cost bench, and converts a capture with
libe3's own tool to check the ring role maps to the intended component,
the source leg is complete, the emit-tail hop column materialises, and
nothing wrapped.
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
Closes #4. Rebased onto
tests/native-memcpy.Draft on purpose. One of several repositories moving to the shared stage recorder at once; each lands as a draft, and the assembled system gets validated together afterwards. Nothing here has run against a radio — see Not done.
What the rebase changed, and why it was not mechanical
tests/native-memcpyrewrites the data path this change instruments: the codelet's 733 KB memcpy is gone (descriptor-only, ~64 B), the gNB converts and writes the shared-memory row itself under the defaultshm.writer: gnb, all CLI flags collapse into one--config <file.yaml>, and the codelet's single timestamp is split intocodelet_entry_ts_nsandcodelet_ts_ns. So this was re-derived against the new code rather than merged into it.Most of that helped. In particular the branch moves the whole RAN-side chain to
CLOCK_MONOTONIC— the gNB hook,jbpf_time_get_ns()and the dispatcher poll — which is latrec's own clock. That is what makes the A1/A2 mapping below possible; the previous revision of this PR had to carry those timestamps asauxpayloads and reconstruct them offline precisely because they were in a different domain.A1 and A2 are recorded here — the gNB needs no instrumentation
Both of A1's boundaries are already on the wire when a slot arrives, so the controller replays them instead of the RAN keeping a ring of its own:
RECORD_BEGIN→PROCESS_BEGINPROCESS_BEGIN→ENCODE_E3SM_BEGINENCODE_E3SM_BEGIN→ENCODE_E3SM_DONEENCODE_E3SM_DONE→WAIT_ENTERRECORD_BEGINis back-dated tognb_ts_ns(last symbol, grid complete, nothing copied) andPROCESS_BEGINtocodelet_ts_ns(just before the codelet submits). Four sub-hops stay recoverable fromauxpayloads, which keeps jbpf dispatch separable from the data movement and preserves the distinction the branch added the entry/exit split for.This is a real behavioural change from the previous revision, where A1 measured ≈ 0 by construction because both stamps were issued back-to-back at handler entry.
The ring invariant, and why there is a clamp
A ring is a single-writer log whose
t_nsmust ascend, and libe3's reader treats the one permitted descent as the wrap point and silently rotates there — a descent produces a plausible-looking capture cut at the wrong offset, not an error. Program order gives a wide margin (the jbpf hook is a synchronous inline call, and A1 is tens of µs against a ≥ 500 µs slot spacing), but a pipeline stall or several sectors interleaving on one ring would break it.So the floor is enforced per thread rather than assumed, and the count of enforced stamps is reported — in the drop CSV's
latrec_clampedcolumn and in the shutdown summary. A non-zero count means A1 is understated for that many slots. That guard immediately earned its keep: it caught a defect in the bench, which was seeding its synthetic clock fromCLOCK_REALTIMEwhile the now-stamps readCLOCK_MONOTONIC.The comments that were wrong
codelet_ts_nswas documented as a "codelet entry timestamp" whose interval withgnb_ts_nswas "jbpf invocation + verifier path overhead". Three errors:jbpf_send_output(), not at entry.gnb_ts_nsclaimedCLOCK_REALTIMEin three places and no longer does. It also never said what makes it A1 — last symbol, grid complete, before any copy — so that is now stated.The rest
22f3918(0.1.2), a genuine fast-forward from both the branch's pin and the previous one.latrec.h,tools/*.py,messages/and all ofcmake/bar the SWIG file are byte-identical, so the stage catalog, ring format andorigin_seqjoin are unchanged. Its message-id work surfaces the assigned id to a dApp callingsend_control/send_report, but not on the Service Model emit path — soorigin_seqremains the only cross-component join, and the claim in the docs stands with that qualifier. (Pin the SHA: the branch was force-pushed and a cached ref resolves to an abandoned lineage.)--stats-log→logging.latrec_dir, placement only; recording is decided at build time by--latrec.codelet_publish_usinsight is preserved in the stamps rather than in a CSV.build.sh. It existed to have libe3 compileasn_DEF_BOOLEANforSpectrum-ConfigControl; the branch stopped compiling that type, so the staging had nothing left to supply while still aborting the build on any host without asn1c's reference skeletons. Verified nothing references the symbol.writer: gnbthe controller moves no slot data, so it measured nothing this process does — and against real work the stamps were never resolvable anyway.What recording costs
Median of 15 batches, net of the loop floor,
-DUSE_NATIVE=OFF:Per record that is ~20–22 ns against a measured 22–28 ns clock read — the clock and essentially nothing else.
Compare within a host, never across one. The two CI legs are separate jobs and drew different runners — an EPYC 7763 and an Intel Xeon 6973P-C — where the
csvarm, identical code in both builds, differed by 2.7×. That arm is the calibration anchor: when it disagrees, nothing else in those two reports is comparable either. The untraced leg is further apart again becauselatrec_tnow()compiles toreturn 0there, so the bench's per-slot clock read vanishes and the loop floor collapses to ~1 ns.Verification
Everything below was run against a libe3 built from the actual pin into a scratch prefix, not
/usr/local— this workstation's/usr/localholds an older libe3, and trusting it is what let two broken build claims through on the previous revision.e3_controller+ bench), so the ASN.1 archive is actually linked — a bench-only build cannot catch a missing symbol.latrec2csv.py: 30,512 complete source-leg rows, filed under the intended component,wrapped=0,lost_records=0, no timestamp descents, zero clamps.auxpayload round-trips, and the four sub-hop subtractions are consistent.RECORD_BEGIN__PROCESS_BEGIN_usis now non-zero — the structural fix.latrecsymbols and carry no ring registry. Stated that way deliberately: the stronger "nolatrecsymbols at all" is build-dependent (the optimiser may leave local copies of the empty inline stubs), so CI asserts on global and undefined symbols plus the absence of the ring registry.stage recs: enabled -> <dir>, confirming the YAML →latrec_set_output_dir()path.Not done
mainonce libe3's latrec work merges.