How can an Exception be created/thrown with no stack trace? [duplicate]

Question

I was trawling through some logs today and came across a strange error.

Here's how it appears in the log:

2014/09/11 15:23:52.801 [CC3A5FDD16035540B87F1B8C5E806588:<removed>] WARN a.b.c.Ddd - Main failure 
java.lang.NullPointerException: null
2014/09/11 15:23:52.801 [CC3A5FDD16035540B87F1B8C5E806588:<removed>] ...

and here's what the code looks like:

} catch (Exception e) {
    Ddd.log.warn("Main failure ", e);
    throw e;
}

The code is in a jsp if that is important. The same exception is repeated once more in the log (as you'd expect from the throw e).

I have no record of what the cause was - the previous line in the log shows execution of a query. This occurred just twice over a 4-day period and seems not to have caused any harm to the system.

Environment: Fairly busy web service running under Tomcat with Java 5.

I am not asking for tips on debugging the system - these errors are long-gone and may even never happen again. I was just stumped as to how any exception (especially an NPE) could be created without a stack trace?

Added

The logger being used is an slf4j driven Logback instance. I believe the warn method is here. Not sure what Logback method that resolves to but I am confident the Throwable parameter is treated specially and if there was an stack trace attached to the Throwable it would appear in the log.

LogBack.xml - as requested:

<?xml version="1.0" encoding="UTF-8"?>
<configuration>
  <property name="log.package" value="Package" />
  <property name="log.pattern" value="%date{yyyy/MM/dd HH:mm:ss.SSS} [%X{session}:%X{device}] %level %logger{25} - %msg%n"/> 
  <property name="log.consolePattern" value="%highlight(%-5level) %white(%logger{25}) - %msg%n"/> 
  <if condition='isDefined("catalina.home")'>
    <then>
      <property name="log.dir" value="${catalina.home}/logs" />
    </then>
    <else>
      <property name="log.dir" value="." />
    </else>
  </if>

  <appender name="console" class="ch.qos.logback.core.ConsoleAppender">
    <filter class="ch.qos.logback.classic.filter.ThresholdFilter">
      <level>DEBUG</level>
    </filter>
    <encoder>
      <Pattern>${log.consolePattern}</Pattern>
    </encoder>
  </appender>

  <appender name="rolling" class="ch.qos.logback.core.rolling.RollingFileAppender">
    <file>${log.dir}/${log.package}.log</file>
    <encoder>
      <Pattern>${log.pattern}</Pattern>
    </encoder>
    <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
      <fileNamePattern>${log.dir}/${log.package}.%d{yyyy-MM-dd}.%i.log.zip</fileNamePattern>
      <timeBasedFileNamingAndTriggeringPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP">
        <!-- or whenever the file size reaches 16MB. -->
        <maxFileSize>16MB</maxFileSize>
      </timeBasedFileNamingAndTriggeringPolicy>
      <!-- Keep no more than 3 months data. -->
      <maxHistory>90</maxHistory>
      <cleanHistoryOnStart>true</cleanHistoryOnStart>
    </rollingPolicy>
  </appender>

  <!-- Default logging levels. -->
  <root level="INFO">
    <appender-ref ref="console"/>
    <appender-ref ref="rolling"/>
  </root>
  <!-- Specific logging levels. -->
  <!-- Generally set to INFO or ERROR but if you need more details, set to DEBUG. -->
  <logger name="org.apache" level="INFO"/>
  <logger name="net.sf.ehcache" level="ERROR"/>
  <logger name="com.zaxxer" level="ERROR"/>
  <logger name="ch.qos" level="ERROR"/>
</configuration>

I hand-edited out the values after the session ID in the log to remove customer data.

Theodora

Prior to slf4j 1.6; it specifically says it wont print the stacktrace according to this link slf4j.org/faq.html#paramException – Saying

@Abhin - Thanks - using slf4j version 1.7.3 - and all other exceptions print with stack traces fine. – Theodora

What is the format of the log output? i.e. how is the logback.xml configured to render the log output? – Belen

@MichaelWiles - Good point - perhaps the issue is in the logger itself!! Logback.xml posted. – Theodora

@Theodora If there is an issue with the logger; changing to 1.7.3 shouldn't have helped. – Saying

The exception itself contains the stack trace info -- that's added when the exception is created. Whether the stack trace is printed or not is up to the exception handler that discards the exception. (Of course, exception handlers that rethrow the exception can log the stack trace if they wish to do so, as well.) – Brest

Answer 1

Sometimes, especially when it comes to NullPointers (in my experience), the jvm can optimize the creation and casting of exceptions, and the stack trace is lost (or more correctly, never created). I suspect that your issue is not related to certain java libs, but rather the jvm itself.

If you add this argument when starting your jvm-process you will get your stack traces back, if my suspicion is correct.

-XX:-OmitStackTraceInFastThrow

This has been asked before, look here for more details:

• NullPointerException in Java with no StackTrace
• Recurring Exception without a stack trace - how to reset?

Note, that this applies sun/oracle jvm

Puttier

Answer 2

1. Maybe the log does not log also the stack trace?

2. Here is an example on how an exception does not have stack trace:

   try {
     throw new Exception() {
       @Override
       public synchronized Throwable fillInStackTrace() {
         return null;
       }
     };
   } catch (Exception e) {
     e.printStackTrace();
   }
   

So maybe that particular exception is a custom one with #fillInStackTrace() overridden, but is strange anyway.

Arson

Still reports the line it was created on in my tests - good thinking though. – Theodora

What do you mean with "the line it was created"? The line where it occurs is not in the stack trace? And you said the stack trace is missing. – Arson

I mean - running your sample code prints com.oldcurmudgeon.test.Test$2 which is indeed close to what I see but not quite the same. – Theodora

Answer 3

See that:

    RuntimeException e = new RuntimeException();
    e.setStackTrace(new StackTraceElement[0]);
    ...
    e.printStackTrace();

or:

    RuntimeException e = new RuntimeException();
    e.setStackTrace(new StackTraceElement[0]);
    ...
    throw e;

You can manipulate with stacktrace.

Official

Your first example records the line it was created on, the second records the full stack trace of the point the exception was thrown. Good reminder that setStackTrace is available. – Theodora

Answer 4

According to this link the stacktrace won't be printed in slf4j prior to 1.6. Having a version greater than 1.6 should resolve the issue.

Saying

That would be the case if it was log.warn("Main failure {}", e);. In this case the logger knows that it is an Exception in the second parameter and so logs the stack trace in it. – Theodora

OK. If your warn method treats it as an Exception; then you might have to look at how the Exception is created or manipulated. – Saying

Answer 5

As I see it, there are three possible culprits:

1. SLF4J doesn't always log exceptions (there used to be some errors in earlier versions). Depending on the underlying logging framework, there could be other configuration issues. Perhaps the exception had a stack trace after all, it just wasn't logged.
2. The exception wasn't a real NullPointerException, but rather a different exception that had the toString() and fillInStackTrace() methods overridden (the former to print the NPE and the latter to skip filling in the stack trace).
3. The NPE was created via Serialization (as opposed to the usual constructor) and lost the stack trace along the way.

Tega