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.
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.
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.
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?
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
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?
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.
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
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.
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.
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.
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.
You patch uses Java 5 and Log4j 1 is on Java 1.4, so that's a no go anyway :-(
(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.
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).
(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.
(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.