Skip to content

Better logs in AuthorizationMiddleware #43862

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Merged
HaoK merged 6 commits into from
Oct 7, 2022
+54 −18
Merged

Better logs in AuthorizationMiddleware #43862

Show file tree
Hide file tree
Changes from 3 commits
Commits
Show all changes
6 commits
Select commit Hold shift + click to select a range
94180c1
Better logs in AuthorizationMiddleware
Sep 9, 2022
012821e
Apply comment
Sep 13, 2022
a62ef8b
Remove from Shipped
Sep 15, 2022
85e5750
Update src/Security/Authorization/Policy/src/AuthorizationMiddleware.cs
luccawilli Oct 4, 2022
c64d4bb
Remove ctors
Oct 4, 2022
62afbf8
Remove logger from Benchmark
Oct 4, 2022
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
44 changes: 41 additions & 3 deletions src/Security/Authorization/Policy/src/AuthorizationMiddleware.cs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -6,6 +6,7 @@
using Microsoft.AspNetCore.Http;
using Microsoft.AspNetCore.Http.Features.Authentication;
using Microsoft.Extensions.DependencyInjection;
using Microsoft.Extensions.Logging;

namespace Microsoft.AspNetCore.Authorization;

Expand All @@ -25,13 +26,28 @@ public class AuthorizationMiddleware
private readonly IAuthorizationPolicyProvider _policyProvider;
private readonly bool _canCache;
private readonly AuthorizationPolicyCache? _policyCache;
private readonly ILogger<AuthorizationMiddleware>? _logger;

/// <summary>
/// Initializes a new instance of <see cref="AuthorizationMiddleware"/>.
/// </summary>
/// <param name="next">The next middleware in the application middleware pipeline.</param>
/// <param name="policyProvider">The <see cref="IAuthorizationPolicyProvider"/>.</param>
public AuthorizationMiddleware(RequestDelegate next, IAuthorizationPolicyProvider policyProvider)
/// <param name="logger">The <see cref="ILogger"/>.</param>
public AuthorizationMiddleware(RequestDelegate next,
IAuthorizationPolicyProvider policyProvider,
ILogger<AuthorizationMiddleware> logger) : this(next, policyProvider)
{
_logger = logger;
}

/// <summary>
/// Initializes a new instance of <see cref="AuthorizationMiddleware"/>.
/// </summary>
/// <param name="next">The next middleware in the application middleware pipeline.</param>
/// <param name="policyProvider">The <see cref="IAuthorizationPolicyProvider"/>.</param>
public AuthorizationMiddleware(RequestDelegate next,
IAuthorizationPolicyProvider policyProvider)
{
_next = next ?? throw new ArgumentNullException(nameof(next));
_policyProvider = policyProvider ?? throw new ArgumentNullException(nameof(policyProvider));
Expand All @@ -44,7 +60,24 @@ public AuthorizationMiddleware(RequestDelegate next, IAuthorizationPolicyProvide
/// <param name="next">The next middleware in the application middleware pipeline.</param>
/// <param name="policyProvider">The <see cref="IAuthorizationPolicyProvider"/>.</param>
/// <param name="services">The <see cref="IServiceProvider"/>.</param>
public AuthorizationMiddleware(RequestDelegate next, IAuthorizationPolicyProvider policyProvider, IServiceProvider services) : this(next, policyProvider)
/// <param name="logger">The <see cref="ILogger"/>.</param>
Copy link
Member

@HaoK HaoK Sep 16, 2022

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

How do we feel about just service locating ILogger<AuthorizationMiddleware> so we don't have to add any new ctors, that would simplify the change a lot

Copy link
Member

@Tratcher Tratcher Sep 16, 2022

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Only the longest constructor should be called by DI, I don't think we need the other new combinations. One new constructor isn't a big deal.

Copy link
Member

@HaoK HaoK Sep 28, 2022

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@luccawilli can you remove all the extra new constuctor overloads except the one we need

public AuthorizationMiddleware(RequestDelegate next,
IAuthorizationPolicyProvider policyProvider,
IServiceProvider services,
ILogger<AuthorizationMiddleware> logger) : this(next, policyProvider, services)
{
_logger = logger;
}

/// <summary>
/// Initializes a new instance of <see cref="AuthorizationMiddleware"/>.
/// </summary>
/// <param name="next">The next middleware in the application middleware pipeline.</param>
/// <param name="policyProvider">The <see cref="IAuthorizationPolicyProvider"/>.</param>
/// <param name="services">The <see cref="IServiceProvider"/>.</param>
public AuthorizationMiddleware(RequestDelegate next,
IAuthorizationPolicyProvider policyProvider,
IServiceProvider services) : this(next, policyProvider)
{
ArgumentNullException.ThrowIfNull(services);

Expand Down Expand Up @@ -108,7 +141,7 @@ public async Task Invoke(HttpContext context)
var policyEvaluator = context.RequestServices.GetRequiredService<IPolicyEvaluator>();

var authenticateResult = await policyEvaluator.AuthenticateAsync(policy, context);

if (authenticateResult?.Succeeded ?? false)
{
if (context.Features.Get<IAuthenticateResultFeature>() is IAuthenticateResultFeature authenticateResultFeature)
Expand All @@ -130,6 +163,11 @@ public async Task Invoke(HttpContext context)
return;
}

if (authenticateResult != null && !authenticateResult.Succeeded)
{
_logger?.LogDebug("Policy authentication schemes {policyName} did not succeed", String.Join(", ", policy.AuthenticationSchemes));
}

object? resource;
if (AppContext.TryGetSwitch(SuppressUseHttpContextAsAuthorizationResource, out var useEndpointAsResource) && useEndpointAsResource)
{
Expand Down
2 changes: 2 additions & 0 deletions src/Security/Authorization/Policy/src/PublicAPI.Unshipped.txt
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -1,5 +1,7 @@
#nullable enable
Microsoft.AspNetCore.Authorization.AuthorizationMiddleware.AuthorizationMiddleware(Microsoft.AspNetCore.Http.RequestDelegate! next, Microsoft.AspNetCore.Authorization.IAuthorizationPolicyProvider! policyProvider, System.IServiceProvider! services) -> void
Microsoft.AspNetCore.Authorization.AuthorizationMiddleware.AuthorizationMiddleware(Microsoft.AspNetCore.Http.RequestDelegate! next, Microsoft.AspNetCore.Authorization.IAuthorizationPolicyProvider! policyProvider, System.IServiceProvider! services, Microsoft.Extensions.Logging.ILogger<Microsoft.AspNetCore.Authorization.AuthorizationMiddleware!>! logger) -> void
Microsoft.AspNetCore.Authorization.AuthorizationMiddleware.AuthorizationMiddleware(Microsoft.AspNetCore.Http.RequestDelegate! next, Microsoft.AspNetCore.Authorization.IAuthorizationPolicyProvider! policyProvider, Microsoft.Extensions.Logging.ILogger<Microsoft.AspNetCore.Authorization.AuthorizationMiddleware!>! logger) -> void
static Microsoft.AspNetCore.Builder.AuthorizationEndpointConventionBuilderExtensions.RequireAuthorization<TBuilder>(this TBuilder builder, Microsoft.AspNetCore.Authorization.AuthorizationPolicy! policy) -> TBuilder
static Microsoft.AspNetCore.Builder.AuthorizationEndpointConventionBuilderExtensions.RequireAuthorization<TBuilder>(this TBuilder builder, System.Action<Microsoft.AspNetCore.Authorization.AuthorizationPolicyBuilder!>! configurePolicy) -> TBuilder
static Microsoft.Extensions.DependencyInjection.PolicyServiceCollectionExtensions.AddAuthorizationBuilder(this Microsoft.Extensions.DependencyInjection.IServiceCollection! services) -> Microsoft.AspNetCore.Authorization.AuthorizationBuilder!
39 changes: 25 additions & 14 deletions src/Security/Authorization/test/AuthorizationMiddlewareTests.cs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -6,11 +6,11 @@
using Microsoft.AspNetCore.Authorization.Policy;
using Microsoft.AspNetCore.Authorization.Test.TestObjects;
using Microsoft.AspNetCore.Builder;
using Microsoft.AspNetCore.Hosting;
using Microsoft.AspNetCore.Http;
using Microsoft.AspNetCore.Routing;
using Microsoft.Extensions.DependencyInjection;
using Microsoft.Extensions.Hosting;
using Microsoft.Extensions.Logging;
using Microsoft.Extensions.Options;
using Microsoft.Extensions.Primitives;
using Moq;
Expand Down Expand Up @@ -46,8 +46,9 @@ public async Task NoEndpointWithFallback_AnonymousUser_Challenges()
var policyProvider = new Mock<IAuthorizationPolicyProvider>();
policyProvider.Setup(p => p.GetFallbackPolicyAsync()).ReturnsAsync(policy);
var next = new TestRequestDelegate();
var logger = new Mock<ILogger<AuthorizationMiddleware>>();

var middleware = CreateMiddleware(next.Invoke, policyProvider.Object);
var middleware = CreateMiddleware(next.Invoke, policyProvider.Object, logger: logger.Object);
var context = GetHttpContext(anonymous: true);

// Act
Expand Down Expand Up @@ -85,8 +86,9 @@ public async Task HasEndpointWithFallbackWithoutAuth_AnonymousUser_Challenges()
policyProvider.Setup(p => p.GetDefaultPolicyAsync()).ReturnsAsync(policy);
policyProvider.Setup(p => p.GetFallbackPolicyAsync()).ReturnsAsync(policy);
var next = new TestRequestDelegate();
var logger = new Mock<ILogger<AuthorizationMiddleware>>();

var middleware = CreateMiddleware(next.Invoke, policyProvider.Object);
var middleware = CreateMiddleware(next.Invoke, policyProvider.Object, logger: logger.Object);
var context = GetHttpContext(anonymous: true, endpoint: CreateEndpoint());

// Act
Expand All @@ -106,8 +108,9 @@ public async Task HasEndpointWithOnlyFallbackAuth_AnonymousUser_Allows()
policyProvider.Setup(p => p.GetFallbackPolicyAsync()).ReturnsAsync(policy);
var next = new TestRequestDelegate();
var authenticationService = new TestAuthenticationService();
var logger = new Mock<ILogger<AuthorizationMiddleware>>();

var middleware = CreateMiddleware(next.Invoke, policyProvider.Object);
var middleware = CreateMiddleware(next.Invoke, policyProvider.Object, logger: logger.Object);
var context = GetHttpContext(anonymous: true, endpoint: CreateEndpoint(new AuthorizeAttribute()), authenticationService: authenticationService);

// Act
Expand All @@ -126,8 +129,9 @@ public async Task HasEndpointWithAuth_AnonymousUser_Challenges()
policyProvider.Setup(p => p.GetDefaultPolicyAsync()).ReturnsAsync(policy);
var next = new TestRequestDelegate();
var authenticationService = new TestAuthenticationService();
var logger = new Mock<ILogger<AuthorizationMiddleware>>();

var middleware = CreateMiddleware(next.Invoke, policyProvider.Object);
var middleware = CreateMiddleware(next.Invoke, policyProvider.Object, logger: logger.Object);
var context = GetHttpContext(anonymous: true, endpoint: CreateEndpoint(new AuthorizeAttribute()), authenticationService: authenticationService);

// Act
Expand All @@ -147,8 +151,9 @@ public async Task HasEndpointWithAuth_ChallengesAuthenticationSchemes()
policyProvider.Setup(p => p.GetDefaultPolicyAsync()).ReturnsAsync(policy);
var next = new TestRequestDelegate();
var authenticationService = new TestAuthenticationService();
var logger = new Mock<ILogger<AuthorizationMiddleware>>();

var middleware = CreateMiddleware(next.Invoke, policyProvider.Object);
var middleware = CreateMiddleware(next.Invoke, policyProvider.Object, logger: logger.Object);
var context = GetHttpContext(endpoint: CreateEndpoint(new AuthorizeAttribute() { AuthenticationSchemes = "whatever" }), authenticationService: authenticationService);

// Act
Expand All @@ -168,8 +173,9 @@ public async Task HasEndpointWithAuth_AnonymousUser_ChallengePerScheme()
policyProvider.Setup(p => p.GetDefaultPolicyAsync()).ReturnsAsync(policy);
var next = new TestRequestDelegate();
var authenticationService = new TestAuthenticationService();
var logger = new Mock<ILogger<AuthorizationMiddleware>>();

var middleware = CreateMiddleware(next.Invoke, policyProvider.Object);
var middleware = CreateMiddleware(next.Invoke, policyProvider.Object, logger: logger.Object);
var context = GetHttpContext(anonymous: true, endpoint: CreateEndpoint(new AuthorizeAttribute()), authenticationService: authenticationService);

// Act
Expand All @@ -193,7 +199,8 @@ public async Task OnAuthorizationAsync_WillCallPolicyProvider()
policyProvider.Setup(p => p.GetFallbackPolicyAsync()).ReturnsAsync(policy)
.Callback(() => getFallbackPolicyCount++);
var next = new TestRequestDelegate();
var middleware = CreateMiddleware(next.Invoke, policyProvider.Object);
var logger = new Mock<ILogger<AuthorizationMiddleware>>();
var middleware = CreateMiddleware(next.Invoke, policyProvider.Object, logger: logger.Object);
var context = GetHttpContext(anonymous: true, endpoint: CreateEndpoint(new AuthorizeAttribute("whatever")));

// Act & Assert
Expand Down Expand Up @@ -235,12 +242,13 @@ public async Task OnAuthorizationAsync_WillNotCallPolicyProviderWithCache()
.Callback(() => getFallbackPolicyCount++);
policyProvider.Setup(p => p.AllowsCachingPolicies).Returns(true);
var next = new TestRequestDelegate();
var logger = new Mock<ILogger<AuthorizationMiddleware>>();

var endpoint = CreateEndpoint(new AuthorizeAttribute("whatever"));
var services = new ServiceCollection()
.AddAuthorization()
.AddSingleton(CreateDataSource(endpoint)).BuildServiceProvider();
var middleware = CreateMiddleware(next.Invoke, policyProvider.Object, services);
var middleware = CreateMiddleware(next.Invoke, policyProvider.Object, services, logger.Object);
var context = GetHttpContext(anonymous: true, endpoint: endpoint);

// Act & Assert
Expand Down Expand Up @@ -299,7 +307,8 @@ public async Task OnAuthorizationAsync_WillCallDerviedDefaultPolicyProviderCanCa
var services = new ServiceCollection()
.AddAuthorization()
.AddSingleton(CreateDataSource(endpoint)).BuildServiceProvider();
var middleware = CreateMiddleware(next.Invoke, policyProvider, services);
var logger = new Mock<ILogger<AuthorizationMiddleware>>();
var middleware = CreateMiddleware(next.Invoke, policyProvider, services, logger.Object);
var context = GetHttpContext(anonymous: true, endpoint: endpoint);

// Act & Assert
Expand Down Expand Up @@ -332,7 +341,8 @@ public async Task OnAuthorizationAsync_WillCallCustomPolicyProviderWithCache()
policyProvider.Setup(p => p.GetFallbackPolicyAsync()).ReturnsAsync(policy)
.Callback(() => getFallbackPolicyCount++);
var next = new TestRequestDelegate();
var middleware = CreateMiddleware(next.Invoke, policyProvider.Object);
var logger = new Mock<ILogger<AuthorizationMiddleware>>();
var middleware = CreateMiddleware(next.Invoke, policyProvider.Object, logger: logger.Object);
var context = GetHttpContext(anonymous: true, endpoint: CreateEndpoint(new AuthorizeAttribute("whatever")));

// Act & Assert
Expand Down Expand Up @@ -444,8 +454,9 @@ public async Task Invoke_AuthSchemesFailShouldSetEmptyPrincipalOnContext()
policyProvider.Setup(p => p.GetDefaultPolicyAsync()).ReturnsAsync(policy);
var next = new TestRequestDelegate();
var authenticationService = new TestAuthenticationService();
var logger = new Mock<ILogger<AuthorizationMiddleware>>();

var middleware = CreateMiddleware(next.Invoke, policyProvider.Object);
var middleware = CreateMiddleware(next.Invoke, policyProvider.Object, logger: logger.Object);
var context = GetHttpContext(endpoint: CreateEndpoint(new AuthorizeAttribute()), authenticationService: authenticationService);

// Act
Expand Down Expand Up @@ -824,11 +835,11 @@ public async Task WebApplicationBuilder_CanRegisterAuthzMiddlewareWithScopedServ
Assert.True(app.Properties.ContainsKey("__AuthorizationMiddlewareSet"));
}

private AuthorizationMiddleware CreateMiddleware(RequestDelegate requestDelegate = null, IAuthorizationPolicyProvider policyProvider = null, IServiceProvider services = null)
private AuthorizationMiddleware CreateMiddleware(RequestDelegate requestDelegate = null, IAuthorizationPolicyProvider policyProvider = null, IServiceProvider services = null, ILogger<AuthorizationMiddleware> logger = null)
{
requestDelegate = requestDelegate ?? ((context) => Task.CompletedTask);
services ??= new ServiceCollection().BuildServiceProvider();
return new AuthorizationMiddleware(requestDelegate, policyProvider, services);
return new AuthorizationMiddleware(requestDelegate, policyProvider, services, logger);
}

private Endpoint CreateEndpoint(params object[] metadata)
Expand Down
8 changes: 6 additions & 2 deletions src/Security/perf/Microbenchmarks/AuthorizationMiddlewareBenchmark.cs
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -1,10 +1,11 @@
// Licensed to the .NET Foundation under one or more agreements.
// Licensed to the .NET Foundation under one or more agreements.
// The .NET Foundation licenses this file to you under the MIT license.

using BenchmarkDotNet.Attributes;
using Microsoft.AspNetCore.Authorization;
using Microsoft.AspNetCore.Http;
using Microsoft.AspNetCore.Http.Features;
using Microsoft.Extensions.Logging;
using Microsoft.Extensions.Options;

namespace Microsoft.AspNetCore.Security;
Expand All @@ -19,7 +20,10 @@ public class AuthorizationMiddlewareBenchmark
public void Setup()
{
var policyProvider = new DefaultAuthorizationPolicyProvider(Options.Create(new AuthorizationOptions()));
_authorizationMiddleware = new AuthorizationMiddleware((context) => Task.CompletedTask, policyProvider);
var logger = LoggerFactory
.Create(logging => { })
.CreateLogger<AuthorizationMiddleware>();
_authorizationMiddleware = new AuthorizationMiddleware((context) => Task.CompletedTask, policyProvider, logger);

_httpContextNoEndpoint = new DefaultHttpContext();

Expand Down