Browse Source

!1010 Fix GELOG format error

From: @zhangxiaokun9
Reviewed-by: @wangxiaotian22,@ji_chen
Signed-off-by: @ji_chen
tags/v1.2.0
mindspore-ci-bot Gitee 3 years ago
parent
commit
eb30d90aa5
6 changed files with 46 additions and 68 deletions
  1. +2
    -2
      ge/common/profiling/ge_profiling.cc
  2. +4
    -4
      ge/common/profiling/profiling_manager.cc
  3. +3
    -3
      ge/hybrid/executor/hybrid_model_async_executor.cc
  4. +1
    -1
      ge/hybrid/model/hybrid_model_builder.cc
  5. +6
    -6
      ge/hybrid/node_executor/node_executor.cc
  6. +30
    -52
      inc/framework/common/debug/ge_log.h

+ 2
- 2
ge/common/profiling/ge_profiling.cc View File

@@ -181,7 +181,7 @@ ge::Status ProfCommandHandle(ProfCommandHandleType type, void *data, uint32_t le
if (type != kProfCommandhandleFinalize) { if (type != kProfCommandhandleFinalize) {
command.module_index = prof_config_param->profSwitch; command.module_index = prof_config_param->profSwitch;
} }
GELOGI("GE commandhandle execute, Command Type: %s, data type config: 0x%llx", iter->second.c_str(),
GELOGI("GE commandhandle execute, Command Type: %s, data type config: 0x%lx", iter->second.c_str(),
command.module_index); command.module_index);
if (type == kProfCommandhandleStart || type == kProfCommandhandleStop) { if (type == kProfCommandhandleStart || type == kProfCommandhandleStop) {
GELOGI("Profiling device nums:%s , deviceID:[%s]", prof_params[0].c_str(), prof_params[kDeviceListIndex].c_str()); GELOGI("Profiling device nums:%s , deviceID:[%s]", prof_params[0].c_str(), prof_params[kDeviceListIndex].c_str());
@@ -192,7 +192,7 @@ ge::Status ProfCommandHandle(ProfCommandHandleType type, void *data, uint32_t le
return ge::FAILED; return ge::FAILED;
} }


GELOGI("Successfully execute profiling command type: %d, command 0x%llx.", type, command.module_index);
GELOGI("Successfully execute profiling command type: %d, command 0x%lx.", type, command.module_index);
return ge::SUCCESS; return ge::SUCCESS;
} }



+ 4
- 4
ge/common/profiling/profiling_manager.cc View File

@@ -540,7 +540,7 @@ FMK_FUNC_HOST_VISIBILITY FMK_FUNC_DEV_VISIBILITY Status ProfilingManager::ProfFi
for (auto device_id_module : device_id_module_map_) { for (auto device_id_module : device_id_module_map_) {
if (device_id_module.second != 0) { if (device_id_module.second != 0) {
uint32_t device_id = static_cast<uint32_t>(device_id_module.first); uint32_t device_id = static_cast<uint32_t>(device_id_module.first);
GELOGI("Prof finalize: device_id: %u, module: 0x%llx.", device_id, device_id_module.second);
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); rt_ret = rtProfilerStop(device_id_module.second, 1, &device_id);
if (rt_ret != RT_ERROR_NONE) { if (rt_ret != RT_ERROR_NONE) {
GELOGE(FAILED, "Runtime profiler stop failed."); GELOGE(FAILED, "Runtime profiler stop failed.");
@@ -629,7 +629,7 @@ Status ProfilingManager::ProfParseParam(const std::map<std::string, std::string>
} }


if (device_num == 0 || device_num > kMaxDeviceNum || device_num != static_cast<int32_t>(device_list.size())) { if (device_num == 0 || device_num > kMaxDeviceNum || device_num != static_cast<int32_t>(device_list.size())) {
GELOGE(FAILED, "Config para device num: %d not equal to device list size: %d.", device_num, device_list.size());
GELOGE(FAILED, "Config para device num: %d not equal to device list size: %zu.", device_num, device_list.size());
return FAILED; return FAILED;
} }
#endif #endif
@@ -659,7 +659,7 @@ FMK_FUNC_HOST_VISIBILITY FMK_FUNC_DEV_VISIBILITY Status ProfilingManager::ProfSt
for (int32_t i = 0; i < device_num; i++) { for (int32_t i = 0; i < device_num; i++) {
device_id_ptr[i] = static_cast<uint32_t>(device_list[i]); device_id_ptr[i] = static_cast<uint32_t>(device_list[i]);
} }
GELOGI("Runtime config param: 0x%llx, device num: %d.", module, device_num);
GELOGI("Runtime config param: 0x%lx, device num: %d.", module, device_num);


rtError_t rt_ret = rtProfilerStart(module, device_num, device_id_ptr.get()); rtError_t rt_ret = rtProfilerStart(module, device_num, device_id_ptr.get());
if (rt_ret != RT_ERROR_NONE) { if (rt_ret != RT_ERROR_NONE) {
@@ -701,7 +701,7 @@ FMK_FUNC_HOST_VISIBILITY FMK_FUNC_DEV_VISIBILITY Status ProfilingManager::ProfSt
for (int32_t i = 0; i < device_num; i++) { for (int32_t i = 0; i < device_num; i++) {
device_id_ptr[i] = static_cast<uint32_t>(device_list[i]); device_id_ptr[i] = static_cast<uint32_t>(device_list[i]);
} }
GELOGI("Prof stop: runtime config param: 0x%llx, device num: %d", module, device_num);
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()); rtError_t rt_ret = rtProfilerStop(module, device_num, device_id_ptr.get());
if (rt_ret != RT_ERROR_NONE) { if (rt_ret != RT_ERROR_NONE) {
GELOGE(FAILED, "Prof stop: runtime profiler config proc failed."); GELOGE(FAILED, "Prof stop: runtime profiler config proc failed.");


+ 3
- 3
ge/hybrid/executor/hybrid_model_async_executor.cc View File

@@ -221,7 +221,7 @@ Status HybridModelAsyncExecutor::PrepareInputs(const InputData &current_data, Hy
auto &tensor_desc = input_tensor_desc_[input_index]; auto &tensor_desc = input_tensor_desc_[input_index];
tensor_desc->SetShape(GeShape(current_data.shapes[input_index])); tensor_desc->SetShape(GeShape(current_data.shapes[input_index]));
args.input_desc[input_index] = tensor_desc; args.input_desc[input_index] = tensor_desc;
GELOGD("Update shape of input[%u] to [%s]", input_index, tensor_desc->MutableShape().ToString().c_str());
GELOGD("Update shape of input[%zu] to [%s]", input_index, tensor_desc->MutableShape().ToString().c_str());
GE_CHK_GRAPH_STATUS_RET(TensorUtils::GetTensorMemorySizeInBytes(*tensor_desc, tensor_size), GE_CHK_GRAPH_STATUS_RET(TensorUtils::GetTensorMemorySizeInBytes(*tensor_desc, tensor_size),
"Failed to calc tensor size, index = %zu, shape = [%s]", "Failed to calc tensor size, index = %zu, shape = [%s]",
input_index, input_index,
@@ -238,7 +238,7 @@ Status HybridModelAsyncExecutor::PrepareInputs(const InputData &current_data, Hy
GE_CHECK_NOTNULL(tensor_buffer); GE_CHECK_NOTNULL(tensor_buffer);
args.inputs.emplace_back(std::shared_ptr<TensorBuffer>(tensor_buffer.release())); args.inputs.emplace_back(std::shared_ptr<TensorBuffer>(tensor_buffer.release()));


GELOGD("To copy input data for input[%u]", input_index);
GELOGD("To copy input data for input[%zu]", input_index);
const DataBuffer &data_buf = blobs[input_index]; const DataBuffer &data_buf = blobs[input_index];
auto mem_size = static_cast<uint64_t>(tensor_size); auto mem_size = static_cast<uint64_t>(tensor_size);
GE_CHK_BOOL_RET_STATUS(mem_size >= data_buf.length, GE_CHK_BOOL_RET_STATUS(mem_size >= data_buf.length,
@@ -247,7 +247,7 @@ Status HybridModelAsyncExecutor::PrepareInputs(const InputData &current_data, Hy
data_buf.length, data_buf.length,
mem_size); mem_size);


GELOGI("[IMAS]CopyPlainData memcpy graph_%u type[F] output[%u] memaddr[%p] mem_size[%u] datasize[%lu]",
GELOGI("[IMAS]CopyPlainData memcpy graph_%u type[F] output[%zu] memaddr[%p] mem_size[%zu] datasize[%lu]",
model_->root_runtime_param_.graph_id, model_->root_runtime_param_.graph_id,
input_index, input_index,
args.inputs[input_index].GetData(), args.inputs[input_index].GetData(),


+ 1
- 1
ge/hybrid/model/hybrid_model_builder.cc View File

@@ -939,7 +939,7 @@ Status HybridModelBuilder::InitVariableTensors() {
GELOGE(MEMALLOC_FAILED, "Malloc host memory for an existed GeTensor failed."); GELOGE(MEMALLOC_FAILED, "Malloc host memory for an existed GeTensor failed.");
return MEMALLOC_FAILED; return MEMALLOC_FAILED;
} }
GELOGD("Host variable [%s] malloc success, size=%lld.", it.first.c_str(), tensor_size);
GELOGD("Host variable [%s] malloc success, size=%ld.", it.first.c_str(), tensor_size);


std::unique_ptr<TensorValue> tensor(new (std::nothrow) TensorValue(mem_info.host_aligned_ptr->MutableGet(), std::unique_ptr<TensorValue> tensor(new (std::nothrow) TensorValue(mem_info.host_aligned_ptr->MutableGet(),
tensor_size)); tensor_size));


+ 6
- 6
ge/hybrid/node_executor/node_executor.cc View File

@@ -117,11 +117,11 @@ Status NodeExecutorManager::GetExecutor(Node &node, const NodeExecutor **executo
auto executor_type = ResolveExecutorType(node); auto executor_type = ResolveExecutorType(node);
const auto it = executors_.find(executor_type); const auto it = executors_.find(executor_type);
if (it == executors_.end()) { if (it == executors_.end()) {
GELOGE(INTERNAL_ERROR, "Failed to get executor by type: %d.", executor_type);
GELOGE(INTERNAL_ERROR, "Failed to get executor by type: %d.", static_cast<int>(executor_type));
return INTERNAL_ERROR; return INTERNAL_ERROR;
} }


GELOGD("[%s] Set node executor by type: %d.", node.GetName().c_str(), executor_type);
GELOGD("[%s] Set node executor by type: %d.", node.GetName().c_str(), static_cast<int>(executor_type));
*executor = it->second.get(); *executor = it->second.get();
return SUCCESS; return SUCCESS;
} }
@@ -165,7 +165,7 @@ Status NodeExecutorManager::CalcOpRunningParam(Node &node) const {
TensorUtils::SetSize(output_tensor, output_mem_size); TensorUtils::SetSize(output_tensor, output_mem_size);
GE_CHK_STATUS_RET(op_desc->UpdateOutputDesc(static_cast<uint32_t>(i), output_tensor), GE_CHK_STATUS_RET(op_desc->UpdateOutputDesc(static_cast<uint32_t>(i), output_tensor),
"hccl update output size failed."); "hccl update output size failed.");
GELOGD("%s output desc[%u], dim_size: %zu, mem_size: %ld.", node.GetName().c_str(), i,
GELOGD("%s output desc[%zu], dim_size: %zu, mem_size: %ld.", node.GetName().c_str(), i,
output_tensor.GetShape().GetDimNum(), output_mem_size); output_tensor.GetShape().GetDimNum(), output_mem_size);
} }
return SUCCESS; return SUCCESS;
@@ -189,14 +189,14 @@ Status NodeExecutorManager::InitializeExecutors() {
GE_CHECK_NOTNULL(build_fn); GE_CHECK_NOTNULL(build_fn);
auto executor = std::unique_ptr<NodeExecutor>(build_fn()); auto executor = std::unique_ptr<NodeExecutor>(build_fn());
if (executor == nullptr) { if (executor == nullptr) {
GELOGE(INTERNAL_ERROR, "Failed to create executor for engine type = %d", engine_type);
GELOGE(INTERNAL_ERROR, "Failed to create executor for engine type = %d", static_cast<int>(engine_type));
return INTERNAL_ERROR; return INTERNAL_ERROR;
} }


GELOGD("Executor of engine type = %d was created successfully", engine_type);
GELOGD("Executor of engine type = %d was created successfully", static_cast<int>(engine_type));
auto ret = executor->Initialize(); auto ret = executor->Initialize();
if (ret != SUCCESS) { if (ret != SUCCESS) {
GELOGE(ret, "Failed to initialize NodeExecutor of type = %d, clear executors", engine_type);
GELOGE(ret, "Failed to initialize NodeExecutor of type = %d, clear executors", static_cast<int>(engine_type));
for (auto &executor_it : executors_) { for (auto &executor_it : executors_) {
executor_it.second->Finalize(); executor_it.second->Finalize();
} }


+ 30
- 52
inc/framework/common/debug/ge_log.h View File

@@ -38,75 +38,53 @@ extern "C" {
enum TraceStatus { TRACE_INIT = 0, TRACE_RUNNING, TRACE_WAITING, TRACE_STOP }; enum TraceStatus { TRACE_INIT = 0, TRACE_RUNNING, TRACE_WAITING, TRACE_STOP };


class GeLog { class GeLog {
public:
public:
static uint64_t GetTid() {
#ifdef __GNUC__ #ifdef __GNUC__
static pid_t GetTid() {
thread_local static pid_t tid = syscall(__NR_gettid);
return tid;
}
thread_local static uint64_t tid = static_cast<uint64_t>(syscall(__NR_gettid));
#else #else
static int GetTid() {
thread_local static int tid = static_cast<int>(GetCurrentThreadId());
return tid;
}
thread_local static uint64_t tid = static_cast<uint64_t>(GetCurrentThreadId());
#endif #endif
return tid;
}
}; };


inline bool IsLogEnable(int module_name, int log_level) { inline bool IsLogEnable(int module_name, int log_level) {
int32_t enable = CheckLogLevel(module_name, log_level); int32_t enable = CheckLogLevel(module_name, log_level);
// 1:enable, 0:disable // 1:enable, 0:disable
if (enable == 1) {
return true;
}
return false;
return (enable == 1);
} }


#define GELOGE(ERROR_CODE, fmt, ...) \
#define GELOGE(ERROR_CODE, fmt, ...) \
dlog_error(GE_MODULE_NAME, "%lu %s: ErrorNo: %d(%s) " fmt, GeLog::GetTid(), __FUNCTION__, ERROR_CODE, \ dlog_error(GE_MODULE_NAME, "%lu %s: ErrorNo: %d(%s) " fmt, GeLog::GetTid(), __FUNCTION__, ERROR_CODE, \
((GE_GET_ERRORNO_STR(ERROR_CODE)).c_str()), ##__VA_ARGS__) ((GE_GET_ERRORNO_STR(ERROR_CODE)).c_str()), ##__VA_ARGS__)
#define GELOGW(fmt, ...) \
if (IsLogEnable(GE_MODULE_NAME, DLOG_WARN)) dlog_warn(GE_MODULE_NAME, "%lu %s:" fmt, GeLog::GetTid(), __FUNCTION__, ##__VA_ARGS__)
#define GELOGI(fmt, ...) \
if (IsLogEnable(GE_MODULE_NAME, DLOG_INFO)) dlog_info(GE_MODULE_NAME, "%lu %s:" fmt, GeLog::GetTid(), __FUNCTION__, ##__VA_ARGS__)
#define GELOGD(fmt, ...) \
if (IsLogEnable(GE_MODULE_NAME, DLOG_DEBUG)) dlog_debug(GE_MODULE_NAME, "%lu %s:" fmt, GeLog::GetTid(), __FUNCTION__, ##__VA_ARGS__)
#define GELOGW(fmt, ...) \
if (IsLogEnable(GE_MODULE_NAME, DLOG_WARN)) \
dlog_warn(GE_MODULE_NAME, "%lu %s:" fmt, GeLog::GetTid(), __FUNCTION__, ##__VA_ARGS__)
#define GELOGI(fmt, ...) \
if (IsLogEnable(GE_MODULE_NAME, DLOG_INFO)) \
dlog_info(GE_MODULE_NAME, "%lu %s:" fmt, GeLog::GetTid(), __FUNCTION__, ##__VA_ARGS__)
#define GELOGD(fmt, ...) \
if (IsLogEnable(GE_MODULE_NAME, DLOG_DEBUG)) \
dlog_debug(GE_MODULE_NAME, "%lu %s:" fmt, GeLog::GetTid(), __FUNCTION__, ##__VA_ARGS__)

#define GEEVENT(fmt, ...) dlog_event(GE_MODULE_NAME, "%lu %s:" fmt, GeLog::GetTid(), __FUNCTION__, ##__VA_ARGS__) #define GEEVENT(fmt, ...) dlog_event(GE_MODULE_NAME, "%lu %s:" fmt, GeLog::GetTid(), __FUNCTION__, ##__VA_ARGS__)
#define GELOGO(fmt, ...) \
Dlog(GE_MODULE_NAME, DLOG_OPLOG, "%lu %s:" fmt, GeLog::GetTid(), __FUNCTION__, ##__VA_ARGS__)
#define GELOGT(VALUE, fmt, ...) \
do { \
TraceStatus stat = VALUE; \
const char *const TraceStatStr[] = {"INIT", "RUNNING", "WAITING", "STOP"}; \
int idx = static_cast<int>(stat); \
char *k = const_cast<char *>("status"); \
char *v = const_cast<char *>(TraceStatStr[idx]); \
KeyValue kv = {k, v}; \
DlogWithKV(static_cast<int>(GE_MODULE_NAME), DLOG_TRACE, &kv, 1, "%lu %s:" fmt, GeLog::GetTid(), __FUNCTION__, ##__VA_ARGS__); \
#define GELOGT(VALUE, fmt, ...) \
do { \
TraceStatus stat = VALUE; \
const char *const TraceStatStr[] = {"INIT", "RUNNING", "WAITING", "STOP"}; \
int idx = static_cast<int>(stat); \
char *k = const_cast<char *>("status"); \
char *v = const_cast<char *>(TraceStatStr[idx]); \
KeyValue kv = {k, v}; \
DlogWithKV(static_cast<int>(GE_MODULE_NAME), DLOG_TRACE, &kv, 1, "%lu %s:" fmt, GeLog::GetTid(), __FUNCTION__, \
##__VA_ARGS__); \
} while (0) } while (0)


#define GE_LOG_ERROR(MOD_NAME, ERROR_CODE, fmt, ...) \
#define GE_LOG_ERROR(MOD_NAME, ERROR_CODE, fmt, ...) \
dlog_error(MOD_NAME, "%lu %s: ErrorNo: %d(%s) " fmt, GeLog::GetTid(), __FUNCTION__, ERROR_CODE, \ dlog_error(MOD_NAME, "%lu %s: ErrorNo: %d(%s) " fmt, GeLog::GetTid(), __FUNCTION__, ERROR_CODE, \
((GE_GET_ERRORNO_STR(ERROR_CODE)).c_str()), ##__VA_ARGS__) ((GE_GET_ERRORNO_STR(ERROR_CODE)).c_str()), ##__VA_ARGS__)
#define GE_LOG_WARN(MOD_NAME, fmt, ...) \
if (IsLogEnable(MOD_NAME, DLOG_WARN)) dlog_warn(MOD_NAME, "%lu %s:" fmt, GeLog::GetTid(), __FUNCTION__, ##__VA_ARGS__)
#define GE_LOG_INFO(MOD_NAME, fmt, ...) \
if (IsLogEnable(MOD_NAME, DLOG_INFO)) dlog_info(MOD_NAME, "%lu %s:" fmt, GeLog::GetTid(), __FUNCTION__, ##__VA_ARGS__)
#define GE_LOG_DEBUG(MOD_NAME, fmt, ...) \
if (IsLogEnable(MOD_NAME, DLOG_DEBUG)) dlog_debug(MOD_NAME, "%lu %s:" fmt, GeLog::GetTid(), __FUNCTION__, ##__VA_ARGS__)
#define GE_LOG_EVENT(MOD_NAME, fmt, ...) dlog_event(MOD_NAME, "%lu %s:" fmt, GeLog::GetTid(), __FUNCTION__, ##__VA_ARGS__)
#define GE_LOG_OPLOG(MOD_NAME, fmt, ...) \
Dlog(MOD_NAME, DLOG_OPLOG, "%lu %s:" fmt, GeLog::GetTid(), __FUNCTION__, ##__VA_ARGS__)

#define GE_LOG_TRACE(MOD_NAME, value, fmt, ...) \
do { \
TraceStatus stat = value; \
const char *const TraceStatStr[] = {"INIT", "RUNNING", "WAITING", "STOP"}; \
int idx = static_cast<int>(stat); \
char *k = const_cast<char *>("status"); \
char *v = const_cast<char *>(TraceStatStr[idx]); \
KeyValue kv = {k, v}; \
DlogWithKV(static_cast<int>(MOD_NAME), DLOG_TRACE, &kv, 1, "%lu %s:" fmt, GeLog::GetTid(), __FUNCTION__, ##__VA_ARGS__); \
} while (0)


// print memory when it is greater than 1KB. // print memory when it is greater than 1KB.
#define GE_PRINT_DYNAMIC_MEMORY(FUNC, PURPOSE, SIZE) \ #define GE_PRINT_DYNAMIC_MEMORY(FUNC, PURPOSE, SIZE) \


Loading…
Cancel
Save