logging-log4j-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Gary Gregory <garydgreg...@gmail.com>
Subject Re: Log4j2 RollingFileAppender deadlock issue
Date Sun, 05 Jul 2015 17:28:34 GMT
Clever patch! I commented in the Jira.

Gary

On Sun, Jul 5, 2015 at 8:00 AM, Remko Popma <remko.popma@gmail.com> wrote:

> Attached a patch to LOG4J2-812
> <https://issues.apache.org/jira/browse/LOG4J2-812> that demonstrates how
> to replace the synchronized block in DatePatternConverter with a
> SoftThreadLocal. Tests all pass. Feedback welcome.
>
> On Sun, Jul 5, 2015 at 5:08 PM, Remko Popma <remko.popma@gmail.com> wrote:
>
>> Benchmark done
>> <https://issues.apache.org/jira/browse/LOG4J2-812?focusedCommentId=14614174&page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel#comment-14614174>,
>> and ThreadLocal is a clear winner over synchronized block.
>>
>> I've started implementing a ThreadLocal registry but I stopped when I
>> realized this won't solve the memory leak problem: ThreadLocal.remove()
>> only removes the value for the current thread. Values created for other
>> threads in the thread pool will not be removed...
>>
>> Instead, I propose we create a SoftThreadLocal class which wraps the
>> value (the SimpleDateFormat in this case) in a SoftReference before storing
>> it in the ThreadLocal. This allows the JVM to reclaim the memory when
>> necessary, which should solve the memory leak. It also means we no longer
>> need to explicitly clear() things when the LoggerContext is stopped.
>>
>> This is also a reusable solution because we can use this class everywhere
>> we use ThreadLocal to cache objects for performance.
>>
>> Thoughts?
>>
>> On Sun, Jul 5, 2015 at 3:33 PM, Ralph Goers <ralph.goers@dslextreme.com>
>> wrote:
>>
>>> That’s right, you were going to do some performance measurements. Please
>>> do and let us know what works best.
>>>
>>> Ralph
>>>
>>> On Jul 4, 2015, at 10:30 PM, Remko Popma <remko.popma@gmail.com> wrote:
>>>
>>> Looks like we already have an outstanding Jira for this: LOG4J2-812
>>> <https://issues.apache.org/jira/browse/LOG4J2-812>.
>>> If there are no objections I can take care of this one.
>>>
>>> On Sun, Jul 5, 2015 at 9:55 AM, Remko Popma <remko.popma@gmail.com>
>>> wrote:
>>>
>>>> One per logger context would make it easier to clear all ThreadContexts
>>>> when a particular logger context is stopped.
>>>>
>>>> Sent from my iPhone
>>>>
>>>> On 2015/07/05, at 0:51, Gary Gregory <garydgregory@gmail.com> wrote:
>>>>
>>>> Would there be one registry or one per logger context?
>>>>
>>>> Gary
>>>>
>>>>
>>>> -------- Original message --------
>>>> From: Remko Popma <remko.popma@gmail.com>
>>>> Date: 07/04/2015 05:41 (GMT-08:00)
>>>> To: Log4J Developers List <log4j-dev@logging.apache.org>
>>>> Subject: Re: Log4j2 RollingFileAppender deadlock issue
>>>>
>>>> ThreadLocal is implemented as an internal Map in each Thread instance,
>>>> so there is constant lookup time regardless of the number of Threads and
>>>> the number of lookups. Contrast this with a lock, where performance will
>>>> decrease exponentially with more concurrent threads.
>>>>
>>>> (See also https://plumbr.eu/blog/java/how-is-threadlocal-implemented )
>>>>
>>>> Sent from my iPhone
>>>>
>>>> On 2015/07/04, at 20:40, Jess Holle <jessh@ptc.com> wrote:
>>>>
>>>> On 7/4/2015 2:51 AM, Gary Gregory wrote:
>>>>
>>>>  On Thu, Jul 2, 2015 at 6:18 AM, Remko Popma <remko.popma@gmail.com>
>>>> wrote:
>>>>
>>>>>  Yes, that could still work: We could use a ThreadLocal containing a
>>>>> custom class which holds the lastTimestamp, cachedDateString as well
as a
>>>>> SimpleDateFormat instance.
>>>>>
>>>>>  As Jess pointed out, we would also need a way to clear the
>>>>> ThreadLocal when the LoggerContext is stopped (to prevent memory leaks
in
>>>>> web apps). This may be the third usage of ThreadLocals in log4j2 now,
so it
>>>>> may be worth creating a reusable mechanism for this.
>>>>> One idea would be to have a ThreadLocal registry in the LoggerContext,
>>>>> where the LoggerContext is responsible for cleaning up all registered
>>>>> ThreadLocals in its stop() method.
>>>>>
>>>>>  Thoughts?
>>>>>
>>>>
>>>>  I'm wondering what the performance cost are of doing a
>>>> ThreadLocal.get() vs. synchronized(this) on each call to format().
>>>>
>>>>   Personally I'd be less concerned with optimizing maximum logger
>>>> throughput on any given thread than:
>>>>
>>>>    1. Ensuring that *not* logging takes minimal time
>>>>    2. Minimizing potential thread contention
>>>>
>>>> Logging at maximum efficiency is a priority, but comes after these
>>>> others.
>>>>
>>>> --
>>>> Jess Holle
>>>>
>>>>
>>>
>>>
>>
>


-- 
E-Mail: garydgregory@gmail.com | ggregory@apache.org
Java Persistence with Hibernate, Second Edition
<http://www.manning.com/bauer3/>
JUnit in Action, Second Edition <http://www.manning.com/tahchiev/>
Spring Batch in Action <http://www.manning.com/templier/>
Blog: http://garygregory.wordpress.com
Home: http://garygregory.com/
Tweet! http://twitter.com/GaryGregory

Mime
View raw message