Add support for delegate profiling in event_tracer

tarun292 · facebook-github-bot · commit cbce03cf0a4c · 2023-09-19T10:35:59.000-07:00
Summary:
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.

Differential Revision: D49360145

fbshipit-source-id: 708dc81b369a56d2c990651963af93e473df6f42
diff --git a/runtime/core/event_tracer.h b/runtime/core/event_tracer.h
@@ -28,6 +28,13 @@ typedef uint32_t DebugHandle;
 constexpr ChainID kUnsetChainId = -1;
 constexpr DebugHandle kUnsetDebugHandle = 0;
 
+/// Different types of delegate debug identifiers that are supported currently.
+enum DelegateDebugIdType {
+  IDENTIFIER_NONE = 0,
+  IDENTIFIER_INT = 1,
+  IDENTIFIER_STR = 2
+};
+
 /**
  * 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 +51,12 @@ struct EventTracerEntry {
   DebugHandle debug_handle;
   /// The time at which this event was started to be tracked.
   et_timestamp_t start_time;
+  /// If this event doesn't represent a delegated event then this should be
+  /// IDENTIFIER_NONE else it should be one of the other values in
+  /// DelegateDebugIdType. The actual delegate debug id value will be stored in
+  /// event_id.
+  DelegateDebugIdType delegate_debug_id_type;
 };
-
 /**
  * EventTracer is a class that users can inherit and implement to
  * log/serialize/stream etc. the profiling and debugging events that are
@@ -92,6 +103,65 @@ 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.
+   * @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 -1 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.
+   */
+  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.
+   * @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 -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 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.
+   */
+  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,132 @@
+/*
+ * 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.
+ * @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 -1 should be passed in here.
+ */
+inline EventTracerEntry event_tracer_start_profiling_delegate(
+    EventTracer* event_tracer,
+    const char* name,
+    DebugHandle delegate_debug_index) {
+#ifdef ET_EVENT_TRACER_ENABLED
+  if (event_tracer) {
+    return event_tracer->start_profiling_delegate(name, delegate_debug_index);
+  }
+#else //! ET_EVENT_TRACER_ENABLED
+  (void)name;
+  (void)delegate_debug_index;
+#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.
+ */
+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.
+ * @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 -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.
+ */
+inline void event_tracer_log_profiling_delegate(
+    EventTracer* event_tracer,
+    const char* name,
+    DebugHandle delegate_debug_index,
+    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_index, start_time, end_time, metadata);
+  }
+#else //! ET_EVENT_TRACER_ENABLED
+  (void)name;
+  (void)delegate_debug_index;
+  (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,6 +55,34 @@ class DummyEventTracer : public EventTracer {
     (void)name;
     return 0;
   }
+
+  EventTracerEntry start_profiling_delegate(
+      const char* name,
+      DebugHandle delegate_debug_index) override {
+    (void)name;
+    (void)delegate_debug_index;
+    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_index,
+      et_timestamp_t start_time,
+      et_timestamp_t end_time,
+      const char* metadata = nullptr) override {
+    (void)name;
+    (void)delegate_debug_index;
+    (void)start_time;
+    (void)end_time;
+    (void)metadata;
+  }
 };
 
 void RunSimpleTracerTest(EventTracer* event_tracer) {
@@ -86,6 +115,30 @@ TEST(TestEventTracer, SimpleEventTracerTest) {
   }
 }
 
+void RunSimpleTracerTestDelegate(EventTracer* event_tracer) {
+  EventTracerEntry event_tracer_entry =
+      event_tracer_start_profiling_delegate(event_tracer, "test_event", -1);
+  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", -1, 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
