From cf565e955db71f90060ecd2e07bc4e34a8d5600f Mon Sep 17 00:00:00 2001 From: Adrian Lizarraga Date: Mon, 15 Jul 2024 17:56:08 -0700 Subject: [PATCH] Revert "Fix ETW Sink Initialize unproperly locking" (#21360) Reverts microsoft/onnxruntime#21226 Causes any onnxruntime app to hang on Windows ARM64. Our pipelines do not have the same ETW environment, so we couldn't catch it. ![image](https://github.com/user-attachments/assets/80edbf7d-be50-4cb0-a016-f390b81dc798) The call to TraceLoggingRegisterEx() recursively calls back into LazyInitialize(): LazyInitialize() -> TraceLoggingRegisterEx() -> ORT_TL_EtwEnableCallback() -> Instance() -> LazyInitialize() The original code got out of the recursive loop by checking the `initialized_` flag. --- .../core/platform/windows/logging/etw_sink.cc | 22 ++++++++++++++++--- .../core/platform/windows/logging/etw_sink.h | 4 ++++ 2 files changed, 23 insertions(+), 3 deletions(-) diff --git a/onnxruntime/core/platform/windows/logging/etw_sink.cc b/onnxruntime/core/platform/windows/logging/etw_sink.cc index 2a74e22850658..b0f9eaf4f62d2 100644 --- a/onnxruntime/core/platform/windows/logging/etw_sink.cc +++ b/onnxruntime/core/platform/windows/logging/etw_sink.cc @@ -98,6 +98,10 @@ ULONGLONG EtwRegistrationManager::Keyword() const { return keyword_; } +HRESULT EtwRegistrationManager::Status() const { + return etw_status_; +} + void EtwRegistrationManager::RegisterInternalCallback(const EtwInternalCallback& callback) { std::lock_guard lock(callbacks_mutex_); callbacks_.push_back(&callback); @@ -140,9 +144,15 @@ EtwRegistrationManager::EtwRegistrationManager() { } void EtwRegistrationManager::LazyInitialize() { - static HRESULT 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)); + 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_)); + } + } } } @@ -161,6 +171,12 @@ void EtwSink::SendImpl(const Timestamp& timestamp, const std::string& logger_id, // register on first usage static EtwRegistrationManager& etw_manager = EtwRegistrationManager::Instance(); + // do something (not that meaningful) with etw_manager so it doesn't get optimized out + // as we want an instance around to do the unregister + if (FAILED(etw_manager.Status())) { + return; + } + // TODO: Validate if this filtering makes sense. if (message.DataType() == DataType::USER) { return; diff --git a/onnxruntime/core/platform/windows/logging/etw_sink.h b/onnxruntime/core/platform/windows/logging/etw_sink.h index ff68aec0b7d64..3af45b813a625 100644 --- a/onnxruntime/core/platform/windows/logging/etw_sink.h +++ b/onnxruntime/core/platform/windows/logging/etw_sink.h @@ -66,6 +66,9 @@ class EtwRegistrationManager { // Get the current keyword uint64_t Keyword() const; + // Get the ETW registration status + HRESULT Status() const; + void RegisterInternalCallback(const EtwInternalCallback& callback); void UnregisterInternalCallback(const EtwInternalCallback& callback); @@ -97,6 +100,7 @@ class EtwRegistrationManager { bool is_enabled_; UCHAR level_; ULONGLONG keyword_; + HRESULT etw_status_; }; } // namespace logging