From fb7c0557bc3f9eb815e21a9da990fb13e60cfbb9 Mon Sep 17 00:00:00 2001 From: Jason E Plumb Date: Wed, 16 Sep 2026 21:36:24 -0700 Subject: [PATCH 1/2] feat(docs): design write-up with measured overhead docs/design.md records the core contracts, the suppression and immortality rationale, the backend and emitter trade-offs, measured per-event costs, and stated limits. bench/overhead_bench measures the scope macro and compiler instrumentation against untraced twins of the same work. Closes #4 Co-Authored-By: Claude Fable 5 --- CMakeLists.txt | 4 ++ bench/CMakeLists.txt | 13 ++++ bench/overhead_bench.cpp | 108 ++++++++++++++++++++++++++++++++ bench/overhead_fib.cpp | 12 ++++ docs/design.md | 131 +++++++++++++++++++++++++++++++++++++++ 5 files changed, 268 insertions(+) create mode 100644 bench/CMakeLists.txt create mode 100644 bench/overhead_bench.cpp create mode 100644 bench/overhead_fib.cpp create mode 100644 docs/design.md diff --git a/CMakeLists.txt b/CMakeLists.txt index 6edb31d..9ed5f8b 100644 --- a/CMakeLists.txt +++ b/CMakeLists.txt @@ -41,4 +41,8 @@ if(PROJECT_IS_TOP_LEVEL) if(CYCLESCOPE_BUILD_EXAMPLES AND NOT MSVC) add_subdirectory(examples) endif() + option(CYCLESCOPE_BUILD_BENCH "Build cyclescope benchmarks" ON) + if(CYCLESCOPE_BUILD_BENCH AND NOT MSVC) + add_subdirectory(bench) + endif() endif() diff --git a/bench/CMakeLists.txt b/bench/CMakeLists.txt new file mode 100644 index 0000000..9479792 --- /dev/null +++ b/bench/CMakeLists.txt @@ -0,0 +1,13 @@ +add_executable(overhead_bench overhead_bench.cpp overhead_fib.cpp) +set_source_files_properties(overhead_fib.cpp PROPERTIES + COMPILE_OPTIONS "-finstrument-functions") +target_link_libraries(overhead_bench PRIVATE cyclescope::cyclescope + cyclescope::instrument) +target_compile_options(overhead_bench PRIVATE -Wall -Wextra) +set_target_properties(overhead_bench PROPERTIES ENABLE_EXPORTS ON) +if(CYCLESCOPE_SANITIZE) + target_compile_options(overhead_bench PRIVATE + -fsanitize=${CYCLESCOPE_SANITIZE} -g -fno-omit-frame-pointer) + target_link_options(overhead_bench PRIVATE + -fsanitize=${CYCLESCOPE_SANITIZE}) +endif() diff --git a/bench/overhead_bench.cpp b/bench/overhead_bench.cpp new file mode 100644 index 0000000..a1b373a --- /dev/null +++ b/bench/overhead_bench.cpp @@ -0,0 +1,108 @@ +// Per-event cost of the two tracing paths, measured as the difference +// against an untraced twin of the same work. This translation unit is +// compiled WITHOUT instrumentation; the instrumented fib twin lives in +// overhead_fib.cpp. +// +// Usage: overhead_bench [scope_iterations] [fib_n] + +#include +#include +#include +#include +#include + +extern "C" long cyclescope_bench_fib_instrumented(int n); + +namespace { + +using bench_clock = std::chrono::steady_clock; + +double seconds_since(bench_clock::time_point start) { + return std::chrono::duration(bench_clock::now() - start).count(); +} + +__attribute__((noinline)) long fib_plain(int n) { + return n < 2 ? n : fib_plain(n - 1) + fib_plain(n - 2); +} + +// Total calls made by the recursive fib: 2 * fib(n + 1) - 1. +long fib_call_count(int n) { + long a = 0; + long b = 1; + for (int i = 0; i < n + 1; ++i) { + const long next = a + b; + a = b; + b = next; + } + return 2 * b - 1; +} + +void measure_scope_macro(std::int64_t iterations) { + auto& collector = cyclescope::collector::instance(); + collector.clear(); + collector.set_capacity_per_thread( + static_cast(iterations) + 1024); + + const auto baseline_start = bench_clock::now(); + for (std::int64_t i = 0; i < iterations; ++i) { + asm volatile(""); + } + const double baseline = seconds_since(baseline_start); + + const auto traced_start = bench_clock::now(); + for (std::int64_t i = 0; i < iterations; ++i) { + CYCLESCOPE_SCOPE("overhead"); + } + const double traced = seconds_since(traced_start); + + std::printf("scope macro %8.1f ns/event (%lld events, %.3f s)\n", + (traced - baseline) / static_cast(iterations) * 1e9, + static_cast(iterations), traced); + collector.clear(); + collector.set_capacity_per_thread(std::size_t{1} << 20); +} + +void measure_instrumentation(int fib_n) { + auto& collector = cyclescope::collector::instance(); + collector.clear(); + const long calls = fib_call_count(fib_n); + collector.set_capacity_per_thread(static_cast(calls) + 1024); + + const auto plain_start = bench_clock::now(); + const long plain_result = fib_plain(fib_n); + const double plain = seconds_since(plain_start); + + const auto traced_start = bench_clock::now(); + const long traced_result = cyclescope_bench_fib_instrumented(fib_n); + const double traced = seconds_since(traced_start); + + if (plain_result != traced_result) { + std::fprintf(stderr, "instrumented fib diverged\n"); + std::exit(1); + } + std::printf( + "instrumentation %8.1f ns/call (%ld calls, plain %.3f s, traced " + "%.3f s)\n", + (traced - plain) / static_cast(calls) * 1e9, calls, plain, + traced); + collector.clear(); + collector.set_capacity_per_thread(std::size_t{1} << 20); +} + +} // namespace + +int main(int argc, char** argv) { + const std::int64_t iterations = + argc > 1 ? std::strtoll(argv[1], nullptr, 10) : 1000000; + const int fib_n = argc > 2 ? std::atoi(argv[2]) : 26; + if (iterations <= 0 || fib_n < 1 || fib_n > 40) { + std::fprintf(stderr, + "usage: overhead_bench [iterations > 0] [1 <= fib_n <= 40]\n"); + return 1; + } + std::printf("overhead_bench: %lld scope iterations, fib(%d)\n", + static_cast(iterations), fib_n); + measure_scope_macro(iterations); + measure_instrumentation(fib_n); + return 0; +} diff --git a/bench/overhead_fib.cpp b/bench/overhead_fib.cpp new file mode 100644 index 0000000..f7f01f7 --- /dev/null +++ b/bench/overhead_fib.cpp @@ -0,0 +1,12 @@ +// Compiled WITH -finstrument-functions: the instrumented twin of the +// benchmark's plain fib, so the measured difference is the hook cost. + +extern "C" { + +__attribute__((noinline)) long cyclescope_bench_fib_instrumented(int n) { + return n < 2 ? n + : cyclescope_bench_fib_instrumented(n - 1) + + cyclescope_bench_fib_instrumented(n - 2); +} + +} // extern "C" diff --git a/docs/design.md b/docs/design.md new file mode 100644 index 0000000..95e108e --- /dev/null +++ b/docs/design.md @@ -0,0 +1,131 @@ +# cyclescope design notes + +cyclescope is a small C++20 scope and function tracing library. Threads +record complete events into per-thread buffers; the collector writes chrome +trace-event JSON that the Perfetto UI (ui.perfetto.dev) and chrome://tracing +load directly. Two front ends feed the same core: an explicit RAII scope +macro, and a compiler-instrumentation backend that traces every function +call in translation units built with -finstrument-functions. + +## Core: per-thread buffers behind one collector + +Each recording thread owns a buffer guarded by its own mutex, uncontended +except while a flush snapshots it, so recording threads never contend with +each other. Buffers are bounded (default 2^20 events per thread) and +overflow drops events with a count that `write_json` reports; a tracing +library that silently grows without bound or silently loses data is worse +than one that tells you which happened. + +The registry keeps a buffer alive after its thread exits so the events +still reach the trace; `clear()` prunes dead buffers, and thread ids come +from a monotonic 64-bit counter so pruning never recycles them. `record()` +is `noexcept`: it is called from destructors, and an allocation failure +counts as a dropped event instead of terminating the program. + +`write_json` snapshots the registry and every buffer first, then performs +all file I/O with no lock held, so a slow disk cannot stall recording +threads or thread registration. The JSON footer is written whenever the +header succeeded, keeping the on-disk file syntactically complete even +after a mid-write failure. + +Event names are `const char*` with required static lifetime (string +literals, `__func__`, or interned strings). Storing pointers rather than +copies keeps the record path at one small struct append. + +## The suppression flag: tracing must never trace itself + +The deepest design constraint comes from how -finstrument-functions +interacts with inline functions and the one-definition rule. Every inline +collector function instantiated in an instrumented translation unit exists +there as an instrumented copy, and the linker may select that copy for the +whole program. Two failure modes follow: + +- A hook fires inside `write_json` while the thread holds a buffer mutex; + the hook calls `record()`, which relocks the same mutex. Self-deadlock. +- In unoptimized builds, an out-of-line instrumented copy of the guard + object's own constructor fires a hook before the guard is set, and the + hook constructs another guard. Unbounded recursion. + +The defense is a thread-local suppression flag with three properties: +`record()`, `write_json()`, and `clear()` set it for their duration, both +hooks check it first and stand down, and the guard's constructor and +destructor are forced inline and marked non-instrumentable so no callable +copy of them can ever exist. A regression test compiles a fixture with +instrumentation and flushes from inside it, the exact deadlock shape, +bounded by a test timeout so a regression fails instead of hanging. + +Teardown is the other lifecycle hazard: hooks and traced destructors can +run after static destruction has begun, so the collector singleton and the +name-interning table and mutex are deliberately immortal. The operating +system reclaims them at process exit; nothing a late hook touches is ever +a destroyed object. A trivially destructible thread-local flag likewise +marks TLS teardown, after which late events on that thread drop safely. + +## Instrumentation backend + +The hooks live in a separately compiled, uninstrumented static library. +Per-thread state is a fixed-depth (512) POD frame stack: no allocation +inside hooks, trivially destructible, safe during TLS teardown. Calls +deeper than the cap are counted and skipped, and an exit whose function +pointer does not match the frame it would close (longjmp, exceptions) is +discarded rather than miscounted. + +Names resolve lazily: the first return from a given function looks it up +with dladdr, demangles when possible, and interns the string for the +process lifetime, so the steady-state cost per event is a mutex-guarded +hash lookup rather than symbol resolution. Symbols outside the dynamic +symbol table fall back to their address; executables on Linux should set +ENABLE_EXPORTS so dladdr can see their symbols. MSVC has no +-finstrument-functions, so the backend is not built there; the scope macro +front end remains fully portable. + +## Emitter choice + +Chrome trace-event JSON with `ph:"X"` complete events is the smallest +format that a first-class interactive viewer consumes with zero tooling on +our side: one JSON file, drag it into Perfetto. Timestamps and durations +are microseconds with nanosecond-resolution inputs. The format costs more +bytes per event than a binary protocol, which is acceptable at the event +rates a scope tracer produces; a binary emitter can be added behind the +same collector if a use case demands it. + +## Measured overhead + +One machine, one data point: arm64 macOS (8 logical cores), Apple clang, +Release, C++20. Single runs of `bench/overhead_bench`, which measures each +path against an untraced twin of the same work and refuses to report if +the instrumented computation diverges. + +| path | cost per event | workload | +| --------------------------- | -------------: | --------------------------------- | +| scope macro (`CYCLESCOPE_SCOPE`) | 136 ns | 1,000,000 scopes vs empty loop | +| compiler instrumentation | 86 ns | fib(26), 635,621 calls vs plain | + +Both paths land in the same order of magnitude: roughly a hundred +nanoseconds per event, dominated by the timestamp read, the uncontended +buffer mutex, and (for instrumentation) the interned-name lookup. That +budget suits functions of microseconds and up; instrumenting a +few-nanosecond leaf function multiplies its cost by an order of magnitude, +which is visible in the fib workload itself (traced runtime grows from +under a millisecond to tens of milliseconds). The practical guidance +follows directly: instrument coarse-grained code or selected translation +units, and use the scope macro where call-level granularity is too fine. + +Reproduce with: + +``` +cmake -S . -B build -DCMAKE_BUILD_TYPE=Release +cmake --build build --parallel +./build/bench/overhead_bench +./build/examples/cyclescope_demo # writes demo.trace.json for Perfetto +``` + +## Limits, stated plainly + +- Names must have static lifetime; dynamic names need interning by the + caller. +- pid is fixed at 1; single-process traces are the target. +- Buffers of exited threads persist until `clear()`; long-running programs + with thread churn should clear after each flush. +- Events recorded on a thread after its TLS teardown, or beyond a buffer's + capacity, are dropped and counted, never silently lost. From 0b00584c626affbe9beef8a5d55c675ef8191754 Mon Sep 17 00:00:00 2001 From: Jason E Plumb Date: Wed, 16 Sep 2026 21:41:04 -0700 Subject: [PATCH 2/2] fix(bench): correct fib call count off-by-one, update measured overhead Co-Authored-By: Claude Fable 5 --- bench/overhead_bench.cpp | 2 +- docs/design.md | 9 +++++---- 2 files changed, 6 insertions(+), 5 deletions(-) diff --git a/bench/overhead_bench.cpp b/bench/overhead_bench.cpp index a1b373a..df6f92f 100644 --- a/bench/overhead_bench.cpp +++ b/bench/overhead_bench.cpp @@ -29,7 +29,7 @@ __attribute__((noinline)) long fib_plain(int n) { long fib_call_count(int n) { long a = 0; long b = 1; - for (int i = 0; i < n + 1; ++i) { + for (int i = 0; i < n; ++i) { const long next = a + b; a = b; b = next; diff --git a/docs/design.md b/docs/design.md index 95e108e..75fa123 100644 --- a/docs/design.md +++ b/docs/design.md @@ -99,11 +99,12 @@ the instrumented computation diverges. | path | cost per event | workload | | --------------------------- | -------------: | --------------------------------- | | scope macro (`CYCLESCOPE_SCOPE`) | 136 ns | 1,000,000 scopes vs empty loop | -| compiler instrumentation | 86 ns | fib(26), 635,621 calls vs plain | +| compiler instrumentation | 136 ns | fib(26), 392,835 calls vs plain | -Both paths land in the same order of magnitude: roughly a hundred -nanoseconds per event, dominated by the timestamp read, the uncontended -buffer mutex, and (for instrumentation) the interned-name lookup. That +The two paths cost the same per event, which is expected: both are +dominated by the shared record path (the timestamp read and the +uncontended buffer mutex), with the instrumentation backend adding only an +interned-name hash lookup on top. That budget suits functions of microseconds and up; instrumenting a few-nanosecond leaf function multiplies its cost by an order of magnitude, which is visible in the fib workload itself (traced runtime grows from