已合并
fix:improve log usability-0907 #4771
fix:improve log usability-0907 #4771
已合并
洪跃城创建于 21 天前
共 15 个文件变更+30-30
@@ -605,7 +605,7 @@ static const char_t *TransTensorNameToReal(const aclmdlDesc *const modelDesc, co
605 std::vector<std::string> valArr;605 std::vector<std::string> valArr;
606 acl::StringUtils::Split(tensorName, '_', valArr);606 acl::StringUtils::Split(tensorName, '_', valArr);
607 if ((valArr.size() != TENSOR_NAME_ATTR_NUM) && (valArr.size() != (TENSOR_NAME_ATTR_NUM + 1U))) {607 if ((valArr.size() != TENSOR_NAME_ATTR_NUM) && (valArr.size() != (TENSOR_NAME_ATTR_NUM + 1U))) {
608- ACL_LOG_INNER_ERROR("[Check][Params]tensorName[%s] cannot be devided into %zu parts", tensorName.c_str(),608+ ACL_LOG_INNER_ERROR("[Check][Params]tensorName[%s] cannot be divided into %zu parts", tensorName.c_str(),
609 TENSOR_NAME_ATTR_NUM);609 TENSOR_NAME_ATTR_NUM);
610 return nullptr;610 return nullptr;
611 }611 }
@@ -271,7 +271,7 @@ void *HostCpuEngine::DlopenLib(const std::string &lib_path) const {
271 const char_t *error = mmDlerror();271 const char_t *error = mmDlerror();
272 error = (error == nullptr) ? "" : error;272 error = (error == nullptr) ? "" : error;
273 GELOGW(273 GELOGW(
274- "[Invoke][DlOpen] failed. path = %s, error = %s. It does not affect subsequenet processing and "274+ "[Invoke][DlOpen] failed. path = %s, error = %s. It does not affect subsequent processing and "
275 "can proceed in non-foldable mode",275 "can proceed in non-foldable mode",
276 lib_path.c_str(), error);276 lib_path.c_str(), error);
277 }277 }
@@ -120,7 +120,7 @@ graphStatus CalOutputSymbolValue(gert::InferSymbolComputeContext *context, const
120 const int64_t block_num =120 const int64_t block_num =
121 static_cast<int64_t>(param_values.size()) / outer_loop_num / block_size / param_dims[static_cast<size_t>(axis)];121 static_cast<int64_t>(param_values.size()) / outer_loop_num / block_size / param_dims[static_cast<size_t>(axis)];
122 const int64_t outer_block_size = static_cast<int64_t>(param_values.size()) / outer_loop_num;122 const int64_t outer_block_size = static_cast<int64_t>(param_values.size()) / outer_loop_num;
123- GELOGD("param total size: %zu, indice total size:%zu, axis dim num: %lld, node %s[%s].", param_values.size(),123+ GELOGD("param total size: %zu, indices total size:%zu, axis dim num: %lld, node %s[%s].", param_values.size(),
124 indice_values.size(), param_dims[static_cast<size_t>(axis)], context->GetNodeName(), context->GetNodeType());124 indice_values.size(), param_dims[static_cast<size_t>(axis)], context->GetNodeName(), context->GetNodeType());
125 for (int64_t i = 0L; i < outer_loop_num; i++) {125 for (int64_t i = 0L; i < outer_loop_num; i++) {
126 for (int64_t j = 0L; j < block_num; j++) {126 for (int64_t j = 0L; j < block_num; j++) {
@@ -128,7 +128,7 @@ graphStatus CalOutputSymbolValue(gert::InferSymbolComputeContext *context, const
128 int64_t gather_index = indice_values[static_cast<size_t>(k + indice_block_size * i)];128 int64_t gather_index = indice_values[static_cast<size_t>(k + indice_block_size * i)];
129 GE_ASSERT_TRUE(129 GE_ASSERT_TRUE(
130 gather_index < param_dims[static_cast<size_t>(axis)],130 gather_index < param_dims[static_cast<size_t>(axis)],
131- "SymbolicKernel compute failed, reason: indice index:%lld should be less than axis:%lld dim:%lld, "131+ "SymbolicKernel compute failed, reason: indices index:%lld should be less than axis:%lld dim:%lld, "
132 "node %s[%s].",132 "node %s[%s].",
133 gather_index, axis, param_dims[axis], context->GetNodeName(), context->GetNodeType());133 gather_index, axis, param_dims[axis], context->GetNodeName(), context->GetNodeType());
134 const auto start_iter =134 const auto start_iter =
@@ -73,7 +73,7 @@ Status ForPass::Run(NodePtr &node) {
73 return FAILED;73 return FAILED;
74 }74 }
75 75 
76- GE_CHK_STATUS_RET(UpdateForBodyInputMapping(while_info), "[Update][InputMapping] for for-body-graph failed, node:%s.",76+ GE_CHK_STATUS_RET(UpdateForBodyInputMapping(while_info), "[Update][InputMapping] for-body-graph failed, node:%s.",
77 node->GetName().c_str());77 node->GetName().c_str());
78 78 
79 // for node has and only has one subgraph79 // for node has and only has one subgraph
@@ -610,7 +610,7 @@ void BinaryManager::GetConstValue(const std::string &key, std::string &dtype, js
610 if (iter != constValue.end()) {610 if (iter != constValue.end()) {
611 valueJson = iter.value();611 valueJson = iter.value();
612 } else {612 } else {
613- TE_DBGLOGF("Get const value value did not succeed.");613+ TE_DBGLOGF("Get const value did not succeed.");
614 }614 }
615}615}
616 616 
@@ -573,7 +573,7 @@ int64_t TeCacheSpaceManager::GetCacheSpaceMaxSizeCfg() {
573 return DEFAULT_MAX_OP_CACHE_SIZE * SIZE_MB_UNIT;573 return DEFAULT_MAX_OP_CACHE_SIZE * SIZE_MB_UNIT;
574 }574 }
575 if (maxSizeIntCfg == 0 || maxSizeIntCfg < CACHE_AGING_FUCNTION_SWITCH || maxSizeIntCfg >= INT_MAX) {575 if (maxSizeIntCfg == 0 || maxSizeIntCfg < CACHE_AGING_FUCNTION_SWITCH || maxSizeIntCfg >= INT_MAX) {
576- TE_WARNLOGF("ASCEND_MAX_OP_CACHE_SIZE[%s] is invalid, it should be -1 or [1, %ld), use default size:500.",576+ TE_WARNLOGF("ASCEND_MAX_OP_CACHE_SIZE[%s] is invalid, it should be -1 or [1, %ld), use default size:500 MB.",
577 maxCacheSizeCfg.c_str(), INT_MAX);577 maxCacheSizeCfg.c_str(), INT_MAX);
578 std::map<std::string, std::string> maxSizeMap = {{"invalid_value", maxCacheSizeCfg},578 std::map<std::string, std::string> maxSizeMap = {{"invalid_value", maxCacheSizeCfg},
579 {"argument", "ASCEND_MAX_OP_CACHE_SIZE"}};579 {"argument", "ASCEND_MAX_OP_CACHE_SIZE"}};
@@ -2228,12 +2228,12 @@ Status DeployPlannerBase::AssignDynamicSchedDequeueQueue(const DeployPlan::Queue
2228 if (queue_info.queue_action == DeployPlan::QueueAction::kStatus) {2228 if (queue_info.queue_action == DeployPlan::QueueAction::kStatus) {
2229 auto &submodel_info = MutableSubmodelInfo(model_instance_name);2229 auto &submodel_info = MutableSubmodelInfo(model_instance_name);
2230 submodel_info.status_input_queue_indices.push_back(dst_endpoint_idx);2230 submodel_info.status_input_queue_indices.push_back(dst_endpoint_idx);
2231- GELOGI("DynamicSched, add status input indices, model instance name=%s, input indice=%d.",2231+ GELOGI("DynamicSched, add status input indices, model instance name=%s, input indices=%d.",
2232 model_instance_name.c_str(), dst_endpoint_idx);2232 model_instance_name.c_str(), dst_endpoint_idx);
2233 } else {2233 } else {
2234 auto &submodel_info = MutableSubmodelInfo(model_instance_name);2234 auto &submodel_info = MutableSubmodelInfo(model_instance_name);
2235 submodel_info.sched_input_queue_indices.push_back(dst_endpoint_idx);2235 submodel_info.sched_input_queue_indices.push_back(dst_endpoint_idx);
2236- GELOGI("DynamicSched, add sched input indices, model instance name=%s, input indice=%d.",2236+ GELOGI("DynamicSched, add sched input indices, model instance name=%s, input indices=%d.",
2237 model_instance_name.c_str(), dst_endpoint_idx);2237 model_instance_name.c_str(), dst_endpoint_idx);
2238 deploy_plan_.dynamic_sched_plan_.datagw_request_bindings_[src_endpoint_idx] = dst_endpoint_idx;2238 deploy_plan_.dynamic_sched_plan_.datagw_request_bindings_[src_endpoint_idx] = dst_endpoint_idx;
2239 GELOGI("DynamicSched, datagw request bindings, datagw input=%d, sched app output=%d.", dst_endpoint_idx,2239 GELOGI("DynamicSched, datagw request bindings, datagw input=%d, sched app output=%d.", dst_endpoint_idx,
@@ -586,17 +586,17 @@ Status DeployContext::SetDynamicSchedModelInfo(deployer::ExecutorRequest_LoadMod
586 auto *const status_queues_def = model_info->mutable_status_queues();586 auto *const status_queues_def = model_info->mutable_status_queues();
587 SetModelQueuesAttrs(submodel_desc.model_instance_name(), model_input_queues, model_output_queues, *status_queues_def);587 SetModelQueuesAttrs(submodel_desc.model_instance_name(), model_input_queues, model_output_queues, *status_queues_def);
588 for (size_t i = 0U; i < model_input_queues.size(); i++) {588 for (size_t i = 0U; i < model_input_queues.size(); i++) {
589- GELOGI("DynamicSched, add model info to load request, name=%s, status input indice=%d, phy input id=%d",589+ GELOGI("DynamicSched, add model info to load request, name=%s, status input index=%d, phy input id=%d",
590 submodel_desc.model_name().c_str(), submodel_desc.status_input_queue_indices()[i],590 submodel_desc.model_name().c_str(), submodel_desc.status_input_queue_indices()[i],
591 model_input_queues[i].queue_id);591 model_input_queues[i].queue_id);
592 }592 }
593 for (size_t i = 0U; i < model_output_queues.size(); i++) {593 for (size_t i = 0U; i < model_output_queues.size(); i++) {
594- GELOGI("DynamicSched, add model info to load request, name=%s, status output indice=%d, phy output id=%d",594+ GELOGI("DynamicSched, add model info to load request, name=%s, status output index=%d, phy output id=%d",
595 submodel_desc.model_name().c_str(), submodel_desc.status_output_queue_indices()[i],595 submodel_desc.model_name().c_str(), submodel_desc.status_output_queue_indices()[i],
596 model_output_queues[i].queue_id);596 model_output_queues[i].queue_id);
597 }597 }
598 for (auto &indice : submodel_desc.input_queue_indices()) {598 for (auto &indice : submodel_desc.input_queue_indices()) {
599- GELOGI("DynamicSched, add model info to load request, name=%s, logic input indice=%d",599+ GELOGI("DynamicSched, add model info to load request, name=%s, logic input index=%d",
600 submodel_desc.model_name().c_str(), indice);600 submodel_desc.model_name().c_str(), indice);
601 }601 }
602 uint32_t model_id = 0U;602 uint32_t model_id = 0U;
@@ -1257,8 +1257,8 @@ Status DeployContext::DataGwSchedInfo(const DeployState &deploy_state, const dep
1257 "DynamicSched GetQueues failed.");1257 "DynamicSched GetQueues failed.");
1258 1258 
1259 GELOGI(1259 GELOGI(
1260- "DynamicSched config sched info to datagw, device_id=%d, device_type=%d, logic input indice=%d, "1260+ "DynamicSched config sched info to datagw, device_id=%d, device_type=%d, logic input index=%d, "
1261- "phy input indice=%u, phy output indice=%u, logic output indice=%d, is_proxy=%d",1261+ "phy input index=%u, phy output index=%u, logic output index=%d, is_proxy=%d",
1262 dev_id, dev_type, input_queue_indice, input_queues[0], output_queues[0], output_queue_indice, is_proxy);1262 dev_id, dev_type, input_queue_indice, input_queues[0], output_queues[0], output_queue_indice, is_proxy);
1263 return flowgw_client_manager_.ConfigSchedInfoToDataGw(dev_id, dev_type, is_proxy, input_queue_indice, input_queues[0],1263 return flowgw_client_manager_.ConfigSchedInfoToDataGw(dev_id, dev_type, is_proxy, input_queue_indice, input_queues[0],
1264 output_queues[0], root_model_id);1264 output_queues[0], root_model_id);
@@ -439,18 +439,18 @@ Status FlowModelSender::TransferDataGwDeployPlan(DeployState &deploy_state) {
439 datagw_config_info->set_is_proxy(is_proxy_q);439 datagw_config_info->set_is_proxy(is_proxy_q);
440 if (submodel_desc.sched_input_queue_indices.size() == 1) {440 if (submodel_desc.sched_input_queue_indices.size() == 1) {
441 datagw_config_info->set_input_queue_indice(submodel_desc.sched_input_queue_indices[0]);441 datagw_config_info->set_input_queue_indice(submodel_desc.sched_input_queue_indices[0]);
442- GELOGI("DynamicSched set datagw sched info, input queue indice=%d.",442+ GELOGI("DynamicSched set datagw sched info, input queue index is %d.",
443 submodel_desc.sched_input_queue_indices[0]);443 submodel_desc.sched_input_queue_indices[0]);
444 } else {444 } else {
445- GELOGE(FAILED, "DynamicSched set datagw sched info failed, input indice num %u!",445+ GELOGE(FAILED, "DynamicSched set datagw sched info failed, input index num %u!",
446 submodel_desc.sched_input_queue_indices.size());446 submodel_desc.sched_input_queue_indices.size());
447 }447 }
448 if (submodel_desc.sched_output_queue_indices.size() == 1) {448 if (submodel_desc.sched_output_queue_indices.size() == 1) {
449 datagw_config_info->set_output_queue_indice(submodel_desc.sched_output_queue_indices[0]);449 datagw_config_info->set_output_queue_indice(submodel_desc.sched_output_queue_indices[0]);
450- GELOGI("DynamicSched set datagw sched info, output queue indice=%d.",450+ GELOGI("DynamicSched set datagw sched info, output queue index=%d.",
451 submodel_desc.sched_output_queue_indices[0]);451 submodel_desc.sched_output_queue_indices[0]);
452 } else {452 } else {
453- GELOGE(FAILED, "DynamicSched set datagw sched info failed, output indice num %u!",453+ GELOGE(FAILED, "DynamicSched set datagw sched info failed, output index num %u!",
454 submodel_desc.sched_output_queue_indices.size());454 submodel_desc.sched_output_queue_indices.size());
455 }455 }
456 datagw_devices_used[submodel_desc.device_info.GetKey()] = &submodel_desc.device_info;456 datagw_devices_used[submodel_desc.device_info.GetKey()] = &submodel_desc.device_info;
@@ -544,11 +544,11 @@ void FlowModelSender::AddDynamicSchedInfo(const DeployState &deploy_state, const
544 if (iter != dynamic_sched_model.end()) {544 if (iter != dynamic_sched_model.end()) {
545 for (const auto &idx : iter->second.status_input_queue_indices) {545 for (const auto &idx : iter->second.status_input_queue_indices) {
546 submodel_desc.add_status_input_queue_indices(idx);546 submodel_desc.add_status_input_queue_indices(idx);
547- GELOGI("DynamicSched add status input queue indice=%d, model name=%s.", idx, model_instance_name.c_str());547+ GELOGI("DynamicSched add status input queue index=%d, model name=%s.", idx, model_instance_name.c_str());
548 }548 }
549 for (const auto &idx : iter->second.status_output_queue_indices) {549 for (const auto &idx : iter->second.status_output_queue_indices) {
550 submodel_desc.add_status_output_queue_indices(idx);550 submodel_desc.add_status_output_queue_indices(idx);
551- GELOGI("DynamicSched add status output queue indice=%d, model name=%s.", idx, model_instance_name.c_str());551+ GELOGI("DynamicSched add status output queue index=%d, model name=%s.", idx, model_instance_name.c_str());
552 }552 }
553 }553 }
554 }554 }
@@ -223,8 +223,8 @@ Status HeterogeneousModelExecutor::DynamicSchedQueueInitialize(const bool is_dyn
223 "DynamicSched, can't find sched app output indices=%u record.",223 "DynamicSched, can't find sched app output indices=%u record.",
224 sched_input_queue_attrs_[i].global_logic_id);224 sched_input_queue_attrs_[i].global_logic_id);
225 datagw_rqt_to_rsp_[iter->second] = sched_input_queue_attrs_[i]; // 获得datagw逻辑input queue到app物理queueid映射225 datagw_rqt_to_rsp_[iter->second] = sched_input_queue_attrs_[i]; // 获得datagw逻辑input queue到app物理queueid映射
226- GELOGI("DynamicSched, scheding request, find datagw input indices=%d to sched app output queueid=%u.", iter->second,226+ GELOGI("DynamicSched, scheduling request, find datagw input indices=%d to sched app output queueid=%u.",
227- sched_input_queue_attrs_[i].queue_id);227+ iter->second, sched_input_queue_attrs_[i].queue_id);
228 }228 }
229 229 
230 for (auto id : sched_input_queue_attrs_) {230 for (auto id : sched_input_queue_attrs_) {
@@ -1094,7 +1094,7 @@ Status HeterogeneousModelExecutor::FlowgwResponseEnqueue(int32_t device_id, int3
1094 };1094 };
1095 GE_CHK_STATUS_RET(exchange_service_->Enqueue(device_id, out_queue_id, rsp_size, fill_func, control_info),1095 GE_CHK_STATUS_RET(exchange_service_->Enqueue(device_id, out_queue_id, rsp_size, fill_func, control_info),
1096 "DynamicSched Failed to enqueue flowgw_response");1096 "DynamicSched Failed to enqueue flowgw_response");
1097- GELOGI("DynamicSched, sent scheding response, datagw_input_index=%d, datagw_input_cnt=%d.", datagw_input_index,1097+ GELOGI("DynamicSched, sent scheduling response, datagw_input_index=%d, datagw_input_cnt=%d.", datagw_input_index,
1098 sched_input_cnt_[datagw_input_index]++);1098 sched_input_cnt_[datagw_input_index]++);
1099 return SUCCESS;1099 return SUCCESS;
1100}1100}
@@ -1133,7 +1133,7 @@ Status HeterogeneousModelExecutor::SchedRun(uint32_t index) {
1133 1133 
1134 DynamicSchedDurationStart();1134 DynamicSchedDurationStart();
1135 int32_t datagw_input_index = flowgw_request.input_index();1135 int32_t datagw_input_index = flowgw_request.input_index();
1136- GELOGI("DynamicSched receive scheding request, datagw_input_index=%d, datagw_input_cnt=%d.", datagw_input_index,1136+ GELOGI("DynamicSched receive scheduling request, datagw_input_index=%d, datagw_input_cnt=%d.", datagw_input_index,
1137 sched_input_cnt_[datagw_input_index]);1137 sched_input_cnt_[datagw_input_index]);
1138 domi::FlowgwResponse flowgw_response;1138 domi::FlowgwResponse flowgw_response;
1139 for (int32_t i = 0; i < flowgw_request.queue_infos_size(); ++i) {1139 for (int32_t i = 0; i < flowgw_request.queue_infos_size(); ++i) {
@@ -33,7 +33,7 @@ def run_benchmark(sess, out, feed_dict, iters, result_cpu):
33 elapsed_ms / iters,33 elapsed_ms / iters,
34 )34 )
35 max_err = np.max(np.abs(result_npu - result_cpu) / (np.abs(result_cpu) + 1e-10))35 max_err = np.max(np.abs(result_npu - result_cpu) / (np.abs(result_cpu) + 1e-10))
36- logging.info("Max relative error vs CPU: %.6f", max_err)36+ logging.info("Max relative diff vs CPU: %.6f", max_err)
37 37 
38 38 
39def build_graph(batch, heads, m, k, n):39def build_graph(batch, heads, m, k, n):
@@ -75,7 +75,7 @@ def run():
75 elapsed_ms / args.iters,75 elapsed_ms / args.iters,
76 )76 )
77 max_err = np.max(np.abs(result_npu - result_cpu) / (np.abs(result_cpu) + 1e-10))77 max_err = np.max(np.abs(result_npu - result_cpu) / (np.abs(result_cpu) + 1e-10))
78- logging.info("Max relative error vs CPU: %.6f", max_err)78+ logging.info("Max relative diff vs CPU: %.6f", max_err)
79 79 
80 80 
81if __name__ == "__main__":81if __name__ == "__main__":
@@ -196,7 +196,7 @@ bool TensorInfoArgs::IsShapeInRange(const TensorInfoArgs &other) const {
196 // check shape range when shape is dynamic196 // check shape range when shape is dynamic
197 if (this->IsUnknownShape()) {197 if (this->IsUnknownShape()) {
198 if (this->shape_.size() != this->shape_range_.size()) {198 if (this->shape_.size() != this->shape_range_.size()) {
199- GELOGD("shape size %zu is not match shape rang size %zu", this->shape_.size(), this->shape_range_.size());199+ GELOGD("shape size %zu is not match shape range size %zu", this->shape_.size(), this->shape_range_.size());
200 return false;200 return false;
201 }201 }
202 for (size_t i = 0U; i < this->shape_range_.size(); ++i) {202 for (size_t i = 0U; i < this->shape_range_.size(); ++i) {
@@ -967,7 +967,7 @@ Status ModelUtils::GetInputOutputDescAddrs(const RuntimeParam &model_param, cons
967 return RT_ERROR_TO_GE_STATUS(rt_ret);967 return RT_ERROR_TO_GE_STATUS(rt_ret);
968 }968 }
969 v_addrs[tensor_cnt] = mem_addr;969 v_addrs[tensor_cnt] = mem_addr;
970- GELOGD("Calc op[%s] tenser[%zu] desc addr[%p] ok", op_desc->GetName().c_str(), tensor_cnt, mem_addr);970+ GELOGD("Calc op[%s] tensor[%zu] desc addr[%p] ok", op_desc->GetName().c_str(), tensor_cnt, mem_addr);
971 tensor_cnt++;971 tensor_cnt++;
972 }972 }
973 return SUCCESS;973 return SUCCESS;
@@ -665,8 +665,8 @@ Status FftsPlusTaskInfo::PrePareForTransfer(const domi::TaskDef &task_def) {
665 }665 }
666 GE_ASSERT_SUCCESS(InitTilingInfo());666 GE_ASSERT_SUCCESS(InitTilingInfo());
667 GE_ASSERT_TRUE(!ge::MulOverflow(dsa_ctx_num, kDsaWorkspaceMaxSize, dsa_workspace_size_));667 GE_ASSERT_TRUE(!ge::MulOverflow(dsa_ctx_num, kDsaWorkspaceMaxSize, dsa_workspace_size_));
668- GELOGI("Prepare for task transfer-ing success, node: %s, ctx num: %d, dsa workspace size: %zu.",668+ GELOGI("Prepare for task transfer success, node: %s, ctx num: %d, dsa workspace size: %zu.", op_desc_->GetNamePtr(),
669- op_desc_->GetNamePtr(), ctx_num, dsa_workspace_size_);669+ ctx_num, dsa_workspace_size_);
670 670 
671 GE_ASSERT_TRUE(!ge::MulOverflow(sizeof(void *), ffts_plus_task_def.addr_size(), args_size_));671 GE_ASSERT_TRUE(!ge::MulOverflow(sizeof(void *), ffts_plus_task_def.addr_size(), args_size_));
672 GE_ASSERT_TRUE(!ge::AddOverflow(args_size_, dsa_workspace_size_, args_size_));672 GE_ASSERT_TRUE(!ge::AddOverflow(args_size_, dsa_workspace_size_, args_size_));