From 8b71d899cf35d965376d896a98f1d49cc47d0b10 Mon Sep 17 00:00:00 2001 From: Sheil Kumar Date: Mon, 22 Jul 2024 11:27:38 -0700 Subject: [PATCH 01/10] Move ETW initialization check assignment to after initialization has completed successfully. --- onnxruntime/core/platform/windows/logging/etw_sink.cc | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/onnxruntime/core/platform/windows/logging/etw_sink.cc b/onnxruntime/core/platform/windows/logging/etw_sink.cc index b0f9eaf4f62d2..33b2d04d0b0c4 100644 --- a/onnxruntime/core/platform/windows/logging/etw_sink.cc +++ b/onnxruntime/core/platform/windows/logging/etw_sink.cc @@ -147,11 +147,11 @@ void EtwRegistrationManager::LazyInitialize() { if (!initialized_) { std::lock_guard lock(init_mutex_); if (!initialized_) { // Double-check locking pattern - initialized_ = true; etw_status_ = ::TraceLoggingRegisterEx(etw_provider_handle, ORT_TL_EtwEnableCallback, nullptr); if (FAILED(etw_status_)) { ORT_THROW("ETW registration failed. Logging will be broken: " + std::to_string(etw_status_)); } + initialized_ = true; } } } From afd6858a3e11b2d230bbe09bfcda9a256f9ffaff Mon Sep 17 00:00:00 2001 From: Sheil Kumar Date: Mon, 22 Jul 2024 13:31:21 -0700 Subject: [PATCH 02/10] Add initialization check to prevent re-entry into the lock during TraceLoggingRegisterEx --- .../core/platform/windows/logging/etw_sink.cc | 13 ++++++++++--- .../core/platform/windows/logging/etw_sink.h | 1 + 2 files changed, 11 insertions(+), 3 deletions(-) diff --git a/onnxruntime/core/platform/windows/logging/etw_sink.cc b/onnxruntime/core/platform/windows/logging/etw_sink.cc index 33b2d04d0b0c4..e9cc40d88e90a 100644 --- a/onnxruntime/core/platform/windows/logging/etw_sink.cc +++ b/onnxruntime/core/platform/windows/logging/etw_sink.cc @@ -143,17 +143,24 @@ EtwRegistrationManager::~EtwRegistrationManager() { EtwRegistrationManager::EtwRegistrationManager() { } -void EtwRegistrationManager::LazyInitialize() { - if (!initialized_) { +void EtwRegistrationManager::LazyInitialize() try { + if (!initialized_ && !initializing_) { std::lock_guard lock(init_mutex_); - if (!initialized_) { // Double-check locking pattern + if (!initialized_ && !initializing_) { // Double-check locking pattern + initializing_ = true; etw_status_ = ::TraceLoggingRegisterEx(etw_provider_handle, ORT_TL_EtwEnableCallback, nullptr); if (FAILED(etw_status_)) { ORT_THROW("ETW registration failed. Logging will be broken: " + std::to_string(etw_status_)); } initialized_ = true; + initializing_ = false; } } +} catch (...) +{ + initialized_ = false; + initializing_ = false; + throw; } void EtwRegistrationManager::InvokeCallbacks(LPCGUID SourceId, ULONG IsEnabled, UCHAR Level, ULONGLONG MatchAnyKeyword, diff --git a/onnxruntime/core/platform/windows/logging/etw_sink.h b/onnxruntime/core/platform/windows/logging/etw_sink.h index 3af45b813a625..19af3e565e095 100644 --- a/onnxruntime/core/platform/windows/logging/etw_sink.h +++ b/onnxruntime/core/platform/windows/logging/etw_sink.h @@ -97,6 +97,7 @@ class EtwRegistrationManager { mutable OrtMutex provider_change_mutex_; OrtMutex init_mutex_; bool initialized_ = false; + bool initializing_ = false; bool is_enabled_; UCHAR level_; ULONGLONG keyword_; From dbac3b94787c18f6a0b762525dd5864de4d7232f Mon Sep 17 00:00:00 2001 From: Sheil Kumar Date: Tue, 23 Jul 2024 07:32:56 -0700 Subject: [PATCH 03/10] Update logging to honor initialization checks --- .../core/platform/windows/logging/etw_sink.cc | 14 +++++++++++++- 1 file changed, 13 insertions(+), 1 deletion(-) diff --git a/onnxruntime/core/platform/windows/logging/etw_sink.cc b/onnxruntime/core/platform/windows/logging/etw_sink.cc index e9cc40d88e90a..c9d908949df4c 100644 --- a/onnxruntime/core/platform/windows/logging/etw_sink.cc +++ b/onnxruntime/core/platform/windows/logging/etw_sink.cc @@ -137,7 +137,14 @@ void NTAPI EtwRegistrationManager::ORT_TL_EtwEnableCallback( EtwRegistrationManager::~EtwRegistrationManager() { std::lock_guard lock(callbacks_mutex_); callbacks_.clear(); - ::TraceLoggingUnregister(etw_provider_handle); + if (initialized_ || initializing_) { + std::lock_guard init_lock(init_mutex_); + assert(!initializing_); + if (initialized_) { + ::TraceLoggingUnregister(etw_provider_handle); + initialized_ = false; + } + } } EtwRegistrationManager::EtwRegistrationManager() { @@ -166,6 +173,11 @@ void EtwRegistrationManager::LazyInitialize() try { void EtwRegistrationManager::InvokeCallbacks(LPCGUID SourceId, ULONG IsEnabled, UCHAR Level, ULONGLONG MatchAnyKeyword, ULONGLONG MatchAllKeyword, PEVENT_FILTER_DESCRIPTOR FilterData, PVOID CallbackContext) { + if (!initialized_) { + // Drop messages until manager is fully initialized. + return; + } + std::lock_guard lock(callbacks_mutex_); for (const auto& callback : callbacks_) { (*callback)(SourceId, IsEnabled, Level, MatchAnyKeyword, MatchAllKeyword, FilterData, CallbackContext); From 5c2d1bd151151d75b17ea51904080174131754e5 Mon Sep 17 00:00:00 2001 From: Sheil Kumar Date: Tue, 30 Jul 2024 15:59:01 -0700 Subject: [PATCH 04/10] change initialization vars to enum, and handle the failed case to avoid reinitializing logger. --- .../core/platform/windows/logging/etw_sink.cc | 27 +++++++++---------- .../core/platform/windows/logging/etw_sink.h | 5 ++-- 2 files changed, 16 insertions(+), 16 deletions(-) diff --git a/onnxruntime/core/platform/windows/logging/etw_sink.cc b/onnxruntime/core/platform/windows/logging/etw_sink.cc index c9d908949df4c..cc12514bd3c30 100644 --- a/onnxruntime/core/platform/windows/logging/etw_sink.cc +++ b/onnxruntime/core/platform/windows/logging/etw_sink.cc @@ -137,13 +137,14 @@ void NTAPI EtwRegistrationManager::ORT_TL_EtwEnableCallback( EtwRegistrationManager::~EtwRegistrationManager() { std::lock_guard lock(callbacks_mutex_); callbacks_.clear(); - if (initialized_ || initializing_) { + if (initialization_status_ == InitializationStatus::Intialized || + initialization_status_ == InitializationStatus::Initializing) { std::lock_guard init_lock(init_mutex_); - assert(!initializing_); - if (initialized_) { - ::TraceLoggingUnregister(etw_provider_handle); - initialized_ = false; - } + assert(initialization_status_ != InitializationStatus::Initializing); + if (initialization_status_ == InitializationStatus::Intialized) { + ::TraceLoggingUnregister(etw_provider_handle); + initialization_status_ = InitializationStatus::NotInitialized; + } } } @@ -151,29 +152,27 @@ EtwRegistrationManager::EtwRegistrationManager() { } void EtwRegistrationManager::LazyInitialize() try { - if (!initialized_ && !initializing_) { + if (initialization_status_ == InitializationStatus::NoitIntialized) { std::lock_guard lock(init_mutex_); - if (!initialized_ && !initializing_) { // Double-check locking pattern - initializing_ = true; + if (initialization_status_ == InitializationStatus::NotInitialized) { // Double-check locking pattern + initialization_status_ == InitializationStatus::Initializing; etw_status_ = ::TraceLoggingRegisterEx(etw_provider_handle, ORT_TL_EtwEnableCallback, nullptr); if (FAILED(etw_status_)) { ORT_THROW("ETW registration failed. Logging will be broken: " + std::to_string(etw_status_)); } - initialized_ = true; - initializing_ = false; + initialization_status_ == InitializationStatus::Initialized; } } } catch (...) { - initialized_ = false; - initializing_ = false; + initialization_status_ == InitializationStatus::Failed; throw; } void EtwRegistrationManager::InvokeCallbacks(LPCGUID SourceId, ULONG IsEnabled, UCHAR Level, ULONGLONG MatchAnyKeyword, ULONGLONG MatchAllKeyword, PEVENT_FILTER_DESCRIPTOR FilterData, PVOID CallbackContext) { - if (!initialized_) { + if (initialization_status_ != InitializationStatus::Initialized) { // Drop messages until manager is fully initialized. return; } diff --git a/onnxruntime/core/platform/windows/logging/etw_sink.h b/onnxruntime/core/platform/windows/logging/etw_sink.h index 19af3e565e095..acd9f6b0892f8 100644 --- a/onnxruntime/core/platform/windows/logging/etw_sink.h +++ b/onnxruntime/core/platform/windows/logging/etw_sink.h @@ -47,6 +47,8 @@ class EtwSink : public ISink { }; class EtwRegistrationManager { + enum class InitializationStatus { NotInitialized, Initializing, Initialized, Failed}; + public: using EtwInternalCallback = std::function Date: Tue, 30 Jul 2024 16:40:56 -0700 Subject: [PATCH 05/10] typo --- onnxruntime/core/platform/windows/logging/etw_sink.cc | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) diff --git a/onnxruntime/core/platform/windows/logging/etw_sink.cc b/onnxruntime/core/platform/windows/logging/etw_sink.cc index cc12514bd3c30..fd902bd6c14ec 100644 --- a/onnxruntime/core/platform/windows/logging/etw_sink.cc +++ b/onnxruntime/core/platform/windows/logging/etw_sink.cc @@ -137,11 +137,11 @@ void NTAPI EtwRegistrationManager::ORT_TL_EtwEnableCallback( EtwRegistrationManager::~EtwRegistrationManager() { std::lock_guard lock(callbacks_mutex_); callbacks_.clear(); - if (initialization_status_ == InitializationStatus::Intialized || + if (initialization_status_ == InitializationStatus::Initialized || initialization_status_ == InitializationStatus::Initializing) { std::lock_guard init_lock(init_mutex_); assert(initialization_status_ != InitializationStatus::Initializing); - if (initialization_status_ == InitializationStatus::Intialized) { + if (initialization_status_ == InitializationStatus::Initialized) { ::TraceLoggingUnregister(etw_provider_handle); initialization_status_ = InitializationStatus::NotInitialized; } @@ -152,7 +152,7 @@ EtwRegistrationManager::EtwRegistrationManager() { } void EtwRegistrationManager::LazyInitialize() try { - if (initialization_status_ == InitializationStatus::NoitIntialized) { + if (initialization_status_ == InitializationStatus::NoitInitialized) { std::lock_guard lock(init_mutex_); if (initialization_status_ == InitializationStatus::NotInitialized) { // Double-check locking pattern initialization_status_ == InitializationStatus::Initializing; From 9362dc623266ab02b237ec1b791ac13984e950a8 Mon Sep 17 00:00:00 2001 From: Sheil Kumar Date: Tue, 30 Jul 2024 16:57:49 -0700 Subject: [PATCH 06/10] more typo --- onnxruntime/core/platform/windows/logging/etw_sink.cc | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/onnxruntime/core/platform/windows/logging/etw_sink.cc b/onnxruntime/core/platform/windows/logging/etw_sink.cc index fd902bd6c14ec..b166e81531171 100644 --- a/onnxruntime/core/platform/windows/logging/etw_sink.cc +++ b/onnxruntime/core/platform/windows/logging/etw_sink.cc @@ -152,7 +152,7 @@ EtwRegistrationManager::EtwRegistrationManager() { } void EtwRegistrationManager::LazyInitialize() try { - if (initialization_status_ == InitializationStatus::NoitInitialized) { + if (initialization_status_ == InitializationStatus::NotInitialized) { std::lock_guard lock(init_mutex_); if (initialization_status_ == InitializationStatus::NotInitialized) { // Double-check locking pattern initialization_status_ == InitializationStatus::Initializing; From fff6c9696d2d62ad3eb42d8cc5fc7cfe775526ef Mon Sep 17 00:00:00 2001 From: Sheil Kumar Date: Tue, 30 Jul 2024 17:13:55 -0700 Subject: [PATCH 07/10] typo --- onnxruntime/core/platform/windows/logging/etw_sink.cc | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) diff --git a/onnxruntime/core/platform/windows/logging/etw_sink.cc b/onnxruntime/core/platform/windows/logging/etw_sink.cc index b166e81531171..db0f6a24ad672 100644 --- a/onnxruntime/core/platform/windows/logging/etw_sink.cc +++ b/onnxruntime/core/platform/windows/logging/etw_sink.cc @@ -155,17 +155,17 @@ void EtwRegistrationManager::LazyInitialize() try { if (initialization_status_ == InitializationStatus::NotInitialized) { std::lock_guard lock(init_mutex_); if (initialization_status_ == InitializationStatus::NotInitialized) { // Double-check locking pattern - initialization_status_ == InitializationStatus::Initializing; + initialization_status_ = InitializationStatus::Initializing; etw_status_ = ::TraceLoggingRegisterEx(etw_provider_handle, ORT_TL_EtwEnableCallback, nullptr); if (FAILED(etw_status_)) { ORT_THROW("ETW registration failed. Logging will be broken: " + std::to_string(etw_status_)); } - initialization_status_ == InitializationStatus::Initialized; + initialization_status_ = InitializationStatus::Initialized; } } } catch (...) { - initialization_status_ == InitializationStatus::Failed; + initialization_status_ = InitializationStatus::Failed; throw; } From a076c97e8b2204275b206c71004b377f80b39255 Mon Sep 17 00:00:00 2001 From: Sheil Kumar Date: Tue, 30 Jul 2024 17:32:10 -0700 Subject: [PATCH 08/10] lint --- onnxruntime/core/platform/windows/logging/etw_sink.h | 5 ++++- 1 file changed, 4 insertions(+), 1 deletion(-) diff --git a/onnxruntime/core/platform/windows/logging/etw_sink.h b/onnxruntime/core/platform/windows/logging/etw_sink.h index acd9f6b0892f8..d6c9ea27b2955 100644 --- a/onnxruntime/core/platform/windows/logging/etw_sink.h +++ b/onnxruntime/core/platform/windows/logging/etw_sink.h @@ -47,7 +47,10 @@ class EtwSink : public ISink { }; class EtwRegistrationManager { - enum class InitializationStatus { NotInitialized, Initializing, Initialized, Failed}; + enum class InitializationStatus { NotInitialized, + Initializing, + Initialized, + Failed }; public: using EtwInternalCallback = std::function Date: Tue, 30 Jul 2024 17:33:20 -0700 Subject: [PATCH 09/10] lint 2 --- onnxruntime/core/platform/windows/logging/etw_sink.cc | 3 +-- 1 file changed, 1 insertion(+), 2 deletions(-) diff --git a/onnxruntime/core/platform/windows/logging/etw_sink.cc b/onnxruntime/core/platform/windows/logging/etw_sink.cc index db0f6a24ad672..e9a4a039e364b 100644 --- a/onnxruntime/core/platform/windows/logging/etw_sink.cc +++ b/onnxruntime/core/platform/windows/logging/etw_sink.cc @@ -163,8 +163,7 @@ void EtwRegistrationManager::LazyInitialize() try { initialization_status_ = InitializationStatus::Initialized; } } -} catch (...) -{ +} catch (...){ initialization_status_ = InitializationStatus::Failed; throw; } From 822c03abf79dcd5c991f09a70c38c54137099d1c Mon Sep 17 00:00:00 2001 From: Sheil Kumar Date: Tue, 30 Jul 2024 17:43:11 -0700 Subject: [PATCH 10/10] lint 3 --- onnxruntime/core/platform/windows/logging/etw_sink.cc | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/onnxruntime/core/platform/windows/logging/etw_sink.cc b/onnxruntime/core/platform/windows/logging/etw_sink.cc index e9a4a039e364b..ef42c88a67ba6 100644 --- a/onnxruntime/core/platform/windows/logging/etw_sink.cc +++ b/onnxruntime/core/platform/windows/logging/etw_sink.cc @@ -163,7 +163,7 @@ void EtwRegistrationManager::LazyInitialize() try { initialization_status_ = InitializationStatus::Initialized; } } -} catch (...){ +} catch (...) { initialization_status_ = InitializationStatus::Failed; throw; }