From bb1972264b89261e98d438367eb54d97eea52c12 Mon Sep 17 00:00:00 2001 From: Hector Li Date: Wed, 17 Apr 2024 09:42:40 -0700 Subject: [PATCH] Enable provider option to let user provider the profiling file path (#20285) Enable provider option to let user provider the profiling file path. Separate out the profiling level for ETW, in case there's switch like ETW enabled when Ort creates the QNN profiling, then gets disabled when Ort logs the profiling events. vise versa. Enhance the logic to decide the profiling level. --- .../core/session/onnxruntime_c_api.h | 1 + .../qnn/builder/qnn_backend_manager.cc | 81 ++++++++++++------- .../qnn/builder/qnn_backend_manager.h | 7 ++ .../providers/qnn/qnn_execution_provider.cc | 28 +++++-- onnxruntime/test/onnx/main.cc | 7 +- .../test/perftest/command_args_parser.cc | 1 + onnxruntime/test/perftest/ort_test_session.cc | 6 +- 7 files changed, 90 insertions(+), 41 deletions(-) diff --git a/include/onnxruntime/core/session/onnxruntime_c_api.h b/include/onnxruntime/core/session/onnxruntime_c_api.h index e40c375cab..e7b8f14871 100644 --- a/include/onnxruntime/core/session/onnxruntime_c_api.h +++ b/include/onnxruntime/core/session/onnxruntime_c_api.h @@ -3618,6 +3618,7 @@ struct OrtApi { * QNN supported keys: * "backend_path": file path to QNN backend library. * "profiling_level": QNN profiling level, options: "off", "basic", "detailed". Default to off. + * "profiling_file_path": QNN profiling file path if ETW not enabled. * "rpc_control_latency": QNN RPC control latency. * "vtcm_mb": QNN VTCM size in MB. default to 0(not set). * "htp_performance_mode": QNN performance mode, options: "burst", "balanced", "default", "high_performance", diff --git a/onnxruntime/core/providers/qnn/builder/qnn_backend_manager.cc b/onnxruntime/core/providers/qnn/builder/qnn_backend_manager.cc index 6bb57b6a3e..f322a27da2 100644 --- a/onnxruntime/core/providers/qnn/builder/qnn_backend_manager.cc +++ b/onnxruntime/core/providers/qnn/builder/qnn_backend_manager.cc @@ -388,15 +388,21 @@ Status QnnBackendManager::ReleaseDevice() { } Status QnnBackendManager::InitializeProfiling() { - if (ProfilingLevel::OFF == profiling_level_ || ProfilingLevel::INVALID == profiling_level_) { + profiling_level_merge_ = profiling_level_; + // use profiling level from ETW if ETW is enabled + if (profiling_level_etw_ != ProfilingLevel::INVALID) { + profiling_level_merge_ = profiling_level_etw_; + } + + if (ProfilingLevel::OFF == profiling_level_merge_ || ProfilingLevel::INVALID == profiling_level_merge_) { LOGS_DEFAULT(INFO) << "Profiling turned off."; return Status::OK(); } QnnProfile_Level_t qnn_profile_level = QNN_PROFILE_LEVEL_BASIC; - if (ProfilingLevel::BASIC == profiling_level_) { + if (ProfilingLevel::BASIC == profiling_level_merge_) { qnn_profile_level = QNN_PROFILE_LEVEL_BASIC; - } else if (ProfilingLevel::DETAILED == profiling_level_) { + } else if (ProfilingLevel::DETAILED == profiling_level_merge_) { qnn_profile_level = QNN_PROFILE_LEVEL_DETAILED; } auto result = qnn_interface_.profileCreate(backend_handle_, qnn_profile_level, &profile_backend_handle_); @@ -900,9 +906,36 @@ void QnnBackendManager::ReleaseResources() { } Status QnnBackendManager::ExtractBackendProfilingInfo() { - if (ProfilingLevel::OFF == profiling_level_ || ProfilingLevel::INVALID == profiling_level_) { + if (ProfilingLevel::OFF == profiling_level_merge_ || ProfilingLevel::INVALID == profiling_level_merge_) { return Status::OK(); } + + bool tracelogging_provider_ep_enabled = false; + const Env& env = Env::Default(); + auto& provider = env.GetTelemetryProvider(); + auto level = provider.Level(); + if (provider.IsEnabled()) { + auto keyword = provider.Keyword(); + if ((keyword & static_cast(onnxruntime::logging::ORTTraceLoggingKeyword::Profiling)) != 0 && level >= 5) { + tracelogging_provider_ep_enabled = true; + } + } + + // ETW disabled previously, but enabled now + if (ProfilingLevel::INVALID == profiling_level_etw_ && tracelogging_provider_ep_enabled) { + LOGS(*logger_, ERROR) << "ETW disabled previously, but enabled now. Can't do the switch! Won't output any profiling."; + return Status::OK(); + } + + // ETW enabled previously, but disabled now + if (ProfilingLevel::INVALID != profiling_level_etw_ && !tracelogging_provider_ep_enabled) { + LOGS(*logger_, ERROR) << "ETW enabled previously, but disabled now. Can't do the switch! Won't output any profiling."; + return Status::OK(); + } + + ORT_RETURN_IF(!tracelogging_provider_ep_enabled && profiling_file_path_.empty(), + "Need to specify a cvs file via provider option profiling_file_path if ETW not enabled."); + ORT_RETURN_IF(nullptr == profile_backend_handle_, "Backend profile handle not valid."); const QnnProfile_EventId_t* profile_events{nullptr}; @@ -917,32 +950,22 @@ Status QnnBackendManager::ExtractBackendProfilingInfo() { Qnn_ErrorHandle_t resultPropertyHasCapability = qnn_interface_.propertyHasCapability(QNN_PROPERTY_PROFILE_SUPPORTS_EXTENDED_EVENT); uint16_t errorCodePropertyHasCapability = static_cast(resultPropertyHasCapability & 0xFFFF); - if (errorCodePropertyHasCapability == QNN_PROFILE_NO_ERROR) { + if (errorCodePropertyHasCapability == QNN_PROPERTY_SUPPORTED) { LOGS(*logger_, VERBOSE) << "The QNN backend supports extended event data."; backendSupportsExtendedEventData = true; } else { LOGS(*logger_, VERBOSE) << "The QNN backend does not support extended event data."; } - bool tracelogging_provider_ep_enabled = false; - const Env& env = Env::Default(); - auto& provider = env.GetTelemetryProvider(); - if (provider.IsEnabled()) { - auto keyword = provider.Keyword(); - if ((keyword & static_cast(onnxruntime::logging::ORTTraceLoggingKeyword::Profiling)) != 0) { - tracelogging_provider_ep_enabled = true; - } - } std::ofstream outfile; if (!tracelogging_provider_ep_enabled) { // Write to CSV in append mode - const char* profilingCsvFilename = "qnn-profiling-data.csv"; - std::ifstream infile(profilingCsvFilename); + std::ifstream infile(profiling_file_path_.c_str()); bool exists = infile.good(); infile.close(); - outfile.open(profilingCsvFilename, std::ios_base::app); - ORT_RETURN_IF(!outfile.is_open(), "Failed to open qnn-profiling-data.csv"); + outfile.open(profiling_file_path_, std::ios_base::app); + ORT_RETURN_IF(!outfile.is_open(), "Failed to open profiling file: ", profiling_file_path_); // If file didn't exist before, write the header if (!exists) { outfile << "Msg Timestamp,Message,Time,Unit of Measurement,Timing Source,Event Level,Event Identifier\n"; @@ -1063,6 +1086,7 @@ Status QnnBackendManager::ExtractProfilingEventExtended( QnnProfile_Error_t errorCode = static_cast(resultGetExtendedEventData & 0xFFFF); ORT_RETURN_IF(QNN_PROFILE_NO_ERROR != errorCode, "Failed to get profile event data: " + std::string(QnnProfileErrorToString(errorCode))); + // need to check the version first std::string message = GetEventTypeString(event_data_extended.v1.type); std::string unit = GetUnitString(event_data_extended.v1.unit); @@ -1071,16 +1095,17 @@ Status QnnBackendManager::ExtractProfilingEventExtended( #endif if (!tracelogging_provider_ep_enabled) { - if (event_data_extended.version == QNN_PROFILE_DATA_VERSION_1) { - outfile << event_data_extended.v1.timestamp << "," - << message << "," - << ExtractQnnScalarValue(event_data_extended.v1.value) << "," - << unit << "," - << "BACKEND" - << "," - << eventLevel << "," - << (event_data_extended.v1.identifier ? event_data_extended.v1.identifier : "NULL") << "\n"; - } + // QNN issue, the version number not correct, ticket created + // if (event_data_extended.version == QNN_PROFILE_DATA_VERSION_1) { + outfile << event_data_extended.v1.timestamp << "," + << message << "," + << ExtractQnnScalarValue(event_data_extended.v1.value) << "," + << unit << "," + << "BACKEND" + << "," + << eventLevel << "," + << (event_data_extended.v1.identifier ? event_data_extended.v1.identifier : "NULL") << "\n"; + //} } else { #ifdef _WIN32 LogQnnProfileEventAsTraceLogging( diff --git a/onnxruntime/core/providers/qnn/builder/qnn_backend_manager.h b/onnxruntime/core/providers/qnn/builder/qnn_backend_manager.h index ff97c4c3a9..673e3c2f33 100644 --- a/onnxruntime/core/providers/qnn/builder/qnn_backend_manager.h +++ b/onnxruntime/core/providers/qnn/builder/qnn_backend_manager.h @@ -32,14 +32,18 @@ class QnnModel; class QnnBackendManager { public: QnnBackendManager(std::string&& backend_path, + ProfilingLevel profiling_level_etw, ProfilingLevel profiling_level, + std::string&& profiling_file_path, ContextPriority context_priority, std::string&& qnn_saver_path, uint32_t device_id, QnnHtpDevice_Arch_t htp_arch, uint32_t soc_model) : backend_path_(backend_path), + profiling_level_etw_(profiling_level_etw), profiling_level_(profiling_level), + profiling_file_path_(profiling_file_path), context_priority_(context_priority), qnn_saver_path_(qnn_saver_path), device_id_(device_id), @@ -225,7 +229,10 @@ class QnnBackendManager { Qnn_LogHandle_t log_handle_ = nullptr; Qnn_DeviceHandle_t device_handle_ = nullptr; Qnn_ContextHandle_t context_ = nullptr; + ProfilingLevel profiling_level_etw_; ProfilingLevel profiling_level_; + ProfilingLevel profiling_level_merge_; + const std::string profiling_file_path_; bool backend_initialized_ = false; bool device_created_ = false; bool context_created_ = false; diff --git a/onnxruntime/core/providers/qnn/qnn_execution_provider.cc b/onnxruntime/core/providers/qnn/qnn_execution_provider.cc index ef90b1f629..235ea45cd4 100644 --- a/onnxruntime/core/providers/qnn/qnn_execution_provider.cc +++ b/onnxruntime/core/providers/qnn/qnn_execution_provider.cc @@ -192,8 +192,12 @@ QNNExecutionProvider::QNNExecutionProvider(const ProviderOptions& provider_optio LOGS_DEFAULT(ERROR) << "No backend path provided."; } + std::string profiling_file_path; static const std::string PROFILING_LEVEL = "profiling_level"; qnn::ProfilingLevel profiling_level = qnn::ProfilingLevel::OFF; + // separate out the profiling level for ETW in case it gets disabled later when we extract the events + // set to invalid to indicate that ETW is no enabled when we setup QNN + qnn::ProfilingLevel profiling_level_etw = qnn::ProfilingLevel::INVALID; const Env& env = Env::Default(); auto& provider = env.GetTelemetryProvider(); if (provider.IsEnabled()) { @@ -203,23 +207,31 @@ QNNExecutionProvider::QNNExecutionProvider(const ProviderOptions& provider_optio if (level != 0) { if (level == 5) { LOGS_DEFAULT(INFO) << "Overriding profiling to basic based on ETW level: " << static_cast(level); - ParseProfilingLevel("basic", profiling_level); + profiling_level_etw = qnn::ProfilingLevel::BASIC; } else if (level < 5) { LOGS_DEFAULT(INFO) << "QNN Profiler ETW level not supported below level 5. Level: " << static_cast(level); + profiling_level_etw = qnn::ProfilingLevel::OFF; } else { LOGS_DEFAULT(INFO) << "Overriding profiling to detailed based on ETW level: " << static_cast(level); - ParseProfilingLevel("detailed", profiling_level); + profiling_level_etw = qnn::ProfilingLevel::DETAILED; } } } - } else { - auto profiling_level_pos = provider_options_map.find(PROFILING_LEVEL); - if (profiling_level_pos != provider_options_map.end()) { - ParseProfilingLevel(profiling_level_pos->second, profiling_level); - } } + // In case ETW gets disabled later + auto profiling_level_pos = provider_options_map.find(PROFILING_LEVEL); + if (profiling_level_pos != provider_options_map.end()) { + ParseProfilingLevel(profiling_level_pos->second, profiling_level); + } + static const std::string PROFILING_FILE = "profiling_file_path"; + auto profiling_file_pos = provider_options_map.find(PROFILING_FILE); + if (profiling_file_pos != provider_options_map.end()) { + profiling_file_path = profiling_file_pos->second; + } + LOGS_DEFAULT(VERBOSE) << "Profiling file path: " << profiling_file_path; + static const std::string RPC_CONTROL_LANTENCY = "rpc_control_latency"; auto latency_pos = provider_options_map.find(RPC_CONTROL_LANTENCY); if (latency_pos != provider_options_map.end()) { @@ -315,7 +327,9 @@ QNNExecutionProvider::QNNExecutionProvider(const ProviderOptions& provider_optio qnn_backend_manager_ = std::make_unique( std::move(backend_path), + profiling_level_etw, profiling_level, + std::move(profiling_file_path), context_priority, std::move(qnn_saver_path), device_id_, diff --git a/onnxruntime/test/onnx/main.cc b/onnxruntime/test/onnx/main.cc index 0d55fd19b9..c190577611 100644 --- a/onnxruntime/test/onnx/main.cc +++ b/onnxruntime/test/onnx/main.cc @@ -55,6 +55,7 @@ void usage() { "\t-i: Specify EP specific runtime options as key value pairs. Different runtime options available are: \n" "\t [QNN only] [backend_path]: QNN backend path. e.g '/folderpath/libQnnHtp.so', '/folderpath/libQnnCpu.so'.\n" "\t [QNN only] [profiling_level]: QNN profiling level, options: 'basic', 'detailed', default 'off'.\n" + "\t [QNN only] [profiling_file_path]: QNN profiling file path if ETW not enabled.\n" "\t [QNN only] [rpc_control_latency]: QNN rpc control latency. default to 10.\n" "\t [QNN only] [vtcm_mb]: QNN VTCM size in MB. default to 0(not set).\n" "\t [QNN only] [htp_performance_mode]: QNN performance mode, options: 'burst', 'balanced', 'default', 'high_performance', \n" @@ -479,9 +480,9 @@ int real_main(int argc, char* argv[], Ort::Env& env) { std::string key(token.substr(0, pos)); std::string value(token.substr(pos + 1)); - if (key == "backend_path") { + if (key == "backend_path" || key == "profiling_file_path") { if (value.empty()) { - ORT_THROW("Please provide the QNN backend path."); + ORT_THROW("Please provide the valid file path."); } } else if (key == "qnn_context_embed_mode") { if (value != "0") { @@ -541,7 +542,7 @@ int real_main(int argc, char* argv[], Ort::Env& env) { } } else { ORT_THROW(R"(Wrong key type entered. Choose from options: ['backend_path', -'profiling_level', 'rpc_control_latency', 'vtcm_mb', 'htp_performance_mode', +'profiling_level', 'profiling_file_path', 'rpc_control_latency', 'vtcm_mb', 'htp_performance_mode', 'qnn_saver_path', 'htp_graph_finalization_optimization_mode', 'qnn_context_priority', 'soc_model', 'htp_arch', 'device_id', 'enable_htp_fp16_precision'])"); } diff --git a/onnxruntime/test/perftest/command_args_parser.cc b/onnxruntime/test/perftest/command_args_parser.cc index 93e44fd8e8..b637ea1874 100644 --- a/onnxruntime/test/perftest/command_args_parser.cc +++ b/onnxruntime/test/perftest/command_args_parser.cc @@ -82,6 +82,7 @@ namespace perftest { "\n" "\t [QNN only] [backend_path]: QNN backend path. e.g '/folderpath/libQnnHtp.so', '/folderpath/libQnnCpu.so'.\n" "\t [QNN only] [profiling_level]: QNN profiling level, options: 'basic', 'detailed', default 'off'.\n" + "\t [profiling_file_path] : QNN profiling file path if ETW not enabled.\n" "\t [QNN only] [rpc_control_latency]: QNN rpc control latency. default to 10.\n" "\t [QNN only] [vtcm_mb]: QNN VTCM size in MB. default to 0(not set).\n" "\t [QNN only] [htp_performance_mode]: QNN performance mode, options: 'burst', 'balanced', 'default', 'high_performance', \n" diff --git a/onnxruntime/test/perftest/ort_test_session.cc b/onnxruntime/test/perftest/ort_test_session.cc index 9743ed18a6..b1dcf094a3 100644 --- a/onnxruntime/test/perftest/ort_test_session.cc +++ b/onnxruntime/test/perftest/ort_test_session.cc @@ -335,9 +335,9 @@ OnnxRuntimeTestSession::OnnxRuntimeTestSession(Ort::Env& env, std::random_device std::string key(token.substr(0, pos)); std::string value(token.substr(pos + 1)); - if (key == "backend_path") { + if (key == "backend_path" || key == "profiling_file_path") { if (value.empty()) { - ORT_THROW("Please provide the QNN backend path."); + ORT_THROW("Please provide the valid file path."); } } else if (key == "profiling_level") { std::set supported_profiling_level = {"off", "basic", "detailed"}; @@ -393,7 +393,7 @@ OnnxRuntimeTestSession::OnnxRuntimeTestSession(Ort::Env& env, std::random_device } } else { ORT_THROW(R"(Wrong key type entered. Choose from options: ['backend_path', -'profiling_level', 'rpc_control_latency', 'vtcm_mb', 'htp_performance_mode', +'profiling_level', 'profiling_file_path', 'rpc_control_latency', 'vtcm_mb', 'htp_performance_mode', 'qnn_saver_path', 'htp_graph_finalization_optimization_mode', 'qnn_context_priority', 'soc_model', 'htp_arch', 'device_id', 'enable_htp_fp16_precision'])"); }