Scope ScriptJwtBearerHandler logs to system-only

release_notes.md

@@ -4,5 +4,6 @@
 - My change description (#PR)
 -->
 - Introduced proper handling in environments where .NET in-proc is not supported.
+- Suppress `JwtBearerHandler` logs from customer logs (#10617)
 - Updated System.Memory.Data reference to 8.0.1
 - Address issue with HTTP proxying throwing `ArgumentException` (#10616)

src/WebJobs.Script.WebHost/Program.cs

@@ -7,6 +7,7 @@
 using Microsoft.AspNetCore.Builder;
 using Microsoft.AspNetCore.Hosting;
 using Microsoft.Azure.WebJobs.Script.Config;
+using Microsoft.Azure.WebJobs.Script.Diagnostics;
 using Microsoft.Azure.WebJobs.Script.WebHost.Configuration;
 using Microsoft.Azure.WebJobs.Script.WebHost.Diagnostics;
 using Microsoft.Extensions.Configuration;
@@ -89,7 +90,7 @@ public static IWebHostBuilder CreateWebHostBuilder(string[] args = null)
                     loggingBuilder.AddWebJobsSystem<WebHostSystemLoggerProvider>();
                     loggingBuilder.Services.AddSingleton<DeferredLoggerProvider>();
                     loggingBuilder.Services.AddSingleton<ILoggerProvider>(s => s.GetRequiredService<DeferredLoggerProvider>());
-
+                    loggingBuilder.Services.AddSingleton<ISystemLoggerFactory, SystemLoggerFactory>();
                     if (context.HostingEnvironment.IsDevelopment())
                     {
                         loggingBuilder.AddConsole();

src/WebJobs.Script.WebHost/Security/Authentication/Jwt/ScriptJwtBearerExtensions.cs

@@ -15,7 +15,10 @@
 using Microsoft.Azure.WebJobs.Script.Extensions;
 using Microsoft.Azure.WebJobs.Script.WebHost;
 using Microsoft.Azure.WebJobs.Script.WebHost.Security.Authentication;
+using Microsoft.Azure.WebJobs.Script.WebHost.Security.Authentication.Jwt;
+using Microsoft.Extensions.DependencyInjection.Extensions;
 using Microsoft.Extensions.Logging;
+using Microsoft.Extensions.Options;
 using Microsoft.Extensions.Primitives;
 using Microsoft.IdentityModel.Tokens;
 using static Microsoft.Azure.WebJobs.Script.EnvironmentSettingNames;
@@ -28,63 +31,68 @@ public static class ScriptJwtBearerExtensions
         private static double _specialized = 0;
 
         public static AuthenticationBuilder AddScriptJwtBearer(this AuthenticationBuilder builder)
-            => builder.AddJwtBearer(o =>
+        {
+            builder.Services.TryAddEnumerable(ServiceDescriptor.Singleton<IPostConfigureOptions<JwtBearerOptions>, JwtBearerPostConfigureOptions>());
+            return builder.AddScheme<JwtBearerOptions, ScriptJwtBearerHandler>(
+                JwtBearerDefaults.AuthenticationScheme, displayName: null, ConfigureOptions);
+        }
+
+        private static void ConfigureOptions(JwtBearerOptions options)
+        {
+            options.Events = new JwtBearerEvents()
             {
-                o.Events = new JwtBearerEvents()
+                OnMessageReceived = c =>
                 {
-                    OnMessageReceived = c =>
+                    // By default, tokens are passed via the standard Authorization Bearer header. However we also support
+                    // passing tokens via the x-ms-site-token header.
+                    if (c.Request.Headers.TryGetValue(ScriptConstants.SiteTokenHeaderName, out StringValues values))
                     {
-                        // By default, tokens are passed via the standard Authorization Bearer header. However we also support
-                        // passing tokens via the x-ms-site-token header.
-                        if (c.Request.Headers.TryGetValue(ScriptConstants.SiteTokenHeaderName, out StringValues values))
-                        {
-                            // the token we set here will be the one used - Authorization header won't be checked.
-                            c.Token = values.FirstOrDefault();
-                        }
-
-                        // Temporary: Tactical fix to address specialization issues. This should likely be moved to a token validator
-                        // TODO: DI (FACAVAL) This will be fixed once the permanent fix is in place
-                        if (_specialized == 0 && !SystemEnvironment.Instance.IsPlaceholderModeEnabled() && Interlocked.CompareExchange(ref _specialized, 1, 0) == 0)
-                        {
-                            o.TokenValidationParameters = CreateTokenValidationParameters();
-                        }
-
-                        return Task.CompletedTask;
-                    },
-                    OnTokenValidated = c =>
+                        // the token we set here will be the one used - Authorization header won't be checked.
+                        c.Token = values.FirstOrDefault();
+                    }
+
+                    // Temporary: Tactical fix to address specialization issues. This should likely be moved to a token validator
+                    // TODO: DI (FACAVAL) This will be fixed once the permanent fix is in place
+                    if (_specialized == 0 && !SystemEnvironment.Instance.IsPlaceholderModeEnabled() && Interlocked.CompareExchange(ref _specialized, 1, 0) == 0)
                     {
-                        var claims = new List<Claim>
-                        {
-                            new Claim(SecurityConstants.AuthLevelClaimType, AuthorizationLevel.Admin.ToString())
-                        };
-                        if (!string.Equals(c.SecurityToken.Issuer, ScriptConstants.AppServiceCoreUri, StringComparison.OrdinalIgnoreCase))
-                        {
-                            claims.Add(new Claim(SecurityConstants.InvokeClaimType, "true"));
-                        }
-
-                        c.Principal.AddIdentity(new ClaimsIdentity(claims));
-
-                        c.Success();
-
-                        return Task.CompletedTask;
-                    },
-                    OnAuthenticationFailed = c =>
+                        options.TokenValidationParameters = CreateTokenValidationParameters();
+                    }
+
+                    return Task.CompletedTask;
+                },
+                OnTokenValidated = c =>
+                {
+                    var claims = new List<Claim>
                     {
-                        LogAuthenticationFailure(c);
+                        new Claim(SecurityConstants.AuthLevelClaimType, AuthorizationLevel.Admin.ToString())
+                    };
 
-                        return Task.CompletedTask;
+                    if (!string.Equals(c.SecurityToken.Issuer, ScriptConstants.AppServiceCoreUri, StringComparison.OrdinalIgnoreCase))
+                    {
+                        claims.Add(new Claim(SecurityConstants.InvokeClaimType, "true"));
                     }
-                };
 
-                o.TokenValidationParameters = CreateTokenValidationParameters();
+                    c.Principal.AddIdentity(new ClaimsIdentity(claims));
+                    c.Success();
 
-                // TODO: DI (FACAVAL) Remove this once the work above is completed.
-                if (!SystemEnvironment.Instance.IsPlaceholderModeEnabled())
+                    return Task.CompletedTask;
+                },
+                OnAuthenticationFailed = c =>
                 {
-                    // We're not in standby mode, so flag as specialized
-                    _specialized = 1;
+                    LogAuthenticationFailure(c);
+                    return Task.CompletedTask;
                 }
-            });
+            };
+
+            options.TokenValidationParameters = CreateTokenValidationParameters();
+
+            // TODO: DI (FACAVAL) Remove this once the work above is completed.
+            if (!SystemEnvironment.Instance.IsPlaceholderModeEnabled())
+            {
+                // We're not in standby mode, so flag as specialized
+                _specialized = 1;
+            }
+        }
 
         private static IEnumerable<string> GetValidAudiences()
         {
@@ -134,12 +142,12 @@ public static TokenValidationParameters CreateTokenValidationParameters()
                 result.AudienceValidator = AudienceValidator;
                 result.IssuerValidator = IssuerValidator;
                 result.ValidAudiences = GetValidAudiences();
-                result.ValidIssuers = new string[]
-                {
+                result.ValidIssuers =
+                [
                     AppServiceCoreUri,
                     string.Format(ScmSiteUriFormat, ScriptSettingsManager.Instance.GetSetting(AzureWebsiteName)),
                     string.Format(SiteUriFormat, ScriptSettingsManager.Instance.GetSetting(AzureWebsiteName))
-                };
+                ];
             }
 
             return result;

src/WebJobs.Script.WebHost/Security/Authentication/Jwt/ScriptJwtBearerHandler.cs

@@ -0,0 +1,33 @@
+// Copyright (c) .NET Foundation. All rights reserved.
+// Licensed under the MIT License. See License.txt in the project root for license information.
+
+using System.Text.Encodings.Web;
+using Microsoft.AspNetCore.Authentication;
+using Microsoft.AspNetCore.Authentication.JwtBearer;
+using Microsoft.Azure.WebJobs.Script.Diagnostics;
+using Microsoft.Extensions.Logging;
+using Microsoft.Extensions.Logging.Abstractions;
+using Microsoft.Extensions.Options;
+
+namespace Microsoft.Azure.WebJobs.Script.WebHost.Security.Authentication.Jwt
+{
+    internal sealed class ScriptJwtBearerHandler : JwtBearerHandler
+    {
+        /// <summary>
+        /// Initializes a new instance of the <see cref="ScriptJwtBearerHandler"/> class.
+        /// </summary>
+        /// <param name="options">The options.</param>
+        /// <param name="encoder">The url encoder.</param>
+        /// <param name="clock">The system clock.</param>
+        /// <param name="loggerFactory">The system logger factory.</param>
+        public ScriptJwtBearerHandler(
+            IOptionsMonitor<JwtBearerOptions> options,
+            UrlEncoder encoder,
+            ISystemClock clock,
+            ISystemLoggerFactory loggerFactory = null)
+            : base(options, (ILoggerFactory)loggerFactory ?? NullLoggerFactory.Instance, encoder, clock)
+        {
+            // Note - ISystemLoggerFactory falls back to NullLoggerFactory to avoid needing this service in tests.
+        }
+    }
+}

src/WebJobs.Script/Diagnostics/ISystemLoggerFactory.cs

@@ -0,0 +1,14 @@
+// Copyright (c) .NET Foundation. All rights reserved.
+// Licensed under the MIT License. See License.txt in the project root for license information.
+
+using Microsoft.Extensions.Logging;
+
+namespace Microsoft.Azure.WebJobs.Script.Diagnostics
+{
+    /// <summary>
+    /// A logger factory which is used to create loggers for system-only logs.
+    /// </summary>
+    internal interface ISystemLoggerFactory : ILoggerFactory
+    {
+    }
+}

src/WebJobs.Script/Diagnostics/SystemLoggerFactory.cs

@@ -0,0 +1,25 @@
+// Copyright (c) .NET Foundation. All rights reserved.
+// Licensed under the MIT License. See License.txt in the project root for license information.
+
+using System;
+using Microsoft.Extensions.Logging;
+
+namespace Microsoft.Azure.WebJobs.Script.Diagnostics
+{
+    /// <summary>
+    /// Default implementation of <see cref="ISystemLoggerFactory"/>.
+    /// </summary>
+    /// <param name="loggerFactory">The logger factory from the root container to wrap.</param>
+    internal class SystemLoggerFactory(ILoggerFactory loggerFactory) : ISystemLoggerFactory
+    {
+        public void AddProvider(ILoggerProvider provider)
+            => throw new InvalidOperationException("Cannot add providers to the system logger factory.");
+
+        public ILogger CreateLogger(string categoryName) => loggerFactory.CreateLogger(categoryName);
+
+        public void Dispose()
+        {
+            // No op - we do not dispose the provided logger factory.
+        }
+    }
+}

test/WebJobs.Script.Tests.Integration/TestFunctionHost.cs

@@ -16,6 +16,7 @@
 using Microsoft.AspNetCore.TestHost;
 using Microsoft.Azure.WebJobs.Host.Executors;
 using Microsoft.Azure.WebJobs.Script.Config;
+using Microsoft.Azure.WebJobs.Script.Diagnostics;
 using Microsoft.Azure.WebJobs.Script.ExtensionBundle;
 using Microsoft.Azure.WebJobs.Script.Models;
 using Microsoft.Azure.WebJobs.Script.WebHost;
@@ -120,6 +121,7 @@ public TestFunctionHost(string scriptPath, string logPath, string testDataPath =
                           return GetMetadataManager(montior, scriptManager, loggerFactory, environment);
                       }, ServiceLifetime.Singleton));
 
+                      services.AddSingleton<ISystemLoggerFactory, SystemLoggerFactory>();
                       services.SkipDependencyValidation();
 
                       // Allows us to configure services as the last step, thereby overriding anything
@@ -352,6 +354,7 @@ public static void WriteNugetPackageSources(string appRoot, params string[] sour
         /// </summary>
         /// <returns>The messages from the WebHost LoggerProvider</returns>
         public IList<LogMessage> GetWebHostLogMessages() => _webHostLoggerProvider.GetAllLogMessages();
+        public IEnumerable<LogMessage> GetWebHostLogMessages(string category) => GetWebHostLogMessages().Where(p => p.Category == category);
 
         public string GetLog() => string.Join(Environment.NewLine, GetScriptHostLogMessages().Concat(GetWebHostLogMessages()).OrderBy(m => m.Timestamp));
 

test/WebJobs.Script.Tests.Integration/WebHostEndToEnd/CSharpEndToEndTests.cs

@@ -11,8 +11,6 @@
 using System.Text;
 using System.Threading.Tasks;
 using Microsoft.Azure.WebJobs.Logging;
-using Microsoft.Azure.WebJobs.Script.Diagnostics;
-using Microsoft.Azure.WebJobs.Script.WebHost.Diagnostics;
 using Microsoft.Azure.WebJobs.Script.WebHost.Models;
 using Microsoft.Azure.WebJobs.Script.Workers;
 using Microsoft.Azure.WebJobs.Script.Workers.Rpc;

test/WebJobs.Script.Tests.Integration/WebHostEndToEnd/JwtTokenAuthTests.cs

@@ -173,8 +173,14 @@ public async Task InvokeNonAdminApi_InvalidToken_DoesNotLogTokenAuthFailure()
             var response = await _fixture.Host.HttpClient.SendAsync(request);
             response.EnsureSuccessStatusCode();
 
-            var validationErrors = _fixture.Host.GetScriptHostLogMessages().Where(p => p.Category == ScriptConstants.LogCategoryHostAuthentication).ToArray();
+            var validationErrors = _fixture.Host.GetScriptHostLogMessages(ScriptConstants.LogCategoryHostAuthentication);
             Assert.Empty(validationErrors);
+
+            const string jwtCategory = "Microsoft.AspNetCore.Authentication.JwtBearer.JwtBearerHandler";
+            var authErrors = _fixture.Host.GetScriptHostLogMessages(jwtCategory)
+                .Concat(_fixture.Host.GetWebHostLogMessages(jwtCategory))
+                .Where(p => p.Level == LogLevel.Error || p.Exception is not null);
+            Assert.Empty(authErrors);
         }
 
         public class TestFixture : EndToEndTestFixture