Sunday, December 04, 2005

Bug: IE doesn't resolve URIs to behaviors correctly

URI's in stylesheets are resolved relative to the stylesheet, not relative to the page that loaded the stylesheet.

It's the only way that makes any sense. Take images for example:
/* this is somestyles.css */

If you resolved the path to background.gif from the page, rather than from somestyles.css then every page would have to sit at the same level as the images directory, which precludes having a site heirachy.

Fortunately this is not how the world works - URIs are resolved based on the base URI of the stylesheet, and everyone's happy...

...except IE (6, but presumably 5+) doesn't do this for DHTML behaviours - the path to the HTC is resolved based on the page that the behaviour applies to. WTF!?

That I never noticed this before is a testament to how little I've ever used DHTML behaviours (I regard them as some kind of voodoo), but that there's been no public outcry presumably means no-one else is either. Or did I miss some kind of wierd DOCTYPE setting to force IE into 'not crap' mode?

(Sure you can make the path root-relative, ie
...but imagine if you're writing an app in a subdirectory (which is the normal VS.Net paradime):
'MyApp' might be the name you use in development, but it might be MyAppDaily for the dailybuild, and it might be just / (as in, run at the root of the site) when you eventually deploy. Want to keep changing your CSS per-environment? I don't think so)

The documentation - not very explicit on how it's expected to work
Other people who have noticed: 'Keith' (comment 15), Dean Edwards, 'Lithium' on microsoft.public.scripting.jscript, but unless my Google-fu is failing there's not many of them.

log4net Context problems with ASP.Net thread agility

Even after my recent revalations about how ASP.Net's agile threading model precudes storing things in threadslots, ThreadStatic's or CallContext almost without exception[1], it still took me until just the other day to realize an important ramification of that:
log4net contexts are broken[2] under ASP.Net
A log4net context is a bag where you can put data that can be referenced by the log4net appenders when the logging calls are rendered. This supports the model where you just publish logging data that's relevant to your immediate scope, and the log4net renderer (based on the pattern you put in your config) just appends all the extra data that you probably want to log (like the CustomerID who's logged in or somesuch).

There are three log4net contexts: GlobalContext, ThreadContext and LogicalThreadContext, which do pretty much what you'd expect - provide places to hang contextual data for logging calls that's either global, thread-local or 'logical call' local (ie propagates across remoting calls). Unfortunately that's just not good enough in an ASP.Net environment, since we now know that neither CallContext nor Thread Local Storage slots get propagated onto the new thread when ASP.Net does a thread switch. Since that's where the ThreadContext and LogicalThreadContext are actually stored, ASP.Net's thread switch either blows away your context (in the case of LogicalThreadContext), or overwrites it (in the case of ThreadContext).

There's nothing fundamentally wrong with log4net, it's just you can't use log4net's ThreadContext or LogicalThreadContext within ASP.Net and expect to get a per-request logging context, though you'd be forgiven for imagining otherwise.

Demo: Storing the requested page URL in ThreadContext, so it's liable to be overwritten if a thread switch happens because two requests come in concurrently:
[3164] INFO  ASP.global_asax /ASPNetThreadingDemo/SlowPage.aspx - Begin request for /ASPNetThreadingDemo/SlowPage.aspx
[3164] INFO  ASP.global_asax /ASPNetThreadingDemo/SlowPage.aspx - End request for /ASPNetThreadingDemo/SlowPage.aspx
[1996] INFO  ASP.global_asax /ASPNetThreadingDemo/SlowPage.aspx - Begin request for /ASPNetThreadingDemo/SlowPage.aspx
[3164] INFO  ASP.global_asax /ASPNetThreadingDemo/FastPage.aspx - Begin request for /ASPNetThreadingDemo/FastPage.aspx
[1996] INFO  ASP.global_asax /ASPNetThreadingDemo/SlowPage.aspx - End request for /ASPNetThreadingDemo/SlowPage.aspx
[1996] INFO  ASP.global_asax /ASPNetThreadingDemo/SlowPage.aspx - End request for /ASPNetThreadingDemo/FastPage.aspx

See how the last logging call has 'SlowPage' in context, even though the request that's finishing is actually for 'FastPage' (I was expecting exactly the reverse, but hey).

It's pretty ironic really, since it was log4net I used to confirm how the threading really worked in the first place, but of all the things I looked at, log4net contexts wasn't one of them. Trouble is, if you're using log4net contexts in ASP.Net this is exactly the kind of thing you'd[3] be doing: setting things up in BeginRequest so they're there for all logging calls throughout the system.

The Workaround:
Fortunately log4net's so flexible that it already contains the solution. For all the contexts, log4net supports the concept of delayed resolution of the context value. To be more specific, log4net gets the context value by calling ToString() on the contents of the context bags when they're frozen and attached to a logging call. If rather than adding the actual value, you add an object who's ToString() provides the value, then you've deferred resolution of what the actual value was.

So in this case, rather adding the value of CustomerID directly into the ThreadContext, you'd add a CustomerIdProvider object instead:
Public Class CustomerIdProvider
 Public Overrides Function ToString() As String
     Return HttpContext.Current.Items("CustomerId")
 End Function
End Class
Since this now leverages HttpContext, you can put it in GlobalContext as well - it's automatically thread-safe.

It's a bit of a drag, but you're going to have to do this for all your non-global log4net context data[4]. It's pretty easy to generalise the class above into an all-purpose HttpContextValueProvider though, so you won't have to spawn a myriad of classes.

The Solution:

log4net's going to have to have an AdaptiveContext. This is a context bag that's stored either in CallContext or in HttpContext, depending on the environment that the application is running within. I'm already doing this for anything I previously put in CallContext in my business layer, but I haven't got round to grafting one onto log4net yet.

[Update: I posted a follow-up post about the need to also implement IFixingRequired - please read. Also, please note the date on this post is 2005, I don't claim this as all current information. YMMV]

[1] Ok, if you don't store anything in TLS / CallContext prior to Page.Init, then you'll be ok (given the current implementation anyway).
[2] ...depending on how you're using them
[3] I.E. 'me, until I realised all this'
[4] Despite all this, log4net's still the best logging framework I know of by far.

Popular Posts