Custom ThrowableRenderer not working log4j 1.x

Question

I am trying to get a custom throwableRenderer to work with log4j 1.2.17.
Note that I cannot upgrade to log4j2 at this stage so I am looking for 1.x solution.

See e.g.
How to make log4j syslog appender write a stack trace in one line?

I am trying to do just that - get the stack trace to be printed on 1 line. I tried 2 approaches I could find on the web - using custom renderer and using Enhanced Pattern Layout. Still no luck!

But the class WRThrowableRenderer (which is my custom renderer)
and its method doRender is simply not called.
This is all in a web app running inside WildFly 8 (Java 8).

I tried at least 10 different things while testing the two approaches but nothing works.

What am I doing wrong?!

Also, is this renderer supposed to affect all loggers and change their behavior when an exception is logged? I think so. I am asking this because I have child loggers under this rootLogger. And they all log via the rootLogger in one single file.

log4j.rootLogger=INFO, stdout

log4j.throwableRenderer=com.yb.common.logging.WRThrowableRenderer

log4j.appender.stdout=org.apache.log4j.ConsoleAppender
log4j.appender.stdout.layout=org.apache.log4j.EnhancedPatternLayout
# log4j.appender.stdout.layout.ConversionPattern=%d{yyyy-MM-dd HH:mm:ss.SSS} %-5p [%t] ###%c{20}:%L### - [[[%m]]]%n
# log4j.appender.stdout.layout.ConversionPattern=%d{yyyy-MM-dd HH:mm:ss.SSS} %-5p [%t] ###%c{20}### [[[%m]]]%n %throwable{separator(|)}
log4j.appender.stdout.layout.ConversionPattern=%d{yyyy-MM-dd HH:mm:ss.SSS} %-5p [%t] ###%c{20}### [[[%m]]]%n
# log4j.appender.stdout.layout.ConversionPattern=%m%n

log4j.appender.stdout.threshold=INFO
log4j.appender.stdout.immediateFlush=true

Answer 1

I am trying to do just that - get the stack trace to be printed on 1 line. I tried 2 approaches I could find on the web - using custom renderer and using Enhanced Pattern Layout.

Without a custom ThrowableRenderer

If you want the stack trace all on one line without using a custom ThrowableRenderer, the best you'll be able to do is get the first line of the stack trace.

For example, using this configuration:

log4j.rootLogger=INFO, stdout
log4j.appender.stdout=org.apache.log4j.ConsoleAppender
log4j.appender.stdout.layout=org.apache.log4j.EnhancedPatternLayout
log4j.appender.stdout.layout.ConversionPattern=[%d] %-5p %m %throwable{short}%n

Will generate this log:

[2020-11-20 10:54:53,454] ERROR Test error message, with stack trace java.lang.IllegalArgumentException: Test exception message

With a custom ThrowableRenderer

If you want the entire stack trace printed on one line, you'll need to use a custom ThrowableRenderer.

1. Create the custom ThrowableRenderer, e.g.

   package org.example;
   
   import org.apache.log4j.DefaultThrowableRenderer;
   import org.apache.log4j.spi.ThrowableRenderer;
   
   import java.util.ArrayList;
   import java.util.Arrays;
   
   public class CustomThrowableRenderer implements ThrowableRenderer {
       private final DefaultThrowableRenderer defaultRenderer = new DefaultThrowableRenderer();
   
       @Override
       public String[] doRender(Throwable throwable) {
           String[] defaultRepresentation = defaultRenderer.doRender(throwable);
           String[] newRepresentation = {String.join("|", Arrays.asList(defaultRepresentation))};
   
           return newRepresentation;
       }
   }
   

2. Configure log4j1 to use the custom ThrowableRenderer

   log4j.throwableRenderer=org.example.CustomThrowableRenderer
   

At this point, the stack trace portion of the log will all be on one line, although it may be on a separate line from the rest of the log.

For example, your configuration from above:

log4j.rootLogger=INFO, stdout
log4j.appender.stdout=org.apache.log4j.ConsoleAppender
log4j.appender.stdout.layout=org.apache.log4j.EnhancedPatternLayout
log4j.appender.stdout.layout.ConversionPattern=%d{yyyy-MM-dd HH:mm:ss.SSS} %-5p [%t] ###%c{20}### [[[%m]]]%n
log4j.throwableRenderer=org.example.CustomThrowableRenderer

Will generate two lines because the stack trace is put on its own line by default:

2020-11-20 11:45:04.706 ERROR [main] ###org.example.App### [[[Test error message, with stack trace]]]
java.lang.IllegalArgumentException: Test exception message|     at org.example.App.logErrorWithStackTrace(App.java:31)| at org.example.App.okayThatsEnough(App.java:25)|        at org.example.App.notLongEnough(App.java:21)|  at org.example.App.makeStackTraceLonger(App.java:17)|   at org.example.App.testLoggingWithStackTraces(App.java:13)|     at org.example.App.main(App.java:9)

You can get the error message and stack trace on one line by using %throwable in your pattern:

log4j.appender.stdout.layout.ConversionPattern=%d{yyyy-MM-dd HH:mm:ss.SSS} %-5p [%t] ###%c{20}### [[[%m]]] %throwable%n

However a blank line will be generated after:

2020-11-20 11:46:46.897 ERROR [main] ###org.example.App### [[[Test error message, with stack trace]]] java.lang.IllegalArgumentException: Test exception message|       at org.example.App.logErrorWithStackTrace(App.java:31)| at org.example.App.okayThatsEnough(App.java:25)|        at org.example.App.notLongEnough(App.java:21)|  at org.example.App.makeStackTraceLonger(App.java:17)|   at org.example.App.testLoggingWithStackTraces(App.java:13)|     at org.example.App.main(App.java:9)

That could probably be fixed as well but it might require a custom appender.

I made a small sample app you can use as a reference: https://github.com/bmaupin/junkpile/tree/master/java/log4j1-custom-throwablerenderer