logging-log4j-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Remko Popma (JIRA)" <j...@apache.org>
Subject [jira] [Comment Edited] (LOG4J2-705) Async logger loses thread context stack for events
Date Sat, 12 Jul 2014 11:17:04 GMT

    [ https://issues.apache.org/jira/browse/LOG4J2-705?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=14059745#comment-14059745
] 

Remko Popma edited comment on LOG4J2-705 at 7/12/14 11:16 AM:
--------------------------------------------------------------

I'm surprised this has not been found earlier. This problem has been there from the start...

The objective of both {{DefaultThreadContextStack}} and {{DefaultThreadContextMap}} is to
be a copy-on-write implementation, the reasoning being that modifications to the map/stack
will be rare, and this will allow us to avoid copying the stack/map for every single log event.
Each log event is given a stack/map instance obtained with a call to {{ThreadContext.getImmutableStack()}}
and {{ThreadContext.getImmutableMap()}}.

For the map, this method returns the internal immutable map. This is safe because with every
modification that map will be replaced with another instance. With the stack we were also
returning the internal representation, but as you pointed out, the {{DefaultThreadContextStack}}
implementation stores the data in a thread-local variable, so instances of this class are
not suitable for passing to another thread because that other thread will not be able to access
the data. 

The solution is to do something similar as we are doing with the map. The thread-local variable
should keep an immutable stack instance that can safely be handed off to other threads. Every
time the stack is modified, a new stack instance will be created and stored in the thread-local
variable.

This requires an API change: we need to add a method {{ThreadContextStack.getImmutableStackOrNull()}},
analogous to the existing {{ThreadContextMap.getImmutableMapOrNull()}} method.

I doubt many users have custom {{ThreadContextStack}} implementations, so I doubt this API
change will impact many users (if anyone at all).


was (Author: remkop@yahoo.com):
I'm surprised this has not been found earlier. This problem has been there from the start...

The objective of both {{DefaultThreadContextStack}} and {{DefaultThreadContextMap}} is to
be a copy-on-write implementation, the reasoning being that modifications to the map/stack
will be rare, and this will allow us to avoid copying the stack/map for every single log event.
Each log event is given a stack/map instance obtained with a call to {{ThreadContext.getImmutableStack()}}
and {{ThreadContext.getImmutableMap()}}.

For the map, this method returns the internal immutable map. This is safe because with every
modification that map will be replaced with another instance. With the stack we were also
returning the internal representation, but as you pointed out, the {{DefaultThreadContextStack}}
implementation stores the data in a thread-local variable, so instances of this class are
not suitable for passing to another thread because that other thread will not be able to access
the data. 

The solution is to do something similar as we are doing with the map. The thread-local variable
keeps an immutable stack instance that can safely be handed off to other threads. Every time
the stack is modified, a new stack instance is created and stored in the thread-local variable.

This requires an API change: we need to add a method {{ThreadContextStack.getImmutableStackOrNull()}},
analogous to the existing {{ThreadContextMap.getImmutableMapOrNull()}} method.

I doubt many users have custom {{ThreadContextStack}} implementations, so I doubt this API
change will impact many users (if anyone at all).

> Async logger loses thread context stack for events
> --------------------------------------------------
>
>                 Key: LOG4J2-705
>                 URL: https://issues.apache.org/jira/browse/LOG4J2-705
>             Project: Log4j 2
>          Issue Type: Bug
>          Components: Core
>    Affects Versions: 2.0-rc2
>            Reporter: Martin Frydl
>            Assignee: Remko Popma
>         Attachments: async-context-test.zip
>
>
> I've enabled the async logger and created some log message with values in thread context
stack. However, the logged message does not contain any of these items.
> Looking at the sources, it seems that AsyncLogger.logMessage() needs to clone the stack
instead of using ThreadContext.getImmutableStack() (line 260). This is because getImmutableStack()
method returns the same stack as original - getting the real one from thread local storage.
So when passed to another thread (as async does), the same stack "looks" into different thread
and returns empty list. It is even possible to break this "immutable" stack when you create
your own appender and use ThreadContext.push() in append() method. This will affect the message
being logged.
> Simple solution is to replace getImmutableStack() method in AsyncLogger.logMessage()
(line 260) with ThreadContext.cloneStack(). But I'm not sure if this is the right way.



--
This message was sent by Atlassian JIRA
(v6.2#6252)

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


Mime
View raw message