handle neg expiry (#1418)

* handle neg expiry * memroy cache provider * PR feedback
AzureAD · Sep 1, 2021 · 6be9af7 · 6be9af7
1 parent a144108
commit 6be9af7
Show file tree

Hide file tree

Showing 7 changed files with 72 additions and 4 deletions.
diff --git a/src/Microsoft.Identity.Web/LoggingEventId.cs b/src/Microsoft.Identity.Web/LoggingEventId.cs
@@ -21,6 +21,7 @@ internal static class LoggingEventId
         public static readonly EventId MemoryCacheRead = new EventId(106, "MemoryCacheRead");
         public static readonly EventId MemoryCacheCount = new EventId(107, "MemoryCacheCount");
         public static readonly EventId BackPropagateL2toL1 = new EventId(108, "BackPropagateL2toL1");
+        public static readonly EventId MemoryCacheNegativeExpiry = new EventId(109, "MemoryCacheNegativeExpiry");
 
         // SessionCacheProvider EventIds 200+
         public static readonly EventId SessionCache = new EventId(200, "SessionCache");

diff --git a/src/Microsoft.Identity.Web/Microsoft.Identity.Web.xml b/src/Microsoft.Identity.Web/Microsoft.Identity.Web.xml
diff --git a/...t.Identity.Web/TokenCacheProviders/Distributed/MsalDistributedTokenCacheAdapter.Logger.cs b/...t.Identity.Web/TokenCacheProviders/Distributed/MsalDistributedTokenCacheAdapter.Logger.cs
@@ -58,6 +58,12 @@ private static class Logger
                     LoggingEventId.MemoryCacheRead,
                     "[MsIdWeb] {CacheType}: {Operation} cacheKey {CacheKey} cache size {Size} ");
 
+            private static readonly Action<ILogger, string, string, Exception?> s_l1CacheNegativeExpiry =
+                LoggerMessage.Define<string, string>(
+                    LogLevel.Debug,
+                    LoggingEventId.MemoryCacheNegativeExpiry,
+                    "[MsIdWeb] {CacheType}: {Operation} The TokenCacheNotificationArgs.SuggestedCacheExpiry from MSAL was negative. ");
+
             private static readonly Action<ILogger, string, string, int, Exception?> s_l1CacheCount =
                 LoggerMessage.Define<string, string, int>(
                     LogLevel.Debug,
@@ -71,7 +77,7 @@ private static class Logger
                     "[MsIdWeb] Back propagate from Distributed to Memory, cache size {Size} ");
 
             /// <summary>
-            /// Memory cache remove.
+            /// Memory cache read.
             /// </summary>
             /// <param name="logger">ILogger.</param>
             /// <param name="cacheType">Distributed or Memory.</param>
@@ -93,6 +99,23 @@ public static void MemoryCacheRead(
                     cacheSize,
                     ex);
 
+            /// <summary>
+            /// Memory cache negative expiry.
+            /// </summary>
+            /// <param name="logger">ILogger.</param>
+            /// <param name="cacheType">Distributed or Memory.</param>
+            /// <param name="operation">Cache operation (Read, Write, etc...).</param>
+            /// <param name="ex">Exception.</param>
+            public static void MemoryCacheNegativeExpiry(
+                ILogger logger,
+                string cacheType,
+                string operation,
+                Exception? ex) => s_l1CacheNegativeExpiry(
+                    logger,
+                    cacheType,
+                    operation,
+                    ex);
+
             /// <summary>
             /// Memory cache remove.
             /// </summary>

diff --git a/...icrosoft.Identity.Web/TokenCacheProviders/Distributed/MsalDistributedTokenCacheAdapter.cs b/...icrosoft.Identity.Web/TokenCacheProviders/Distributed/MsalDistributedTokenCacheAdapter.cs
@@ -237,6 +237,11 @@ protected override async Task WriteCacheBytesAsync(
             if (cacheSerializerHints != null && cacheSerializerHints?.SuggestedCacheExpiry != null)
             {
                 cacheExpiry = cacheSerializerHints.SuggestedCacheExpiry.Value.UtcDateTime - DateTime.UtcNow;
+                if (cacheExpiry < TimeSpan.Zero)
+                {
+                    cacheExpiry = TimeSpan.FromMilliseconds(1);
+                    Logger.MemoryCacheNegativeExpiry(_logger, _memoryCacheType, write, null);
+                }
             }
 
             if (_memoryCache != null)

diff --git a/src/Microsoft.Identity.Web/TokenCacheProviders/InMemory/MsalMemoryTokenCacheProvider.cs b/src/Microsoft.Identity.Web/TokenCacheProviders/InMemory/MsalMemoryTokenCacheProvider.cs
@@ -92,6 +92,10 @@ protected override Task WriteCacheBytesAsync(
             if (cacheSerializerHints != null && cacheSerializerHints?.SuggestedCacheExpiry != null)
             {
                 cacheExpiry = cacheSerializerHints.SuggestedCacheExpiry.Value.UtcDateTime - DateTime.UtcNow;
+                if (cacheExpiry < TimeSpan.Zero)
+                {
+                    cacheExpiry = TimeSpan.FromMilliseconds(1);
+                }
             }
 
             MemoryCacheEntryOptions memoryCacheEntryOptions = new MemoryCacheEntryOptions()

diff --git a/tests/Microsoft.Identity.Web.Test.Common/TestHelpers/TestMsalDistributedTokenCacheAdapter.cs b/tests/Microsoft.Identity.Web.Test.Common/TestHelpers/TestMsalDistributedTokenCacheAdapter.cs
@@ -6,6 +6,7 @@
 using Microsoft.Extensions.Caching.Distributed;
 using Microsoft.Extensions.Logging;
 using Microsoft.Extensions.Options;
+using Microsoft.Identity.Web.TokenCacheProviders;
 using Microsoft.Identity.Web.TokenCacheProviders.Distributed;
 
 namespace Microsoft.Identity.Web.Test.Common.TestHelpers
@@ -32,9 +33,9 @@ public async Task TestRemoveKeyAsync(string cacheKey)
             await RemoveKeyAsync(cacheKey).ConfigureAwait(false);
         }
 
-        public async Task TestWriteCacheBytesAsync(string cacheKey, byte[] bytes)
+        public async Task TestWriteCacheBytesAsync(string cacheKey, byte[] bytes, CacheSerializerHints cacheSerializerHints = null)
         {
-            await WriteCacheBytesAsync(cacheKey, bytes).ConfigureAwait(false);
+            await WriteCacheBytesAsync(cacheKey, bytes, cacheSerializerHints).ConfigureAwait(false);
         }
 
         public async Task<byte[]> TestReadCacheBytesAsync(string cacheKey)

diff --git a/tests/Microsoft.Identity.Web.Test/L1L2CacheTests.cs b/tests/Microsoft.Identity.Web.Test/L1L2CacheTests.cs
@@ -8,6 +8,7 @@
 using Microsoft.Extensions.Logging;
 using Microsoft.Extensions.Options;
 using Microsoft.Identity.Web.Test.Common.TestHelpers;
+using Microsoft.Identity.Web.TokenCacheProviders;
 using Microsoft.Identity.Web.TokenCacheProviders.Distributed;
 using Xunit;
 
@@ -51,6 +52,30 @@ public async Task WriteCache_WritesInL1L2_TestAsync()
             Assert.Single(L2Cache.dict);
         }
 
+        [Fact]
+        public async Task WriteCache_NegativeExpiry_TestAsync()
+        {
+            // Arrange
+            byte[] cache = new byte[3];
+            AssertCacheValues(_testCacheAdapter);
+            Assert.Equal(0, _testCacheAdapter._memoryCache.Count);
+            Assert.Empty(L2Cache.dict);
+            CacheSerializerHints cacheSerializerHints = new CacheSerializerHints();
+            cacheSerializerHints.SuggestedCacheExpiry = System.DateTimeOffset.Now - System.TimeSpan.FromHours(1);
+
+            // Act
+            await _testCacheAdapter.TestWriteCacheBytesAsync(DefaultCacheKey, cache, cacheSerializerHints).ConfigureAwait(false);
+
+            // Assert
+            Assert.Equal(1, _testCacheAdapter._memoryCache.Count);
+            Assert.Single(L2Cache.dict);
+            await Task.Delay(1000).ConfigureAwait(false);
+
+            Assert.Null(_testCacheAdapter._memoryCache.Get(DefaultCacheKey));
+            await _testCacheAdapter.TestReadCacheBytesAsync(DefaultCacheKey).ConfigureAwait(false);
+            Assert.Equal(1, _testCacheAdapter._memoryCache.Count);
+        }
+
         [Fact]
         public async Task SetL1Cache_ReadL1_TestAsync()
         {