diff --git a/HzMemoryCache/Diagnostics/ThrashingDetector.cs b/HzMemoryCache/Diagnostics/ThrashingDetector.cs new file mode 100644 index 0000000..4f553db --- /dev/null +++ b/HzMemoryCache/Diagnostics/ThrashingDetector.cs @@ -0,0 +1,8 @@ +namespace HzCache.Diagnostics +{ + internal class ThrashingDetector(string checksum) + { + public int Counter { get; set; } = 0; + public string Checksum => checksum; + } +} \ No newline at end of file diff --git a/HzMemoryCache/HzMemoryCache.cs b/HzMemoryCache/HzMemoryCache.cs index 6ee70f8..1b92300 100644 --- a/HzMemoryCache/HzMemoryCache.cs +++ b/HzMemoryCache/HzMemoryCache.cs @@ -1,4 +1,9 @@ #nullable enable + +using HzCache.Diagnostics; +using Microsoft.Extensions.Caching.Memory; +using Microsoft.Extensions.Logging; +using Microsoft.Extensions.Options; using System; using System.Collections; using System.Collections.Concurrent; @@ -10,8 +15,6 @@ using System.Threading; using System.Threading.Tasks; using System.Threading.Tasks.Dataflow; -using HzCache.Diagnostics; -using Microsoft.Extensions.Logging; namespace HzCache { @@ -27,6 +30,7 @@ public partial class HzMemoryCache : IEnumerable>, private readonly ConcurrentDictionary dictionary = new(); private readonly HzCacheMemoryLocker memoryLocker = new(new HzCacheMemoryLockerOptions()); private readonly HzCacheOptions options; + private readonly MemoryCache thrashingDetectorCache = new(new MemoryCacheOptions()); //IDispisable members private bool _disposedValue; @@ -244,7 +248,7 @@ public bool Remove(string key, bool sendBackplaneNotification, Func @@ -292,7 +296,7 @@ public static IPropagatorBlock> CreateBuffer(TimeSpan timeS private void StartUpdateChecksumAndNotify() { - var options = new DataflowLinkOptions {PropagateCompletion = true}; + var options = new DataflowLinkOptions { PropagateCompletion = true }; var actionBlock = new ActionBlock>(ttlValues => { try @@ -325,6 +329,8 @@ private bool RemoveItem(string key, CacheItemChangeType changeType, bool sendNot if (result) { + DetectCacheThrashing(key, ttlValue?.checksum); + result = dictionary.TryRemove(key, out ttlValue); if (result) { @@ -340,6 +346,48 @@ private bool RemoveItem(string key, CacheItemChangeType changeType, bool sendNot return result; } + // Remember the value we are removing from the local cache. + // If the same value is being removed again and again in a short time frame, + // we are likely experiencing cache thrashing. + private void DetectCacheThrashing(string key, string? ttlValueChecksum) + { + try + { + if (!options.LogCacheThrashing) + { + return; + } + + if (ttlValueChecksum == null || options.logger == null) + return; + if (!thrashingDetectorCache.TryGetValue(key, out ThrashingDetector? thrashingDetector)) + { + thrashingDetectorCache.Set(key, new ThrashingDetector(ttlValueChecksum), options.ThrashingWindow); + return; + } + + if (thrashingDetector.Checksum == ttlValueChecksum) + { + thrashingDetector.Counter++; + } + else + { + thrashingDetectorCache.Remove(key); + } + + if (thrashingDetector.Counter == options.ThrashingLimit) + { + options.logger.LogWarning( + "Cache Thrashing Detected: {Key} has been removed from local cache {ThrashingLimit} times in the last {ThrashingWindow}s. Checksum of existing value:{Checksum}", + key, options.ThrashingLimit, options.ThrashingWindow.TotalSeconds, ttlValueChecksum); + } + } + catch (Exception e) + { + options.logger?.LogError(e, "Error in DetectCacheThrashing {Key}", key); + } + } + private void NotifyItemChange(string key, CacheItemChangeType changeType, TTLValue ttlValue, byte[]? objectData = null, bool isPattern = false) { options.valueChangeListener(key, changeType, ttlValue, objectData, isPattern); @@ -357,6 +405,7 @@ private void Dispose(bool disposing) if (disposing) { cleanUpTimer.Dispose(); + thrashingDetectorCache.Dispose(); } _disposedValue = true; @@ -405,4 +454,4 @@ public static bool IsNullOrDefault(T argument) return false; } } -} +} \ No newline at end of file diff --git a/HzMemoryCache/IHzCache.cs b/HzMemoryCache/IHzCache.cs index 85f6389..b73a675 100644 --- a/HzMemoryCache/IHzCache.cs +++ b/HzMemoryCache/IHzCache.cs @@ -1,4 +1,5 @@ #nullable enable + using System; using System.Collections.Generic; using System.Threading.Tasks; @@ -29,7 +30,6 @@ public enum NotificationType Async, Sync, None } - /// /// The eviction policy to use for the cache. /// LRU is "Least Recently Used" and FIFO is "First In First Out". Which is almost true. @@ -92,6 +92,21 @@ public class HzCacheOptions /// benefit of compression. /// public long compressionThreshold { get; set; } = Int64.MaxValue; + + /// + /// Enables logging of cache thrashing events, which occur when keys are removed frequently. + /// + public bool LogCacheThrashing { get; set; } = false; + + /// + /// The time window during which cache removals are counted for thrashing detection. + /// + public TimeSpan ThrashingWindow { get; set; } = TimeSpan.FromSeconds(60); + + /// + /// The number of removals within that triggers a cache thrashing warning. + /// + public int ThrashingLimit { get; set; } = 3; } public interface IHzCache @@ -182,6 +197,7 @@ public interface IHzCache bool Remove(string key); Task ClearAsync(); + Task RemoveAsync(string key); } @@ -198,7 +214,6 @@ public interface IDetailedHzCache : IHzCache /// void Clear(); - /// /// Tries to remove item with the specified key, also returns the object removed in an "out" var /// diff --git a/RedisBackedHzCache/RedisBackedHzCache.cs b/RedisBackedHzCache/RedisBackedHzCache.cs index 3da1ba5..dbd7cd2 100644 --- a/RedisBackedHzCache/RedisBackedHzCache.cs +++ b/RedisBackedHzCache/RedisBackedHzCache.cs @@ -97,7 +97,10 @@ public RedisBackedHzCache(RedisBackedHzCacheOptions options) } } }, - defaultTTL = options.defaultTTL + defaultTTL = options.defaultTTL, + LogCacheThrashing = options.LogCacheThrashing, + ThrashingLimit = options.ThrashingLimit, + ThrashingWindow = options.ThrashingWindow, }); if (string.IsNullOrWhiteSpace(options.redisConnectionString)) @@ -181,7 +184,7 @@ public CacheStatistics GetStatistics() public T Get(string key) { - using var activity = HzActivities.Source.StartActivityWithCommonTags(HzActivities.Names.Get, HzActivities.Area.RedisBackedHzCache, key: key); + using var activity = HzActivities.Source.StartActivityWithCommonTags(HzActivities.Names.Get, HzActivities.Area.RedisBackedHzCache, key: key); var value = hzCache.Get(key); if (value == null && options.useRedisAs2ndLevelCache) { @@ -226,7 +229,7 @@ public IList GetOrSetBatch(IList keys, Func, List GetOrSetBatch(IList keys, Func, List>> valueFactory, TimeSpan ttl) { - using var activity = HzActivities.Source.StartActivityWithCommonTags(HzActivities.Names.GetOrSetBatch, HzActivities.Area.RedisBackedHzCache, key: string.Join(",",keys??new List())); + using var activity = HzActivities.Source.StartActivityWithCommonTags(HzActivities.Names.GetOrSetBatch, HzActivities.Area.RedisBackedHzCache, key: string.Join(",", keys ?? new List())); Func, List>> redisFactory = idList => { // Create a list of redis keys from the list of cache keys @@ -290,4 +293,4 @@ private string CacheKeyFromRedisKey(string redisKey) return redisKey.Substring(options.applicationCachePrefix.Length + 1); } } -} +} \ No newline at end of file