GPU async timing instrumentation via MX_TRACE_ASYNC

source/MaterialXTest/MaterialXRenderGlsl/RenderGlsl.cpp

@@ -19,8 +19,59 @@
 
 #include <MaterialXFormat/Util.h>
 
+#ifdef MATERIALX_BUILD_PERFETTO_TRACING
+#include <MaterialXRenderGlsl/External/Glad/glad.h>
+#include <chrono>
+#endif
+
 namespace mx = MaterialX;
 
+#ifdef MATERIALX_BUILD_PERFETTO_TRACING
+namespace {
+
+uint64_t getCurrentTimeNs()
+{
+    using namespace std::chrono;
+    return duration_cast<nanoseconds>(steady_clock::now().time_since_epoch()).count();
+}
+
+class GpuTimerQuery
+{
+  public:
+    GpuTimerQuery()
+    {
+        glGenQueries(1, &_query);
+    }
+
+    ~GpuTimerQuery()
+    {
+        glDeleteQueries(1, &_query);
+    }
+
+    void begin()
+    {
+        glBeginQuery(GL_TIME_ELAPSED, _query);
+    }
+
+    void end()
+    {
+        glEndQuery(GL_TIME_ELAPSED);
+    }
+
+    uint64_t getDurationNs()
+    {
+        GLuint64 elapsedTime;
+        glGetQueryObjectui64v(_query, GL_QUERY_RESULT, &elapsedTime);
+        return elapsedTime;
+    }
+
+  private:
+    GLuint _query;
+};
+
+} // anonymous namespace
+#endif // MATERIALX_BUILD_PERFETTO_TRACING
+
 //
 // Render validation tester for the GLSL shading language
 //
@@ -359,7 +410,19 @@ bool GlslShaderRenderTester::runRenderer(const std::string& shaderName,
                     unsigned int height = (unsigned int) testOptions.renderSize[1] * supersampleFactor;
                     _renderer->setSize(width, height);
 
+#ifdef MATERIALX_BUILD_PERFETTO_TRACING
+                    uint64_t cpuStartNs = getCurrentTimeNs();
+                    GpuTimerQuery gpuTimer;
+                    gpuTimer.begin();
+#endif
                     _renderer->render();
+
+#ifdef MATERIALX_BUILD_PERFETTO_TRACING
+                    gpuTimer.end();
+                    glFinish();
+                    uint64_t gpuDurationNs = gpuTimer.getDurationNs();
+                    MX_TRACE_ASYNC(mx::Tracing::AsyncTrack::GPU, mx::Tracing::Category::Render, shaderName.c_str(), cpuStartNs, gpuDurationNs);
+#endif
                 }
 
                 {

source/MaterialXTrace/PerfettoSink.cpp

@@ -7,7 +7,9 @@
 
 #ifdef MATERIALX_BUILD_PERFETTO_TRACING
 
+#include <cstdint>
 #include <fstream>
+#include <limits>
 #include <mutex>
 
 // Define Perfetto trace categories for MaterialX
@@ -31,6 +33,10 @@ MATERIALX_NAMESPACE_BEGIN
 namespace Tracing
 {
 
+// Stable Perfetto track IDs for async tracks (must not collide with thread IDs).
+// Use max uint64_t minus small offsets -- no OS will assign these as thread IDs.
+constexpr uint64_t GPU_TRACK_ID = std::numeric_limits<uint64_t>::max();
+
 PerfettoSink::PerfettoSink(std::string outputPath, size_t bufferSizeKb)
     : _outputPath(std::move(outputPath))
 {
@@ -41,6 +47,14 @@ PerfettoSink::PerfettoSink(std::string outputPath, size_t bufferSizeKb)
         args.backends |= perfetto::kInProcessBackend;
         perfetto::Tracing::Initialize(args);
         perfetto::TrackEvent::Register();
+
+        // Initialize async track descriptors with stable IDs and names
+        {
+            perfetto::Track gpuTrack(GPU_TRACK_ID);
+            auto desc = gpuTrack.Serialize();
+            desc.set_name("GPU");
+            perfetto::TrackEvent::SetTrackDescriptor(gpuTrack, desc);
+        }
     });
 
     // Create and start a tracing session
@@ -155,6 +169,34 @@ void PerfettoSink::counter(Category category, const char* name, double value)
     }
 }
 
+void PerfettoSink::asyncEvent(AsyncTrack track, Category category,
+                              const char* eventName, uint64_t startNs, uint64_t durationNs)
+{
+    // Currently only GPU track is supported
+    assert(track == AsyncTrack::GPU && "Only AsyncTrack::GPU is currently supported");
+    perfetto::Track perfTrack(GPU_TRACK_ID);
+
+    // Emit begin and end events with explicit timestamps
+    switch (category)
+    {
+        case Category::Render:
+            TRACE_EVENT_BEGIN("mx.render", nullptr, perfTrack, startNs,
+                [&](perfetto::EventContext ctx) { ctx.event()->set_name(eventName); });
+            TRACE_EVENT_END("mx.render", perfTrack, startNs + durationNs);
+            break;
+        case Category::ShaderGen:
+            TRACE_EVENT_BEGIN("mx.shadergen", nullptr, perfTrack, startNs,
+                [&](perfetto::EventContext ctx) { ctx.event()->set_name(eventName); });
+            TRACE_EVENT_END("mx.shadergen", perfTrack, startNs + durationNs);
+            break;
+        default:
+            TRACE_EVENT_BEGIN("mx.render", nullptr, perfTrack, startNs,
+                [&](perfetto::EventContext ctx) { ctx.event()->set_name(eventName); });
+            TRACE_EVENT_END("mx.render", perfTrack, startNs + durationNs);
+            break;
+    }
+}
+
 void PerfettoSink::setThreadName(const char* name)
 {
     // Set thread name for trace visualization

source/MaterialXTrace/PerfettoSink.h

@@ -70,6 +70,8 @@ class PerfettoSink : public Sink
     void beginEvent(Category category, const char* name) override;
     void endEvent(Category category) override;
     void counter(Category category, const char* name, double value) override;
+    void asyncEvent(AsyncTrack track, Category category,
+                   const char* eventName, uint64_t startNs, uint64_t durationNs) override;
     void setThreadName(const char* name) override;
 
   private:

source/MaterialXTrace/Tracing.h

@@ -22,6 +22,7 @@
 
 #include <cassert>
 #include <cstddef>
+#include <cstdint>
 #include <memory>
 #include <string>
 
@@ -55,6 +56,15 @@ enum class Category
     Count
 };
 
+/// @enum AsyncTrack
+/// Async track identifiers for operations with explicit timing (e.g., GPU work).
+enum class AsyncTrack
+{
+    /// GPU render operations (measured via GL timer queries)
+    GPU = 0
+    // Add more tracks here as needed (e.g., Compile, Transfer)
+};
+
 /// @class Sink
 /// Abstract tracing sink interface.
 /// 
@@ -74,6 +84,17 @@ class MX_TRACE_API Sink
     /// Record a counter value (e.g., GPU time, memory usage).
     virtual void counter(Category category, const char* name, double value) = 0;
 
+    /// Record an async event with explicit timing (e.g., GPU operations).
+    /// This creates a slice on a separate track, useful for GPU work that
+    /// runs asynchronously from CPU traces.
+    /// @param track The async track to record on (e.g., AsyncTrack::GPU)
+    /// @param category The trace category for filtering
+    /// @param eventName Name of the event (e.g., material name)
+    /// @param startNs Start timestamp in nanoseconds (can be approximate)
+    /// @param durationNs Duration in nanoseconds (should be accurate)
+    virtual void asyncEvent(AsyncTrack track, Category category,
+                           const char* eventName, uint64_t startNs, uint64_t durationNs) = 0;
+
     /// Set the current thread's name for trace visualization.
     virtual void setThreadName(const char* name) = 0;
 };
@@ -142,6 +163,14 @@ class MX_TRACE_API Dispatcher
             _sink->counter(category, name, value);
     }
 
+    /// Record an async event with explicit timing.
+    void asyncEvent(AsyncTrack track, Category category,
+                   const char* eventName, uint64_t startNs, uint64_t durationNs)
+    {
+        if (_sink)
+            _sink->asyncEvent(track, category, eventName, startNs, durationNs);
+    }
+
   private:
     Dispatcher() = default;
     Dispatcher(const Dispatcher&) = delete;
@@ -234,6 +263,10 @@ MATERIALX_NAMESPACE_END
 #define MX_TRACE_COUNTER(category, name, value) \
     MaterialX::Tracing::Dispatcher::getInstance().counter(category, name, value)
 
+/// Record an async event with explicit timing (e.g., GPU operations).
+#define MX_TRACE_ASYNC(track, category, eventName, startNs, durationNs) \
+    MaterialX::Tracing::Dispatcher::getInstance().asyncEvent(track, category, eventName, startNs, durationNs)
+
 /// Begin a trace event (must be paired with MX_TRACE_END).
 #define MX_TRACE_BEGIN(category, name) \
     MaterialX::Tracing::Dispatcher::getInstance().beginEvent(category, name)
@@ -247,6 +280,7 @@ MATERIALX_NAMESPACE_END
 #define MX_TRACE_SCOPE(category, name)
 #define MX_TRACE_FUNCTION(category)
 #define MX_TRACE_COUNTER(category, name, value)
+#define MX_TRACE_ASYNC(track, category, eventName, startNs, durationNs)
 #define MX_TRACE_BEGIN(category, name)
 #define MX_TRACE_END(category)