Add EFCacheKey to EFCacheableLogEvent

VahidN · Dec 10, 2024 · d6ebd2c · d6ebd2c
1 parent 14ac0c3
commit d6ebd2c
Show file tree

Hide file tree

Showing 11 changed files with 144 additions and 84 deletions.
diff --git a/src/EFCoreSecondLevelCacheInterceptor/DbCommandInterceptorProcessor.cs b/src/EFCoreSecondLevelCacheInterceptor/DbCommandInterceptorProcessor.cs
@@ -64,6 +64,8 @@ public T ProcessExecutedCommands<T>(DbCommand command, DbContext? context, T res
             return result;
         }
 
+        EFCacheKey? efCacheKey = null;
+
         try
         {
             if (!_cacheServiceCheck.IsCacheServiceAvailable())
@@ -84,14 +86,16 @@ public T ProcessExecutedCommands<T>(DbCommand command, DbContext? context, T res
                 {
                     var logMessage = $"Returning the cached TableRows[{rowsReader.TableName}].";
                     _interceptorProcessorLogger.LogDebug(CacheableEventId.CacheHit, logMessage);
-                    _logger.NotifyCacheableEvent(CacheableLogEventId.CacheHit, logMessage, command.CommandText);
+
+                    _logger.NotifyCacheableEvent(CacheableLogEventId.CacheHit, logMessage, command.CommandText,
+                        efCacheKey);
                 }
 
                 return result;
             }
 
             var commandText = command.CommandText;
-            var efCacheKey = _cacheKeyProvider.GetEFCacheKey(command, context, cachePolicy ?? new EFCachePolicy());
+            efCacheKey = _cacheKeyProvider.GetEFCacheKey(command, context, cachePolicy ?? new EFCachePolicy());
 
             if (_cacheDependenciesProcessor.InvalidateCacheDependencies(commandText, efCacheKey))
             {
@@ -104,7 +108,7 @@ public T ProcessExecutedCommands<T>(DbCommand command, DbContext? context, T res
                 {
                     var message = $"Skipping a none-cachable command[{commandText}].";
                     _interceptorProcessorLogger.LogDebug(message);
-                    _logger.NotifyCacheableEvent(CacheableLogEventId.CachingSkipped, message, commandText);
+                    _logger.NotifyCacheableEvent(CacheableLogEventId.CachingSkipped, message, commandText, efCacheKey);
                 }
 
                 return result;
@@ -123,7 +127,9 @@ public T ProcessExecutedCommands<T>(DbCommand command, DbContext? context, T res
                     {
                         var message = $"[{data}] added to the cache[{efCacheKey}].";
                         _interceptorProcessorLogger.LogDebug(CacheableEventId.QueryResultCached, message);
-                        _logger.NotifyCacheableEvent(CacheableLogEventId.QueryResultCached, message, commandText);
+
+                        _logger.NotifyCacheableEvent(CacheableLogEventId.QueryResultCached, message, commandText,
+                            efCacheKey);
                     }
                 }
 
@@ -150,7 +156,9 @@ public T ProcessExecutedCommands<T>(DbCommand command, DbContext? context, T res
                     {
                         var message = $"TableRows[{tableRows.TableName}] added to the cache[{efCacheKey}].";
                         _interceptorProcessorLogger.LogDebug(CacheableEventId.QueryResultCached, message);
-                        _logger.NotifyCacheableEvent(CacheableLogEventId.QueryResultCached, message, commandText);
+
+                        _logger.NotifyCacheableEvent(CacheableLogEventId.QueryResultCached, message, commandText,
+                            efCacheKey);
                     }
                 }
 
@@ -174,7 +182,9 @@ public T ProcessExecutedCommands<T>(DbCommand command, DbContext? context, T res
                     {
                         var message = $"[{result}] added to the cache[{efCacheKey}].";
                         _interceptorProcessorLogger.LogDebug(CacheableEventId.QueryResultCached, message);
-                        _logger.NotifyCacheableEvent(CacheableLogEventId.QueryResultCached, message, commandText);
+
+                        _logger.NotifyCacheableEvent(CacheableLogEventId.QueryResultCached, message, commandText,
+                            efCacheKey);
                     }
                 }
 
@@ -193,7 +203,9 @@ public T ProcessExecutedCommands<T>(DbCommand command, DbContext? context, T res
             if (_logger.IsLoggerEnabled)
             {
                 _interceptorProcessorLogger.LogCritical(ex, message: "Interceptor Error");
-                _logger.NotifyCacheableEvent(CacheableLogEventId.CachingError, ex.ToString(), command.CommandText);
+
+                _logger.NotifyCacheableEvent(CacheableLogEventId.CachingError, ex.ToString(), command.CommandText,
+                    efCacheKey);
             }
 
             return result;
@@ -210,6 +222,8 @@ public T ProcessExecutingCommands<T>(DbCommand command, DbContext? context, T re
             return result;
         }
 
+        EFCacheKey? efCacheKey = null;
+
         try
         {
             if (!_cacheServiceCheck.IsCacheServiceAvailable())
@@ -232,13 +246,13 @@ public T ProcessExecutingCommands<T>(DbCommand command, DbContext? context, T re
                 {
                     var message = $"Skipping a none-cachable command[{commandText}].";
                     _interceptorProcessorLogger.LogDebug(message);
-                    _logger.NotifyCacheableEvent(CacheableLogEventId.CachingSkipped, message, commandText);
+                    _logger.NotifyCacheableEvent(CacheableLogEventId.CachingSkipped, message, commandText, efCacheKey);
                 }
 
                 return result;
             }
 
-            var efCacheKey = _cacheKeyProvider.GetEFCacheKey(command, context, cachePolicy);
+            efCacheKey = _cacheKeyProvider.GetEFCacheKey(command, context, cachePolicy);
 
             if (_cacheService.GetValue(efCacheKey, cachePolicy) is not { } cacheResult)
             {
@@ -259,7 +273,9 @@ public T ProcessExecutingCommands<T>(DbCommand command, DbContext? context, T re
                     {
                         var message = "Suppressed the result with an empty TableRows.";
                         _interceptorProcessorLogger.LogDebug(message);
-                        _logger.NotifyCacheableEvent(CacheableLogEventId.QueryResultSuppressed, message, commandText);
+
+                        _logger.NotifyCacheableEvent(CacheableLogEventId.QueryResultSuppressed, message, commandText,
+                            efCacheKey);
                     }
 
                     using var rows = new EFTableRowsDataReader(new EFTableRows()
@@ -278,7 +294,9 @@ public T ProcessExecutingCommands<T>(DbCommand command, DbContext? context, T re
                         $"Suppressed the result with the TableRows[{cacheResult.TableRows.TableName}] from the cache[{efCacheKey}].";
 
                     _interceptorProcessorLogger.LogDebug(message);
-                    _logger.NotifyCacheableEvent(CacheableLogEventId.QueryResultSuppressed, message, commandText);
+
+                    _logger.NotifyCacheableEvent(CacheableLogEventId.QueryResultSuppressed, message, commandText,
+                        efCacheKey);
                 }
 
                 using var dataRows = new EFTableRowsDataReader(cacheResult.TableRows
@@ -299,7 +317,9 @@ public T ProcessExecutingCommands<T>(DbCommand command, DbContext? context, T re
                 {
                     var message = $"Suppressed the result with {cachedResult} from the cache[{efCacheKey}].";
                     _interceptorProcessorLogger.LogDebug(message);
-                    _logger.NotifyCacheableEvent(CacheableLogEventId.QueryResultSuppressed, message, commandText);
+
+                    _logger.NotifyCacheableEvent(CacheableLogEventId.QueryResultSuppressed, message, commandText,
+                        efCacheKey);
                 }
 
                 return (T)Convert.ChangeType(InterceptionResult<int>.SuppressWithResult(cachedResult), typeof(T),
@@ -314,7 +334,9 @@ public T ProcessExecutingCommands<T>(DbCommand command, DbContext? context, T re
                 {
                     var message = $"Suppressed the result with {cachedResult} from the cache[{efCacheKey}].";
                     _interceptorProcessorLogger.LogDebug(message);
-                    _logger.NotifyCacheableEvent(CacheableLogEventId.QueryResultSuppressed, message, commandText);
+
+                    _logger.NotifyCacheableEvent(CacheableLogEventId.QueryResultSuppressed, message, commandText,
+                        efCacheKey);
                 }
 
                 return (T)Convert.ChangeType(
@@ -326,7 +348,7 @@ public T ProcessExecutingCommands<T>(DbCommand command, DbContext? context, T re
             {
                 var message = $"Skipped the result with {result?.GetType()} type.";
                 _interceptorProcessorLogger.LogDebug(message);
-                _logger.NotifyCacheableEvent(CacheableLogEventId.CachingSkipped, message, commandText);
+                _logger.NotifyCacheableEvent(CacheableLogEventId.CachingSkipped, message, commandText, efCacheKey);
             }
 
             return result;
@@ -341,7 +363,9 @@ public T ProcessExecutingCommands<T>(DbCommand command, DbContext? context, T re
             if (_logger.IsLoggerEnabled)
             {
                 _interceptorProcessorLogger.LogCritical(ex, message: "Interceptor Error");
-                _logger.NotifyCacheableEvent(CacheableLogEventId.CachingError, ex.ToString(), command.CommandText);
+
+                _logger.NotifyCacheableEvent(CacheableLogEventId.CachingError, ex.ToString(), command.CommandText,
+                    efCacheKey);
             }
 
             return result;
@@ -396,7 +420,7 @@ private bool ShouldSkipCachingDbContext(DbContext context, string commandText)
         {
             var message = $"Skipped caching of this DbContext: {context.GetType()}";
             _interceptorProcessorLogger.LogDebug(message);
-            _logger.NotifyCacheableEvent(CacheableLogEventId.CachingSkipped, message, commandText);
+            _logger.NotifyCacheableEvent(CacheableLogEventId.CachingSkipped, message, commandText, efCacheKey: null);
         }
 
         return result;
@@ -421,7 +445,7 @@ private bool ShouldSkipCachingResults(string commandText, object value)
         {
             var message = "Skipped caching of this result based on the provided predicate.";
             _interceptorProcessorLogger.LogDebug(message);
-            _logger.NotifyCacheableEvent(CacheableLogEventId.CachingSkipped, message, commandText);
+            _logger.NotifyCacheableEvent(CacheableLogEventId.CachingSkipped, message, commandText, efCacheKey: null);
         }
 
         return result;

diff --git a/src/EFCoreSecondLevelCacheInterceptor/EFCacheDependenciesProcessor.cs b/src/EFCoreSecondLevelCacheInterceptor/EFCacheDependenciesProcessor.cs
@@ -95,7 +95,7 @@ public SortedSet<string> GetCacheDependencies(EFCachePolicy cachePolicy,
                     $"It's not possible to calculate the related table names of the current query[{commandText}]. Please use EFCachePolicy.Configure(options => options.CacheDependencies(\"real_table_name_1\", \"real_table_name_2\")) to specify them explicitly.";
 
                 _dependenciesProcessorLogger.LogDebug(message);
-                _logger.NotifyCacheableEvent(CacheableLogEventId.CachingError, message, commandText);
+                _logger.NotifyCacheableEvent(CacheableLogEventId.CachingError, message, commandText, efCacheKey: null);
             }
 
             cacheDependencies = new SortedSet<string>(StringComparer.OrdinalIgnoreCase)
@@ -125,7 +125,7 @@ public bool InvalidateCacheDependencies(string commandText, EFCacheKey cacheKey)
             {
                 var message = $"Skipped invalidating a none-CRUD command[{commandText}].";
                 _dependenciesProcessorLogger.LogDebug(message);
-                _logger.NotifyCacheableEvent(CacheableLogEventId.InvalidationSkipped, message, commandText);
+                _logger.NotifyCacheableEvent(CacheableLogEventId.InvalidationSkipped, message, commandText, cacheKey);
             }
 
             return false;
@@ -139,7 +139,7 @@ public bool InvalidateCacheDependencies(string commandText, EFCacheKey cacheKey)
                     $"Skipped invalidating the related cache entries of this query[{commandText}] based on the provided predicate.";
 
                 _dependenciesProcessorLogger.LogDebug(message);
-                _logger.NotifyCacheableEvent(CacheableLogEventId.InvalidationSkipped, message, commandText);
+                _logger.NotifyCacheableEvent(CacheableLogEventId.InvalidationSkipped, message, commandText, cacheKey);
             }
 
             return false;
@@ -153,7 +153,7 @@ public bool InvalidateCacheDependencies(string commandText, EFCacheKey cacheKey)
         {
             var message = $"Invalidated [{string.Join(separator: ", ", cacheKey.CacheDependencies)}] dependencies.";
             _dependenciesProcessorLogger.LogDebug(CacheableEventId.QueryResultInvalidated, message);
-            _logger.NotifyCacheableEvent(CacheableLogEventId.QueryResultInvalidated, message, commandText);
+            _logger.NotifyCacheableEvent(CacheableLogEventId.QueryResultInvalidated, message, commandText, cacheKey);
         }
 
         _logger.NotifyCacheInvalidation(clearAllCachedEntries: false, cacheKey.CacheDependencies);
@@ -179,7 +179,9 @@ private void LogProcess(SortedSet<string> tableNames,
                 $"ContextTableNames: {names}, PossibleQueryTableNames: {texts} -> CacheDependencies: {dependencies}.";
 
             _dependenciesProcessorLogger.LogDebug(message);
-            _logger.NotifyCacheableEvent(CacheableLogEventId.CacheDependenciesCalculated, message, commandText);
+
+            _logger.NotifyCacheableEvent(CacheableLogEventId.CacheDependenciesCalculated, message, commandText,
+                efCacheKey: null);
         }
     }
 

diff --git a/src/EFCoreSecondLevelCacheInterceptor/EFCacheManagerCoreProvider.cs b/src/EFCoreSecondLevelCacheInterceptor/EFCacheManagerCoreProvider.cs
@@ -143,7 +143,9 @@ public void InvalidateCacheDependencies(EFCacheKey cacheKey)
                         $"Invalidated all of the cache entries due to early expiration of a root cache key[{rootCacheKey}].";
 
                     _cacheManagerCoreProviderLogger.LogDebug(CacheableEventId.QueryResultInvalidated, message);
-                    _logger.NotifyCacheableEvent(CacheableLogEventId.QueryResultInvalidated, message, commandText: "");
+
+                    _logger.NotifyCacheableEvent(CacheableLogEventId.QueryResultInvalidated, message, commandText: "",
+                        cacheKey);
                 }
 
                 ClearAllCachedEntries();

diff --git a/src/EFCoreSecondLevelCacheInterceptor/EFCachePolicyParser.cs b/src/EFCoreSecondLevelCacheInterceptor/EFCachePolicyParser.cs
@@ -131,7 +131,9 @@ public string RemoveEFCachePolicyTag(string commandText)
         {
             var message = $"Using EFCachePolicy: {efCachePolicy}.";
             _policyParserLogger.LogDebug(message: "Using EFCachePolicy: {EfCachePolicy}.", efCachePolicy);
-            _logger.NotifyCacheableEvent(CacheableLogEventId.CachePolicyCalculated, message, commandText);
+
+            _logger.NotifyCacheableEvent(CacheableLogEventId.CachePolicyCalculated, message, commandText,
+                efCacheKey: null);
         }
 
         return efCachePolicy;
@@ -145,7 +147,7 @@ private bool ShouldSkipCachingCommands(string commandText)
         {
             var message = $"Skipped caching of this command[{commandText}] based on the provided predicate.";
             _policyParserLogger.LogDebug(message);
-            _logger.NotifyCacheableEvent(CacheableLogEventId.CachingSkipped, message, commandText);
+            _logger.NotifyCacheableEvent(CacheableLogEventId.CachingSkipped, message, commandText, efCacheKey: null);
         }
 
         return result;
@@ -446,7 +448,9 @@ private bool ContainsNonDeterministicFunction(string commandText)
             {
                 var message = $"Skipped caching because of the non-deterministic function -> `{item}`.";
                 _policyParserLogger.LogDebug(message);
-                _logger.NotifyCacheableEvent(CacheableLogEventId.CachingSkipped, message, commandText);
+
+                _logger.NotifyCacheableEvent(CacheableLogEventId.CachingSkipped, message, commandText,
+                    efCacheKey: null);
             }
 
             return hasFn;

diff --git a/src/EFCoreSecondLevelCacheInterceptor/EFCacheableLogEvent.cs b/src/EFCoreSecondLevelCacheInterceptor/EFCacheableLogEvent.cs
@@ -22,6 +22,11 @@ public class EFCacheableLogEvent
     /// </summary>
     public string CommandText { set; get; } = default!;
 
+    /// <summary>
+    ///     Stores information of the computed key of the input LINQ query.
+    /// </summary>
+    public EFCacheKey? EFCacheKey { set; get; }
+
     /// <summary>
     ///     Defines a mechanism for retrieving a service object.
     ///     For instance, you can create an ILoggerFactory by using it.

diff --git a/src/EFCoreSecondLevelCacheInterceptor/EFCoreSecondLevelCacheInterceptor.csproj b/src/EFCoreSecondLevelCacheInterceptor/EFCoreSecondLevelCacheInterceptor.csproj
@@ -1,7 +1,7 @@
 <Project Sdk="Microsoft.NET.Sdk">
     <PropertyGroup>
         <Description>Entity Framework Core Second Level Caching Library.</Description>
-        <VersionPrefix>4.8.8</VersionPrefix>
+        <VersionPrefix>4.9.0</VersionPrefix>
         <Authors>Vahid Nasiri</Authors>
         <TargetFrameworks>net9.0;net8.0;net7.0;net6.0;net5.0;netstandard2.1;netstandard2.0;net462;netcoreapp3.1;</TargetFrameworks>
         <GenerateDocumentationFile>true</GenerateDocumentationFile>

diff --git a/src/EFCoreSecondLevelCacheInterceptor/EFDebugLogger.cs b/src/EFCoreSecondLevelCacheInterceptor/EFDebugLogger.cs
@@ -42,7 +42,7 @@ public EFDebugLogger(IOptions<EFCoreSecondLevelCacheSettings> cacheSettings,
         {
             var message = $"InstanceId: {Guid.NewGuid()}, Started @{DateTime.UtcNow} UTC.";
             logger.LogDebug(message);
-            NotifyCacheableEvent(CacheableLogEventId.CachingSystemStarted, message, commandText: "");
+            NotifyCacheableEvent(CacheableLogEventId.CachingSystemStarted, message, commandText: "", efCacheKey: null);
         }
     }
 
@@ -54,7 +54,10 @@ public EFDebugLogger(IOptions<EFCoreSecondLevelCacheSettings> cacheSettings,
     /// <summary>
     ///     If you set DisableLogging to false, this delegate will give you the internal caching events of the library.
     /// </summary>
-    public void NotifyCacheableEvent(CacheableLogEventId eventId, string message, string commandText)
+    public void NotifyCacheableEvent(CacheableLogEventId eventId,
+        string message,
+        string commandText,
+        EFCacheKey? efCacheKey)
     {
         if (IsLoggerEnabled && _cacheableEvent is not null)
         {
@@ -63,6 +66,7 @@ public void NotifyCacheableEvent(CacheableLogEventId eventId, string message, st
                 EventId = eventId,
                 Message = message,
                 CommandText = commandText,
+                EFCacheKey = efCacheKey,
                 ServiceProvider = _serviceProvider
             });
         }

diff --git a/src/EFCoreSecondLevelCacheInterceptor/EFEasyCachingCoreProvider.cs b/src/EFCoreSecondLevelCacheInterceptor/EFEasyCachingCoreProvider.cs
@@ -158,7 +158,9 @@ public void InvalidateCacheDependencies(EFCacheKey cacheKey)
                         $"Invalidated all of the cache entries due to early expiration of a root cache key[{rootCacheKey}].";
 
                     _easyCachingCoreProviderLogger.LogDebug(CacheableEventId.QueryResultInvalidated, message);
-                    _logger.NotifyCacheableEvent(CacheableLogEventId.QueryResultInvalidated, message, commandText: "");
+
+                    _logger.NotifyCacheableEvent(CacheableLogEventId.QueryResultInvalidated, message, commandText: "",
+                        cacheKey);
                 }
 
                 ClearAllCachedEntries();

diff --git a/src/EFCoreSecondLevelCacheInterceptor/IEFDebugLogger.cs b/src/EFCoreSecondLevelCacheInterceptor/IEFDebugLogger.cs
@@ -15,7 +15,7 @@ public interface IEFDebugLogger
     /// <summary>
     ///     If you set DisableLogging to false, this delegate will give you the internal caching events of the library.
     /// </summary>
-    void NotifyCacheableEvent(CacheableLogEventId eventId, string message, string commandText);
+    void NotifyCacheableEvent(CacheableLogEventId eventId, string message, string commandText, EFCacheKey? efCacheKey);
 
     /// <summary>
     ///     Represents some information about the current cache invalidation event