Slf4j with Log4j does not print wrapped exception (caused by) when wrapper exception has a message

Question

First example:

public class Main {

    private static final Logger logger = LoggerFactory.getLogger(Main.class);

    public static void main(String[] args) throws Exception {
        try {
            throw new RuntimeException(new NullPointerException("NPE"));
        } catch (RuntimeException e) {
            logger.error("Error:", e);
        }
    }
}

Output:

Error:
java.lang.RuntimeException: java.lang.NullPointerException: NPE
    at Main.main(Main.java:10)

In the second example we just add a message to the RuntimeException also:

throw new RuntimeException("RTE", new NullPointerException("NPE"));

Output:

Error:
java.lang.RuntimeException: RTE
    at Main.main(Main.java:10)

Why is NullPointerException not logged in this case?

Note: e.printStackTrace() prints both exceptions in both cases:

java.lang.RuntimeException: RTE
    at Main.main(Main.java:10)
Caused by: java.lang.NullPointerException: NPE
    ... 1 more

Versions:

slf4j-api: 1.7.12
slf4j-log4j12: 1.7.12
log4j: 1.2.17

Answer 1

Giving it a possible try using all the docs and debugging I could, I hope this helps in whatever way it can :

  @param message the message object to log.
  @param t the exception to log, including its stack trace.
  public void error(Object message, Throwable t) 

So both your cases are including the stack-trace of the RuntimeException thrown by the statement of code. Not much of a difference.

Case 1 : throw new RuntimeException(new NullPointerException("NPE"));

Quoting from the RuntimeException Java-Doc and NullPointerException Java-Doc

public RuntimeException(Throwable cause)

Constructs a new runtime exception with the specified cause and a detail message of (cause==null ? null : cause.toString()) (which typically contains the class and detail message of cause). This constructor is useful for runtime exceptions that are little more than wrappers for other throwables.

---

public NullPointerException(String s)

Constructs a NullPointerException with the specified detail message.

---

So that possibly answers the first part of your question where java.lang.RuntimeException is thrown during execution which is caused by the new NullPointerException but as cause==null evaluates to false the cause.toString() is printed i.e java.lang.NullPointerException and now since this exception itself has a message passed that follows as NPE

Note : You have mentioned the cause as NullPointerException in your code.(hence cause==null evaluates to false)

Case 2 : throw new RuntimeException("RTE", new NullPointerException("NPE"))

public RuntimeException(String message, Throwable cause)

Constructs a new runtime exception with the specified detail message and cause. Note that the detail message associated with cause is not automatically incorporated in this runtime exception's detail message.

---

In which case you end up getting java.lang.RuntimeException being thrown with a message RTE since your cause is a child of RuntimeException itself and the parent is caught first, it gets executed and the child is not reached in this case.

Answer 2

I noticed that in the log4j.properties file I'm using there is the following line:

log4j.throwableRenderer=org.apache.log4j.EnhancedThrowableRenderer

It seems to be causing the caused by elements to be omitted when the exception is logged.

Once removed, the full stack trace is logged.