Attached a patch to 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, 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.
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. 


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