2

I've written a custom HttpModule that implements the Application_PreRequestHandlerExecute and Application_PostRequestHandlerExecute events in order to log all request times. I'm trying to instrument an MVC web application with this HttpModule to log the performance of all requests into it. The MVC web application uses Http Session with the timeout set to the default 20 minutes. We have a suite of JMeter load tests that, prior to my HttpModule, were running fine. However, when I instrument the application, after 20 minutes of JMeter running its tests, it starts throwing errors all over the place that indicate that all the session variables have been dropped.

Why is this happening? I'm not accessing session state at all in my HttpModule, so I'm at a loss for what might be causing this. Here's the full code for the custom HttpModule. It seems that the mere presence of this HttpModule is causing session timeout problems for any apps configured to use it.

public class LoggerModule : IHttpModule
{
    public void Dispose()
    {
    }

    public void Init(HttpApplication context)
    {
        if (context == null)
        {
            return;
        }

        // Using PreRequestHandlerExecute/PostRequestHandlerExecute instead of BeginRequest/EndRequest
        // from: http://stackoverflow.com/questions/12981298/how-to-analyze-the-performance-of-requests-in-asp-net-mvc-application
        // NOTE: The Web.config for each application should be configured with preCondition="managedHandler".  See
        // http://stackoverflow.com/questions/18989449/how-does-precondition-managedhandler-work-for-modules.
        // TL;DR is that this HttpModule will only run for managed resources like MVC endpoints, .aspx requests, etc. and won't run for static files.
        context.PreRequestHandlerExecute += this.Application_PreRequestHandlerExecute;
        context.PostRequestHandlerExecute += this.Application_PostRequestHandlerExecute;
    }

    private void Application_PreRequestHandlerExecute(object sender, EventArgs e)
    {
        // Store the current time in order to determine the time taken to process each request.
        (sender as HttpApplication).Context.Items["PerformanceLoggerStart"] = DateTime.Now;
    }

    private void Application_PostRequestHandlerExecute(object sender, EventArgs e)
    {
        HttpContext context = (sender as HttpApplication).Context;

        if (context == null)
        {
            return;
        }

        // Calculate the time taken to process the request
        DateTime start = (DateTime)context.Items["PerformanceLoggerStart"];
        double millisecondsTaken = (DateTime.Now - start).TotalMilliseconds;

        // Asynchronously log performance.  Note that this also insulates the profiled application from any exceptions that may be thrown by the task being done.
        Task.Run(() => Logger.LogPerformance(new LogEntry
        {
            // Get the full URL as it appears in the browser MINUS any MVC route-specific parameter like a GUID
            Endpoint = ApplicationInformation.TrimIdFromMVCRoute(context.Request.Url),

            // GET, POST, etc.
            Action = context.Request.HttpMethod,

            // Name of the machine executing this code
            MachineName = Environment.MachineName,

            // Get the application name from the URL - depends on whether running locally or remotely
            ApplicationName = ApplicationInformation.GetApplicationName(context.Request.Url, context.Request.ApplicationPath),

            // Time taken to process the request
            MillisecondsTaken = millisecondsTaken
        }));
    }
}
Andy
  • 2,709
  • 5
  • 37
  • 64
  • 2
    I'm guessing that `Logger.LogPerformance` is throwing an unhandled exception. That exception isn't propagated back to the calling thread unless `Task.Wait` is called or the result of `Task.Run` is examined. Have you tried calling `Logger.LogPerformance` directly (i.e. without wrapping it in `Task.Run`)? – Chris R. Timmons Jun 02 '16 at 15:59
  • Thanks Chris - the Task.Run was the culprit - it wasn't actually throwing an exception, but simply having the Task.Run present means that HttpContext. is not accessible. If you want to add an answer, I'll give you the points. – Andy Jun 02 '16 at 17:54
  • Thanks, but it was just a wild guess on my part. Glad you solved the problem. – Chris R. Timmons Jun 02 '16 at 18:26

0 Answers0