Add CookiePolicy logging #1588

samples/CookiePolicySample/Program.cs

@@ -12,7 +12,7 @@ namespace CookiePolicySample
                 .ConfigureLogging(factory =>
                 {
                     factory.AddConsole();
-                    factory.AddFilter("Console", level => level >= LogLevel.Information);
+                    factory.AddFilter("Microsoft", LogLevel.Trace);
                 })
                 .UseKestrel()
                 .UseContentRoot(Directory.GetCurrentDirectory())

src/Microsoft.AspNetCore.CookiePolicy/CookiePolicyMiddleware.cs

@@ -1,10 +1,13 @@
 // Copyright (c) .NET Foundation. All rights reserved.
 // Licensed under the Apache License, Version 2.0. See License.txt in the project root for license information.
 
+using System;
 using System.Threading.Tasks;
 using Microsoft.AspNetCore.Builder;
 using Microsoft.AspNetCore.Http;
 using Microsoft.AspNetCore.Http.Features;
+using Microsoft.Extensions.Logging;
+using Microsoft.Extensions.Logging.Abstractions;
 using Microsoft.Extensions.Options;
 
 namespace Microsoft.AspNetCore.CookiePolicy
@@ -12,13 +15,20 @@ namespace Microsoft.AspNetCore.CookiePolicy
     public class CookiePolicyMiddleware
     {
         private readonly RequestDelegate _next;
+        private readonly ILogger _logger;
 
-        public CookiePolicyMiddleware(
+        public CookiePolicyMiddleware(RequestDelegate next, IOptions<CookiePolicyOptions> options, ILoggerFactory factory)
-            RequestDelegate next,
+        {
-            IOptions<CookiePolicyOptions> options)
+            Options = options.Value;
+            _next = next ?? throw new ArgumentNullException(nameof(next));
+            _logger = factory.CreateLogger<CookiePolicyMiddleware>();
+        }
+
+        public CookiePolicyMiddleware(RequestDelegate next, IOptions<CookiePolicyOptions> options)
         {
             Options = options.Value;
             _next = next;
+            _logger = NullLogger.Instance;
         }
 
         public CookiePolicyOptions Options { get; set; }
@@ -26,7 +36,7 @@ namespace Microsoft.AspNetCore.CookiePolicy
         public Task Invoke(HttpContext context)
         {
             var feature = context.Features.Get<IResponseCookiesFeature>() ?? new ResponseCookiesFeature(context.Features);
-            var wrapper = new ResponseCookiesWrapper(context, Options, feature);
+            var wrapper = new ResponseCookiesWrapper(context, Options, feature, _logger);
             context.Features.Set<IResponseCookiesFeature>(new CookiesWrapperFeature(wrapper));
             context.Features.Set<ITrackingConsentFeature>(wrapper);
 

src/Microsoft.AspNetCore.CookiePolicy/LoggingExtensions.cs

@@ -0,0 +1,105 @@
+// Copyright (c) .NET Foundation. All rights reserved.
+// Licensed under the Apache License, Version 2.0. See License.txt in the project root for license information.
+
+using System;
+
+namespace Microsoft.Extensions.Logging
+{
+    internal static class LoggingExtensions
+    {
+        private static Action<ILogger, bool, Exception> _needsConsent;
+        private static Action<ILogger, bool, Exception> _hasConsent;
+        private static Action<ILogger, Exception> _consentGranted;
+        private static Action<ILogger, Exception> _consentWithdrawn;
+        private static Action<ILogger, string, Exception> _cookieSuppressed;
+        private static Action<ILogger, string, Exception> _deleteCookieSuppressed;
+        private static Action<ILogger, string, Exception> _upgradedToSecure;
+        private static Action<ILogger, string, string, Exception> _upgradedSameSite;
+        private static Action<ILogger, string, Exception> _upgradedToHttpOnly;
+
+        static LoggingExtensions()
+        {
+            _needsConsent = LoggerMessage.Define<bool>(
+                eventId: 1,
+                logLevel: LogLevel.Trace,
+                formatString: "Needs consent: {needsConsent}.");
+            _hasConsent = LoggerMessage.Define<bool>(
+                eventId: 2,
+                logLevel: LogLevel.Trace,
+                formatString: "Has consent: {hasConsent}.");
+            _consentGranted = LoggerMessage.Define(
+                eventId: 3,
+                logLevel: LogLevel.Debug,
+                formatString: "Consent granted.");
+            _consentWithdrawn = LoggerMessage.Define(
+                eventId: 4,
+                logLevel: LogLevel.Debug,
+                formatString: "Consent withdrawn.");
+            _cookieSuppressed = LoggerMessage.Define<string>(
+                eventId: 5,
+                logLevel: LogLevel.Debug,
+                formatString: "Cookie '{key}' suppressed due to consent policy.");
+            _deleteCookieSuppressed = LoggerMessage.Define<string>(
+                eventId: 6,
+                logLevel: LogLevel.Debug,
+                formatString: "Delete cookie '{key}' suppressed due to developer policy.");
+            _upgradedToSecure = LoggerMessage.Define<string>(
+                eventId: 7,
+                logLevel: LogLevel.Debug,
+                formatString: "Cookie '{key}' upgraded to 'secure'.");
+            _upgradedSameSite = LoggerMessage.Define<string, string>(
+                eventId: 8,
+                logLevel: LogLevel.Debug,
+                formatString: "Cookie '{key}' same site mode upgraded to '{mode}'.");
+            _upgradedToHttpOnly = LoggerMessage.Define<string>(
+                eventId: 9,
+                logLevel: LogLevel.Debug,
+                formatString: "Cookie '{key}' upgraded to 'httponly'.");
+        }
+
+        public static void NeedsConsent(this ILogger logger, bool needsConsent)
+        {
+            _needsConsent(logger, needsConsent, null);
+        }
+
+        public static void HasConsent(this ILogger logger, bool hasConsent)
+        {
+            _hasConsent(logger, hasConsent, null);
+        }
+
+        public static void ConsentGranted(this ILogger logger)
+        {
+            _consentGranted(logger, null);
+        }
+
+        public static void ConsentWithdrawn(this ILogger logger)
+        {
+            _consentWithdrawn(logger, null);
+        }
+
+        public static void CookieSuppressed(this ILogger logger, string key)
+        {
+            _cookieSuppressed(logger, key, null);
+        }
+
+        public static void DeleteCookieSuppressed(this ILogger logger, string key)
+        {
+            _deleteCookieSuppressed(logger, key, null);
+        }
+
+        public static void CookieUpgradedToSecure(this ILogger logger, string key)
+        {
+            _upgradedToSecure(logger, key, null);
+        }
+
+        public static void CookieSameSiteUpgraded(this ILogger logger, string key, string mode)
+        {
+            _upgradedSameSite(logger, key, mode, null);
+        }
+
+        public static void CookieUpgradedToHttpOnly(this ILogger logger, string key)
+        {
+            _upgradedToHttpOnly(logger, key, null);
+        }
+    }
+}

src/Microsoft.AspNetCore.CookiePolicy/Microsoft.AspNetCore.CookiePolicy.csproj

@@ -10,6 +10,7 @@
 
   <ItemGroup>
     <PackageReference Include="Microsoft.AspNetCore.Http" Version="$(MicrosoftAspNetCoreHttpPackageVersion)" />
+    <PackageReference Include="Microsoft.Extensions.Logging.Abstractions" Version="$(MicrosoftExtensionsLoggingAbstractionsPackageVersion)" />
     <PackageReference Include="Microsoft.Extensions.Options" Version="$(MicrosoftExtensionsOptionsPackageVersion)" />
   </ItemGroup>
 

src/Microsoft.AspNetCore.CookiePolicy/ResponseCookiesWrapper.cs

@@ -5,21 +5,23 @@ using System;
 using Microsoft.AspNetCore.Builder;
 using Microsoft.AspNetCore.Http;
 using Microsoft.AspNetCore.Http.Features;
+using Microsoft.Extensions.Logging;
 
 namespace Microsoft.AspNetCore.CookiePolicy
 {
     internal class ResponseCookiesWrapper : IResponseCookies, ITrackingConsentFeature
     {
         private const string ConsentValue = "yes";
-
+        private readonly ILogger _logger;
         private bool? _isConsentNeeded;
         private bool? _hasConsent;
 
-        public ResponseCookiesWrapper(HttpContext context, CookiePolicyOptions options, IResponseCookiesFeature feature)
+        public ResponseCookiesWrapper(HttpContext context, CookiePolicyOptions options, IResponseCookiesFeature feature, ILogger logger)
         {
             Context = context;
             Feature = feature;
             Options = options;
+            _logger = logger;
         }
 
         private HttpContext Context { get; }
@@ -38,6 +40,7 @@ namespace Microsoft.AspNetCore.CookiePolicy
                 {
                     _isConsentNeeded = Options.CheckConsentNeeded == null ? false
                         : Options.CheckConsentNeeded(Context);
+                    _logger.NeedsConsent(_isConsentNeeded.Value);
                 }
 
                 return _isConsentNeeded.Value;
@@ -52,6 +55,7 @@ namespace Microsoft.AspNetCore.CookiePolicy
                 {
                     var cookie = Context.Request.Cookies[Options.ConsentCookie.Name];
                     _hasConsent = string.Equals(cookie, ConsentValue, StringComparison.Ordinal);
+                    _logger.HasConsent(_hasConsent.Value);
                 }
 
                 return _hasConsent.Value;
@@ -67,6 +71,7 @@ namespace Microsoft.AspNetCore.CookiePolicy
                 var cookieOptions = Options.ConsentCookie.Build(Context);
                 // Note policy will be applied. We don't want to bypass policy because we want HttpOnly, Secure, etc. to apply.
                 Append(Options.ConsentCookie.Name, ConsentValue, cookieOptions);
+                _logger.ConsentGranted();
             }
             _hasConsent = true;
         }
@@ -78,6 +83,7 @@ namespace Microsoft.AspNetCore.CookiePolicy
                 var cookieOptions = Options.ConsentCookie.Build(Context);
                 // Note policy will be applied. We don't want to bypass policy because we want HttpOnly, Secure, etc. to apply.
                 Delete(Options.ConsentCookie.Name, cookieOptions);
+                _logger.ConsentWithdrawn();
             }
             _hasConsent = false;
         }
@@ -137,12 +143,16 @@ namespace Microsoft.AspNetCore.CookiePolicy
             {
                 Cookies.Append(key, value, options);
             }
+            else
+            {
+                _logger.CookieSuppressed(key);
+            }
         }
 
         private bool ApplyAppendPolicy(ref string key, ref string value, CookieOptions options)
         {
             var issueCookie = CanTrack || options.IsEssential;
-            ApplyPolicy(options);
+            ApplyPolicy(key, options);
             if (Options.OnAppendCookie != null)
             {
                 var context = new AppendCookieContext(Context, options, key, value)
@@ -182,7 +192,7 @@ namespace Microsoft.AspNetCore.CookiePolicy
 
             // Assume you can always delete cookies unless directly overridden in the user event.
             var issueCookie = true;
-            ApplyPolicy(options);
+            ApplyPolicy(key, options);
             if (Options.OnDeleteCookie != null)
             {
                 var context = new DeleteCookieContext(Context, options, key)
@@ -201,17 +211,30 @@ namespace Microsoft.AspNetCore.CookiePolicy
             {
                 Cookies.Delete(key, options);
             }
+            else
+            {
+                _logger.DeleteCookieSuppressed(key);
+            }
         }
 
-        private void ApplyPolicy(CookieOptions options)
+        private void ApplyPolicy(string key, CookieOptions options)
         {
             switch (Options.Secure)
             {
                 case CookieSecurePolicy.Always:
-                    options.Secure = true;
+                    if (!options.Secure)
+                    {
+                        options.Secure = true;
+                        _logger.CookieUpgradedToSecure(key);
+                    }
                     break;
                 case CookieSecurePolicy.SameAsRequest:
-                    options.Secure = Context.Request.IsHttps;
+                    // Never downgrade a cookie
+                    if (Context.Request.IsHttps && !options.Secure)
+                    {
+                        options.Secure = true;
+                        _logger.CookieUpgradedToSecure(key);
+                    }
                     break;
                 case CookieSecurePolicy.None:
                     break;
@@ -226,10 +249,15 @@ namespace Microsoft.AspNetCore.CookiePolicy
                     if (options.SameSite == SameSiteMode.None)
                     {
                         options.SameSite = SameSiteMode.Lax;
+                        _logger.CookieSameSiteUpgraded(key, "lax");
                     }
                     break;
                 case SameSiteMode.Strict:
-                    options.SameSite = SameSiteMode.Strict;
+                    if (options.SameSite != SameSiteMode.Strict)
+                    {
+                        options.SameSite = SameSiteMode.Strict;
+                        _logger.CookieSameSiteUpgraded(key, "strict");
+                    }
                     break;
                 default:
                     throw new InvalidOperationException($"Unrecognized {nameof(SameSiteMode)} value {Options.MinimumSameSitePolicy.ToString()}");
@@ -237,7 +265,11 @@ namespace Microsoft.AspNetCore.CookiePolicy
             switch (Options.HttpOnly)
             {
                 case HttpOnlyPolicy.Always:
-                    options.HttpOnly = true;
+                    if (!options.HttpOnly)
+                    {
+                        options.HttpOnly = true;
+                        _logger.CookieUpgradedToHttpOnly(key);
+                    }
                     break;
                 case HttpOnlyPolicy.None:
                     break;

test/Microsoft.AspNetCore.CookiePolicy.Test/CookiePolicyTests.cs

@@ -102,7 +102,7 @@ namespace Microsoft.AspNetCore.CookiePolicy.Test
                         Assert.Equal("A=A; path=/; samesite=lax", transaction.SetCookie[0]);
                         Assert.Equal("B=B; path=/; samesite=lax", transaction.SetCookie[1]);
                         Assert.Equal("C=C; path=/; samesite=lax", transaction.SetCookie[2]);
-                        Assert.Equal("D=D; path=/; samesite=lax", transaction.SetCookie[3]);
+                        Assert.Equal("D=D; path=/; secure; samesite=lax", transaction.SetCookie[3]);
                     }),
                 new RequestTest("https://example.com/secureSame",
                     transaction =>