NullPointerException en Java sans StackTrace

333

J'ai eu des exemples de notre code Java attraper un NullPointerException, mais quand j'essaie de journaliser le StackTrace (qui finit essentiellement par appeler Throwable.printStackTrace()), tout ce que je reçois est:

java.lang.NullPointerException

Quelqu'un at-il rencontré ce? J'ai essayé de googler pour "trace de pile vide du pointeur java null" mais je n'ai rien trouvé de tel.

Edward Shtern
la source
Quel est le contexte? Y a-t-il plusieurs fils impliqués? J'ai rencontré des problèmes pour obtenir la trace de pile d'une exception dans un SwingWorker.
Michael Myers
Aucun filetage impliqué ici, juste du vieux Java.
Edward Shtern
1
@Bozho - nope - vous ne savez pas encore comment reproduire le NullPointer.
Edward Shtern
1
en relation: stackoverflow.com/questions/1076191/…
Joshua Goldberg
Plus d'infos sur -XX:-OmitStackTraceInFastThrowdans le dup: stackoverflow.com/questions/4659151/…
Vadzim

Réponses:

407

Vous utilisez probablement la JVM HotSpot (à l'origine par Sun Microsystems, achetée plus tard par Oracle, une partie de l'OpenJDK), qui effectue beaucoup d'optimisation. Pour récupérer les traces de pile, vous devez passer l'option -XX:-OmitStackTraceInFastThrowà la JVM.

L'optimisation est que lorsqu'une exception (généralement une NullPointerException) se produit pour la première fois, la trace de pile complète est imprimée et la JVM se souvient de la trace de pile (ou peut-être simplement de l'emplacement du code). Lorsque cette exception se produit assez souvent, la trace de pile n'est plus imprimée, à la fois pour obtenir de meilleures performances et pour ne pas inonder le journal avec des traces de pile identiques.

Pour voir comment cela est implémenté dans la machine virtuelle Java HotSpot, récupérez-en une copie et recherchez la variable globale OmitStackTraceInFastThrow. La dernière fois que j'ai regardé le code (en 2019), il était dans le fichier graphKit.cpp .

Roland Illig
la source
1
Merci pour le conseil. Une idée s'il y a des problèmes cachés pour passer cette option (cela semble assez anodin tant que mon application ne lève pas une tonne d'exceptions)?
Edward Shtern
Il n'y a pas de pièges cachés à ma connaissance. Lorsque vous regardez le code source du Hotspot, vous pouvez voir que cette option n'est utilisée qu'à un seul endroit (graphKit.cpp). Et ça me va bien.
Roland Illig
34
Je pensais ajouter le peu d'informations supplémentaires que lorsque la trace de la pile est optimisée, c'est parce qu'elle a été entièrement gérée au moins une fois: jawspeak.com/2010/05/26/…
sharakan
1
J'utilise une JVM OpenJDK, version 1.8.0u171 (Debian 9), et il semble également accepter le -XX:-OmitStackTraceInFastThrowdrapeau. Je n'ai pas encore confirmé si c'était la raison pour laquelle je n'imprimais pas non plus les traces de pile (par exemple, en utilisant e.printStackTrace), mais cela semble très probable. J'ai développé la réponse pour refléter cette découverte.
Chris W.
Dans notre cas, les 125 premières exceptions avaient une trace de pile, puis les autres sur 3 rotations de fichiers journaux n'en avaient aucune. Cette réponse a été très utile pour trouver le coupable.
sukhmel
61

Comme vous l'avez mentionné dans un commentaire, vous utilisez log4j. J'ai découvert (par inadvertance) un endroit où j'avais écrit

LOG.error(exc);

au lieu du typique

LOG.error("Some informative message", e);

par paresse ou peut-être tout simplement pas y penser. La partie malheureuse de cela est qu'elle ne se comporte pas comme prévu. L'API de l'enregistreur prend en fait Object comme premier argument, pas une chaîne - puis il appelle toString () sur l'argument. Donc, au lieu d'obtenir la jolie jolie trace de pile, il imprime simplement la toString - ce qui dans le cas de NPE est assez inutile.

C'est peut-être ce que vous vivez?

Steven Schlansker
la source
+1: Cela expliquerait le comportement décrit, et vous n'êtes pas le seul à avoir découvert cela :)
Peter Lang
4
Nous avons en fait une politique standard de ne jamais utiliser le premier formulaire ci-dessus (LOG.error (exc);) - nous utilisons toujours la signature à 2 paramètres afin d'ajouter une déclaration descriptive aux journaux au lieu d'une simple trace de pile.
Edward Shtern
5
Bien sûr, mais la politique ne signifie pas qu'elle est toujours exécutée correctement! Je pensais que cela valait la peine d'être mentionné, au moins.
Steven Schlansker
C'est vrai, mais dans ce cas, c'était ;-)
Edward Shtern
28

Nous avons vu ce même comportement dans le passé. Il s'est avéré que, pour une raison folle, si une exception NullPointerException se produisait au même endroit dans le code plusieurs fois, après un certain temps, l'utilisation Log.error(String, Throwable)cesserait d'inclure les traces de pile complètes.

Essayez de regarder plus loin dans votre journal. Vous pouvez trouver le coupable.

EDIT: ce bug semble pertinent, mais il a été corrigé il y a si longtemps que ce n'est probablement pas la cause.

Matt Solnit
la source
2
Le bogue est fermé, mais l'indicateur -XX: -OmitStackTraceInFastThrow est toujours nécessaire pour contourner l'optimisation des performances.
Joshua Goldberg
J'ai vu ça récemment beaucoup. Des indices sur ce qui pourrait être à l'origine de cela, ou comment y remédier? Le système d'exploitation forestière est peut-être en place depuis des jours, et la cause réelle a changé, peu importe la recherche fastidieuse ...
Pawel Veselov
5
Pawel, avez-vous essayé le -XX:-OmitStackTraceInFastThrowdrapeau JVM suggéré par Joshua? Voir aussi stackoverflow.com/a/2070568/6198 .
Matt Solnit
1
C'était tout pour nous. Merci.
Andrew Cheong
20

Voici une explication: Hotspot a fait perdre aux traces de pile des exceptions en production - et le correctif

Je l'ai testé sur Mac OS X

  • version java "1.6.0_26"
  • Environnement d'exécution Java (TM) SE (build 1.6.0_26-b03-383-11A511)
  • Machine virtuelle serveur Java HotSpot (TM) 64 bits (build 20.1-b02-383, mode mixte)

    Object string = "abcd";
    int i = 0;
    while (i < 12289) {
        i++;
        try {
            Integer a = (Integer) string;
        } catch (Exception e) {
            e.printStackTrace();
        }
    }

Pour ce fragment de code spécifique, 12288 itérations (+ fréquence?) Semblent être la limite où la JVM a décidé d'utiliser l'exception préallouée ...

Benoît Guérout
la source
10

exception.toString ne vous donne pas le StackTrace, il ne renvoie que

une brève description de ce jetable. Le résultat est la concaténation de:

* the name of the class of this object
* ": " (a colon and a space)
* the result of invoking this object's getLocalizedMessage() method

Utilisez exception.printStackTraceplutôt pour sortir le StackTrace.

Peter Lang
la source
Désolé, j'ai mal parlé dans mon message d'origine. Je les enregistre via Log4J, qui utilise printStackTrace ().
Edward Shtern
1
Avez-vous essayé d'utiliser getStackTrace()pour vous assurer que le problème ne vient pas de votre enregistreur?
Peter Lang
1
Si vous utilisez log4j, veillez à envoyer l'exception dans le cadre de l'argument à la méthode log. Je posterai une réponse avec cela.
Ravi Wallau
@raviaw point valide! @Edward Shtern: pouvez-vous confirmer que vous utilisez définitivement la forme à 2 arguments de la méthode log4j? Je sais que vous avez mentionné dans une réponse plus bas que c'est la politique de l'entreprise de le faire, mais êtes-vous ABSOLUMENT sûr que dans ce cas, vous suivez la politique?
KarstenF
Cela peut être long, mais est-il possible que l'exception provienne d'un code tiers? Il s'agit peut-être d'un wrapper d'exception (mal écrit), dont toString () renvoie simplement le nom de classe de l'exception encapsulée et qui ne fournit pas la trace de pile sous-jacente. Essayez de mettre quelque chose comme logger.info ("Exception class =" + exc.class.getCanonicalName ()) dans votre bloc catch et voyez ce que vous obtenez.
KarstenF
4

Autre suggestion - si vous utilisez Eclipse, vous pouvez définir un point d'arrêt sur NullPointerException lui-même (dans la perspective de débogage, allez dans l'onglet "Points d'arrêt" et cliquez sur la petite icône qui contient un!)

Vérifiez à la fois les options "interceptées" et "non interceptées". Désormais, lorsque vous déclenchez le NPE, vous allez immédiatement atteindre le point d'arrêt et vous pouvez ensuite parcourir et voir exactement comment il est géré et pourquoi vous n'obtenez pas de trace de pile.

Steven Schlansker
la source
1

toString()renvoie uniquement le nom de l'exception et le message facultatif. Je suggère d'appeler

exception.printStackTrace()

pour vider le message, ou si vous avez besoin des détails sanglants:

 StackTraceElement[] trace = exception.getStackTrace()
Sheldon Young
la source
Voir ci-dessus - J'ai mal parlé - J'utilise printStackTrace ().
Edward Shtern
1

(Votre question n'est toujours pas claire quant à savoir si votre code appelle printStackTrace()ou si cela est effectué par un gestionnaire de journalisation.)

Voici quelques explications possibles sur ce qui pourrait se produire:

  • L'enregistreur / gestionnaire utilisé a été configuré pour afficher uniquement la chaîne de message de l'exception, pas une trace de pile complète.

  • Votre application (ou une bibliothèque tierce) enregistre l'exception en utilisant LOG.error(ex);plutôt que la forme à 2 arguments (par exemple) de la méthode log4j Logger.

  • Le message vient d'un endroit différent de celui où vous pensez qu'il est; par exemple, il s'agit en fait d'une méthode de bibliothèque tierce, ou de trucs aléatoires laissés par des tentatives antérieures de débogage.

  • L'exception en cours de journalisation a surchargé certaines méthodes pour masquer la trace de pile. Si tel est le cas, l'exception ne sera pas une véritable NullPointerException, mais sera un sous-type personnalisé de NPE ou même une exception non connectée.

Je pense que la dernière explication possible est assez improbable, mais les gens envisagent au moins de faire ce genre de chose pour "empêcher" l'ingénierie inverse. Bien sûr, cela ne réussit vraiment qu'à rendre la vie difficile aux développeurs honnêtes.

Stephen C
la source
1

Lorsque vous utilisez AspectJ dans votre projet, il peut arriver qu'un aspect masque sa partie de la trace de pile. Par exemple, aujourd'hui, j'ai eu:

java.lang.NullPointerException:
  at com.company.product.MyTest.test(MyTest.java:37)

Cette trace de pile a été imprimée lors de l'exécution du test via le surefire de Maven.

En revanche, lors de l'exécution du test dans IntelliJ, une trace de pile différente a été imprimée:

java.lang.NullPointerException
  at com.company.product.library.ArgumentChecker.nonNull(ArgumentChecker.java:67)
  at ...
  at com.company.product.aspects.CheckArgumentsAspect.wrap(CheckArgumentsAspect.java:82)
  at ...
  at com.company.product.MyTest.test(MyTest.java:37)
Roland Illig
la source
0

Cela produira l'exception, utilisez uniquement pour déboguer, vous devriez mieux gérer vos exceptions.

import java.io.PrintWriter;
import java.io.StringWriter;
    public static String getStackTrace(Throwable t)
    {
        StringWriter sw = new StringWriter();
        PrintWriter pw = new PrintWriter(sw, true);
        t.printStackTrace(pw);
        pw.flush();
        sw.flush();
        return sw.toString();
    }
Michael D. Irizarry
la source