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

Correlation is lost in chained async HttpModule handlers #75

Open
regexrowboat opened this issue Jul 1, 2020 · 1 comment
Open

Correlation is lost in chained async HttpModule handlers #75

regexrowboat opened this issue Jul 1, 2020 · 1 comment

Comments

@regexrowboat
Copy link

regexrowboat commented Jul 1, 2020

I've found an issue with using async handlers in IHttpModule that causes correlation (Activity.Current) to be completely lost in any handlers that are called after the async handler has been called.

The issue seems to be caused by the legacy Asynchronous Programming Model (APM) that Http Modules use, which doesn't seem to propagate ExecutionContext.

It only occurs with async handlers. Synchronous handlers, even when using the APM model propagate ExecutionContext and Activity.Current correctly.

This is an example module that reproduces the problem. To run it, just add this HttpModule to any empty .NET application with the Application Insights Web SDK installed, then send requests to it and watch the Debug output.

When I run this, it produces the following:

DependencyTrackingHandler Activity: System.Diagnostics.Activity
DependencyTrackingHandler Activity:

I would expect that the second log entry would also have a valid System.Diagnostics.Activity, but it's null. If you replace the postAuthenticate handler with a synchronous method, then the Activity is propagated down to the postAuthorize handler as expected, so it appears to only be an issue with async handler chains.

The unfortunate result of Activity being wiped is that any dependency calls I make in the second handler don't have any correlation context, no operation_ParentId and different operation_Id values for each dependency.

<system.webServer>
    <modules>
      <remove name="TelemetryCorrelationHttpModule" />
      <add name="TelemetryCorrelationHttpModule" type="Microsoft.AspNet.TelemetryCorrelation.TelemetryCorrelationHttpModule, Microsoft.AspNet.TelemetryCorrelation" preCondition="managedHandler" />
      <remove name="ApplicationInsightsWebTracking" />
      <add name="ApplicationInsightsWebTracking" type="Microsoft.ApplicationInsights.Web.ApplicationInsightsHttpModule, Microsoft.AI.Web" preCondition="managedHandler" />
      <add name="HttpTrackingModule" type="AspNetWithoutMvc.HttpTrackingModule, AspNetWithoutMvc, Culture=neutral" />
    </modules>
</system.webServer>
public class HttpTrackingModule : IHttpModule
    {
        public void Dispose()
        {
        }

        public void Init(HttpApplication context)
        {
            EventHandlerTaskAsyncHelper sync = new EventHandlerTaskAsyncHelper(this.HandleEvent(this.SyncTest()));

            context.AddOnAuthenticateRequestAsync(sync.BeginEventHandler, sync.EndEventHandler);

            EventHandlerTaskAsyncHelper postAuthenticate = new EventHandlerTaskAsyncHelper(this.HandleEvent(this.Track(false)));

            context.AddOnPostAuthenticateRequestAsync(postAuthenticate.BeginEventHandler, postAuthenticate.EndEventHandler);

            EventHandlerTaskAsyncHelper postAuthorize = new EventHandlerTaskAsyncHelper(this.HandleEvent(this.Track(true)));

            context.AddOnPostAuthorizeRequestAsync(postAuthorize.BeginEventHandler, postAuthorize.EndEventHandler);
        }

        private Func<HttpApplication, Task> SyncTest()
        {
            return (HttpApplication) =>
            {
                return Task.CompletedTask;
            };
        }

        private Func<HttpApplication, Task> Track(bool shouldComplete)
        {
            return async (HttpApplication context) =>
            {
                Debug.Print("DependencyTrackingHandler Activity: " + Activity.Current);

                List<Task<HttpResponseMessage>> tasks = Enumerable.Range(0, 1).Select(i => new HttpClient().GetAsync("https://bing.com")).ToList();

                await Task.WhenAll(tasks);

                if (shouldComplete)
                {
                    context.Response.StatusCode = 200;
                    context.CompleteRequest();
                }
            };
        }

        private TaskEventHandler HandleEvent(Func<HttpApplication, Task> handler)
        {
            return async (object sender, EventArgs e) =>
            {
                try
                {
                    HttpApplication context = sender as HttpApplication;

                    await handler(context);
                }
                catch (Exception ex)
                {
                    Console.WriteLine(ex.Message);
                }
            };
        }
    }
@akhilesh84
Copy link

akhilesh84 commented Sep 2, 2022

I wonder why there isn't any comment on this thread in more than 2 years. I guess I have run into a similar problem. The only difference is that my own module (which has async handlers) comes before the TelemetryHttpModule. Any activity that gets created in my custom module does not get propagated to the Telemetry module.

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

No branches or pull requests

2 participants