Provide support for logging Blazor request information

[srafay]

NLog version: 5.0.1
NLog.Web.AspNetCore version: 5.0.0
Platform: .Net 6.0 (Blazor Server)

Hey is it possible to log the URL of request in ASP.NET Blazor applications? Right now when I define ${aspnet-request-Url} in the layout, it only gives this in logs:

https://localhost/_blazor

Is there a workaround for Blazor?
Related question on StackOverflow: https://stackoverflow.com/questions/72063711/logging-url-in-blazor-server-using-nlog

[welcome]

Hi! Thanks for opening your first issue here! Please make sure to follow the issue template - so we could help you better!

[snakefoot]

I don't have any experience with AspNetCore and Blazor. Guess you should ask Microsoft how to extract the blazor-request-information at server-side. Then you can make a pull-request for NLog.Web that implements a layoutrenderer, that can extract the request-information.

[repo-ranger]

Please add the requested info, so we could help you better! (This issue will be closed in 7 days)

[srafay]

I tried searching inside HttpContext and HttpRequest but it only has /_blazor in Path. From the documentation, it is advised to use Uri property from NavigationManager class for getting current URL in Blazor applications.

using Microsoft.AspNetCore.Components;
...
[Inject]
public NavigationManager MyNavigationManager {get; set;}

Would it be possible to somehow inject NavigationManager inside LayoutRenderers? @snakefoot

[snakefoot]

You are wellcome to try creating a LayoutRenderer that resolves NavigationManager as Service-Dependency.

You can look at AspNetEnvironmentLayoutRenderer.cs for inspiration of how to resolve a service (Ex. IHostEnvironment):

https://github.com/NLog/NLog.Web/blob/master/src/NLog.Web.AspNetCore/LayoutRenderers/AspNetEnvironmentLayoutRenderer.cs

So these should be the steps:

• Clone the NLog.Web-repository
• Create a new Blazor-Example-Application that depends on the NLog.Web.AspNetCore-project with NLog.config
• Create the new LayoutRenderer that resolves NavigationManager
• Test the new LayoutRenderer by using it in the Nlog.config for the new Blazor-Example-Application

[srafay]

Thanks @snakefoot for directions, I followed the steps and tried to use the new layout. I tried to resolve NavigationManager just like how IHostEnvironment is resolved in AspNetEnvironmentLayoutRenderer.cs.

/* AspNetNavigationManagerLayoutRenderer.cs */

using System;
using System.Text;
using Microsoft.AspNetCore.Components;
using NLog.Config;
using NLog.LayoutRenderers;
using NLog.Web.DependencyInjection;

namespace NLog.Web.LayoutRenderers
{
    /// <summary>
    /// Rendering development environment. <see cref="NavigationManager" />
    /// </summary>
    [LayoutRenderer("aspnet-navigation-manager")]
    [ThreadAgnostic]
    public class AspNetNavigationManagerLayoutRenderer : LayoutRenderer
    {
        private NavigationManager _navigationManager;

        private NavigationManager NavManager => _navigationManager ?? (_navigationManager = ServiceLocator.ResolveService<NavigationManager>(ResolveService<IServiceProvider>(), LoggingConfiguration));

        /// <summary>
        /// Append to target
        /// </summary>
        /// <param name="builder">The <see cref="StringBuilder" /> to append the rendered data to.</param>
        /// <param name="logEvent">Logging event.</param>
        protected override void Append(StringBuilder builder, LogEventInfo logEvent)
        {
            builder.Append(NavManager?.Uri);
        }

        /// <inheritdoc />
        protected override void CloseLayoutRenderer()
        {
            _navigationManager = null;
            base.CloseLayoutRenderer();
        }
    }
}

But whenever it tries to resolve the service, it gets an error here:

/* NLog.Web\src\NLog.Web.AspNetCore\Internal\ServiceLocator.cs : line29 */

var service = serviceProvider?.GetService(typeof(TService)) as TService;

System.InvalidOperationException: 'Cannot resolve scoped service 'Microsoft.AspNetCore.Components.NavigationManager' from root provider.'

Can you think of any reasons for this error?
Thanks again!

[snakefoot]

Sounds like NavigationManager can only be resolved server-side using middleware, as parameter to middleware InvokeAsync-method.

Maybe it can be done like https://github.com/NLog/NLog.Web/blob/master/src/NLog.Web.AspNetCore/NLogRequestPostedBodyMiddleware.cs

And inject the NavigationManager-Uri into HttpContext.Items.

[srafay]

Thank you @snakefoot. After trying to inject NavigationManager in the middleware, I found out a few things for Blazor Server applications:

1. NavigationManager doesn't get initialized in the middleware.
2. Middlewares only get called on the first request, subsequent requests donot call any middleware.

Initiliazing NavigationManager in middleware

When you create a middleware and pass the NavigationManager as a parameter to middlewares Invoke method, for some reasons, NavigationManager doesn't get initialized. NavigationManager._isInitialized is false. If you try to get the Uri from the NavigationManager inside a middleware, you get an exception:

public async Task Invoke(HttpContext context, NavigationManager navigationManager)
{
    var requestUri = navigationManager.Uri;
}

Exception:

System.InvalidOperationException: ''RemoteNavigationManager' has not been initialized.'

Tried to find out if its possible to access NavigationManager in the middleware, but it seems like its not possible with the Blazor server applications. Quoting an answer for a similar question from StackOverflow (source):

NavigationManager is a DI service that receives data from the Blazor client side code running in the browser whenever a browser side navigation event occurs. You can't access it directly from middleware because it only exists in the Blazor Hub session on the server.

As for why the middlewares don't get invoked for each request, its because only the first request is an HTTP request to the server which loads all the components and the static data (css/js/images), in this case middleware gets invoked and the browser establishes SignalR connection with the application. Once a SignalR connection is established, it uses Websockets for communicating between the client-server and no HTTP request is made after that. According to Blazor documentation:

The Blazor Server hosting model supports the Scoped lifetime across HTTP requests but not across SignalR connection/circuit messages among components that are loaded on the client. The Razor Pages or MVC portion of the app treats scoped services normally and recreates the services on each HTTP request when navigating among pages or views or from a page or view to a component. Scoped services aren't reconstructed when navigating among components on the client, where the communication to the server takes place over the SignalR connection of the user's circuit, not via HTTP requests. In the following component scenarios on the client, scoped services are reconstructed because a new circuit is created for the user:

• The user closes the browser's window. The user opens a new window and navigates back to the app.
• The user closes a tab of the app in a browser window. The user opens a new tab and navigates back to the app.
• The user selects the browser's reload/refresh button.

So even if someone somehow manages to inject and initialize NavigationManager through a hacky way in a middleware, middleware will only be called once and not all the time; unless you force all the requests to reload the components and send an HTTP request like this (which I probably cannot afford to do for my app)

@inject NavigationManager NavigationManager;
...
NavigationManager.NavigateTo("url", forceLoad: true);
/* forceLoad: If true, bypasses client-side routing and forces the browser to load the new page from the 
server, whether or not the URI would normally be handled by the client-side router. 
see: https://docs.microsoft.com/en-us/dotnet/api/microsoft.aspnetcore.components.navigationmanager.navigateto
*/

---

Solution for now (event-properties)

So the only possible way, I think, for getting request url in Blazor server is:

• Inject NavigationManager in Blazor component.
• Attach NavigationManager.Uri property to the logger by using .WithProperty method.
• Log this property value by using ${event-properties} layout renderer.

Sample counter page from Blazor app:

/* Counter.razor */
@page "/counter"
@inject NavigationManager navigationManager

<PageTitle>Counter</PageTitle>

<h1>Counter</h1>

<p role="status">Current count: @currentCount</p>

<button class="btn btn-primary" @onclick="IncrementCount">Click me</button>

@code {
    private int currentCount = 0;

    /* Define Logger */
    NLog.Logger _logger = NLog.LogManager.GetCurrentClassLogger();

    private void IncrementCount()
    {
        currentCount++;
        /* Attach property 'navigation-manager-uri' to the logger */
        var loggerWithProps = _logger.WithProperty("navigation-manager-uri", navigationManager.Uri);
        loggerWithProps.Info("Increment Count");
    }
}

NLog config file:

<!-- NLog.config -->
<targets>
    <target layout="${when:when='${event-properties:item=navigation-manager-uri}'!='':Inner=${event-properties:item=navigation-manager-uri} }${message}">
    </target>
</targets>

which gives correct output logs:

Now listening on: https://localhost:7123
Now listening on: http://localhost:5123
Application started. Press Ctrl+C to shut down.
Hosting environment: Development
Content root path: D:\Projects\Blazor NLog
https://localhost:7123/counter Increment Count
https://localhost:7123/counter Increment Count
https://localhost:7123/counter Increment Count

---

Posting the code for future, someone might be able to figure out how to make it work...

• AspNetNavigationManagerLayoutRenderer.cs
• NLogNavigationManagerMiddleware.cs
• NLogNavigationManagerMiddlewareOptions.cs
• Usage.txt
• Gist link: https://gist.github.com/srafay/479dff91f56d2e43d2da174a03c76679

[snakefoot]

So initializing the NavigationManager on the server-side is rather expensive, as it has to transfer additional state from the blazor-client to the blazor-server.

Still strange that there is not an easy way for tracking the navigation of the blazor-client. But I guess the blazor-client-side can do navigation without contacting the blazor-server-side.

But thank you do doing the investigation. Maybe someone will find a more elegant way of capturing state (Maybe using alternate way than NavigationManager)

[snakefoot]

Closing the issue, since outside the scope of NLog core.

Experts in Microsoft Blazor Application Development are very wellcome to provide their elegant solutions at stackoverflow.com:

https://stackoverflow.com/questions/72063711/logging-url-in-blazor-server-using-nlog

[alexandrejobin]

With .NET 8, we now have access to CreateInboundActivityHandler in the CircuitHandler. There's not much documentation but I'm presently trying to see if we can use ILogger.BeginScope to add context information from Blazor. For my understanding, CreateInboundActivityHandler get called each time there's an activity from SignalR. So it's like the first step before accessing the components. For now it works but I have to make more tests to see if it's a solid solution.

public class LoggingCircuitHandler : CircuitHandler
{
    private readonly NavigationManager _navigationManager;
    private readonly ILogger<LoggingCircuitHandler> _logger;

    public LoggingCircuitHandler(NavigationManager navigationManager, ILogger<LoggingCircuitHandler> logger)
    {
        _navigationManager = navigationManager;
        _logger = logger;

    }

    public override Task OnCircuitOpenedAsync(Circuit circuit, CancellationToken cancellationToken)
    {
        _logger.LogInformation("Circuit opened for {circuitId}.", circuit.Id);
        return base.OnCircuitOpenedAsync(circuit, cancellationToken);
    }

    public override Task OnConnectionUpAsync(Circuit circuit, CancellationToken cancellationToken)
    {
        _logger.LogInformation("Connection up for {circuitId}.", circuit.Id);
        return base.OnConnectionUpAsync(circuit, cancellationToken);
    }

    public override Task OnConnectionDownAsync(Circuit circuit, CancellationToken cancellationToken)
    {
        _logger.LogInformation("Connection down for {circuitId}.", circuit.Id);
        return base.OnConnectionDownAsync(circuit, cancellationToken);
    }

    public override Task OnCircuitClosedAsync(Circuit circuit, CancellationToken cancellationToken)
    {
        _logger.LogInformation("Circuit closed for {circuitId}.", circuit.Id);
        return base.OnCircuitClosedAsync(circuit, cancellationToken);
    }

    public override Func<CircuitInboundActivityContext, Task> CreateInboundActivityHandler(Func<CircuitInboundActivityContext, Task> next)
    {
        return context =>
        {
            var scopeTags = new Dictionary<string, object>()
            {
                ["BlazorUri"] = _navigationManager.Uri,
                ["CircuitId"] = context.Circuit.Id
            };

            using (_logger.BeginScope(scopeTags))
            {
                return next(context);
            }                    
        };
    }
}

Program.cs

builder.Services.AddScoped<CircuitHandler, LoggingCircuitHandler>();

[snakefoot]

@alexandrejobin Thank you for your input. You might also post it as alternative solution to this question on StackOverflow:

• https://stackoverflow.com/q/72063711/193178