From c0919602eed8034cd3fe05da9aa10d9a96643d75 Mon Sep 17 00:00:00 2001 From: Shivam Raikundalia Date: Thu, 19 Sep 2024 09:32:33 -0700 Subject: [PATCH] Roctracer events show up out of order (#990) Summary: Pull Request resolved: https://github.com/pytorch/kineto/pull/990 Add debug to show that some events in roctracer can start before the previous one ends Differential Revision: D63033163 --- libkineto/src/RoctracerLogger.cpp | 8 +++++++- 1 file changed, 7 insertions(+), 1 deletion(-) diff --git a/libkineto/src/RoctracerLogger.cpp b/libkineto/src/RoctracerLogger.cpp index e0cff8337..32fea42ca 100644 --- a/libkineto/src/RoctracerLogger.cpp +++ b/libkineto/src/RoctracerLogger.cpp @@ -301,7 +301,8 @@ void RoctracerLogger::activity_callback(const char* begin, const char* end, void std::unique_lock lock(s_flush.mutex_); const roctracer_record_t* record = (const roctracer_record_t*)(begin); const roctracer_record_t* end_record = (const roctracer_record_t*)(end); - + static uint64_t last_end = 0; + static std::string last_kernel_name = ""; while (record < end_record) { if (record->correlation_id > s_flush.maxCompletedCorrelationId_) { s_flush.maxCompletedCorrelationId_ = record->correlation_id; @@ -320,6 +321,11 @@ void RoctracerLogger::activity_callback(const char* begin, const char* end, void ? demangle(record->kernel_name) : std::string() ); + if (record->begin_ns < last_end && !row->kernelName.empty() && !last_kernel_name.empty()) { + LOG(WARNING) << "Out of order activity: " << record->begin_ns << " < " << last_end << ". Difference: " << (last_end - record->begin_ns) << " ns. Kernel: " << row->kernelName << " last Kernel: " << last_kernel_name; + } + last_end = record->end_ns; + last_kernel_name = row->kernelName; insert_row_to_buffer(row); roctracer_next_record(record, &record); }