diff --git a/onnxruntime/core/common/path_string.h b/onnxruntime/core/common/path_string.h index 76434f5453..6cfb327cce 100644 --- a/onnxruntime/core/common/path_string.h +++ b/onnxruntime/core/common/path_string.h @@ -13,6 +13,15 @@ #include #endif +// for converting / printing ORT_TSTR path strings to std::string +#ifdef _WIN32 +#define ORT_TSTR_CONVERT_TO_PRINTABLE_STRING(X) std::wstring_convert>().to_bytes(X) +#define ORT_TSTR_CONVERT_FROM_STRING(X) std::wstring_convert>().from_bytes(X); +#else +#define ORT_TSTR_CONVERT_TO_PRINTABLE_STRING(X) X +#define ORT_TSTR_CONVERT_FROM_STRING(X) X +#endif + #include "core/common/common.h" #include "core/session/onnxruntime_c_api.h" diff --git a/onnxruntime/core/framework/config_options.cc b/onnxruntime/core/framework/config_options.cc index 3b322e1fcd..1a4acb6dab 100644 --- a/onnxruntime/core/framework/config_options.cc +++ b/onnxruntime/core/framework/config_options.cc @@ -52,4 +52,11 @@ Status ConfigOptions::AddConfigEntry(const char* config_key, const char* config_ return Status::OK(); } +std::ostream& operator<<(std::ostream& os, const ConfigOptions& config_options) { + for (const auto& [key, value] : config_options.configurations) { + os << " " << key << ": " << value; + } + return os; +} + } // namespace onnxruntime diff --git a/onnxruntime/core/framework/config_options.h b/onnxruntime/core/framework/config_options.h index 4297819bed..7b7c226819 100644 --- a/onnxruntime/core/framework/config_options.h +++ b/onnxruntime/core/framework/config_options.h @@ -32,6 +32,8 @@ struct ConfigOptions { // Add a config pair (config_key, config_value) to this instance of ConfigOptions Status AddConfigEntry(const char* config_key, const char* config_value) noexcept; + + friend std::ostream& operator<<(std::ostream& os, const ConfigOptions& config_options); }; } // namespace onnxruntime diff --git a/onnxruntime/core/framework/execution_providers.h b/onnxruntime/core/framework/execution_providers.h index 7bf11f8293..d97953fd9d 100644 --- a/onnxruntime/core/framework/execution_providers.h +++ b/onnxruntime/core/framework/execution_providers.h @@ -12,6 +12,9 @@ #include "core/framework/execution_provider.h" #include "core/graph/graph_viewer.h" #include "core/common/logging/logging.h" +#ifdef _WIN32 +#include "core/platform/tracing.h" +#endif namespace onnxruntime { @@ -36,7 +39,19 @@ class ExecutionProviders { ORT_IGNORE_RETURN_VALUE(provider_idx_map_.insert({provider_id, new_provider_idx})); // update execution provider options - exec_provider_options_[provider_id] = p_exec_provider->GetProviderOptions(); + auto providerOptions = p_exec_provider->GetProviderOptions(); + exec_provider_options_[provider_id] = providerOptions; + +#ifdef _WIN32 + for (const auto& config_pair : providerOptions) { + TraceLoggingWrite( + telemetry_provider_handle, + "ProviderOptions", + TraceLoggingString(provider_id.c_str(), "ProviderId"), + TraceLoggingString(config_pair.first.c_str(), "Key"), + TraceLoggingString(config_pair.second.c_str(), "Value")); + } +#endif exec_provider_ids_.push_back(provider_id); exec_providers_.push_back(p_exec_provider); diff --git a/onnxruntime/core/framework/session_options.h b/onnxruntime/core/framework/session_options.h index 8deeb4c2b8..40c59cfcf6 100644 --- a/onnxruntime/core/framework/session_options.h +++ b/onnxruntime/core/framework/session_options.h @@ -5,6 +5,8 @@ #include #include +#include +#include #include "core/common/gsl.h" #include "core/common/inlined_containers.h" #include "core/framework/config_options.h" @@ -24,6 +26,21 @@ enum class ExecutionOrder { PRIORITY_BASED = 1 // priority-based topological sort }; +inline std::ostream& operator<<(std::ostream& os, const ExecutionOrder& order) { + switch (order) { + case ExecutionOrder::DEFAULT: + os << "DEFAULT"; + break; + case ExecutionOrder::PRIORITY_BASED: + os << "PRIORITY_BASED"; + break; + default: + os << "UNKNOWN"; + break; + } + return os; +} + enum class FreeDimensionOverrideType { Invalid = 0, Denotation = 1, @@ -89,6 +106,7 @@ struct SessionOptions { /// Log severity for the inference session. Applies to session load, initialization, etc. /// See https://github.com/microsoft/onnxruntime/blob/main/include/onnxruntime/core/common/logging/severity.h + /// See https://github.com/microsoft/onnxruntime/blob/main/include/onnxruntime/core/session/onnxruntime_c_api.h#L231 for OrtLoggingLevel mappings /// Default = -1 (use default logger severity) int session_log_severity_level = -1; int session_log_verbosity_level = 0; ///< VLOG level if debug build and session_log_severity_level is 0 (VERBOSE). @@ -154,4 +172,37 @@ struct SessionOptions { void* user_logging_param = nullptr; }; +inline std::ostream& operator<<(std::ostream& os, const SessionOptions& session_options) { + os << "Session Options { " + << " execution_mode:" << session_options.execution_mode + << " execution_order:" << session_options.execution_order + << " enable_profiling:" << session_options.enable_profiling + << " optimized_model_filepath:" << ORT_TSTR_CONVERT_TO_PRINTABLE_STRING(session_options.optimized_model_filepath) + << " enable_mem_pattern:" << session_options.enable_mem_pattern + << " enable_mem_reuse:" << session_options.enable_mem_reuse + << " enable_cpu_mem_arena:" << session_options.enable_cpu_mem_arena + << " profile_file_prefix:" << ORT_TSTR_CONVERT_TO_PRINTABLE_STRING(session_options.profile_file_prefix) + << " session_logid:" << session_options.session_logid + << " session_log_severity_level:" << session_options.session_log_severity_level + << " session_log_verbosity_level:" << session_options.session_log_verbosity_level + << " max_num_graph_transformation_steps:" << session_options.max_num_graph_transformation_steps + << " graph_optimization_level:" << static_cast(session_options.graph_optimization_level) + << " intra_op_param:" << session_options.intra_op_param + << " inter_op_param:" << session_options.inter_op_param + //<< " free_dimension_overrides:" << session_options.free_dimension_overrides + << " use_per_session_threads:" << session_options.use_per_session_threads + << " thread_pool_allow_spinning:" << session_options.thread_pool_allow_spinning + << " use_deterministic_compute:" << session_options.use_deterministic_compute + << " config_options: { " << session_options.config_options << " }" + //<< " initializers_to_share_map:" << session_options.initializers_to_share_map +#if !defined(ORT_MINIMAL_BUILD) && !defined(DISABLE_EXTERNAL_INITIALIZERS) + //<< " external_initializers:" << session_options.external_initializers +#endif +#if !defined(ORT_MINIMAL_BUILD) || defined(ORT_MINIMAL_BUILD_CUSTOM_OPS) + //<< " custom_op_libs:" << session_options.custom_op_libs +#endif + << " }"; + return os; +} + } // namespace onnxruntime diff --git a/onnxruntime/core/session/inference_session.cc b/onnxruntime/core/session/inference_session.cc index 5935f29299..575529a06f 100644 --- a/onnxruntime/core/session/inference_session.cc +++ b/onnxruntime/core/session/inference_session.cc @@ -48,6 +48,9 @@ #include "core/platform/Barrier.h" #include "core/platform/ort_mutex.h" #include "core/platform/threadpool.h" +#ifdef _WIN32 +#include "core/platform/tracing.h" +#endif #include "core/providers/cpu/controlflow/utils.h" #include "core/providers/cpu/cpu_execution_provider.h" #ifdef USE_DML // TODO: This is necessary for the workaround in TransformGraph @@ -344,6 +347,7 @@ void InferenceSession::ConstructorCommon(const SessionOptions& session_options, // The call to InitLogger depends on the final state of session_options_. Hence it should be invoked // after the invocation of FinalizeSessionOptions. InitLogger(logging_manager_); // this sets session_logger_ so that it can be used for logging after this point. + TraceSessionOptions(session_options); #if !defined(ORT_MINIMAL_BUILD) // Update the number of steps for the graph transformer manager using the "finalized" session options @@ -457,6 +461,50 @@ void InferenceSession::ConstructorCommon(const SessionOptions& session_options, telemetry_ = {}; } +void InferenceSession::TraceSessionOptions(const SessionOptions& session_options) { + LOGS(*session_logger_, INFO) << session_options; + +#ifdef _WIN32 + TraceLoggingWrite(telemetry_provider_handle, + "SessionOptions", + TraceLoggingUInt8(static_cast(session_options.execution_mode), "execution_mode"), + TraceLoggingUInt8(static_cast(session_options.execution_order), "execution_order"), + TraceLoggingBoolean(session_options.enable_profiling, "enable_profiling"), + TraceLoggingString(ORT_TSTR_CONVERT_TO_PRINTABLE_STRING(session_options.optimized_model_filepath).c_str(), "optimized_model_filepath"), + TraceLoggingBoolean(session_options.enable_mem_pattern, "enable_mem_pattern"), + TraceLoggingBoolean(session_options.enable_mem_reuse, "enable_mem_reuse"), + TraceLoggingBoolean(session_options.enable_cpu_mem_arena, "enable_cpu_mem_arena"), + TraceLoggingString(ORT_TSTR_CONVERT_TO_PRINTABLE_STRING(session_options.profile_file_prefix).c_str(), "profile_file_prefix"), + TraceLoggingString(session_options.session_logid.c_str(), "session_logid"), + TraceLoggingInt8(static_cast(session_options.session_log_severity_level), "session_log_severity_level"), + TraceLoggingInt8(static_cast(session_options.session_log_verbosity_level), "session_log_verbosity_level"), + TraceLoggingUInt32(session_options.max_num_graph_transformation_steps, "max_num_graph_transformation_steps"), + TraceLoggingUInt8(static_cast(session_options.graph_optimization_level), "graph_optimization_level"), + TraceLoggingBoolean(session_options.use_per_session_threads, "use_per_session_threads"), + TraceLoggingBoolean(session_options.thread_pool_allow_spinning, "thread_pool_allow_spinning"), + TraceLoggingBoolean(session_options.use_deterministic_compute, "use_deterministic_compute")); + + TraceLoggingWrite( + telemetry_provider_handle, + "SessionOptions_IntraOrtThreadPoolParams", + TraceLoggingInt32(session_options.intra_op_param.thread_pool_size, "thread_pool_size"), + TraceLoggingBoolean(session_options.intra_op_param.auto_set_affinity, "auto_set_affinity"), + TraceLoggingBoolean(session_options.intra_op_param.allow_spinning, "allow_spinning"), + TraceLoggingInt32(session_options.intra_op_param.dynamic_block_base_, "dynamic_block_base_"), + TraceLoggingUInt32(session_options.intra_op_param.stack_size, "stack_size"), + TraceLoggingString(!session_options.intra_op_param.affinity_str.empty() ? session_options.intra_op_param.affinity_str.c_str() : "", "affinity_str"), + TraceLoggingBoolean(session_options.intra_op_param.set_denormal_as_zero, "set_denormal_as_zero")); + + for (const auto& config_pair : session_options.config_options.configurations) { + TraceLoggingWrite( + telemetry_provider_handle, + "SessionOptions_ConfigEntry", + TraceLoggingString(config_pair.first.c_str(), "Key"), + TraceLoggingString(config_pair.second.c_str(), "Value")); + } +#endif +} + InferenceSession::InferenceSession(const SessionOptions& session_options, const Environment& session_env) : #if !defined(ORT_MINIMAL_BUILD) diff --git a/onnxruntime/core/session/inference_session.h b/onnxruntime/core/session/inference_session.h index 4db436f132..96db49aabd 100644 --- a/onnxruntime/core/session/inference_session.h +++ b/onnxruntime/core/session/inference_session.h @@ -642,6 +642,8 @@ class InferenceSession { void InitLogger(logging::LoggingManager* logging_manager); + void TraceSessionOptions(const SessionOptions& session_options); + [[nodiscard]] common::Status CheckShapes(const std::string& input_name, const TensorShape& input_shape, const TensorShape& expected_shape, const char* input_output_moniker) const; diff --git a/onnxruntime/core/session/provider_registration.cc b/onnxruntime/core/session/provider_registration.cc index cb51a0c460..81e58c9dd0 100644 --- a/onnxruntime/core/session/provider_registration.cc +++ b/onnxruntime/core/session/provider_registration.cc @@ -12,6 +12,10 @@ #include "core/session/ort_apis.h" #include "core/providers/openvino/openvino_provider_factory_creator.h" +#ifdef _WIN32 +#include "core/platform/tracing.h" +#endif + #if defined(USE_DML) #include "core/providers/dml/dml_provider_factory_creator.h" #endif @@ -66,6 +70,17 @@ ORT_API_STATUS_IMPL(OrtApis::SessionOptionsAppendExecutionProvider, return status; } +#ifdef _WIN32 + for (const auto& config_pair : provider_options) { + TraceLoggingWrite( + telemetry_provider_handle, + "ProviderOptionsAppendExecutionProvider", + TraceLoggingString(provider_name, "ProviderName"), + TraceLoggingString(config_pair.first.c_str(), "Key"), + TraceLoggingString(config_pair.second.c_str(), "Value")); + } +#endif + auto create_not_supported_status = [&provider_name]() { return OrtApis::CreateStatus(ORT_INVALID_ARGUMENT, (std::string(provider_name) + " execution provider is not supported in this build. ").c_str()); diff --git a/onnxruntime/core/util/thread_utils.cc b/onnxruntime/core/util/thread_utils.cc index 54602e70a0..48f58add82 100644 --- a/onnxruntime/core/util/thread_utils.cc +++ b/onnxruntime/core/util/thread_utils.cc @@ -13,6 +13,23 @@ #include "core/common/string_utils.h" #include "core/common/logging/logging.h" +std::ostream& operator<<(std::ostream& os, const OrtThreadPoolParams& params) { + os << "OrtThreadPoolParams {"; + os << " thread_pool_size: " << params.thread_pool_size; + os << " auto_set_affinity: " << params.auto_set_affinity; + os << " allow_spinning: " << params.allow_spinning; + os << " dynamic_block_base_: " << params.dynamic_block_base_; + os << " stack_size: " << params.stack_size; + os << " affinity_str: " << params.affinity_str; + // os << " name: " << (params.name ? params.name : L"nullptr"); + os << " set_denormal_as_zero: " << params.set_denormal_as_zero; + // os << " custom_create_thread_fn: " << (params.custom_create_thread_fn ? "set" : "nullptr"); + // os << " custom_thread_creation_options: " << (params.custom_thread_creation_options ? "set" : "nullptr"); + // os << " custom_join_thread_fn: " << (params.custom_join_thread_fn ? "set" : "nullptr"); + os << " }"; + return os; +} + namespace onnxruntime { namespace concurrency { diff --git a/onnxruntime/core/util/thread_utils.h b/onnxruntime/core/util/thread_utils.h index 6108450389..d63d620dbc 100644 --- a/onnxruntime/core/util/thread_utils.h +++ b/onnxruntime/core/util/thread_utils.h @@ -48,6 +48,8 @@ struct OrtThreadPoolParams { OrtCustomJoinThreadFn custom_join_thread_fn = nullptr; }; +std::ostream& operator<<(std::ostream& os, const OrtThreadPoolParams& params); + struct OrtThreadingOptions { // Params for creating the threads that parallelizes execution of an op OrtThreadPoolParams intra_op_thread_pool_params;