logging-log4j-user mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Jacob Kjome <h...@visi.com>
Subject Re: Context Based Repository Selectors and MDC
Date Sat, 06 Nov 2004 05:31:48 GMT
At 10:49 AM 11/5/2004 -0600, you wrote:
 >That's correct Jake, the 2 apps are logging to separate files successfully.
 >

Good, I figured as much, but just wanted to make sure.

 >After re-reading Chapter 7 on Mapped Diagnostic Contexts in Ceki's book
 >and running through the debugger I may have an answer.  (Please let me
 >know if anything seems screwy here.  I'm using Tomcat 5.0.18.)
 >
 >I used a debugger to put a breakpoint in the MDC put0(String key, Object
 >o) method.  When I executed the following:
 >
 >webapp1
 >-------
 >MDC.put("AppName", "foo");
 >logger.info("app1 here");
 >
 >The debugger showed:
 >
 >1) Thread [http80-Processor24]
 >2) MDC (id=113)
 >3) Hashtable (id=234)
 >contents of Hashtable={AppName=foo}
 >
 >I resumed running the thread until completion.  I then ran:
 >
 >webapp2
 >-------
 >MDC.put("AppName", "bar");
 >logger.info("app1 here");
 >
 >Coincidentally, app2 used the very same thread as app1.  The debugger
 >showed:
 >
 >1) Thread [http80-Processor24]
 >2) MDC (id=113)
 >3) Hashtable (id=234)
 >contents of Hashtable={AppName=foo}<<< 'stale value' from previous 'put'
 >
 >The breakpoint was before 'ht.put(key, o);' so I could see the values
 >from app1 were still in the Hashtable.
 >
 >Here is my simple explanation for what happened.  Since the Hashtable is
 >based on the ThreadLocalMap and the thread was the same between app1 and
 >app2 both apps were using the same Hashtable.  I did not perform any MDC
 >'remove' operations so the app1 values were still present.
 >
 >If my explanation is correct, forgetting to put a 'remove' in a finally
 >block could screw up the logging in an unrelated app or even in the same
 >app.  Is this correct?
 >
 >What do you think?
 >

Yes, definitely if they were the same thread.  It seems really weird to me 
that you'd get the same thread, though.  I suppose Tomcat could be pooling 
threads, but consistently having the same thread for separate requests to 
separate applications doesn't seem quite right.  I'm sure I'm missing 
something obvious.

Yoav, you're a Tomcat expert.  Any insights you can share?

Jake

 >
 >Jacob Kjome wrote:
 >
 >> At 05:07 PM 11/4/2004 -0600, you wrote:
 >>  >Thanks Jacob, I did as you suggested and checked out the
 >>  >ContextClassLoaderSelector from LOG4J_SANDBOX_ALPHA3.  I'm calling this
 >>  >class from the initLoggerRepository() method in InitContextListener
 >> like so:
 >>  >
 >>  >//ContextClassLoaderSelector.doIdempotentInitialization();
 >>  >try {
 >>  >       Object guard = new Object();
 >>  >       LogManager.setRepositorySelector(new ContextJNDISelector(),
 >> guard);
 >>  >} catch (IllegalArgumentException iae) {
 >>  >       LogLog.debug("Attempted to reset the LoggerFactory without
 >> possessing
 >>  >the guard.");
 >>  >}
 >>  >
 >>  >I'm still getting the same behavior as before, app2 is overwriting
 >>  >values in the MDC that app1 put there.
 >>  >
 >>
 >> Just to be clear, you are saying that each app's normal logging is
 >> properly separated, but the MDC is not, correct?  I haven't looked much
 >> into how the MDC works.  If what you say is correct, MDC seems global to
 >> Log4j rather than being pegged to a LoggerRepository.
 >>
 >>  >I'm brand new to the classloading experience, but shouldn't we expect
 >>  >this behavior since the MDC is loaded by Tomcat's standard classloader?
 >>  >
 >>
 >> It depends if MDC should be associated with a LoggerRepository or if it
 >> is global to Log4j.  Can anyone else answer this question more
 >> definitively for Ted?
 >>
 >>
 >> Jake
 >>
 >>
 >>  >Jacob Kjome wrote:
 >>  >
 >>  >> At 05:14 PM 11/1/2004 -0600, you wrote:
 >>  >>  >I used Jacob Kjome's InitContextListener and
 >> ContextClassLoaderSelector
 >>  >>  >classes to separate the logging for 2 test web apps that I'm writing.
 >>  >>
 >>  >> First, you should be using the ContextJNDISelector rather than the
 >>  >> ContextClassLoaderSelector.  The latter is problematic as behavior can
 >>  >> change as classloader behavior changes.
 >>  >>
 >>  >> Second, which version of log4j-sandbox are you using?  By that I mean,
 >>  >> did you check out the tagged (unofficial) release of
 >>  >> LOG4J_SANDBOX_ALPHA2 or LOG4J_SANDBOX_ALPHA3?  If the latter, this may
 >>  >> very well not work well with the ContextClassLoaderSelector because of
 >>  >> some classloading stuff I did to avoid class cast exceptions in certain
 >>  >> cases (case in point of behavior changing as classloading changes).  If
 >>  >> you checked out the HEAD, you've probably noticed that
 >>  >> ContextJNDISelector is in the Attic (if you found it at all).  This is
 >>  >> because Ceki moved it to log4j proper (and made many changes
 >> specific to
 >>  >> log4j-1.3).  I suggest you check out LOG4J_SANDBOX_ALPHA3 which will
 >>  >> include ContextJNDISelector (compatible with Log4j-1.2.x) and use it
 >>  >> instead of ContextClassLoaderSelector.
 >>  >>
 >>  >>  >
 >>  >>  >I put the log4j-1.2.8.jar in C:\Program Files\Apache Software
 >>  >>  >Foundation\Tomcat 5.0\shared\lib and coded something like the
 >> following:
 >>  >>  >
 >>  >>  >webapp1
 >>  >>  >-------
 >>  >>  >MDC.put("AppName", "foo");
 >>  >>  >logger.info("app1 here");
 >>  >>  >
 >>  >>  >webapp2
 >>  >>  >-------
 >>  >>  >MDC.put("AppName", "bar");
 >>  >>  >logger.info("app2 here");
 >>  >>  >
 >>  >>  >The FileAppenders I'm using are writing to the correct log files
 >> but the
 >>  >>  >values in the MDC for app1 appear to overwritten by values from app2.
 >>  >>  >In the debugger it appears that the same MDC object and its
 >> members are
 >>  >>  >referenced by both webapps, thus explaining the overwriting part.
 >>  >>  >
 >>  >>  >Can I put the log4j-1.2.8.jar in the shared/lib or common/lib and
 >> still
 >>  >>  >use the MDC in this fashion?
 >>  >>  >
 >>  >>
 >>  >> I'm not positive how this might affect things, but please do as I
 >>  >> suggest above and use ContextJNDISelector.  If that doesn't work any
 >>  >> better, then post a follow-up here and we'll have a look at other
 >>  >> solutions.
 >>  >>
 >>  >> Jake
 >>  >>
 >>  >> ---------------------------------------------------------------------
 >>  >> To unsubscribe, e-mail: log4j-user-unsubscribe@logging.apache.org
 >>  >> For additional commands, e-mail: log4j-user-help@logging.apache.org
 >>  >>
 >>  >>
 >>  >
 >>  >---------------------------------------------------------------------
 >>  >To unsubscribe, e-mail: log4j-user-unsubscribe@logging.apache.org
 >>  >For additional commands, e-mail: log4j-user-help@logging.apache.org
 >>  >
 >>  >
 >>
 >> ---------------------------------------------------------------------
 >> To unsubscribe, e-mail: log4j-user-unsubscribe@logging.apache.org
 >> For additional commands, e-mail: log4j-user-help@logging.apache.org
 >>
 >>
 >
 >---------------------------------------------------------------------
 >To unsubscribe, e-mail: log4j-user-unsubscribe@logging.apache.org
 >For additional commands, e-mail: log4j-user-help@logging.apache.org
 >
 >  


---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-user-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-user-help@logging.apache.org


Mime
View raw message