From 9cdf6529b84c780649b607bd06dc824cc3b50396 Mon Sep 17 00:00:00 2001 From: Ryan Tremblay Date: Mon, 30 Mar 2026 17:01:32 -0700 Subject: [PATCH 01/12] Add basic Android impl --- Source/Android/arcana/tracing/trace_region.h | 61 ++++++++++++++++++-- 1 file changed, 55 insertions(+), 6 deletions(-) diff --git a/Source/Android/arcana/tracing/trace_region.h b/Source/Android/arcana/tracing/trace_region.h index cd3b650..815d553 100644 --- a/Source/Android/arcana/tracing/trace_region.h +++ b/Source/Android/arcana/tracing/trace_region.h @@ -4,6 +4,12 @@ #pragma once +#include +#include +#include + +#define TRACE_TAG "trace_region" + namespace arcana { enum class trace_level @@ -12,8 +18,6 @@ namespace arcana log, }; - // TODO: https://developer.android.com/topic/performance/tracing/custom-events-native - // https://developer.android.com/ndk/reference/group/tracing class trace_region final { public: @@ -21,24 +25,69 @@ namespace arcana trace_region(const trace_region&) = delete; trace_region& operator=(const trace_region&) = delete; - trace_region(const char*) + trace_region(const char* name) : + m_active{s_enabled.load()} { + if (m_active) + { + if (s_logEnabled) + { + __android_log_print(ANDROID_LOG_DEBUG, TRACE_TAG, "[trace_region] BEGIN %s (this=%p)", name, static_cast(this)); + } + ATrace_beginSection(name); + } } - trace_region(trace_region&&) = default; + trace_region(trace_region&& other) : + m_active{other.m_active} + { + other.m_active = false; + } ~trace_region() { + if (m_active) + { + if (s_logEnabled) + { + __android_log_print(ANDROID_LOG_DEBUG, TRACE_TAG, "[trace_region] END (this=%p)", static_cast(this)); + } + ATrace_endSection(); + } } - trace_region& operator=(trace_region&&) = default; + trace_region& operator=(trace_region&& other) + { + if (m_active) + { + if (s_logEnabled) + { + __android_log_print(ANDROID_LOG_DEBUG, TRACE_TAG, "[trace_region] END (move) (this=%p)", static_cast(this)); + } + ATrace_endSection(); + } - static void enable(trace_level = trace_level::mark) + m_active = other.m_active; + other.m_active = false; + + return *this; + } + + static void enable(trace_level level = trace_level::mark) { + s_enabled = true; + s_logEnabled = level == trace_level::log; } static void disable() { + s_enabled = false; + s_logEnabled = false; } + + private: + static inline std::atomic s_enabled{false}; + static inline std::atomic s_logEnabled{false}; + bool m_active; }; } From 544ae074b0fad755c57c87dc49b4b69dd44f9eaa Mon Sep 17 00:00:00 2001 From: Ryan Tremblay Date: Tue, 31 Mar 2026 10:48:30 -0700 Subject: [PATCH 02/12] Add async support --- Source/Android/arcana/tracing/trace_region.h | 107 ++++++++++++++++--- 1 file changed, 92 insertions(+), 15 deletions(-) diff --git a/Source/Android/arcana/tracing/trace_region.h b/Source/Android/arcana/tracing/trace_region.h index 815d553..d6a3e32 100644 --- a/Source/Android/arcana/tracing/trace_region.h +++ b/Source/Android/arcana/tracing/trace_region.h @@ -2,11 +2,38 @@ // Copyright (C) Microsoft Corporation. All rights reserved. // +// +// Android trace_region implementation using the NDK ATrace API. +// +// This uses ATrace_beginAsyncSection/ATrace_endAsyncSection (API 29+) which pair +// begin/end events by name + cookie, allowing trace regions to be moved across +// threads (e.g. when an RAII trace_region is captured into an async continuation). +// The sync API (ATrace_beginSection/ATrace_endSection) uses a per-thread stack, +// which breaks when begin and end occur on different threads. +// +// When targeting minSdkVersion < 29, the async functions are resolved at runtime +// via dlsym. If unavailable (device below API 29), falls back to the sync API. +// +// NOTE: Async trace sections may not be visible in Android Studio's Profiler UI. +// To view them, capture a trace with Perfetto: +// +// adb shell atrace --async_start -a -c +// # ... interact with the app ... +// adb shell atrace --async_stop -o /data/local/tmp/trace.txt +// adb pull /data/local/tmp/trace.txt +// +// Then open the trace file at https://ui.perfetto.dev +// + #pragma once #include +#include #include #include +#if __ANDROID_MIN_SDK_VERSION__ < 29 +#include +#endif #define TRACE_TAG "trace_region" @@ -26,49 +53,54 @@ namespace arcana trace_region& operator=(const trace_region&) = delete; trace_region(const char* name) : - m_active{s_enabled.load()} + m_cookie{s_enabled ? s_nextCookie.fetch_add(1, std::memory_order_relaxed) : 0}, + m_name{m_cookie != 0 ? name : ""} { - if (m_active) + if (m_cookie != 0) { if (s_logEnabled) { - __android_log_print(ANDROID_LOG_DEBUG, TRACE_TAG, "[trace_region] BEGIN %s (this=%p)", name, static_cast(this)); + __android_log_print(ANDROID_LOG_DEBUG, TRACE_TAG, "[trace_region] BEGIN %s (cookie=%d, this=%p)", m_name.c_str(), m_cookie, static_cast(this)); } - ATrace_beginSection(name); + traceBegin(m_name.c_str(), m_cookie); } } + // Move constructor transfers ownership; the moved-from region becomes inactive + // (cookie set to 0) so its destructor won't emit a spurious end event. trace_region(trace_region&& other) : - m_active{other.m_active} + m_cookie{other.m_cookie}, + m_name{std::move(other.m_name)} { - other.m_active = false; + other.m_cookie = 0; } ~trace_region() { - if (m_active) + if (m_cookie != 0) { if (s_logEnabled) { - __android_log_print(ANDROID_LOG_DEBUG, TRACE_TAG, "[trace_region] END (this=%p)", static_cast(this)); + __android_log_print(ANDROID_LOG_DEBUG, TRACE_TAG, "[trace_region] END (cookie=%d, this=%p)", m_cookie, static_cast(this)); } - ATrace_endSection(); + traceEnd(m_name.c_str(), m_cookie); } } trace_region& operator=(trace_region&& other) { - if (m_active) + if (m_cookie != 0) { if (s_logEnabled) { - __android_log_print(ANDROID_LOG_DEBUG, TRACE_TAG, "[trace_region] END (move) (this=%p)", static_cast(this)); + __android_log_print(ANDROID_LOG_DEBUG, TRACE_TAG, "[trace_region] END (move) (cookie=%d, this=%p)", m_cookie, static_cast(this)); } - ATrace_endSection(); + traceEnd(m_name.c_str(), m_cookie); } - m_active = other.m_active; - other.m_active = false; + m_cookie = other.m_cookie; + m_name = std::move(other.m_name); + other.m_cookie = 0; return *this; } @@ -86,8 +118,53 @@ namespace arcana } private: + static void traceBegin(const char* name, int32_t cookie) + { +#if __ANDROID_MIN_SDK_VERSION__ >= 29 + ATrace_beginAsyncSection(name, cookie); +#else + // Prefer async API if available at runtime (device is API 29+). + // Fall back to sync API which uses a per-thread stack — correct for + // same-thread RAII, but cross-thread begin/end pairs won't match. + if (s_beginAsync) + s_beginAsync(name, cookie); + else + ATrace_beginSection(name); +#endif + } + + static void traceEnd(const char* name, int32_t cookie) + { +#if __ANDROID_MIN_SDK_VERSION__ >= 29 + ATrace_endAsyncSection(name, cookie); +#else + if (s_endAsync) + s_endAsync(name, cookie); + else + ATrace_endSection(); +#endif + } + static inline std::atomic s_enabled{false}; static inline std::atomic s_logEnabled{false}; - bool m_active; + static inline std::atomic s_nextCookie{1}; + +#if __ANDROID_MIN_SDK_VERSION__ < 29 + // Resolve async trace functions at load time. These are available on + // devices running API 29+, even when the app targets a lower minSdkVersion. + using AsyncTraceFunc = void (*)(const char*, int32_t); + static inline const AsyncTraceFunc s_beginAsync{ + reinterpret_cast(dlsym(RTLD_DEFAULT, "ATrace_beginAsyncSection"))}; + static inline const AsyncTraceFunc s_endAsync{ + reinterpret_cast(dlsym(RTLD_DEFAULT, "ATrace_endAsyncSection"))}; +#endif + + // Cookie uniquely identifies this trace interval for the async API, analogous + // to os_signpost_id_t on Apple. A cookie of 0 means the region is inactive. + int32_t m_cookie; + // Name is stored as std::string (not const char*) because callers may pass + // c_str() from a temporary std::string, and ATrace_endAsyncSection needs the + // name to match the corresponding begin call. + std::string m_name; }; } From 29cdf4deebeca44ee6aef1b6807f4c31d90c51c5 Mon Sep 17 00:00:00 2001 From: Ryan Tremblay Date: Tue, 31 Mar 2026 10:55:47 -0700 Subject: [PATCH 03/12] Remove sync calls since they don't really work --- Source/Android/arcana/tracing/trace_region.h | 10 ++-------- 1 file changed, 2 insertions(+), 8 deletions(-) diff --git a/Source/Android/arcana/tracing/trace_region.h b/Source/Android/arcana/tracing/trace_region.h index d6a3e32..77ecb2a 100644 --- a/Source/Android/arcana/tracing/trace_region.h +++ b/Source/Android/arcana/tracing/trace_region.h @@ -12,7 +12,8 @@ // which breaks when begin and end occur on different threads. // // When targeting minSdkVersion < 29, the async functions are resolved at runtime -// via dlsym. If unavailable (device below API 29), falls back to the sync API. +// via dlsym. If unavailable (device below API 29), ATrace is silently skipped +// (logcat output at trace_level::log still works). // // NOTE: Async trace sections may not be visible in Android Studio's Profiler UI. // To view them, capture a trace with Perfetto: @@ -123,13 +124,8 @@ namespace arcana #if __ANDROID_MIN_SDK_VERSION__ >= 29 ATrace_beginAsyncSection(name, cookie); #else - // Prefer async API if available at runtime (device is API 29+). - // Fall back to sync API which uses a per-thread stack — correct for - // same-thread RAII, but cross-thread begin/end pairs won't match. if (s_beginAsync) s_beginAsync(name, cookie); - else - ATrace_beginSection(name); #endif } @@ -140,8 +136,6 @@ namespace arcana #else if (s_endAsync) s_endAsync(name, cookie); - else - ATrace_endSection(); #endif } From ad5b8b53192faeebc72d66c9e04b593b29ec4855 Mon Sep 17 00:00:00 2001 From: Ryan Tremblay Date: Tue, 31 Mar 2026 10:59:05 -0700 Subject: [PATCH 04/12] Add comments for existing Apple impl --- Source/Apple/arcana/tracing/trace_region.h | 18 ++++++++++++++++++ 1 file changed, 18 insertions(+) diff --git a/Source/Apple/arcana/tracing/trace_region.h b/Source/Apple/arcana/tracing/trace_region.h index ad66cc3..0bee87c 100644 --- a/Source/Apple/arcana/tracing/trace_region.h +++ b/Source/Apple/arcana/tracing/trace_region.h @@ -2,6 +2,24 @@ // Copyright (C) Microsoft Corporation. All rights reserved. // +// +// Apple trace_region implementation using os_signpost. +// +// Signpost intervals are logged to the OS_LOG_CATEGORY_POINTS_OF_INTEREST category, +// which makes them appear on the "Points of Interest" timeline in Instruments. +// Each interval is identified by a unique os_signpost_id_t, allowing begin/end +// pairs to be matched even across threads or when multiple regions overlap. +// +// To capture and view traces in Instruments: +// 1. Open Instruments (Xcode → Open Developer Tool → Instruments, or ⌘I from Xcode) +// 2. Choose the "Blank" template, then add the "os_signpost" instrument +// (click "+", search for "os_signpost", and add it) +// 3. Select your app as the target and click Record +// 4. Interact with the app, then stop recording +// 5. Trace regions appear on the "Points of Interest" timeline as labeled intervals +// 6. Click on an interval to see its name and duration in the detail pane +// + #pragma once #include From 3fb570c22ea9ebd115cf52d030da3fbe92bffe90 Mon Sep 17 00:00:00 2001 From: Ryan Tremblay Date: Tue, 31 Mar 2026 11:50:04 -0700 Subject: [PATCH 05/12] Initial windows impl --- Source/Windows/arcana/tracing/trace_region.h | 134 ++++++++++++++++++- 1 file changed, 129 insertions(+), 5 deletions(-) diff --git a/Source/Windows/arcana/tracing/trace_region.h b/Source/Windows/arcana/tracing/trace_region.h index b728a65..8ce4b7d 100644 --- a/Source/Windows/arcana/tracing/trace_region.h +++ b/Source/Windows/arcana/tracing/trace_region.h @@ -2,17 +2,66 @@ // Copyright (C) Microsoft Corporation. All rights reserved. // +// +// Windows trace_region implementation using ETW TraceLogging. +// +// Events are emitted via TraceLoggingWrite as "TraceRegionStart" and +// "TraceRegionStop" events under the "Arcana.TraceRegion" ETW provider. +// Each event includes the region name and a unique cookie for correlating +// begin/end pairs across threads. +// +// TRACELOGGING_DEFINE_PROVIDER_STORAGE creates static (TU-local) provider +// storage with no external symbols, avoiding linker conflicts when included +// from multiple translation units. The handle is defined as a C++17 inline +// variable so all TUs share a single provider pointer. +// +// To capture and view traces (from an elevated command prompt): +// 1. Start an ETW trace session: +// tracelog -start ArcanaTrace -f arcana.etl -guid #B2A07E6E-A49F-4C4F-B9D2-8D3E5C7F1A2B +// 2. Run the application +// 3. Stop the trace: +// tracelog -stop ArcanaTrace +// 4. View the trace in Windows Performance Analyzer (WPA): +// wpa arcana.etl +// Look for "Arcana.TraceRegion" in the Generic Events table. +// Alternatively, decode to text: +// tracefmt -o arcana.txt arcana.etl +// +// Debug log output (at trace_level::log) goes to OutputDebugStringA, +// visible in the Visual Studio Output window or DebugView (SysInternals). +// + #pragma once +#include +#include +#include +#include +#include + +#pragma comment(lib, "advapi32.lib") + namespace arcana { + namespace detail + { + // Static per-TU storage — no external symbols, no linker conflicts. + TRACELOGGING_DEFINE_PROVIDER_STORAGE( + s_traceRegionProviderStorage, + "Arcana.TraceRegion", + // {B2A07E6E-A49F-4C4F-B9D2-8D3E5C7F1A2B} + (0xB2A07E6E, 0xA49F, 0x4C4F, 0xB9, 0xD2, 0x8D, 0x3E, 0x5C, 0x7F, 0x1A, 0x2B)); + + // C++17 inline — linker picks one definition, all TUs share the same handle. + inline TraceLoggingHProvider const g_traceRegionProvider = &s_traceRegionProviderStorage; + } + enum class trace_level { mark, log, }; - // TODO: https://docs.microsoft.com/en-us/windows/win32/tracelogging/tracelogging-native-quick-start class trace_region final { public: @@ -20,24 +69,99 @@ namespace arcana trace_region(const trace_region&) = delete; trace_region& operator=(const trace_region&) = delete; - trace_region(const char*) + trace_region(const char* name) : + m_cookie{s_enabled ? s_nextCookie.fetch_add(1, std::memory_order_relaxed) : 0}, + m_name{m_cookie != 0 ? name : ""} { + if (m_cookie != 0) + { + if (s_logEnabled) + { + char buf[256]; + std::snprintf(buf, sizeof(buf), "[trace_region] BEGIN %s (cookie=%d)\n", m_name.c_str(), m_cookie); + OutputDebugStringA(buf); + } + TraceLoggingWrite(detail::g_traceRegionProvider, + "TraceRegionStart", + TraceLoggingString(m_name.c_str(), "Name"), + TraceLoggingInt32(m_cookie, "Cookie")); + } } - trace_region(trace_region&&) = default; + // Move constructor transfers ownership; the moved-from region becomes inactive + // (cookie set to 0) so its destructor won't emit a spurious stop event. + trace_region(trace_region&& other) : + m_cookie{other.m_cookie}, + m_name{std::move(other.m_name)} + { + other.m_cookie = 0; + } ~trace_region() { + if (m_cookie != 0) + { + if (s_logEnabled) + { + char buf[256]; + std::snprintf(buf, sizeof(buf), "[trace_region] END (cookie=%d)\n", m_cookie); + OutputDebugStringA(buf); + } + TraceLoggingWrite(detail::g_traceRegionProvider, + "TraceRegionStop", + TraceLoggingString(m_name.c_str(), "Name"), + TraceLoggingInt32(m_cookie, "Cookie")); + } } - trace_region& operator=(trace_region&&) = default; + trace_region& operator=(trace_region&& other) + { + if (m_cookie != 0) + { + if (s_logEnabled) + { + char buf[256]; + std::snprintf(buf, sizeof(buf), "[trace_region] END (move) (cookie=%d)\n", m_cookie); + OutputDebugStringA(buf); + } + TraceLoggingWrite(detail::g_traceRegionProvider, + "TraceRegionStop", + TraceLoggingString(m_name.c_str(), "Name"), + TraceLoggingInt32(m_cookie, "Cookie")); + } + + m_cookie = other.m_cookie; + m_name = std::move(other.m_name); + other.m_cookie = 0; + + return *this; + } - static void enable(trace_level = trace_level::mark) + static void enable(trace_level level = trace_level::mark) { + TraceLoggingRegister(detail::g_traceRegionProvider); + s_enabled = true; + s_logEnabled = level == trace_level::log; } static void disable() { + s_enabled = false; + s_logEnabled = false; + TraceLoggingUnregister(detail::g_traceRegionProvider); } + + private: + static inline std::atomic s_enabled{false}; + static inline std::atomic s_logEnabled{false}; + static inline std::atomic s_nextCookie{1}; + + // Cookie uniquely identifies this trace interval, analogous to + // os_signpost_id_t on Apple. A cookie of 0 means the region is inactive. + int32_t m_cookie; + // Name is stored as std::string (not const char*) because callers may pass + // c_str() from a temporary std::string, and the stop event needs the name + // to match the corresponding start event for correlation. + std::string m_name; }; } From afd36afde38181ce183e46899c2bc8c6285dd2e3 Mon Sep 17 00:00:00 2001 From: Ryan Tremblay Date: Tue, 31 Mar 2026 11:50:27 -0700 Subject: [PATCH 06/12] Switch to logman --- Source/Windows/arcana/tracing/trace_region.h | 11 ++++------- 1 file changed, 4 insertions(+), 7 deletions(-) diff --git a/Source/Windows/arcana/tracing/trace_region.h b/Source/Windows/arcana/tracing/trace_region.h index 8ce4b7d..94bda86 100644 --- a/Source/Windows/arcana/tracing/trace_region.h +++ b/Source/Windows/arcana/tracing/trace_region.h @@ -17,15 +17,12 @@ // // To capture and view traces (from an elevated command prompt): // 1. Start an ETW trace session: -// tracelog -start ArcanaTrace -f arcana.etl -guid #B2A07E6E-A49F-4C4F-B9D2-8D3E5C7F1A2B +// logman create trace ArcanaTrace -p "{B2A07E6E-A49F-4C4F-B9D2-8D3E5C7F1A2B}" -o arcana.etl -ets // 2. Run the application // 3. Stop the trace: -// tracelog -stop ArcanaTrace -// 4. View the trace in Windows Performance Analyzer (WPA): -// wpa arcana.etl -// Look for "Arcana.TraceRegion" in the Generic Events table. -// Alternatively, decode to text: -// tracefmt -o arcana.txt arcana.etl +// logman stop ArcanaTrace -ets +// 4. Open arcana.etl in Windows Performance Analyzer (WPA) or PerfView. +// In WPA, look for "Arcana.TraceRegion" in the Generic Events table. // // Debug log output (at trace_level::log) goes to OutputDebugStringA, // visible in the Visual Studio Output window or DebugView (SysInternals). From 42c1233e62c43abd72e6b9dc21a9d02040452f75 Mon Sep 17 00:00:00 2001 From: Ryan Tremblay Date: Tue, 31 Mar 2026 12:53:26 -0700 Subject: [PATCH 07/12] Regions of Interest --- Source/Windows/arcana/tracing/trace_region.h | 52 +++++++++++++++----- 1 file changed, 39 insertions(+), 13 deletions(-) diff --git a/Source/Windows/arcana/tracing/trace_region.h b/Source/Windows/arcana/tracing/trace_region.h index 94bda86..a1eb714 100644 --- a/Source/Windows/arcana/tracing/trace_region.h +++ b/Source/Windows/arcana/tracing/trace_region.h @@ -5,10 +5,10 @@ // // Windows trace_region implementation using ETW TraceLogging. // -// Events are emitted via TraceLoggingWrite as "TraceRegionStart" and -// "TraceRegionStop" events under the "Arcana.TraceRegion" ETW provider. -// Each event includes the region name and a unique cookie for correlating -// begin/end pairs across threads. +// Events are emitted as ETW activity start/stop pairs via TraceLoggingWriteActivity +// under the "Arcana.TraceRegion" provider. Each trace region gets a unique activity +// GUID (derived from an integer cookie), allowing WPA to correlate begin/end events +// into duration spans — even across threads. // // TRACELOGGING_DEFINE_PROVIDER_STORAGE creates static (TU-local) provider // storage with no external symbols, avoiding linker conflicts when included @@ -22,7 +22,8 @@ // 3. Stop the trace: // logman stop ArcanaTrace -ets // 4. Open arcana.etl in Windows Performance Analyzer (WPA) or PerfView. -// In WPA, look for "Arcana.TraceRegion" in the Generic Events table. +// In WPA, trace regions appear as duration spans in the Regions of Interest +// activity view under "Arcana.TraceRegion". // // Debug log output (at trace_level::log) goes to OutputDebugStringA, // visible in the Visual Studio Output window or DebugView (SysInternals). @@ -34,6 +35,7 @@ #include #include #include +#include #include #pragma comment(lib, "advapi32.lib") @@ -68,7 +70,8 @@ namespace arcana trace_region(const char* name) : m_cookie{s_enabled ? s_nextCookie.fetch_add(1, std::memory_order_relaxed) : 0}, - m_name{m_cookie != 0 ? name : ""} + m_name{m_cookie != 0 ? name : ""}, + m_activityId{cookieToGuid(m_cookie)} { if (m_cookie != 0) { @@ -78,8 +81,11 @@ namespace arcana std::snprintf(buf, sizeof(buf), "[trace_region] BEGIN %s (cookie=%d)\n", m_name.c_str(), m_cookie); OutputDebugStringA(buf); } - TraceLoggingWrite(detail::g_traceRegionProvider, - "TraceRegionStart", + TraceLoggingWriteActivity(detail::g_traceRegionProvider, + "TraceRegion", + &m_activityId, + nullptr, + TraceLoggingOpcode(EVENT_TRACE_TYPE_START), TraceLoggingString(m_name.c_str(), "Name"), TraceLoggingInt32(m_cookie, "Cookie")); } @@ -89,7 +95,8 @@ namespace arcana // (cookie set to 0) so its destructor won't emit a spurious stop event. trace_region(trace_region&& other) : m_cookie{other.m_cookie}, - m_name{std::move(other.m_name)} + m_name{std::move(other.m_name)}, + m_activityId{other.m_activityId} { other.m_cookie = 0; } @@ -104,8 +111,11 @@ namespace arcana std::snprintf(buf, sizeof(buf), "[trace_region] END (cookie=%d)\n", m_cookie); OutputDebugStringA(buf); } - TraceLoggingWrite(detail::g_traceRegionProvider, - "TraceRegionStop", + TraceLoggingWriteActivity(detail::g_traceRegionProvider, + "TraceRegion", + &m_activityId, + nullptr, + TraceLoggingOpcode(EVENT_TRACE_TYPE_STOP), TraceLoggingString(m_name.c_str(), "Name"), TraceLoggingInt32(m_cookie, "Cookie")); } @@ -121,14 +131,18 @@ namespace arcana std::snprintf(buf, sizeof(buf), "[trace_region] END (move) (cookie=%d)\n", m_cookie); OutputDebugStringA(buf); } - TraceLoggingWrite(detail::g_traceRegionProvider, - "TraceRegionStop", + TraceLoggingWriteActivity(detail::g_traceRegionProvider, + "TraceRegion", + &m_activityId, + nullptr, + TraceLoggingOpcode(EVENT_TRACE_TYPE_STOP), TraceLoggingString(m_name.c_str(), "Name"), TraceLoggingInt32(m_cookie, "Cookie")); } m_cookie = other.m_cookie; m_name = std::move(other.m_name); + m_activityId = other.m_activityId; other.m_cookie = 0; return *this; @@ -149,6 +163,15 @@ namespace arcana } private: + // Derives a deterministic GUID from the cookie for ETW activity correlation. + // Only needs to be unique within a single trace session. + static GUID cookieToGuid(int32_t cookie) + { + // Use the provider GUID as a base, with the cookie in Data1. + return {static_cast(cookie), 0xA49F, 0x4C4F, + {0xB9, 0xD2, 0x8D, 0x3E, 0x5C, 0x7F, 0x1A, 0x2B}}; + } + static inline std::atomic s_enabled{false}; static inline std::atomic s_logEnabled{false}; static inline std::atomic s_nextCookie{1}; @@ -160,5 +183,8 @@ namespace arcana // c_str() from a temporary std::string, and the stop event needs the name // to match the corresponding start event for correlation. std::string m_name; + // Activity GUID derived from cookie, used by ETW to correlate start/stop + // events into duration spans in WPA. + GUID m_activityId; }; } From 1f315bf656c9848feef1aeac587a878189c33ec2 Mon Sep 17 00:00:00 2001 From: Ryan Tremblay Date: Thu, 2 Apr 2026 14:50:04 -0700 Subject: [PATCH 08/12] PR feedback --- Source/Windows/arcana/tracing/trace_region.h | 32 ++++++++++++++++++-- 1 file changed, 29 insertions(+), 3 deletions(-) diff --git a/Source/Windows/arcana/tracing/trace_region.h b/Source/Windows/arcana/tracing/trace_region.h index a1eb714..b2aa3d0 100644 --- a/Source/Windows/arcana/tracing/trace_region.h +++ b/Source/Windows/arcana/tracing/trace_region.h @@ -33,6 +33,7 @@ #include #include +#include #include #include #include @@ -71,7 +72,8 @@ namespace arcana trace_region(const char* name) : m_cookie{s_enabled ? s_nextCookie.fetch_add(1, std::memory_order_relaxed) : 0}, m_name{m_cookie != 0 ? name : ""}, - m_activityId{cookieToGuid(m_cookie)} + m_activityId{cookieToGuid(m_cookie)}, + m_registration{m_cookie != 0 ? s_registration : nullptr} { if (m_cookie != 0) { @@ -96,7 +98,8 @@ namespace arcana trace_region(trace_region&& other) : m_cookie{other.m_cookie}, m_name{std::move(other.m_name)}, - m_activityId{other.m_activityId} + m_activityId{other.m_activityId}, + m_registration{std::move(other.m_registration)} { other.m_cookie = 0; } @@ -143,6 +146,7 @@ namespace arcana m_cookie = other.m_cookie; m_name = std::move(other.m_name); m_activityId = other.m_activityId; + m_registration = std::move(other.m_registration); other.m_cookie = 0; return *this; @@ -151,6 +155,10 @@ namespace arcana static void enable(trace_level level = trace_level::mark) { TraceLoggingRegister(detail::g_traceRegionProvider); + // Create a shared_ptr whose custom deleter calls TraceLoggingUnregister. + // Each active trace_region holds a copy, so the provider stays registered + // until disable() is called AND all outstanding regions are destroyed. + s_registration = std::make_shared(); s_enabled = true; s_logEnabled = level == trace_level::log; } @@ -159,10 +167,23 @@ namespace arcana { s_enabled = false; s_logEnabled = false; - TraceLoggingUnregister(detail::g_traceRegionProvider); + // Release our ref. If active trace_regions still hold copies, + // the provider stays registered until their destructors run. + s_registration.reset(); } private: + // RAII guard for provider registration. When the last shared_ptr to this + // object is released, the provider is unregistered. This ensures the + // provider stays registered as long as any trace_region is alive. + struct ProviderRegistration + { + ~ProviderRegistration() + { + TraceLoggingUnregister(detail::g_traceRegionProvider); + } + }; + // Derives a deterministic GUID from the cookie for ETW activity correlation. // Only needs to be unique within a single trace session. static GUID cookieToGuid(int32_t cookie) @@ -175,6 +196,7 @@ namespace arcana static inline std::atomic s_enabled{false}; static inline std::atomic s_logEnabled{false}; static inline std::atomic s_nextCookie{1}; + static inline std::shared_ptr s_registration; // Cookie uniquely identifies this trace interval, analogous to // os_signpost_id_t on Apple. A cookie of 0 means the region is inactive. @@ -186,5 +208,9 @@ namespace arcana // Activity GUID derived from cookie, used by ETW to correlate start/stop // events into duration spans in WPA. GUID m_activityId; + // Ref-counted handle to the provider registration. Ensures the provider + // stays registered until this region emits its stop event, even if + // disable() is called while regions are still alive. + std::shared_ptr m_registration; }; } From 52d5241decda3b442cc8660febac76ccf9da8252 Mon Sep 17 00:00:00 2001 From: Ryan Tremblay Date: Thu, 2 Apr 2026 14:54:21 -0700 Subject: [PATCH 09/12] PR feedback --- Source/Android/arcana/tracing/trace_region.h | 5 +++++ Source/Apple/arcana/tracing/trace_region.h | 5 +++++ Source/Windows/arcana/tracing/trace_region.h | 5 +++++ 3 files changed, 15 insertions(+) diff --git a/Source/Android/arcana/tracing/trace_region.h b/Source/Android/arcana/tracing/trace_region.h index 77ecb2a..6ea5aa0 100644 --- a/Source/Android/arcana/tracing/trace_region.h +++ b/Source/Android/arcana/tracing/trace_region.h @@ -90,6 +90,11 @@ namespace arcana trace_region& operator=(trace_region&& other) { + if (this == &other) + { + return *this; + } + if (m_cookie != 0) { if (s_logEnabled) diff --git a/Source/Apple/arcana/tracing/trace_region.h b/Source/Apple/arcana/tracing/trace_region.h index 0bee87c..924b16c 100644 --- a/Source/Apple/arcana/tracing/trace_region.h +++ b/Source/Apple/arcana/tracing/trace_region.h @@ -76,6 +76,11 @@ namespace arcana trace_region& operator=(trace_region&& other) { + if (this == &other) + { + return *this; + } + if (m_id != OS_SIGNPOST_ID_NULL) { if (s_logEnabled) diff --git a/Source/Windows/arcana/tracing/trace_region.h b/Source/Windows/arcana/tracing/trace_region.h index b2aa3d0..de5da03 100644 --- a/Source/Windows/arcana/tracing/trace_region.h +++ b/Source/Windows/arcana/tracing/trace_region.h @@ -126,6 +126,11 @@ namespace arcana trace_region& operator=(trace_region&& other) { + if (this == &other) + { + return *this; + } + if (m_cookie != 0) { if (s_logEnabled) From b32094a66a3fe9cc365c0eeec9e9cc5cb913c7b3 Mon Sep 17 00:00:00 2001 From: Ryan Tremblay Date: Thu, 2 Apr 2026 15:00:57 -0700 Subject: [PATCH 10/12] PR feedback --- Source/Android/arcana/tracing/trace_region.h | 8 +++----- Source/Apple/arcana/tracing/trace_region.h | 8 +++----- 2 files changed, 6 insertions(+), 10 deletions(-) diff --git a/Source/Android/arcana/tracing/trace_region.h b/Source/Android/arcana/tracing/trace_region.h index 6ea5aa0..8bd4913 100644 --- a/Source/Android/arcana/tracing/trace_region.h +++ b/Source/Android/arcana/tracing/trace_region.h @@ -36,8 +36,6 @@ #include #endif -#define TRACE_TAG "trace_region" - namespace arcana { enum class trace_level @@ -61,7 +59,7 @@ namespace arcana { if (s_logEnabled) { - __android_log_print(ANDROID_LOG_DEBUG, TRACE_TAG, "[trace_region] BEGIN %s (cookie=%d, this=%p)", m_name.c_str(), m_cookie, static_cast(this)); + __android_log_print(ANDROID_LOG_DEBUG, "trace_region", "[trace_region] BEGIN %s (cookie=%d, this=%p)", m_name.c_str(), m_cookie, static_cast(this)); } traceBegin(m_name.c_str(), m_cookie); } @@ -82,7 +80,7 @@ namespace arcana { if (s_logEnabled) { - __android_log_print(ANDROID_LOG_DEBUG, TRACE_TAG, "[trace_region] END (cookie=%d, this=%p)", m_cookie, static_cast(this)); + __android_log_print(ANDROID_LOG_DEBUG, "trace_region", "[trace_region] END (cookie=%d, this=%p)", m_cookie, static_cast(this)); } traceEnd(m_name.c_str(), m_cookie); } @@ -99,7 +97,7 @@ namespace arcana { if (s_logEnabled) { - __android_log_print(ANDROID_LOG_DEBUG, TRACE_TAG, "[trace_region] END (move) (cookie=%d, this=%p)", m_cookie, static_cast(this)); + __android_log_print(ANDROID_LOG_DEBUG, "trace_region", "[trace_region] END (move) (cookie=%d, this=%p)", m_cookie, static_cast(this)); } traceEnd(m_name.c_str(), m_cookie); } diff --git a/Source/Apple/arcana/tracing/trace_region.h b/Source/Apple/arcana/tracing/trace_region.h index 924b16c..dd980c8 100644 --- a/Source/Apple/arcana/tracing/trace_region.h +++ b/Source/Apple/arcana/tracing/trace_region.h @@ -26,8 +26,6 @@ #include #include -#define SIGNPOST_NAME "trace_region" - namespace arcana { enum class trace_level @@ -52,7 +50,7 @@ namespace arcana { os_log_debug(s_log, "[trace_region] BEGIN %s (id=%llu, this=%p)", name, m_id, this); } - os_signpost_interval_begin(s_log, m_id, SIGNPOST_NAME, "%s", name); + os_signpost_interval_begin(s_log, m_id, "trace_region", "%s", name); } } @@ -70,7 +68,7 @@ namespace arcana { os_log_debug(s_log, "[trace_region] END (id=%llu, this=%p)", m_id, this); } - os_signpost_interval_end(s_log, m_id, SIGNPOST_NAME); + os_signpost_interval_end(s_log, m_id, "trace_region"); } } @@ -87,7 +85,7 @@ namespace arcana { os_log_debug(s_log, "[trace_region] END (move) (id=%llu, this=%p)", m_id, this); } - os_signpost_interval_end(s_log, m_id, SIGNPOST_NAME); + os_signpost_interval_end(s_log, m_id, "trace_region"); } m_id = other.m_id; From 69e59d5bbb3e6680e5ace49530c24e58a91b955f Mon Sep 17 00:00:00 2001 From: Ryan Tremblay Date: Thu, 2 Apr 2026 15:03:42 -0700 Subject: [PATCH 11/12] PR feedback --- Source/Android/arcana/tracing/trace_region.h | 10 ++++++++++ Source/Apple/arcana/tracing/trace_region.h | 10 ++++++++++ Source/Windows/arcana/tracing/trace_region.h | 10 ++++++++++ 3 files changed, 30 insertions(+) diff --git a/Source/Android/arcana/tracing/trace_region.h b/Source/Android/arcana/tracing/trace_region.h index 8bd4913..c75ad1e 100644 --- a/Source/Android/arcana/tracing/trace_region.h +++ b/Source/Android/arcana/tracing/trace_region.h @@ -111,12 +111,22 @@ namespace arcana static void enable(trace_level level = trace_level::mark) { + if (s_enabled) + { + return; + } + s_enabled = true; s_logEnabled = level == trace_level::log; } static void disable() { + if (!s_enabled) + { + return; + } + s_enabled = false; s_logEnabled = false; } diff --git a/Source/Apple/arcana/tracing/trace_region.h b/Source/Apple/arcana/tracing/trace_region.h index dd980c8..8f734aa 100644 --- a/Source/Apple/arcana/tracing/trace_region.h +++ b/Source/Apple/arcana/tracing/trace_region.h @@ -96,12 +96,22 @@ namespace arcana static void enable(trace_level level = trace_level::mark) { + if (s_enabled) + { + return; + } + s_enabled = true; s_logEnabled = level == trace_level::log; } static void disable() { + if (!s_enabled) + { + return; + } + s_enabled = false; s_logEnabled = false; } diff --git a/Source/Windows/arcana/tracing/trace_region.h b/Source/Windows/arcana/tracing/trace_region.h index de5da03..10e6ab5 100644 --- a/Source/Windows/arcana/tracing/trace_region.h +++ b/Source/Windows/arcana/tracing/trace_region.h @@ -159,6 +159,11 @@ namespace arcana static void enable(trace_level level = trace_level::mark) { + if (s_enabled) + { + return; + } + TraceLoggingRegister(detail::g_traceRegionProvider); // Create a shared_ptr whose custom deleter calls TraceLoggingUnregister. // Each active trace_region holds a copy, so the provider stays registered @@ -170,6 +175,11 @@ namespace arcana static void disable() { + if (!s_enabled) + { + return; + } + s_enabled = false; s_logEnabled = false; // Release our ref. If active trace_regions still hold copies, From 9a15fefdbc41683446828dd48d6d10384eff3f75 Mon Sep 17 00:00:00 2001 From: Ryan Tremblay Date: Thu, 2 Apr 2026 15:26:59 -0700 Subject: [PATCH 12/12] PR feedback --- Source/Windows/arcana/tracing/trace_region.h | 7 ++++--- 1 file changed, 4 insertions(+), 3 deletions(-) diff --git a/Source/Windows/arcana/tracing/trace_region.h b/Source/Windows/arcana/tracing/trace_region.h index 10e6ab5..940c316 100644 --- a/Source/Windows/arcana/tracing/trace_region.h +++ b/Source/Windows/arcana/tracing/trace_region.h @@ -201,11 +201,12 @@ namespace arcana // Derives a deterministic GUID from the cookie for ETW activity correlation. // Only needs to be unique within a single trace session. + // Fixed bytes are intentionally different from the provider GUID to avoid + // collisions when the cookie happens to match the provider's Data1. static GUID cookieToGuid(int32_t cookie) { - // Use the provider GUID as a base, with the cookie in Data1. - return {static_cast(cookie), 0xA49F, 0x4C4F, - {0xB9, 0xD2, 0x8D, 0x3E, 0x5C, 0x7F, 0x1A, 0x2B}}; + return {static_cast(cookie), 0x1E3A, 0x4B5C, + {0xA7, 0xD0, 0x6F, 0x2E, 0x9C, 0x8B, 0x3D, 0x14}}; } static inline std::atomic s_enabled{false};