NullPointerException stack trace not available without debug agent

Question

Hi all,

I have recently found a bug that causes a NullPointerException. The exception is caught and logged using a standard slf4j statement. Abridged code below:

for(Action action : actions.getActions()) {
    try {
        context = action.execute(context);
    } catch (Exception e) {
        logger.error("...", e);
        break;
    }
}

As you can see, nothing fancy. However, of all the exception logging statements that we have, just this one does not print a stack trace. All it prints is the message (represented as "...") and the name of the exception class (java.lang.NullPointerException).

Since the stack trace on an exception is lazy loaded, I thought maybe there is a instruction reordering issue of some sort and decided to call e.getStackTrace() before the log statement. This made no difference.

So I decided to restart with the debug agent enabled. However, because I even attached to the process, I noticed that now the stack traces were printing. So clearly the presence of the debug agent caused some additional debug information to become available.

I have since then fixed the root cause of the exception. But I would like to learn why the stack trace was unavailable without a debugger. Anyone know?

Clarification: this is not a logging issue. Imagine the same try/catch clause, but in the catch, I print the value of:

e.getStackTrace().length

Without a debugger this prints '0', with a debugger it prints a positive number (9 in this case).

More info: this is happening on JDK 1.6.0_13, 64bit, amd64, linux 2.6.9

Answer 1

I can replicate this but it seems kind of weird that this would be happening in your Action somewhere.

If you call setStackTrace with an empty array, that'll cause only the text to be shown.

 public class Fark {
   public static void main(String[] args) {
       try {
           Fark.throwMe(args.length != 0);

       }
       catch (Exception e) {
           e.printStackTrace();
       }

   }

     public static final void throwMe(boolean arg) throws Exception{
         Exception e = new NullPointerException();
         if (arg) {
           e.setStackTrace(new StackTraceElement[0]);
         }
         throw e;
     }
 }

Running it....

% java Fark
java.lang.NullPointerException
        at Fark.throwMe(Fark.java:15)
        at Fark.main(Fark.java:5)

% java Fark nothing
java.lang.NullPointerException

Answer 2

Is it possible that this code is in an inner loop? Then then JIT compiler might be compiling the call stack for this to native code, losing the stack information. Then when you attach the debugger it disables the JIT, making the information available again.

The other manual exceptions keep displaying the information as the JIT is not optimising.

It looks like this can sometimes happen for others from a comment in this class source code at line 102:

http://logging.apache.org/log4j/1.2/xref/org/apache/log4j/spi/LocationInfo.html

Answer 3

With the JVM flag -XX:-OmitStackTraceInFastThrow you can disable the performance optimization of the JVM for this use case. IF this flag ist set, the stacktrace will be available.

For more information please have a look at the following release notes:

"The compiler in the server VM now provides correct stack backtraces for all "cold" built-in exceptions. For performance purposes, when such an exception is thrown a few times, the method may be recompiled. After recompilation, the compiler may choose a faster tactic using preallocated exceptions that do not provide a stack trace. To disable completely the use of preallocated exceptions, use this new flag: -XX:-OmitStackTraceInFastThrow." http://java.sun.com/j2se/1.5.0/relnotes.html