AI/rocm-systems
2
0
Fork 0
Código Incidencias Pull Requests Acciones Paquetes Proyectos Lanzamientos Wiki Actividad

Fixing Performance Issue with API Tracing V2

Explorar el Código 
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


[ROCm/rocprofiler commit: 4a33787c01]
Este commit está contenido en:
Ammar ELWazir
2023-04-20 12:49:32 +00:00
cometido por Ammar Elwazir
padre 2a8c6b0a47
commit 03a0e9bec0
Se han modificado 5 ficheros con 188 adiciones y 74 borrados
Descargar archivo de parche Descargar archivo de diferencias Expandir todos los archivos Contraer todos los archivos
projects/rocprofiler/inc/rocprofiler.h
+19
Ver fichero
@@ -1476,6 +1476,21 @@ typedef struct {
uint64_t id;
} rocprofiler_tracer_external_id_t;
typedef enum {
/**
* No phase, it is an activity record or asynchronous output data
*/
ROCPROFILER_PHASE_NONE = 0,
/**
* Enter phase for API calls
*/
ROCPROFILER_PHASE_ENTER = 1,
/**
* Exit phase for API calls
*/
ROCPROFILER_PHASE_EXIT = 2
} rocprofiler_api_tracing_phase_t;
/**
* Tracing record, this will represent all the information reported by the
* tracer regarding APIs and their data that were traced and collected
@@ -1530,6 +1545,10 @@ typedef struct {
* Thread id
*/
rocprofiler_thread_id_t thread_id;
/**
* API Tracing phase (Enter/Exit/None(Activity Records/Asynchronous Output Records))
*/
rocprofiler_api_tracing_phase_t phase;
} rocprofiler_record_tracer_t;
/**
projects/rocprofiler/plugin/file/file.cpp
+27 -10
Ver fichero
@@ -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;
}
projects/rocprofiler/plugin/perfetto/perfetto.cpp
+67 -18
Ver fichero
@@ -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: {
projects/rocprofiler/src/core/session/tracer/src/roctracer.cpp
+4
Ver fichero
@@ -265,6 +265,7 @@ template <activity_domain_t domain> struct ApiTracer {
rocprofiler_timestamp_t{trace_data->phase_enter_timestamp},
hsa_support::timestamp_ns()};
record.thread_id = rocprofiler_thread_id_t{GetTid()};
record.phase = ROCPROFILER_PHASE_NONE;
if (auto external_id = ExternalCorrelationId()) {
rocprofiler_record_tracer_t ext_record{};
@@ -275,6 +276,7 @@ template <activity_domain_t domain> struct ApiTracer {
ext_record.correlation_id =
rocprofiler_tracer_activity_correlation_id_t{record.correlation_id};
ext_record.external_id = rocprofiler_tracer_external_id_t{*external_id};
ext_record.phase = ROCPROFILER_PHASE_NONE;
// Write the external correlation id record directly followed by the
// activity record.
rocmtools::GetROCMToolObj()
@@ -400,6 +402,7 @@ int TracerCallback(activity_domain_t domain, uint32_t operation_id, void* data)
rocprofiler_record.agent_id = rocprofiler_agent_id_t{(uint64_t)record->device_id};
rocprofiler_record.queue_id = rocprofiler_queue_id_t{record->queue_id};
rocprofiler_record.thread_id = rocprofiler_thread_id_t{GetTid()};
rocprofiler_record.phase = ROCPROFILER_PHASE_NONE;
if (operation_id == HIP_OP_ID_DISPATCH && record->kernel_name != nullptr) {
rocprofiler_record.api_data_handle.handle = strdup(record->kernel_name);
rocprofiler_record.api_data_handle.size = (strlen(record->kernel_name) + 1);
@@ -462,6 +465,7 @@ int TracerCallback(activity_domain_t domain, uint32_t operation_id, void* data)
rocprofiler_record.agent_id = rocprofiler_agent_id_t{(uint64_t)record->device_id};
rocprofiler_record.queue_id = rocprofiler_queue_id_t{record->queue_id};
rocprofiler_record.thread_id = rocprofiler_thread_id_t{GetTid()};
rocprofiler_record.phase = ROCPROFILER_PHASE_NONE;
if (record->kernel_name != nullptr && record->op == HSA_OP_ID_DISPATCH) {
rocprofiler_record.api_data_handle.handle = strdup(record->kernel_name);
rocprofiler_record.api_data_handle.size = strlen(record->kernel_name) + 1;
projects/rocprofiler/src/core/session/tracer/tracer.cpp
+71 -46
Ver fichero
@@ -183,11 +183,12 @@ size_t Tracer::GetHIPApiDataInfoSize(rocprofiler_tracer_hip_api_data_info_t kind
return strlen(roctracer_op_string(ACTIVITY_DOMAIN_HIP_OPS, operation_id.id)) + 1;
}
case ROCPROFILER_HIP_STREAM_ID: {
std::lock_guard<std::mutex> lock(stream_ids_map_lock);
if (!stream_ids.empty() && stream_ids.find(operation_id.id) != stream_ids.end())
return std::to_string(stream_ids.at(operation_id.id).second).size() + 1;
else
return 0;
// std::lock_guard<std::mutex> lock(stream_ids_map_lock);
// if (!stream_ids.empty() && stream_ids.find(operation_id.id) != stream_ids.end())
// return std::to_string(stream_ids.at(operation_id.id).second).size() + 1;
// else
// return 0;
warning("Stream ID is not supported!");
}
case ROCPROFILER_HIP_API_DATA: {
return api_data_id.size;
@@ -258,12 +259,13 @@ char* Tracer::GetHIPApiDataInfo(rocprofiler_tracer_hip_api_data_info_t kind,
return const_cast<char*>(roctracer_op_string(ACTIVITY_DOMAIN_HIP_OPS, operation_id.id));
}
case ROCPROFILER_HIP_STREAM_ID: {
std::lock_guard<std::mutex> lock(stream_ids_map_lock);
if (!stream_ids.empty() && stream_ids.find(operation_id.id) != stream_ids.end())
return strdup(
const_cast<char*>(std::to_string(stream_ids.at(operation_id.id).second).c_str()));
else
return nullptr;
// std::lock_guard<std::mutex> lock(stream_ids_map_lock);
// if (!stream_ids.empty() && stream_ids.find(operation_id.id) != stream_ids.end())
// return strdup(
// const_cast<char*>(std::to_string(stream_ids.at(operation_id.id).second).c_str()));
// else
// return nullptr;
warning("Stream ID is not supported!");
}
case ROCPROFILER_HIP_API_DATA: {
return const_cast<char*>(reinterpret_cast<const char*>(api_data_id.handle));
@@ -284,7 +286,6 @@ void api_callback(activity_domain_t domain, uint32_t cid, const void* callback_d
switch (domain) {
case ACTIVITY_DOMAIN_ROCTX: {
const roctx_api_data_t* data = reinterpret_cast<const roctx_api_data_t*>(callback_data);
// if (data->args.message) roctx_labels.emplace(data->args.id, data->args.message);
args_data->user_sync_callback(
rocprofiler_record_tracer_t{
rocprofiler_record_header_t{
@@ -296,7 +297,7 @@ void api_callback(activity_domain_t domain, uint32_t cid, const void* callback_d
rocprofiler_tracer_activity_correlation_id_t{0},
rocprofiler_record_header_timestamp_t{roctracer::hsa_support::timestamp_ns(),
rocprofiler_timestamp_t{0}},
0, 0, GetTid()},
0, 0, GetTid(), ROCPROFILER_PHASE_ENTER},
args_data->session_id);
break;
}
@@ -304,7 +305,18 @@ void api_callback(activity_domain_t domain, uint32_t cid, const void* callback_d
hsa_api_data_t* data =
const_cast<hsa_api_data_t*>(reinterpret_cast<const hsa_api_data_t*>(callback_data));
if (data->phase == ACTIVITY_API_PHASE_ENTER) {
*(data->phase_data) = roctracer::hsa_support::timestamp_ns().value;
args_data->user_sync_callback(
rocprofiler_record_tracer_t{
rocprofiler_record_header_t{
ROCPROFILER_TRACER_RECORD,
rocprofiler_record_id_t{rocmtools::GetROCMToolObj()->GetUniqueRecordId()}},
rocprofiler_tracer_external_id_t{0}, ACTIVITY_DOMAIN_HSA_API,
rocprofiler_tracer_operation_id_t{cid},
rocprofiler_tracer_api_data_handle_t{callback_data, sizeof(*data)},
rocprofiler_tracer_activity_correlation_id_t{data->correlation_id},
rocprofiler_record_header_timestamp_t{rocprofiler_timestamp_t{0}, rocprofiler_timestamp_t{0}},
0, 0, GetTid(), ROCPROFILER_PHASE_ENTER},
args_data->session_id);
} else {
args_data->user_sync_callback(
rocprofiler_record_tracer_t{
@@ -315,9 +327,9 @@ void api_callback(activity_domain_t domain, uint32_t cid, const void* callback_d
rocprofiler_tracer_operation_id_t{cid},
rocprofiler_tracer_api_data_handle_t{callback_data, sizeof(*data)},
rocprofiler_tracer_activity_correlation_id_t{data->correlation_id},
rocprofiler_record_header_timestamp_t{rocprofiler_timestamp_t{*(data->phase_data)},
roctracer::hsa_support::timestamp_ns()},
0, 0, GetTid()},
rocprofiler_record_header_timestamp_t{rocprofiler_timestamp_t{0},
rocprofiler_timestamp_t{0}},
0, 0, GetTid(), ROCPROFILER_PHASE_EXIT},
args_data->session_id);
}
break;
@@ -326,32 +338,6 @@ void api_callback(activity_domain_t domain, uint32_t cid, const void* callback_d
hip_api_data_t* data =
const_cast<hip_api_data_t*>(reinterpret_cast<const hip_api_data_t*>(callback_data));
if (data->phase == ACTIVITY_API_PHASE_ENTER) {
*(data->phase_data) = roctracer::hsa_support::timestamp_ns().value;
} else {
hipApiArgsInit((hip_api_id_t)cid, data);
std::string hip_api_data_string = hipApiString((hip_api_id_t)cid, data);
std::string start_str = "stream=";
int start = hip_api_data_string.find(start_str);
uint64_t stream_id = 0;
if (start >= 0) {
int end = hip_api_data_string.find(",", start);
std::string stream_id_str = hip_api_data_string.substr(start + start_str.length(), end);
std::stringstream ss;
ss << std::hex << stream_id_str;
ss >> stream_id;
}
{
std::lock_guard<std::mutex> lock(stream_ids_map_lock);
if (used_stream_ids.find(stream_id) == used_stream_ids.end()) {
uint64_t stream_generated_id = stream_count.fetch_add(1, std::memory_order_release);
used_stream_ids.emplace(stream_id, stream_generated_id);
stream_ids.emplace(data->correlation_id,
std::make_pair(stream_id, stream_generated_id));
} else {
stream_ids.emplace(data->correlation_id,
std::make_pair(stream_id, used_stream_ids.at(stream_id)));
}
}
args_data->user_sync_callback(
rocprofiler_record_tracer_t{
rocprofiler_record_header_t{
@@ -361,9 +347,48 @@ void api_callback(activity_domain_t domain, uint32_t cid, const void* callback_d
rocprofiler_tracer_operation_id_t{cid},
rocprofiler_tracer_api_data_handle_t{callback_data, sizeof(*data)},
rocprofiler_tracer_activity_correlation_id_t{data->correlation_id},
rocprofiler_record_header_timestamp_t{rocprofiler_timestamp_t{*(data->phase_data)},
roctracer::hsa_support::timestamp_ns()},
0, 0, GetTid()},
rocprofiler_record_header_timestamp_t{rocprofiler_timestamp_t{0},
rocprofiler_timestamp_t{0}},
0, 0, GetTid(), ROCPROFILER_PHASE_ENTER},
args_data->session_id);
} else {
// TODO(aelwazir): STREAM ID GET need to be removed
// hipApiArgsInit((hip_api_id_t)cid, data);
// std::string hip_api_data_string = hipApiString((hip_api_id_t)cid, data);
// std::string start_str = "stream=";
// int start = hip_api_data_string.find(start_str);
// uint64_t stream_id = 0;
// if (start >= 0) {
// int end = hip_api_data_string.find(",", start);
// std::string stream_id_str = hip_api_data_string.substr(start + start_str.length(), end);
// std::stringstream ss;
// ss << std::hex << stream_id_str;
// ss >> stream_id;
// }
// {
// std::lock_guard<std::mutex> lock(stream_ids_map_lock);
// if (used_stream_ids.find(stream_id) == used_stream_ids.end()) {
// uint64_t stream_generated_id = stream_count.fetch_add(1, std::memory_order_release);
// used_stream_ids.emplace(stream_id, stream_generated_id);
// stream_ids.emplace(data->correlation_id,
// std::make_pair(stream_id, stream_generated_id));
// } else {
// stream_ids.emplace(data->correlation_id,
// std::make_pair(stream_id, used_stream_ids.at(stream_id)));
// }
// }
args_data->user_sync_callback(
rocprofiler_record_tracer_t{
rocprofiler_record_header_t{
ROCPROFILER_TRACER_RECORD,
rocprofiler_record_id_t{rocmtools::GetROCMToolObj()->GetUniqueRecordId()}},
rocprofiler_tracer_external_id_t{0}, ACTIVITY_DOMAIN_HIP_API,
rocprofiler_tracer_operation_id_t{cid},
rocprofiler_tracer_api_data_handle_t{callback_data, sizeof(*data)},
rocprofiler_tracer_activity_correlation_id_t{data->correlation_id},
rocprofiler_record_header_timestamp_t{rocprofiler_timestamp_t{0},
rocprofiler_timestamp_t{0}},
0, 0, GetTid(), ROCPROFILER_PHASE_EXIT},
args_data->session_id);
}
break;