Skip to content

Trace core: events, buffers, Perfetto emitter, scope macro - #6

Merged
jasoneplumb merged 4 commits into
mainlinefrom
feature/trace-core
Sep 17, 2026
Merged

jasoneplumb merged 4 commits into
mainlinefrom
feature/trace-core

Conversation

@jasoneplumb

Copy link
Copy Markdown
Owner

Summary

The heart of the library: threads record complete events into their own buffers and the collector writes chrome trace-event JSON that Perfetto and chrome://tracing load.

Closes #2

Changes

  • include/cyclescope/trace.hpp: collector singleton with per-thread buffers (each thread locks only its own mutex on the hot path; a flush snapshots buffers briefly), bounded capacity with drop counting reported by write_json, registry keeps buffers of exited threads alive
  • Emitter: ph:"X" complete events, ts/dur in microseconds, JSON-escaped names, small stable tids
  • trace_scope RAII plus CYCLESCOPE_SCOPE(name) and CYCLESCOPE_SCOPE_FUNC(); names require static lifetime (documented)
  • Tests: JSON shape and escaping, per-thread capacity and drop counts, 4-thread recording surviving thread exit, and a record-versus-flush race case, all under TSan in CI

Test plan

  • Release and TSan builds green locally on macOS arm64 (2/2 test binaries, 5 trace cases)

Assumptions

  • Event names are static-lifetime pointers (literals, func); dynamic names would need interning and are out of scope for the core
  • pid is fixed at 1; single-process traces are the target
  • The uncontended per-buffer mutex on the record path is the simplicity/portability trade; per-event cost gets measured in the design write-up

🤖 Generated with Claude Code

Per-thread bounded buffers with drop counting behind a registry that
outlives exiting threads; recording locks only the caller's own buffer.
write_json emits chrome trace-event complete events (ts/dur in
microseconds, escaped names) loadable by the Perfetto UI. RAII
trace_scope and the CYCLESCOPE_SCOPE / CYCLESCOPE_SCOPE_FUNC macros
cover the annotation surface.

Closes #2

Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
@jasoneplumb jasoneplumb added enhancement New feature or request review-requested Trigger Claude review labels Sep 17, 2026
std::uint64_t duration_ns) {
thread_buffer& mine = local_buffer();
std::lock_guard guard(mine.mutex);
if (mine.events.size() >= capacity_.load(std::memory_order_relaxed)) {

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

OOM in destructor → std::terminate

push_back can throw std::bad_alloc when the vector reallocates (the size-vs-capacity_ check guards the logical limit but not the allocator). That exception propagates through record() and then through trace_scope::~trace_scope(), which is implicitly noexcept in C++11+, causing std::terminate.

Minimal fix — catch and count:

Suggested change
if (mine.events.size() >= capacity_.load(std::memory_order_relaxed)) {
try {
mine.events.push_back({name, start_ns, duration_ns});
} catch (const std::bad_alloc&) {
++mine.dropped;
}

Alternatively, reserve(capacity) in the thread_buffer constructor so push_back never allocates; that trades upfront memory for no-throw guarantee.

Comment thread include/cyclescope/trace.hpp Outdated
// Registered once per thread; the registry keeps the buffer alive after
// the thread exits so its events still reach the trace.
thread_buffer& local_buffer() {
thread_local std::shared_ptr<thread_buffer> mine = [this] {

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

buffers_ grows without bound on thread churn

Every OS thread that calls record() pushes a shared_ptr<thread_buffer> here and that entry is never removed. For programs using thread pools or many short-lived threads this is an unbounded memory leak; it also makes each write_json() and clear() walk increasingly large numbers of empty, dead-thread buffers.

A low-overhead mitigation: mark the buffer "dead" from the thread_local destructor (a std::atomic<bool> alive{true} in thread_buffer, flipped to false when the shared_ptr in thread_local is destroyed via a custom deleter). Then write_json() can skip dead-and-empty buffers, and a future compact() can prune them under registry_mutex_.

Comment thread include/cyclescope/trace.hpp Outdated
first ? "" : ",", name.c_str(),
static_cast<double>(event.start_ns) / 1e3,
static_cast<double>(event.duration_ns) / 1e3,
buffer->tid) >= 0;

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Malformed JSON left on disk when any I/O error occurs

ok = ok && fputs(...) short-circuits: once ok is false this line is skipped, so the file on disk ends with a truncated event list — no closing ]}. The function correctly returns false, but Perfetto's JSON parser will reject the file silently, and callers that don't propagate the error (e.g. fire-and-forget flush on shutdown) may be left confused.

Consider writing the footer unconditionally so the output is always well-formed JSON (even if truncated mid-list earlier):

Suggested change
buffer->tid) >= 0;
std::fputs("\n]}\n", out);
ok = ok && !std::ferror(out);
ok = (std::fclose(out) == 0) && ok;

At minimum, document that the file should be unlinked if write_json returns false.

@claude

claude Bot commented Sep 17, 2026

Copy link
Copy Markdown

Review summary — 3 issues found

Reviewed include/cyclescope/trace.hpp and tests/trace_test.cpp. The overall design is clean (per-thread buffers, lock ordering is correct, no deadlocks, JSON escaping handles all control characters). Three substantive issues:

1. push_back OOM → std::terminate (critical) — line 58

vector::push_back in record() can throw std::bad_alloc when the vector reallocates. That exception propagates out of record() and into trace_scope::~trace_scope(), which is implicitly noexcept, causing std::terminate. Fix: catch std::bad_alloc in record() and increment dropped, or reserve(capacity) upfront so push_back is guaranteed non-allocating.

2. buffers_ grows without bound on thread churn (medium) — line 127

Every thread that ever calls record() permanently adds an entry to buffers_; nothing prunes it. Programs using thread pools (many short-lived threads) accumulate dead buffers that are traversed on every write_json() / clear() call. Add a liveness flag to thread_buffer and flip it from the thread_local destructor so dead-and-empty buffers can be skipped or pruned.

3. Malformed JSON left on disk on any I/O error (medium) — line 91

ok = ok && fputs("\n]}\n", out) short-circuits when ok is already false, so if any earlier fprintf fails the closing ]} is never written. The file on disk is truncated mid-array. write_json returns false correctly, but callers that ignore the return value (shutdown flush) may feed Perfetto invalid JSON. Write the footer unconditionally, or document that the file must be unlinked on failure.


No issues with lock ordering, memory ordering (relaxed capacity_ is correctly a soft bound), JSON formatting, TSan coverage, or test structure.

…tional footer

Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
@jasoneplumb

Copy link
Copy Markdown
Owner Author

All three findings applied. record() is noexcept and counts an allocation failure as a dropped event, so a trace_scope destructor can never terminate the program. Buffers carry a liveness flag flipped from the thread_local handle's destructor; clear() prunes dead buffers, tids come from a monotonic counter so pruning never recycles them, and the churn contract is documented (clear after each flush). The JSON footer is written unconditionally so the on-disk file stays syntactically complete even after a mid-write failure. New test covers churn pruning and tid stability.

🤖 Generated with Claude Code

@jasoneplumb jasoneplumb added review-requested Trigger Claude review and removed review-requested Trigger Claude review labels Sep 17, 2026
// - Event names must outlive the collector (string literals, __func__, or
// otherwise static storage); the buffer stores the pointer, not a copy.
// - Recording is safe from any thread. Each thread locks only its own
// buffer's mutex, which is uncontended except while a flush snapshots it.

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This contract claim is inaccurate. write_json holds buffer->mutex for the entire inner event loop, including every fprintf call (lines 86–100). That is not a brief snapshot — it is a full file-write under lock. If the underlying I/O stalls (NFS, disk pressure, full buffer), any thread trying to record() into that buffer blocks for the same duration.

The fix is to copy events under the lock and then write without holding it:

std::vector<trace_event> snapshot;
uint64_t local_dropped;
{
    std::lock_guard buffer_guard(buffer->mutex);
    snapshot = buffer->events;
    local_dropped = buffer->dropped;
}
dropped += local_dropped;
for (const auto& event : snapshot) { ... }

The comment should then read "uncontended except while a flush copies it."


std::lock_guard registry_guard(registry_mutex_);
for (const auto& buffer : buffers_) {
std::lock_guard buffer_guard(buffer->mutex);

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

buffer_guard is held across all fprintf calls in the inner loop (lines 88–100). For a buffer with many events this keeps buffer->mutex locked for the full duration of the disk write, blocking any concurrent record() call on the same thread's buffer. See the comment on line 22 — a snapshot-then-write pattern fixes both the documentation mismatch and the liveness issue.

Comment thread include/cyclescope/trace.hpp Outdated
std::fprintf(
out,
"%s\n{\"name\":\"%s\",\"cat\":\"scope\",\"ph\":\"X\","
"\"ts\":%.3f,\"dur\":%.3f,\"pid\":1,\"tid\":%u}",

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

%u expects unsigned int, but buffer->tid is std::uint32_t, which may be unsigned long on some platforms (ILP32L LP64). This is undefined behavior per the C standard. Use PRIu32 from <cinttypes>:

Suggested change
"\"ts\":%.3f,\"dur\":%.3f,\"pid\":1,\"tid\":%u}",
"\"ts\":%.3f,\"dur\":%.3f,\"pid\":1,\"tid\":%" PRIu32 "}",

(Add #include <cinttypes> to the include block.)

Comment thread include/cyclescope/trace.hpp Outdated
std::uint64_t dropped = 0;
bool first = true;

std::lock_guard registry_guard(registry_mutex_);

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

registry_mutex_ is held for the entire write_json call — including all formatting and I/O. Any thread whose local_buffer() hasn't been called yet (first event on that thread) will block on registry_mutex_ for the full flush duration, because thread-local buffer registration also acquires this lock (line 161). Consider snapshotting buffers_ under the registry lock and then releasing it before writing.

Comment thread include/cyclescope/trace.hpp Outdated
}
}
// The footer is written even after an earlier failure, so the file on
// disk is syntactically complete JSON whenever the filesystem allows.

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

The "syntactically complete JSON" guarantee only holds when the header write on line 80 succeeded. If fputs("{\"traceEvents\":[", out) fails, ok becomes false, no events are written (short-circuit), but the footer "\n]}\n" is still unconditionally written — leaving a file containing only \n]}\n, which is not valid JSON.

Additionally, if a fprintf inside the loop partially writes before failing (which fprintf can do), the file may contain a truncated event object, also invalid JSON.

Consider only writing the footer when the header succeeded, or noting in the comment that the guarantee applies only to I/O that fails cleanly (complete-write or no-write semantics).

@claude

claude Bot commented Sep 17, 2026

Copy link
Copy Markdown

Review summary — 4 issues found

1. buffer->mutex held across all file I/O in write_json (lines 86–100) — liveness bug

The documented contract (line 22) says the per-buffer mutex is held only while a flush "snapshots" the buffer. In practice it is held for the entire inner fprintf loop. Any thread calling record() on the same buffer blocks for the full duration of the disk write. On slow I/O (NFS, saturated disk) this stalls hot recording paths indefinitely. Fix: copy the event vector under the lock, release the lock, then write the copy.

2. registry_mutex_ held across entire write_json (line 84) — thread startup blocked during flush

New threads whose first record() hasn't fired yet must acquire registry_mutex_ in local_buffer() to register their buffer. Because write_json holds registry_mutex_ for the full flush, those threads stall. Fix: snapshot buffers_ (a vector of shared_ptrs) under the registry lock, release it, then iterate the snapshot.

3. %u with std::uint32_t tid (line 94) — undefined behavior on some platforms

%u matches unsigned int; std::uint32_t may be unsigned long on some ABIs. Use PRIu32 from <cinttypes>.

4. "Syntactically complete JSON" guarantee overstated (line 103) — invalid JSON on header-write failure

If the opening fputs for the header fails, ok becomes false, no events are written (short-circuit), but the footer is still unconditionally appended — producing a file containing only the closing fragment, which is invalid JSON. The guarantee should be scoped to the case where the header write succeeded.


Logic, lifetime, and memory-ordering review of include/cyclescope/trace.hpp and tests/trace_test.cpp. No issues found in the test file beyond the shared-singleton caveat already addressed by reset_collector().

Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
@jasoneplumb

Copy link
Copy Markdown
Owner Author

All four cycle 2 findings applied. write_json snapshots the registry and every buffer up front (documented as a transient copy) and performs all file I/O with no lock held, so recording threads and thread registration never wait on the disk. tid formatting uses PRIu32. The footer is written only once the header succeeded, and the completeness guarantee in the comment is scoped accordingly. This is cycle 3 of the review; merging on green per the cycle policy.

🤖 Generated with Claude Code

@jasoneplumb jasoneplumb added review-requested Trigger Claude review and removed review-requested Trigger Claude review labels Sep 17, 2026
Comment thread include/cyclescope/trace.hpp Outdated

std::mutex registry_mutex_;
std::vector<std::shared_ptr<thread_buffer>> buffers_;
std::uint32_t next_tid_ = 1; // Guarded by registry_mutex_.

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Bug: next_tid_ wraps at 2^32, contradicting the "never recycles" invariant

next_tid_ is uint32_t, so after exactly 2^32 thread registrations it wraps back to 0 (or 1 on the first overflow if it starts at 1) and silently reuses tid values. The comment on lines 179–180 says "Tids come from a monotonic counter, so pruning never recycles them" — that claim is only correct before the overflow.

For programs with heavy thread churn this means two live buffers in buffers_ can end up with the same tid, producing a trace where Perfetto merges unrelated threads on the same lane, silently corrupting the timeline.

Fix: use uint64_t (essentially infinite) or detect overflow and either assert or wrap to a reserved "overflow" tid value.

// the thread exits so its events still reach the trace. Tids come from a
// monotonic counter, so pruning never recycles them.
thread_buffer& local_buffer() {
thread_local buffer_handle handle = [this] {

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Potential UB: "phoenix singleton" — accessing a destroyed thread-local during thread exit

handle is a function-local thread_local, so its constructor runs the first time this thread calls local_buffer() and its destructor runs at thread exit in LIFO order relative to other thread-locals.

The hazard: any thread-local object that was constructed before the first call to record() in this thread will be destroyed after handle. If that object's destructor calls record() (directly or via a library function like a logger), the program re-enters local_buffer() and dereferences handle.buffer — a destroyed object — which is undefined behaviour.

This is the classic "phoenix singleton" problem. A minimal mitigation is a thread_local bool dead-flag:

thread_local bool tls_dead = false;

~buffer_handle() {
  tls_dead = true;   // mark before locking, so record() can check
  if (buffer != nullptr) { ... }
}

void record(...) noexcept {
  if (tls_dead) return;   // thread is unwinding, buffer gone
  ...
}

The bool is always initialized before handle (it's a trivially-initialized thread_local), so it's always valid to read.

Comment on lines +99 to +101
if (dropped_total != nullptr) {
*dropped_total = dropped;
}

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Logic error: output parameter dropped_total is written before fopen, so it is mutated even when the function returns false

*dropped_total is set here (line 100–101), but fopen isn't attempted until line 103. If fopen fails the function returns false at line 105 — yet *dropped_total already holds the snapshot value.

A caller that passes a non-null dropped_total and only consults it on success is fine, but the API contract documented in the comment ("receives the number of events lost to capacity limits") doesn't say it's conditional on success. Moving the assignment to just before return ok (or only when ok is true) would make the behaviour unambiguous:

    ok = (std::fclose(out) == 0) && ok;
    if (dropped_total != nullptr && ok) {
      *dropped_total = dropped;
    }
    return ok;

Alternatively, document explicitly that dropped_total may be updated even on failure.

@claude

claude Bot commented Sep 17, 2026

Copy link
Copy Markdown

Review summary

Three substantive issues found — all in include/cyclescope/trace.hpp:

Bugs / UB

  1. next_tid_ (uint32_t) wraps at 2^32, recycling tids (line 212)
    The code comment claims tids are never recycled, but the counter overflows after 2^32 thread registrations. Programs with long-running thread churn will see silent tid aliasing in traces. Fix: promote to uint64_t.

  2. Phoenix singleton UB during thread exit (line 182)
    If any thread-local (constructed before the first record() call) has a destructor that calls record(), the already-destroyed thread_local buffer_handle handle is accessed — UB. A thread_local bool tls_dead checked at the top of record() / local_buffer() is the standard mitigation.

API correctness

  1. *dropped_total written before fopen, so it is mutated on failure (lines 99–101)
    The output parameter is set from the snapshot before the file is opened. If fopen fails the function returns false but the caller's dropped_total variable has already been overwritten. Move the assignment to after the file is confirmed written, or document that it is unconditional.

Everything else looks solid: the two-phase snapshot design is correct, mutex nesting is deadlock-free, the escape function is JSON-spec compliant, fclose is always called, and the test suite covers the key concurrent-access paths under TSan.

…tal documented

Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
@jasoneplumb

Copy link
Copy Markdown
Owner Author

All three cycle 3 findings applied: tids are uint64 (never wrap), a trivially destructible thread_local flag guards record() against traced destructors running after TLS teardown (late events drop safely), and dropped_total is documented as always written. Cycle limit reached with findings at hardening level; merging on green.

🤖 Generated with Claude Code

@jasoneplumb
jasoneplumb merged commit 8e428f5 into mainline Sep 17, 2026
3 checks passed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

enhancement New feature or request review-requested Trigger Claude review

Projects

None yet

Development

Successfully merging this pull request may close these issues.

Trace core: events, buffers, Perfetto emitter, scope macro

1 participant