Pergunta sobre stack-trace, java, nullpointerexception, logging – Rastreio de pilha NullPointerException não disponível sem agente de depuração

58

Eu encontrei recentemente um bug que causa um NullPointerException. A exceção é capturada e registrada usando uma instrução padrão slf4j. Código abreviado abaixo:

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

Como você pode ver, nada extravagante. No entanto, de todas as instruções de log de exceção que temos, apenas esta não imprime um rastreio de pilha. Tudo o que imprime é a mensagem (representada por "...") e o nome da classe de exceção (java.lang.NullPointerException).

Como o rastreio de pilha em uma exceção é carregado com preguiça, pensei que talvez houvesse uma questão de reordenamento de instrução de algum tipo e decidi chamar e.getStackTrace () antes da instrução de log. Isso não fez diferença.

Então, decidi reiniciar com o agente de depuração ativado. No entanto, porque eu mesmo anexado ao processo, notei que agora os rastreamentos de pilha estavam imprimindo. Então, claramente, a presença do agente de depuração fez com que algumas informações de depuração adicionais ficassem disponíveis.

Desde então, consertei a causa raiz da exceção. Mas gostaria de saber por que o rastreamento de pilha não estava disponível sem um depurador. Ninguem sabe?

Esclarecimento:este não é um problema de registro. Imagine a mesma cláusula try / catch, mas na captura, imprimo o valor de:

e.getStackTrace().length

Sem um depurador, este imprime "0", com um depurador imprime um número positivo (9 neste caso).

Mais informações: isso está acontecendo no JDK 1.6.0_13, 64bit, amd64, linux 2.6.9

JDK 1.6.0_13, 64 bits no linux 2.6.9 omerkudat
Tente registrar as ações, para que você possa ter uma ideia de qual ação causa isso David Rabinowitz
possível duplicata deNullPointerException em Java sem StackTrace Christian
Obrigado por esta pergunta (e a solução)! Acabei de receber isso como um relatório de bug para o meu aplicativo de registro e estava quase enlouquecendo ... porque nãoestava nenhum bug no meu código. Isso esclareceu as coisas um pouco. Huxi

Sua resposta

3   a resposta
19

É possível que esse código esteja em um loop interno? o compilador JIT pode estar compilando a pilha de chamadas para isso no código nativo, perdendo as informações da pilha., quando você conecta o depurador, ele desativa o JIT, disponibilizando as informações novamente.

As outras exceções manuais continuam exibindo as informações, pois o JIT não está otimizando.

Parece que isso às vezes pode acontecer para os outros a partir de um comentário neste código-fonte da classe na linha 102:

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

Mais tarde, consegui confirmar que desligar o JIT (JAVA_COMPILER = false) faz com que o rastreio completo da pilha esteja disponível sempre que essa exceção ocorrer. omerkudat
0

mas parece meio estranho que isso esteja acontecendo em sua ação em algum lugar.

Se você chamar setStackTrace com uma matriz vazia, isso fará com que apenas o texto seja mostrado.

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

Correndo ...

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

% java Fark nothing
java.lang.NullPointerException
Acontece a mesma coisa se você simplesmente joga um NullPointerException na tentativa? seth
Sim, o mesmo comportamento se eu jogar manualmente. E isso acontece apenas neste try / catch. Em outros, quando jogo manualmente, obtenho um comportamento normal (ou seja, pilha completa). omerkudat
Sim, alguém mencionou isso também. Este não é o caso. omerkudat
88

-OmitStackTraceInFastThrow, é possível desativar a otimização de desempenho da JVM para este caso de uso. Se este parâmetro for dado, o que desativa o sinalizador, o stacktrace estará disponível.

Para mais informações, por favor veja as seguintes notas de lançamento:

"O compilador na VM do servidor agora fornece rastreamentos de pilha corretos para todas as exceções internas" frias ". Para fins de desempenho, quando essa exceção é lançada algumas vezes, o método pode ser recompilado. Após a recompilação, o compilador pode escolher uma Tática mais rápida usando exceções pré-alocadas que não fornecem um rastreamento de pilha. Para desabilitar completamente o uso de exceções pré-alocadas, use este novo sinalizador: -XX: -OmitStackTraceInFastThrow. "http://java.sun.com/j2se/1.5.0/relnotes.html

Obrigado por apontar isso! Daniel
Nós tivemos o mesmo problema novamente e tentamos esta opção, e funcionou muito bem, muito melhor do que desligar o JIT completamente. Obrigado! omerkudat
Isso é muito interessante, obrigado por apontar isso. omerkudat

Perguntas relacionadas