Created attachment 27347 [details] Simple code demonstrating the bug Log4j version: 1.2.16 I have an appender attached to a logger. This appender performs the LoggingEvent processing in a thread other than the thread where the LoggingEvents were generated. Due to that fact that LoggingEvent.threadName is lazily initialized (under certain conditions: there are different constructors and I don't know which one is used when) I'm getting a wrong thread name in the LoggingEvent. Probably the LoggingEvent.threadName should not be lazily initialized. In attachment there is a simple code demonstrating the bug. In addition please pay attention that LoggingEvent class is not thread-safe: access to LoggingEvent.threadName is not synchronized. So if in the example above I have several appenders processing LoggingEvents in different threads the actual thread name visible to appenders is unpredictable.
The code is behaving as designed, though it was designed for a far earlier era. Designing for concurrency is one of the prime motivations for the log4j 2 effort. Improving concurrency in log4j 1.x is a minefield with ample opportunity for unintended consequences. There are (at least were) substantial performance benefits to avoid copying thread state information into the logging event. The following fragment of AsyncAppender shows how it forces the retrieval of state information so that the logging event has a fixed state before it is made visible to other threads. event.getNDC(); event.getThreadName(); // Get a copy of this thread's MDC. event.getMDCCopy(); if (locationInfo) { event.getLocationInformation(); } event.getRenderedMessage(); event.getThrowableStrRep();
Thanks for the answer, Curt. Just to make sure the solution which is used in AsyncAppender is bullet-proof. As I mentioned, LoggingEvent.threadName is not volatile and access to it is not synchronized. So, where is the guarantee that after being initialized in one thread (with event.getThreadName()) it is visible to other threads as well (dispatcher in case of AsyncAppender)? Does the guarantee come from the piggybacking on synchronization on buffer?