[L0 v2] implement profiling support

Author: igchor

source/adapters/level_zero/v2/api.cpp

@@ -225,14 +225,6 @@ ur_result_t urKernelGetSuggestedLocalWorkSize(ur_kernel_handle_t hKernel,
   return UR_RESULT_ERROR_UNSUPPORTED_FEATURE;
 }
 
-ur_result_t urEventGetProfilingInfo(ur_event_handle_t hEvent,
-                                    ur_profiling_info_t propName,
-                                    size_t propSize, void *pPropValue,
-                                    size_t *pPropSizeRet) {
-  logger::error("{} function not implemented!", __FUNCTION__);
-  return UR_RESULT_ERROR_UNSUPPORTED_FEATURE;
-}
-
 ur_result_t urEventGetNativeHandle(ur_event_handle_t hEvent,
                                    ur_native_handle_t *phNativeEvent) {
   logger::error("{} function not implemented!", __FUNCTION__);

source/adapters/level_zero/v2/context.cpp

@@ -49,13 +49,12 @@ ur_context_handle_t_::ur_context_handle_t_(ze_context_handle_t hContext,
                                            bool ownZeContext)
     : commandListCache(hContext),
       eventPoolCache(phDevices[0]->Platform->getNumDevices(),
-                     [context = this,
-                      platform = phDevices[0]->Platform](DeviceId deviceId) {
+                     [context = this, platform = phDevices[0]->Platform](
+                         DeviceId deviceId, v2::event_flags_t flags) {
                        auto device = platform->getDeviceById(deviceId);
                        // TODO: just use per-context id?
                        return std::make_unique<v2::provider_normal>(
-                           context, device, v2::EVENT_COUNTER,
-                           v2::QUEUE_IMMEDIATE);
+                           context, device, v2::QUEUE_IMMEDIATE, flags);
                      }),
       hContext(hContext, ownZeContext),
       hDevices(phDevices, phDevices + numDevices),

source/adapters/level_zero/v2/event.cpp

@@ -14,15 +14,20 @@
 #include "event_pool.hpp"
 #include "event_provider.hpp"
 
-ur_event_handle_t_::ur_event_handle_t_(v2::event_allocation eventAllocation,
-                                       v2::event_pool *pool)
-    : type(eventAllocation.type), zeEvent(std::move(eventAllocation.borrow)),
-      pool(pool) {}
+#include "../ur_interface_loader.hpp"
+
+ur_event_handle_t_::ur_event_handle_t_(
+    v2::raii::cache_borrowed_event eventAllocation, v2::event_pool *pool)
+    : zeEvent(std::move(eventAllocation)), pool(pool),
+      adjustedEventStartTimestamp(0), recordEventEndTimestamp(0),
+      adjustedEventEndTimestamp(0),
+      zeTimerResolution(getDevice()->ZeDeviceProperties->timerResolution),
+      timestampMaxValue(getDevice()->getTimestampMask()) {}
 
 void ur_event_handle_t_::reset() {
   // consider make an abstraction for regular/counter based
   // events if there's more of this type of conditions
-  if (type == v2::event_type::EVENT_REGULAR) {
+  if (pool->getFlags() & v2::EVENT_FLAGS_COUNTER) {
     zeEventHostReset(zeEvent.get());
   }
 }
@@ -40,11 +45,90 @@ ur_result_t ur_event_handle_t_::release() {
   if (!RefCount.decrementAndTest())
     return UR_RESULT_SUCCESS;
 
+  if (isTimestamped() && adjustedEventEndTimestamp == 0) {
+    // L0 will write end timestamp to this event some time in the future,
+    // so we can't release it yet.
+    // TODO: delay releasing until the end timestamp is written.
+    return UR_RESULT_SUCCESS;
+  }
+
   pool->free(this);
 
   return UR_RESULT_SUCCESS;
 }
 
+bool ur_event_handle_t_::isTimestamped() const {
+  // If we are recording, the start time of the event will be non-zero.
+  return adjustedEventStartTimestamp != 0;
+}
+
+bool ur_event_handle_t_::isProfilingEnabled() const {
+  return pool->getFlags() & v2::EVENT_FLAGS_PROFILING_ENABLED;
+}
+
+ur_device_handle_t ur_event_handle_t_::getDevice() const {
+  return pool->getProvider()->device();
+}
+
+uint64_t ur_event_handle_t_::getEventStartTimestmap() const {
+  return adjustedEventStartTimestamp;
+}
+
+static uint64_t adjustEndEventTimestamp(uint64_t adjustedStartTimestamp,
+                                        uint64_t endTimestamp,
+                                        uint64_t timestampMaxValue,
+                                        uint64_t timerResolution) {
+  // End time needs to be adjusted for resolution and valid bits.
+  uint64_t adjustedTimestamp =
+      (endTimestamp & timestampMaxValue) * timerResolution;
+
+  // Handle a possible wrap-around (the underlying HW counter is < 64-bit).
+  // Note, it will not report correct time if there were multiple wrap
+  // arounds, and the longer term plan is to enlarge the capacity of the
+  // HW timestamps.
+  if (adjustedTimestamp < adjustedStartTimestamp)
+    adjustedTimestamp += timestampMaxValue * timerResolution;
+
+  return adjustedTimestamp;
+}
+
+uint64_t ur_event_handle_t_::getEventEndTimestamp() {
+  std::scoped_lock<ur_shared_mutex> lock(this->Mutex);
+
+  // If adjustedEventEndTimestamp on the event is non-zero it means it has
+  // collected the result of the queue already. In that case it has been
+  // adjusted and is ready for immediate return.
+  if (adjustedEventEndTimestamp)
+    return adjustedEventEndTimestamp;
+
+  // If the result is 0, we have not yet gotten results back and so we just
+  // return it.
+  if (recordEventEndTimestamp == 0)
+    return recordEventEndTimestamp;
+
+  // Now that we have the result, there is no need to keep it in the queue
+  // anymore, so we cache it on the event and evict the record from the
+  // queue.
+  adjustedEventEndTimestamp =
+      adjustEndEventTimestamp(getEventStartTimestmap(), recordEventEndTimestamp,
+                              timestampMaxValue, zeTimerResolution);
+  return adjustedEventEndTimestamp;
+}
+
+void ur_event_handle_t_::recordStartTimestamp() {
+  uint64_t deviceStartTimestamp = 0;
+  UR_CALL_THROWS(ur::level_zero::urDeviceGetGlobalTimestamps(
+      getDevice(), &deviceStartTimestamp, nullptr));
+
+  std::scoped_lock<ur_shared_mutex> lock(this->Mutex);
+
+  adjustedEventStartTimestamp = deviceStartTimestamp;
+}
+
+uint64_t *ur_event_handle_t_::getEventEndTimestampPtr() {
+  return &recordEventEndTimestamp;
+}
+
 namespace ur::level_zero {
 ur_result_t urEventRetain(ur_event_handle_t hEvent) { return hEvent->retain(); }
 
@@ -88,4 +172,82 @@ ur_result_t urEventGetInfo(ur_event_handle_t hEvent, ur_event_info_t propName,
 
   return UR_RESULT_SUCCESS;
 }
+
+ur_result_t urEventGetProfilingInfo(
+    ur_event_handle_t hEvent, ///< [in] handle of the event object
+    ur_profiling_info_t
+        propName, ///< [in] the name of the profiling property to query
+    size_t
+        propValueSize, ///< [in] size in bytes of the profiling property value
+    void *pPropValue,  ///< [out][optional] value of the profiling property
+    size_t *pPropValueSizeRet ///< [out][optional] pointer to the actual size in
+                              ///< bytes returned in propValue
+) {
+  // The event must either have profiling enabled or be recording timestamps.
+  bool isTimestampedEvent = hEvent->isTimestamped();
+  if (!hEvent->isProfilingEnabled() && !isTimestampedEvent) {
+    return UR_RESULT_ERROR_PROFILING_INFO_NOT_AVAILABLE;
+  }
+
+  UrReturnHelper returnValue(propValueSize, pPropValue, pPropValueSizeRet);
+
+  // For timestamped events we have the timestamps ready directly on the event
+  // handle, so we short-circuit the return.
+  if (isTimestampedEvent) {
+    uint64_t contextStartTime = hEvent->getEventStartTimestmap();
+    switch (propName) {
+    case UR_PROFILING_INFO_COMMAND_QUEUED:
+    case UR_PROFILING_INFO_COMMAND_SUBMIT:
+      return returnValue(contextStartTime);
+    case UR_PROFILING_INFO_COMMAND_END:
+    case UR_PROFILING_INFO_COMMAND_START:
+    case UR_PROFILING_INFO_COMMAND_COMPLETE: {
+      return returnValue(hEvent->getEventEndTimestamp());
+    }
+    default:
+      logger::error("urEventGetProfilingInfo: not supported ParamName");
+      return UR_RESULT_ERROR_INVALID_VALUE;
+    }
+  }
+
+  ze_kernel_timestamp_result_t tsResult;
+
+  auto zeTimerResolution =
+      hEvent->getDevice()->ZeDeviceProperties->timerResolution;
+  auto timestampMaxValue = hEvent->getDevice()->getTimestampMask();
+
+  switch (propName) {
+  case UR_PROFILING_INFO_COMMAND_START: {
+    ZE2UR_CALL(zeEventQueryKernelTimestamp, (hEvent->getZeEvent(), &tsResult));
+    uint64_t contextStartTime =
+        (tsResult.global.kernelStart & timestampMaxValue) * zeTimerResolution;
+    return returnValue(contextStartTime);
+  }
+  case UR_PROFILING_INFO_COMMAND_END:
+  case UR_PROFILING_INFO_COMMAND_COMPLETE: {
+    ZE2UR_CALL(zeEventQueryKernelTimestamp, (hEvent->getZeEvent(), &tsResult));
+
+    uint64_t contextStartTime =
+        (tsResult.global.kernelStart & timestampMaxValue);
+
+    auto adjustedEndTime =
+        adjustEndEventTimestamp(contextStartTime, tsResult.global.kernelEnd,
+                                timestampMaxValue, zeTimerResolution);
+    return returnValue(adjustedEndTime);
+  }
+  case UR_PROFILING_INFO_COMMAND_QUEUED:
+  case UR_PROFILING_INFO_COMMAND_SUBMIT:
+    // Note: No users for this case
+    // The "command_submit" time is implemented by recording submission
+    // timestamp with a call to urDeviceGetGlobalTimestamps before command
+    // enqueue.
+    //
+    return returnValue(uint64_t{0});
+  default:
+    logger::error("urEventGetProfilingInfo: not supported ParamName");
+    return UR_RESULT_ERROR_INVALID_VALUE;
+  }
+
+  return UR_RESULT_SUCCESS;
+}
 } // namespace ur::level_zero

source/adapters/level_zero/v2/event.hpp

@@ -24,7 +24,7 @@ class event_pool;
 
 struct ur_event_handle_t_ : _ur_object {
 public:
-  ur_event_handle_t_(v2::event_allocation eventAllocation,
+  ur_event_handle_t_(v2::raii::cache_borrowed_event eventAllocation,
                      v2::event_pool *pool);
 
   void reset();
@@ -33,8 +33,30 @@ struct ur_event_handle_t_ : _ur_object {
   ur_result_t retain();
   ur_result_t release();
 
+  // Tells if this event was created as a timestamp event, allowing profiling
+  // info even if profiling is not enabled.
+  bool isTimestamped() const;
+
+  // Tells if this event comes from a pool that has profiling enabled.
+  bool isProfilingEnabled() const;
+
+  // Device associated with this event
+  ur_device_handle_t getDevice() const;
+
+  void recordStartTimestamp();
+  uint64_t *getEventEndTimestampPtr();
+
+  uint64_t getEventStartTimestmap() const;
+  uint64_t getEventEndTimestamp();
+
 private:
-  v2::event_type type;
   v2::raii::cache_borrowed_event zeEvent;
   v2::event_pool *pool;
+
+  uint64_t adjustedEventStartTimestamp;
+  uint64_t recordEventEndTimestamp;
+  uint64_t adjustedEventEndTimestamp;
+
+  const uint64_t zeTimerResolution;
+  const uint64_t timestampMaxValue;
 };

source/adapters/level_zero/v2/event_pool.cpp

@@ -48,6 +48,10 @@ void event_pool::free(ur_event_handle_t_ *event) {
   event->RefCount.increment();
 }
 
-event_provider *event_pool::getProvider() { return provider.get(); }
+event_provider *event_pool::getProvider() const { return provider.get(); }
+
+event_flags_t event_pool::getFlags() const {
+  return getProvider()->eventFlags();
+}
 
 } // namespace v2

source/adapters/level_zero/v2/event_pool.hpp

@@ -46,7 +46,8 @@ class event_pool {
   // Free an event back to the pool. Thread safe.
   void free(ur_event_handle_t_ *event);
 
-  event_provider *getProvider();
+  event_provider *getProvider() const;
+  event_flags_t getFlags() const;
 
 private:
   std::unique_ptr<event_provider> provider;

source/adapters/level_zero/v2/event_pool_cache.cpp

@@ -16,29 +16,32 @@ namespace v2 {
 event_pool_cache::event_pool_cache(size_t max_devices,
                                    ProviderCreateFunc ProviderCreate)
     : providerCreate(ProviderCreate) {
-  pools.resize(max_devices);
+  pools.resize(max_devices * (1ULL << EVENT_FLAGS_USED_BITS));
 }
 
 event_pool_cache::~event_pool_cache() {}
 
-raii::cache_borrowed_event_pool event_pool_cache::borrow(DeviceId id) {
+raii::cache_borrowed_event_pool event_pool_cache::borrow(DeviceId id,
+                                                         event_flags_t flags) {
   std::unique_lock<ur_mutex> Lock(mutex);
 
-  if (id >= pools.size()) {
+  event_descriptor event_desc{id, flags};
+
+  if (event_desc.index() >= pools.size()) {
     return nullptr;
   }
 
-  auto &vec = pools[id];
+  auto &vec = pools[event_desc.index()];
   if (vec.empty()) {
-    vec.emplace_back(std::make_unique<event_pool>(providerCreate(id)));
+    vec.emplace_back(std::make_unique<event_pool>(providerCreate(id, flags)));
   }
 
   auto pool = vec.back().release();
   vec.pop_back();
 
-  return raii::cache_borrowed_event_pool(pool, [this](event_pool *pool) {
+  return raii::cache_borrowed_event_pool(pool, [this, flags](event_pool *pool) {
     std::unique_lock<ur_mutex> Lock(mutex);
-    pools[pool->Id()].emplace_back(pool);
+    pools[event_descriptor{pool->Id(), flags}.index()].emplace_back(pool);
   });
 }
 

source/adapters/level_zero/v2/event_pool_cache.hpp

@@ -32,17 +32,28 @@ using cache_borrowed_event_pool =
 
 class event_pool_cache {
 public:
-  using ProviderCreateFunc =
-      std::function<std::unique_ptr<event_provider>(DeviceId)>;
+  using ProviderCreateFunc = std::function<std::unique_ptr<event_provider>(
+      DeviceId, event_flags_t flags)>;
 
   event_pool_cache(size_t max_devices, ProviderCreateFunc);
   ~event_pool_cache();
 
-  raii::cache_borrowed_event_pool borrow(DeviceId);
+  raii::cache_borrowed_event_pool borrow(DeviceId, event_flags_t flags);
 
 private:
   ur_mutex mutex;
   ProviderCreateFunc providerCreate;
+
+  struct event_descriptor {
+    DeviceId device;
+    event_flags_t flags;
+
+    uint64_t index() {
+      return uint64_t(flags) | (uint64_t(device) << EVENT_FLAGS_USED_BITS);
+    }
+  };
+
+  // Indexed by event_descriptor::index()
   std::vector<std::vector<std::unique_ptr<event_pool>>> pools;
 };
 

source/adapters/level_zero/v2/event_provider.hpp

@@ -21,7 +21,12 @@
 
 namespace v2 {
 
-enum event_type { EVENT_REGULAR, EVENT_COUNTER };
+using event_flags_t = uint32_t;
+enum event_flag_t {
+  EVENT_FLAGS_COUNTER = UR_BIT(0),
+  EVENT_FLAGS_PROFILING_ENABLED = UR_BIT(1),
+};
+static constexpr size_t EVENT_FLAGS_USED_BITS = 2;
 
 class event_provider;
 
@@ -31,16 +36,12 @@ using cache_borrowed_event =
                     std::function<void(::ze_event_handle_t)>>;
 } // namespace raii
 
-struct event_allocation {
-  event_type type;
-  raii::cache_borrowed_event borrow;
-};
-
 class event_provider {
 public:
   virtual ~event_provider() = default;
-  virtual event_allocation allocate() = 0;
+  virtual raii::cache_borrowed_event allocate() = 0;
   virtual ur_device_handle_t device() = 0;
+  virtual event_flags_t eventFlags() const = 0;
 };
 
 } // namespace v2