Add option to disable operator profiling

runtime/core/event_tracer.h

@@ -67,6 +67,18 @@ enum class EventTracerDebugLogLevel {
   kIntermediateOutputs,
 };
 
+/**
+ * Indicates the level of profiling that should be enabled. Profiling
+ * events will be logged in increasing order of verbosity as we go down the
+ * enum list. Thus it is important to keep the enum values in the right order.
+ */
+enum class EventTracerProfilingLevel {
+  /// No operator profiling.
+  kProfileMethodOnly,
+  /// All profiling events enabled.
+  kProfileAllEvents,
+};
+
 /**
  * This is the struct which should be returned when a profiling event is
  * started. This is used to uniquely identify that profiling event and will be
@@ -423,6 +435,21 @@ class EventTracer {
     return event_tracer_debug_level_;
   }
 
+  /**
+   * Set the level of event tracer profiling that is desired.
+   */
+  void set_event_tracer_profiling_level(
+      EventTracerProfilingLevel profiling_level) {
+    event_tracer_profiling_level_ = profiling_level;
+  }
+
+  /**
+   * Return the current level of event tracer profiling.
+   */
+  EventTracerProfilingLevel event_tracer_profiling_level() {
+    return event_tracer_profiling_level_;
+  }
+
   /**
    * Return the current status of intermediate outputs logging mode.
    */
@@ -458,6 +485,8 @@ class EventTracer {
   int bundled_input_index_ = kUnsetBundledInputIndex;
   EventTracerDebugLogLevel event_tracer_debug_level_ =
       EventTracerDebugLogLevel::kNoLogging;
+  EventTracerProfilingLevel event_tracer_profiling_level_ =
+      EventTracerProfilingLevel::kProfileAllEvents;
 };
 
 } // namespace runtime

runtime/core/event_tracer_hooks.h

@@ -33,14 +33,58 @@ namespace executorch {
 namespace runtime {
 namespace internal {
 
+/**
+ * This class enables scope based profiling where needed using RAII for
+ * operators only. If operator profiling is disabled then this class is a no-op.
+ */
+class EventTracerProfileOpScope final {
+ public:
+  EventTracerProfileOpScope(EventTracer* event_tracer, const char* name) {
+#ifdef ET_EVENT_TRACER_ENABLED
+    event_tracer_ = event_tracer;
+    if (event_tracer_ == nullptr) {
+      return;
+    }
+    if (event_tracer_->event_tracer_profiling_level() >
+        executorch::runtime::EventTracerProfilingLevel::kProfileMethodOnly) {
+      event_entry_ = event_tracer->start_profiling(name);
+    }
+#else //! ET_EVENT_TRACER_ENABLED
+    (void)event_tracer;
+    (void)name;
+#endif
+  }
+
+  ~EventTracerProfileOpScope() {
+#ifdef ET_EVENT_TRACER_ENABLED
+    if (event_tracer_ == nullptr) {
+      return;
+    }
+    if (event_tracer_->event_tracer_profiling_level() >
+        executorch::runtime::EventTracerProfilingLevel::kProfileMethodOnly) {
+      event_tracer_->end_profiling(event_entry_);
+    }
+#endif
+  }
+
+ private:
+#ifdef ET_EVENT_TRACER_ENABLED
+  EventTracer* event_tracer_;
+  EventTracerEntry event_entry_;
+#endif
+};
+
+using EventTracerProfileScope = EventTracerProfileOpScope;
+
 /**
  * This class enables scope based profiling where needed using RAII.
  * Profiling will be started when the object is created and will end
- * when the object goes out of scope.
+ * when the object goes out of scope. This is specifically intended to
+ * be used for profiling methods in the runtime.
  */
-class EventTracerProfileScope final {
+class EventTracerProfileMethodScope final {
  public:
-  EventTracerProfileScope(EventTracer* event_tracer, const char* name) {
+  EventTracerProfileMethodScope(EventTracer* event_tracer, const char* name) {
 #ifdef ET_EVENT_TRACER_ENABLED
     event_tracer_ = event_tracer;
     if (event_tracer_ == nullptr) {
@@ -53,7 +97,7 @@ class EventTracerProfileScope final {
 #endif
   }
 
-  ~EventTracerProfileScope() {
+  ~EventTracerProfileMethodScope() {
 #ifdef ET_EVENT_TRACER_ENABLED
     if (event_tracer_ == nullptr) {
       return;
@@ -111,6 +155,13 @@ class EventTracerProfileInstructionScope final {
 #endif
 };
 
+inline bool event_tracer_enabled() {
+#ifdef ET_EVENT_TRACER_ENABLED
+  return true;
+#else //! ET_EVENT_TRACER_ENABLED
+  return false;
+#endif
+}
 /**
  * Create a new event block with the specified name. Any events logged
  * after this will be associated with this new event block.
@@ -271,7 +322,10 @@ using ::executorch::runtime::internal::event_tracer_set_bundled_input_index;
 using ::executorch::runtime::internal::event_tracer_track_allocation;
 using ::executorch::runtime::internal::event_tracer_track_allocator;
 using ::executorch::runtime::internal::EventTracerProfileInstructionScope;
+using ::executorch::runtime::internal::EventTracerProfileMethodScope;
+using ::executorch::runtime::internal::EventTracerProfileOpScope;
 using ::executorch::runtime::internal::EventTracerProfileScope;
+
 } // namespace internal
 } // namespace executor
 } // namespace torch

runtime/core/test/event_tracer_test.cpp

@@ -44,14 +44,16 @@ class DummyEventTracer : public EventTracer {
       const char* name,
       ChainID chain_id = kUnsetChainId,
       DebugHandle debug_handle = kUnsetDebugHandle) override {
-    (void)name;
     (void)chain_id;
     (void)debug_handle;
+    ET_CHECK(strlen(name) + 1 < sizeof(event_name_));
+    memcpy(event_name_, name, strlen(name) + 1);
     return EventTracerEntry();
   }
 
   void end_profiling(EventTracerEntry prof_entry) override {
     (void)prof_entry;
+    memset(event_name_, 0, sizeof(event_name_));
     return;
   }
 
@@ -156,13 +158,18 @@ class DummyEventTracer : public EventTracer {
     return logged_evalue_type_;
   }
 
+  char* get_event_name() {
+    return event_name_;
+  }
+
   void reset_logged_value() {
     logged_evalue_ = EValue(false);
   }
 
  private:
   EValue logged_evalue_ = EValue(false);
   LoggedEValueType logged_evalue_type_;
+  char event_name_[1024];
 };
 
 /**
@@ -175,15 +182,15 @@ void RunSimpleTracerTest(EventTracer* event_tracer) {
   using executorch::runtime::internal::event_tracer_track_allocation;
   using executorch::runtime::internal::event_tracer_track_allocator;
   using executorch::runtime::internal::EventTracerProfileInstructionScope;
-  using executorch::runtime::internal::EventTracerProfileScope;
+  using executorch::runtime::internal::EventTracerProfileMethodScope;
 
   event_tracer_create_event_block(event_tracer, "ExampleEvent");
   event_tracer_create_event_block(event_tracer, "ExampleEvent");
   EventTracerEntry event_entry =
       event_tracer_begin_profiling_event(event_tracer, "ExampleEvent");
   event_tracer_end_profiling_event(event_tracer, event_entry);
   {
-    EventTracerProfileScope event_tracer_profile_scope(
+    EventTracerProfileMethodScope event_tracer_profile_scope(
         event_tracer, "ExampleScope");
   }
   {
@@ -282,3 +289,39 @@ TEST(TestEventTracer, SimpleEventTracerTestLogging) {
 
 // TODO(T163645377): Add more test coverage to log and verify events passed into
 // DummyTracer.
+TEST(TestEventTracer, EventTracerProfileOpControl) {
+  DummyEventTracer dummy;
+  // Op profiling is enabled by default. Test that it works.
+  {
+    {
+      executorch::runtime::internal::EventTracerProfileOpScope
+          event_tracer_op_scope(&dummy, "ExampleOpScope");
+      EXPECT_EQ(strcmp(dummy.get_event_name(), "ExampleOpScope"), 0);
+    }
+    EXPECT_EQ(strcmp(dummy.get_event_name(), ""), 0);
+
+    // Normal profiling should still work.
+    {
+      executorch::runtime::internal::EventTracerProfileMethodScope
+          event_tracer_profiler_scope(&dummy, "ExampleProfilerScope");
+      EXPECT_EQ(strcmp(dummy.get_event_name(), "ExampleProfilerScope"), 0);
+    }
+
+    dummy.set_event_tracer_profiling_level(
+        executorch::runtime::EventTracerProfilingLevel::kProfileMethodOnly);
+
+    // Op profiling should be disabled now.
+    {
+      executorch::runtime::internal::EventTracerProfileOpScope
+          event_tracer_op_scope(&dummy, "ExampleOpScope");
+      EXPECT_EQ(strcmp(dummy.get_event_name(), ""), 0);
+    }
+
+    // Normal profiling should still work.
+    {
+      executorch::runtime::internal::EventTracerProfileMethodScope
+          event_tracer_profiler_scope(&dummy, "1ExampleProfilerScope");
+      EXPECT_EQ(strcmp(dummy.get_event_name(), "1ExampleProfilerScope"), 0);
+    }
+  }
+}

runtime/executor/method.cpp

@@ -572,8 +572,8 @@ Result<Method> Method::load(
 
 Error Method::init(executorch_flatbuffer::ExecutionPlan* s_plan) {
   EXECUTORCH_SCOPE_PROF("Method::init");
-  internal::EventTracerProfileScope event_tracer_profile_scope =
-      internal::EventTracerProfileScope(event_tracer_, "Method::init");
+  internal::EventTracerProfileMethodScope event_tracer_profile_scope =
+      internal::EventTracerProfileMethodScope(event_tracer_, "Method::init");
   ET_CHECK_OR_RETURN_ERROR(
       // Don't use !initialized() here because we also want to fail on the
       // InitializationFailed state.
@@ -1022,8 +1022,8 @@ Error Method::execute_instruction() {
   switch (instruction->instr_args_type()) {
     case executorch_flatbuffer::InstructionArguments::KernelCall: {
       EXECUTORCH_SCOPE_PROF("OPERATOR_CALL");
-      internal::EventTracerProfileScope event_tracer_scope =
-          internal::EventTracerProfileScope(event_tracer_, "OPERATOR_CALL");
+      internal::EventTracerProfileOpScope event_tracer_op_scope =
+          internal::EventTracerProfileOpScope(event_tracer_, "OPERATOR_CALL");
       // TODO(T147221312): Also expose tensor resizer via the context.
       KernelRuntimeContext context(event_tracer_, temp_allocator_);
       auto args = chain.argument_lists_[step_state_.instr_idx];
@@ -1057,8 +1057,8 @@ Error Method::execute_instruction() {
     } break;
     case executorch_flatbuffer::InstructionArguments::DelegateCall: {
       EXECUTORCH_SCOPE_PROF("DELEGATE_CALL");
-      internal::EventTracerProfileScope event_tracer_profile_scope =
-          internal::EventTracerProfileScope(event_tracer_, "DELEGATE_CALL");
+      internal::EventTracerProfileOpScope event_tracer_op_scope =
+          internal::EventTracerProfileOpScope(event_tracer_, "DELEGATE_CALL");
       // We know that instr_args_as_DelegateCall is non-null because it was
       // checked at init time.
       auto delegate_idx =
@@ -1101,8 +1101,8 @@ Error Method::execute_instruction() {
     } break;
     case executorch_flatbuffer::InstructionArguments::JumpFalseCall: {
       EXECUTORCH_SCOPE_PROF("JF_CALL");
-      internal::EventTracerProfileScope event_tracer_profile_scope =
-          internal::EventTracerProfileScope(event_tracer_, "JF_CALL");
+      internal::EventTracerProfileOpScope event_tracer_op_scope =
+          internal::EventTracerProfileOpScope(event_tracer_, "JF_CALL");
       // We know that instr_args_as_JumpFalseCall is non-null because it was
       // checked at init time.
       auto jf_call = instruction->instr_args_as_JumpFalseCall();
@@ -1120,17 +1120,17 @@ Error Method::execute_instruction() {
     } break;
     case executorch_flatbuffer::InstructionArguments::MoveCall: {
       EXECUTORCH_SCOPE_PROF("MOVE_CALL");
-      internal::EventTracerProfileScope event_tracer_profile_scope =
-          internal::EventTracerProfileScope(event_tracer_, "MOVE_CALL");
+      internal::EventTracerProfileOpScope event_tracer_op_scope =
+          internal::EventTracerProfileOpScope(event_tracer_, "MOVE_CALL");
       // We know that instr_args_as_MoveCall is non-null because it was checked
       // at init time.
       auto move_call = instruction->instr_args_as_MoveCall();
       mutable_value(move_call->move_to()) = get_value(move_call->move_from());
     } break;
     case executorch_flatbuffer::InstructionArguments::FreeCall: {
       EXECUTORCH_SCOPE_PROF("FREE_CALL");
-      internal::EventTracerProfileScope event_tracer_profile_scope =
-          internal::EventTracerProfileScope(event_tracer_, "FREE_CALL");
+      internal::EventTracerProfileOpScope event_tracer_op_scope =
+          internal::EventTracerProfileOpScope(event_tracer_, "FREE_CALL");
       // We know that instr_args_as_FreeCall is non-null because it was checked
       // at init time.
       auto free_call = instruction->instr_args_as_FreeCall();
@@ -1191,8 +1191,8 @@ Error Method::step() {
           static_cast<int32_t>(step_state_.chain_idx),
           static_cast<uint32_t>(step_state_.instr_idx));
   EXECUTORCH_SCOPE_PROF("Method::step");
-  internal::EventTracerProfileScope event_tracer_profile_scope =
-      internal::EventTracerProfileScope(event_tracer_, "Method::step");
+  internal::EventTracerProfileMethodScope event_tracer_profile_scope =
+      internal::EventTracerProfileMethodScope(event_tracer_, "Method::step");
   ET_CHECK_OR_RETURN_ERROR(
       initialized(),
       InvalidState,
@@ -1233,8 +1233,8 @@ Error Method::experimental_step() {
 
 Error Method::execute() {
   internal::event_tracer_create_event_block(event_tracer_, "Execute");
-  internal::EventTracerProfileScope event_tracer_profile_scope =
-      internal::EventTracerProfileScope(event_tracer_, "Method::execute");
+  internal::EventTracerProfileMethodScope event_tracer_profile_scope =
+      internal::EventTracerProfileMethodScope(event_tracer_, "Method::execute");
   EXECUTORCH_SCOPE_PROF("Method::execute");
   ET_CHECK_OR_RETURN_ERROR(
       initialized(),

runtime/executor/program.cpp

@@ -241,8 +241,9 @@ Result<Method> Program::load_method(
     EventTracer* event_tracer) const {
   EXECUTORCH_SCOPE_PROF("Program::load_method");
   internal::event_tracer_create_event_block(event_tracer, "Default");
-  internal::EventTracerProfileScope event_tracer_scope =
-      internal::EventTracerProfileScope(event_tracer, "Program::load_method");
+  internal::EventTracerProfileMethodScope event_tracer_scope =
+      internal::EventTracerProfileMethodScope(
+          event_tracer, "Program::load_method");
   // If we can't create a MethodMeta for the Method, the Method is corrupt;
   // Method::method_meta() assumes success, so we must fail here.
   Result<MethodMeta> meta = method_meta(method_name);