diff --git a/.jenkins/check/config/filter_cpplint.txt b/.jenkins/check/config/filter_cpplint.txt index 1c341f3a188..e34492ab931 100644 --- a/.jenkins/check/config/filter_cpplint.txt +++ b/.jenkins/check/config/filter_cpplint.txt @@ -16,6 +16,7 @@ "mindspore/mindspore/ccsrc/plugin/device/cpu/kernel/nnacl/" "readability/casting" "mindspore/mindspore/ccsrc/plugin/device/gpu/hal/device/gpu_kernel_runtime.cc" "build/include_what_you_use" "mindspore/mindspore/ccsrc/utils/convert_utils_py.cc" "whitespace/indent" +"mindspore/mindspore/core/utils/log_adapter.cc" "runtime/references" # Modelzoo "mindspore/model_zoo/official/cv/yolov4_tiny/infer/mxbase/src/Yolov4TinyDetection.h" "runtime/references" diff --git a/mindspore/ccsrc/pipeline/jit/debug/trace.cc b/mindspore/ccsrc/pipeline/jit/debug/trace.cc index 6c8b9e79987..92e9378f00e 100644 --- a/mindspore/ccsrc/pipeline/jit/debug/trace.cc +++ b/mindspore/ccsrc/pipeline/jit/debug/trace.cc @@ -475,7 +475,22 @@ void ClearTraceStack() { cnode_debug_stack.clear(); } -void GetTraceStackInfo(std::ostringstream &oss) { +void PrintMessage(std::ostringstream &oss, const std::string &content, bool add_title) { + if (add_title) { + const std::string &message = oss.str(); + size_t length = message.length(); + if ((length != 0) && (message[length - 1] != '\n')) { + oss << "\n"; + } + + oss << "\n----------------------------------------------------\n" + << "- The Traceback of Net Construct Code:" + << "\n----------------------------------------------------"; + } + oss << content; +} + +void GetTraceStackInfo(std::ostringstream &oss, bool add_title) { TraceGraphEval(); std::ostringstream trace_info; GetEvalStackInfo(trace_info); @@ -484,11 +499,13 @@ void GetTraceStackInfo(std::ostringstream &oss) { if (debug_info != nullptr && TraceManager::record_debug_info_flag() == true) { auto debug_str = trace::GetDebugInfo(debug_info); if (!debug_str.empty()) { - oss << "\n\n# " << debug_str; + std::ostringstream content; + content << "\n\n# " << debug_str; + PrintMessage(oss, content.str(), add_title); } } } else { - oss << trace_info.str(); + PrintMessage(oss, trace_info.str(), add_title); } } diff --git a/mindspore/ccsrc/pipeline/jit/debug/trace.h b/mindspore/ccsrc/pipeline/jit/debug/trace.h index 2c80341a227..09a15865c28 100644 --- a/mindspore/ccsrc/pipeline/jit/debug/trace.h +++ b/mindspore/ccsrc/pipeline/jit/debug/trace.h @@ -46,7 +46,7 @@ void TraceEvalCNodeEnter(const abstract::AnfNodeConfigPtr &node_cfg); void TraceEvalCNodeLeave(); TraceCNodeEvalStack &GetCNodeDebugStack(); TraceGraphEvalStack &GetCurrentGraphEvalStack(); -void GetTraceStackInfo(std::ostringstream &oss); +void GetTraceStackInfo(std::ostringstream &oss, bool add_title = false); std::string GetAbstractStr(const abstract::AbstractBasePtr &abs); void ClearTraceStack(); } // namespace trace diff --git a/mindspore/core/utils/log_adapter.cc b/mindspore/core/utils/log_adapter.cc index c332d97a28f..7d4ce169589 100644 --- a/mindspore/core/utils/log_adapter.cc +++ b/mindspore/core/utils/log_adapter.cc @@ -34,6 +34,7 @@ // namespace to support utils module definition namespace mindspore { constexpr int kNameMaxLength = 18; +constexpr size_t kStep = 2; #if defined(__ANDROID__) || defined(ANDROID) constexpr const char *ANDROID_LOG_TAG = "MS_LITE"; #endif @@ -179,6 +180,137 @@ void LogWriter::set_trace_provider(const TraceProvider &trace_provider) { LogWriter::TraceProvider LogWriter::trace_provider() { return trace_provider_; } +static inline std::string GetEnv(const std::string &envvar) { + const char *value = std::getenv(envvar.c_str()); + + if (value == nullptr) { + return std::string(); + } + + return std::string(value); +} + +// When GLOG_logtostderr is set to 0, logs are output to a file, then will print duplicate message +// in exception log and stack. Otherwise when GLOG_logtostderr is set to 1, logs are output to the screen, +// then will only print message in exception stack. +void LogWriter::RemoveLabelBeforeOutputLog(const std::ostringstream &msg) const { + if (GetEnv("GLOG_logtostderr") == "0") { + std::string str = msg.str(); + auto replace = [&](const std::string &orgStr, const std::string &newStr) { + std::string::size_type pos; + while ((pos = str.find(orgStr)) != std::string::npos) { + str.replace(pos, orgStr.length(), newStr); + } + return str; + }; + // remove label "#dmsg#" and "#umsg#" + str = replace("#dmsg#", ""); + str = replace("#umsg#", ""); + std::ostringstream replaced_msg; + replaced_msg << str; + OutputLog(replaced_msg); + } +} + +// Function to split string based on character delimiter +void SplitString(const std::string &message, const std::string &delimiter, std::vector *output) { + size_t pos1, pos2; + pos1 = 0; + pos2 = message.find(delimiter); + MS_EXCEPTION_IF_NULL(output); + + while (pos2 != std::string::npos) { + (void)output->emplace_back(message.substr(pos1, pos2 - pos1)); + pos1 = pos2 + delimiter.size(); + pos2 = message.find(delimiter, pos1); + } + + if (pos1 != message.length()) { + (void)output->emplace_back(message.substr(pos1)); + } +} + +// Parse exception message format like: Error Description#dmsg#Developer Message Title#dmsg#Developer Message Content +// #umsg#User Message Title#umsg#User Message Content +void ParseExceptionMessage(const std::string &message, std::ostringstream &oss, std::vector *dmsg, + std::vector *umsg) { + std::vector vec; + SplitString(message, "#dmsg#", &vec); // first:split message by label #dmsg# + + if (!vec.empty() && (vec[0].find("#umsg#") == std::string::npos)) { + oss << vec[0]; + } + + MS_EXCEPTION_IF_NULL(dmsg); + MS_EXCEPTION_IF_NULL(umsg); + + for (size_t i = 0; i < vec.size(); i++) { + if (vec[i].find("#umsg#") != std::string::npos) { + std::vector temp; + SplitString(vec[i], "#umsg#", &temp); // second:split message by label #umsg# + if (!temp.empty()) { + if (i == 0) { + oss << temp[0]; + } else { + (void)dmsg->emplace_back(temp[0]); + } + (void)umsg->insert(umsg->end(), temp.begin() + 1, temp.end()); + } + } else { + if (i != 0) { + (void)dmsg->emplace_back(vec[i]); + } + } + } +} + +void PrintMessage(std::ostringstream &oss, const std::string &title, const std::string &content) { + const std::string &message = oss.str(); + size_t length = message.length(); + if ((length != 0) && (message[length - 1] != '\n')) { + oss << "\n"; + } + + oss << "\n----------------------------------------------------\n" + << title << "\n----------------------------------------------------\n" + << content; +} + +void DisplayDevExceptionMessage(std::ostringstream &oss, const std::vector &dmsg, + const LocationInfo &location) { + bool display = true; + if (GetEnv("MS_EXCEPTION_DISPLAY_LEVEL") == "1") { + display = false; + } + + if (display) { + const std::string CPP_CALL_STACK_TITLE = "- C++ Call Stack: (For framework developers)"; + std::ostringstream cpp_call_stack_content; + cpp_call_stack_content << location.file_ << ":" << location.line_ << " " << location.func_ << "\n"; + PrintMessage(oss, CPP_CALL_STACK_TITLE, cpp_call_stack_content.str()); + + size_t size = dmsg.size(); + if ((size != 0) && (size % kStep == 0)) { + for (size_t i = 0; i < size; i += kStep) { + std::ostringstream dmsg_title; + dmsg_title << "- " << dmsg[i] << " (For framework developers)"; + PrintMessage(oss, dmsg_title.str(), dmsg[i + 1]); + } + } + } +} + +void DisplayUserExceptionMessage(std::ostringstream &oss, const std::vector &umsg) { + size_t size = umsg.size(); + if ((size != 0) && (size % kStep == 0)) { + for (size_t i = 0; i < size; i += kStep) { + std::ostringstream umsg_title; + umsg_title << "- " << umsg[i]; + PrintMessage(oss, umsg_title.str(), umsg[i + 1]); + } + } +} + void LogWriter::OutputLog(const std::ostringstream &msg) const { #ifdef USE_GLOG #define google mindspore_private @@ -219,21 +351,26 @@ void LogWriter::operator^(const LogStream &stream) const { std::ostringstream msg; msg << stream.sstream_->rdbuf(); std::ostringstream oss; - oss << location_.file_ << ":" << location_.line_ << " " << location_.func_ << "] "; - oss << msg.str(); + std::vector dmsg; + std::vector umsg; + + ParseExceptionMessage(msg.str(), oss, &dmsg, &umsg); + DisplayUserExceptionMessage(oss, umsg); thread_local bool running = false; if (!running) { running = true; if (this_thread_max_log_level >= EXCEPTION) { - OutputLog(msg); + RemoveLabelBeforeOutputLog(msg); } if (trace_provider_ != nullptr) { - trace_provider_(oss); + trace_provider_(oss, true); } running = false; } + DisplayDevExceptionMessage(oss, dmsg, location_); + if (exception_handler_ != nullptr) { exception_handler_(exception_type_, oss.str()); } @@ -241,16 +378,6 @@ void LogWriter::operator^(const LogStream &stream) const { } #endif -static inline std::string GetEnv(const std::string &envvar) { - const char *value = std::getenv(envvar.c_str()); - - if (value == nullptr) { - return std::string(); - } - - return std::string(value); -} - enum class LogConfigToken : size_t { INVALID, // indicate invalid token LEFT_BRACE, // '{' diff --git a/mindspore/core/utils/log_adapter.h b/mindspore/core/utils/log_adapter.h index 1c5b479ac4b..fc76cf7a712 100644 --- a/mindspore/core/utils/log_adapter.h +++ b/mindspore/core/utils/log_adapter.h @@ -247,7 +247,7 @@ class TryCatchGuard { class MS_CORE_API LogWriter { public: using ExceptionHandler = void (*)(ExceptionType, const std::string &); - using TraceProvider = std::function; + using TraceProvider = std::function; LogWriter(const LocationInfo &location, MsLogLevel log_level, SubModuleId submodule, ExceptionType excp_type = NoExceptionType) @@ -272,6 +272,7 @@ class MS_CORE_API LogWriter { private: void OutputLog(const std::ostringstream &msg) const; + void RemoveLabelBeforeOutputLog(const std::ostringstream &msg) const; LocationInfo location_; MsLogLevel log_level_; diff --git a/tests/ut/cpp/utils/log_adapter_test.cc b/tests/ut/cpp/utils/log_adapter_test.cc new file mode 100644 index 00000000000..141dbea1aeb --- /dev/null +++ b/tests/ut/cpp/utils/log_adapter_test.cc @@ -0,0 +1,61 @@ +/** + * Copyright 2022 Huawei Technologies Co., Ltd + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ + +#include "common/common_test.h" +#include "utils/log_adapter.h" + +namespace { +constexpr char kMsExceptionDisplayLevel[] = "MS_EXCEPTION_DISPLAY_LEVEL"; +} // namespace + +namespace mindspore { +class TestLogAdapter : public UT::Common { + public: + TestLogAdapter() {} + + void TearDown() override { (void)unsetenv(kMsExceptionDisplayLevel); } +}; + +/// Feature: Error message structure optimization, hierarchical printing +/// Description: set MS_EXCEPTION_DISPLAY_LEVEL to 0 and run pass +/// Expectation: dmsg and umsg both display +TEST_F(TestLogAdapter, TestParseExceptionMessage1) { + (void)setenv(kMsExceptionDisplayLevel, "0", 1); + try { + MS_LOG(EXCEPTION) << "Exception Description#dmsg#The Dev Title1:#dmsg#The Dev Content1" + << "#umsg#The User Title1:#umsg#The User Content1"; + } catch (const std::exception &ex) { + const std::string &exception_str = ex.what(); + MS_LOG(INFO) << exception_str; + ASSERT_TRUE(exception_str.find("- C++ Call Stack: (For framework developers)") != std::string::npos); + } +} + +/// Feature: Error message structure optimization, hierarchical printing +/// Description: set MS_EXCEPTION_DISPLAY_LEVEL to 1 and run pass +/// Expectation: only umsg displays +TEST_F(TestLogAdapter, TestParseExceptionMessage2) { + (void)setenv(kMsExceptionDisplayLevel, "1", 1); + try { + MS_EXCEPTION(TypeError) << "Exception Description#dmsg#The Dev Title1:#dmsg#The Dev Content1" + << "#umsg#The User Title1:#umsg#The User Content1"; + } catch (const std::exception &ex) { + const std::string &exception_str = ex.what(); + MS_LOG(INFO) << exception_str; + ASSERT_TRUE(exception_str.find("The Dev Content1") == std::string::npos); + } +} +} // namespace mindspore