You are viewing a plain text version of this content. The canonical link for it is here.
Posted to log4j-dev@logging.apache.org by bu...@apache.org on 2011/08/04 11:03:15 UTC

DO NOT REPLY [Bug 51612] New: LoggingEvent can contain wrong thread name in multithreaded environment

https://issues.apache.org/bugzilla/show_bug.cgi?id=51612

             Bug #: 51612
           Summary: LoggingEvent can contain wrong thread name in
                    multithreaded environment
           Product: Log4j
           Version: 1.2
          Platform: PC
            Status: NEW
          Severity: normal
          Priority: P2
         Component: Other
        AssignedTo: log4j-dev@logging.apache.org
        ReportedBy: r_gorbonosov@mail.ru
    Classification: Unclassified


Created attachment 27347
  --> https://issues.apache.org/bugzilla/attachment.cgi?id=27347
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.

-- 
Configure bugmail: https://issues.apache.org/bugzilla/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug.

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

DO NOT REPLY [Bug 51612] LoggingEvent can contain wrong thread name in multithreaded environment

Posted by bu...@apache.org.
https://issues.apache.org/bugzilla/show_bug.cgi?id=51612

RJoker <r_...@mail.ru> changed:

           What    |Removed                     |Added
----------------------------------------------------------------------------
                 CC|                            |r_gorbonosov@mail.ru
         OS/Version|                            |All

-- 
Configure bugmail: https://issues.apache.org/bugzilla/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug.

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

DO NOT REPLY [Bug 51612] LoggingEvent can contain wrong thread name in multithreaded environment

Posted by bu...@apache.org.
https://issues.apache.org/bugzilla/show_bug.cgi?id=51612

--- Comment #2 from RJoker <r_...@mail.ru> 2011-08-11 14:48:21 UTC ---
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?

-- 
Configure bugmail: https://issues.apache.org/bugzilla/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug.

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

DO NOT REPLY [Bug 51612] LoggingEvent can contain wrong thread name in multithreaded environment

Posted by bu...@apache.org.
https://issues.apache.org/bugzilla/show_bug.cgi?id=51612

Curt Arnold <ca...@apache.org> changed:

           What    |Removed                     |Added
----------------------------------------------------------------------------
             Status|NEW                         |RESOLVED
         Resolution|                            |WONTFIX

--- Comment #1 from Curt Arnold <ca...@apache.org> 2011-08-08 03:18:17 UTC ---
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();

-- 
Configure bugmail: https://issues.apache.org/bugzilla/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug.

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