diff --git a/include/cyclescope/trace.hpp b/include/cyclescope/trace.hpp new file mode 100644 index 0000000..bc70c00 --- /dev/null +++ b/include/cyclescope/trace.hpp @@ -0,0 +1,258 @@ +#pragma once + +#include +#include +#include +#include +#include +#include +#include +#include +#include +#include + +// Scope tracing core. Threads record complete events (name, start, +// duration) into their own buffers; a collector owns every buffer and +// writes the whole trace as chrome trace-event JSON, which the Perfetto UI +// and chrome://tracing both load. +// +// Contracts: +// - 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. +// - Buffers are bounded (set_capacity_per_thread); overflow drops events +// and counts the drops, and write_json reports the total dropped. + +namespace cyclescope { + +namespace detail { +// Trivially destructible, so reading it stays defined even after this +// thread's nontrivial thread_locals (including the buffer handle) are +// gone. Set during TLS teardown; record() then drops late events. +inline thread_local bool tls_shutdown = false; +} // namespace detail + +struct trace_event { + const char* name; + std::uint64_t start_ns; + std::uint64_t duration_ns; +}; + +// Nanoseconds since the first use in the process; monotonic. +inline std::uint64_t trace_now_ns() { + static const auto anchor = std::chrono::steady_clock::now(); + return static_cast( + std::chrono::duration_cast( + std::chrono::steady_clock::now() - anchor) + .count()); +} + +class collector { + public: + static collector& instance() { + static collector self; + return self; + } + + void set_capacity_per_thread(std::size_t capacity) { + capacity_.store(capacity, std::memory_order_relaxed); + } + + // Hot path: records into the calling thread's buffer. Never throws: + // trace_scope destructors call this, and an allocation failure counts + // as a dropped event rather than terminating the program. + void record(const char* name, std::uint64_t start_ns, + std::uint64_t duration_ns) noexcept { + if (detail::tls_shutdown) { + // A traced destructor ran after this thread's buffer handle was + // destroyed; the event is dropped rather than touching dead TLS. + return; + } + thread_buffer& mine = local_buffer(); + std::lock_guard guard(mine.mutex); + if (mine.events.size() >= capacity_.load(std::memory_order_relaxed)) { + ++mine.dropped; + return; + } + try { + mine.events.push_back({name, start_ns, duration_ns}); + } catch (const std::bad_alloc&) { + ++mine.dropped; + } + } + + // Writes every buffer as chrome trace-event JSON. Returns false when the + // file cannot be opened or written. `dropped_total`, when non-null, is + // always written with the number of events lost to capacity limits, + // including when the function returns false. + // + // No lock is held across file I/O: the registry and each buffer are + // snapshotted first (a transient copy of the event data), so recording + // threads and thread registration never stall behind a slow disk. + bool write_json(const char* path, std::uint64_t* dropped_total = nullptr) { + std::vector> registered; + { + std::lock_guard registry_guard(registry_mutex_); + registered = buffers_; + } + + struct buffer_snapshot { + std::vector events; + std::uint64_t tid = 0; + }; + std::vector snapshots; + snapshots.reserve(registered.size()); + std::uint64_t dropped = 0; + for (const auto& buffer : registered) { + std::lock_guard buffer_guard(buffer->mutex); + dropped += buffer->dropped; + snapshots.push_back({buffer->events, buffer->tid}); + } + if (dropped_total != nullptr) { + *dropped_total = dropped; + } + + std::FILE* out = std::fopen(path, "w"); + if (out == nullptr) { + return false; + } + const bool header_ok = std::fputs("{\"traceEvents\":[", out) >= 0; + bool ok = header_ok; + if (header_ok) { + bool first = true; + for (const auto& snapshot : snapshots) { + for (const trace_event& event : snapshot.events) { + const std::string name = escape(event.name); + ok = ok && + std::fprintf( + out, + "%s\n{\"name\":\"%s\",\"cat\":\"scope\",\"ph\":\"X\"," + "\"ts\":%.3f,\"dur\":%.3f,\"pid\":1,\"tid\":%" PRIu64 "}", + first ? "" : ",", name.c_str(), + static_cast(event.start_ns) / 1e3, + static_cast(event.duration_ns) / 1e3, + snapshot.tid) >= 0; + first = false; + } + } + // Whenever the header made it out, the footer is written even after + // an event-write failure, so the file on disk stays syntactically + // complete JSON if the filesystem allows. + const bool footer_ok = std::fputs("\n]}\n", out) >= 0; + ok = ok && footer_ok; + } + ok = (std::fclose(out) == 0) && ok; + return ok; + } + + // Empties every buffer and drop counter, and prunes buffers whose + // threads have exited. Live buffers stay registered. Call only while no + // thread is recording. Buffers of exited threads are retained until this + // runs so their events still reach the trace; long-running programs with + // thread churn should clear() after each flush. + void clear() { + std::lock_guard registry_guard(registry_mutex_); + std::vector> kept; + kept.reserve(buffers_.size()); + for (const auto& buffer : buffers_) { + std::lock_guard buffer_guard(buffer->mutex); + buffer->events.clear(); + buffer->dropped = 0; + if (buffer->alive) { + kept.push_back(buffer); + } + } + buffers_.swap(kept); + } + + private: + struct thread_buffer { + std::mutex mutex; + std::vector events; + std::uint64_t dropped = 0; + std::uint64_t tid = 0; + bool alive = true; // Guarded by mutex; false once the thread exits. + }; + + // Marks the buffer dead when its thread exits, so clear() can prune it, + // and flags TLS teardown so later record() calls bail out safely. + struct buffer_handle { + std::shared_ptr buffer; + ~buffer_handle() { + detail::tls_shutdown = true; + if (buffer != nullptr) { + std::lock_guard guard(buffer->mutex); + buffer->alive = false; + } + } + }; + + collector() = default; + + // Registered once per thread; the registry keeps the buffer alive after + // 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] { + auto buffer = std::make_shared(); + std::lock_guard guard(registry_mutex_); + buffer->tid = next_tid_++; + buffers_.push_back(buffer); + return buffer_handle{buffer}; + }(); + return *handle.buffer; + } + + static std::string escape(const char* raw) { + std::string out; + for (const char* p = raw != nullptr ? raw : "(null)"; *p != '\0'; ++p) { + const unsigned char c = static_cast(*p); + if (c == '"' || c == '\\') { + out += '\\'; + out += static_cast(c); + } else if (c < 0x20) { + char buf[8]; + std::snprintf(buf, sizeof(buf), "\\u%04x", c); + out += buf; + } else { + out += static_cast(c); + } + } + return out; + } + + std::mutex registry_mutex_; + std::vector> buffers_; + std::uint64_t next_tid_ = 1; // Guarded by registry_mutex_; never wraps. + std::atomic capacity_{std::size_t{1} << 20}; +}; + +// RAII scope: records one complete event covering its lifetime. +class trace_scope { + public: + explicit trace_scope(const char* name) + : name_(name), start_ns_(trace_now_ns()) {} + trace_scope(const trace_scope&) = delete; + trace_scope& operator=(const trace_scope&) = delete; + ~trace_scope() { + collector::instance().record(name_, start_ns_, + trace_now_ns() - start_ns_); + } + + private: + const char* name_; + std::uint64_t start_ns_; +}; + +} // namespace cyclescope + +#define CYCLESCOPE_CONCAT_INNER(a, b) a##b +#define CYCLESCOPE_CONCAT(a, b) CYCLESCOPE_CONCAT_INNER(a, b) + +// Names one scope explicitly; the argument must have static lifetime. +#define CYCLESCOPE_SCOPE(name) \ + ::cyclescope::trace_scope CYCLESCOPE_CONCAT(cs_scope_, __LINE__)(name) + +// Names the scope after the enclosing function. +#define CYCLESCOPE_SCOPE_FUNC() CYCLESCOPE_SCOPE(__func__) diff --git a/tests/CMakeLists.txt b/tests/CMakeLists.txt index d547c40..09305ec 100644 --- a/tests/CMakeLists.txt +++ b/tests/CMakeLists.txt @@ -29,3 +29,4 @@ function(cyclescope_add_test name) endfunction() cyclescope_add_test(log_test) +cyclescope_add_test(trace_test) diff --git a/tests/trace_test.cpp b/tests/trace_test.cpp new file mode 100644 index 0000000..f53e200 --- /dev/null +++ b/tests/trace_test.cpp @@ -0,0 +1,163 @@ +#define DOCTEST_CONFIG_IMPLEMENT_WITH_MAIN +#include + +#include +#include +#include +#include +#include +#include +#include + +namespace { + +std::string slurp(const std::string& path) { + std::ifstream in(path); + std::ostringstream out; + out << in.rdbuf(); + return out.str(); +} + +std::size_t count_occurrences(const std::string& text, + const std::string& needle) { + std::size_t count = 0; + for (std::size_t at = text.find(needle); at != std::string::npos; + at = text.find(needle, at + needle.size())) { + ++count; + } + return count; +} + +std::string temp_trace_path(const char* tag) { + return std::string("cyclescope_test_") + tag + ".trace.json"; +} + +// The collector is a process-wide singleton, so every test case starts by +// clearing it and restoring the default capacity. +void reset_collector() { + cyclescope::collector::instance().clear(); + cyclescope::collector::instance().set_capacity_per_thread(std::size_t{1} + << 20); +} + +} // namespace + +TEST_CASE("scope events land in valid trace json") { + reset_collector(); + { + CYCLESCOPE_SCOPE("outer"); + CYCLESCOPE_SCOPE("inner"); + } + { + CYCLESCOPE_SCOPE_FUNC(); + } + + const std::string path = temp_trace_path("basic"); + std::uint64_t dropped = 999; + REQUIRE(cyclescope::collector::instance().write_json(path.c_str(), + &dropped)); + const std::string json = slurp(path); + std::remove(path.c_str()); + + CHECK(dropped == 0); + CHECK(json.find("{\"traceEvents\":[") == 0); + CHECK(json.rfind("]}\n") == json.size() - 3); + CHECK(count_occurrences(json, "\"ph\":\"X\"") == 3); + CHECK(json.find("\"name\":\"outer\"") != std::string::npos); + CHECK(json.find("\"name\":\"inner\"") != std::string::npos); + CHECK(json.find("\"cat\":\"scope\"") != std::string::npos); +} + +TEST_CASE("names are escaped for json") { + reset_collector(); + cyclescope::collector::instance().record("quote\"back\\slash\tend", 10, + 20); + const std::string path = temp_trace_path("escape"); + REQUIRE(cyclescope::collector::instance().write_json(path.c_str())); + const std::string json = slurp(path); + std::remove(path.c_str()); + CHECK(json.find("quote\\\"back\\\\slash\\u0009end") != std::string::npos); +} + +TEST_CASE("capacity bounds each thread and drops are counted") { + reset_collector(); + cyclescope::collector::instance().set_capacity_per_thread(4); + // This thread's buffer may already hold events from earlier cases in + // this binary; record from a fresh thread for a clean count. + std::thread worker([] { + for (int i = 0; i < 10; ++i) { + cyclescope::collector::instance().record("bounded", 0, 1); + } + }); + worker.join(); + + const std::string path = temp_trace_path("bounded"); + std::uint64_t dropped = 0; + REQUIRE(cyclescope::collector::instance().write_json(path.c_str(), + &dropped)); + const std::string json = slurp(path); + std::remove(path.c_str()); + CHECK(count_occurrences(json, "\"name\":\"bounded\"") == 4); + CHECK(dropped == 6); +} + +TEST_CASE("threads keep distinct tids and survive exit") { + reset_collector(); + constexpr int kThreads = 4; + constexpr int kEventsPerThread = 100; + std::vector workers; + workers.reserve(kThreads); + for (int t = 0; t < kThreads; ++t) { + workers.emplace_back([] { + for (int i = 0; i < kEventsPerThread; ++i) { + CYCLESCOPE_SCOPE("worker"); + } + }); + } + for (auto& w : workers) { + w.join(); + } + + const std::string path = temp_trace_path("threads"); + REQUIRE(cyclescope::collector::instance().write_json(path.c_str())); + const std::string json = slurp(path); + std::remove(path.c_str()); + // All events survive their threads' exit. + CHECK(count_occurrences(json, "\"name\":\"worker\"") == + kThreads * kEventsPerThread); +} + +TEST_CASE("clear prunes exited threads and tids stay unique") { + reset_collector(); + std::thread first([] { CYCLESCOPE_SCOPE("gen1"); }); + first.join(); + cyclescope::collector::instance().clear(); // Prunes gen1's dead buffer. + + std::thread second([] { CYCLESCOPE_SCOPE("gen2"); }); + second.join(); + + const std::string path = temp_trace_path("churn"); + REQUIRE(cyclescope::collector::instance().write_json(path.c_str())); + const std::string json = slurp(path); + std::remove(path.c_str()); + CHECK(count_occurrences(json, "\"name\":\"gen1\"") == 0); + CHECK(count_occurrences(json, "\"name\":\"gen2\"") == 1); +} + +TEST_CASE("recording races a concurrent flush safely") { + reset_collector(); + std::atomic stop{false}; + std::thread recorder([&] { + while (!stop.load(std::memory_order_relaxed)) { + CYCLESCOPE_SCOPE("racing"); + } + }); + for (int i = 0; i < 20; ++i) { + const std::string path = temp_trace_path("race"); + CHECK(cyclescope::collector::instance().write_json(path.c_str())); + std::remove(path.c_str()); + } + stop.store(true, std::memory_order_relaxed); + recorder.join(); + CHECK(true); +}