2009-02-19 5 views
4

Je remarque un comportement étrange en utilisant la journalisation standard lors des tests JUnit. JUnit redirige-t-il la sortie standard vers un flux différent? Comment puis-je avoir accès à cela?Comportement de journalisation Weird JUnit

Voici un test JUnit simple qui démontre le comportement que je décris.

@Test 
public void logMessage() { 
    // set up new logger with output directed to standard out 
    Logger logger = Logger.getLogger("my.test.logger"); 
    logger.addHandler(new StreamHandler(System.out, new SimpleFormatter())); 

    // log a warning message 
    logger.warning("logger message"); // message 1 

    // turn off parent handlers 
    logger.setUseParentHandlers(false); 

    // log a second warning message 
    logger.warning("second logger message"); // message 2 

    // print somehting to standard output 
    System.out.println("standard output message"); //message 3 
} 

Notez que j'ai créé un nouvel enregistreur qui envoie simplement ses messages de journal à la sortie standard (System.out).

Voici la sortie Junit

Testsuite: com.my.FormatterTest 
Feb 19, 2009 12:02:33 PM com.my.FormatterTest logMessage 
WARNING: logger message 
standard output message 
Tests run: 1, Failures: 0, Errors: 0, Time elapsed: 0.079 sec 

------------- Standard Output --------------- 
standard output message 
------------- ---------------- --------------- 
------------- Standard Error ----------------- 
Feb 19, 2009 12:02:33 PM com.my.FormatterTest logMessage 
WARNING: logger message 
------------- ---------------- --------------- 
Feb 19, 2009 12:02:33 PM com.my.FormatterTest logMessage 
WARNING: logger message 
Feb 19, 2009 12:02:33 PM com.my.FormatterTest logMessage 
WARNING: second logger message 
test: 
BUILD SUCCESSFUL (total time: 2 seconds) 

Pourquoi ne pas message 1 ou un message 2 apparaissent dans la sortie standard partie de la sortie de JUnit?

Merci!

Répondre

5

krosenvold's comments m'a conduit à la bonne réponse (merci!).

Il semble que stdout soit en fait redirigé vers un autre flux (JUnit). Le vrai problème, cependant, était que le buffer du StreamHandler n'était pas vidé jusqu'à après stdout a été réinitialisé à son flux de sortie d'origine (résultant en les messages de journal n'apparaissant pas dans la sortie de JUnit pour stdout). Changer le code à ce qui suit donne le bon comportement.

@Test 
public void logMessage() { 
    // set up new logger with output directed to standard out 
    Logger logger = Logger.getLogger("my.test.logger"); 
    StreamHandler sh = new StreamHandler(System.out, new SimpleFormatter()); 
    logger.addHandler(sh); 

    // log a warning message 
    logger.warning("logger message"); // message 1 

    // turn off parent handlers 
    logger.setUseParentHandlers(false); 

    // log a second warning message 
    logger.warning("second logger message"); // message 2 

    // print somehting to standard output 
    System.out.println("standard output message"); //message 3 

    // FLUSH THE STREAM HANDLER !!! 
    sh.flush(); 
} 

yeilds

Testsuite: com.my.FormatterTest 
Feb 20, 2009 12:58:17 PM com.my.FormatterTest logMessage 
WARNING: logger message 
standard output message 
Feb 20, 2009 12:58:17 PM com.my.FormatterTest logMessage 
WARNING: logger message 
Feb 20, 2009 12:58:17 PM com.my.FormatterTest logMessage 
WARNING: second logger message 
Tests run: 1, Failures: 0, Errors: 0, Time elapsed: 0.078 sec 

------------- Standard Output --------------- 
standard output message 
Feb 20, 2009 12:58:17 PM com.my.FormatterTest logMessage 
WARNING: logger message 
Feb 20, 2009 12:58:17 PM com.my.FormatterTest logMessage 
WARNING: second logger message 
------------- ---------------- --------------- 
------------- Standard Error ----------------- 
Feb 20, 2009 12:58:17 PM com.my.FormatterTest logMessage 
WARNING: logger message 
------------- ---------------- --------------- 
test: 
BUILD SUCCESSFUL (total time: 2 seconds) 
time: 2 seconds) 
+0

+1 Merci! Je configure un test qui génère à la fois un fichier journal et la console avec une coutume. Le fichier journal était bon mais la console conservait l'impression des résultats dans le désordre. Le changer en StreamHandler a résolu le problème. –

6

Comme vous le suggérez indirectement, les té- ripheurs junit redirigent stdout et stderr vers un flux séparé pendant l'exécution du test. Votre enregistreur est normalement initialisé avant que cette redirection se produise, ce qui signifie qu'il utilise le fichier System.out/System.err habituel pour se connecter à la console.

Cela peut être vu assez facilement en regardant la source de la classe JunitTestRunner. J'ai regardé une partie du code source parce que votre question m'a rendu curieux. Je ne sais pas quel TestRunner vous utilisez, et la réponse peut être là; les redirections de flux ne font pas partie du framework junit mais sont implémentées par ant/eclipse/maven/idea. Il ressemble comme vous ajoutezHandler n'a aucun effet whatsovever, donc je soupçonne quelque chose l'intercepte (votre sortie serait logique si tous la journalisation a été effectuée par un enregistreur parent).

+0

Dans mon exemple, je suis d'ajouter un nouveau gestionnaire à l'enregistreur pointé System.out * à l'intérieur du test lui-même *. Pourquoi cela n'utilise-t-il pas aussi l'ensemble stdout redirigé par TestRunner? – Vinnie

+0

Bon point sur le coureur JUnit Test. J'utilise le coureur de test dans NetBeans. Je ne comprends toujours pas comment 2 références à System.out peuvent écrire des piqûres à deux endroits différents dans la même méthode. C'est un gratte-tête pour moi et c'est frustrant. – Vinnie