A strange tale of HttpApplication.AuthenticateRequest and Trace
You know how sometimes you think you're pretty sure you know what the sum total of your database shenanigans are in any given ASP.NET page, but you want to make sure? Well, under load it's hard to do a SQL trace and really see what the hell is going on. Because I have all the SQLness funneling through a handful of helper methods in POP Forums (which is so close to a public beta that I can smell it), I figured it'd be easy enough to output the various calls to the Trace in ASP.NET, along with some execution times. Easy it was.
But there was one piece of weirdness I couldn't understand. The database call to update user session data, fired from an HttpModule's AuthenticateRequest event, seemed to be firing three times, every page. My first clue that something was strange should have been that the execution times were exactly the same, for all three entries in the Trace output.
Still, I stepped through the code first, putting a conditional breakpoint to make sure I was only tracking the page request and not the CSS and graphics (since the runtime serves all of the above on the local dev server app). Yep, just one call. Then I did fire up the SQL trace, and sure enough, just one call to the database. But when I looked at the ASP.NET page trace (via trace.axd), the call appeared three times.
The bottom line is that the database call isn't being made in triplicate, even if it is appearing in Trace three times. Still, I'd love to know what's going on in the interaction between the ASP.NET Trace and the HttpModule. I'd even like to step into the framework code, but so far, I have no idea how to do that, even though I think I have it enabled. I'd really like to just browse the framework code, but I still don't know how or if that's possible. It's a useless feature, frankly, if I can't make it work.