Correct timestamp skew adjustments for kernel and async copy tracing (#827)

[ROCm/rocprofiler-sdk commit: e2bce49655]

projects/rocprofiler-sdk/source/lib/rocprofiler-sdk/hsa/async_copy.cpp

@@ -340,6 +340,14 @@ operator+=(hsa_amd_profiling_async_copy_time_t& lhs, uint64_t rhs)
     return lhs;
 }
 
+hsa_amd_profiling_async_copy_time_t&
+operator-=(hsa_amd_profiling_async_copy_time_t& lhs, uint64_t rhs)
+{
+    lhs.start -= rhs;
+    lhs.end -= rhs;
+    return lhs;
+}
+
 hsa_amd_profiling_async_copy_time_t&
 operator*=(hsa_amd_profiling_async_copy_time_t& lhs, uint64_t rhs)
 {
@@ -377,15 +385,15 @@ async_copy_handler(hsa_signal_value_t signal_value, void* arg)
     // normalize
     copy_time *= sysclock_period;
 
+    // below is a hack for clock skew issues:
+    // the timestamp of this handler for the copy will always be after when the copy ended
+    if(ts < copy_time.end) copy_time -= (copy_time.end - ts);
+
     // below is a hack for clock skew issues:
     // the timestamp of the function call triggering the copy will always be before when the copy
     // started
     if(copy_time.start < _data->start_ts) copy_time += (_data->start_ts - copy_time.start);
 
-    // below is a hack for clock skew issues:
-    // the timestamp of this handler for the copy will always be after when the copy ended
-    if(copy_time.end < ts) copy_time += (ts - copy_time.end);
-
     // if we encounter this in CI, it will cause test to fail
     ROCP_CI_LOG_IF(ERROR, copy_time_status == HSA_STATUS_SUCCESS && copy_time.end < copy_time.start)
         << "hsa_amd_profiling_get_async_copy_time for returned async times where the end time ("

projects/rocprofiler-sdk/source/lib/rocprofiler-sdk/kernel_dispatch/tracing.cpp

@@ -69,6 +69,14 @@ operator+=(hsa_amd_profiling_dispatch_time_t& lhs, uint64_t rhs)
     return lhs;
 }
 
+hsa_amd_profiling_dispatch_time_t&
+operator-=(hsa_amd_profiling_dispatch_time_t& lhs, uint64_t rhs)
+{
+    lhs.start -= rhs;
+    lhs.end -= rhs;
+    return lhs;
+}
+
 hsa_amd_profiling_dispatch_time_t&
 operator*=(hsa_amd_profiling_dispatch_time_t& lhs, uint64_t rhs)
 {
@@ -119,17 +127,17 @@ dispatch_complete(queue_info_session_t& session)
         // normalize
         dispatch_time *= sysclock_period;
 
+        // below is a hack for clock skew issues:
+        // the timestamp of this handler for the kernel dispatch will always be after when the
+        // kernel completed
+        if(ts < dispatch_time.end) dispatch_time -= (dispatch_time.end - ts);
+
         // below is a hack for clock skew issues:
         // the timestamp of the packet rewriter for the kernel packet will always be before when the
         // kernel started
         if(dispatch_time.start < session.enqueue_ts)
             dispatch_time += (session.enqueue_ts - dispatch_time.start);
 
-        // below is a hack for clock skew issues:
-        // the timestamp of this handler for the kernel dispatch will always be after when the
-        // kernel completed
-        if(dispatch_time.end < ts) dispatch_time += (ts - dispatch_time.end);
-
         callback_record.start_timestamp = dispatch_time.start;
         callback_record.end_timestamp   = dispatch_time.end;
     }