Add support for delegate profiling in event_tracer (#408)

tarun292 · facebook-github-bot · commit 7a1b7f4a00b0 · 2023-09-23T18:00:01.000-07:00
Summary: Pull Request resolved: #408 This diff should most probably be the final event_tracer diff that adds the user-facing API's for delegate profiling. `event_tracer_hooks_delegate.h` can be included by delegate authors in their backend runtime code to get access to these interfaces that will enable them to do profiling logging currently and debugging logging in the future. - Made changes to `event_tracer.h` to add the hooks to the `EventTracer` class. - Added `event_tracer_hooks_delegate.h` that contains the public interfaces that delegate authors can call into. Reviewed By: dbort Differential Revision: D49360145 fbshipit-source-id: fef2800b2129d93098b8d3868da9007cbc100f4f
diff --git a/runtime/core/event_tracer.h b/runtime/core/event_tracer.h
@@ -28,6 +28,19 @@ typedef uint32_t DebugHandle;
 constexpr ChainID kUnsetChainId = -1;
 constexpr DebugHandle kUnsetDebugHandle = 0;
 
+/// Different types of delegate debug identifiers that are supported currently.
+enum class DelegateDebugIdType {
+  /// Default value, indicates that it's not a delegate event.
+  kNone,
+  /// Indicates a delegate event logged using an integer delegate debug
+  /// identifier.
+  kInt,
+  /// Indicates a delegate event logged using a string delegate debug
+  /// identifier i.e. the delegate debug id is a pointer to a string table
+  /// managed by the class implementing EventTracer functionality.
+  kStr
+};
+
 /**
  * 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
@@ -44,8 +57,16 @@ struct EventTracerEntry {
   DebugHandle debug_handle;
   /// The time at which this event was started to be tracked.
   et_timestamp_t start_time;
+  /// When delegate_event_id_type != DelegateDebugIdType::kNone it indicates
+  /// that event_id represents a delegate event. If delegate_event_id_type is:
+  /// 1) kInt then event_id contains an integer delegate debug id.
+  /// 2) kStr then event_id contains a string table index into a string table
+  /// maintained by the class implementing EventTracer functionality that will
+  /// give us the string identifier of this delegate event. For more details
+  /// refer to the DelegateMappingBuilder library present in
+  /// executorch/exir/backend/utils.py.
+  DelegateDebugIdType delegate_event_id_type;
 };
-
 /**
  * EventTracer is a class that users can inherit and implement to
  * log/serialize/stream etc. the profiling and debugging events that are
@@ -79,8 +100,9 @@ class EventTracer {
    * around. The string must be copied over into internal memory during this
    * call.
    * @param[in] chain_id The id of the chain to which this event belongs to. If
-   * -1 is passed in the chain_id and debug_handle stored in the class
-   * internally will be used.
+   * kUnsetChainId is passed in the chain_id and kUnsetDebugHandle for
+   * debug_handle then the values stored in the class internally for these
+   * properties will be used.
    * @param[in] debug_handle Debug handle generated ahead-of-time during model
    * compilation.
    *
@@ -92,6 +114,73 @@ class EventTracer {
       ChainID chain_id = kUnsetChainId,
       DebugHandle debug_handle = kUnsetDebugHandle) = 0;
 
+  /**
+   * Start the profiling of a delegate event. Similar to start_profiling it will
+   * return an instance of EventTracerEntry that contains the details of this
+   * event.
+   *
+   * @param[in] name Human readable name for the delegate event. This name has
+   * to be the same name that was passed in during the Debug delegate mapping
+   * generation in the export/ahead-of-time process. If indices and not names
+   * are used by this delegate to identify ops executed in the backend then
+   * nullptr can be passed in. Users calling this interface do not need to keep
+   * the memory pointed to by this pointer around. The string must be copied
+   * over into internal memory during this call.
+   * @param[in] delegate_debug_index The id of the delegate event. If string
+   * based names are used by this delegate to identify ops executed in the
+   * backend then kUnsetDebugHandle should be passed in here.
+   */
+  virtual EventTracerEntry start_profiling_delegate(
+      const char* name,
+      DebugHandle delegate_debug_index) = 0;
+
+  /**
+   * Signal the end of the delegate profiling event contained in
+   * event_tracer_entry. Users also have the option to log some some free-from
+   * string based metadata along with this.
+   *
+   * @param[in] event_tracer_entry The EventTracerEntry returned by a call to
+   * start_profiling_delegate().
+   * @param[in] metadata Optional free-form metadata associated with the
+   * delegate event. This should be a null terminated ASCII string. Users
+   * calling this interface do not need to keep the memory pointed to by this
+   * pointer around. The string must be copied over into internal memory during
+   * this call.
+   */
+  virtual void end_profiling_delegate(
+      EventTracerEntry event_tracer_entry,
+      const char* metadata = nullptr) = 0;
+
+  /**
+   * Some delegates get access to the profiling details only after the complete
+   * graph has been executed. This interface is to support such use cases. It
+   * can be called in a loop etc. to log any number of profiling events that are
+   * part of this delegate.
+   *
+   * @param[in] name Human readable name for the delegate event. This name has
+   * to be the same name that was passed in during the Debug delegate mapping
+   * generation in the export/ahead-of-time process. If indices and not names
+   * are used by this delegate to identify ops executed in the backend then
+   * nullptr can be passed in. Users calling this interface do not need to keep
+   * the memory pointed to by this pointer around. The string must be copied
+   * over into internal memory during this call.
+   * @param[in] delegate_debug_index The id of the delegate event. If string
+   * based names are used by this delegate to identify ops executed in the
+   * backend then kUnsetDebugHandle should be passed in here.
+   * @param[in] start_time The timestamp when the delegate event started.
+   * @param[in] end_time The timestamp when the delegate event finished.
+   * @param[in] metadata Optional data relevant to the execution that the user
+   * wants to log along with this event. Pointer to metadata doesn't need to be
+   * valid after the call to this function. This should be a null terminated
+   * ASCII string.
+   */
+  virtual void log_profiling_delegate(
+      const char* name,
+      DebugHandle delegate_debug_index,
+      et_timestamp_t start_time,
+      et_timestamp_t end_time,
+      const char* metadata = nullptr) = 0;
+
   /**
    * End the profiling of the event identified by prof_entry
    *
diff --git a/runtime/core/event_tracer_hooks_delegate.h b/runtime/core/event_tracer_hooks_delegate.h
@@ -0,0 +1,142 @@
+/*
+ * Copyright (c) Meta Platforms, Inc. and affiliates.
+ * All rights reserved.
+ *
+ * This source code is licensed under the BSD-style license found in the
+ * LICENSE file in the root directory of this source tree.
+ */
+
+#pragma once
+
+#include <executorch/runtime/core/event_tracer.h>
+
+/**
+ * @file
+ *
+ * This file contains the hooks that can be used by runtime delegate backend
+ * authors to log profiling and debugging events from backend code. In order to
+ * use these hooks delegate authors would have needed to generate a delegate
+ * debug identifier mapping using the DelegateMappingBuilder library present in
+ * executorch/exir/backend/utils.py. The delegate debug identifiers generated by
+ * that library are the ones that need to be passed to these hooks to log
+ * events. Using any other identifiers will cause post-processing of the events
+ * data to not properly link back to the nodes in the original lowered graph.
+ *
+ * The benefit of defining these hooks is that we can easily control whether or
+ * not we want to compile in the EventTracer code based on the status of the
+ * ET_EVENT_TRACER_ENABLED flag.
+ */
+
+namespace torch {
+namespace executor {
+
+/**
+ * Start the profiling of a delegate event. Similar to start_profiling it will
+ * return an instance of EventTracerEntry that contains the details of this
+ * event. Can be left in production code as these hooks compile conditionally.
+ *
+ * @param[in] event_tracer The event tracer instance that is doing the logging.
+ * @param[in] name Human readable name for the delegate event. This name has
+ * to be the same name that was passed in during the Debug delegate mapping
+ * generation in the export/ahead-of-time process. If indices and not names
+ * are used by this delegate to identify ops executed in the backend then
+ * nullptr can be passed in. Users calling this interface do not need to keep
+ * the memory pointed to by this pointer around. The string must be copied over
+ * into internal memory during this call.
+ * @param[in] delegate_debug_id The id of the delegate event. If string
+ * based names are used by this delegate to identify ops executed in the
+ * backend then kUnsetDebugHandle should be passed in here.
+ */
+inline EventTracerEntry event_tracer_start_profiling_delegate(
+    EventTracer* event_tracer,
+    const char* name,
+    DebugHandle delegate_debug_id) {
+#ifdef ET_EVENT_TRACER_ENABLED
+  if (event_tracer) {
+    return event_tracer->start_profiling_delegate(name, delegate_debug_id);
+  }
+#else //! ET_EVENT_TRACER_ENABLED
+  (void)name;
+  (void)delegate_debug_id;
+#endif
+  // There is no active tracer; this value will be ignored.
+  return EventTracerEntry();
+}
+/**
+ * Signal the end of the delegate profiling event contained in
+ * event_tracer_entry. Users also have the option to log some some free-from
+ * string based metadata along with this. Can be left in production code as
+ * these hooks compile conditionally.
+ *
+ * @param[in] event_tracer The event tracer instance that is doing the logging.
+ * @param[in] event_tracer_entry The EventTracerEntry returned by a call to
+ * start_profiling_delegate().
+ * @param[in] metadata Free-form metadata associated with the delegate event.
+ * Users calling this interface do not need to keep the memory pointed to by
+ * this pointer around. The string must be copied over into internal memory
+ * during this call. The input string must also be null terminated.
+ */
+inline void event_tracer_end_profiling_delegate(
+    EventTracer* event_tracer,
+    EventTracerEntry event_tracer_entry,
+    const char* metadata = nullptr) {
+#ifdef ET_EVENT_TRACER_ENABLED
+  if (event_tracer) {
+    event_tracer->end_profiling_delegate(event_tracer_entry, metadata);
+  }
+#else //! ET_EVENT_TRACER_ENABLED
+  (void)event_tracer_entry;
+  (void)metadata;
+#endif
+}
+
+/**
+ * Some delegates get access to the profiling details only after the complete
+ * graph has been executed. This interface is to support such use cases. It
+ * can be called in a loop etc. to log any number of profiling events that are
+ * part of this delegate. Can be left in production code as these hooks
+ * compile conditionally.
+ *
+ * @param[in] event_tracer The event tracer instance that is doing the logging.
+ * @param[in] name Human readable name for the delegate event. This name has
+ * to be the same name that was passed in during the Debug delegate mapping
+ * generation in the export/ahead-of-time process. If indices and not names
+ * are used by this delegate to identify ops executed in the backend then
+ * nullptr can be passed in. Users calling this interface do not need to keep
+ * the memory pointed to by this pointer around. The string must
+ * be copied over into internal memory during this call.
+ * @param[in] delegate_debug_id The id of the delegate event. If string
+ * based names are used by this delegate to identify ops executed in the
+ * backend then -1 should be passed in here.
+ * @param[in] start_time The timestamp when the delegate event started.
+ * @param[in] end_time The timestamp when the delegate event finished.
+ * @param[in] metadata Any extra data relevant to the execution that the user
+ * wants to log along with this event. Pointer to metadata doesn't need to be
+ * valid after the call to this function. Users calling this interface do not
+ * need to keep the memory pointed to by this pointer around. The string must
+ * be copied over into internal memory during this call. The input string must
+ * also be a null terminated.
+ */
+inline void event_tracer_log_profiling_delegate(
+    EventTracer* event_tracer,
+    const char* name,
+    DebugHandle delegate_debug_id,
+    et_timestamp_t start_time,
+    et_timestamp_t end_time,
+    const char* metadata = nullptr) {
+#ifdef ET_EVENT_TRACER_ENABLED
+  if (event_tracer) {
+    event_tracer->log_profiling_delegate(
+        name, delegate_debug_id, start_time, end_time, metadata);
+  }
+#else //! ET_EVENT_TRACER_ENABLED
+  (void)name;
+  (void)delegate_debug_id;
+  (void)start_time;
+  (void)end_time;
+  (void)metadata;
+#endif
+}
+
+} // namespace executor
+} // namespace torch
diff --git a/runtime/core/targets.bzl b/runtime/core/targets.bzl
@@ -24,6 +24,7 @@ def define_common_targets():
             "error.h",
             "event_tracer.h",
             "event_tracer_hooks.h",
+            "event_tracer_hooks_delegate.h",
             "freeable_buffer.h",
             "function_ref.h",
             "result.h",
diff --git a/runtime/core/test/event_tracer_test.cpp b/runtime/core/test/event_tracer_test.cpp
@@ -12,6 +12,7 @@
 // Enable flag for test
 #define ET_EVENT_TRACER_ENABLED
 #include <executorch/runtime/core/event_tracer_hooks.h>
+#include <executorch/runtime/core/event_tracer_hooks_delegate.h>
 
 namespace torch {
 namespace executor {
@@ -54,8 +55,39 @@ class DummyEventTracer : public EventTracer {
     (void)name;
     return 0;
   }
+
+  EventTracerEntry start_profiling_delegate(
+      const char* name,
+      DebugHandle delegate_debug_id) override {
+    (void)name;
+    (void)delegate_debug_id;
+    return EventTracerEntry();
+  }
+
+  void end_profiling_delegate(
+      EventTracerEntry event_tracer_entry,
+      const char* metadata) override {
+    (void)event_tracer_entry;
+    (void)metadata;
+  }
+
+  void log_profiling_delegate(
+      const char* name,
+      DebugHandle delegate_debug_id,
+      et_timestamp_t start_time,
+      et_timestamp_t end_time,
+      const char* metadata = nullptr) override {
+    (void)name;
+    (void)delegate_debug_id;
+    (void)start_time;
+    (void)end_time;
+    (void)metadata;
+  }
 };
 
+/**
+ * Exercise all the event_tracer API's for a basic sanity check.
+ */
 void RunSimpleTracerTest(EventTracer* event_tracer) {
   event_tracer_create_event_block(event_tracer, "ExampleEvent");
   event_tracer_create_event_block(event_tracer, "ExampleEvent");
@@ -86,6 +118,33 @@ TEST(TestEventTracer, SimpleEventTracerTest) {
   }
 }
 
+/**
+ * Exercise all the event_tracer API's for delegates as a basic sanity check.
+ */
+void RunSimpleTracerTestDelegate(EventTracer* event_tracer) {
+  EventTracerEntry event_tracer_entry = event_tracer_start_profiling_delegate(
+      event_tracer, "test_event", kUnsetDebugHandle);
+  event_tracer_end_profiling_delegate(
+      event_tracer, event_tracer_entry, nullptr);
+  event_tracer_start_profiling_delegate(event_tracer, nullptr, 1);
+  event_tracer_end_profiling_delegate(
+      event_tracer, event_tracer_entry, "test_metadata");
+  event_tracer_log_profiling_delegate(
+      event_tracer, "test_event", kUnsetDebugHandle, 0, 1, nullptr);
+  event_tracer_log_profiling_delegate(event_tracer, nullptr, 1, 0, 1, nullptr);
+}
+
+TEST(TestEventTracer, SimpleEventTracerTestDelegate) {
+  // Call all the EventTracer macro's with a valid pointer to an event tracer
+  // and also with a null pointer (to test that the null case works).
+  DummyEventTracer dummy;
+  std::vector<DummyEventTracer*> dummy_event_tracer_arr = {&dummy, nullptr};
+  for (size_t i = 0; i < dummy_event_tracer_arr.size(); i++) {
+    RunSimpleTracerTestDelegate(&dummy);
+    RunSimpleTracerTestDelegate(nullptr);
+  }
+}
+
 } // namespace executor
 } // namespace torch
 // TODO : (T163645377) Add more test coverage to log and verify events passed
diff --git a/sdk/etdump/etdump_flatcc.h b/sdk/etdump/etdump_flatcc.h
@@ -45,6 +45,20 @@ class ETDumpGen : public EventTracer {
   virtual void end_profiling(EventTracerEntry prof_entry) override;
   virtual void track_allocation(AllocatorID id, size_t size) override;
   virtual AllocatorID track_allocator(const char* name) override;
+  virtual EventTracerEntry start_profiling_delegate(
+      const char* name,
+      DebugHandle delegate_debug_index) override {
+    return EventTracerEntry();
+  };
+  virtual void end_profiling_delegate(
+      EventTracerEntry event_tracer_entry,
+      const char* metadata = nullptr) override{};
+  virtual void log_profiling_delegate(
+      const char* name,
+      DebugHandle delegate_debug_index,
+      et_timestamp_t start_time,
+      et_timestamp_t end_time,
+      const char* metadata = nullptr) override{};
   etdump_result get_etdump_data();
   size_t get_num_blocks();
 
