Geek Answers Handbook

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

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 will also add a message to the RuntimeException :

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

Output:

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

Why is a NullPointerException not being 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
+6
source share
4 answers

I noticed that in the log4j.properties file that I am using, there is the following line:

 log4j.throwableRenderer=org.apache.log4j.EnhancedThrowableRenderer

The elements caused by seem to be omitted when an exception is thrown.

After deletion, a complete stack trace is tracked.

+6
source

Providing the opportunity to try all the documents and debugging, I could hope that this helps in any way:

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

Thus, both cases include a RuntimeException stack trace thrown by code. Not a big difference.

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

Quote from RuntimeException Java-Doc and NullPointerException Java-Doc

 public RuntimeException(Throwable cause)

Throws a new exception at runtime with the specified reason and a verbose message (cause==null ? null : cause.toString()) (which usually contains a message about the class and details of the reason). This constructor is useful for runtime exceptions, which are slightly larger than the wrappers for other metadata.

 public NullPointerException(String s)

Throws a NullPointerException with the specified verbose message.

So maybe answer the first part of your question when a java.lang.RuntimeException is cause.toString() at runtime, raised by new NullPointerException , but as cause==null evaluates to false, cause.toString() is printed i.e. java.lang.NullPointerException , and now, since this exception contains a message that follows as NPE

Note. You mentioned the reason 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)

Throws a new exception at runtime with the specified verbose message and reason. Note that the verbose message related to the reason is not automatically included in this verbose runtime exception message.

In this case, you will receive a java.lang.RuntimeException message with an RTE message, since your reason is the child of the RuntimeException itself, and the parent executes it first, in which case the child is not reached.

+6
source

There are 2 questions.

  • Why is a NullPointerException not logged in this case [throw new RuntimeException ("RTE", new NullPointerException ("NPE");)?

Ans:

In fact, SLF4J has no impact on that case . This is a pure JVM issue. In the JVM, it is required to compute each passed parameter before calling the function. If you follow these two examples, you can easily understand this problem.

Example 1:

 public class Main { public static void main(String[] args) { throw new RuntimeException(new NullPointerException("NPE")); } }

Output:

 Exception in thread "main" java.lang.RuntimeException: java.lang.NullPointerException: NPE // Here, "java.lang.NullPointerException: NPE" - this portion is used as message according to RuntimeException at Main.main(Main.java:3) Caused by: java.lang.NullPointerException: NPE ... 1 more

Here "java.lang.NullPointerException: NPE" - this part is used as a message according to RuntimeException, which is also thrown from another NullPointerException (String s)

Example 2:

 public class Main { public static void main(String[] args) { throw new RuntimeException("RTE", new NullPointerException("NPE")); } }

Output:

 Exception in thread "main" java.lang.RuntimeException: RTE // Here "RTE" is used as message at Main.main(Main.java:3) Caused by: java.lang.NullPointerException: NPE ... 1 more

Here, "RTE" used as a message.

You have used 3 times exceptions in your code. This is a good encoding.

  1. Why does e.printStackTrace () print both exceptions in both cases?

e.printStackTrace() outputs this brochure and its backtracking to the standard error stream. It prints a stack trace for this Throwable object in the error output stream, which is the value of the System.err field since your output:

 java.lang.RuntimeException: RTE at Main.main(Main.java:10) Caused by: java.lang.NullPointerException: NPE ... 1 more
  • The first line of output ["java.lang.RuntimeException: RTE"] contains the result of the toString () method for this Throwable object.
  • The remaining rows represent the data previously recorded by the fillInStackTrace () method .

  • backtrace for throws with an initialized, non-null reason generally should include a return line for this reason. The format of this information is implementation dependent. For your understanding, follow the backtrace example below:

     HighLevelException: MidLevelException: LowLevelException at Junk.a(Junk.java:13) at Junk.main(Junk.java:4) Caused by: MidLevelException: LowLevelException at Junk.c(Junk.java:23) at Junk.b(Junk.java:17) at Junk.a(Junk.java:11) ... 1 more Caused by: LowLevelException at Junk.e(Junk.java:30) at Junk.d(Junk.java:27) at Junk.c(Junk.java:21) ... 3 more

  • "... one"

    These lines indicate that the remainder of the stack trace for this exception corresponds to the specified number of frames from the bottom of the stack trace of the exception caused by this exception (“close” exception).

Link to the resource:

For SLF4J you can go through

  • The sysout-over-slf4j module redirects all calls to System.out and System.err to a specific SLF4J logger with the name completely the class in which the call to System.out.println (or similar) was made at custom levels.
  • idalia SLF4J extensions allow logging at the level specified in runtime , rather than compile-time .
+1
source

I had a similar problem when I used Slf4j Logger in my Apache Spark application running in cluster mode. As I found out, the problem in my case was caused by the JVM optimization related to OmitStackTraceInFastThrow , which basically did not print the entire stack just a top-level error without any details.

In your case, it could be hiding the error message from NullPointerException . Try adding this argument to the JVM -XX:-OmitStackTraceInFastThrow when the application starts and let us know if it works.

0
source

More articles:


All Articles