From 45dd1db08117592dc25b2f080a0ba1a382007eab Mon Sep 17 00:00:00 2001 From: "liyihan2@huawei.com" Date: Tue, 27 Apr 2021 22:24:06 +0800 Subject: [PATCH 01/11] common log optimize --- ge/common/kernel_store.cc | 4 + ge/common/model_parser/model_parser.cc | 18 ++- ge/common/model_saver.cc | 15 +- ge/common/op/ge_op_utils.cc | 25 ++- ge/common/profiling/ge_profiling.cc | 46 ++++-- ge/common/profiling/profiling_manager.cc | 185 ++++++++++++++++------- ge/common/properties_manager.cc | 13 +- ge/common/util.cc | 67 +++++--- 8 files changed, 264 insertions(+), 109 deletions(-) diff --git a/ge/common/kernel_store.cc b/ge/common/kernel_store.cc index d746fd10..38440d70 100755 --- a/ge/common/kernel_store.cc +++ b/ge/common/kernel_store.cc @@ -38,6 +38,10 @@ bool KernelStore::Build() { buffer_.resize(total_len); } catch (std::bad_alloc &e) { GELOGE(ge::MEMALLOC_FAILED, "All build memory failed, memory size %zu", total_len); + GELOGE(ge::MEMALLOC_FAILED, "[Malloc][Memmory]Resize buffer failed, memory size %zu, " + "exception %s", total_len, e.what()); + REPORT_CALL_ERROR("E19999", "Resize buffer failed, memory size %zu, exception %s", + total_len, e.what()); return false; } diff --git a/ge/common/model_parser/model_parser.cc b/ge/common/model_parser/model_parser.cc index 9c00ab08..0d320938 100644 --- a/ge/common/model_parser/model_parser.cc +++ b/ge/common/model_parser/model_parser.cc @@ -32,17 +32,24 @@ FMK_FUNC_HOST_VISIBILITY FMK_FUNC_DEV_VISIBILITY Status ModelParserBase::LoadFro std::string real_path = RealPath(model_path); if (real_path.empty()) { GELOGE(ACL_ERROR_GE_EXEC_MODEL_PATH_INVALID, "Model file path '%s' is invalid", model_path); + GELOGE(ACL_ERROR_GE_EXEC_MODEL_PATH_INVALID, "[Check][Param]Model file path %s is invalid", + model_path); + REPORT_INNER_ERROR("E19999", "Model file path %s is invalid", model_path); return ACL_ERROR_GE_EXEC_MODEL_PATH_INVALID; } if (GetFileLength(model_path) == -1) { - GELOGE(ACL_ERROR_GE_EXEC_MODEL_PATH_INVALID, "File size not valid, file: %s.", model_path); + GELOGE(ACL_ERROR_GE_EXEC_MODEL_PATH_INVALID, "[Check][Param]File size not valid, file %s", + model_path); + REPORT_INNER_ERROR("E19999", "File size not valid, file %s", model_path); return ACL_ERROR_GE_EXEC_MODEL_PATH_INVALID; } std::ifstream fs(real_path.c_str(), std::ifstream::binary); if (!fs.is_open()) { - GELOGE(ACL_ERROR_GE_EXEC_MODEL_PATH_INVALID, "Open file: %s failed, error: %s", model_path, strerror(errno)); + GELOGE(ACL_ERROR_GE_EXEC_MODEL_PATH_INVALID, "[Open][File]Failed, file %s, error %s", + model_path, strerror(errno)); + REPORT_CALL_ERROR("E19999", "Open file %s failed, error %s", model_path, strerror(errno)); return ACL_ERROR_GE_EXEC_MODEL_PATH_INVALID; } @@ -57,6 +64,10 @@ FMK_FUNC_HOST_VISIBILITY FMK_FUNC_DEV_VISIBILITY Status ModelParserBase::LoadFro char *data = new (std::nothrow) char[len]; if (data == nullptr) { GELOGE(ACL_ERROR_GE_MEMORY_ALLOCATION, "Load model From file failed, bad memory allocation occur. (need:%u)", len); + GELOGE(ACL_ERROR_GE_MEMORY_ALLOCATION, "[Load][ModelFromFile]Failed, " + "bad memory allocation occur(need %u), file %s", len, model_path); + REPORT_CALL_ERROR("E19999", "Load model from file %s failed, " + "bad memory allocation occur(need %u)", model_path, len); return ACL_ERROR_GE_MEMORY_ALLOCATION; } @@ -105,7 +116,8 @@ FMK_FUNC_HOST_VISIBILITY FMK_FUNC_DEV_VISIBILITY Status ModelParserBase::ParseMo model_len = file_header->length; GELOGD("Model_len is %u, model_file_head_len is %zu.", model_len, sizeof(ModelFileHeader)); } else { - GELOGE(ACL_ERROR_GE_PARAM_INVALID, "Invalid model. ModelEncryptType not supported."); + GELOGE(ACL_ERROR_GE_PARAM_INVALID, "[Check][Param]Invalid, model encrypt type not supported"); + REPORT_CALL_ERROR("E19999","Invalid model ,encrypt type not supported"); res = ACL_ERROR_GE_PARAM_INVALID; } diff --git a/ge/common/model_saver.cc b/ge/common/model_saver.cc index 49382e7f..01b3fd66 100755 --- a/ge/common/model_saver.cc +++ b/ge/common/model_saver.cc @@ -33,7 +33,8 @@ FMK_FUNC_HOST_VISIBILITY FMK_FUNC_DEV_VISIBILITY Status ModelSaver::SaveJsonToFi const Json &model) { Status ret = SUCCESS; if (file_path == nullptr || SUCCESS != CheckPath(file_path)) { - GELOGE(FAILED, "Check output file failed."); + GELOGE(FAILED, "[Check][OutputFile]Failed, file %s", file_path); + REPORT_CALL_ERROR("E19999", "Output file %s check invalid", file_path); return FAILED; } std::string model_str; @@ -41,11 +42,12 @@ FMK_FUNC_HOST_VISIBILITY FMK_FUNC_DEV_VISIBILITY Status ModelSaver::SaveJsonToFi model_str = model.dump(kInteval, ' ', false, Json::error_handler_t::ignore); } catch (std::exception &e) { ErrorManager::GetInstance().ATCReportErrMessage("E19007", {"exception"}, {e.what()}); - GELOGE(FAILED, "Failed to convert JSON to string, reason: %s.", e.what()); + GELOGE(FAILED, "[Convert][File]Failed to convert JSON to string, file %s, reason %s", + file_path, e.what()); return FAILED; } catch (...) { ErrorManager::GetInstance().ATCReportErrMessage("E19008"); - GELOGE(FAILED, "Failed to convert JSON to string."); + GELOGE(FAILED, "[Convert][File]Failed to convert JSON to string, file %s", file_path); return FAILED; } @@ -59,7 +61,7 @@ FMK_FUNC_HOST_VISIBILITY FMK_FUNC_DEV_VISIBILITY Status ModelSaver::SaveJsonToFi int32_t fd = mmOpen2(real_path, M_RDWR | M_CREAT | O_TRUNC, mode); if (fd == EN_ERROR || fd == EN_INVALID_PARAM) { ErrorManager::GetInstance().ATCReportErrMessage("E19001", {"file", "errmsg"}, {file_path, strerror(errno)}); - GELOGE(FAILED, "Open file[%s] failed. errmsg:%s", file_path, strerror(errno)); + GELOGE(FAILED, "[Open][File]Failed, file %s, errmsg %s", file_path, strerror(errno)); return FAILED; } const char *model_char = model_str.c_str(); @@ -70,12 +72,13 @@ FMK_FUNC_HOST_VISIBILITY FMK_FUNC_DEV_VISIBILITY Status ModelSaver::SaveJsonToFi ErrorManager::GetInstance().ATCReportErrMessage( "E19004", {"file", "errmsg"}, {file_path, strerror(errno)}); // Need to both print the error info of mmWrite and mmClose, so return ret after mmClose - GELOGE(FAILED, "Write to file failed. errno:%ld, errmsg:%s", mmpa_ret, strerror(errno)); + GELOGE(FAILED, "[Write][Data]To file %s failed. errno %ld, errmsg %s", file_path, mmpa_ret, strerror(errno)); ret = FAILED; } // Close file if (mmClose(fd) != EN_OK) { - GELOGE(FAILED, "Close file failed. errmsg:%s", strerror(errno)); + GELOGE(FAILED, "[Close][File]Failed, file %s, errmsg %s", file_path, strerror(errno)); + REPORT_CALL_ERROR("E19999", "Close file %s failed, errmsg %s", file_path, strerror(errno)); ret = FAILED; } return ret; diff --git a/ge/common/op/ge_op_utils.cc b/ge/common/op/ge_op_utils.cc index fc2990b6..0303bcdf 100644 --- a/ge/common/op/ge_op_utils.cc +++ b/ge/common/op/ge_op_utils.cc @@ -239,7 +239,8 @@ Status OpUtils::SetDataByDataType(size_t out_size, const std::vector &ch const std::vector &chunk_output, GeTensor *output) { unique_ptr output_data(new (std::nothrow) T[out_size]()); if (output_data == nullptr) { - GELOGE(MEMALLOC_FAILED, "New buf failed"); + GELOGE(MEMALLOC_FAILED, "[Malloc][Data]New buf failed"); + REPORT_CALL_ERROR("E19999", "New buf failed"); return INTERNAL_ERROR; } @@ -275,7 +276,10 @@ Status OpUtils::SetOutputSliceDataByDataType(void *data, int64_t data_size, cons int64_t dim_i = input_dims[i]; int64_t stride_i = stride[i]; if (dim_i == 0) { - GELOGE(PARAM_INVALID, "Dim_i of size tensor can't be 0."); + GELOGE(PARAM_INVALID, "[Check][Param]Invalid, Dim_i %s of size tensor is 0", + ShapeToString(input_dims[i]).c_str()); + REPORT_INNER_ERROR("E19999", "Dim_i %s of size tensor is 0, invalid", + ShapeToString(input_dims[i]).c_str()); return PARAM_INVALID; } chunk_size = chunk_size / dim_i; @@ -299,7 +303,8 @@ FMK_FUNC_HOST_VISIBILITY FMK_FUNC_DEV_VISIBILITY Status OpUtils::SetOutputSliceD void *data, int64_t data_size, int32_t data_type, std::vector &input_dims, std::vector &begin, std::vector &output_dims, GeTensor *output, std::vector &stride) { if (data == nullptr || output == nullptr) { - GELOGE(PARAM_INVALID, "Input param is nullptr."); + GELOGE(PARAM_INVALID, "[Check][Param]Input param is nullptr"); + REPORT_INNER_ERROR("E19999", "Input param is nullptr"); return PARAM_INVALID; } @@ -436,14 +441,18 @@ FMK_FUNC_HOST_VISIBILITY FMK_FUNC_DEV_VISIBILITY Status OpUtils::SetWeights(ge:: FMK_FUNC_HOST_VISIBILITY FMK_FUNC_DEV_VISIBILITY Status OpUtils::GetShapeDataFromConstTensor(const ConstGeTensorPtr &tensor, DataType type, std::vector &dims) { if (tensor == nullptr) { - GELOGE(PARAM_INVALID, "Input tensor is nullptr"); + GELOGE(PARAM_INVALID, "[Check][Param]Input tensor is nullptr"); + REPORT_INNER_ERROR("E19999","Input tensor is nullptr"); return PARAM_INVALID; } // If the tensor data is a vector, the shape dimension must be 1 if (tensor->GetTensorDesc().GetShape().GetDims().size() > 1) { - GELOGE(PARAM_INVALID, "The dimension of the input tensor shape cannot be more than 1, it is %zu", + GELOGE(PARAM_INVALID, "[Check][Param]The dimension of the input tensor shape " + "cannot be more than 1, it is %zu", tensor->GetTensorDesc().GetShape().GetDims().size()); + REPORT_CALL_ERROR("E19999", "The dimension of the input tensor shape %zu invalid, " + "more than 1", tensor->GetTensorDesc().GetShape().GetDims().size()); return PARAM_INVALID; } @@ -462,8 +471,10 @@ OpUtils::GetShapeDataFromConstTensor(const ConstGeTensorPtr &tensor, DataType ty dims.push_back(shape_data[i]); } } else { - GELOGE(PARAM_INVALID, "Data type only can be DT_INT32 or DT_INT64. type is %s", - TypeUtils::DataTypeToSerialString(type).c_str()); + GELOGE(PARAM_INVALID, "[Check][DataType]Invalid, type only can be DT_INT32 or DT_INT64, " + "type is %s", TypeUtils::DataTypeToSerialString(type).c_str()); + REPORT_INNER_ERROR("E19999", "Data type %s check invalid, only can be DT_INT32 or DT_INT64", + TypeUtils::DataTypeToSerialString(type).c_str()); return PARAM_INVALID; } diff --git a/ge/common/profiling/ge_profiling.cc b/ge/common/profiling/ge_profiling.cc index 08fdc0ae..3f885a91 100644 --- a/ge/common/profiling/ge_profiling.cc +++ b/ge/common/profiling/ge_profiling.cc @@ -67,11 +67,13 @@ bool TransProfConfigToParam(const ProfCommandHandleData &profCommand, vector MAX_DEV_NUM) { - GELOGE(ge::PARAM_INVALID, "The device nums: %u is invalid.", device_nums); + GELOGE(ge::PARAM_INVALID, "[Check][DeviceNums]Invalid, device nums: %u", device_nums); + REPORT_INNER_ERROR("E19999", "DeviceNums %u check invalid", device_nums); return false; } @@ -79,12 +81,16 @@ bool isProfConfigValid(const uint32_t *deviceid_list, uint32_t device_nums) { int32_t dev_count = 0; rtError_t rt_err = rtGetDeviceCount(&dev_count); if (rt_err != RT_ERROR_NONE) { - GELOGE(ge::INTERNAL_ERROR, "Get the Device count fail."); + GELOGE(ge::INTERNAL_ERROR, "[Get][DeviceCount]Failed, error_code %d", rt_err); + REPORT_CALL_ERROR("E19999", "Get device count failed, error_code %d", rt_err); return false; } if (device_nums > static_cast(dev_count)) { - GELOGE(ge::PARAM_INVALID, "Device num(%u) is not in range 1 ~ %d.", device_nums, dev_count); + GELOGE(ge::PARAM_INVALID, "[Check][Param]Device num %u is not in range [1,%d]", + device_nums, dev_count); + REPORT_INNER_ERROR("E19999", "Device num %u check invalid, it is not in range [1,%d]", + device_nums, dev_count); return false; } @@ -92,11 +98,14 @@ bool isProfConfigValid(const uint32_t *deviceid_list, uint32_t device_nums) { for (size_t i = 0; i < device_nums; ++i) { uint32_t dev_id = deviceid_list[i]; if (dev_id >= static_cast(dev_count)) { - GELOGE(ge::PARAM_INVALID, "Device id %u is not in range 0 ~ %d(exclude %d)", dev_id, dev_count, dev_count); + GELOGE(ge::PARAM_INVALID, "[Check][DeviceId]Device id %u is not in range [0,%d)", + dev_id, dev_count); + REPORT_CALL_ERROR("E19999", "Device id %u is not in range [0,%d)", dev_id, dev_count); return false; } if (record.count(dev_id) > 0) { - GELOGE(ge::PARAM_INVALID, "Device id %u is duplicatedly set", dev_id); + GELOGE(ge::PARAM_INVALID, "[Check][DeviceId]Device id %u is duplicatedly set", dev_id); + REPORT_CALL_ERROR("E19999", "Device id %u is not unique, duplicatedly set", dev_id); return false; } record.insert(dev_id); @@ -106,7 +115,8 @@ bool isProfConfigValid(const uint32_t *deviceid_list, uint32_t device_nums) { ge::Status RegProfCtrlCallback(MsprofCtrlCallback func) { if (func == nullptr) { - GELOGE(ge::PARAM_INVALID, "Msprof ctrl callback is nullptr."); + GELOGE(ge::PARAM_INVALID, "[Check][Param]Msprof ctrl callback is nullptr"); + REPORT_INNER_ERROR("E19999", "Msprof ctrl callback is nullptr"); return ge::PARAM_INVALID; } if (ge::ProfilingManager::Instance().GetMsprofCallback().msprofCtrlCallback != nullptr) { @@ -119,13 +129,15 @@ ge::Status RegProfCtrlCallback(MsprofCtrlCallback func) { ge::Status RegProfSetDeviceCallback(MsprofSetDeviceCallback func) { if (func == nullptr) { - GELOGE(ge::PARAM_INVALID, "MsprofSetDeviceCallback callback is nullptr."); + GELOGE(ge::PARAM_INVALID, "[Check][Param]MsprofSetDeviceCallback callback is nullptr"); + REPORT_INNER_ERROR("E19999", "MsprofSetDeviceCallback callback is nullptr"); return ge::PARAM_INVALID; } // Pass MsprofSetDeviceCallback to runtime ge::Status rt_ret = rtRegDeviceStateCallback(kRtSetDeviceRegName.c_str(), static_cast(func)); if (rt_ret != ge::SUCCESS) { - GELOGE(rt_ret, "Pass MsprofSetDeviceCallback to runtime failed!"); + GELOGE(rt_ret, "[Pass][MsprofSetDeviceCallback]To runtime failed!"); + REPORT_CALL_ERROR("E19999", "Pass MsprofSetDeviceCallback to runtime failed, ret 0x%X", rt_ret); return rt_ret; } return ge::SUCCESS; @@ -133,7 +145,8 @@ ge::Status RegProfSetDeviceCallback(MsprofSetDeviceCallback func) { ge::Status RegProfReporterCallback(MsprofReporterCallback func) { if (func == nullptr) { - GELOGE(ge::PARAM_INVALID, "MsprofReporterCallback callback is nullptr."); + GELOGE(ge::PARAM_INVALID, "[Check][Param]MsprofReporterCallback callback is nullptr"); + REPORT_INNER_ERROR("E19999", "MsprofReporterCallback callback is nullptr"); return ge::PARAM_INVALID; } if (ge::ProfilingManager::Instance().GetMsprofCallback().msprofReporterCallback != nullptr) { @@ -144,7 +157,10 @@ ge::Status RegProfReporterCallback(MsprofReporterCallback func) { // Pass MsprofReporterCallback to runtime ge::Status rt_ret = rtSetMsprofReporterCallback(func); if (rt_ret != ge::SUCCESS) { - GELOGE(rt_ret, "Pass MsprofReporterCallback to runtime failed!!"); + GELOGE(rt_ret, "[Pass][Param]Pass MsprofReporterCallback to runtime failed, error_code %u", + rt_ret); + REPORT_CALL_ERROR("E19999", "Pass MsprofReporterCallback to runtime failed, error_code %u", + rt_ret); return rt_ret; } // Pass MsprofReporterCallback to hccl @@ -169,7 +185,8 @@ ge::Status ProfCommandHandle(ProfCommandHandleType type, void *data, uint32_t le } if (!TransProfConfigToParam(*prof_config_param, prof_params)) { - GELOGE(ge::PARAM_INVALID, "Transfer profilerConfig to string vector failed"); + GELOGE(ge::PARAM_INVALID, "[Check][Param]Transfer profilerConfig to string vector failed"); + REPORT_CALL_ERROR("E19999", "Transfer profilerConfig to string vector failed"); return ge::PARAM_INVALID; } } @@ -188,7 +205,10 @@ ge::Status ProfCommandHandle(ProfCommandHandleType type, void *data, uint32_t le } ge::Status ret = graph_loader.CommandHandle(command); if (ret != ge::SUCCESS) { - GELOGE(ret, "Handle profiling command failed"); + GELOGE(ret, "[Handle][Command]Handle profiling command failed, command type %s, error_code %u", + iter->second.c_str(), ret); + REPORT_CALL_ERROR("E19999", "Handle profiling command failed, command type %s, error_code %u", + iter->second.c_str(), ret); return ge::FAILED; } diff --git a/ge/common/profiling/profiling_manager.cc b/ge/common/profiling/profiling_manager.cc index 443f5213..f5419170 100644 --- a/ge/common/profiling/profiling_manager.cc +++ b/ge/common/profiling/profiling_manager.cc @@ -87,21 +87,26 @@ FMK_FUNC_HOST_VISIBILITY FMK_FUNC_DEV_VISIBILITY ge::Status ProfilingManager::In struct MsprofGeOptions prof_conf = {{ 0 }}; Status ret = InitFromOptions(options, prof_conf); if (ret != SUCCESS) { - GELOGE(ret, "Failed to init profiling."); + GELOGE(ret, "[Init][Profiling]Failed, error_code %u", ret); + REPORT_CALL_ERROR("E19999", "Init profiling failed, error_code %u", ret); return ret; } if (is_execute_profiling_) { if (prof_cb_.msprofCtrlCallback == nullptr) { - GELOGE(ge::PARAM_INVALID, "MsprofCtrlCallback callback is nullptr."); + GELOGE(ge::PARAM_INVALID, "[Check][Param]MsprofCtrlCallback callback is nullptr"); + REPORT_INNER_ERROR("E19999", "MsprofCtrlCallback callback is nullptr"); return ge::PARAM_INVALID; } int32_t cb_ret = prof_cb_.msprofCtrlCallback( static_cast(MsprofCtrlCallbackType::MSPROF_CTRL_INIT_GE_OPTIONS), static_cast(&prof_conf), sizeof(MsprofGeOptions)); if (cb_ret != 0) { - GELOGE(FAILED, "Call msprofCtrlCallback failed, type:%u, return:%d", + GELOGE(FAILED, "[Call][msprofCtrlCallback]Failed, type %u, return %d", static_cast(MsprofCtrlCallbackType::MSPROF_CTRL_INIT_GE_OPTIONS), cb_ret); + REPORT_CALL_ERROR("E19999", "Call msprofCtrlCallback failed, type %u, return %d", + static_cast(MsprofCtrlCallbackType::MSPROF_CTRL_INIT_GE_OPTIONS), + cb_ret); return FAILED; } GELOGI("Profiling init success"); @@ -122,7 +127,10 @@ ge::Status ProfilingManager::InitFromOptions(const Options &options, MsprofGeOpt // enable profiling by ge option if (strncpy_s(prof_conf.options, MSPROF_OPTIONS_DEF_LEN_MAX, options.profiling_options.c_str(), MSPROF_OPTIONS_DEF_LEN_MAX - 1) != EOK) { - GELOGE(INTERNAL_ERROR, "copy profiling_options failed."); + GELOGE(INTERNAL_ERROR, "[copy][ProfilingOptions]Failed, options %s", + options.profiling_options.c_str()); + REPORT_CALL_ERROR("E19999", "Copy profiling_options %s failed", + options.profiling_options.c_str()); return INTERNAL_ERROR; } is_execute_profiling_ = true; @@ -147,13 +155,17 @@ ge::Status ProfilingManager::InitFromOptions(const Options &options, MsprofGeOpt // Parse json str for bp fp Status ret = ParseOptions(prof_conf.options); if (ret != ge::SUCCESS) { - GELOGE(ge::PARAM_INVALID, "Parse training trace param failed."); + GELOGE(ge::PARAM_INVALID, "[Parse][Options]Parse training trace param %s failed, error_code %u", + prof_conf.options, ret); + REPORT_CALL_ERROR("E19999", "Parse training trace param %s failed, error_code %u", + prof_conf.options, ret); return ge::PARAM_INVALID; } if (strncpy_s(prof_conf.jobId, MSPROF_OPTIONS_DEF_LEN_MAX, options.job_id.c_str(), MSPROF_OPTIONS_DEF_LEN_MAX - 1) != EOK) { - GELOGE(INTERNAL_ERROR, "copy job_id failed."); + GELOGE(INTERNAL_ERROR, "[Copy][JobId]Failed, original job_id %s", options.job_id.c_str()); + REPORT_CALL_ERROR("E19999", "Copy job_id %s failed", options.job_id.c_str()); return INTERNAL_ERROR; } GELOGI("Job id: %s, original job id: %s.", prof_conf.jobId, options.job_id.c_str()); @@ -163,7 +175,8 @@ ge::Status ProfilingManager::InitFromOptions(const Options &options, MsprofGeOpt ge::Status ProfilingManager::ParseOptions(const std::string &options) { if (options.empty()) { - GELOGE(ge::PARAM_INVALID, "Profiling options is empty."); + GELOGE(ge::PARAM_INVALID, "[Check][Param]Profiling options is empty"); + REPORT_INNER_ERROR("E19999", "Profiling options is empty"); return ge::PARAM_INVALID; } try { @@ -178,7 +191,9 @@ ge::Status ProfilingManager::ParseOptions(const std::string &options) { } GELOGI("GE profiling training trace:%s", training_trace.c_str()); if (training_trace != "on") { - GELOGE(ge::PARAM_INVALID, "Training trace param:%s is invalid.", training_trace.c_str()); + GELOGE(ge::PARAM_INVALID, "[Check][Param]Training trace param:%s is invalid.", + training_trace.c_str()); + REPORT_INNER_ERROR("E19999", "Training trace param:%s is invalid.", training_trace.c_str()); return ge::PARAM_INVALID; } fp_point_ = prof_options[kFpPoint]; @@ -188,7 +203,8 @@ ge::Status ProfilingManager::ParseOptions(const std::string &options) { } is_training_trace_ = true; } catch (...) { - GELOGE(FAILED, "Json prof_conf options is invalid."); + GELOGE(FAILED, "[Check][Param]Json prof_conf options is invalid"); + REPORT_INNER_ERROR("E19999", "Json prof_conf options is invalid"); return ge::PARAM_INVALID; } return ge::SUCCESS; @@ -202,7 +218,8 @@ FMK_FUNC_HOST_VISIBILITY FMK_FUNC_DEV_VISIBILITY void ProfilingManager::StopProf if (device_num != 0) { auto device_id_ptr = std::unique_ptr(new (std::nothrow) uint32_t[device_num]); if (device_id_ptr == nullptr) { - GELOGE(FAILED, "Stop profiling: device id ptr is null."); + GELOGE(FAILED, "[Stop][Profiling]Device id ptr is null."); + REPORT_INNER_ERROR("E19999", "Stop profiling, device id ptr is null"); return; } for (int32_t i = 0; i < device_num; i++) { @@ -216,7 +233,8 @@ FMK_FUNC_HOST_VISIBILITY FMK_FUNC_DEV_VISIBILITY void ProfilingManager::StopProf // stop profiling if (prof_cb_.msprofCtrlCallback == nullptr) { - GELOGE(ge::PARAM_INVALID, "MsprofCtrlCallback callback is nullptr."); + GELOGE(ge::PARAM_INVALID, "[Check][Param]MsprofCtrlCallback callback is nullptr"); + REPORT_INNER_ERROR("E19999", "MsprofCtrlCallback callback is nullptr"); return; } int32_t cb_ret = prof_cb_.msprofCtrlCallback(static_cast(MsprofCtrlCallbackType::MSPROF_CTRL_FINALIZE), @@ -278,10 +296,14 @@ FMK_FUNC_HOST_VISIBILITY FMK_FUNC_DEV_VISIBILITY void ProfilingManager::Profilin try { reported_data = task_info.dump(kInteval, ' ', false, Json::error_handler_t::ignore); } catch (std::exception &e) { - GELOGE(FAILED, "Failed to convert JSON to string, reason: %s.", e.what()); + GELOGE(FAILED, "[Convert][ReportData]Failed to convert json to string, reason %s.", + e.what()); + REPORT_CALL_ERROR("E19999", "Failed to convert reported_data from json to string, reason %s", + e.what()); return ; } catch (...) { - GELOGE(FAILED, "Failed to convert JSON to string."); + GELOGE(FAILED, "[Convert][ReportedData]Failed to convert JSON to string"); + REPORT_CALL_ERROR("E19999", "Failed to convert reported data from json to string"); return; } reported_data.append(",") @@ -300,7 +322,8 @@ FMK_FUNC_HOST_VISIBILITY FMK_FUNC_DEV_VISIBILITY Status ProfilingManager::Profil index_id, model_id, tag_id); rt_ret = rtProfilerTraceEx(index_id, model_id, tag_id, stream); if (rt_ret != RT_ERROR_NONE) { - GELOGE(RT_FAILED, "[Call][rtProfilerTraceEx] failed, ret: 0x%X", rt_ret); + GELOGE(RT_FAILED, "[Call][rtProfilerTraceEx]Failed, ret 0x%X", rt_ret); + REPORT_CALL_ERROR("E19999", "Call rtProfilerTraceEx failed, ret 0x%X", rt_ret); return RT_ERROR_TO_GE_STATUS(rt_ret); } GELOGD("Profiling Step Info TraceTask execute async success, index_id = %lu, model_id = %lu, tag_id = %u", @@ -314,7 +337,8 @@ FMK_FUNC_HOST_VISIBILITY FMK_FUNC_DEV_VISIBILITY Status ProfilingManager::Profil uint32_t stream_id = 0; rt_ret = rtGetTaskIdAndStreamID(&task_id, &stream_id); if (rt_ret != RT_ERROR_NONE) { - GELOGE(RT_FAILED, "[Get][RtsInfo] task_id and stream_id failed, ret: 0x%X.", rt_ret); + GELOGE(RT_FAILED, "[Get][RtsInfo]Task_id and stream_id failed, ret 0x%X", rt_ret); + REPORT_CALL_ERROR("E19999", "Get task_id and stream_id failed, ret 0x%X", rt_ret); return RT_ERROR_TO_GE_STATUS(rt_ret); } GELOGD("Get profiling args, task_id[%u], stream_id[%u]", task_id, stream_id); @@ -333,8 +357,13 @@ FMK_FUNC_HOST_VISIBILITY FMK_FUNC_DEV_VISIBILITY Status ProfilingManager::Profil reported_data = step_info.dump(kInteval, ' ', false, Json::error_handler_t::ignore); } catch (std::exception &e) { GELOGE(FAILED, "Failed to convert JSON to string, reason: %s.", e.what()); + GELOGE(FAILED, "[Convert][ReportedData]Failed to convert from json to string, reason: %s", + e.what()); + REPORT_CALL_ERROR("E19999", "Failed to convert reported data from json to string, reason: %s", + e.what()); } catch (...) { - GELOGE(FAILED, "Failed to convert JSON to string."); + GELOGE(FAILED, "[Convert][ReportedData]Failed to convert from json to string"); + REPORT_CALL_ERROR("E19999", "Failed to convert reported data from json to string"); } reported_data.append(",") .append("\n"); @@ -390,7 +419,8 @@ FMK_FUNC_HOST_VISIBILITY FMK_FUNC_DEV_VISIBILITY void ProfilingManager::ReportPr int32_t logic_device_id = 0; rtError_t rt_ret = rtGetDevice(&logic_device_id); if (rt_ret != RT_ERROR_NONE) { - GELOGE(rt_ret, "runtime get logic_device_id failed, current logic_device_id:%d", logic_device_id); + GELOGE(rt_ret, "[Get][LogicDeviceId]Failed, ret 0x%X", rt_ret); + REPORT_CALL_ERROR("E19999", "Get logic device id failed, ret 0x%X", rt_ret); return; } GELOGD("current logic_device_id:%d", logic_device_id); @@ -452,7 +482,8 @@ FMK_FUNC_HOST_VISIBILITY FMK_FUNC_DEV_VISIBILITY Status ProfilingManager::ProfMo // register Framework to profiling int32_t cb_ret = PluginInit(); if (cb_ret != 0) { - GELOGE(cb_ret, "profiling plugin init failed, ret:%d", cb_ret); + GELOGE(cb_ret, "[Init][ProfilingPlugin]Failed, ret %d", cb_ret); + REPORT_CALL_ERROR("E19999", "Init profiling plugin failed, ret %d", cb_ret); return cb_ret; } GELOGI("Prof subscribe: model load profiling on."); @@ -465,7 +496,8 @@ FMK_FUNC_HOST_VISIBILITY FMK_FUNC_DEV_VISIBILITY Status ProfilingManager::ProfMo device[0] = davinci_model->GetDeviceId(); rtError_t rt_ret = rtProfilerStart(module, device_num, device); if (rt_ret != RT_ERROR_NONE) { - GELOGE(FAILED, "Runtime profiler start failed."); + GELOGE(FAILED, "[Start][Profiler]Malloc buffer failed, ret 0x%X", rt_ret); + REPORT_CALL_ERROR("E19999", "Malloc buffer failed when start profiling, ret 0x%X", rt_ret); return FAILED; } UpdateSubscribeDeviceModuleMap(kProfModelSubscribe, device[0], module); @@ -473,7 +505,8 @@ FMK_FUNC_HOST_VISIBILITY FMK_FUNC_DEV_VISIBILITY Status ProfilingManager::ProfMo // Report profiling data Status p_ret = davinci_model->ReportProfilingData(); if (p_ret != SUCCESS) { - GELOGE(p_ret, "Report profiling data failed."); + GELOGE(p_ret, "[Report][ProfilingData]Failed, ret %u", p_ret); + REPORT_CALL_ERROR("E19999", "Report profiling data failed, ret %u", p_ret); return p_ret; } #endif @@ -499,13 +532,17 @@ FMK_FUNC_HOST_VISIBILITY FMK_FUNC_DEV_VISIBILITY Status ProfilingManager::ProfMo // The same device_id, only stop at last time rtError_t rt_ret = rtProfilerStop(subs_dev_module_[device[0]].module, dev_num, device); if (rt_ret != RT_ERROR_NONE) { - GELOGE(FAILED, "Runtime profiler stop failed."); + GELOGE(FAILED, "[Stop][Profiler]Malloc buffer Failed, ret %d", rt_ret); + REPORT_CALL_ERROR("E19999", "Malloc buffer failed when stop profiling, ret %d", rt_ret); return FAILED; } } UpdateSubscribeDeviceModuleMap(kProfModelUnsubscribe, device[0], subs_dev_module_[device[0]].module); } else { - GELOGE(FAILED, "The device_id:%u has not been subscribed, do not need to cancel.", device[0]); + GELOGE(FAILED, "[Cancel][DeviceId]The device_id %u has not been subscribed, " + "do not need to cancel", device[0]); + REPORT_CALL_ERROR("E19999", "The device_id %u has not been subscribed, do not need to cancel", + device[0]); return FAILED; } @@ -527,14 +564,16 @@ FMK_FUNC_HOST_VISIBILITY FMK_FUNC_DEV_VISIBILITY Status ProfilingManager::ProfIn // register Framework to profiling int32_t cb_ret = PluginInit(); if (cb_ret != 0) { - GELOGE(cb_ret, "profiling plugin init failed, ret:%d", cb_ret); + GELOGE(cb_ret, "[Init][ProfilingPlugin]Failed, ret %d", cb_ret); + REPORT_CALL_ERROR("E19999", "Init profiling plugin failed, ret %d", cb_ret); return cb_ret; } int32_t device_num = -1; rtError_t rt_ret = rtProfilerStart(model_load_mask, device_num, nullptr); if (rt_ret != RT_ERROR_NONE) { - GELOGE(FAILED, "Runtime profiler start failed."); + GELOGE(FAILED, "[Start][Profiler]Malloc buffer failed, ret 0x%X", rt_ret); + REPORT_CALL_ERROR("E19999", "Malloc buffer failed when start profiling, ret 0x%X", rt_ret); return FAILED; } is_load_profiling_ = true; @@ -563,7 +602,8 @@ FMK_FUNC_HOST_VISIBILITY FMK_FUNC_DEV_VISIBILITY Status ProfilingManager::ProfFi int32_t dev_num = -1; rtError_t rt_ret = rtProfilerStop(PROF_MODEL_LOAD_MASK, dev_num, nullptr); if (rt_ret != RT_ERROR_NONE) { - GELOGE(FAILED, "Runtime profiler stop failed."); + GELOGE(FAILED, "[Stop][Profiler]Malloc buffer failed, ret 0x%X", rt_ret); + REPORT_CALL_ERROR("E19999", "Malloc buffer failed when stop profiling, ret 0x%X", rt_ret); return FAILED; } for (auto device_id_module : device_id_module_map_) { @@ -572,7 +612,9 @@ FMK_FUNC_HOST_VISIBILITY FMK_FUNC_DEV_VISIBILITY Status ProfilingManager::ProfFi GELOGI("Prof finalize: device_id: %u, module: 0x%lx.", device_id, device_id_module.second); rt_ret = rtProfilerStop(device_id_module.second, 1, &device_id); if (rt_ret != RT_ERROR_NONE) { - GELOGE(FAILED, "Runtime profiler stop failed."); + GELOGE(FAILED, "[Stop][Profiler]Failed, device_id %d, ret 0x%X", device_id, rt_ret); + REPORT_CALL_ERROR("E19999", "Stop runtime profiler failed, device_id %d, ret 0x%X", + device_id,rt_ret); return FAILED; } } @@ -611,18 +653,26 @@ Status ProfilingManager::ProfParseDeviceId(const std::map try { device_num = std::stoi(iter->second); } catch (std::invalid_argument &) { - GELOGE(FAILED, "Device nun: %s is invalid.", iter->second.c_str()); + GELOGE(FAILED, "[Parse][Param]Failed, device num %s is invalid", iter->second.c_str()); + REPORT_CALL_ERROR("E19999", "Parse param failed, device num %s is invalid", + iter->second.c_str()); return FAILED; } catch (std::out_of_range &) { - GELOGE(FAILED, "Device num: %s is out of range.", iter->second.c_str()); + GELOGE(FAILED, "[Parse][Param]Failed, device num %s cannot change to int", + iter->second.c_str()); + REPORT_CALL_ERROR("E19999", "Parse param failed, device num %s cannot change to int", + iter->second.c_str()); return FAILED; } catch (...) { - GELOGE(FAILED, "Device num: %s cannot change to int.", iter->second.c_str()); + GELOGE(FAILED, "[Parse][Param]Failed, device num %s cannot change to int", + iter->second.c_str()); + REPORT_CALL_ERROR("E19999", "Parse param failed, device num %s cannot change to int", + iter->second.c_str()); return FAILED; } } else { - GELOGE(FAILED, "Config para not contain device num."); + GELOGE(FAILED, "[Parse][Param]Config para not contain device num %s", iter->second.c_str()); + REPORT_CALL_ERROR("E19999", "Parse param failed, config para not contain device num %s", + iter->second.c_str()); return FAILED; } // device id if (ProfParseDeviceId(config_para, device_list) != SUCCESS) { - GELOGE(FAILED, "Parse config para device id failed."); + GELOGE(FAILED, "[Parse][DeviceId]Failed"); + REPORT_CALL_ERROR("E19999", "Parse device id failed"); return FAILED; } if (device_num == 0 || device_num > kMaxDeviceNum || device_num != static_cast(device_list.size())) { - GELOGE(FAILED, "Config para device num: %d not equal to device list size: %zu.", device_num, device_list.size()); + GELOGE(FAILED, "[Parse][Param]Failed, config para device num %d not equal to " + "device list size %zu", device_num, device_list.size()); + REPORT_INNER_ERROR("E19999", "[Parse][Param]Failed, config para device num %d " + "not equal to device list size %zu", device_num, device_list.size()); return FAILED; } #endif @@ -676,13 +740,18 @@ FMK_FUNC_HOST_VISIBILITY FMK_FUNC_DEV_VISIBILITY Status ProfilingManager::ProfSt int32_t device_num = 0; vector device_list; if (ProfParseParam(config_para, device_num, device_list) != SUCCESS) { - GELOGE(FAILED, "Prof start parse param failed."); + GELOGE(FAILED, "[Parse][Param]Prof start parse param failed, device num %d, " + "device list size %zu", device_num, device_list.size()); + REPORT_CALL_ERROR("E19999", "Prof start parse param failed, device num %d, " + "device list size %zu", device_num, device_list.size()); return FAILED; } auto device_id_ptr = std::unique_ptr(new (std::nothrow) uint32_t[device_num]); if (device_id_ptr == nullptr) { - GELOGE(FAILED, "Prof start: device id ptr is null."); + GELOGE(FAILED, "[Start][Profiling]Malloc buffer failed when start profiling, device num %d", device_num); + REPORT_CALL_ERROR("E19999", "Malloc buffer failed when start profiling, device num %d", + device_num); return FAILED; } for (int32_t i = 0; i < device_num; i++) { @@ -692,7 +761,10 @@ FMK_FUNC_HOST_VISIBILITY FMK_FUNC_DEV_VISIBILITY Status ProfilingManager::ProfSt rtError_t rt_ret = rtProfilerStart(module, device_num, device_id_ptr.get()); if (rt_ret != RT_ERROR_NONE) { - GELOGE(FAILED, "Runtime profiler config proc failed."); + GELOGE(FAILED, "[Start][Profiler]Runtime profiler config proc failed, config param 0x%lx, " + "device num %d, ret 0x%X", module, device_num, rt_ret); + REPORT_CALL_ERROR("E19999", "Runtime profiler config proc failed, config param 0x%lx, " + "device num %d, ret 0x%X", module, device_num, rt_ret); return FAILED; } if ((module & PROF_MODEL_EXECUTE_MASK) == PROF_MODEL_EXECUTE_MASK) { @@ -719,12 +791,17 @@ FMK_FUNC_HOST_VISIBILITY FMK_FUNC_DEV_VISIBILITY Status ProfilingManager::ProfSt int32_t device_num = 0; vector device_list; if (ProfParseParam(config_para, device_num, device_list) != SUCCESS) { - GELOGE(FAILED, "Prof stop parse param failed."); + GELOGE(FAILED, "[Stop][Profiling]Prof stop parse param failed, device num %d, " + "device list size %zu", device_num, device_list.size()); + REPORT_CALL_ERROR("E19999", "Prof stop parse param failed, device num %d, device list size %zu", + device_num, device_list.size()); return FAILED; } auto device_id_ptr = std::unique_ptr(new (std::nothrow) uint32_t[device_num]); if (device_id_ptr == nullptr) { - GELOGE(FAILED, "Prof stop: device id ptr is null."); + GELOGE(FAILED, "[Stop][Profiling]Malloc buffer failed when stop profiling, device num %d", device_num); + REPORT_CALL_ERROR("E19999", "Malloc buffer failed when stop profiling, device num %d", + device_num); return FAILED; } for (int32_t i = 0; i < device_num; i++) { @@ -733,7 +810,10 @@ FMK_FUNC_HOST_VISIBILITY FMK_FUNC_DEV_VISIBILITY Status ProfilingManager::ProfSt GELOGI("Prof stop: runtime config param: 0x%lx, device num: %d", module, device_num); rtError_t rt_ret = rtProfilerStop(module, device_num, device_id_ptr.get()); if (rt_ret != RT_ERROR_NONE) { - GELOGE(FAILED, "Prof stop: runtime profiler config proc failed."); + GELOGE(FAILED, "[Stop][Profiler]Runtime profiler config proc failed, config param 0x%lx, " + "device num: %d, ret 0x%X", module, device_num, rt_ret); + REPORT_CALL_ERROR("E19999", "Runtime profiler config proc failed, config param 0x%lx, " + "device num %d, ret 0x%X", module, device_num, rt_ret); return FAILED; } uint64_t execute_model_mask = module & PROF_MODEL_EXECUTE_MASK; @@ -790,7 +870,8 @@ FMK_FUNC_HOST_VISIBILITY FMK_FUNC_DEV_VISIBILITY bool ProfilingManager::Profilin int32_t logic_device_id = 0; rtError_t rt_ret = rtGetDevice(&logic_device_id); if (rt_ret != RT_ERROR_NONE) { - GELOGE(rt_ret, "Runtime get logic_device_id failed, current logic_device_id:%d", logic_device_id); + GELOGE(rt_ret, "[Get][LogicDeviceId]Failed, ret 0x%X", rt_ret); + REPORT_CALL_ERROR("E19999", "Get logic device id failed, ret 0x%X", rt_ret); } GELOGI("Current logic_device_id:%d", logic_device_id); @@ -805,7 +886,8 @@ FMK_FUNC_HOST_VISIBILITY FMK_FUNC_DEV_VISIBILITY bool ProfilingManager::Profilin FMK_FUNC_HOST_VISIBILITY FMK_FUNC_DEV_VISIBILITY Status ProfilingManager::PluginInit() { if (prof_cb_.msprofReporterCallback == nullptr) { - GELOGE(ge::PARAM_INVALID, "MsprofReporterCallback callback is nullptr."); + GELOGE(ge::PARAM_INVALID, "[Check][Param]MsprofReporterCallback callback is nullptr"); + REPORT_INNER_ERROR("E19999", "MsprofReporterCallback callback is nullptr"); return ge::PARAM_INVALID; } int32_t cb_ret = prof_cb_.msprofReporterCallback( @@ -813,8 +895,8 @@ FMK_FUNC_HOST_VISIBILITY FMK_FUNC_DEV_VISIBILITY Status ProfilingManager::Plugin static_cast(MsprofReporterCallbackType::MSPROF_REPORTER_INIT), nullptr, 0); if (cb_ret != MSPROF_ERROR_NONE) { - REPORT_CALL_ERROR("E19999", "Profiling reporter init failed, ret = %d.", cb_ret); - GELOGE(INTERNAL_ERROR, "[Init][ProfilingReporter] profiling init failed, ret = %d.", cb_ret); + REPORT_CALL_ERROR("E19999", "Profiling reporter init failed, ret 0x%X", cb_ret); + GELOGE(INTERNAL_ERROR, "[Init][ProfilingReporter]Failed, ret 0x%X", cb_ret); return INTERNAL_ERROR; } @@ -823,8 +905,8 @@ FMK_FUNC_HOST_VISIBILITY FMK_FUNC_DEV_VISIBILITY Status ProfilingManager::Plugin static_cast(MsprofReporterCallbackType::MSPROF_REPORTER_DATA_MAX_LEN), &reporter_max_len_, sizeof(uint32_t)); if (cb_ret != MSPROF_ERROR_NONE) { - REPORT_CALL_ERROR("E19999", "Get profiling reporter data max len failed, ret = %d.", cb_ret); - GELOGE(INTERNAL_ERROR, "[Init][ProfilingReporter] Get profiling reporter data max len failed, ret = %d.", cb_ret); + REPORT_CALL_ERROR("E19999", "Get profiling reporter data max len failed, ret 0x%X", cb_ret); + GELOGE(INTERNAL_ERROR, "[Get][ProfilingDataMaxLen]Failed, ret 0x%X", cb_ret); return INTERNAL_ERROR; } @@ -834,7 +916,8 @@ FMK_FUNC_HOST_VISIBILITY FMK_FUNC_DEV_VISIBILITY Status ProfilingManager::Plugin FMK_FUNC_HOST_VISIBILITY FMK_FUNC_DEV_VISIBILITY void ProfilingManager::PluginUnInit() const { #ifdef DAVINCI_SUPPORT_PROFILING if (prof_cb_.msprofReporterCallback == nullptr) { - GELOGE(ge::PARAM_INVALID, "MsprofReporterCallback callback is nullptr."); + GELOGE(ge::PARAM_INVALID, "[Check][Param]MsprofReporterCallback callback is nullptr"); + REPORT_INNER_ERROR("E19999", "MsprofReporterCallback callback is nullptr"); return; } int32_t cb_ret = prof_cb_.msprofReporterCallback( @@ -850,7 +933,8 @@ FMK_FUNC_HOST_VISIBILITY FMK_FUNC_DEV_VISIBILITY void ProfilingManager::PluginUn FMK_FUNC_HOST_VISIBILITY FMK_FUNC_DEV_VISIBILITY Status ProfilingManager::CallMsprofReport( ReporterData &reporter_data) const { if (prof_cb_.msprofReporterCallback == nullptr) { - GELOGE(ge::PARAM_INVALID, "MsprofReporterCallback callback is nullptr."); + GELOGE(ge::PARAM_INVALID, "[Check][Param]MsprofReporterCallback callback is nullptr"); + REPORT_INNER_ERROR("E19999", "MsprofReporterCallback callback is nullptr"); return ge::PARAM_INVALID; } return prof_cb_.msprofReporterCallback( @@ -946,5 +1030,4 @@ FMK_FUNC_HOST_VISIBILITY FMK_FUNC_DEV_VISIBILITY void ProfilingManager::GetFpBpP return; } - } // namespace ge diff --git a/ge/common/properties_manager.cc b/ge/common/properties_manager.cc index eae29e34..e1f4c66e 100644 --- a/ge/common/properties_manager.cc +++ b/ge/common/properties_manager.cc @@ -69,7 +69,8 @@ bool PropertiesManager::LoadFileContent(const std::string &file_path) { std::ifstream fs(resolved_file_path, std::ifstream::in); if (!fs.is_open()) { - GELOGE(PARAM_INVALID, "Open %s failed.", file_path.c_str()); + GELOGE(PARAM_INVALID, "[Open][File]Failed, file path %s invalid", file_path.c_str()); + REPORT_CALL_ERROR("E19999", "Open file failed, path %s invalid", file_path.c_str()); return false; } @@ -77,7 +78,8 @@ bool PropertiesManager::LoadFileContent(const std::string &file_path) { while (getline(fs, line)) { // line not with \n if (!ParseLine(line)) { - GELOGE(PARAM_INVALID, "Parse line failed. content is [%s].", line.c_str()); + GELOGE(PARAM_INVALID, "[Parse][Line]Failed, content is %s", line.c_str()); + REPORT_CALL_ERROR("E19999", "Parse line failed, content is %s", line.c_str()); fs.close(); return false; } @@ -100,15 +102,18 @@ bool PropertiesManager::ParseLine(const std::string &line) { if (!temp.empty()) { std::string::size_type pos = temp.find_first_of(delimiter); if (pos == std::string::npos) { - GELOGE(PARAM_INVALID, "Incorrect line [%s], it must include [%s].Perhaps you use illegal chinese symbol", + GELOGE(PARAM_INVALID, "[Check][Param]Incorrect line %s, it must include %s", line.c_str(), delimiter.c_str()); + REPORT_CALL_ERROR("E19999", "Incorrect line %s, it must include %s", + line.c_str(), delimiter.c_str()); return false; } std::string map_key = Trim(temp.substr(0, pos)); std::string value = Trim(temp.substr(pos + 1)); if (map_key.empty() || value.empty()) { - GELOGE(PARAM_INVALID, "Map_key or value empty. %s", line.c_str()); + GELOGE(PARAM_INVALID, "[Check][Param]Map_key or value empty, line %s", line.c_str()); + REPORT_CALL_ERROR("E19999", "Map_key or value empty, line %s", line.c_str()); return false; } diff --git a/ge/common/util.cc b/ge/common/util.cc index 63d75de1..adec958c 100644 --- a/ge/common/util.cc +++ b/ge/common/util.cc @@ -83,7 +83,7 @@ FMK_FUNC_HOST_VISIBILITY FMK_FUNC_DEV_VISIBILITY bool ReadProtoFromBinaryFile(co std::ifstream fs(real_path, std::ifstream::in | std::ifstream::binary); if (!fs.is_open()) { ErrorManager::GetInstance().ATCReportErrMessage("E19001", {"file", "errmsg"}, {file, "ifstream is_open failed"}); - GELOGE(ge::FAILED, "Open real path[%s] failed.", file); + GELOGE(ge::FAILED, "[Open][File]Failed, file path %s", file); return false; } @@ -96,7 +96,7 @@ FMK_FUNC_HOST_VISIBILITY FMK_FUNC_DEV_VISIBILITY bool ReadProtoFromBinaryFile(co if (!ret) { ErrorManager::GetInstance().ATCReportErrMessage("E19005", {"file"}, {file}); - GELOGE(ge::FAILED, "Parse file[%s] failed.", file); + GELOGE(ge::FAILED, "[Parse][File]Failed, file %s", file); return ret; } @@ -155,7 +155,8 @@ FMK_FUNC_HOST_VISIBILITY FMK_FUNC_DEV_VISIBILITY bool ReadBytesFromBinaryFile(co std::ifstream file(real_path.c_str(), std::ios::binary | std::ios::ate); if (!file.is_open()) { - GELOGE(ge::FAILED, "Read file %s failed.", file_name); + GELOGE(ge::FAILED, "[Read][File]Failed, file %s", file_name); + REPORT_CALL_ERROR("E19999", "Read file %s failed", file_name); return false; } @@ -182,7 +183,8 @@ FMK_FUNC_HOST_VISIBILITY FMK_FUNC_DEV_VISIBILITY bool ReadBytesFromBinaryFile(co std::ifstream file(real_path.c_str(), std::ios::binary | std::ios::ate); if (!file.is_open()) { - GELOGE(ge::FAILED, "Read file %s failed.", file_name); + GELOGE(ge::FAILED, "[Read][File]Failed, file %s", file_name); + REPORT_CALL_ERROR("E19999", "Read file %s failed", file_name); return false; } @@ -250,7 +252,8 @@ FMK_FUNC_HOST_VISIBILITY FMK_FUNC_DEV_VISIBILITY std::string CurrentTimeInStr() std::time_t now = std::time(nullptr); std::tm *ptm = std::localtime(&now); if (ptm == nullptr) { - GELOGE(ge::FAILED, "Localtime failed."); + GELOGE(ge::FAILED, "[Check][Param]Localtime incorrect"); + REPORT_CALL_ERROR("E19999", "Localtime incorrect"); return ""; } @@ -277,17 +280,15 @@ FMK_FUNC_HOST_VISIBILITY FMK_FUNC_DEV_VISIBILITY bool ReadProtoFromText(const ch if (!fs.is_open()) { ErrorManager::GetInstance().ATCReportErrMessage("E19017", {"realpth", "protofile"}, {real_path, file}); - GELOGE(ge::FAILED, "Fail to open proto file real path is '%s' when orginal file path is '%s'.", real_path.c_str(), - file); + GELOGE(ge::FAILED, "[Open][ProtoFile]Failed, real path %s, orginal file path %s", + real_path.c_str(), file); return false; } google::protobuf::io::IstreamInputStream input(&fs); bool ret = google::protobuf::TextFormat::Parse(&input, message); GE_IF_BOOL_EXEC(!ret, ErrorManager::GetInstance().ATCReportErrMessage("E19018", {"protofile"}, {file}); - GELOGE(ret, - "Parse file[%s] through [google::protobuf::TextFormat::Parse] failed, " - "please check whether the file is a valid protobuf format file.", + GELOGE(ret, "[Parse][File]Through [google::protobuf::TextFormat::Parse] failed, file %s", file)); fs.close(); @@ -490,7 +491,8 @@ FMK_FUNC_HOST_VISIBILITY bool ValidateStr(const std::string &str, const std::str ret = regexec(®, str.c_str(), 0, NULL, 0); if (ret) { regerror(ret, ®, ebuff, kMaxBuffSize); - GELOGE(ge::PARAM_INVALID, "regexec failed, reason: %s", ebuff); + GELOGE(ge::PARAM_INVALID, "[Rgexec][Param]Failed, reason %s", ebuff); + REPORT_CALL_ERROR("E19999", "Rgexec failed, reason %s", ebuff); regfree(®); return false; } @@ -518,35 +520,44 @@ FMK_FUNC_HOST_VISIBILITY bool ValidateStr(const std::string &str, const std::str FMK_FUNC_HOST_VISIBILITY bool IsValidFile(const char *file_path) { if (file_path == nullptr) { - GELOGE(PARAM_INVALID, "Config path is null."); + GELOGE(PARAM_INVALID, "[Check][Param]Config path is null"); + REPORT_INNER_ERROR("E19999", "Config path is null"); return false; } if (!CheckInputPathValid(file_path)) { - GELOGE(PARAM_INVALID, "Config path is invalid: %s", file_path); + GELOGE(PARAM_INVALID, "[Check][Param]Config path %s is invalid", file_path); + REPORT_CALL_ERROR("E19999", "Config path %s is invalid", file_path); return false; } // Normalize the path std::string resolved_file_path = RealPath(file_path); if (resolved_file_path.empty()) { - GELOGE(PARAM_INVALID, "Invalid input file path [%s], make sure that the file path is correct.", file_path); + GELOGE(PARAM_INVALID, "[Check][Param]Invalid input file path %s", file_path); + REPORT_CALL_ERROR("E19999", "Invalid input file path %s", file_path); return false; } mmStat_t stat = {0}; int32_t ret = mmStatGet(resolved_file_path.c_str(), &stat); if (ret != EN_OK) { - GELOGE(PARAM_INVALID, "cannot get config file status, which path is %s, maybe not exist, return %d, errcode %d", - resolved_file_path.c_str(), ret, mmGetErrorCode()); + GELOGE(PARAM_INVALID, "[Get][FileStatus]Failed, which path %s maybe not exist, " + "return %d, errcode %d", resolved_file_path.c_str(), ret, mmGetErrorCode()); + REPORT_CALL_ERROR("E19999", "Get config file status failed, which path %s maybe not exist, " + "return %d, errcode %d", resolved_file_path.c_str(), ret, mmGetErrorCode()); return false; } if ((stat.st_mode & S_IFMT) != S_IFREG) { - GELOGE(PARAM_INVALID, "config file is not a common file, which path is %s, mode is %u", resolved_file_path.c_str(), - stat.st_mode); + GELOGE(PARAM_INVALID, "[Check][Param]Config file is not a common file, which path is %s, " + "mode is %u", resolved_file_path.c_str(), stat.st_mode); + REPORT_CALL_ERROR("E19999", "Config file is not a common file, which path is %s, " + "mode is %u", resolved_file_path.c_str(), stat.st_mode); return false; } if (stat.st_size > kMaxConfigFileByte) { - GELOGE(PARAM_INVALID, "config file %s size[%ld] is larger than max config file Bytes[%u]", + GELOGE(PARAM_INVALID, "[Check][Param]Config file %s size %ld is larger than max config file Bytes %u", resolved_file_path.c_str(), stat.st_size, kMaxConfigFileByte); + REPORT_CALL_ERROR("E19999", "Config file %s size %ld is larger than max config file Bytes %u", + resolved_file_path.c_str(), stat.st_size, kMaxConfigFileByte); return false; } return true; @@ -554,29 +565,35 @@ FMK_FUNC_HOST_VISIBILITY bool IsValidFile(const char *file_path) { FMK_FUNC_HOST_VISIBILITY FMK_FUNC_DEV_VISIBILITY Status CheckPath(const char *path, size_t length) { if (path == nullptr) { - GELOGE(PARAM_INVALID, "Config path is invalid."); + GELOGE(PARAM_INVALID, "[Check][Param]Config path is invalid"); + REPORT_CALL_ERROR("E19999", "Config path is invalid"); return PARAM_INVALID; } if (strlen(path) != length) { - GELOGE(PARAM_INVALID, "Path is invalid or length of config path is not equal to given length."); + GELOGE(PARAM_INVALID, "[Check][Param]Path %s is invalid or length %zu " + "not equal to given length %zu", path, strlen(path), length); + REPORT_CALL_ERROR("E19999", "Path %s is invalid or length %zu " + "not equal to given length %zu", path, strlen(path), length); return PARAM_INVALID; } if (length == 0 || length > MMPA_MAX_PATH) { - GELOGE(PARAM_INVALID, "Length of config path is invalid."); + GELOGE(PARAM_INVALID, "[Check][Param]Length of config path %zu is invalid", length); + REPORT_INNER_ERROR("E19999", "Length of config path %zu is invalid", length); return PARAM_INVALID; } INT32 is_dir = mmIsDir(path); if (is_dir != EN_OK) { - GELOGE(PATH_INVALID, "Open directory %s failed, maybe it is not exit or not a dir. errmsg:%s", - path, strerror(errno)); + GELOGE(PATH_INVALID, "[Open][Directory]Failed, directory path %s, errmsg %s", path, strerror(errno)); + REPORT_CALL_ERROR("E19999", "Open directory %s failed, errmsg %s", path, strerror(errno)); return PATH_INVALID; } if (mmAccess2(path, M_R_OK) != EN_OK) { - GELOGE(PATH_INVALID, "Read path[%s] failed, errmsg[%s]", path, strerror(errno)); + GELOGE(PATH_INVALID, "[Read][Path]Failed, path %s, errmsg %s", path, strerror(errno)); + REPORT_CALL_ERROR("E19999", "Read path %s failed, errmsg %s", path, strerror(errno)); return PATH_INVALID; } return SUCCESS; From 53fb85307d4480a6da78f715a5b3efb898e2dda1 Mon Sep 17 00:00:00 2001 From: "liyihan2@huawei.com" Date: Wed, 28 Apr 2021 14:46:45 +0800 Subject: [PATCH 02/11] common log optimize --- ge/common/op/ge_op_utils.cc | 6 +- ge/engine_manager/dnnengine_manager.cc | 111 +++++++++++++++++-------- 2 files changed, 79 insertions(+), 38 deletions(-) diff --git a/ge/common/op/ge_op_utils.cc b/ge/common/op/ge_op_utils.cc index 0303bcdf..5d1b8089 100644 --- a/ge/common/op/ge_op_utils.cc +++ b/ge/common/op/ge_op_utils.cc @@ -276,10 +276,8 @@ Status OpUtils::SetOutputSliceDataByDataType(void *data, int64_t data_size, cons int64_t dim_i = input_dims[i]; int64_t stride_i = stride[i]; if (dim_i == 0) { - GELOGE(PARAM_INVALID, "[Check][Param]Invalid, Dim_i %s of size tensor is 0", - ShapeToString(input_dims[i]).c_str()); - REPORT_INNER_ERROR("E19999", "Dim_i %s of size tensor is 0, invalid", - ShapeToString(input_dims[i]).c_str()); + GELOGE(PARAM_INVALID, "[Check][Param]Invalid, Dim_i of size tensor is 0"); + REPORT_INNER_ERROR("E19999", "Dim_i of size tensor is 0, invalid"); return PARAM_INVALID; } chunk_size = chunk_size / dim_i; diff --git a/ge/engine_manager/dnnengine_manager.cc b/ge/engine_manager/dnnengine_manager.cc index 2bd9b3e5..1425ddf6 100644 --- a/ge/engine_manager/dnnengine_manager.cc +++ b/ge/engine_manager/dnnengine_manager.cc @@ -71,13 +71,15 @@ Status DNNEngineManager::Initialize(const std::map &op std::vector so_func{so_api_func}; Status status = plugin_mgr_.Load(path, so_func); if (status != SUCCESS) { - GELOGE(status, "Load engine's so failed. LibPath is %s", path.c_str()); + GELOGE(status, "[Load][EngineSo]Failed, lib path %s", path.c_str()); + REPORT_CALL_ERROR("E19999", "Load engine so failed, lib path %s", path.c_str()); return status; } status = plugin_mgr_.InvokeAll &>(so_api_func, engines_map_); if (status != SUCCESS) { - GELOGE(status, "Get DNNEngineObjs failed."); + GELOGE(status, "[Get][DNNEngineObjs]Failed"); + REPORT_CALL_ERROR("E19999", "Get DNNEngineObjs failed"); return status; } @@ -94,16 +96,21 @@ Status DNNEngineManager::Initialize(const std::map &op status = iter->second->Initialize(options); if (status != SUCCESS) { - GELOGE(status, "Engine: %s initialize failed.", (iter->first).c_str()); + GELOGE(status, "[Init][Engine]Failed, engine %s", (iter->first).c_str()); + REPORT_CALL_ERROR("E19999", "Initialize engine %s failed", (iter->first).c_str()); return status; } + // Check engines' attribute DNNEngineAttribute attrs; iter->second->GetAttributes(attrs); if (attrs.runtime_type == RuntimeType::DEVICE) { if ((attrs.mem_type.size()) != 1 || (attrs.mem_type[0] != GE_ENGINE_ATTR_MEM_TYPE_HBM)) { - GELOGE(GE_ENG_MEMTYPE_ERROR, "Engine: %s in aicore, but the memory type is not HBM", (iter->first).c_str()); + GELOGE(GE_ENG_MEMTYPE_ERROR, "[Check][Param]Engine %s in aicore, but the memory type is not HBM, " + "mem_type_size %d", (iter->first).c_str(), attrs.mem_type.size()); + REPORT_CALL_ERROR("E19999", "Engine %s in aicore, but the memory type is not HBM, " + "mem_type_size %d", (iter->first).c_str(), attrs.mem_type.size()); return GE_ENG_MEMTYPE_ERROR; } } @@ -111,13 +118,15 @@ Status DNNEngineManager::Initialize(const std::map &op status = ParserJsonFile(); if (status != SUCCESS) { - GELOGE(status, "parse json file failed"); + GELOGE(status, "[Parse][JsonFile]Failed"); + REPORT_CALL_ERROR("E19999", "Parse json file failed"); return status; } status = CheckJsonFile(); if (status != SUCCESS) { - GELOGE(status, "check json file failed"); + GELOGE(status, "[Check][JsonFile]Failed"); + REPORT_CALL_ERROR("E19999", "Check json file failed"); return status; } @@ -138,7 +147,8 @@ Status DNNEngineManager::Finalize() { GELOGI("DNNEngine name: %s.", (iter->first).c_str()); Status status = iter->second->Finalize(); if (status != SUCCESS) { - GELOGE(status, "Engine finalize failed."); + GELOGE(status, "[Finalize][Engine]Failed, engine %s", (iter->first).c_str()); + REPORT_CALL_ERROR("E19999", "Finalize engine %s failed", (iter->first).c_str()); return status; } } @@ -188,7 +198,8 @@ std::string DNNEngineManager::GetDNNEngineName(const ge::NodePtr &node_ptr) { // Use the OpsKernelManager in GELib to get the opInfos for this opCode std::shared_ptr instance_ptr = ge::GELib::GetInstance(); if ((instance_ptr == nullptr) || (!instance_ptr->InitFlag())) { - GELOGE(GE_CLI_GE_NOT_INITIALIZED, "GetDNNEngineName failed."); + GELOGE(GE_CLI_GE_NOT_INITIALIZED, "[Get][DNNEngineName]Failed, instance_ptr is null"); + REPORT_CALL_ERROR("E19999", "Get DNNEngineName failed, instance_ptr is null"); return ""; } OpsKernelManager &ops_kernel_manager = instance_ptr->OpsKernelManagerObj(); @@ -234,8 +245,8 @@ std::string DNNEngineManager::GetDNNEngineName(const ge::NodePtr &node_ptr) { ErrorManager::GetInstance().ATCReportErrMessage("E13001", {"kernelname", "optype", "opname"}, {kernel_name, op_desc->GetType(), op_desc->GetName()}); GELOGE(FAILED, - "The custom operator registered by the user does not support the logic function delivered by this " - "network. Check support failed, kernel_name is %s, op type is %s, op name is %s", + "[Check][Param]The custom operator registered by the user does not support " + "the logic function delivered by this network, kernel_name %s, op type %s, op name %s", kernel_name.c_str(), op_desc->GetType().c_str(), op_desc->GetName().c_str()); std::string error_info = "The custom operator registered by the user does not support the logic function" "delivered by this network"; @@ -262,8 +273,8 @@ std::string DNNEngineManager::GetDNNEngineName(const ge::NodePtr &node_ptr) { reason += it.first + ":" + it.second + ";"; ErrorManager::GetInstance().ATCReportErrMessage( "E13002", {"optype", "opskernel", "reason"}, {op_desc->GetType(), it.first, it.second}); - GELOGE(GE_GRAPH_ASSIGN_ENGINE_FAILED, "GetDNNEngineName:Op type %s of ops kernel %s is unsupported, reason:%s", - op_desc->GetType().c_str(), it.first.c_str(), it.second.c_str()); + GELOGE(GE_GRAPH_ASSIGN_ENGINE_FAILED, "[Concat][UnsupportedReasons]Op type %s of ops kernel %s is unsupported, " + "reason %s", op_desc->GetType().c_str(), it.first.c_str(), it.second.c_str()); } analyzer::DataInfo analyze_info{root_graph->GetSessionID(), root_graph->GetGraphID(), @@ -273,7 +284,7 @@ std::string DNNEngineManager::GetDNNEngineName(const ge::NodePtr &node_ptr) { ErrorManager::GetInstance().ATCReportErrMessage( "E13003", {"opname", "optype"}, {op_desc->GetName(), op_desc->GetType()}); - GELOGE(GE_GRAPH_ASSIGN_ENGINE_FAILED, "Can't find any supported ops kernel and engine of %s, type is %s", + GELOGE(GE_GRAPH_ASSIGN_ENGINE_FAILED, "[Get][DNNEngineName]Can't find any supported ops kernel and engine of %s, type is %s", op_desc->GetName().c_str(), op_desc->GetType().c_str()); return ""; } @@ -289,8 +300,10 @@ std::string DNNEngineManager::GetHostCpuEngineName(const std::vector &op return kHostCpuEngineName; } } - GELOGE(FAILED, "DNNEngineManager: HostCpuEngine not support [%s, %s].", + GELOGE(FAILED, "[Get][HostCpuEngineName]Failed, HostCpuEngine not support [%s, %s]", op_desc->GetName().c_str(), op_desc->GetType().c_str()); + REPORT_CALL_ERROR("E19999", "Get HostCpuEngineName failed, HostCpuEngine not support [%s, %s]", + op_desc->GetName().c_str(), op_desc->GetType().c_str()); return ""; } @@ -304,7 +317,8 @@ Status DNNEngineManager::ParserJsonFile() { nlohmann::json scheduler_json_file; Status status = ReadJsonFile(path, &scheduler_json_file); if (status != SUCCESS) { - GELOGE(FAILED, "Read scheduler json file failed and the file path is %s", path.c_str()); + GELOGE(FAILED, "[Read][JsonFile]Failed, file %s", path.c_str()); + REPORT_CALL_ERROR("E19999", "Read json file %s failed", path.c_str()); return FAILED; } if (scheduler_json_file.is_null()) { @@ -316,11 +330,15 @@ Status DNNEngineManager::ParserJsonFile() { try { nlohmann::json scheduler_utils_json = scheduler_json_file[kSchedulerUnits]; if (scheduler_utils_json.is_null()) { - GELOGE(FAILED, "The message of scheduler units is not found"); + GELOGE(FAILED, "[Check[Param]Find scheduler units failed, the message is null"); + REPORT_CALL_ERROR("E19999", "Find scheduler units failed, the message is null"); return FAILED; } if (!scheduler_utils_json.is_array()) { - GELOGE(FAILED, "The message of kSchedulerUnits is not array and the file path is %s", json_file_path.c_str()); + GELOGE(FAILED, "[Check][Param]The message of kSchedulerUnits is not array and the file path is %s", + json_file_path.c_str()); + REPORT_CALL_ERROR("E19999", "The message of kSchedulerUnits is not array and the file path is %s", + json_file_path.c_str()); return FAILED; } auto size = scheduler_json_file[kSchedulerUnits].size(); @@ -329,19 +347,22 @@ Status DNNEngineManager::ParserJsonFile() { std::map engine_conf_map; nlohmann::json engines_json_map = scheduler_utils_json[i][kCalEngines]; if (engines_json_map.is_null()) { - GELOGE(FAILED, "The message of cal_engines is not found"); + GELOGE(FAILED, "[Check][Param]The message of cal_engines is null"); + REPORT_CALL_ERROR("E19999", "The message of cal_engines is null"); return FAILED; } std::string scheduler_id_temp = scheduler_utils_json[i][kId]; if (!scheduler_id_temp.empty()) { scheduler_conf.id = scheduler_id_temp; } else { - GELOGE(FAILED, "Scheduler ID is null"); + GELOGE(FAILED, "[Check][Param]Scheduler ID is null"); + REPORT_CALL_ERROR("E19999", "Scheduler ID is null"); return FAILED; } status = ParserEngineMessage(engines_json_map, scheduler_id_temp, engine_conf_map); if (status != SUCCESS) { - GELOGE(FAILED, "Parser engines messages failed"); + GELOGE(FAILED, "[Parse][EngineMessage]Failed, scheduler_id_temp %s", scheduler_id_temp); + REPORT_CALL_ERROR("E19999", "Parse engine message failed, scheduler_id_temp %s", scheduler_id_temp); return FAILED; } scheduler_conf.name = scheduler_utils_json[i][kName]; @@ -349,13 +370,17 @@ Status DNNEngineManager::ParserJsonFile() { scheduler_conf.cal_engines = engine_conf_map; auto it = schedulers_.find(scheduler_id_temp); if (it != schedulers_.end()) { - GELOGE(FAILED, "There are the same scheduler ts %s in the json file", scheduler_id_temp.c_str()); + GELOGE(FAILED, "[Check][Param]There are the same scheduler ts %s in the json file", + scheduler_id_temp.c_str()); + REPORT_CALL_ERROR("E19999", "[Check][Param]There are the same scheduler ts %s in the json file", + scheduler_id_temp.c_str()); return FAILED; } schedulers_.emplace(scheduler_id_temp, scheduler_conf); } } catch (const nlohmann::detail::type_error &e) { - GELOGE(FAILED, "Parser json file failed"); + GELOGE(FAILED, "[Parse][JsonFile]Failed, reason %s", e.what()); + REPORT_CALL_ERROR("E19999", "Parse json file failed, reason %s", e.what()); return FAILED; } @@ -367,7 +392,8 @@ Status DNNEngineManager::ParserEngineMessage(const json engines_json, const std: std::map &engines) { GELOGI("Begin to parser engine massage"); if (engines_json.is_null()) { - GELOGE(FAILED, "The message of cal_engines is null"); + GELOGE(FAILED, "[Check][Param]The message of cal_engines is null"); + REPORT_INNER_ERROR("E19999", "The message of cal_engines is null"); return FAILED; } try { @@ -382,7 +408,8 @@ Status DNNEngineManager::ParserEngineMessage(const json engines_json, const std: if (!engine_id.empty()) { engine_conf_ptr->id = engine_id; } else { - GELOGE(FAILED, "engineID is null"); + GELOGE(FAILED, "[Check][Param]Engine ID is null"); + REPORT_CALL_ERROR("E19999", "Engine ID is null"); return FAILED; } if (engines_elems.find(kName) != engines_elems.end()) { @@ -404,17 +431,22 @@ Status DNNEngineManager::ParserEngineMessage(const json engines_json, const std: engine_conf_ptr->scheduler_id = scheduler_mark; auto it = engines.find(engine_id); if (it != engines.end()) { - GELOGE(FAILED, "There are the same engine %s message in the json file", engine_id.c_str()); + GELOGE(FAILED, "[Check][Param]There are the same engine %s message in the json file", + engine_id.c_str()); + REPORT_CALL_ERROR("E19999", "There are the same engine %s message in the json file", + engine_id.c_str()); return FAILED; } engines.emplace(engine_id, engine_conf_ptr); } } else { - GELOGE(FAILED, "The message of cal_engines is not array in the json file"); + GELOGE(FAILED, "[Check][Param]The message of cal_engines is not array in the json file"); + REPORT_CALL_ERROR("E19999", "The message of cal_engines is not array in the json file"); return FAILED; } } catch (const json::exception &e) { - GELOGE(FAILED, "construct json content failed"); + GELOGE(FAILED, "[Construct][JsonContent]Failed, reason %s", e.what()); + REPORT_CALL_ERROR("E19999", "Construct json content failed, reason %s", e.what()) return FAILED; } GELOGI("Parser engine massage success"); @@ -424,18 +456,21 @@ Status DNNEngineManager::ParserEngineMessage(const json engines_json, const std: Status DNNEngineManager::ReadJsonFile(const std::string &file_path, JsonHandle handle) { GELOGD("Begin to read json file"); if (file_path.empty()) { - GELOGE(FAILED, "Json path %s is not valid", file_path.c_str()); + GELOGE(FAILED, "[Check][Param]Json path %s is invalid", file_path.c_str()); + REPORT_CALL_ERROR("E19999", "Json path %s is invalid", file_path.c_str()); return FAILED; } nlohmann::json *json_file = reinterpret_cast(handle); if (json_file == nullptr) { - GELOGE(FAILED, "JsonFile is nullptr"); + GELOGE(FAILED, "[Check][Param]Json file is nullptr"); + REPORT_CALL_ERROR("E19999", "Json file is nullptr"); return FAILED; } const char *file = file_path.data(); if ((mmAccess2(file, M_F_OK)) != EN_OK) { if (engines_map_.size() != 0) { - GELOGE(FAILED, "The json file %s is not exist, errmsg:%s", file_path.c_str(), strerror(errno)); + GELOGE(FAILED, "[Check][Param]The json file %s not exists, err %s", file_path.c_str(), strerror(errno)); + REPORT_CALL_ERROR("E19999", "Json file %s not exists, err %s", file_path.c_str(), strerror(errno)); return FAILED; } else { GELOGW("The json file %s is not needed.", file_path.c_str()); @@ -445,14 +480,16 @@ Status DNNEngineManager::ReadJsonFile(const std::string &file_path, JsonHandle h std::ifstream ifs(file_path); if (!ifs.is_open()) { - GELOGE(FAILED, "Open json file %s failed", file_path.c_str()); + GELOGE(FAILED, "[Open][JsonFile]Failed, file %s", file_path.c_str()); + REPORT_CALL_ERROR("E19999", "Open json file %s failed", file_path.c_str()); return FAILED; } try { ifs >> *json_file; } catch (const json::exception &e) { - GELOGE(FAILED, "Read json file failed"); + GELOGE(FAILED, "[Read][JsonFile]Failed, reason %s", e.what()); + REPORT_CALL_ERROR("E19999", "Read json file failed, reason %s", e.what()); ifs.close(); return FAILED; } @@ -474,11 +511,17 @@ Status DNNEngineManager::CheckJsonFile() { } } if (count == 0) { - GELOGE(FAILED, "The engine message %s is not found in the json file", engine_name.c_str()); + GELOGE(FAILED, "[Check][JsonFile]The engine message %s is not found in the json file", + engine_name.c_str()); + REPORT_INNER_ERROR("E19999", "The engine message %s is not found in the json file", + engine_name.c_str()); return FAILED; } if (count > 1) { - GELOGE(FAILED, "The same engine message %s is existed in the json file", engine_name.c_str()); + GELOGE(FAILED, "[Check][JsonFile]The same engine message %s exists in the json file", + engine_name.c_str()); + REPORT_INNER_ERROR("E19999", "The same engine message %s exists in the json file", + engine_name.c_str()); return FAILED; } } From 70ec4a17374987774e1568372698223e0eff2767 Mon Sep 17 00:00:00 2001 From: "liyihan2@huawei.com" Date: Wed, 28 Apr 2021 15:04:08 +0800 Subject: [PATCH 03/11] common log optimize --- ge/common/model_saver.cc | 3 +- ge/common/profiling/profiling_manager.cc | 18 ++++++------ ge/common/util.cc | 11 ++++---- ge/engine_manager/dnnengine_manager.cc | 36 ++++++++++++++---------- 4 files changed, 39 insertions(+), 29 deletions(-) diff --git a/ge/common/model_saver.cc b/ge/common/model_saver.cc index 01b3fd66..42cdf26e 100755 --- a/ge/common/model_saver.cc +++ b/ge/common/model_saver.cc @@ -72,7 +72,8 @@ FMK_FUNC_HOST_VISIBILITY FMK_FUNC_DEV_VISIBILITY Status ModelSaver::SaveJsonToFi ErrorManager::GetInstance().ATCReportErrMessage( "E19004", {"file", "errmsg"}, {file_path, strerror(errno)}); // Need to both print the error info of mmWrite and mmClose, so return ret after mmClose - GELOGE(FAILED, "[Write][Data]To file %s failed. errno %ld, errmsg %s", file_path, mmpa_ret, strerror(errno)); + GELOGE(FAILED, "[Write][Data]To file %s failed. errno %ld, errmsg %s", + file_path, mmpa_ret, strerror(errno)); ret = FAILED; } // Close file diff --git a/ge/common/profiling/profiling_manager.cc b/ge/common/profiling/profiling_manager.cc index f5419170..f7015525 100644 --- a/ge/common/profiling/profiling_manager.cc +++ b/ge/common/profiling/profiling_manager.cc @@ -106,7 +106,7 @@ FMK_FUNC_HOST_VISIBILITY FMK_FUNC_DEV_VISIBILITY ge::Status ProfilingManager::In static_cast(MsprofCtrlCallbackType::MSPROF_CTRL_INIT_GE_OPTIONS), cb_ret); REPORT_CALL_ERROR("E19999", "Call msprofCtrlCallback failed, type %u, return %d", static_cast(MsprofCtrlCallbackType::MSPROF_CTRL_INIT_GE_OPTIONS), - cb_ret); + cb_ret); return FAILED; } GELOGI("Profiling init success"); @@ -204,7 +204,7 @@ ge::Status ProfilingManager::ParseOptions(const std::string &options) { is_training_trace_ = true; } catch (...) { GELOGE(FAILED, "[Check][Param]Json prof_conf options is invalid"); - REPORT_INNER_ERROR("E19999", "Json prof_conf options is invalid"); + REPORT_INNER_ERROR("E19999", "Json prof_conf options is invalid"); return ge::PARAM_INVALID; } return ge::SUCCESS; @@ -234,7 +234,7 @@ FMK_FUNC_HOST_VISIBILITY FMK_FUNC_DEV_VISIBILITY void ProfilingManager::StopProf // stop profiling if (prof_cb_.msprofCtrlCallback == nullptr) { GELOGE(ge::PARAM_INVALID, "[Check][Param]MsprofCtrlCallback callback is nullptr"); - REPORT_INNER_ERROR("E19999", "MsprofCtrlCallback callback is nullptr"); + REPORT_INNER_ERROR("E19999", "MsprofCtrlCallback callback is nullptr"); return; } int32_t cb_ret = prof_cb_.msprofCtrlCallback(static_cast(MsprofCtrlCallbackType::MSPROF_CTRL_FINALIZE), @@ -299,7 +299,7 @@ FMK_FUNC_HOST_VISIBILITY FMK_FUNC_DEV_VISIBILITY void ProfilingManager::Profilin GELOGE(FAILED, "[Convert][ReportData]Failed to convert json to string, reason %s.", e.what()); REPORT_CALL_ERROR("E19999", "Failed to convert reported_data from json to string, reason %s", - e.what()); + e.what()); return ; } catch (...) { GELOGE(FAILED, "[Convert][ReportedData]Failed to convert JSON to string"); @@ -497,7 +497,7 @@ FMK_FUNC_HOST_VISIBILITY FMK_FUNC_DEV_VISIBILITY Status ProfilingManager::ProfMo rtError_t rt_ret = rtProfilerStart(module, device_num, device); if (rt_ret != RT_ERROR_NONE) { GELOGE(FAILED, "[Start][Profiler]Malloc buffer failed, ret 0x%X", rt_ret); - REPORT_CALL_ERROR("E19999", "Malloc buffer failed when start profiling, ret 0x%X", rt_ret); + REPORT_CALL_ERROR("E19999", "Malloc buffer failed when start profiling, ret 0x%X", rt_ret); return FAILED; } UpdateSubscribeDeviceModuleMap(kProfModelSubscribe, device[0], module); @@ -533,7 +533,7 @@ FMK_FUNC_HOST_VISIBILITY FMK_FUNC_DEV_VISIBILITY Status ProfilingManager::ProfMo rtError_t rt_ret = rtProfilerStop(subs_dev_module_[device[0]].module, dev_num, device); if (rt_ret != RT_ERROR_NONE) { GELOGE(FAILED, "[Stop][Profiler]Malloc buffer Failed, ret %d", rt_ret); - REPORT_CALL_ERROR("E19999", "Malloc buffer failed when stop profiling, ret %d", rt_ret); + REPORT_CALL_ERROR("E19999", "Malloc buffer failed when stop profiling, ret %d", rt_ret); return FAILED; } } @@ -749,7 +749,8 @@ FMK_FUNC_HOST_VISIBILITY FMK_FUNC_DEV_VISIBILITY Status ProfilingManager::ProfSt auto device_id_ptr = std::unique_ptr(new (std::nothrow) uint32_t[device_num]); if (device_id_ptr == nullptr) { - GELOGE(FAILED, "[Start][Profiling]Malloc buffer failed when start profiling, device num %d", device_num); + GELOGE(FAILED, "[Start][Profiling]Malloc buffer failed when start profiling, device num %d", + device_num); REPORT_CALL_ERROR("E19999", "Malloc buffer failed when start profiling, device num %d", device_num); return FAILED; @@ -799,7 +800,8 @@ FMK_FUNC_HOST_VISIBILITY FMK_FUNC_DEV_VISIBILITY Status ProfilingManager::ProfSt } auto device_id_ptr = std::unique_ptr(new (std::nothrow) uint32_t[device_num]); if (device_id_ptr == nullptr) { - GELOGE(FAILED, "[Stop][Profiling]Malloc buffer failed when stop profiling, device num %d", device_num); + GELOGE(FAILED, "[Stop][Profiling]Malloc buffer failed when stop profiling, device num %d", + device_num); REPORT_CALL_ERROR("E19999", "Malloc buffer failed when stop profiling, device num %d", device_num); return FAILED; diff --git a/ge/common/util.cc b/ge/common/util.cc index adec958c..bc5b74ca 100644 --- a/ge/common/util.cc +++ b/ge/common/util.cc @@ -288,8 +288,8 @@ FMK_FUNC_HOST_VISIBILITY FMK_FUNC_DEV_VISIBILITY bool ReadProtoFromText(const ch google::protobuf::io::IstreamInputStream input(&fs); bool ret = google::protobuf::TextFormat::Parse(&input, message); GE_IF_BOOL_EXEC(!ret, ErrorManager::GetInstance().ATCReportErrMessage("E19018", {"protofile"}, {file}); - GELOGE(ret, "[Parse][File]Through [google::protobuf::TextFormat::Parse] failed, file %s", - file)); + GELOGE(ret, "[Parse][File]Through [google::protobuf::TextFormat::Parse] failed, " + "file %s", file)); fs.close(); return ret; @@ -554,8 +554,8 @@ FMK_FUNC_HOST_VISIBILITY bool IsValidFile(const char *file_path) { return false; } if (stat.st_size > kMaxConfigFileByte) { - GELOGE(PARAM_INVALID, "[Check][Param]Config file %s size %ld is larger than max config file Bytes %u", - resolved_file_path.c_str(), stat.st_size, kMaxConfigFileByte); + GELOGE(PARAM_INVALID, "[Check][Param]Config file %s size %ld is larger than max config " + "file Bytes %u", resolved_file_path.c_str(), stat.st_size, kMaxConfigFileByte); REPORT_CALL_ERROR("E19999", "Config file %s size %ld is larger than max config file Bytes %u", resolved_file_path.c_str(), stat.st_size, kMaxConfigFileByte); return false; @@ -586,7 +586,8 @@ FMK_FUNC_HOST_VISIBILITY FMK_FUNC_DEV_VISIBILITY Status CheckPath(const char *pa INT32 is_dir = mmIsDir(path); if (is_dir != EN_OK) { - GELOGE(PATH_INVALID, "[Open][Directory]Failed, directory path %s, errmsg %s", path, strerror(errno)); + GELOGE(PATH_INVALID, "[Open][Directory]Failed, directory path %s, errmsg %s", + path, strerror(errno)); REPORT_CALL_ERROR("E19999", "Open directory %s failed, errmsg %s", path, strerror(errno)); return PATH_INVALID; } diff --git a/ge/engine_manager/dnnengine_manager.cc b/ge/engine_manager/dnnengine_manager.cc index 1425ddf6..9b48d47d 100644 --- a/ge/engine_manager/dnnengine_manager.cc +++ b/ge/engine_manager/dnnengine_manager.cc @@ -107,8 +107,8 @@ Status DNNEngineManager::Initialize(const std::map &op iter->second->GetAttributes(attrs); if (attrs.runtime_type == RuntimeType::DEVICE) { if ((attrs.mem_type.size()) != 1 || (attrs.mem_type[0] != GE_ENGINE_ATTR_MEM_TYPE_HBM)) { - GELOGE(GE_ENG_MEMTYPE_ERROR, "[Check][Param]Engine %s in aicore, but the memory type is not HBM, " - "mem_type_size %d", (iter->first).c_str(), attrs.mem_type.size()); + GELOGE(GE_ENG_MEMTYPE_ERROR, "[Check][Param]Engine %s in aicore, but the memory type is " + "not HBM, mem_type_size %d", (iter->first).c_str(), attrs.mem_type.size()); REPORT_CALL_ERROR("E19999", "Engine %s in aicore, but the memory type is not HBM, " "mem_type_size %d", (iter->first).c_str(), attrs.mem_type.size()); return GE_ENG_MEMTYPE_ERROR; @@ -246,7 +246,8 @@ std::string DNNEngineManager::GetDNNEngineName(const ge::NodePtr &node_ptr) { {kernel_name, op_desc->GetType(), op_desc->GetName()}); GELOGE(FAILED, "[Check][Param]The custom operator registered by the user does not support " - "the logic function delivered by this network, kernel_name %s, op type %s, op name %s", + "the logic function delivered by this network, kernel_name %s, op type %s, " + "op name %s", kernel_name.c_str(), op_desc->GetType().c_str(), op_desc->GetName().c_str()); std::string error_info = "The custom operator registered by the user does not support the logic function" "delivered by this network"; @@ -273,8 +274,9 @@ std::string DNNEngineManager::GetDNNEngineName(const ge::NodePtr &node_ptr) { reason += it.first + ":" + it.second + ";"; ErrorManager::GetInstance().ATCReportErrMessage( "E13002", {"optype", "opskernel", "reason"}, {op_desc->GetType(), it.first, it.second}); - GELOGE(GE_GRAPH_ASSIGN_ENGINE_FAILED, "[Concat][UnsupportedReasons]Op type %s of ops kernel %s is unsupported, " - "reason %s", op_desc->GetType().c_str(), it.first.c_str(), it.second.c_str()); + GELOGE(GE_GRAPH_ASSIGN_ENGINE_FAILED, "[Concat][UnsupportedReasons]Op type %s of ops kernel %s " + "is unsupported, reason %s", + op_desc->GetType().c_str(), it.first.c_str(), it.second.c_str()); } analyzer::DataInfo analyze_info{root_graph->GetSessionID(), root_graph->GetGraphID(), @@ -284,7 +286,8 @@ std::string DNNEngineManager::GetDNNEngineName(const ge::NodePtr &node_ptr) { ErrorManager::GetInstance().ATCReportErrMessage( "E13003", {"opname", "optype"}, {op_desc->GetName(), op_desc->GetType()}); - GELOGE(GE_GRAPH_ASSIGN_ENGINE_FAILED, "[Get][DNNEngineName]Can't find any supported ops kernel and engine of %s, type is %s", + GELOGE(GE_GRAPH_ASSIGN_ENGINE_FAILED, "[Get][DNNEngineName]Can't find any supported ops kernel " + "and engine of %s, type is %s", op_desc->GetName().c_str(), op_desc->GetType().c_str()); return ""; } @@ -335,10 +338,10 @@ Status DNNEngineManager::ParserJsonFile() { return FAILED; } if (!scheduler_utils_json.is_array()) { - GELOGE(FAILED, "[Check][Param]The message of kSchedulerUnits is not array and the file path is %s", - json_file_path.c_str()); - REPORT_CALL_ERROR("E19999", "The message of kSchedulerUnits is not array and the file path is %s", - json_file_path.c_str()); + GELOGE(FAILED, "[Check][Param]The message of kSchedulerUnits is not array and " + "the file path is %s", json_file_path.c_str()); + REPORT_CALL_ERROR("E19999", "The message of kSchedulerUnits is not array and " + "the file path is %s", json_file_path.c_str()); return FAILED; } auto size = scheduler_json_file[kSchedulerUnits].size(); @@ -362,7 +365,8 @@ Status DNNEngineManager::ParserJsonFile() { status = ParserEngineMessage(engines_json_map, scheduler_id_temp, engine_conf_map); if (status != SUCCESS) { GELOGE(FAILED, "[Parse][EngineMessage]Failed, scheduler_id_temp %s", scheduler_id_temp); - REPORT_CALL_ERROR("E19999", "Parse engine message failed, scheduler_id_temp %s", scheduler_id_temp); + REPORT_CALL_ERROR("E19999", "Parse engine message failed, scheduler_id_temp %s", + scheduler_id_temp); return FAILED; } scheduler_conf.name = scheduler_utils_json[i][kName]; @@ -372,8 +376,8 @@ Status DNNEngineManager::ParserJsonFile() { if (it != schedulers_.end()) { GELOGE(FAILED, "[Check][Param]There are the same scheduler ts %s in the json file", scheduler_id_temp.c_str()); - REPORT_CALL_ERROR("E19999", "[Check][Param]There are the same scheduler ts %s in the json file", - scheduler_id_temp.c_str()); + REPORT_CALL_ERROR("E19999", "[Check][Param]There are the same scheduler ts %s " + "in the json file", scheduler_id_temp.c_str()); return FAILED; } schedulers_.emplace(scheduler_id_temp, scheduler_conf); @@ -469,8 +473,10 @@ Status DNNEngineManager::ReadJsonFile(const std::string &file_path, JsonHandle h const char *file = file_path.data(); if ((mmAccess2(file, M_F_OK)) != EN_OK) { if (engines_map_.size() != 0) { - GELOGE(FAILED, "[Check][Param]The json file %s not exists, err %s", file_path.c_str(), strerror(errno)); - REPORT_CALL_ERROR("E19999", "Json file %s not exists, err %s", file_path.c_str(), strerror(errno)); + GELOGE(FAILED, "[Check][Param]The json file %s not exists, err %s", + file_path.c_str(), strerror(errno)); + REPORT_CALL_ERROR("E19999", "Json file %s not exists, err %s", + file_path.c_str(), strerror(errno)); return FAILED; } else { GELOGW("The json file %s is not needed.", file_path.c_str()); From 9579447c563b6217ed9540dbeffb5cdf9f90c2f5 Mon Sep 17 00:00:00 2001 From: "liyihan2@huawei.com" Date: Wed, 28 Apr 2021 15:33:03 +0800 Subject: [PATCH 04/11] common log optimize --- ge/engine_manager/dnnengine_manager.cc | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/ge/engine_manager/dnnengine_manager.cc b/ge/engine_manager/dnnengine_manager.cc index 9b48d47d..6095edb5 100644 --- a/ge/engine_manager/dnnengine_manager.cc +++ b/ge/engine_manager/dnnengine_manager.cc @@ -450,7 +450,7 @@ Status DNNEngineManager::ParserEngineMessage(const json engines_json, const std: } } catch (const json::exception &e) { GELOGE(FAILED, "[Construct][JsonContent]Failed, reason %s", e.what()); - REPORT_CALL_ERROR("E19999", "Construct json content failed, reason %s", e.what()) + REPORT_CALL_ERROR("E19999", "Construct json content failed, reason %s", e.what()); return FAILED; } GELOGI("Parser engine massage success"); From 6c3e42487b63bf19a549844cba3b234653096909 Mon Sep 17 00:00:00 2001 From: "liyihan2@huawei.com" Date: Wed, 28 Apr 2021 16:01:10 +0800 Subject: [PATCH 05/11] common log optimize --- ge/engine_manager/dnnengine_manager.cc | 8 ++++---- 1 file changed, 4 insertions(+), 4 deletions(-) diff --git a/ge/engine_manager/dnnengine_manager.cc b/ge/engine_manager/dnnengine_manager.cc index 6095edb5..4f57b466 100644 --- a/ge/engine_manager/dnnengine_manager.cc +++ b/ge/engine_manager/dnnengine_manager.cc @@ -108,9 +108,9 @@ Status DNNEngineManager::Initialize(const std::map &op if (attrs.runtime_type == RuntimeType::DEVICE) { if ((attrs.mem_type.size()) != 1 || (attrs.mem_type[0] != GE_ENGINE_ATTR_MEM_TYPE_HBM)) { GELOGE(GE_ENG_MEMTYPE_ERROR, "[Check][Param]Engine %s in aicore, but the memory type is " - "not HBM, mem_type_size %d", (iter->first).c_str(), attrs.mem_type.size()); + "not HBM, mem_type_size %lu", (iter->first).c_str(), attrs.mem_type.size()); REPORT_CALL_ERROR("E19999", "Engine %s in aicore, but the memory type is not HBM, " - "mem_type_size %d", (iter->first).c_str(), attrs.mem_type.size()); + "mem_type_size %lu", (iter->first).c_str(), attrs.mem_type.size()); return GE_ENG_MEMTYPE_ERROR; } } @@ -364,9 +364,9 @@ Status DNNEngineManager::ParserJsonFile() { } status = ParserEngineMessage(engines_json_map, scheduler_id_temp, engine_conf_map); if (status != SUCCESS) { - GELOGE(FAILED, "[Parse][EngineMessage]Failed, scheduler_id_temp %s", scheduler_id_temp); + GELOGE(FAILED, "[Parse][EngineMessage]Failed, scheduler_id_temp %s", scheduler_id_temp.c_str()); REPORT_CALL_ERROR("E19999", "Parse engine message failed, scheduler_id_temp %s", - scheduler_id_temp); + scheduler_id_temp.c_str()); return FAILED; } scheduler_conf.name = scheduler_utils_json[i][kName]; From 3469a1093c46abdb5724f782399bff5b594149ff Mon Sep 17 00:00:00 2001 From: "liyihan2@huawei.com" Date: Thu, 29 Apr 2021 11:00:59 +0800 Subject: [PATCH 06/11] common log optimize --- ge/common/model_parser/model_parser.cc | 5 +-- ge/common/util.cc | 8 ++-- ge/engine_manager/dnnengine_manager.cc | 52 +++++++++++++------------- 3 files changed, 31 insertions(+), 34 deletions(-) diff --git a/ge/common/model_parser/model_parser.cc b/ge/common/model_parser/model_parser.cc index 0d320938..ce654887 100644 --- a/ge/common/model_parser/model_parser.cc +++ b/ge/common/model_parser/model_parser.cc @@ -31,10 +31,9 @@ FMK_FUNC_HOST_VISIBILITY FMK_FUNC_DEV_VISIBILITY Status ModelParserBase::LoadFro ge::ModelData &model_data) { std::string real_path = RealPath(model_path); if (real_path.empty()) { - GELOGE(ACL_ERROR_GE_EXEC_MODEL_PATH_INVALID, "Model file path '%s' is invalid", model_path); GELOGE(ACL_ERROR_GE_EXEC_MODEL_PATH_INVALID, "[Check][Param]Model file path %s is invalid", model_path); - REPORT_INNER_ERROR("E19999", "Model file path %s is invalid", model_path); + REPORT_CALL_ERROR("E19999", "Model file path %s is invalid", model_path); return ACL_ERROR_GE_EXEC_MODEL_PATH_INVALID; } @@ -117,7 +116,7 @@ FMK_FUNC_HOST_VISIBILITY FMK_FUNC_DEV_VISIBILITY Status ModelParserBase::ParseMo GELOGD("Model_len is %u, model_file_head_len is %zu.", model_len, sizeof(ModelFileHeader)); } else { GELOGE(ACL_ERROR_GE_PARAM_INVALID, "[Check][Param]Invalid, model encrypt type not supported"); - REPORT_CALL_ERROR("E19999","Invalid model ,encrypt type not supported"); + REPORT_CALL_ERROR("E19999","Invalid model, encrypt type not supported"); res = ACL_ERROR_GE_PARAM_INVALID; } diff --git a/ge/common/util.cc b/ge/common/util.cc index bc5b74ca..7a600d09 100644 --- a/ge/common/util.cc +++ b/ge/common/util.cc @@ -252,8 +252,8 @@ FMK_FUNC_HOST_VISIBILITY FMK_FUNC_DEV_VISIBILITY std::string CurrentTimeInStr() std::time_t now = std::time(nullptr); std::tm *ptm = std::localtime(&now); if (ptm == nullptr) { - GELOGE(ge::FAILED, "[Check][Param]Localtime incorrect"); - REPORT_CALL_ERROR("E19999", "Localtime incorrect"); + GELOGE(ge::FAILED, "[Check][Param]Localtime incorrect, errmsg %s", strerror(errno)); + REPORT_CALL_ERROR("E19999", "Localtime incorrect, errmsg", strerror(errno)); return ""; } @@ -532,8 +532,8 @@ FMK_FUNC_HOST_VISIBILITY bool IsValidFile(const char *file_path) { // Normalize the path std::string resolved_file_path = RealPath(file_path); if (resolved_file_path.empty()) { - GELOGE(PARAM_INVALID, "[Check][Param]Invalid input file path %s", file_path); - REPORT_CALL_ERROR("E19999", "Invalid input file path %s", file_path); + GELOGE(PARAM_INVALID, "[Check][Param]Invalid input file path %s, errmsg %s", file_path, strerror(errno)); + REPORT_CALL_ERROR("E19999", "Invalid input file path %s, errmsg %s", file_path, strerror(errno)); return false; } diff --git a/ge/engine_manager/dnnengine_manager.cc b/ge/engine_manager/dnnengine_manager.cc index 4f57b466..e9dde746 100644 --- a/ge/engine_manager/dnnengine_manager.cc +++ b/ge/engine_manager/dnnengine_manager.cc @@ -78,8 +78,8 @@ Status DNNEngineManager::Initialize(const std::map &op status = plugin_mgr_.InvokeAll &>(so_api_func, engines_map_); if (status != SUCCESS) { - GELOGE(status, "[Get][DNNEngineObjs]Failed"); - REPORT_CALL_ERROR("E19999", "Get DNNEngineObjs failed"); + GELOGE(status, "[Get][DNNEngineObjs]Failed, so_api_func %s", so_api_fun.c_str()); + REPORT_CALL_ERROR("E19999", "Get DNNEngineObjs failed, so_api_func %s", so_api_func.c_str()); return status; } @@ -109,7 +109,7 @@ Status DNNEngineManager::Initialize(const std::map &op if ((attrs.mem_type.size()) != 1 || (attrs.mem_type[0] != GE_ENGINE_ATTR_MEM_TYPE_HBM)) { GELOGE(GE_ENG_MEMTYPE_ERROR, "[Check][Param]Engine %s in aicore, but the memory type is " "not HBM, mem_type_size %lu", (iter->first).c_str(), attrs.mem_type.size()); - REPORT_CALL_ERROR("E19999", "Engine %s in aicore, but the memory type is not HBM, " + REPORT_INNER_ERROR("E19999", "Engine %s in aicore, but the memory type is not HBM, " "mem_type_size %lu", (iter->first).c_str(), attrs.mem_type.size()); return GE_ENG_MEMTYPE_ERROR; } @@ -119,14 +119,12 @@ Status DNNEngineManager::Initialize(const std::map &op status = ParserJsonFile(); if (status != SUCCESS) { GELOGE(status, "[Parse][JsonFile]Failed"); - REPORT_CALL_ERROR("E19999", "Parse json file failed"); return status; } status = CheckJsonFile(); if (status != SUCCESS) { GELOGE(status, "[Check][JsonFile]Failed"); - REPORT_CALL_ERROR("E19999", "Check json file failed"); return status; } @@ -198,8 +196,8 @@ std::string DNNEngineManager::GetDNNEngineName(const ge::NodePtr &node_ptr) { // Use the OpsKernelManager in GELib to get the opInfos for this opCode std::shared_ptr instance_ptr = ge::GELib::GetInstance(); if ((instance_ptr == nullptr) || (!instance_ptr->InitFlag())) { - GELOGE(GE_CLI_GE_NOT_INITIALIZED, "[Get][DNNEngineName]Failed, instance_ptr is null"); - REPORT_CALL_ERROR("E19999", "Get DNNEngineName failed, instance_ptr is null"); + GELOGE(GE_CLI_GE_NOT_INITIALIZED, "[Get][DNNEngineName]Failed, gelib not init before"); + REPORT_INNER_ERROR("E19999", "Get DNNEngineName failed, gelib not init before"); return ""; } OpsKernelManager &ops_kernel_manager = instance_ptr->OpsKernelManagerObj(); @@ -274,7 +272,7 @@ std::string DNNEngineManager::GetDNNEngineName(const ge::NodePtr &node_ptr) { reason += it.first + ":" + it.second + ";"; ErrorManager::GetInstance().ATCReportErrMessage( "E13002", {"optype", "opskernel", "reason"}, {op_desc->GetType(), it.first, it.second}); - GELOGE(GE_GRAPH_ASSIGN_ENGINE_FAILED, "[Concat][UnsupportedReasons]Op type %s of ops kernel %s " + GELOGE(GE_GRAPH_ASSIGN_ENGINE_FAILED, "[Check][OpSupported]Op type %s of ops kernel %s " "is unsupported, reason %s", op_desc->GetType().c_str(), it.first.c_str(), it.second.c_str()); } @@ -305,7 +303,7 @@ std::string DNNEngineManager::GetHostCpuEngineName(const std::vector &op } GELOGE(FAILED, "[Get][HostCpuEngineName]Failed, HostCpuEngine not support [%s, %s]", op_desc->GetName().c_str(), op_desc->GetType().c_str()); - REPORT_CALL_ERROR("E19999", "Get HostCpuEngineName failed, HostCpuEngine not support [%s, %s]", + REPORT_INNER_ERROR("E19999", "Get HostCpuEngineName failed, HostCpuEngine not support [%s, %s]", op_desc->GetName().c_str(), op_desc->GetType().c_str()); return ""; } @@ -333,15 +331,15 @@ Status DNNEngineManager::ParserJsonFile() { try { nlohmann::json scheduler_utils_json = scheduler_json_file[kSchedulerUnits]; if (scheduler_utils_json.is_null()) { - GELOGE(FAILED, "[Check[Param]Find scheduler units failed, the message is null"); - REPORT_CALL_ERROR("E19999", "Find scheduler units failed, the message is null"); + GELOGE(FAILED, "[Check[Param]Find scheduler units failed, the message is null, file %s", path.c_str()); + REPORT_INNER_ERROR("E19999", "Find scheduler units failed, the message is null, file %s", path.c_str()); return FAILED; } if (!scheduler_utils_json.is_array()) { GELOGE(FAILED, "[Check][Param]The message of kSchedulerUnits is not array and " - "the file path is %s", json_file_path.c_str()); - REPORT_CALL_ERROR("E19999", "The message of kSchedulerUnits is not array and " - "the file path is %s", json_file_path.c_str()); + "the file path is %s", path.c_str()); + REPORT_INNER_ERROR("E19999", "The message of kSchedulerUnits is not array and " + "the file path is %s", path.c_str()); return FAILED; } auto size = scheduler_json_file[kSchedulerUnits].size(); @@ -350,16 +348,16 @@ Status DNNEngineManager::ParserJsonFile() { std::map engine_conf_map; nlohmann::json engines_json_map = scheduler_utils_json[i][kCalEngines]; if (engines_json_map.is_null()) { - GELOGE(FAILED, "[Check][Param]The message of cal_engines is null"); - REPORT_CALL_ERROR("E19999", "The message of cal_engines is null"); + GELOGE(FAILED, "[Check][Param]The message of cal_engines is null, file %s", path.c_str()); + REPORT_INNER_ERROR("E19999", "The message of cal_engines is null, file %s", path.c_str()); return FAILED; } std::string scheduler_id_temp = scheduler_utils_json[i][kId]; if (!scheduler_id_temp.empty()) { scheduler_conf.id = scheduler_id_temp; } else { - GELOGE(FAILED, "[Check][Param]Scheduler ID is null"); - REPORT_CALL_ERROR("E19999", "Scheduler ID is null"); + GELOGE(FAILED, "[Check][Param]Scheduler ID is null, file %s", path.c_str()); + REPORT_INNER_ERROR("E19999", "Scheduler ID is null, file %s", path.c_str()); return FAILED; } status = ParserEngineMessage(engines_json_map, scheduler_id_temp, engine_conf_map); @@ -376,15 +374,15 @@ Status DNNEngineManager::ParserJsonFile() { if (it != schedulers_.end()) { GELOGE(FAILED, "[Check][Param]There are the same scheduler ts %s in the json file", scheduler_id_temp.c_str()); - REPORT_CALL_ERROR("E19999", "[Check][Param]There are the same scheduler ts %s " + REPORT_INNER_ERROR("E19999", "[Check][Param]There are the same scheduler ts %s " "in the json file", scheduler_id_temp.c_str()); return FAILED; } schedulers_.emplace(scheduler_id_temp, scheduler_conf); } } catch (const nlohmann::detail::type_error &e) { - GELOGE(FAILED, "[Parse][JsonFile]Failed, reason %s", e.what()); - REPORT_CALL_ERROR("E19999", "Parse json file failed, reason %s", e.what()); + GELOGE(FAILED, "[Parse][JsonFile]Failed, file %s, reason %s", path.c_str(), e.what()); + REPORT_CALL_ERROR("E19999", "Parse json file %s failed, reason %s", path.c_str(), e.what()); return FAILED; } @@ -413,7 +411,7 @@ Status DNNEngineManager::ParserEngineMessage(const json engines_json, const std: engine_conf_ptr->id = engine_id; } else { GELOGE(FAILED, "[Check][Param]Engine ID is null"); - REPORT_CALL_ERROR("E19999", "Engine ID is null"); + REPORT_INNER_ERROR("E19999", "Engine ID is null"); return FAILED; } if (engines_elems.find(kName) != engines_elems.end()) { @@ -437,7 +435,7 @@ Status DNNEngineManager::ParserEngineMessage(const json engines_json, const std: if (it != engines.end()) { GELOGE(FAILED, "[Check][Param]There are the same engine %s message in the json file", engine_id.c_str()); - REPORT_CALL_ERROR("E19999", "There are the same engine %s message in the json file", + REPORT_INNER_ERROR("E19999", "There are the same engine %s message in the json file", engine_id.c_str()); return FAILED; } @@ -445,12 +443,12 @@ Status DNNEngineManager::ParserEngineMessage(const json engines_json, const std: } } else { GELOGE(FAILED, "[Check][Param]The message of cal_engines is not array in the json file"); - REPORT_CALL_ERROR("E19999", "The message of cal_engines is not array in the json file"); + REPORT_INNER_ERROR("E19999", "The message of cal_engines is not array in the json file"); return FAILED; } } catch (const json::exception &e) { GELOGE(FAILED, "[Construct][JsonContent]Failed, reason %s", e.what()); - REPORT_CALL_ERROR("E19999", "Construct json content failed, reason %s", e.what()); + REPORT_INNER_ERROR("E19999", "Construct json content failed, reason %s", e.what()); return FAILED; } GELOGI("Parser engine massage success"); @@ -460,8 +458,8 @@ Status DNNEngineManager::ParserEngineMessage(const json engines_json, const std: Status DNNEngineManager::ReadJsonFile(const std::string &file_path, JsonHandle handle) { GELOGD("Begin to read json file"); if (file_path.empty()) { - GELOGE(FAILED, "[Check][Param]Json path %s is invalid", file_path.c_str()); - REPORT_CALL_ERROR("E19999", "Json path %s is invalid", file_path.c_str()); + GELOGE(FAILED, "[Check][Param]Json path is invalid"); + REPORT_INNER_ERROR("E19999", "Json path is invalid"); return FAILED; } nlohmann::json *json_file = reinterpret_cast(handle); From b8b05a5f4dd486385df0c6cc408b696351e27d33 Mon Sep 17 00:00:00 2001 From: "liyihan2@huawei.com" Date: Thu, 29 Apr 2021 14:19:04 +0800 Subject: [PATCH 07/11] common log optimize --- ge/common/util.cc | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/ge/common/util.cc b/ge/common/util.cc index 7a600d09..6887b096 100644 --- a/ge/common/util.cc +++ b/ge/common/util.cc @@ -253,7 +253,7 @@ FMK_FUNC_HOST_VISIBILITY FMK_FUNC_DEV_VISIBILITY std::string CurrentTimeInStr() std::tm *ptm = std::localtime(&now); if (ptm == nullptr) { GELOGE(ge::FAILED, "[Check][Param]Localtime incorrect, errmsg %s", strerror(errno)); - REPORT_CALL_ERROR("E19999", "Localtime incorrect, errmsg", strerror(errno)); + REPORT_CALL_ERROR("E19999", "Localtime incorrect, errmsg %s", strerror(errno)); return ""; } From 1361d2948aa850730646def76496c144bae8845c Mon Sep 17 00:00:00 2001 From: "liyihan2@huawei.com" Date: Thu, 29 Apr 2021 14:27:50 +0800 Subject: [PATCH 08/11] common log optimize --- ge/engine_manager/dnnengine_manager.cc | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/ge/engine_manager/dnnengine_manager.cc b/ge/engine_manager/dnnengine_manager.cc index e9dde746..79d9264d 100644 --- a/ge/engine_manager/dnnengine_manager.cc +++ b/ge/engine_manager/dnnengine_manager.cc @@ -78,7 +78,7 @@ Status DNNEngineManager::Initialize(const std::map &op status = plugin_mgr_.InvokeAll &>(so_api_func, engines_map_); if (status != SUCCESS) { - GELOGE(status, "[Get][DNNEngineObjs]Failed, so_api_func %s", so_api_fun.c_str()); + GELOGE(status, "[Get][DNNEngineObjs]Failed, so_api_func %s", so_api_func.c_str()); REPORT_CALL_ERROR("E19999", "Get DNNEngineObjs failed, so_api_func %s", so_api_func.c_str()); return status; } From b43d62078a6dd50ac1d20c941daab2870433956c Mon Sep 17 00:00:00 2001 From: "liyihan2@huawei.com" Date: Thu, 29 Apr 2021 15:37:48 +0800 Subject: [PATCH 09/11] common log optimize --- ge/engine_manager/dnnengine_manager.cc | 4 ++-- ge/graph/passes/input_output_connection_identify_pass.cc | 2 -- 2 files changed, 2 insertions(+), 4 deletions(-) diff --git a/ge/engine_manager/dnnengine_manager.cc b/ge/engine_manager/dnnengine_manager.cc index 79d9264d..7a3f7aec 100644 --- a/ge/engine_manager/dnnengine_manager.cc +++ b/ge/engine_manager/dnnengine_manager.cc @@ -458,8 +458,8 @@ Status DNNEngineManager::ParserEngineMessage(const json engines_json, const std: Status DNNEngineManager::ReadJsonFile(const std::string &file_path, JsonHandle handle) { GELOGD("Begin to read json file"); if (file_path.empty()) { - GELOGE(FAILED, "[Check][Param]Json path is invalid"); - REPORT_INNER_ERROR("E19999", "Json path is invalid"); + GELOGE(FAILED, "[Check][Param]Json path is empty"); + REPORT_INNER_ERROR("E19999", "Json path is empty"); return FAILED; } nlohmann::json *json_file = reinterpret_cast(handle); diff --git a/ge/graph/passes/input_output_connection_identify_pass.cc b/ge/graph/passes/input_output_connection_identify_pass.cc index 6e2b3049..e27c2e1f 100644 --- a/ge/graph/passes/input_output_connection_identify_pass.cc +++ b/ge/graph/passes/input_output_connection_identify_pass.cc @@ -48,8 +48,6 @@ Status InputOutputConnectionIdentifyPass::Run(ComputeGraphPtr graph) { } if (graph->GetParentGraph() != nullptr) { - REPORT_INNER_ERROR("E19999", "Param graph's parent graph is nullptr, " - "check invalid"); GELOGD("Current graph %s is a subgraph, skip identification of nodes that connect to input and output.", graph->GetName().c_str()); return SUCCESS; From 00cd307cbc08e572023d79ae17130bbea0e96968 Mon Sep 17 00:00:00 2001 From: "liyihan2@huawei.com" Date: Thu, 29 Apr 2021 15:47:31 +0800 Subject: [PATCH 10/11] common log optimize --- ge/common/profiling/ge_profiling.cc | 8 ++++---- 1 file changed, 4 insertions(+), 4 deletions(-) diff --git a/ge/common/profiling/ge_profiling.cc b/ge/common/profiling/ge_profiling.cc index 3f885a91..b784726b 100644 --- a/ge/common/profiling/ge_profiling.cc +++ b/ge/common/profiling/ge_profiling.cc @@ -136,8 +136,8 @@ ge::Status RegProfSetDeviceCallback(MsprofSetDeviceCallback func) { // Pass MsprofSetDeviceCallback to runtime ge::Status rt_ret = rtRegDeviceStateCallback(kRtSetDeviceRegName.c_str(), static_cast(func)); if (rt_ret != ge::SUCCESS) { - GELOGE(rt_ret, "[Pass][MsprofSetDeviceCallback]To runtime failed!"); - REPORT_CALL_ERROR("E19999", "Pass MsprofSetDeviceCallback to runtime failed, ret 0x%X", rt_ret); + GELOGE(rt_ret, "[Pass][MsprofSetDeviceCallback]To runtime failed, ret 0x%X", ret); + REPORT_CALL_ERROR("E19999", "Pass MsprofSetDeviceCallback to runtime failed, ret 0x%X", rt_ret); return rt_ret; } return ge::SUCCESS; @@ -183,7 +183,7 @@ ge::Status ProfCommandHandle(ProfCommandHandleType type, void *data, uint32_t le if (!isProfConfigValid(prof_config_param->devIdList, prof_config_param->devNums)) { return ge::FAILED; } - + if (!TransProfConfigToParam(*prof_config_param, prof_params)) { GELOGE(ge::PARAM_INVALID, "[Check][Param]Transfer profilerConfig to string vector failed"); REPORT_CALL_ERROR("E19999", "Transfer profilerConfig to string vector failed"); @@ -208,7 +208,7 @@ ge::Status ProfCommandHandle(ProfCommandHandleType type, void *data, uint32_t le GELOGE(ret, "[Handle][Command]Handle profiling command failed, command type %s, error_code %u", iter->second.c_str(), ret); REPORT_CALL_ERROR("E19999", "Handle profiling command failed, command type %s, error_code %u", - iter->second.c_str(), ret); + iter->second.c_str(), ret); return ge::FAILED; } From 3a5b6c96ee4e43d23f2bd4e38735a15c073c52d4 Mon Sep 17 00:00:00 2001 From: "liyihan2@huawei.com" Date: Thu, 29 Apr 2021 15:52:15 +0800 Subject: [PATCH 11/11] common log optimize --- ge/common/profiling/ge_profiling.cc | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/ge/common/profiling/ge_profiling.cc b/ge/common/profiling/ge_profiling.cc index b784726b..5e892ff8 100644 --- a/ge/common/profiling/ge_profiling.cc +++ b/ge/common/profiling/ge_profiling.cc @@ -136,7 +136,7 @@ ge::Status RegProfSetDeviceCallback(MsprofSetDeviceCallback func) { // Pass MsprofSetDeviceCallback to runtime ge::Status rt_ret = rtRegDeviceStateCallback(kRtSetDeviceRegName.c_str(), static_cast(func)); if (rt_ret != ge::SUCCESS) { - GELOGE(rt_ret, "[Pass][MsprofSetDeviceCallback]To runtime failed, ret 0x%X", ret); + GELOGE(rt_ret, "[Pass][MsprofSetDeviceCallback]To runtime failed, ret 0x%X", rt_ret); REPORT_CALL_ERROR("E19999", "Pass MsprofSetDeviceCallback to runtime failed, ret 0x%X", rt_ret); return rt_ret; }