Bug 51047 - Move org.apache.log4j.Category to reentrant read/write locks
Summary: Move org.apache.log4j.Category to reentrant read/write locks
Status: NEW
Alias: None
Product: Log4j - Now in Jira
Classification: Unclassified
Component: Other (show other bugs)
Version: 1.2
Hardware: PC Windows XP
: P2 major
Target Milestone: ---
Assignee: log4j-dev
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2011-04-11 05:46 UTC by Bartek Kowalewski
Modified: 2015-06-26 18:07 UTC (History)
3 users (show)



Attachments
Sample (refactored) Category class - JDK 5.0, log4j 1.2.16 (35.56 KB, text/x-java)
2011-04-11 05:50 UTC, Bartek Kowalewski
Details
minimal-intrusive patch (6.39 KB, patch)
2015-06-25 20:31 UTC, mirabilos
Details | Diff

Note You need to log in before you can comment on or make changes to this bug.
Description Bartek Kowalewski 2011-04-11 05:46:30 UTC
As mentioned in https://issues.apache.org/bugzilla/show_bug.cgi?id=41214#c36 and 
https://issues.apache.org/bugzilla/show_bug.cgi?id=50213#c6,  org.apache.log4j.Category uses a suboptimal synchronization mechanism. All methods are synchronized and treated the same way no matter if they modify the list of appenders or not.

This might cause performance degradation in a really multithreaded env.

It should not be hard to improve this synchronization mechanism without the
need to change API. Introduce a read-write lock to be used on all _non-static_ methods - instead of the synchronized keyword? 

Log4j 1.2.x is compliant with JDK 1.2, right? If so, using
java.util.concurrent.locks classes is not an option. Maybe a simple custom impl
of read-write lock would be enough? It might not be optimal to use a custom class. Maybe backport util concurrent? If adding external dependencies to the 1.2 branch of log4j is not an option, maybe we could inline the the reentrant read-write lock class into log4j?

WDYT?

I could create a patch once you decide which option is the best one.
Comment 1 Bartek Kowalewski 2011-04-11 05:50:00 UTC
Created attachment 26871 [details]
Sample (refactored) Category class - JDK 5.0, log4j 1.2.16

Attaching a sample implementation of the Category class with read write locks. Please note - this is only a sample - it's based on JDK5 while the final impl should be able to run under JDK 1.2.
Comment 2 Noel Grandin 2011-04-11 09:44:21 UTC
First rule of optimization - Don't.
Second rule of optimization - Don't... yet.
Third rule of optimizing - profile it first

I don't see any signs that the Category code actually showed up in a performance profile.
Comment 3 Noel Grandin 2011-04-11 09:48:45 UTC
Ah sorry, I see that this discussion happened on bug #50213.

But you realise that with your read/write lock, you're going to end up calling your appenders in parallel.
Are appenders expected to handle that situation?
Comment 4 Bartek Kowalewski 2011-04-11 10:18:16 UTC
We observed this issue when doing performance tests with 80-160 tps (and plenty of threads running in parallel). The app was later profiled and lots of threads were waiting on this synchronization. Changing these mechanism helped as the only synchronization that is now on the path is in the appender. As we have more than one appender, log4j now handles the number of threads that we use better - improved thread parallelism is observed :-).

AppenderSkeleton doAppend() is synchronized. Removing the old synchronization mechanism from Category will not cause appenders to malfunction no matter how concrete appenders are implemented. That's what source code suggests and that's also what we observed in our tests :).

I also logged an improvement related to synchronization in AsyncAppender: https://issues.apache.org/bugzilla/show_bug.cgi?id=51048
Comment 5 Erik Brakkee 2011-11-13 20:25:07 UTC
Is something still happening on this issue? We ran into this issue today (sunday) and it caused complete server freezes of more than 30 seconds just because rendering of one exception in one thread took 30-60 seconds. We were quite surprised to find this, especially with the claim that log4j was designed for concurrency.

When can we expect a new version of log4j in the 1.2 series that solves these issues?
Comment 6 Ralph Goers 2011-11-13 21:13:29 UTC
I'm not optimistic this will be addressed in Log4j 1.2.  However, I've been working on Log4j 2.0 for quite a while and it is getting fairly close to an alpha release. It should not have this problem.  Although the API will change, it has an adapter for the Log4j 1.2 API so you should be able to use it without having to change most of your code.
Comment 7 jan.swaelens 2014-08-28 09:48:23 UTC
Hello,

We are currently on log4j version 1.2.14 and are also noticing long sync waits (10-20-30 seconds) on this operation. Is this behavior still included in the latest (1.2.17) version?
Or should we also opt to move to the 2.x release to allow the use of async appenders?

thanks for your thoughts
Comment 8 Gary Gregory 2014-08-28 12:41:56 UTC
At this point, you best bet is to test this yourself or migrate to version 2.

The version 1.x line is not actively maintained.
Comment 9 mirabilos 2015-06-25 20:31:16 UTC
Created attachment 32857 [details]
minimal-intrusive patch

Hi,

because your new file also reindents the code and, worse, the comments, I provide a minimal-intrusive change against log4j 1.2.16 so it can actually be reviewed.

We may or may not test that tomorrow. This is just ahead of time preparation work.
Comment 10 Gary Gregory 2015-06-25 22:51:14 UTC
Hi,

At this point I would not put too much hope in seeing a new 1.2.x release. We are not actively maintaining it. I would migrate to v2 and use the 1.2 compatibility layer to get started.
Comment 11 mirabilos 2015-06-26 12:19:02 UTC
Hm, that doesn’t work for us – we don’t even use it explicitly, but things like WildFly and Liferay do.

But we can just exchange the one .class file in their JARs locally, and we can have the patch here for reference. Or maybe you could commit it, even if you don’t add a new formal release.
Comment 12 Gary Gregory 2015-06-26 16:01:36 UTC
You patch uses Java 5 and Log4j 1 is on Java 1.4, so that's a no go anyway :-(
Comment 13 Jess Holle 2015-06-26 16:12:36 UTC
(In reply to Gary Gregory from comment #12)
> You patch uses Java 5 and Log4j 1 is on Java 1.4, so that's a no go anyway
> :-(

I've long since given up and been building and relying upon my own patched log4j 1.2.17 that addresses many such issues by requiring Java 6 and eschewing absolute compatibility with log4j extensions.

There's lot of simple tricks, e.g. using a CopyOnWriteArrayList for the appenders, hoisting layout formatting out of the sync block on an opt-in basis, etc.

Yes, log4j 2.x is now out and I should probably look at it more.  That said, when you have a lot of custom log4j 1.x appenders and layouts and loads of code log4j 1.2 and a sizeable portion of it using API's beyond the "simple" set, this is a non-trivial undertaking.  Getting better performance out of 1.2.x until one has time for that undertaking only makes sense.
Comment 14 mirabilos 2015-06-26 16:17:38 UTC
We’re on Java 7, and Operations will move everything to Java 8 Really Soon Now™ because of the security support situation (using Debian’s OpenJDK exclusively helps, but better is better).
Comment 15 Jess Holle 2015-06-26 16:30:29 UTC
(In reply to mirabilos from comment #14)
> We’re on Java 7, and Operations will move everything to Java 8 Really Soon
> Now™ because of the security support situation (using Debian’s OpenJDK
> exclusively helps, but better is better).

There are some key places I'd like to patch to use Collections.forEach() -- as many of its implementations should be faster than the Iterator usage -- but I'm holding off for now.  I'm not sure why -- since I'm really using Java 8 for everything now.
Comment 16 Gary Gregory 2015-06-26 18:07:28 UTC
(In reply to Jess Holle from comment #13)
> (In reply to Gary Gregory from comment #12)
> > You patch uses Java 5 and Log4j 1 is on Java 1.4, so that's a no go anyway
> > :-(
> 
> I've long since given up and been building and relying upon my own patched
> log4j 1.2.17 that addresses many such issues by requiring Java 6 and
> eschewing absolute compatibility with log4j extensions.
> 
> There's lot of simple tricks, e.g. using a CopyOnWriteArrayList for the
> appenders, hoisting layout formatting out of the sync block on an opt-in
> basis, etc.
> 
> Yes, log4j 2.x is now out and I should probably look at it more.  That said,
> when you have a lot of custom log4j 1.x appenders and layouts and loads of
> code log4j 1.2 and a sizeable portion of it using API's beyond the "simple"
> set, this is a non-trivial undertaking.  Getting better performance out of
> 1.2.x until one has time for that undertaking only makes sense.

I hear you. I have a big work project that is deeply intertwined in log4jj 1.2 and it's quite likely to stay there... For new projects we use v2.