Log out ORT session options

onnxruntime/core/common/path_string.h

@@ -13,6 +13,15 @@
 #include <cctype>
 #endif
 
+// for converting / printing ORT_TSTR path strings to std::string
+#ifdef _WIN32
+#define ORT_TSTR_CONVERT_TO_PRINTABLE_STRING(X) std::wstring_convert<std::codecvt_utf8<wchar_t>>().to_bytes(X)
+#define ORT_TSTR_CONVERT_FROM_STRING(X) std::wstring_convert<std::codecvt_utf8<wchar_t>>().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"
 

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

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

onnxruntime/core/framework/session_options.h

@@ -5,6 +5,8 @@
 
 #include <string>
 #include <vector>
+#include <iostream>
+#include <codecvt>
 #include "core/common/gsl.h"
 #include "core/common/inlined_containers.h"
 #include "core/framework/config_options.h"
@@ -24,6 +26,21 @@
   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 @@
 
   /// 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 @@
   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<int>(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

onnxruntime/core/session/inference_session.cc

@@ -48,6 +48,7 @@
 #include "core/platform/Barrier.h"
 #include "core/platform/ort_mutex.h"
 #include "core/platform/threadpool.h"
+#include "core/platform/tracing.h"
 #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
@@ -343,6 +344,7 @@
   // 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
@@ -456,6 +458,48 @@
   telemetry_ = {};
 }
 
+void InferenceSession::TraceSessionOptions(const SessionOptions& session_options) {
+  LOGS(*session_logger_, INFO) << session_options;
+
+  TraceLoggingWrite(telemetry_provider_handle,
+                    "SessionOptions",
+                    TraceLoggingUInt8(static_cast<UINT8>(session_options.execution_mode), "execution_mode"),
+                    TraceLoggingUInt8(static_cast<UINT8>(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<INT8>(session_options.session_log_severity_level), "session_log_severity_level"),
+                    TraceLoggingInt8(static_cast<INT8>(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<UINT8>(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"));
+  }
+}
+
 InferenceSession::InferenceSession(const SessionOptions& session_options, const Environment& session_env)
     :
 #if !defined(ORT_MINIMAL_BUILD)

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;
 

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 {
 

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;