Instrument cache operations

Author: uditagarwal97

sycl/source/detail/persistent_device_code_cache.cpp

@@ -16,6 +16,8 @@
 #include <fstream>
 #include <optional>
 
+#include <time.h>
+
 #if defined(__SYCL_RT_OS_POSIX_SUPPORT)
 #include <unistd.h>
 #else
@@ -402,6 +404,10 @@ void PersistentDeviceCodeCache::putItemToDisc(
     const SerializedObj &SpecConsts, const std::string &BuildOptionsString,
     const ur_program_handle_t &NativePrg) {
 
+#ifdef __SYCL_INSTRUMENT_PERSISTENT_CACHE
+  InstrumentCache Instrument{"putItemToDisc: "};
+#endif
+
   if (!areImagesCacheable(Imgs))
     return;
 
@@ -460,8 +466,12 @@ void PersistentDeviceCodeCache::putItemToDisc(
   }
 
   // Update the cache size file and trigger cache eviction if needed.
-  if (TotalSize)
+  if (TotalSize) {
+#ifdef __SYCL_INSTRUMENT_PERSISTENT_CACHE
+    InstrumentCache Instrument{"Eviction: "};
+#endif
     updateCacheFileSizeAndTriggerEviction(getRootDir(), TotalSize);
+  }
 }
 
 void PersistentDeviceCodeCache::putCompiledKernelToDisc(
@@ -513,6 +523,10 @@ std::vector<std::vector<char>> PersistentDeviceCodeCache::getItemFromDisc(
   if (!areImagesCacheable(Imgs))
     return {};
 
+#ifdef __SYCL_INSTRUMENT_PERSISTENT_CACHE
+  InstrumentCache Instrument{"getItemFromDisc: "};
+#endif
+
   std::vector<const RTDeviceBinaryImage *> SortedImgs = getSortedImages(Imgs);
   std::vector<std::vector<char>> Binaries(Devices.size());
   std::string FileNames;
@@ -538,8 +552,12 @@ std::vector<std::vector<char>> PersistentDeviceCodeCache::getItemFromDisc(
 
           // Explicitly update the access time of the file. This is required for
           // eviction.
-          if (isEvictionEnabled())
+          if (isEvictionEnabled()) {
+#ifdef __SYCL_INSTRUMENT_PERSISTENT_CACHE
+            InstrumentCache Instrument{"Updating file access time: "};
+#endif
             updateFileModificationTime(FileName + ".bin");
+          }
 
           FileNames += FullFileName + ";";
           break;

sycl/source/detail/persistent_device_code_cache.hpp

@@ -8,6 +8,7 @@
 
 #pragma once
 
+#include <chrono>
 #include <detail/config.hpp>
 #include <detail/device_binary_image.hpp>
 #include <fcntl.h>
@@ -20,6 +21,12 @@
 #include <thread>
 #include <vector>
 
+#define __SYCL_INSTRUMENT_PERSISTENT_CACHE
+
+#ifdef __SYCL_INSTRUMENT_PERSISTENT_CACHE
+#include <chrono>
+#endif
+
 namespace sycl {
 inline namespace _V1 {
 namespace detail {
@@ -90,6 +97,29 @@ class PersistentDeviceCodeCache {
    *  - on cache read operation it is treated as cache miss.
    */
 private:
+#ifdef __SYCL_INSTRUMENT_PERSISTENT_CACHE
+  // Class to instrument cache operations.
+  class InstrumentCache {
+    std::string PrintMsg;
+    std::chrono::high_resolution_clock::time_point StartTime;
+
+  public:
+    InstrumentCache(const std::string &Name) : PrintMsg(Name) {
+      // Store start time.
+      StartTime = std::chrono::high_resolution_clock::now();
+    }
+    ~InstrumentCache() {
+      // Calculate time spent and print message.
+      auto EndTime = std::chrono::high_resolution_clock::now();
+      auto Duration = std::chrono::duration_cast<std::chrono::nanoseconds>(
+                          EndTime - StartTime)
+                          .count();
+      PersistentDeviceCodeCache::trace(PrintMsg + std::to_string(Duration) +
+                                       "ns");
+    }
+  };
+#endif
+
   /* Write built binary to persistent cache
    * Format: BinarySize, Binary
    */