Can I use ILogger.BeginScope() in Blazor (server)?

I have the following code for a page in my code:

string username = user.Name;
using (Logger.BeginScope("User:{username}", username))
{
if (Logger.IsEnabled(LogLevel.Trace))
Logger.LogTrace($"/Manager/Campaign ModeState={ModeState} UniqueId={UniqueId}");
}

And when this is logged (yes set to Trace) I get this:

'LouisHowe.web.exe' (CoreCLR: clrhost): Loaded 'C:\git\LouisHowe\LouisHowe.web\bin\Debug\net7.0\Newtonsoft.Json.dll'. Skipped loading symbols. Module is optimized and the debugger option 'Just My Code' is enabled.
LouisHowe.web.Pages.Manager.CampaignPage: Trace: /Manager/Campaign ModeState=Read UniqueId=Colorado_campaign_Boulder
Microsoft.EntityFrameworkCore.Query: Warning: Compiling a query which loads related collections for more than one collection navigation, either via 'Include' or through projection, but no 'QuerySplittingBehavior' has been configured. By default, Entity Framework will use 'QuerySplittingBehavior.SingleQuery', which can potentially result in slow query performance. See https://go.microsoft.com/fwlink/?linkid=2134277 for more information. To identify the query that's triggering this warning call 'ConfigureWarnings(w => w.Throw(RelationalEventId.MultipleCollectionIncludeWarning))'.

So no "User:david@whatever.com"

Is BeginScope ignored in Blazor server? Do I need to set something else?

And if it can be done, I also have the following (to add this to every log) - also does not work

Program.cs:

app.UseAuthentication();
app.UseAuthorization();
// must be after UseAuthentication/UseAuthorization
app.UseMiddleware<UserScopeMiddleware>();

UserScopeMiddleware.cs:

public class UserScopeMiddleware
{
private readonly RequestDelegate _next;
private readonly ILogger<UserScopeMiddleware> _logger;
public UserScopeMiddleware(RequestDelegate next, ILogger<UserScopeMiddleware> logger)
{
_next = next;
_logger = logger;
}
public async Task InvokeAsync(HttpContext context)
{
if (context.User.Identity is { IsAuthenticated: true })
{
var username = context.User.Identity.Name;
using (_logger.BeginScope("User:{username}", username))
{
await _next(context);
}
}
else
{
await _next(context);
}
}
}

Anything I need to add to make this work?

I changed my logging setup to:

builder.Logging.ClearProviders();
builder.Logging.AddJsonConsole();

and now in the console I get:

  "Timestamp": "23:18:00 ",
"EventId": 0,
"LogLevel": "Warning",
"Category": "LouisHowe.web.Pages.Manager.CampaignPage",
"Message": "/Manager/Campaign ModeState=Read UniqueId=Colorado_campaign_Boulder",
"State": {
"Message": "/Manager/Campaign ModeState=Read UniqueId=Colorado_campaign_Boulder",
"{OriginalFormat}": "/Manager/Campaign ModeState=Read UniqueId=Colorado_campaign_Boulder"
},
"Scopes": [
{
"Message": "SpanId:2cc5a3dbc3bfb348, TraceId:230638cecbe62fa814c1cca7a29c4966, ParentId:0000000000000000",
"SpanId": "2cc5a3dbc3bfb348",
"TraceId": "230638cecbe62fa814c1cca7a29c4966",
"ParentId": "0000000000000000"
},
{
"Message": "ConnectionId:0HMRO5LSIICLH",
"ConnectionId": "0HMRO5LSIICLH"
},
{
"Message": "RequestPath:/_blazor RequestId:0HMRO5LSIICLH:00000025",
"RequestId": "0HMRO5LSIICLH:00000025",
"RequestPath": "/_blazor"
},
{
"Message": "TransportConnectionId:P5EJP_vUZlsTIYRpRDkuAQ",
"TransportConnectionId": "P5EJP_vUZlsTIYRpRDkuAQ"
},
{
"Message": "User:colorado@thielen.com",
"username": "colorado@thielen.com",
"{OriginalFormat}": "User:{username}"
}
]

so Logger.BeginScope works!

However, if I remove the

using (Logger.BeginScope("User:{username}", username))
{
}

so that I'm dependent on the middleware - that does not work. With the explicit BeginScope gone I get:

{
"Timestamp": "23:18:00 ",
"EventId": 0,
"LogLevel": "Warning",
"Category": "LouisHowe.web.Pages.Manager.CampaignPage",
"Message": "/Manager/Campaign ModeState=Read UniqueId=Colorado_campaign_Boulder",
"State": {
"Message": "/Manager/Campaign ModeState=Read UniqueId=Colorado_campaign_Boulder",
"{OriginalFormat}": "/Manager/Campaign ModeState=Read UniqueId=Colorado_campaign_Boulder"
},
"Scopes": [
{
"Message": "SpanId:adb3b8b31b1b0cf6, TraceId:af46f44789291db3fef2c8e45229dcb0, ParentId:0000000000000000",
"SpanId": "adb3b8b31b1b0cf6",
"TraceId": "af46f44789291db3fef2c8e45229dcb0",
"ParentId": "0000000000000000"
},
{
"Message": "ConnectionId:0HMRO5NIOFFT0",
"ConnectionId": "0HMRO5NIOFFT0"
},
{
"Message": "RequestPath:/_blazor RequestId:0HMRO5NIOFFT0:00000025",
"RequestId": "0HMRO5NIOFFT0:00000025",
"RequestPath": "/_blazor"
},
{
"Message": "TransportConnectionId:7HQYBvsIgykJEIJzGgdjBg",
"TransportConnectionId": "7HQYBvsIgykJEIJzGgdjBg"
}
]

so... anyway to get the middleware working?

Ok, the trick is to create an ILogger wrapper. So created this class:

/// <summary>
/// Provides a logger where each log will have a scope with the User's AspNetId and email.
/// </summary>
public class ScopedLoggerFactory
{
private readonly ILoggerFactory _factory;
private readonly AuthenticationStateProvider _provider;
public ScopedLoggerFactory(ILoggerFactory factory, AuthenticationStateProvider provider)
{
_factory = factory;
_provider = provider;
}
/// <summary>
/// Get the ILogger.
/// </summary>
/// <typeparam name="T">The class the logger is going to log in.</typeparam>
/// <returns>AN ILogger with the scope set on each Log call.</returns>
public async Task<ScopedLogger<T>> GetLogger<T>()
{
var logger = _factory.CreateLogger<T>();
var user = await _provider.GetAuthenticationStateAsync();
var username = user.User.Identity?.Name;
string? aspNetId = user.User.Claims.FirstOrDefault(c => c.Type ==
"http://schemas.xmlsoap.org/ws/2005/05/identity/claims/nameidentifier")?.Value;
return new ScopedLogger<T>(logger, aspNetId, username);
}
}
/// <summary>
/// An ILogger where each Log() call will be in a scope with the user information.
/// </summary>
/// <typeparam name="T">The class the logger is going to log in.</typeparam>
public class ScopedLogger<T> : ILogger<T>
{
private readonly ILogger<T> _logger;
private readonly string? aspNetId;
private readonly string? username;
public ScopedLogger(ILogger<T> logger, string? aspNetId, string? username)
{
_logger = logger;
this.aspNetId = aspNetId;
this.username = username;
}
/// <inheritdoc />
public void Log<TState>(LogLevel logLevel, EventId eventId, TState state, Exception? exception,
Func<TState, Exception?, string> formatter)
{
using (_logger.BeginScope("User:{username}, {aspNetId}", username, aspNetId))
_logger.Log(logLevel, eventId, state, exception, formatter);
}
/// <inheritdoc />
public IDisposable? BeginScope<TState>(TState state) where TState : notnull
{
return _logger.BeginScope(state);
}
/// <inheritdoc />
public bool IsEnabled(LogLevel logLevel)
{
return _logger.IsEnabled(logLevel);
}
}

And then in the whatever.razor.cs files:

[Inject]
private ScopedLoggerFactory ScopedLoggerFactory { get; set; } = default!;
ScopedLogger<CampaignPage> Logger { get; set; } = default!;
// ...
Logger = await ScopedLoggerFactory.GetLogger<CampaignPage>();