Fixing Performance Issue with API Tracing V2

Records right now will report basic raw data, no pre-processing in API anymore, and it will be left to the tool to process data from the output of synchronous callbacks of the API tracing records output

Change-Id: I8e5845e49e1228cb2fb60ca188ee748745b6a1af
This commit is contained in:
Ammar ELWazir
2023-04-20 12:49:32 +00:00
committed by Ammar Elwazir
parent c1afcb95e7
commit 4a33787c01
5 changed files with 188 additions and 74 deletions
+27 -10
View File
@@ -278,16 +278,33 @@ class file_plugin_t {
}
}
output_file_t* output_file = get_output_file(output_type_t::TRACER, tracer_record.domain);
*output_file << "Record [" << tracer_record.header.id.handle << "], Domain("
<< GetDomainName(tracer_record.domain) << "), Begin("
<< tracer_record.timestamps.begin.value;
if (tracer_record.domain != ACTIVITY_DOMAIN_ROCTX)
*output_file << "), End(" << tracer_record.timestamps.end.value;
*output_file << "), Correlation ID( " << tracer_record.correlation_id.value << ")";
if (tracer_record.domain == ACTIVITY_DOMAIN_ROCTX && roctx_id >= 0) *output_file << ", ROCTX ID(" << roctx_id << ")";
if (tracer_record.domain == ACTIVITY_DOMAIN_ROCTX && roctx_message.size() > 1) *output_file << ", ROCTX Message(" << roctx_message << ")";
if (function_name.size() > 1) *output_file << ", Function(" << function_name << ")";
if (kernel_name.size() > 1) *output_file << ", Kernel Name(" << kernel_name.c_str() << ")";
*output_file << "Record(" << tracer_record.header.id.handle << "), Domain("
<< GetDomainName(tracer_record.domain) << "),";
if (tracer_record.domain == ACTIVITY_DOMAIN_ROCTX && roctx_id >= 0) *output_file << " ROCTX_ID(" << roctx_id << "),";
if (tracer_record.domain == ACTIVITY_DOMAIN_ROCTX && roctx_message.size() > 1) *output_file << " ROCTX_Message(" << roctx_message << "),";
if (function_name.size() > 1) *output_file << " Function(" << function_name << "),";
if (kernel_name.size() > 1) *output_file << " Kernel_Name(" << kernel_name.c_str() << "),";
if (tracer_record.phase == ROCPROFILER_PHASE_NONE) {
*output_file << " Begin(" << tracer_record.timestamps.begin.value
<< "), End(" << tracer_record.timestamps.end.value << ")";
} else {
if(tracer_record.phase == ROCPROFILER_PHASE_ENTER && tracer_record.domain != ACTIVITY_DOMAIN_ROCTX){
rocprofiler_timestamp_t timestamp;
rocprofiler_get_timestamp(&timestamp);
*output_file << " Begin(" << timestamp.value << "),";
}
if(tracer_record.phase == ROCPROFILER_PHASE_ENTER && tracer_record.domain == ACTIVITY_DOMAIN_ROCTX) {
rocprofiler_timestamp_t timestamp;
rocprofiler_get_timestamp(&timestamp);
*output_file << " timestamp(" << timestamp.value << "),";
}
if (tracer_record.phase == ROCPROFILER_PHASE_EXIT) {
rocprofiler_timestamp_t timestamp;
rocprofiler_get_timestamp(&timestamp);
*output_file << " End(" << timestamp.value << "),";
}
}
*output_file << " Correlation_ID(" << tracer_record.correlation_id.value << ")";
*output_file << std::endl;
}
+67 -18
View File
@@ -452,17 +452,33 @@ class perfetto_plugin_t {
}
}
if (tracer_record.operation_id.id == 1) {
if(tracer_record.phase == ROCPROFILER_PHASE_NONE) {
if (tracer_record.operation_id.id == 1) {
perfetto::StaticString roctx_message_pft(
(!roctx_message.empty() ? roctx_message.c_str() : ""));
TRACE_EVENT_BEGIN("ROCTX_API", roctx_message_pft, roctx_track,
tracer_record.timestamps.begin.value, "Timestamp(ns)",
tracer_record.timestamps.begin.value, "RocTx ID", roctx_id);
roctx_track_entries_++;
} else {
TRACE_EVENT_END("ROCTX_API", roctx_track, tracer_record.timestamps.begin.value);
roctx_track_entries_--;
}
} else {
rocprofiler_timestamp_t timestamp;
rocprofiler_get_timestamp(&timestamp);
if (tracer_record.operation_id.id == 1) {
perfetto::StaticString roctx_message_pft(
(!roctx_message.empty() ? roctx_message.c_str() : ""));
TRACE_EVENT_BEGIN("ROCTX_API", roctx_message_pft, roctx_track,
tracer_record.timestamps.begin.value, "Timestamp(ns)",
tracer_record.timestamps.begin.value, "RocTx ID", roctx_id);
timestamp.value, "Timestamp(ns)",
timestamp.value, "RocTx ID", roctx_id);
roctx_track_entries_++;
} else {
TRACE_EVENT_END("ROCTX_API", roctx_track, tracer_record.timestamps.begin.value);
TRACE_EVENT_END("ROCTX_API", roctx_track, timestamp.value);
roctx_track_entries_--;
}
}
break;
}
case ACTIVITY_DOMAIN_HSA_API: {
@@ -499,10 +515,14 @@ class perfetto_plugin_t {
session_id, ROCPROFILER_HSA_FUNCTION_NAME, tracer_record.api_data_handle,
tracer_record.operation_id, &function_name));
}
TRACE_EVENT_BEGIN("HSA_API", perfetto::StaticString(function_name), hsa_track,
tracer_record.timestamps.begin.value,
rocprofiler_timestamp_t timestamp;
rocprofiler_get_timestamp(&timestamp);
if(tracer_record.phase == ROCPROFILER_PHASE_ENTER)
TRACE_EVENT_BEGIN("HSA_API", perfetto::StaticString(function_name), hsa_track,
timestamp.value,
perfetto::Flow::ProcessScoped(tracer_record.correlation_id.value));
TRACE_EVENT_END("HSA_API", hsa_track, tracer_record.timestamps.end.value);
if(tracer_record.phase == ROCPROFILER_PHASE_EXIT)
TRACE_EVENT_END("HSA_API", hsa_track, timestamp.value);
break;
}
case ACTIVITY_DOMAIN_HIP_API: {
@@ -555,16 +575,34 @@ class perfetto_plugin_t {
free(kernel_name_str);
}
}
if (kernel_name.size() > 0) {
TRACE_EVENT_BEGIN("HIP_API", perfetto::StaticString(function_name), hip_track,
tracer_record.timestamps.begin.value, "Kernel Name", kernel_name,
perfetto::Flow::ProcessScoped(tracer_record.correlation_id.value));
} else {
TRACE_EVENT_BEGIN("HIP_API", perfetto::StaticString(function_name), hip_track,
tracer_record.timestamps.begin.value,
perfetto::Flow::ProcessScoped(tracer_record.correlation_id.value));
rocprofiler_timestamp_t timestamp;
rocprofiler_get_timestamp(&timestamp);
if(tracer_record.phase == ROCPROFILER_PHASE_ENTER) {
if (kernel_name.size() > 0) {
TRACE_EVENT_BEGIN("HIP_API", perfetto::StaticString(function_name), hip_track,
timestamp.value, "Kernel Name", kernel_name,
perfetto::Flow::ProcessScoped(tracer_record.correlation_id.value));
} else {
TRACE_EVENT_BEGIN("HIP_API", perfetto::StaticString(function_name), hip_track,
timestamp.value,
perfetto::Flow::ProcessScoped(tracer_record.correlation_id.value));
}
}
if(tracer_record.phase == ROCPROFILER_PHASE_EXIT) {
TRACE_EVENT_END("HIP_API", hip_track, timestamp.value);
}
if(tracer_record.phase == ROCPROFILER_PHASE_NONE) {
if (kernel_name.size() > 0) {
TRACE_EVENT_BEGIN("HIP_API", perfetto::StaticString(function_name), hip_track,
tracer_record.timestamps.begin.value, "Kernel Name", kernel_name,
perfetto::Flow::ProcessScoped(tracer_record.correlation_id.value));
} else {
TRACE_EVENT_BEGIN("HIP_API", perfetto::StaticString(function_name), hip_track,
tracer_record.timestamps.begin.value,
perfetto::Flow::ProcessScoped(tracer_record.correlation_id.value));
}
TRACE_EVENT_END("HIP_API", hip_track, tracer_record.timestamps.end.value);
}
TRACE_EVENT_END("HIP_API", hip_track, tracer_record.timestamps.end.value);
break;
}
case ACTIVITY_DOMAIN_EXT_API: {
@@ -607,6 +645,8 @@ class perfetto_plugin_t {
}
}
auto& stream_track = stream_track_it->second;
rocprofiler_timestamp_t timestamp;
rocprofiler_get_timestamp(&timestamp);
if (tracer_record.api_data_handle.handle && tracer_record.api_data_handle.size > 1) {
kernel_name = rocmtools::cxx_demangle(
strdup(reinterpret_cast<const char*>(tracer_record.api_data_handle.handle)));
@@ -629,12 +669,21 @@ class perfetto_plugin_t {
} else {
activity_name = const_cast<char*>(std::string("N/A").c_str());
}
TRACE_EVENT_BEGIN("HIP_OPS", perfetto::StaticString(activity_name), stream_track,
if(tracer_record.phase == ROCPROFILER_PHASE_NONE)
TRACE_EVENT_BEGIN("HIP_OPS", perfetto::StaticString(activity_name), stream_track,
tracer_record.timestamps.begin.value, "Agent ID",
tracer_record.agent_id.handle, "Process ID", GetPid(),
perfetto::Flow::ProcessScoped(tracer_record.correlation_id.value));
else if(tracer_record.phase == ROCPROFILER_PHASE_ENTER)
TRACE_EVENT_BEGIN("HIP_OPS", perfetto::StaticString(activity_name), stream_track,
timestamp.value, "Agent ID",
tracer_record.agent_id.handle, "Process ID", GetPid(),
perfetto::Flow::ProcessScoped(tracer_record.correlation_id.value));
}
TRACE_EVENT_END("HIP_OPS", stream_track, tracer_record.timestamps.end.value);
if(tracer_record.phase == ROCPROFILER_PHASE_NONE)
TRACE_EVENT_END("HIP_OPS", stream_track, tracer_record.timestamps.end.value);
else if(tracer_record.phase == ROCPROFILER_PHASE_EXIT)
TRACE_EVENT_END("HIP_OPS", stream_track, timestamp.value);
break;
}
case ACTIVITY_DOMAIN_HSA_OPS: {