CVS-174008: Enable ETW Tracing for OVEP

cmake/onnxruntime_providers_openvino.cmake

@@ -51,6 +51,11 @@
   target_include_directories(onnxruntime_providers_openvino SYSTEM PUBLIC ${ONNXRUNTIME_ROOT} ${CMAKE_CURRENT_BINARY_DIR} ${OpenVINO_INCLUDE_DIR} ${OPENVINO_INCLUDE_DIR_LIST} ${PYTHON_INCLUDE_DIRS} $ENV{OPENCL_INCS} $ENV{OPENCL_INCS}/../../cl_headers/)
   target_link_libraries(onnxruntime_providers_openvino ${ONNXRUNTIME_PROVIDERS_SHARED} Boost::mp11 ${OPENVINO_LIB_LIST} ${ABSEIL_LIBS} Eigen3::Eigen onnx_proto)
 
+  # ETW TraceLogging depends on Advapi32 on Windows
+  if(WIN32)
+    target_link_libraries(onnxruntime_providers_openvino advapi32)
+  endif()
+
   target_compile_definitions(onnxruntime_providers_openvino PRIVATE FILE_NAME=\"onnxruntime_providers_openvino.dll\")
 
   if(MSVC)

onnxruntime/core/providers/openvino/contexts.h

@@ -127,16 +127,35 @@
                                                                "enable_causallm", "disable_dynamic_shapes", "reshape_input", "layout"};
 };
 
+struct RuntimeConfig {
+  std::unordered_map<std::string, std::string> options;
+  std::optional<std::string> Get(const std::string& key) const {
+    auto it = options.find(key);
+    return it != options.end() ? std::optional{it->second} : std::nullopt;
+  }
+};
+
 // Holds context applicable to the entire EP instance.
 struct SessionContext : ProviderInfo {
-  SessionContext(const ProviderInfo& info) : ProviderInfo{info} {}
+  SessionContext(const ProviderInfo& info) : ProviderInfo{info} {
+    InitRuntimeConfig();
+  }
+
   std::vector<bool> deviceAvailableList = {true, true, true, true, true, true, true, true};
   std::filesystem::path onnx_model_path_name;
   uint32_t onnx_opset_version{0};
   mutable bool is_wholly_supported_graph = false;  // Value is set to mutable to modify from capability
   mutable bool has_external_weights = false;       // Value is set to mutable to modify from capability
   const std::vector<uint32_t> OpenVINO_Version = {OPENVINO_VERSION_MAJOR, OPENVINO_VERSION_MINOR};
   const std::string openvino_sdk_version = std::to_string(OPENVINO_VERSION_MAJOR) + "." + std::to_string(OPENVINO_VERSION_MINOR);
+  RuntimeConfig runtime_config;
+
+ private:
+  void InitRuntimeConfig() {
+    if (config_options) {
+      runtime_config.options = config_options->GetConfigOptionsMap();
+    }
+  }
 };
 
 // Holds context specific to subgraph.

onnxruntime/core/providers/openvino/openvino_execution_provider.cc

@@ -21,6 +21,8 @@
 namespace onnxruntime {
 namespace openvino_ep {
 
+std::atomic<uint32_t> OpenVINOExecutionProvider::global_session_counter_{0};
+
 // Parking this code here for now before it's moved to the factory
 #if defined OPENVINO_CONFIG_HETERO || defined OPENVINO_CONFIG_MULTI || defined OPENVINO_CONFIG_AUTO
 static std::vector<std::string> parseDevices(const std::string& device_string,
@@ -58,6 +60,11 @@ OpenVINOExecutionProvider::OpenVINOExecutionProvider(const ProviderInfo& info, s
       shared_context_{std::move(shared_context)},
       ep_ctx_handle_{session_context_.openvino_sdk_version, *GetLogger()} {
   InitProviderOrtApi();
+#ifdef _WIN32
+  session_id_ = global_session_counter_.fetch_add(1) + 1;
+  // Trace all runtime options (includes both session and provider options)
+  OVTracing::Instance().LogAllRuntimeOptions(session_id_, session_context_);
+#endif
 }
 
 OpenVINOExecutionProvider::~OpenVINOExecutionProvider() {

onnxruntime/core/providers/openvino/openvino_execution_provider.h

@@ -11,10 +11,15 @@
 #include <vector>
 #include <set>
 #include <utility>
+#include <atomic>
 
 #include "core/providers/openvino/backend_manager.h"
 #include "core/providers/openvino/contexts.h"
 
+#ifdef _WIN32
+#include "core/providers/openvino/ov_tracing.h"
+#endif
+
 namespace onnxruntime {
 namespace openvino_ep {
 
@@ -74,6 +79,10 @@ class OpenVINOExecutionProvider : public IExecutionProvider {
   std::shared_ptr<SharedContext> shared_context_;
   std::list<BackendManager> backend_managers_;  // EP session owns the backend objects
   EPCtxHandler ep_ctx_handle_;
+
+  // Tracing and session tracking
+  uint32_t session_id_{0};
+  static std::atomic<uint32_t> global_session_counter_;
 };
 
 }  // namespace openvino_ep

onnxruntime/core/providers/openvino/ov_tracing.cc

@@ -0,0 +1,228 @@
+// Copyright (c) Intel Corporation. All rights reserved.
+// Licensed under the MIT License.
+#include "core/providers/openvino/ov_tracing.h"
+
+#ifdef _WIN32
+#include <windows.h>
+#ifdef _MSC_VER
+#pragma warning(push)
+#pragma warning(disable : 26440)
+#endif
+#include <TraceLoggingProvider.h>
+#include <winmeta.h>
+#include "core/platform/windows/TraceLoggingConfig.h"
+
+TRACELOGGING_DEFINE_PROVIDER(
+    ov_tracing_provider_handle,
+    "Intel.ML.ONNXRuntime.OpenVINO",
+    // {"b5a8c2e1-4d7f-4a3b-9c2e-1f8e5a6b7c9d"}
+    (0xb5a8c2e1, 0x4d7f, 0x4a3b, 0x9c, 0x2e, 0x1f, 0x8e, 0x5a, 0x6b, 0x7c, 0x9d),
+    TraceLoggingOptionMicrosoftTelemetry());
+
+#ifdef _MSC_VER
+#pragma warning(pop)
+#endif
+
+namespace {
+std::string EscapeJsonString(const std::string& input) {
+  std::string escaped;
+  // Reserve extra space for escaping
+  escaped.reserve(input.size() + input.size() / 5);
+
+  for (char c : input) {
+    switch (c) {
+      case '\"':
+        escaped += "\\\"";
+        break;
+      case '\\':
+        escaped += "\\\\";
+        break;
+      case '\b':
+        escaped += "\\b";
+        break;
+      case '\f':
+        escaped += "\\f";
+        break;
+      case '\n':
+        escaped += "\\n";
+        break;
+      case '\r':
+        escaped += "\\r";
+        break;
+      case '\t':
+        escaped += "\\t";
+        break;
+      default:
+        if (static_cast<unsigned char>(c) < 0x20) {
+          char unicode_escape[7];
+          sprintf_s(unicode_escape, sizeof(unicode_escape), "\\u%04x", static_cast<unsigned char>(c));
+          escaped += unicode_escape;
+        } else {
+          escaped += c;
+        }
+        break;
+    }
+  }
+  return escaped;
+}
+}  // namespace
+
+namespace onnxruntime {
+namespace openvino_ep {
+
+std::mutex OVTracing::mutex_;
+std::mutex OVTracing::provider_change_mutex_;
+uint32_t OVTracing::global_register_count_ = 0;
+bool OVTracing::enabled_ = true;
+UCHAR OVTracing::level_ = 0;
+UINT64 OVTracing::keyword_ = 0;
+std::vector<const OVTracing::EtwInternalCallback*> OVTracing::callbacks_;
+std::mutex OVTracing::callbacks_mutex_;
+
+OVTracing::OVTracing() {
+  std::lock_guard<std::mutex> lock(mutex_);
+  if (global_register_count_ == 0) {
+    HRESULT hr = TraceLoggingRegisterEx(ov_tracing_provider_handle, ORT_TL_EtwEnableCallback, nullptr);
+    if (SUCCEEDED(hr)) {
+      global_register_count_ += 1;
+    }
+  }
+}
+
+OVTracing::~OVTracing() noexcept {
+  // Clean up TraceLogging, only hold mutex_
+  try {
+    std::lock_guard<std::mutex> lock(mutex_);
+    if (global_register_count_ > 0) {
+      global_register_count_ -= 1;
+      if (global_register_count_ == 0) {
+        TraceLoggingUnregister(ov_tracing_provider_handle);
+      }
+    }
+  } catch (...) {
+    // Suppress exceptions in destructor
+  }
+
+  // Clean up callbacks, only hold callbacks_mutex_
+  try {
+    std::lock_guard<std::mutex> lock_callbacks(callbacks_mutex_);
+    callbacks_.clear();
+  } catch (...) {
+    // Suppress exceptions in destructor
+  }
+}
+
+OVTracing& OVTracing::Instance() {
+  static OVTracing instance;
+  return instance;
+}
+
+bool OVTracing::IsEnabled() const {
+  std::lock_guard<std::mutex> lock(provider_change_mutex_);
+  return enabled_;
+}
+
+UCHAR OVTracing::Level() const {
+  std::lock_guard<std::mutex> lock(provider_change_mutex_);
+  return level_;
+}
+
+UINT64 OVTracing::Keyword() const {
+  std::lock_guard<std::mutex> lock(provider_change_mutex_);
+  return keyword_;
+}
+
+void OVTracing::LogAllRuntimeOptions(uint32_t session_id, const SessionContext& ctx) const {
+  if (!IsEnabled()) return;
+
+  // Log OpenVINO SDK version separately
+  TraceLoggingWrite(ov_tracing_provider_handle, "OV.SDK.Version",
+                    TraceLoggingLevel(WINEVENT_LEVEL_VERBOSE),
+                    TraceLoggingUInt32(session_id, "session_id"),
+                    TraceLoggingString(ctx.openvino_sdk_version.c_str(), "openvino_sdk_version"));
+
+  constexpr std::string_view provider_prefix = "ep.openvinoexecutionprovider.";
+  std::ostringstream provider_opts;
+  std::ostringstream session_opts;
+  bool provider_first = true;
+  bool session_first = true;
+
+  provider_opts << "{";
+  session_opts << "{";
+
+  // Segregate options based on prefix
+  for (const auto& [key, value] : ctx.runtime_config.options) {
+    if (!value.empty()) {
+      if (key.starts_with(provider_prefix)) {
+        // Provider option
+        if (!provider_first) provider_opts << ",";
+        provider_opts << "\"" << key << "\":\"" << EscapeJsonString(value) << "\"";
+        provider_first = false;
+      } else {
+        // Session option
+        if (!session_first) session_opts << ",";
+        session_opts << "\"" << key << "\":\"" << EscapeJsonString(value) << "\"";
+        session_first = false;
+      }
+    }
+  }
+
+  provider_opts << "}";
+  session_opts << "}";
+
+  // Log provider options only if there are any
+  if (!provider_first) {
+    TraceLoggingWrite(ov_tracing_provider_handle, "OVEP.Provider.Options",
+                      TraceLoggingLevel(WINEVENT_LEVEL_VERBOSE),
+                      TraceLoggingUInt32(session_id, "session_id"),
+                      TraceLoggingString(provider_opts.str().c_str(), "provider_options"));
+  }
+
+  // Log session options only if there are any
+  if (!session_first) {
+    TraceLoggingWrite(ov_tracing_provider_handle, "OVEP.Session.Options",
+                      TraceLoggingLevel(WINEVENT_LEVEL_VERBOSE),
+                      TraceLoggingUInt32(session_id, "session_id"),
+                      TraceLoggingString(session_opts.str().c_str(), "session_options"));
+  }
+}
+
+void OVTracing::RegisterInternalCallback(const EtwInternalCallback& callback) {
+  std::lock_guard<std::mutex> lock_callbacks(callbacks_mutex_);
+  callbacks_.push_back(&callback);
+}
+
+void OVTracing::UnregisterInternalCallback(const EtwInternalCallback& callback) {
+  std::lock_guard<std::mutex> lock_callbacks(callbacks_mutex_);
+  auto new_end = std::remove_if(callbacks_.begin(), callbacks_.end(),
+                                [&callback](const EtwInternalCallback* ptr) {
+                                  return ptr == &callback;
+                                });
+  callbacks_.erase(new_end, callbacks_.end());
+}
+
+void NTAPI OVTracing::ORT_TL_EtwEnableCallback(
+    _In_ LPCGUID SourceId, _In_ ULONG IsEnabled, _In_ UCHAR Level, _In_ ULONGLONG MatchAnyKeyword,
+    _In_ ULONGLONG MatchAllKeyword, _In_opt_ PEVENT_FILTER_DESCRIPTOR FilterData, _In_opt_ PVOID CallbackContext) {
+  {
+    std::lock_guard<std::mutex> lock(provider_change_mutex_);
+    enabled_ = (IsEnabled != 0);
+    level_ = Level;
+    keyword_ = MatchAnyKeyword;
+  }
+  // Release lock before invoking callbacks to prevent deadlock
+  InvokeCallbacks(SourceId, IsEnabled, Level, MatchAnyKeyword, MatchAllKeyword, FilterData, CallbackContext);
+}
+
+void OVTracing::InvokeCallbacks(LPCGUID SourceId, ULONG IsEnabled, UCHAR Level, ULONGLONG MatchAnyKeyword,
+                                ULONGLONG MatchAllKeyword, PEVENT_FILTER_DESCRIPTOR FilterData, PVOID CallbackContext) {
+  std::lock_guard<std::mutex> lock_callbacks(callbacks_mutex_);
+  for (const auto& callback : callbacks_) {
+    (*callback)(SourceId, IsEnabled, Level, MatchAnyKeyword, MatchAllKeyword, FilterData, CallbackContext);
+  }
+}
+
+}  // namespace openvino_ep
+}  // namespace onnxruntime
+
+#endif  // defined(_WIN32)

onnxruntime/core/providers/openvino/ov_tracing.h

@@ -0,0 +1,64 @@
+// Copyright (c) Intel Corporation. All rights reserved.
+// Licensed under the MIT License.
+#pragma once
+
+#ifdef _WIN32
+#include <windows.h>
+#include <TraceLoggingProvider.h>
+#include <winmeta.h>
+
+#include <functional>
+#include <mutex>
+#include <string>
+#include <vector>
+#include <sstream>
+#include <unordered_map>
+#include <optional>
+#include <algorithm>
+#include "core/providers/openvino/contexts.h"
+
+TRACELOGGING_DECLARE_PROVIDER(ov_tracing_provider_handle);
+
+namespace onnxruntime {
+namespace openvino_ep {
+
+class OVTracing {
+ public:
+  static OVTracing& Instance();
+  bool IsEnabled() const;
+  unsigned char Level() const;
+  UINT64 Keyword() const;
+
+  void LogAllRuntimeOptions(uint32_t session_id, const SessionContext& ctx) const;
+
+  using EtwInternalCallback = std::function<void(
+      LPCGUID, ULONG, UCHAR, ULONGLONG, ULONGLONG, PEVENT_FILTER_DESCRIPTOR, PVOID)>;
+  static void RegisterInternalCallback(const EtwInternalCallback& callback);
+  static void UnregisterInternalCallback(const EtwInternalCallback& callback);
+
+ private:
+  OVTracing();
+  ~OVTracing();
+  OVTracing(const OVTracing&) = delete;
+  OVTracing& operator=(const OVTracing&) = delete;
+  OVTracing(OVTracing&&) = delete;
+  OVTracing& operator=(OVTracing&&) = delete;
+
+  static std::mutex mutex_;
+  static uint32_t global_register_count_;
+  static bool enabled_;
+  static std::vector<const EtwInternalCallback*> callbacks_;
+  static std::mutex callbacks_mutex_;
+  static std::mutex provider_change_mutex_;
+  static UCHAR level_;
+  static ULONGLONG keyword_;
+
+  static void InvokeCallbacks(LPCGUID, ULONG, UCHAR, ULONGLONG, ULONGLONG, PEVENT_FILTER_DESCRIPTOR, PVOID);
+  static void NTAPI ORT_TL_EtwEnableCallback(_In_ LPCGUID, _In_ ULONG, _In_ UCHAR, _In_ ULONGLONG,
+                                             _In_ ULONGLONG, _In_opt_ PEVENT_FILTER_DESCRIPTOR, _In_opt_ PVOID);
+};
+
+}  // namespace openvino_ep
+}  // namespace onnxruntime
+
+#endif  // defined(_WIN32)