Skip to content

Commit 19ebc1f

Browse files
ankitm3kMayureshV1Copilot
authored
CVS-174008: Enable ETW Tracing for OVEP (#827)
* Update: Enable OVEP ETW Tracing & Logging * fix: Refactor code & fix load_config tracing logic * fix: refactor logging logic * fix: amend review changes * fix: amend review changes. * fix: amend string parsing & add linking advapi32 in cmake * fix: refine options parsing * fix: perform atomic add for the global session counter * add: enable ep.stop_share_ep_contexts sess opt logging * fix:lint fixes * fix: ort wprp file * fix: OVTracing renamed * refactor logging of runtime options * lint fixes * fix: coverity fixes * fix: fix event options logging * Update onnxruntime/core/providers/openvino/ov_tracing.cc Co-authored-by: Copilot <[email protected]> * Revert "Update onnxruntime/core/providers/openvino/ov_tracing.cc" This reverts commit 05920e2. --------- Co-authored-by: MayureshV1 <[email protected]> Co-authored-by: Copilot <[email protected]> Co-authored-by: Mayuresh M Varerkar <[email protected]>
1 parent f7483e6 commit 19ebc1f

File tree

7 files changed

+339
-1
lines changed

7 files changed

+339
-1
lines changed

cmake/onnxruntime_providers_openvino.cmake

Lines changed: 5 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -51,6 +51,11 @@
5151
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/)
5252
target_link_libraries(onnxruntime_providers_openvino ${ONNXRUNTIME_PROVIDERS_SHARED} Boost::mp11 ${OPENVINO_LIB_LIST} ${ABSEIL_LIBS} Eigen3::Eigen onnx_proto)
5353

54+
# ETW TraceLogging depends on Advapi32 on Windows
55+
if(WIN32)
56+
target_link_libraries(onnxruntime_providers_openvino advapi32)
57+
endif()
58+
5459
target_compile_definitions(onnxruntime_providers_openvino PRIVATE FILE_NAME=\"onnxruntime_providers_openvino.dll\")
5560

5661
if(MSVC)

onnxruntime/core/providers/openvino/contexts.h

Lines changed: 20 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -127,16 +127,35 @@ struct ProviderInfo {
127127
"enable_causallm", "disable_dynamic_shapes", "reshape_input", "layout"};
128128
};
129129

130+
struct RuntimeConfig {
131+
std::unordered_map<std::string, std::string> options;
132+
std::optional<std::string> Get(const std::string& key) const {
133+
auto it = options.find(key);
134+
return it != options.end() ? std::optional{it->second} : std::nullopt;
135+
}
136+
};
137+
130138
// Holds context applicable to the entire EP instance.
131139
struct SessionContext : ProviderInfo {
132-
SessionContext(const ProviderInfo& info) : ProviderInfo{info} {}
140+
SessionContext(const ProviderInfo& info) : ProviderInfo{info} {
141+
InitRuntimeConfig();
142+
}
143+
133144
std::vector<bool> deviceAvailableList = {true, true, true, true, true, true, true, true};
134145
std::filesystem::path onnx_model_path_name;
135146
uint32_t onnx_opset_version{0};
136147
mutable bool is_wholly_supported_graph = false; // Value is set to mutable to modify from capability
137148
mutable bool has_external_weights = false; // Value is set to mutable to modify from capability
138149
const std::vector<uint32_t> OpenVINO_Version = {OPENVINO_VERSION_MAJOR, OPENVINO_VERSION_MINOR};
139150
const std::string openvino_sdk_version = std::to_string(OPENVINO_VERSION_MAJOR) + "." + std::to_string(OPENVINO_VERSION_MINOR);
151+
RuntimeConfig runtime_config;
152+
153+
private:
154+
void InitRuntimeConfig() {
155+
if (config_options) {
156+
runtime_config.options = config_options->GetConfigOptionsMap();
157+
}
158+
}
140159
};
141160

142161
// Holds context specific to subgraph.

onnxruntime/core/providers/openvino/openvino_execution_provider.cc

Lines changed: 7 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -21,6 +21,8 @@
2121
namespace onnxruntime {
2222
namespace openvino_ep {
2323

24+
std::atomic<uint32_t> OpenVINOExecutionProvider::global_session_counter_{0};
25+
2426
// Parking this code here for now before it's moved to the factory
2527
#if defined OPENVINO_CONFIG_HETERO || defined OPENVINO_CONFIG_MULTI || defined OPENVINO_CONFIG_AUTO
2628
static std::vector<std::string> parseDevices(const std::string& device_string,
@@ -58,6 +60,11 @@ OpenVINOExecutionProvider::OpenVINOExecutionProvider(const ProviderInfo& info, s
5860
shared_context_{std::move(shared_context)},
5961
ep_ctx_handle_{session_context_.openvino_sdk_version, *GetLogger()} {
6062
InitProviderOrtApi();
63+
#ifdef _WIN32
64+
session_id_ = global_session_counter_.fetch_add(1) + 1;
65+
// Trace all runtime options (includes both session and provider options)
66+
OVTracing::Instance().LogAllRuntimeOptions(session_id_, session_context_);
67+
#endif
6168
}
6269

6370
OpenVINOExecutionProvider::~OpenVINOExecutionProvider() {

onnxruntime/core/providers/openvino/openvino_execution_provider.h

Lines changed: 9 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -11,10 +11,15 @@
1111
#include <vector>
1212
#include <set>
1313
#include <utility>
14+
#include <atomic>
1415

1516
#include "core/providers/openvino/backend_manager.h"
1617
#include "core/providers/openvino/contexts.h"
1718

19+
#ifdef _WIN32
20+
#include "core/providers/openvino/ov_tracing.h"
21+
#endif
22+
1823
namespace onnxruntime {
1924
namespace openvino_ep {
2025

@@ -74,6 +79,10 @@ class OpenVINOExecutionProvider : public IExecutionProvider {
7479
std::shared_ptr<SharedContext> shared_context_;
7580
std::list<BackendManager> backend_managers_; // EP session owns the backend objects
7681
EPCtxHandler ep_ctx_handle_;
82+
83+
// Tracing and session tracking
84+
uint32_t session_id_{0};
85+
static std::atomic<uint32_t> global_session_counter_;
7786
};
7887

7988
} // namespace openvino_ep
Lines changed: 228 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,228 @@
1+
// Copyright (c) Intel Corporation. All rights reserved.
2+
// Licensed under the MIT License.
3+
#include "core/providers/openvino/ov_tracing.h"
4+
5+
#ifdef _WIN32
6+
#include <windows.h>
7+
#ifdef _MSC_VER
8+
#pragma warning(push)
9+
#pragma warning(disable : 26440)
10+
#endif
11+
#include <TraceLoggingProvider.h>
12+
#include <winmeta.h>
13+
#include "core/platform/windows/TraceLoggingConfig.h"
14+
15+
TRACELOGGING_DEFINE_PROVIDER(
16+
ov_tracing_provider_handle,
17+
"Intel.ML.ONNXRuntime.OpenVINO",
18+
// {"b5a8c2e1-4d7f-4a3b-9c2e-1f8e5a6b7c9d"}
19+
(0xb5a8c2e1, 0x4d7f, 0x4a3b, 0x9c, 0x2e, 0x1f, 0x8e, 0x5a, 0x6b, 0x7c, 0x9d),
20+
TraceLoggingOptionMicrosoftTelemetry());
21+
22+
#ifdef _MSC_VER
23+
#pragma warning(pop)
24+
#endif
25+
26+
namespace {
27+
std::string EscapeJsonString(const std::string& input) {
28+
std::string escaped;
29+
// Reserve extra space for escaping
30+
escaped.reserve(input.size() + input.size() / 5);
31+
32+
for (char c : input) {
33+
switch (c) {
34+
case '\"':
35+
escaped += "\\\"";
36+
break;
37+
case '\\':
38+
escaped += "\\\\";
39+
break;
40+
case '\b':
41+
escaped += "\\b";
42+
break;
43+
case '\f':
44+
escaped += "\\f";
45+
break;
46+
case '\n':
47+
escaped += "\\n";
48+
break;
49+
case '\r':
50+
escaped += "\\r";
51+
break;
52+
case '\t':
53+
escaped += "\\t";
54+
break;
55+
default:
56+
if (static_cast<unsigned char>(c) < 0x20) {
57+
char unicode_escape[7];
58+
sprintf_s(unicode_escape, sizeof(unicode_escape), "\\u%04x", static_cast<unsigned char>(c));
59+
escaped += unicode_escape;
60+
} else {
61+
escaped += c;
62+
}
63+
break;
64+
}
65+
}
66+
return escaped;
67+
}
68+
} // namespace
69+
70+
namespace onnxruntime {
71+
namespace openvino_ep {
72+
73+
std::mutex OVTracing::mutex_;
74+
std::mutex OVTracing::provider_change_mutex_;
75+
uint32_t OVTracing::global_register_count_ = 0;
76+
bool OVTracing::enabled_ = true;
77+
UCHAR OVTracing::level_ = 0;
78+
UINT64 OVTracing::keyword_ = 0;
79+
std::vector<const OVTracing::EtwInternalCallback*> OVTracing::callbacks_;
80+
std::mutex OVTracing::callbacks_mutex_;
81+
82+
OVTracing::OVTracing() {
83+
std::lock_guard<std::mutex> lock(mutex_);
84+
if (global_register_count_ == 0) {
85+
HRESULT hr = TraceLoggingRegisterEx(ov_tracing_provider_handle, ORT_TL_EtwEnableCallback, nullptr);
86+
if (SUCCEEDED(hr)) {
87+
global_register_count_ += 1;
88+
}
89+
}
90+
}
91+
92+
OVTracing::~OVTracing() noexcept {
93+
// Clean up TraceLogging, only hold mutex_
94+
try {
95+
std::lock_guard<std::mutex> lock(mutex_);
96+
if (global_register_count_ > 0) {
97+
global_register_count_ -= 1;
98+
if (global_register_count_ == 0) {
99+
TraceLoggingUnregister(ov_tracing_provider_handle);
100+
}
101+
}
102+
} catch (...) {
103+
// Suppress exceptions in destructor
104+
}
105+
106+
// Clean up callbacks, only hold callbacks_mutex_
107+
try {
108+
std::lock_guard<std::mutex> lock_callbacks(callbacks_mutex_);
109+
callbacks_.clear();
110+
} catch (...) {
111+
// Suppress exceptions in destructor
112+
}
113+
}
114+
115+
OVTracing& OVTracing::Instance() {
116+
static OVTracing instance;
117+
return instance;
118+
}
119+
120+
bool OVTracing::IsEnabled() const {
121+
std::lock_guard<std::mutex> lock(provider_change_mutex_);
122+
return enabled_;
123+
}
124+
125+
UCHAR OVTracing::Level() const {
126+
std::lock_guard<std::mutex> lock(provider_change_mutex_);
127+
return level_;
128+
}
129+
130+
UINT64 OVTracing::Keyword() const {
131+
std::lock_guard<std::mutex> lock(provider_change_mutex_);
132+
return keyword_;
133+
}
134+
135+
void OVTracing::LogAllRuntimeOptions(uint32_t session_id, const SessionContext& ctx) const {
136+
if (!IsEnabled()) return;
137+
138+
// Log OpenVINO SDK version separately
139+
TraceLoggingWrite(ov_tracing_provider_handle, "OV.SDK.Version",
140+
TraceLoggingLevel(WINEVENT_LEVEL_VERBOSE),
141+
TraceLoggingUInt32(session_id, "session_id"),
142+
TraceLoggingString(ctx.openvino_sdk_version.c_str(), "openvino_sdk_version"));
143+
144+
constexpr std::string_view provider_prefix = "ep.openvinoexecutionprovider.";
145+
std::ostringstream provider_opts;
146+
std::ostringstream session_opts;
147+
bool provider_first = true;
148+
bool session_first = true;
149+
150+
provider_opts << "{";
151+
session_opts << "{";
152+
153+
// Segregate options based on prefix
154+
for (const auto& [key, value] : ctx.runtime_config.options) {
155+
if (!value.empty()) {
156+
if (key.starts_with(provider_prefix)) {
157+
// Provider option
158+
if (!provider_first) provider_opts << ",";
159+
provider_opts << "\"" << key << "\":\"" << EscapeJsonString(value) << "\"";
160+
provider_first = false;
161+
} else {
162+
// Session option
163+
if (!session_first) session_opts << ",";
164+
session_opts << "\"" << key << "\":\"" << EscapeJsonString(value) << "\"";
165+
session_first = false;
166+
}
167+
}
168+
}
169+
170+
provider_opts << "}";
171+
session_opts << "}";
172+
173+
// Log provider options only if there are any
174+
if (!provider_first) {
175+
TraceLoggingWrite(ov_tracing_provider_handle, "OVEP.Provider.Options",
176+
TraceLoggingLevel(WINEVENT_LEVEL_VERBOSE),
177+
TraceLoggingUInt32(session_id, "session_id"),
178+
TraceLoggingString(provider_opts.str().c_str(), "provider_options"));
179+
}
180+
181+
// Log session options only if there are any
182+
if (!session_first) {
183+
TraceLoggingWrite(ov_tracing_provider_handle, "OVEP.Session.Options",
184+
TraceLoggingLevel(WINEVENT_LEVEL_VERBOSE),
185+
TraceLoggingUInt32(session_id, "session_id"),
186+
TraceLoggingString(session_opts.str().c_str(), "session_options"));
187+
}
188+
}
189+
190+
void OVTracing::RegisterInternalCallback(const EtwInternalCallback& callback) {
191+
std::lock_guard<std::mutex> lock_callbacks(callbacks_mutex_);
192+
callbacks_.push_back(&callback);
193+
}
194+
195+
void OVTracing::UnregisterInternalCallback(const EtwInternalCallback& callback) {
196+
std::lock_guard<std::mutex> lock_callbacks(callbacks_mutex_);
197+
auto new_end = std::remove_if(callbacks_.begin(), callbacks_.end(),
198+
[&callback](const EtwInternalCallback* ptr) {
199+
return ptr == &callback;
200+
});
201+
callbacks_.erase(new_end, callbacks_.end());
202+
}
203+
204+
void NTAPI OVTracing::ORT_TL_EtwEnableCallback(
205+
_In_ LPCGUID SourceId, _In_ ULONG IsEnabled, _In_ UCHAR Level, _In_ ULONGLONG MatchAnyKeyword,
206+
_In_ ULONGLONG MatchAllKeyword, _In_opt_ PEVENT_FILTER_DESCRIPTOR FilterData, _In_opt_ PVOID CallbackContext) {
207+
{
208+
std::lock_guard<std::mutex> lock(provider_change_mutex_);
209+
enabled_ = (IsEnabled != 0);
210+
level_ = Level;
211+
keyword_ = MatchAnyKeyword;
212+
}
213+
// Release lock before invoking callbacks to prevent deadlock
214+
InvokeCallbacks(SourceId, IsEnabled, Level, MatchAnyKeyword, MatchAllKeyword, FilterData, CallbackContext);
215+
}
216+
217+
void OVTracing::InvokeCallbacks(LPCGUID SourceId, ULONG IsEnabled, UCHAR Level, ULONGLONG MatchAnyKeyword,
218+
ULONGLONG MatchAllKeyword, PEVENT_FILTER_DESCRIPTOR FilterData, PVOID CallbackContext) {
219+
std::lock_guard<std::mutex> lock_callbacks(callbacks_mutex_);
220+
for (const auto& callback : callbacks_) {
221+
(*callback)(SourceId, IsEnabled, Level, MatchAnyKeyword, MatchAllKeyword, FilterData, CallbackContext);
222+
}
223+
}
224+
225+
} // namespace openvino_ep
226+
} // namespace onnxruntime
227+
228+
#endif // defined(_WIN32)
Lines changed: 64 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,64 @@
1+
// Copyright (c) Intel Corporation. All rights reserved.
2+
// Licensed under the MIT License.
3+
#pragma once
4+
5+
#ifdef _WIN32
6+
#include <windows.h>
7+
#include <TraceLoggingProvider.h>
8+
#include <winmeta.h>
9+
10+
#include <functional>
11+
#include <mutex>
12+
#include <string>
13+
#include <vector>
14+
#include <sstream>
15+
#include <unordered_map>
16+
#include <optional>
17+
#include <algorithm>
18+
#include "core/providers/openvino/contexts.h"
19+
20+
TRACELOGGING_DECLARE_PROVIDER(ov_tracing_provider_handle);
21+
22+
namespace onnxruntime {
23+
namespace openvino_ep {
24+
25+
class OVTracing {
26+
public:
27+
static OVTracing& Instance();
28+
bool IsEnabled() const;
29+
unsigned char Level() const;
30+
UINT64 Keyword() const;
31+
32+
void LogAllRuntimeOptions(uint32_t session_id, const SessionContext& ctx) const;
33+
34+
using EtwInternalCallback = std::function<void(
35+
LPCGUID, ULONG, UCHAR, ULONGLONG, ULONGLONG, PEVENT_FILTER_DESCRIPTOR, PVOID)>;
36+
static void RegisterInternalCallback(const EtwInternalCallback& callback);
37+
static void UnregisterInternalCallback(const EtwInternalCallback& callback);
38+
39+
private:
40+
OVTracing();
41+
~OVTracing();
42+
OVTracing(const OVTracing&) = delete;
43+
OVTracing& operator=(const OVTracing&) = delete;
44+
OVTracing(OVTracing&&) = delete;
45+
OVTracing& operator=(OVTracing&&) = delete;
46+
47+
static std::mutex mutex_;
48+
static uint32_t global_register_count_;
49+
static bool enabled_;
50+
static std::vector<const EtwInternalCallback*> callbacks_;
51+
static std::mutex callbacks_mutex_;
52+
static std::mutex provider_change_mutex_;
53+
static UCHAR level_;
54+
static ULONGLONG keyword_;
55+
56+
static void InvokeCallbacks(LPCGUID, ULONG, UCHAR, ULONGLONG, ULONGLONG, PEVENT_FILTER_DESCRIPTOR, PVOID);
57+
static void NTAPI ORT_TL_EtwEnableCallback(_In_ LPCGUID, _In_ ULONG, _In_ UCHAR, _In_ ULONGLONG,
58+
_In_ ULONGLONG, _In_opt_ PEVENT_FILTER_DESCRIPTOR, _In_opt_ PVOID);
59+
};
60+
61+
} // namespace openvino_ep
62+
} // namespace onnxruntime
63+
64+
#endif // defined(_WIN32)

0 commit comments

Comments
 (0)