2009-07-02 13 views
55

Recientemente encontré un error que causa una NullPointerException. La excepción se captura y se registra usando una declaración slf4j estándar. Código abreviado a continuación:NullPointerException stack trace no está disponible sin el agente de depuración

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

Como puede ver, nada especial. Sin embargo, de todas las declaraciones de registro de excepciones que tenemos, solo esta no imprime un seguimiento de pila. Todo lo que imprime es el mensaje (representado como "...") y el nombre de la clase de excepción (java.lang.NullPointerException).

Dado que el seguimiento de la pila de una excepción está cargado de forma diferida, pensé que tal vez hay un problema de reorganización de instrucciones y decidí llamar a e.getStackTrace() antes de la declaración de registro. Esto no hizo diferencia.

Así que decidí reiniciar con el agente de depuración habilitado. Sin embargo, debido a que incluso adjunté el proceso, noté que ahora los trazos de pila estaban imprimiendo. Entonces, claramente, la presencia del agente de depuración provocó que estuviera disponible cierta información de depuración adicional.

Desde entonces he solucionado la causa de la excepción. Pero me gustaría saber por qué el seguimiento de la pila no estaba disponible sin un depurador. ¿Nadie sabe?

aclaración: esto no es un problema de registro. Imagínese el mismo bloque try/catch, pero en la captura, imprimo el valor de:

e.getStackTrace().length 

Sin un depurador este impresiones '0', con un depurador que se imprime un número positivo (9 en este caso).

Más información: esto está sucediendo en JDK 1.6.0_13 de 64 bits en AMD64, Linux 2.6.9

+2

¿qué vm estás usando? ese comportamiento suena * muy * raro. –

+0

JDK 1.6.0_13, 64 bits en Linux 2.6.9 – omerkudat

+0

¿Qué sucede cuando "arrojas una nueva NullPointerException() 'dentro del intento? – seth

Respuesta

18

¿Es posible que este código está en un bucle interno? Entonces, el compilador JIT podría estar compilando la pila de llamadas para este código nativo, perdiendo la información de la pila. Luego, cuando conecta el depurador, deshabilita el JIT, haciendo que la información vuelva a estar disponible.

Las otras excepciones manuales siguen mostrando la información ya que el JIT no se está optimizando.

Parece que esto a veces puede suceder por otros de un comentario en el código fuente de la clase en la línea 102:

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

+3

Más tarde logré confirmar que apagar el JIT (JAVA_COMPILER = false) hace que el seguimiento de pila completo esté disponible cada vez que se produce esta excepción. – omerkudat

0

puedo replicar esto, pero parece un poco raro que esto estaría sucediendo en su acción alguna parte.

Si llama a setStackTrace con una matriz vacía, eso solo hará que se muestre el texto.

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; 
    } 
} 

Ejecución de ella ....

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

% java Fark nothing 
java.lang.NullPointerException 
+0

Sí, alguien mencionó esto también. Este no es el caso. – omerkudat

+0

¿Ocurre lo mismo si solo arrojas una NullPointerException en el intento? – seth

+0

Sí, el mismo comportamiento si lanzo manualmente. Y esto sucede solo en este try/catch. En otros, donde lanzo manualmente, obtengo un comportamiento normal (es decir, de pila completa). – omerkudat

83

Con la bandera de JVM -XX: -OmitStackTraceInFastThrow puede desactivar la optimización del rendimiento de la JVM para este caso de uso. Si se proporciona este parámetro, que desactiva el indicador, la pila de seguimiento estará disponible.

Para obtener más información, echar un vistazo a las siguientes notas de la versión:

"El compilador en el servidor de VM proporciona ahora trazas de pila correctos para todos 'en frío' excepciones incorporadas Por motivos de rendimiento, cuando tal una. se lanza una excepción varias veces, se puede recompilar el método. Después de la recompilación, el compilador puede elegir una táctica más rápida utilizando excepciones preasignadas que no proporcionan un seguimiento de pila. Para deshabilitar por completo el uso de excepciones preasignadas, use este nuevo indicador: -XX : -OmitStackTraceInFastThrow ". http://java.sun.com/j2se/1.5.0/relnotes.html

+0

Esto es muy interesante, gracias por señalarlo. – omerkudat

+3

Tuvimos el mismo problema otra vez y probamos esta opción, y funcionó muy bien, mucho mejor que apagar completamente el JIT. ¡Gracias! – omerkudat

+0

¡Gracias por señalar esto! – Daniel

Cuestiones relacionadas