logging-log4j-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Remko Popma <remko.po...@gmail.com>
Subject Re: Log4j2 RollingFileAppender deadlock issue
Date Sun, 05 Jul 2015 15:00:20 GMT
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
>>>
>>>
>>
>>
>

Mime
View raw message