Make the ROCM profiler thread-safe, session-aware and preserve logical ordering between CPU and GPU events

include/onnxruntime/core/common/profiler_common.h

@@ -27,26 +27,49 @@ static constexpr const char* event_categor_names_[EVENT_CATEGORY_MAX] = {
 
 // Timing record for all events.
 struct EventRecord {
+  EventRecord() = default;
   EventRecord(EventCategory category,
               int process_id,
               int thread_id,
-              std::string event_name,
+              std::string&& event_name,
               long long time_stamp,
               long long duration,
-              std::unordered_map<std::string, std::string>&& event_args) : cat(category),
-                                                                           pid(process_id),
-                                                                           tid(thread_id),
-                                                                           name(std::move(event_name)),
-                                                                           ts(time_stamp),
-                                                                           dur(duration),
-                                                                           args(event_args) {}
-  EventCategory cat;
-  int pid;
-  int tid;
-  std::string name;
-  long long ts;
-  long long dur;
-  std::unordered_map<std::string, std::string> args;
+              std::unordered_map<std::string, std::string>&& event_args)
+      : cat(category),
+        pid(process_id),
+        tid(thread_id),
+        name(std::move(event_name)),
+        ts(time_stamp),
+        dur(duration),
+        args(std::move(event_args)) {}
+
+  EventRecord(EventCategory category,
+              int process_id,
+              int thread_id,
+              const std::string& event_name,
+              long long time_stamp,
+              long long duration,
+              const std::unordered_map<std::string, std::string>& event_args)
+      : cat(category),
+        pid(process_id),
+        tid(thread_id),
+        name(event_name),
+        ts(time_stamp),
+        dur(duration),
+        args(event_args) {}
+
+  EventRecord(const EventRecord& other) = default;
+  EventRecord(EventRecord&& other) = default;
+  EventRecord& operator=(const EventRecord& other) = default;
+  EventRecord& operator=(EventRecord&& other) = default;
+
+  EventCategory cat = EventCategory::API_EVENT;
+  int pid = -1;
+  int tid = -1;
+  std::string name{};
+  long long ts = 0;
+  long long dur = 0;
+  std::unordered_map<std::string, std::string> args{};
 };
 
 using Events = std::vector<EventRecord>;
@@ -55,7 +78,7 @@ using Events = std::vector<EventRecord>;
 class EpProfiler {
  public:
   virtual ~EpProfiler() = default;
-  virtual bool StartProfiling() = 0;                                    // called when profiling starts
+  virtual bool StartProfiling(TimePoint profiling_start_time) = 0;      // called when profiling starts
   virtual void EndProfiling(TimePoint start_time, Events& events) = 0;  // called when profiling ends, save all captures numbers to "events"
   virtual void Start(uint64_t){};                                       // called before op start, accept an id as argument to identify the op
   virtual void Stop(uint64_t){};                                        // called after op stop, accept an id as argument to identify the op

onnxruntime/core/common/profiler.cc

@@ -25,7 +25,7 @@ ::onnxruntime::TimePoint profiling::Profiler::Start() {
   auto ts = TimeDiffMicroSeconds(profiling_start_time_, start_time);
   for (const auto& ep_profiler : ep_profilers_) {
     ep_profiler->Start(ts);
-  } 
+  }
   return start_time;
 }
 
@@ -49,7 +49,7 @@ void Profiler::StartProfiling(const logging::Logger* custom_logger) {
   custom_logger_ = custom_logger;
   profiling_start_time_ = std::chrono::high_resolution_clock::now();
   for (const auto& ep_profiler : ep_profilers_) {
-    ep_profiler->StartProfiling();
+    ep_profiler->StartProfiling(profiling_start_time_);
   }
 }
 
@@ -62,7 +62,7 @@ void Profiler::StartProfiling(const std::basic_string<T>& file_name) {
   profile_stream_file_ = ToUTF8String(file_name);
   profiling_start_time_ = std::chrono::high_resolution_clock::now();
   for (const auto& ep_profiler : ep_profilers_) {
-    ep_profiler->StartProfiling();
+    ep_profiler->StartProfiling(profiling_start_time_);
   }
 }
 
@@ -87,7 +87,7 @@ void Profiler::EndTimeAndRecordEvent(EventCategory category,
     //TODO: sync_gpu if needed.
     std::lock_guard<OrtMutex> lock(mutex_);
     if (events_.size() < max_num_events_) {
-      events_.emplace_back(event);
+      events_.emplace_back(std::move(event));
     } else {
       if (session_logger_ && !max_events_reached) {
         LOGS(*session_logger_, ERROR)

onnxruntime/core/common/profiler.h

@@ -67,7 +67,8 @@ class Profiler {
   */
   uint64_t GetStartTimeNs() const {
     return std::chrono::duration_cast<std::chrono::nanoseconds>(
-      profiling_start_time_.time_since_epoch()).count();
+               profiling_start_time_.time_since_epoch())
+        .count();
   }
   /*
   Record a single event. Time is measured till the call of this function from
@@ -108,12 +109,12 @@ class Profiler {
   static void SetGlobalMaxNumEvents(size_t new_max_num_events) {
     global_max_num_events_.store(new_max_num_events);
   }
-  
+
   void AddEpProfilers(std::unique_ptr<EpProfiler> ep_profiler) {
     if (ep_profiler) {
       ep_profilers_.push_back(std::move(ep_profiler));
       if (enabled_) {
-        ep_profilers_.back()->StartProfiling();
+        ep_profilers_.back()->StartProfiling(profiling_start_time_);
       }
     }
   }

onnxruntime/core/common/profiler_common.cc

@@ -50,4 +50,3 @@ std::string demangle(const std::string& name) {
 
 }  // namespace profiling
 }  // namespace onnxruntime
-

onnxruntime/core/providers/cuda/cuda_profiler.cc

@@ -93,7 +93,7 @@ void CUPTIAPI CudaProfiler::BufferCompleted(CUcontext, uint32_t, uint8_t* buffer
   free(buffer);
 }
 
-bool CudaProfiler::StartProfiling() {
+bool CudaProfiler::StartProfiling(TimePoint /* profiling_start_time */) {
   if (!enabled.test_and_set()) {
     if (cuptiActivityEnable(CUPTI_ACTIVITY_KIND_RUNTIME) == CUPTI_SUCCESS &&
         cuptiActivityEnable(CUPTI_ACTIVITY_KIND_DRIVER) == CUPTI_SUCCESS &&
@@ -146,7 +146,7 @@ void CudaProfiler::EndProfiling(TimePoint start_time, Events& events) {
         for (auto& evt_iter : map_iter.second) {
           evt_iter.args["op_name"] = insert_iter->args["op_name"];
         }
-        insert_iter = events.insert(insert_iter+1, map_iter.second.begin(), map_iter.second.end());
+        insert_iter = events.insert(insert_iter + 1, map_iter.second.begin(), map_iter.second.end());
       } else {
         insert_iter = events.insert(insert_iter, map_iter.second.begin(), map_iter.second.end());
       }
@@ -197,7 +197,7 @@ void CudaProfiler::Clear() {
   }
 }
 
-#else // for cuda 10.x, no profiling
+#else  // for cuda 10.x, no profiling
 
 void CUPTIAPI CudaProfiler::BufferRequested(uint8_t**, size_t*, size_t*) {}
 void CUPTIAPI CudaProfiler::BufferCompleted(CUcontext, uint32_t, uint8_t*, size_t, size_t) {}

onnxruntime/core/providers/cuda/cuda_profiler.h

@@ -31,7 +31,7 @@ class CudaProfiler final : public EpProfiler {
     return *this;
   }
   ~CudaProfiler();
-  bool StartProfiling() override;
+  bool StartProfiling(TimePoint profiling_start_time) override;
   void EndProfiling(TimePoint start_time, Events& events) override;
   void Start(uint64_t) override;
   void Stop(uint64_t) override;
@@ -72,13 +72,13 @@ namespace profiling {
 
 class CudaProfiler final : public EpProfiler {
  public:
-  bool StartProfiling() override { return true; }
+  bool StartProfiling(TimePoint) override { return true; }
   void EndProfiling(TimePoint, Events&) override{};
   void Start(uint64_t) override{};
   void Stop(uint64_t) override{};
 };
 
-}
-}
+}  // namespace profiling
+}  // namespace onnxruntime
 
 #endif