AI/rocm-systems
2
0
Fork 0
Code Issues Pull Requests Actions Packages Projects Releases Wiki Activity

Merge "SWDEV-254329 : extending debug trace with timestamps, cmake option '-DCMAKE_DEBUG_TRACE=1'" into amd-staging

Browse Source 
[ROCm/roctracer commit: d5c138b518]
This commit is contained in:
Evgeny Shcherbakov
2020-10-20 12:34:23 -04:00
committed by Gerrit Code Review
parent d8da7486f7 9eeab1fb91
commit e98e56578b
2 changed files with 20 additions and 15 deletions
Download Patch File Download Diff File Expand all files Collapse all files
projects/roctracer/src/core/roctracer.cpp
+14 -9
View File
@@ -93,7 +93,6 @@ THE SOFTWARE.
#define ONLOAD_TRACE_BEG() ONLOAD_TRACE("begin") #define ONLOAD_TRACE_BEG() ONLOAD_TRACE("begin")
#define ONLOAD_TRACE_END() ONLOAD_TRACE("end") #define ONLOAD_TRACE_END() ONLOAD_TRACE("end")
static inline uint32_t GetPid() { return syscall(__NR_getpid); } static inline uint32_t GetPid() { return syscall(__NR_getpid); }
static inline uint32_t GetTid() { return syscall(__NR_gettid); } static inline uint32_t GetTid() { return syscall(__NR_gettid); }
@@ -173,6 +172,9 @@ void RestoreHsaApi() {
} }
namespace roctracer { namespace roctracer {
// timestamp definitino
typedef hsa_rt_utils::Timer::timestamp_t timestamp_t;
decltype(hsa_amd_memory_async_copy)* hsa_amd_memory_async_copy_fn; decltype(hsa_amd_memory_async_copy)* hsa_amd_memory_async_copy_fn;
decltype(hsa_amd_memory_async_copy_rect)* hsa_amd_memory_async_copy_rect_fn; decltype(hsa_amd_memory_async_copy_rect)* hsa_amd_memory_async_copy_rect_fn;
@@ -348,6 +350,8 @@ void* HIP_SyncApiDataCallback(
const void* callback_data, const void* callback_data,
void* arg) void* arg)
{ {
static hsa_rt_utils::Timer timer;
void* ret = NULL; void* ret = NULL;
const hip_api_data_t* data = reinterpret_cast<const hip_api_data_t*>(callback_data); const hip_api_data_t* data = reinterpret_cast<const hip_api_data_t*>(callback_data);
hip_api_data_t* data_ptr = const_cast<hip_api_data_t*>(data); hip_api_data_t* data_ptr = const_cast<hip_api_data_t*>(data);
@@ -393,8 +397,8 @@ void* HIP_SyncApiDataCallback(
} }
const char * name = roctracer_op_string(ACTIVITY_DOMAIN_HIP_API, op_id, 0); const char * name = roctracer_op_string(ACTIVITY_DOMAIN_HIP_API, op_id, 0);
DEBUG_TRACE("HIP_SyncApiDataCallback(\"%s\") phase(%d): op(%u) record(%p) data(%p) pool(%p) depth(%d) correlation_id(%lu)\n", DEBUG_TRACE("HIP_SyncApiDataCallback(\"%s\") phase(%d): op(%u) record(%p) data(%p) pool(%p) depth(%d) correlation_id(%lu) time_ns(%lu)\n",
name, phase, op_id, record, data, pool, (int)(record_pair_stack.size()), (data_ptr) ? data_ptr->correlation_id : 0); name, phase, op_id, record, data, pool, (int)(record_pair_stack.size()), (data_ptr) ? data_ptr->correlation_id : 0, timer.timestamp_ns());
return ret; return ret;
} }
@@ -406,6 +410,7 @@ void* HIP_SyncActivityCallback(
void* arg) void* arg)
{ {
static hsa_rt_utils::Timer timer; static hsa_rt_utils::Timer timer;
const timestamp_t timestamp_ns = timer.timestamp_ns();
void* ret = NULL; void* ret = NULL;
const hip_api_data_t* data = reinterpret_cast<const hip_api_data_t*>(callback_data); const hip_api_data_t* data = reinterpret_cast<const hip_api_data_t*>(callback_data);
@@ -436,7 +441,7 @@ void* HIP_SyncActivityCallback(
// Filing record info // Filing record info
record->domain = ACTIVITY_DOMAIN_HIP_API; record->domain = ACTIVITY_DOMAIN_HIP_API;
record->op = op_id; record->op = op_id;
record->begin_ns = timer.timestamp_ns(); record->begin_ns = timestamp_ns;
// Correlation ID generating // Correlation ID generating
uint64_t correlation_id = data->correlation_id; uint64_t correlation_id = data->correlation_id;
@@ -461,7 +466,7 @@ void* HIP_SyncActivityCallback(
} }
// Filing record info // Filing record info
record->end_ns = timer.timestamp_ns(); record->end_ns = timestamp_ns;
record->process_id = syscall(__NR_getpid); record->process_id = syscall(__NR_getpid);
record->thread_id = syscall(__NR_gettid); record->thread_id = syscall(__NR_gettid);
@@ -485,8 +490,8 @@ void* HIP_SyncActivityCallback(
} }
const char * name = roctracer_op_string(ACTIVITY_DOMAIN_HIP_API, op_id, 0); const char * name = roctracer_op_string(ACTIVITY_DOMAIN_HIP_API, op_id, 0);
DEBUG_TRACE("HIP_SyncActivityCallback(\"%s\") phase(%d): op(%u) record(%p) data(%p) pool(%p) depth(%d) correlation_id(%lu)\n", DEBUG_TRACE("HIP_SyncActivityCallback(\"%s\") phase(%d): op(%u) record(%p) data(%p) pool(%p) depth(%d) correlation_id(%lu) beg_ns(%lu) end_ns(%lu)\n",
name, phase, op_id, record, data, pool, (int)(record_pair_stack.size()), (data_ptr) ? data_ptr->correlation_id : 0); name, phase, op_id, record, data, pool, (int)(record_pair_stack.size()), (data_ptr) ? data_ptr->correlation_id : 0, timestamp_ns);
return ret; return ret;
} }
@@ -503,8 +508,8 @@ void HCC_AsyncActivityCallback(uint32_t op_id, void* record, void* arg) {
pool->Write(*record_ptr); pool->Write(*record_ptr);
const char * name = roctracer_op_string(ACTIVITY_DOMAIN_HCC_OPS, record_ptr->op, record_ptr->kind); const char * name = roctracer_op_string(ACTIVITY_DOMAIN_HCC_OPS, record_ptr->op, record_ptr->kind);
DEBUG_TRACE("HCC_AsyncActivityCallback(\"%s\"): op(%u) kind(%u) record(%p) pool(%p) correlation_id(%d)\n", DEBUG_TRACE("HCC_AsyncActivityCallback(\"%s\"): op(%u) kind(%u) record(%p) pool(%p) correlation_id(%d) beg_ns(%lu) end_ns(%lu)\n",
name, record_ptr->op, record_ptr->kind, record, pool, record_ptr->correlation_id); name, record_ptr->op, record_ptr->kind, record, pool, record_ptr->correlation_id, record_ptr->begin_ns, record_ptr->end_ns);
} }
// Open output file // Open output file
projects/roctracer/test/tool/tracer_tool.cpp
+6 -6
View File
@@ -454,8 +454,8 @@ void hip_api_callback(
} }
const char * name = roctracer_op_string(domain, cid, 0); const char * name = roctracer_op_string(domain, cid, 0);
DEBUG_TRACE("hip_api_callback(\"%s\") phase(%d): cid(%u) data(%p) entry(%p) name(\"%s\") correlation_id(%lu)\n", DEBUG_TRACE("hip_api_callback(\"%s\") phase(%d): cid(%u) data(%p) entry(%p) name(\"%s\") correlation_id(%lu) timestamp(%lu)\n",
name, data->phase, cid, data, entry, (entry) ? entry->name : NULL, data->correlation_id); name, data->phase, cid, data, entry, (entry) ? entry->name : NULL, data->correlation_id, timestamp);
} }
void mark_api_callback( void mark_api_callback(
@@ -500,8 +500,8 @@ void hip_api_flush_cb(hip_api_trace_entry_t* entry) {
oss << std::dec << rec_ss.str() << " " << str; oss << std::dec << rec_ss.str() << " " << str;
const char * name = roctracer_op_string(entry->domain, entry->cid, 0); const char * name = roctracer_op_string(entry->domain, entry->cid, 0);
DEBUG_TRACE("hip_api_flush_cb(\"%s\"): domain(%u) cid(%u) entry(%p) name(\"%s\" correlation_id(%lu))\n", DEBUG_TRACE("hip_api_flush_cb(\"%s\"): domain(%u) cid(%u) entry(%p) name(\"%s\" correlation_id(%lu) beg(%lu) end(%lu))\n",
name, entry->domain, entry->cid, entry, entry->name, correlation_id); name, entry->domain, entry->cid, entry, entry->name, correlation_id, begin_timestamp, end_timestamp);
if (domain == ACTIVITY_DOMAIN_HIP_API) { if (domain == ACTIVITY_DOMAIN_HIP_API) {
#if HIP_PROF_HIP_API_STRING #if HIP_PROF_HIP_API_STRING
@@ -631,8 +631,8 @@ void pool_activity_callback(const char* begin, const char* end, void* arg) {
while (record < end_record) { while (record < end_record) {
const char * name = roctracer_op_string(record->domain, record->op, record->kind); const char * name = roctracer_op_string(record->domain, record->op, record->kind);
DEBUG_TRACE("pool_activity_callback(\"%s\"): domain(%u) op(%u) kind(%u) record(%p) correlation_id(%lu)\n", DEBUG_TRACE("pool_activity_callback(\"%s\"): domain(%u) op(%u) kind(%u) record(%p) correlation_id(%lu) beg(%lu) end(%lu)\n",
name, record->domain, record->op, record->kind, record, record->correlation_id); name, record->domain, record->op, record->kind, record, record->correlation_id, record->begin_ns, record->end_ns);
switch(record->domain) { switch(record->domain) {
case ACTIVITY_DOMAIN_HCC_OPS: case ACTIVITY_DOMAIN_HCC_OPS: