[SYCL] Repurpose SYCL_CACHE_TRACE to enable fine-grained tracing of SYCL caches (#15822)

Currently, we use SYCL_CACHE_TRACE for events in persistent cache only.
This PR repurposes SYCL_CACHE_TRACE to also enable tracing of in-memory
cache and kernel_compiler.

After this change, SYCL_CACHE_TRACE will accept the following bit-masks:

| Bit-mask | Corresponding cache tracing |
| ------ | ----------- |
| 0x01 | Enable tracing of persistent cache |
| 0x02 | Enable tracing of in-memory cache |
| 0x04 | Enable tracing of `kernel_compiler` cache |


Any valid combination of the above bit-masks can be used to
enable/disable tracing of the corresponding caches.

---------

Co-authored-by: Steffen Larsen <[email protected]>

Author: uditagarwal97

sycl/doc/EnvironmentVariables.md

@@ -210,7 +210,7 @@ variables in production code.</span>
 | `SYCL_USE_KERNEL_SPV` | Path to the SPIR-V binary | Load device image from the specified file. If runtime is unable to read the file, `sycl::runtime_error` exception is thrown. The image is assumed to have been created using the `-fno-sycl-dead-args-optimization` option. |
 | `SYCL_DUMP_IMAGES` | Any(\*) | Dump device image binaries to file. Control has no effect if `SYCL_USE_KERNEL_SPV` is set. |
 | `SYCL_HOST_UNIFIED_MEMORY` | Integer | Enforce host unified memory support or lack of it for the execution graph builder. If set to 0, it is enforced as not supported by all devices. If set to 1, it is enforced as supported by all devices. |
-| `SYCL_CACHE_TRACE` | Any(\*) | If the variable is set, messages are sent to std::cerr when caching events or non-blocking failures happen (e.g. unable to access cache item file). |
+| `SYCL_CACHE_TRACE` | Described [below](#sycl_cache_trace-options). | Enable tracing for different SYCL and `kernel_compiler` caches. |
 | `SYCL_PARALLEL_FOR_RANGE_ROUNDING_TRACE` | Any(\*) | Enables tracing of `parallel_for` invocations with rounded-up ranges. |
 | `SYCL_PI_SUPPRESS_ERROR_MESSAGE` | Any(\*) | Suppress printing of error message, only used for CI in order not to interrupt errors generated by underlying toolchains; note that the variable only modifies the printing of the error message (error value, name, description and location), the handling of error return code and aborting/throwing behaviour remains unchanged. |
 | `SYCL_JIT_COMPILER_DEBUG` | Any(\*) | Passes can specify their own debug types, `sycl-spec-const-materializer` enables debug output generation in specialization constants materialization pass. |
@@ -245,6 +245,17 @@ Supported tracing levels are in the table below
 | 2 | Enable tracing of the UR calls |
 | -1 | Enable all levels of tracing |
 
+### `SYCL_CACHE_TRACE` Options
+
+`SYCL_CACHE_TRACE` accepts a bit-mask to control the tracing of different SYCL caches. The input value is parsed as an integer and the following bit-masks are used to determine the tracing behavior:
+| Bit-mask | Corresponding cache tracing |
+| ------ | ----------- |
+| 0x01 | Enable tracing of persistent cache |
+| 0x02 | Enable tracing of in-memory cache |
+| 0x04 | Enable tracing of `kernel_compiler` cache |
+
+Any valid combination of the above bit-masks can be used to enable/disable tracing of the corresponding caches. If the input value is not 0 and not a valid number, the disk cache tracing will be enabled (deprecated behavior).
+The default value is 0 and no tracing is enabled.
 
 ## Debugging variables for Level Zero Plugin
 

sycl/source/detail/config.def

@@ -26,7 +26,7 @@ CONFIG(SYCL_PROGRAM_APPEND_COMPILE_OPTIONS, 64, __SYCL_PROGRAM_APPEND_COMPILE_OP
 CONFIG(SYCL_HOST_UNIFIED_MEMORY, 1, __SYCL_HOST_UNIFIED_MEMORY)
 // 260 (Windows limit) - 12 (filename) - 84 (cache directory structure)
 CONFIG(SYCL_CACHE_DIR, 164, __SYCL_CACHE_DIR)
-CONFIG(SYCL_CACHE_TRACE, 1, __SYCL_CACHE_TRACE)
+CONFIG(SYCL_CACHE_TRACE, 4, __SYCL_CACHE_TRACE)
 CONFIG(SYCL_CACHE_DISABLE_PERSISTENT, 1, __SYCL_CACHE_DISABLE_PERSISTENT)
 CONFIG(SYCL_CACHE_PERSISTENT, 1, __SYCL_CACHE_PERSISTENT)
 CONFIG(SYCL_CACHE_EVICTION_DISABLE, 1, __SYCL_CACHE_EVICTION_DISABLE)

sycl/source/detail/config.hpp

@@ -698,6 +698,64 @@ template <> class SYCLConfig<SYCL_JIT_AMDGCN_PTX_TARGET_FEATURES> {
   }
 };
 
+// SYCL_CACHE_TRACE accepts a bit-mask to control the tracing of
+// different SYCL caches. The input value is parsed as an integer and
+// the following bit-masks is used to determine the tracing behavior:
+// 0x01 - trace disk cache
+// 0x02 - trace in-memory cache
+// 0x04 - trace kernel_compiler cache
+// Any valid combination of the above bit-masks can be used to enable/disable
+// tracing of the corresponding caches. If the input value is not null and
+// not a valid number, the disk cache tracing will be enabled (depreciated
+// behavior). The default value is 0 and no tracing is enabled.
+template <> class SYCLConfig<SYCL_CACHE_TRACE> {
+  using BaseT = SYCLConfigBase<SYCL_CACHE_TRACE>;
+  enum TraceBitmask { DiskCache = 1, InMemCache = 2, KernelCompiler = 4 };
+
+public:
+  static unsigned int get() { return getCachedValue(); }
+  static void reset() { (void)getCachedValue(true); }
+  static bool isTraceDiskCache() {
+    return getCachedValue() & TraceBitmask::DiskCache;
+  }
+  static bool isTraceInMemCache() {
+    return getCachedValue() & TraceBitmask::InMemCache;
+  }
+  static bool isTraceKernelCompiler() {
+    return getCachedValue() & TraceBitmask::KernelCompiler;
+  }
+
+private:
+  static unsigned int getCachedValue(bool ResetCache = false) {
+    const auto Parser = []() {
+      const char *ValStr = BaseT::getRawValue();
+      int intVal = 0;
+
+      if (ValStr) {
+        try {
+          intVal = std::stoi(ValStr);
+        } catch (...) {
+          // If the value is not null and not a number, it is considered
+          // to enable disk cache tracing. This is the legacy behavior.
+          intVal = 1;
+        }
+      }
+
+      // Legacy behavior.
+      if (intVal > 7)
+        intVal = 1;
+
+      return intVal;
+    };
+
+    static unsigned int Level = Parser();
+    if (ResetCache)
+      Level = Parser();
+
+    return Level;
+  }
+};
+
 #undef INVALID_CONFIG_EXCEPTION
 
 } // namespace detail

sycl/source/detail/persistent_device_code_cache.hpp

@@ -190,9 +190,10 @@ class PersistentDeviceCodeCache {
 
   /* Sends message to std:cerr stream when SYCL_CACHE_TRACE environemnt is set*/
   static void trace(const std::string &msg) {
-    static const char *TraceEnabled = SYCLConfig<SYCL_CACHE_TRACE>::get();
-    if (TraceEnabled)
-      std::cerr << "*** Code caching: " << msg << std::endl;
+    static const bool traceEnabled =
+        SYCLConfig<SYCL_CACHE_TRACE>::isTraceDiskCache();
+    if (traceEnabled)
+      std::cerr << "[Persistent Cache]: " << msg << std::endl;
   }
 };
 } // namespace detail

sycl/test-e2e/KernelAndProgram/test_cache_jit_aot.cpp

@@ -66,8 +66,8 @@
 // RUN: %{cache_vars} %{run-unfiltered-devices} %t.out 2>&1 | FileCheck %s --check-prefixes RESULT1
 // ******************************
 
-// CHECK-CACHE-WRITE: Code caching: device binary has been cached
-// CHECK-CACHE-READ: Code caching: using cached device binary
+// CHECK-CACHE-WRITE: [Persistent Cache]: device binary has been cached
+// CHECK-CACHE-READ: [Persistent Cache]: using cached device binary
 
 // RESULT1: Result (0): 1
 // RESULT1: Result (1): 1

sycl/unittests/config/ConfigTests.cpp

@@ -232,3 +232,95 @@ TEST(ConfigTests, CheckConfigProcessing) {
             sycl::detail::SYCLConfig<
                 sycl::detail::SYCL_PRINT_EXECUTION_GRAPH>::get());
 }
+
+// SYCL_CACHE_TRACE accepts a bit-mask to control the tracing of
+// different SYCL caches. The input value is parsed as an integer and
+// the following bit-masks is used to determine the tracing behavior:
+// 0x01 - trace disk cache
+// 0x02 - trace in-memory cache
+// 0x04 - trace kernel_compiler cache
+// Any valid combination of the above bit-masks can be used to enable/disable
+// tracing of the corresponding caches. If the input value is not null and
+// not a valid number, the disk cache tracing will be enabled (depreciated
+// behavior). The default value is 0 and no tracing is enabled.
+using namespace sycl::detail;
+TEST(ConfigTests, CheckSyclCacheTraceTest) {
+
+  // Lambda to test parsing of SYCL_CACHE_TRACE
+  auto TestConfig = [](int expectedValue, int expectedDiskCache,
+                       int expectedInMemCache, int expectedKernelCompiler) {
+    EXPECT_EQ(static_cast<unsigned int>(expectedValue),
+              SYCLConfig<SYCL_CACHE_TRACE>::get());
+
+    EXPECT_EQ(
+        expectedDiskCache,
+        static_cast<int>(
+            sycl::detail::SYCLConfig<SYCL_CACHE_TRACE>::isTraceDiskCache()));
+    EXPECT_EQ(
+        expectedInMemCache,
+        static_cast<int>(
+            sycl::detail::SYCLConfig<SYCL_CACHE_TRACE>::isTraceInMemCache()));
+    EXPECT_EQ(expectedKernelCompiler,
+              static_cast<int>(sycl::detail::SYCLConfig<
+                               SYCL_CACHE_TRACE>::isTraceKernelCompiler()));
+  };
+
+  // Lambda to set SYCL_CACHE_TRACE
+  auto SetSyclCacheTraceEnv = [](const char *value) {
+#ifdef _WIN32
+    _putenv_s("SYCL_CACHE_TRACE", value);
+#else
+    setenv("SYCL_CACHE_TRACE", value, 1);
+#endif
+  };
+
+  SetSyclCacheTraceEnv("0");
+  sycl::detail::readConfig(true);
+  TestConfig(0, 0, 0, 0);
+
+  SetSyclCacheTraceEnv("1");
+  sycl::detail::SYCLConfig<SYCL_CACHE_TRACE>::reset();
+  TestConfig(1, 1, 0, 0);
+
+  SetSyclCacheTraceEnv("2");
+  sycl::detail::SYCLConfig<SYCL_CACHE_TRACE>::reset();
+  TestConfig(2, 0, 1, 0);
+
+  SetSyclCacheTraceEnv("3");
+  sycl::detail::SYCLConfig<SYCL_CACHE_TRACE>::reset();
+  TestConfig(3, 1, 1, 0);
+
+  SetSyclCacheTraceEnv("4");
+  sycl::detail::SYCLConfig<SYCL_CACHE_TRACE>::reset();
+  TestConfig(4, 0, 0, 1);
+
+  SetSyclCacheTraceEnv("5");
+  sycl::detail::SYCLConfig<SYCL_CACHE_TRACE>::reset();
+  TestConfig(5, 1, 0, 1);
+
+  SetSyclCacheTraceEnv("6");
+  sycl::detail::SYCLConfig<SYCL_CACHE_TRACE>::reset();
+  TestConfig(6, 0, 1, 1);
+
+  SetSyclCacheTraceEnv("7");
+  sycl::detail::SYCLConfig<SYCL_CACHE_TRACE>::reset();
+  TestConfig(7, 1, 1, 1);
+
+  SetSyclCacheTraceEnv("8");
+  sycl::detail::SYCLConfig<SYCL_CACHE_TRACE>::reset();
+  TestConfig(1, 1, 0, 0);
+
+  // Set random non-null value. It should default to 1.
+  SetSyclCacheTraceEnv("random");
+  sycl::detail::SYCLConfig<SYCL_CACHE_TRACE>::reset();
+  TestConfig(1, 1, 0, 0);
+
+  // When SYCL_CACHE_TRACE is not set, it should default to 0.
+#ifdef _WIN32
+  _putenv_s("SYCL_CACHE_TRACE", "");
+#else
+  unsetenv("SYCL_CACHE_TRACE");
+#endif
+  sycl::detail::SYCLConfig<SYCL_CACHE_TRACE>::reset();
+  TestConfig(0, 0, 0, 0);
+}