Skip to content

Add optional [LAT] latency-profiling log points#46

Open
Thecave3 wants to merge 1 commit into
mainfrom
feature/e3ap-latency-instrumentation
Open

Add optional [LAT] latency-profiling log points#46
Thecave3 wants to merge 1 commit into
mainfrom
feature/e3ap-latency-instrumentation

Conversation

@Thecave3

Copy link
Copy Markdown
Collaborator

What

Compile-gated [LAT] log markers on the E3 send / receive / dispatch boundaries, so the end-to-end critical path can be measured offline from interleaved logs — no wire or schema change.

How

  • New include/libe3/latency.hppE3_LAT / E3_LAT_CLOCK_OFFSET macros emitting one machine-parseable INFO line:
    [LAT] stage=<name> t_ns=<monotonic ns> anchor_ns=<producer_ts|0> [k=v ...]
    
    t_ns uses steady_clock (== CLOCK_MONOTONIC on glibc), so it subtracts directly against same-node C timestamps. When disabled the macros collapse to a dead NullLatSink chain (zero cost).
  • New CMake option LIBE3_ENABLE_LATENCY (default OFF) → defines LIBE3_LATENCY on both library targets. Gating is the compile switch, not the log level — a profiling run does not have to raise the logger to DEBUG.
  • src/core/e3_interface.cpp: ind_wire_tx (outbound send), ctrl_wire_rx (inbound control off the wire), ctrl_dispatch (handoff to the SM), plus a per-process clock_offset marker at inbound-loop start.

Enabling

./build_libe3 --install --cmake-opt "-DLIBE3_ENABLE_LATENCY=ON"

Testing

Default builds are unaffected (macros expand away). With the option on, [LAT] lines appear at INFO for each boundary plus one clock_offset line at startup.

@github-actions

github-actions Bot commented Jul 23, 2026

Copy link
Copy Markdown
Contributor

⏱️ Full-loop Latency Benchmark (commit a4c1818)

Full-loop latency benchmark (N=1038 after 50 warmup)

All values in microseconds (us). Link: zmq, transport: ipc, encoding: ASN.1 APER.

Phase mean p50 p99 max
1. Collect indication data 0.10 0.11 0.28 1.28
2. Create & encode indication 0.52 0.45 1.22 13.34
3. Deliver indication (RAN -> dApp) 81.48 75.28 142.93 153.04
4. Decode indication 0.31 0.25 0.94 8.73
5. Process data 0.02 0.02 0.03 0.13
6. Create & encode control 0.22 0.17 0.60 2.81
7. Deliver control (dApp -> RAN) 90.17 85.82 152.12 163.68
8. Decode & handle control 0.29 0.24 0.95 10.93
Total round-trip 173.11 134.66 252.68 274.21

Benchmarked on ubuntu-latest, Release build, ZMQ + IPC, ASN.1 APER.

@github-actions

github-actions Bot commented Jul 23, 2026

Copy link
Copy Markdown
Contributor

🔄 E2E dApp Integration Results (commit a4c1818)

posix/ipc

  • dApp exit: 0
  • Indications received: 7

posix/tcp

  • dApp exit: 0
  • Indications received: 7

zmq/ipc

  • dApp exit: 0
  • Indications received: 7

zmq/tcp

  • dApp exit: 0
  • Indications received: 7

example_simple_agent + example_simple_dapp on ubuntu-latest, Release build

@github-actions

github-actions Bot commented Jul 23, 2026

Copy link
Copy Markdown
Contributor

🔀 E2E Topologies — multi-dApp / multi-RAN (commit a4c1818)

zmq/ipc

  • 1 RAN - 1 dApp: indications=5
    • dapp peer=t11 ran=ran-solo sub=1 indications=5 seq=[0..4] dropped=0 (0%) age_ms(avg=0 max=0 @seq=0) hist[<=1:5 2-5:0 6-10:0 >10:0]
  • 1 RAN - 2 dApps: dApp#1 ind=5 sub=1, dApp#2 ind=6 sub=2, RAN saw 2 dApps
    • dapp1 peer=t12 ran=ran-shared sub=1 indications=5 seq=[0..4] dropped=0 (0%) age_ms(avg=0 max=0 @seq=0) hist[<=1:5 2-5:0 6-10:0 >10:0]
    • dapp2 peer=t12 ran=ran-shared sub=2 indications=6 seq=[0..5] dropped=0 (0%) age_ms(avg=0 max=0 @seq=0) hist[<=1:6 2-5:0 6-10:0 >10:0]
  • 2 RANs - 1 dApp: from ran-a ind=5, from ran-b ind=5
    • dapp peer=t2a ran=ran-a sub=1 indications=5 seq=[0..4] dropped=0 (0%) age_ms(avg=0 max=0 @seq=0) hist[<=1:5 2-5:0 6-10:0 >10:0]
    • dapp peer=t2b ran=ran-b sub=1 indications=5 seq=[0..4] dropped=0 (0%) age_ms(avg=0 max=0 @seq=0) hist[<=1:5 2-5:0 6-10:0 >10:0]

zmq/tcp

  • 1 RAN - 1 dApp: indications=5
    • dapp peer=default ran=ran-solo sub=1 indications=5 seq=[0..4] dropped=0 (0%) age_ms(avg=0 max=0 @seq=0) hist[<=1:5 2-5:0 6-10:0 >10:0]
  • 1 RAN - 2 dApps: dApp#1 ind=5 sub=1, dApp#2 ind=6 sub=2, RAN saw 2 dApps
    • dapp1 peer=default ran=ran-shared sub=1 indications=5 seq=[0..4] dropped=0 (0%) age_ms(avg=0 max=0 @seq=0) hist[<=1:5 2-5:0 6-10:0 >10:0]
    • dapp2 peer=default ran=ran-shared sub=2 indications=6 seq=[0..5] dropped=0 (0%) age_ms(avg=0 max=0 @seq=0) hist[<=1:6 2-5:0 6-10:0 >10:0]
  • 2 RANs - 1 dApp: from ran-a ind=5, from ran-b ind=5
    • dapp peer=default ran=ran-a sub=1 indications=5 seq=[0..4] dropped=0 (0%) age_ms(avg=0 max=0 @seq=0) hist[<=1:5 2-5:0 6-10:0 >10:0]
    • dapp peer=off100 ran=ran-b sub=1 indications=5 seq=[0..4] dropped=0 (0%) age_ms(avg=0 max=0 @seq=0) hist[<=1:5 2-5:0 6-10:0 >10:0]

example_simple_agent + example_simple_dapp on ubuntu-latest, Release. Indication age is report-only.

Compile-gated log markers on the E3 send/receive/dispatch boundaries so the
end-to-end critical path can be measured offline from interleaved logs, without
any wire/schema change.

- New include/libe3/latency.hpp: E3_LAT / E3_LAT_CLOCK_OFFSET macros emitting a
  single machine-parseable INFO line
  ([LAT] stage=<name> t_ns=<monotonic ns> anchor_ns=<producer_ts|0> [k=v ...]).
  t_ns uses steady_clock (== CLOCK_MONOTONIC on glibc) so it subtracts directly
  against same-node C timestamps. When disabled the macros collapse to a
  dead NullLatSink chain (zero cost).
- New CMake option LIBE3_ENABLE_LATENCY (default OFF) -> defines LIBE3_LATENCY
  on both library targets. Gating is the compile switch, not the log level.
- e3_interface.cpp: ind_wire_tx (outbound send), ctrl_wire_rx (inbound control
  off the wire) and ctrl_dispatch (handoff to the SM), plus a per-process
  clock_offset marker at inbound-loop start for future cross-node alignment.
@Thecave3
Thecave3 force-pushed the feature/e3ap-latency-instrumentation branch from 209dd6d to a4c1818 Compare July 23, 2026 19:52
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant