Add ETDump tracing to CpuBackend (pytorch#23926)

Summary:

`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

.claude/faq.md

@@ -7,7 +7,7 @@ Error codes defined in `runtime/core/error.h`.
 |------|------|--------------|
 | 0x10 | InvalidArgument | Input shape mismatch - inputs don't match export shapes. Use dynamic shapes if needed. |
 | 0x14 | OperatorMissing | Selective build missing operator. Regenerate `et_operator_library` from current model. |
-| 0x20 | NotFound | Missing backend. Link with `--whole-archive`: `-Wl,--whole-archive libxnnpack_backend.a -Wl,--no-whole-archive` |
+| 0x20 | NotFound | Missing backend. Link with `--whole-archive`: `-Wl,--whole-archive libxnnpack_backend.a -Wl,--no-whole-archive libxnnpack_profiler.a` |
 
 ## Export Issues
 

.claude/skills/building/SKILL.md

@@ -202,7 +202,7 @@ Most commonly needed flags (full list: `CMakeLists.txt`):
 | Artifact | Location |
 |----------|----------|
 | Core runtime | `cmake-out/lib/libexecutorch.a` |
-| XNNPACK backend | `cmake-out/lib/libxnnpack_backend.a` |
+| XNNPACK backend | `cmake-out/lib/libxnnpack_backend.a` and `cmake-out/lib/libxnnpack_profiler.a` |
 | executor_runner | `cmake-out/executor_runner` (Ninja/Make) or `cmake-out/Release/executor_runner` (Xcode) |
 | Model runners | `cmake-out/examples/models/<model>/<runner>` |
 

backends/cpu/CMakeLists.txt

@@ -35,8 +35,15 @@ if(EXECUTORCH_BUILD_NATIVE_CPU)
   target_link_libraries(
     cpu_xnnpack
     PUBLIC cpu_runtime
-    PRIVATE extension_threadpool
+    PRIVATE extension_threadpool xnnpack_profiler
   )
+  if(EXECUTORCH_ENABLE_EVENT_TRACER)
+    # Traced builds include XNNPACK's internal runtime header from its source
+    # root.
+    target_include_directories(
+      cpu_xnnpack PRIVATE $<TARGET_PROPERTY:XNNPACK,SOURCE_DIR>
+    )
+  endif()
   if(EXECUTORCH_BUILD_SHARED)
     target_link_libraries(cpu_xnnpack PRIVATE xnnpack_shared)
   else()
@@ -106,8 +113,13 @@ add_library(
 )
 target_link_libraries(
   cpu_backend PRIVATE native_program extension_threadpool
-                      optimized_native_cpu_ops_lib
+                      optimized_native_cpu_ops_lib xnnpack_profiler
 )
+if(EXECUTORCH_ENABLE_EVENT_TRACER)
+  target_include_directories(
+    cpu_backend PRIVATE $<TARGET_PROPERTY:XNNPACK,SOURCE_DIR>
+  )
+endif()
 if(EXECUTORCH_BUILD_SHARED)
   set_target_properties(
     cpu_backend PROPERTIES OUTPUT_NAME executorch_backend_cpu

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,9 @@ struct PlanStep {
   KernelRegion region;
   std::unique_ptr<Executable> executable;
   StorageRequirements storage;
+  /// ETDump delegate event name: provider/implementation:first_node[+N].
+  /// Empty unless ET_EVENT_TRACER_ENABLED is defined.
+  std::string trace_name;
 };
 
 /// One static prepared plan. Graph, bindings and allocator outlive the plan.

backends/cpu/runtime/KernelProvider.h

@@ -65,6 +65,9 @@ runtime::Result<Buffer> allocate_buffer(
 struct ExecutionContext {
   size_t threads = 1;
   pthreadpool* threadpool = nullptr;
+  /// Providers enable internal profiling when set during preparation with a
+  /// profiling level above kProfileMethodOnly. The plan records one delegate
+  /// event per step at every level when set during execution.
   runtime::EventTracer* event_tracer = nullptr;
 };
 
@@ -122,6 +125,10 @@ class Executable {
   virtual runtime::Error reshape() = 0;
   virtual runtime::Error bind(const Buffer& scratch = {}) = 0;
   virtual runtime::Error run(const ExecutionContext& context) = 0;
+  /// Callers of run must call this afterwards, even when run fails. The plan
+  /// calls it after closing the step's trace event, so internal events are
+  /// logged without inflating it.
+  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,67 @@ class XNNExecutable final : public Executable {
     return Error::Ok;
   }
 
-  Error run(const ExecutionContext&) override {
+  Error run(const ExecutionContext& context) override {
+    // Closes a session left open by a caller that skipped submit_trace.
+    submit_trace();
     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[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 +1209,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) {