Skip to content
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.

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

Inconsistent RequestTelemetry.Name in AspNetCore when using UseExceptionHandler or UseStatusCodePagesWithReExecute #2878

Open
ohlus opened this issue Jun 12, 2024 · 4 comments
Labels

Comments

@ohlus
Copy link

ohlus commented Jun 12, 2024

  • List of NuGet packages and version that you are using:
    • Microsoft.ApplicationInsights.AspNetCore 2.22.0
  • Runtime version: net8.0
  • Hosting environment: Windows

Describe the bug

When using UseExceptionHandler and/or UseStatusCodePagesWithReExecute in an AspNetCore application, the values of RequestTelemetry.Name are inconsistent.
The logged request name in Application Insights for the same url/controller action
is different depending on whether the request was unauthorized, an exception was thrown or otherwise status code 400-599 was returned.

This is really unexpected and makes analyzing failures in Azure Portal very difficult if not impossible, because Application Insights user interface shows requests grouped by their name.

Related to this issue #1555, but it's closed. So I'm creating this issue with detailed information and a repo so it will hopefully be addressed this time.

To Reproduce

I have created a simple repo to reproduce the behavior here:

https:/ohlus/app-insights-request-name

The home page shows a few links that lead to differences in the logged RequestTelemetry.Name by calling simple MVC controller actions
and a simple custom middleware to show that the behavior is also different without using routing/endpoints.

The middlware configuration derives from a template, then adding Application Insights in Visual Studio 2022 and finally adding UseExceptionHandler and UseStatusCodePagesWithReExecute and custom middleware:

var app = builder.Build();

app.UseExceptionHandler("/ErrorHandler/Error");
app.UseStatusCodePagesWithReExecute("/ErrorHandler/Error");

app.UseHttpsRedirection();

app.UseStaticFiles();

app.UseRouting();

app.UseAuthentication();
app.UseAuthorization();

app.UseEndpoints(_ => { });
app.MapControllerRoute(
    name: "default",
    pattern: "{controller=Home}/{action=Index}/{id?}");

app.UseCustomMiddleware();

app.Run();

This table summarizes the results of the logged requests and what I expected them to be:

url resultCode name OK expected name
https://localhost:7266/Test/Return200 200 GET Test/Return200
https://localhost:7266/Test/Return401 401 GET Test/Return401
https://localhost:7266/Test/Return500 500 GET Test/Return500
https://localhost:7266/Test/ThrowException 500 GET Test/ThrowException
https://localhost:7266/Test/AuthorizationPolicy 401 GET ErrorHandler/Error GET Test/AuthorizationPolicy
https://localhost:7266/Test/OnlyPostSupported 405 GET ErrorHandler/Error GET Test/OnlyPostSupported
https://localhost:7266/NonExistingAddress 404 GET ErrorHandler/Error GET /NonExistingAddress
https://localhost:7266/CustomMiddleware204 204 GET /CustomMiddleware204
https://localhost:7266/CustomMiddleware500 500 GET ErrorHandler/Error GET /CustomMiddleware500
https://localhost:7266/CustomMiddlewareThrow 500 GET ErrorHandler/Error GET /CustomMiddlewareThrow

/Test/AuthorizationPolicy controller action is decorated with [Authorize] attribute.
/Test/OnlyPostSupported action is decorated with [HttpPost].

Based on the name, the actions/middleware will either return an empty response with status code set or throw an exception.

If I comment out UseExceptionHandler and UseStatusCodePagesWithReExecute, then even without re-execution there is a difference in the request name:

url resultCode name OK expected name
https://localhost:7266/Test/AuthorizationPolicy 401 GET /Test/AuthorizationPolicy GET Test/AuthorizationPolicy

Note the leading /. For controller actions I expect that the / won't be there,
because then requests to this one specific action will be in two different groups.

@ohlus ohlus added the bug label Jun 12, 2024
@JarrodJ83
Copy link

Really hoping to see this fixed. It makes it incredibly hard to troubleshoot issues when everything gets lumped together. Does anyone have a workaround for this until there is an official fix?

@ohlus
Copy link
Author

ohlus commented Jul 29, 2024

@JarrodJ83 This is the current state of my workaround. The idea is to use a middleware that generates and saves the request name to a HttpContext feature on the first execution of the request pipeline. If the pipeline is being re-executed, it detects it because of the already set feature on the HttpContext.
Then after the _next was executed it sets the RequestTelemetry.Name. It can't do that at the beginning, because RequestTelemetry feature isn't available yet.
I'm not claiming this is 100% correct, but so far I haven't found anything better.
Perhaps the right solution would be possible using the DiagnosticListener, but I haven't spent too much time investigating it.
I hope this helps you and others. If anyone has an opinion on this, I'm interested 😄

app.UseRouting();
app.UseAppInsightsRequestTelemetryMiddleware(); // This must be right after UseRouting.
public static class AppInsightsRequestTelemetryMiddlewareExtensions
{
    public static IApplicationBuilder UseAppInsightsRequestTelemetryMiddleware(this IApplicationBuilder builder)
        => builder.UseMiddleware<AppInsightsRequestTelemetryMiddleware>();
}
public sealed record RequestTelemetryNameFeature(string? RequestName)
{
    public static readonly RequestTelemetryNameFeature NullRequestName = new(RequestName: null);
}

public sealed class AppInsightsRequestTelemetryMiddleware
{
    private readonly RequestDelegate _next;

    public AppInsightsRequestTelemetryMiddleware(RequestDelegate next)
    {
        _next = next;
    }

    public Task InvokeAsync(HttpContext httpContext)
    {
        // detect re-execution
        if (httpContext.Features.Get<RequestTelemetryNameFeature>() is not null)
        {
            return _next(httpContext);
        }

        var name = AppInsightsRequestTelemetryHelpers.GetRequestNameFromHttpContext(httpContext);
        if (string.IsNullOrEmpty(name))
        {
            httpContext.Features.Set(RequestTelemetryNameFeature.NullRequestName);

            return RunNextAndSetNameAsync(httpContext);
        }

        httpContext.Features.Set(new RequestTelemetryNameFeature(name));

        return RunNextAndSetNameAsync(httpContext);
    }

    private async Task RunNextAndSetNameAsync(HttpContext httpContext)
    {
        try
        {
            await _next(httpContext);
        }
        finally
        {
            SetRequestTelemetryName(httpContext);
        }
    }

    private void SetRequestTelemetryName(HttpContext httpContext)
    {
        if (httpContext.Features.Get<RequestTelemetryNameFeature>() is { RequestName: string name }
         && httpContext.Features.Get<RequestTelemetry>() is { } requestTelemetry)
        {
            requestTelemetry.Name = name;
        }
    }
}

This helper generates the request name. Because this library doesn't expose the implementation at NETCORE/src/Microsoft.ApplicationInsights.AspNetCore/DiagnosticListeners/Implementation/HostingDiagnosticListener.cs, it needs to reimplement it:

public static class AppInsightsRequestTelemetryHelpers
{
    public static string? GetRequestNameFromHttpContext(HttpContext httpContext)
    {
        var nameCandidate = GetNameFromRouteValueDictionary(httpContext.Request.RouteValues)
                         ?? httpContext.Request.Path.Value;

        if (string.IsNullOrEmpty(nameCandidate))
        {
            return null;
        }

        var name = httpContext.Request.Method + " " + nameCandidate;
        return name;
    }

    public static string? GetNameFromRouteValueDictionary(RouteValueDictionary routeValues)
    {
        // same logic that AI dotnet uses:
        // NETCORE/src/Microsoft.ApplicationInsights.AspNetCore/DiagnosticListeners/Implementation/HostingDiagnosticListener.cs

        if (routeValues.Count <= 0)
        {
            return null;
        }

        string? name = null;
        routeValues.TryGetValue("controller", out var controller);
        var controllerString = (controller is null) ? string.Empty : controller.ToString();

        if (!string.IsNullOrEmpty(controllerString))
        {
            name = controllerString;

            if (routeValues.TryGetValue("action", out var action) && action != null)
            {
                // ReSharper disable once RedundantToStringCall
                name += "/" + action.ToString();
            }

            if (routeValues.Keys.Count > 2)
            {
                var sortedKeys = routeValues.Keys
                    .Where(
                        key => !string.Equals(key, "controller", StringComparison.OrdinalIgnoreCase)
                            && !string.Equals(key, "action", StringComparison.OrdinalIgnoreCase)
                            && !string.Equals(key, "!__route_group", StringComparison.OrdinalIgnoreCase))
                    .OrderBy(key => key, StringComparer.OrdinalIgnoreCase)
                    .ToArray();

                if (sortedKeys.Length > 0)
                {
                    var arguments = string.Join('/', sortedKeys);
                    name += " [" + arguments + "]";
                }
            }
        }
        else
        {
            routeValues.TryGetValue("page", out var page);
            var pageString = (page is null) ? string.Empty : page.ToString();
            if (!string.IsNullOrEmpty(pageString))
            {
                name = pageString;
            }
        }

        return name;
    }
}

@tbasallo
Copy link

I've also used a similar method but as a TelemetryInitializer - yours seems more robust. I found this chasing down 404 errors that show up under /Error from the status code handler.

This really needs an official solution - shouldn't be this difficult for a premium product

@oferns
Copy link

oferns commented Oct 16, 2024

There is a simpler way to do this. Add this static function to your Error controller (assumes you are injecting the HttpContextAccessor into the Error controller) and then call it as the first line of your Error controller action


        public Task<ProblemDetails> Index([FromRoute] int? sc, CancellationToken cancel)
        {
            SetTelemetry(contextAccessor.HttpContext);
        // Rest of your error handling code
        }


`

    private static void SetTelemetry(HttpContext? httpContext) {

        if (httpContext is null) { return; }

        var requestTel = httpContext.Features.Get<RequestTelemetry>();
        var originalRequest = httpContext.Features.Get<IHttpRequestFeature>();
        var exceptionFeature = httpContext.Features.Get<IExceptionHandlerFeature>();


        if (requestTel is not null && originalRequest is not null) {
            requestTel.Name = $"{originalRequest.Method} {exceptionFeature?.Path ?? originalRequest.Path}";
        } 
    }

`

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

No branches or pull requests

4 participants