From 39fcadc8286cfb8b09704c5485fd105bc5c75034 Mon Sep 17 00:00:00 2001 From: Jake Stevens Date: Wed, 28 Oct 2026 10:36:10 -0700 Subject: [PATCH] Add ETDump tracing to `CpuBackend` (#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 `XNNPACK: #` events 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. Authored with Claude Code. Differential Revision: D125525223 --- backends/cpu/runtime/CPUBackend.cpp | 5 +- backends/cpu/runtime/CPUPlan.cpp | 17 ++- backends/cpu/runtime/CPUPlan.h | 2 + backends/cpu/runtime/KernelProvider.h | 5 + .../providers/xnnpack/XNNPACKProvider.cpp | 92 +++++++++++++- backends/cpu/runtime/test/CPUPlanTest.cpp | 116 ++++++++++++++++++ backends/cpu/targets.bzl | 40 ++++-- backends/cpu/test/runner.cpp | 32 ++++- .../xnnpack/runtime/profiling/XNNProfiler.cpp | 73 ++++++++--- .../xnnpack/runtime/profiling/XNNProfiler.h | 20 ++- backends/xnnpack/targets.bzl | 23 +++- backends/xnnpack/third-party/xnnpack.buck.bzl | 9 ++ .../xnnpack/third-party/third_party_libs.bzl | 10 +- .../executorch/build/build_variables.bzl | 5 +- 14 files changed, 412 insertions(+), 37 deletions(-) diff --git a/backends/cpu/runtime/CPUBackend.cpp b/backends/cpu/runtime/CPUBackend.cpp index ea753b4f78d..26cbdcd7627 100644 --- a/backends/cpu/runtime/CPUBackend.cpp +++ b/backends/cpu/runtime/CPUBackend.cpp @@ -95,7 +95,10 @@ class CPUExecution { return error; } plan_ = std::make_unique( - graph, buffers_, std::move(configuration), execution_context()); + graph, + buffers_, + std::move(configuration), + execution_context(context.event_tracer())); error = plan_->select(); if (error != Error::Ok) { return error; diff --git a/backends/cpu/runtime/CPUPlan.cpp b/backends/cpu/runtime/CPUPlan.cpp index 0588bea431d..c095a4f0827 100644 --- a/backends/cpu/runtime/CPUPlan.cpp +++ b/backends/cpu/runtime/CPUPlan.cpp @@ -5,6 +5,7 @@ // LICENSE file in the root directory of this source tree. #include +#include #include #include @@ -172,7 +173,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; } @@ -342,7 +349,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; @@ -380,6 +387,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) { diff --git a/backends/cpu/runtime/CPUPlan.h b/backends/cpu/runtime/CPUPlan.h index 76d4dbf86b3..37ee487095e 100644 --- a/backends/cpu/runtime/CPUPlan.h +++ b/backends/cpu/runtime/CPUPlan.h @@ -18,6 +18,8 @@ struct PlanStep { KernelRegion region; std::unique_ptr 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. diff --git a/backends/cpu/runtime/KernelProvider.h b/backends/cpu/runtime/KernelProvider.h index 670cd9ee693..f5957fae0db 100644 --- a/backends/cpu/runtime/KernelProvider.h +++ b/backends/cpu/runtime/KernelProvider.h @@ -66,6 +66,8 @@ struct ExecutionContext { size_t threads = 1; bool avx2_fma = false; 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; }; @@ -118,6 +120,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 { diff --git a/backends/cpu/runtime/providers/xnnpack/XNNPACKProvider.cpp b/backends/cpu/runtime/providers/xnnpack/XNNPACKProvider.cpp index 03f9d112725..94e8db551c8 100644 --- a/backends/cpu/runtime/providers/xnnpack/XNNPACKProvider.cpp +++ b/backends/cpu/runtime/providers/xnnpack/XNNPACKProvider.cpp @@ -6,7 +6,11 @@ #include #include +#include #include +#ifdef ET_EVENT_TRACER_ENABLED +#include "src/xnnpack/subgraph.h" // @manual +#endif #include #include @@ -14,12 +18,15 @@ #include #include #include +#include #include +#include #include 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) { @@ -39,6 +46,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(error)); + } + return error == Error::Ok; +} + bool constant(const ptn::Value& value) { return value.role == ptn::ValueRole::Parameter || value.role == ptn::ValueRole::ConstantTensor || @@ -101,6 +119,8 @@ class XNNState { return Error::Ok; } std::map, Buffer> converted_weights; + /// Numbers ETDump operator names uniquely across the provider's regions. + std::unordered_map operator_counts; xnn_workspace_t workspace = nullptr; xnn_weights_cache_t cache = nullptr; }; @@ -184,13 +204,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; } @@ -209,6 +243,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; } @@ -231,19 +270,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 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 dimensions(ptn::ValueId id) const { const auto& sizes = context_.graph.value(id).tensor_meta().sizes; return {sizes.begin(), sizes.end()}; @@ -849,6 +934,9 @@ class XNNExecutable final : public Executable { bool bound_ = false; std::vector bindings_; std::vector external_; + XNNProfiler profiler_; + bool profiling_ = false; + bool tracing_ = false; }; const XNNOp* find_op(std::string_view target) { diff --git a/backends/cpu/runtime/test/CPUPlanTest.cpp b/backends/cpu/runtime/test/CPUPlanTest.cpp index 700f2f7bb36..992f240ce10 100644 --- a/backends/cpu/runtime/test/CPUPlanTest.cpp +++ b/backends/cpu/runtime/test/CPUPlanTest.cpp @@ -7,6 +7,8 @@ #include #include #include +#include +#include #include @@ -15,11 +17,55 @@ #include #include #include +#include +#include namespace executorch::backends::cpu { namespace { using namespace executorch::runtime; +struct TraceRun { + std::vector delegates; + std::vector metadata; + std::vector kernels; +}; + +std::vector read_trace(etdump::ETDumpGen& tracer) { + const auto result = tracer.get_etdump_data(); + std::unique_ptr data(result.buf, &free); + std::vector runs; + if (!data) { + return runs; + } + size_t size = 0; + const auto run_data = + etdump_ETDump_run_data(etdump_ETDump_as_root_with_identifier( + flatbuffers_read_size_prefix(result.buf, &size), + etdump_ETDump_file_identifier)); + for (size_t run = 0; run < etdump_RunData_vec_len(run_data); ++run) { + auto& trace = runs.emplace_back(); + const auto events = + etdump_RunData_events(etdump_RunData_vec_at(run_data, run)); + for (size_t index = 0; index < etdump_Event_vec_len(events); ++index) { + const auto event = + etdump_Event_profile_event(etdump_Event_vec_at(events, index)); + EXPECT_LE( + etdump_ProfileEvent_start_time(event), + etdump_ProfileEvent_end_time(event)); + if (const auto name = etdump_ProfileEvent_delegate_debug_id_str(event)) { + trace.delegates.emplace_back(name); + const auto bytes = etdump_ProfileEvent_delegate_debug_metadata(event); + trace.metadata.emplace_back( + reinterpret_cast(bytes), + flatbuffers_uint8_vec_len(bytes)); + } else { + trace.kernels.emplace_back(etdump_ProfileEvent_name(event)); + } + } + } + return runs; +} + class CPUPlanTest : public ::testing::Test { protected: void value(const char* name, bool input = false) { @@ -51,6 +97,17 @@ class CPUPlanTest : public ::testing::Test { node.outputs = {{ptn::OutputValueKind::Tensor, out, {}}}; graph.nodes.push_back(std::move(node)); } + void sum_gelu_out() { + value("x", true); + value("y", true); + value("sum"); + value("gelu"); + value("out"); + add("sum", 0, 1, 2); + gelu("gelu", 2, 3); + add("out", 2, 3, 4); + finish({4}); + } void finish(std::vector outputs) { graph.output_ids = std::move(outputs); graph.initialize_schedule(); @@ -347,6 +404,65 @@ TEST_F(CPUPlanTest, RetainsConstantsWithRuntimeConsumersOrGraphOutputs) { } } +TEST_F(CPUPlanTest, TracesEveryStepAndXNNPACKOperatorOnEachExecution) { +#ifndef ET_EVENT_TRACER_ENABLED + GTEST_SKIP() << "Requires -c executorch.event_tracer_enabled=true"; +#endif + sum_gelu_out(); + etdump::ETDumpGen tracer; + execution.event_tracer = &tracer; + CPUPlan plan(graph, buffers, configuration, execution); + ASSERT_EQ(plan.select(), Error::Ok); + ASSERT_EQ(plan.prepare(allocator), Error::Ok); + for (int run = 0; run < 2; ++run) { + tracer.create_event_block("forward"); + ASSERT_EQ(plan.execute(execution), Error::Ok); + } + + const auto runs = read_trace(tracer); + ASSERT_EQ(runs.size(), 2); + const auto& names = runs[0].delegates; + EXPECT_EQ( + runs[0].kernels, (std::vector{"native_call_gelu.out"})); + ASSERT_EQ(names.size(), 5); + EXPECT_EQ(names[0], "XNNPACK/subgraph:sum"); + EXPECT_EQ(names[2], "Reference/registry:gelu"); + EXPECT_EQ(names[3], "XNNPACK/subgraph:out"); + const auto suffix = names[1].rfind(" #1"); + ASSERT_EQ(suffix, names[1].size() - 3) << names[1]; + EXPECT_EQ(names[4], names[1].substr(0, suffix) + " #2"); + const std::string add_shapes = R"({"inputs":[[11],[11]],"outputs":[[11]]})"; + EXPECT_EQ(runs[0].metadata[1], add_shapes); + EXPECT_EQ(runs[0].metadata[4], add_shapes); + EXPECT_EQ(runs[1].delegates, names); + EXPECT_EQ(runs[1].metadata, runs[0].metadata); +} + +TEST_F(CPUPlanTest, MethodOnlyProfilingTracesStepsWithoutXNNPACKOperators) { +#ifndef ET_EVENT_TRACER_ENABLED + GTEST_SKIP() << "Requires -c executorch.event_tracer_enabled=true"; +#endif + sum_gelu_out(); + etdump::ETDumpGen tracer; + tracer.set_event_tracer_profiling_level( + EventTracerProfilingLevel::kProfileMethodOnly); + execution.event_tracer = &tracer; + CPUPlan plan(graph, buffers, configuration, execution); + ASSERT_EQ(plan.select(), Error::Ok); + ASSERT_EQ(plan.prepare(allocator), Error::Ok); + tracer.create_event_block("forward"); + ASSERT_EQ(plan.execute(execution), Error::Ok); + + const auto runs = read_trace(tracer); + ASSERT_EQ(runs.size(), 1); + EXPECT_EQ( + runs[0].delegates, + (std::vector{ + "XNNPACK/subgraph:sum", + "Reference/registry:gelu", + "XNNPACK/subgraph:out"})); +} + TEST_F( CPUPlanTest, DisconnectedBranchesRemainSeparateAndRejectNonTopologicalSchedule) { diff --git a/backends/cpu/targets.bzl b/backends/cpu/targets.bzl index 04ef3cf5e20..ddc260126ac 100644 --- a/backends/cpu/targets.bzl +++ b/backends/cpu/targets.bzl @@ -1,7 +1,21 @@ load("@fbsource//xplat/executorch/backends/xnnpack/third-party:third_party_libs.bzl", "third_party_dep") load("@fbsource//xplat/executorch/build:runtime_wrapper.bzl", "runtime") +load("@fbsource//xplat/executorch/runtime/core:targets.bzl", "event_tracer_enabled") load(":cpu_backend.bzl", "cpu_backend", "cpu_provider") +# XNNPACK internal headers are only used for traced builds; mirrors +# get_event_tracer_flags so they are present exactly when ET_EVENT_TRACER_ENABLED is. +def _xnnpack_tracing_deps(): + headers = [third_party_dep("XNNPACK_internal_headers")] + if event_tracer_enabled(): + return headers + if runtime.is_oss: + return [] + return select({ + "DEFAULT": [], + "fbsource//xplat/executorch/tools/buck/constraints:event-tracer-enabled": headers, + }) + def define_common_targets(): runtime.cxx_library( name = "cpu_runtime", @@ -50,9 +64,10 @@ def define_common_targets(): exported_headers = ["runtime/providers/xnnpack/XNNPACKProvider.h"], exported_deps = [":cpu_runtime"], deps = [ + "//executorch/backends/xnnpack:xnnpack_profiler", "//executorch/extension/threadpool:threadpool", third_party_dep("XNNPACK"), - ], + ] + _xnnpack_tracing_deps(), visibility = ["PUBLIC"], ) @@ -79,6 +94,7 @@ def define_common_targets(): srcs = ["test/runner.cpp"], deps = [ ":cpu_backend", + "//executorch/devtools/etdump:etdump_flatcc", "//executorch/extension/module:module", "//executorch/extension/tensor:tensor", "//executorch/extension/threadpool:threadpool", @@ -92,17 +108,27 @@ def define_common_targets(): visibility = [":provider_test"], ) + plan_test_deps = [ + ":cpu_runtime", + ":cpu_reference", + ":cpu_xnnpack", + "//executorch/devtools/etdump:etdump_flatcc", + "//executorch/configurations:optimized_native_cpu_ops", + ] runtime.cxx_test( name = "plan_test", srcs = ["runtime/test/CPUPlanTest.cpp"], - deps = [ - ":cpu_runtime", - ":cpu_reference", - ":cpu_xnnpack", - "//executorch/configurations:optimized_native_cpu_ops", - ], + deps = plan_test_deps, ) + if not runtime.is_oss: + runtime.cxx_test( + name = "plan_test_event_tracer", + srcs = ["runtime/test/CPUPlanTest.cpp"], + deps = plan_test_deps, + modifiers = ["fbsource//xplat/executorch/tools/buck/constraints:event-tracer-enabled"], + ) + runtime.cxx_test( name = "provider_test", srcs = ["runtime/test/ProviderTest.cpp"], diff --git a/backends/cpu/test/runner.cpp b/backends/cpu/test/runner.cpp index 41f1e8aca74..150c1c00e61 100644 --- a/backends/cpu/test/runner.cpp +++ b/backends/cpu/test/runner.cpp @@ -5,6 +5,7 @@ // LICENSE file in the root directory of this source tree. #include +#include #include #include #include @@ -12,7 +13,9 @@ #include #include #include +#include #include +#include #include #include @@ -28,7 +31,23 @@ int main(int argc, char** argv) { executorch::extension::threadpool::NoThreadPoolGuard threadpool_guard; executorch::runtime::BackendOptions<1 + 2 * max_preferences> options; executorch::runtime::LoadBackendOptionsMap backends; - executorch::extension::Module module(argv[1]); + const char* etdump_path = std::getenv("ET_CPU_ETDUMP"); + std::unique_ptr tracer; + if (etdump_path) { +#ifdef ET_EVENT_TRACER_ENABLED + tracer = std::make_unique(); +#else + fprintf( + stderr, + "ET_CPU_ETDUMP requires -c executorch.event_tracer_enabled=true\n"); + return 1; +#endif + } + auto* etdump = tracer.get(); + executorch::extension::Module module( + argv[1], + executorch::extension::Module::LoadMode::File, + std::move(tracer)); if (argc > 3) { using executorch::runtime::Error; if (options.set_option("preference_count", argc - 3) != Error::Ok) { @@ -120,5 +139,16 @@ int main(int argc, char** argv) { golden.size(), max_error); } + if (etdump) { + const auto result = etdump->get_etdump_data(); + std::unique_ptr dump_data(result.buf, &free); + std::ofstream file(etdump_path, std::ios::binary); + if (!dump_data || + !file.write(static_cast(result.buf), result.size)) { + fprintf(stderr, "Failed to write ETDump to %s\n", etdump_path); + return 1; + } + printf("ETDump: path=%s bytes=%zu\n", etdump_path, result.size); + } return 0; } diff --git a/backends/xnnpack/runtime/profiling/XNNProfiler.cpp b/backends/xnnpack/runtime/profiling/XNNProfiler.cpp index 4d928b18a93..7835a369651 100644 --- a/backends/xnnpack/runtime/profiling/XNNProfiler.cpp +++ b/backends/xnnpack/runtime/profiling/XNNProfiler.cpp @@ -20,6 +20,7 @@ #include #include #include +#include // NOLINTEND namespace executorch::backends::xnnpack::delegate::profiling { @@ -32,18 +33,38 @@ using executorch::runtime::EventTracer; XNNProfiler::XNNProfiler() : state_(XNNProfilerState::Uninitialized), run_count_(0) {} -Error XNNProfiler::initialize(xnn_runtime_t runtime) { +Error XNNProfiler::initialize( + xnn_runtime_t runtime, + std::unordered_map* op_counts) { runtime_ = runtime; // Fetch the runtime operator information from XNNPACK. ET_CHECK_OK_OR_RETURN_ERROR(get_runtime_num_operators()); ET_CHECK_OK_OR_RETURN_ERROR(get_runtime_operator_names()); + std::unordered_map local_op_counts; + ET_CHECK_OK_OR_RETURN_ERROR( + format_operator_event_names(op_counts ? *op_counts : local_op_counts)); state_ = XNNProfilerState::Ready; return Error::Ok; } +Error XNNProfiler::set_operator_metadata(std::vector&& metadata) { + ET_CHECK_OR_RETURN_ERROR( + state_ != XNNProfilerState::Uninitialized, + InvalidState, + "XNNProfiler must be initialized prior to setting operator metadata."); + ET_CHECK_OR_RETURN_ERROR( + metadata.size() == op_count_, + Internal, + "XNNPACK described %zu operators but profiles %zu", + metadata.size(), + op_count_); + op_metadata_ = std::move(metadata); + return Error::Ok; +} + Error XNNProfiler::start(EventTracer* event_tracer) { // Validate profiler state. if (state_ == XNNProfilerState::Uninitialized) { @@ -168,6 +189,28 @@ Error XNNProfiler::get_runtime_operator_timings() { return Error::Ok; } +Error XNNProfiler::format_operator_event_names( + std::unordered_map& op_counts) { + op_event_names_.clear(); + op_event_names_.reserve(op_count_); + size_t name_len = 0; + for (size_t i = 0; i < op_count_; i++) { + ET_CHECK_OR_RETURN_ERROR( + name_len < op_names_.size(), + Internal, + "XNNPACK reported %zu operators but %zu names", + op_count_, + i); + auto op_name = std::string(&op_names_[name_len]); + name_len += op_name.size() + 1; + + // Format the op name as {name} #{count}. + const auto count = ++op_counts[op_name]; + op_event_names_.push_back(op_name + " #" + std::to_string(count)); + } + return Error::Ok; +} + void XNNProfiler::log_operator_timings() { #ifdef ENABLE_XNNPACK_PROFILING // Update running average state and log average timing for each op. @@ -202,20 +245,9 @@ void XNNProfiler::submit_trace() { auto tick_ns_conv_multiplier = runtime::pal_ticks_to_ns_multiplier(); ET_CHECK(op_timings_.size() == op_count_); - size_t name_len = 0; et_timestamp_t time = start_time_; - std::unordered_map op_counts; for (auto i = 0u; i < op_count_; i++) { - auto op_name = &op_names_[name_len]; - name_len += strlen(op_name) + 1; - - // Format the op name as {name} #{count}. - auto op_name_str = std::string(op_name); - op_counts[op_name_str]++; - auto name_formatted = - op_name_str + " #" + std::to_string(op_counts[op_name_str]); - // Convert from microseconds (XNNPACK) to PAL ticks (ET). // The tick_ns_conv_ratio is ns / tick. We want ticks: // ticks = us * (ns / us) / conv_ratio @@ -226,12 +258,15 @@ void XNNProfiler::submit_trace() { auto end_time = time + interval_ticks; + const auto* metadata = op_metadata_.empty() ? nullptr : &op_metadata_[i]; executorch::runtime::event_tracer_log_profiling_delegate( event_tracer_, - name_formatted.c_str(), + op_event_names_[i].c_str(), /*delegate_debug_id=*/static_cast(-1), time, - end_time); + end_time, + metadata ? metadata->data() : nullptr, + metadata ? metadata->size() : 0); // Assume that the next op starts immediately after the previous op. // This may not be strictly true, but it should be close enough. @@ -246,8 +281,16 @@ void XNNProfiler::submit_trace() { // Stub implementation for when profiling is disabled. XNNProfiler::XNNProfiler() {} -Error XNNProfiler::initialize(xnn_runtime_t runtime) { +Error XNNProfiler::initialize( + xnn_runtime_t runtime, + std::unordered_map* op_counts) { (void)runtime; + (void)op_counts; + return Error::Ok; +} + +Error XNNProfiler::set_operator_metadata(std::vector&& metadata) { + (void)metadata; return Error::Ok; } diff --git a/backends/xnnpack/runtime/profiling/XNNProfiler.h b/backends/xnnpack/runtime/profiling/XNNProfiler.h index 2eaec0ad115..c634f5903af 100644 --- a/backends/xnnpack/runtime/profiling/XNNProfiler.h +++ b/backends/xnnpack/runtime/profiling/XNNProfiler.h @@ -12,6 +12,8 @@ #include #include +#include +#include #include namespace executorch { @@ -28,9 +30,19 @@ class XNNProfiler { /** * Initialize the profiler. This must be called after model is - * compiled and before calling begin_execution. + * compiled and before calling begin_execution. Trace events are named + * {name} #{count}; runtimes sharing op_counts continue one numbering. */ - executorch::runtime::Error initialize(xnn_runtime_t runtime); + executorch::runtime::Error initialize( + xnn_runtime_t runtime, + std::unordered_map* op_counts = nullptr); + + /** + * Attach metadata to each operator's trace event, in operator order. Fails + * if the count differs from the runtime's operator count. + */ + executorch::runtime::Error set_operator_metadata( + std::vector&& metadata); /** * Start a new profiling session. This is typically invoked @@ -54,6 +66,8 @@ class XNNProfiler { size_t op_count_; std::vector op_names_; + std::vector op_event_names_; + std::vector op_metadata_; std::vector op_timings_; uint64_t run_count_; et_timestamp_t start_time_; @@ -68,6 +82,8 @@ class XNNProfiler { executorch::runtime::Error get_runtime_operator_names(); executorch::runtime::Error get_runtime_num_operators(); executorch::runtime::Error get_runtime_operator_timings(); + executorch::runtime::Error format_operator_event_names( + std::unordered_map& op_counts); void log_operator_timings(); diff --git a/backends/xnnpack/targets.bzl b/backends/xnnpack/targets.bzl index b3af589df10..7ab6d1c8ac6 100644 --- a/backends/xnnpack/targets.bzl +++ b/backends/xnnpack/targets.bzl @@ -1,5 +1,5 @@ load("@fbsource//xplat/executorch/backends/xnnpack/third-party:third_party_libs.bzl", "third_party_dep") -load("@fbsource//xplat/executorch/build:build_variables.bzl", "XNNPACK_BACKEND_BUCK_SRCS") +load("@fbsource//xplat/executorch/build:build_variables.bzl", "XNNPACK_BACKEND_BUCK_SRCS", "XNNPACK_PROFILER_BUCK_SRCS") load("@fbsource//xplat/executorch/build:runtime_wrapper.bzl", "get_aten_mode_options", "runtime") def _get_preprocessor_flags(): @@ -35,21 +35,36 @@ def define_common_targets(): for aten_mode in get_aten_mode_options(): aten_suffix = "_aten" if aten_mode else "" + runtime.cxx_library( + name = "xnnpack_profiler" + aten_suffix, + srcs = XNNPACK_PROFILER_BUCK_SRCS, + exported_headers = ["runtime/profiling/XNNProfiler.h"], + visibility = ["PUBLIC"], + # Exported because XNNProfiler's layout depends on it. + exported_preprocessor_flags = [ + # Uncomment to enable per operator timings + # "-DENABLE_XNNPACK_PROFILING", + ], + exported_deps = [ + third_party_dep("XNNPACK"), + "//executorch/runtime/core:core", + "//executorch/runtime/core:event_tracer" + aten_suffix, + ], + ) + runtime.cxx_library( name = "xnnpack_backend" + aten_suffix, srcs = XNNPACK_BACKEND_BUCK_SRCS, headers = native.glob([ "runtime/*.h", - "runtime/profiling/*.h", ]), visibility = ["PUBLIC"], preprocessor_flags = [ - # Uncomment to enable per operator timings - # "-DENABLE_XNNPACK_PROFILING", # Uncomment to enable using KleidiAI Kernels # "-DENABLE_XNNPACK_KLEIDI" ] + _get_preprocessor_flags(), exported_deps = [ + ":xnnpack_profiler" + aten_suffix, "//executorch/runtime/backend:interface" + aten_suffix, ], exported_headers = [ diff --git a/backends/xnnpack/third-party/xnnpack.buck.bzl b/backends/xnnpack/third-party/xnnpack.buck.bzl index 3aa82f89cd4..d4b2a582635 100644 --- a/backends/xnnpack/third-party/xnnpack.buck.bzl +++ b/backends/xnnpack/third-party/xnnpack.buck.bzl @@ -1214,3 +1214,12 @@ def define_xnnpack(): "ovr_config//cpu:arm64": ARM_XNNPACK_DEPS, }), ) + + # @lint-ignore BUCKLINT: native and fb_native are explicitly forbidden in fbcode. + native.cxx_library( + name = "XNNPACK_internal_headers", + exported_headers = get_xnnpack_headers(), + header_namespace = "", + visibility = ["PUBLIC"], + exported_deps = [":pthreadpool"], + ) diff --git a/shim_et/xplat/executorch/backends/xnnpack/third-party/third_party_libs.bzl b/shim_et/xplat/executorch/backends/xnnpack/third-party/third_party_libs.bzl index 594107325be..b52df59c7c8 100644 --- a/shim_et/xplat/executorch/backends/xnnpack/third-party/third_party_libs.bzl +++ b/shim_et/xplat/executorch/backends/xnnpack/third-party/third_party_libs.bzl @@ -1,6 +1,9 @@ load("@fbsource//xplat/executorch/build:runtime_wrapper.bzl", "runtime") -_XNNPACK_LATEST = "fbsource//third-party/XNNPACK:XNNPACK" +_XNNPACK_LATEST = { + "XNNPACK": "fbsource//third-party/XNNPACK:XNNPACK", + "XNNPACK_internal_headers": "fbsource//third-party/XNNPACK:public-headers", +} # Dictionary mappping third-party library name to the correct OSS/Internal target dependencies. # the values of the dictionary are lists where the first element is the internal dep and the @@ -9,6 +12,7 @@ _THIRD_PARTY_LIBS = { "FP16": ["fbsource//xplat/third-party/FP16:FP16Fbcode", "//backends/xnnpack/third-party:FP16"], "FXdiv": ["fbsource//xplat/third-party/FXdiv:FXdiv", "//backends/xnnpack/third-party:FXdiv"], "XNNPACK": ["fbsource//xplat/third-party/XNNPACK:XNNPACK", "//backends/xnnpack/third-party:XNNPACK"], + "XNNPACK_internal_headers": ["fbsource//xplat/third-party/XNNPACK:public-headers", "//backends/xnnpack/third-party:XNNPACK_internal_headers"], "clog": ["fbsource//xplat/third-party/clog:clog", "//backends/xnnpack/third-party:clog"], "cpuinfo": ["fbsource//third-party/cpuinfo:cpuinfo", "//backends/xnnpack/third-party:cpuinfo"], "pthreadpool": ["fbsource//xplat/third-party/pthreadpool:pthreadpool", "//backends/xnnpack/third-party:pthreadpool"], @@ -21,6 +25,6 @@ def third_party_dep(name): if runtime.is_oss: return _THIRD_PARTY_LIBS[name][1] - if name == "XNNPACK" and native.read_config("executorch", "use_latest_xnnpack", "false") == "true": - return _XNNPACK_LATEST + if name in _XNNPACK_LATEST and native.read_config("executorch", "use_latest_xnnpack", "false") == "true": + return _XNNPACK_LATEST[name] return _THIRD_PARTY_LIBS[name][0] diff --git a/shim_et/xplat/executorch/build/build_variables.bzl b/shim_et/xplat/executorch/build/build_variables.bzl index 82d0c40064e..9c631c9f0d9 100644 --- a/shim_et/xplat/executorch/build/build_variables.bzl +++ b/shim_et/xplat/executorch/build/build_variables.bzl @@ -422,10 +422,13 @@ XNNPACK_BACKEND_BUCK_SRCS = [ "runtime/XNNWeightsCacheManager.cpp", "runtime/XNNWorkspaceManager.cpp", "runtime/XnnpackBackendOptions.cpp", +] + +XNNPACK_PROFILER_BUCK_SRCS = [ "runtime/profiling/XNNProfiler.cpp", ] -XNNPACK_BACKEND_SRCS = ["backends/xnnpack/" + x for x in XNNPACK_BACKEND_BUCK_SRCS] +XNNPACK_BACKEND_SRCS = ["backends/xnnpack/" + x for x in XNNPACK_BACKEND_BUCK_SRCS + XNNPACK_PROFILER_BUCK_SRCS] XNNPACK_SCHEMA_SRCS = [ "backends/xnnpack/serialization/runtime_schema.fbs",