Add ETDump tracing to CpuBackend (#23926)

Summary:
Pull Request resolved: #23926

`CPUPlan` records one ETDump delegate event per step, named `provider/implementation:first_node[+N]`, so every provider is traced without provider changes. The XNNPACK provider enables XNNPACK runtime profiling when a tracer is attached and logs `<operator> #<n>` events, such as `Transpose (ND, X32) #3`, inside its step, with each operator's input and output shapes as JSON delegate metadata.

Shapes come from XNNPACK's internal runtime (`src/xnnpack/subgraph.h`). That header dependency and the code that reads it are only compiled when `ET_EVENT_TRACER_ENABLED` is defined. `runner` writes an ETDump when `ET_CPU_ETDUMP` is set.

CMake builds `XNNProfiler` as a separate `xnnpack_profiler` library that `xnnpack_backend` and the CPU provider targets link, matching the Buck split, and adds XNNPACK's source root to the CPU targets' include path for the traced build. The Apple XNNPACK framework packs the new archive.

Authored with Claude Code.

Differential Revision: D125525223

Author: JakeStevens

backends/cpu/CMakeLists.txt

@@ -35,7 +35,12 @@ if(EXECUTORCH_BUILD_NATIVE_CPU)
   target_link_libraries(
     cpu_xnnpack
     PUBLIC cpu_runtime
-    PRIVATE extension_threadpool
+    PRIVATE extension_threadpool xnnpack_profiler
+  )
+  # Traced builds include XNNPACK's internal runtime header from its source
+  # root.
+  target_include_directories(
+    cpu_xnnpack PRIVATE $<TARGET_PROPERTY:XNNPACK,SOURCE_DIR>
   )
   if(EXECUTORCH_BUILD_SHARED)
     target_link_libraries(cpu_xnnpack PRIVATE xnnpack_shared)
@@ -106,7 +111,10 @@ add_library(
 )
 target_link_libraries(
   cpu_backend PRIVATE native_program extension_threadpool
-                      optimized_native_cpu_ops_lib
+                      optimized_native_cpu_ops_lib xnnpack_profiler
+)
+target_include_directories(
+  cpu_backend PRIVATE $<TARGET_PROPERTY:XNNPACK,SOURCE_DIR>
 )
 if(EXECUTORCH_BUILD_SHARED)
   set_target_properties(

backends/cpu/runtime/CPUBackend.cpp

@@ -93,7 +93,10 @@ class CPUExecution {
       return error;
     }
     plan_ = std::make_unique<CPUPlan>(
-        graph, buffers_, std::move(configuration), current_execution_context());
+        graph,
+        buffers_,
+        std::move(configuration),
+        current_execution_context(context.event_tracer()));
     error = plan_->select();
     if (error != Error::Ok) {
       return error;

backends/cpu/runtime/CPUPlan.cpp

@@ -5,6 +5,7 @@
 // LICENSE file in the root directory of this source tree.
 
 #include <executorch/backends/cpu/runtime/CPUPlan.h>
+#include <executorch/runtime/core/event_tracer_hooks_delegate.h>
 
 #include <algorithm>
 #include <cstring>
@@ -174,7 +175,13 @@ Error CPUPlan::execute(const ExecutionContext& context) {
     }
   }
   for (auto& step : steps_) {
+    const auto entry = event_tracer_start_profiling_delegate(
+        context.event_tracer,
+        step.trace_name.c_str(),
+        kUnsetDelegateDebugIntId);
     const auto error = step.executable->run(context);
+    event_tracer_end_profiling_delegate(context.event_tracer, entry);
+    step.executable->submit_trace();
     if (error != Error::Ok) {
       return error;
     }
@@ -344,7 +351,7 @@ Error CPUPlan::select() {
     // cycle.
     if (steps_.empty() || steps_.back().implementation != selected ||
         !selected->accepts_regions() || !connected) {
-      steps_.push_back({selected_provider, selected, {}, nullptr, {}});
+      steps_.push_back({selected_provider, selected, {}, nullptr, {}, {}});
     }
     steps_.back().region.nodes.push_back(id);
     node_regions.at(id) = steps_.size() - 1;
@@ -382,6 +389,14 @@ Error CPUPlan::select() {
     step.region.outputs.assign(outputs.begin(), outputs.end());
     std::sort(step.region.inputs.begin(), step.region.inputs.end());
     std::sort(step.region.outputs.begin(), step.region.outputs.end());
+#ifdef ET_EVENT_TRACER_ENABLED
+    step.trace_name = std::string(step.provider->name()) + "/" +
+        std::string(step.implementation->name()) + ":" +
+        graph.node(step.region.nodes.front()).name;
+    if (step.region.nodes.size() > 1) {
+      step.trace_name += "+" + std::to_string(step.region.nodes.size() - 1);
+    }
+#endif
   }
   requirements_.resize(graph.values.size());
   for (size_t id = 0; id < graph.values.size(); ++id) {

backends/cpu/runtime/CPUPlan.h

@@ -18,6 +18,8 @@ struct PlanStep {
   KernelRegion region;
   std::unique_ptr<Executable> executable;
   StorageRequirements storage;
+  /// ETDump delegate event name: provider/implementation:first_node[+N].
+  std::string trace_name;
 };
 
 /// One static prepared plan. Graph, bindings and allocator outlive the plan.

backends/cpu/runtime/KernelProvider.h

@@ -65,6 +65,8 @@ runtime::Result<Buffer> allocate_buffer(
 struct ExecutionContext {
   size_t threads = 1;
   pthreadpool* threadpool = nullptr;
+  /// Providers enable internal profiling when set during preparation. The plan
+  /// records one delegate event per step when set during execution.
   runtime::EventTracer* event_tracer = nullptr;
 };
 
@@ -122,6 +124,9 @@ class Executable {
   virtual runtime::Error reshape() = 0;
   virtual runtime::Error bind(const Buffer& scratch = {}) = 0;
   virtual runtime::Error run(const ExecutionContext& context) = 0;
+  /// Called after the plan closes the step's trace event, so internal events
+  /// are logged without inflating it. Called even when run fails.
+  virtual void submit_trace() {}
 };
 
 class KernelImplementation {

backends/cpu/runtime/providers/xnnpack/XNNPACKProvider.cpp

@@ -6,22 +6,29 @@
 
 #include <executorch/backends/cpu/runtime/op_helpers/Convolution.h>
 #include <executorch/backends/cpu/runtime/providers/xnnpack/XNNPACKProvider.h>
+#include <executorch/backends/xnnpack/runtime/profiling/XNNProfiler.h>
 #include <executorch/extension/memory_allocator/malloc_memory_allocator.h>
 #include <xnnpack.h>
+#ifdef ET_EVENT_TRACER_ENABLED
+#include "src/xnnpack/subgraph.h" // @manual
+#endif
 
 #include <algorithm>
 #include <array>
 #include <cmath>
 #include <limits>
 #include <map>
 #include <numeric>
+#include <string>
 #include <string_view>
+#include <unordered_map>
 #include <unordered_set>
 #include <utility>
 
 namespace executorch::backends::cpu {
 namespace {
 using namespace executorch::runtime;
+using executorch::backends::xnnpack::delegate::profiling::XNNProfiler;
 
 Error check(xnn_status status, const char* operation) {
   if (status == xnn_status_success) {
@@ -41,6 +48,17 @@ Error check(xnn_status status, const char* operation) {
     }                                                            \
   } while (false)
 
+bool profiling_ok(Error error, const char* operation) {
+  if (error != Error::Ok) {
+    ET_LOG(
+        Error,
+        "CPU XNNPACK profiling %s failed: %u",
+        operation,
+        static_cast<unsigned int>(error));
+  }
+  return error == Error::Ok;
+}
+
 bool constant(const ptn::Value& value) {
   return value.role == ptn::ValueRole::Parameter ||
       value.role == ptn::ValueRole::ConstantTensor ||
@@ -244,6 +262,8 @@ class XNNState {
     return std::exchange(packing_source_bytes_, 0);
   }
   std::map<std::pair<ptn::ValueId, bool>, Buffer> converted_weights;
+  /// Numbers ETDump operator names uniquely across the provider's regions.
+  std::unordered_map<std::string, uint32_t> operator_counts;
   xnn_workspace_t workspace = nullptr;
   xnn_weights_cache_t cache = nullptr;
 
@@ -334,13 +354,27 @@ class XNNExecutable final : public Executable {
         return error;
       }
     }
+    uint32_t runtime_flags = 0;
+#ifdef ET_EVENT_TRACER_ENABLED
+    auto* tracer = context_.execution.event_tracer;
+    if (tracer &&
+        tracer->event_tracer_profiling_level() >
+            EventTracerProfilingLevel::kProfileMethodOnly) {
+      runtime_flags |= XNN_FLAG_BASIC_PROFILING;
+    }
+#endif
     CPU_XNN_CHECK(xnn_create_runtime_v4(
         subgraph_,
         state_.cache,
         state_.workspace,
         context_.execution.threadpool,
-        0,
+        runtime_flags,
         &runtime_));
+    if (runtime_flags & XNN_FLAG_BASIC_PROFILING) {
+      profiling_ = profiling_ok(
+          profiler_.initialize(runtime_, &state_.operator_counts),
+          "initialization");
+    }
     return Error::Ok;
   }
 
@@ -359,6 +393,11 @@ class XNNExecutable final : public Executable {
           "XNNPACK inferred a different semantic shape for %s",
           context_.graph.value(binding.id).name.c_str());
     }
+#ifdef ET_EVENT_TRACER_ENABLED
+    if (profiling_) {
+      profiling_ok(describe_operators(), "metadata");
+    }
+#endif
     return Error::Ok;
   }
 
@@ -381,19 +420,65 @@ class XNNExecutable final : public Executable {
     return Error::Ok;
   }
 
-  Error run(const ExecutionContext&) override {
+  Error run(const ExecutionContext& context) override {
     ET_CHECK_OR_RETURN_ERROR(
         bound_, InvalidState, "XNNPACK requires a successful bind");
     // Shared workspace growth can relocate another region's internal values.
     CPU_XNN_CHECK(
         xnn_setup_runtime_v2(runtime_, external_.size(), external_.data()));
+    tracing_ = profiling_ &&
+        profiling_ok(profiler_.start(context.event_tracer), "start");
     CPU_XNN_CHECK(xnn_invoke_runtime(runtime_));
     return Error::Ok;
   }
 
+  void submit_trace() override {
+    if (tracing_) {
+      tracing_ = false;
+      profiling_ok(profiler_.end(), "end");
+    }
+  }
+
  private:
   friend const XNNOp* find_op(std::string_view target);
 
+#ifdef ET_EVENT_TRACER_ENABLED
+  // Reads XNNPACK's internal runtime, which the public API does not expose.
+  // xnn_get_runtime_profiling_info reports names and timings for opdata with a
+  // primary operator, in opdata order; this must apply the same filter.
+  Error describe_operators() {
+    std::vector<std::string> shapes;
+    for (size_t index = 0; index < runtime_->num_ops; ++index) {
+      const auto& op = runtime_->opdata[index];
+      if (op.operator_objects[0] != nullptr) {
+        shapes.push_back(
+            "{\"inputs\":" + value_shapes(op.inputs, op.num_inputs) +
+            ",\"outputs\":" + value_shapes(op.outputs, op.num_outputs) + "}");
+      }
+    }
+    return profiler_.set_operator_metadata(std::move(shapes));
+  }
+
+  std::string value_shapes(const uint32_t* ids, uint32_t count) const {
+    std::string text = "[";
+    for (uint32_t index = 0; index < count; ++index) {
+      text += index ? "," : "";
+      if (ids == nullptr || ids[index] == XNN_INVALID_VALUE_ID ||
+          ids[index] >= runtime_->num_values) {
+        text += "null";
+        continue;
+      }
+      const auto& shape = runtime_->values[ids[index]].shape;
+      text += "[";
+      for (size_t dim = 0; dim < shape.num_dims; ++dim) {
+        text += (dim ? "," : "") + std::to_string(shape.dim[dim]);
+      }
+      text += "]";
+    }
+    return text + "]";
+  }
+#endif
+
   std::vector<size_t> dimensions(ptn::ValueId id) const {
     const auto& sizes = context_.graph.value(id).tensor_meta().sizes;
     return {sizes.begin(), sizes.end()};
@@ -1122,6 +1207,9 @@ class XNNExecutable final : public Executable {
   bool bound_ = false;
   std::vector<Binding> bindings_;
   std::vector<xnn_external_value> external_;
+  XNNProfiler profiler_;
+  bool profiling_ = false;
+  bool tracing_ = false;
 };
 
 const XNNOp* find_op(std::string_view target) {