奇怪的 JUnit 日志记录行为

Question

我注意到在 JUnit 测试期间使用标准日志记录有一些奇怪的行为。 JUnit 是否将标准输出重定向到不同的流？我怎样才能访问它？

这是一个简单的 JUnit 测试，演示了我所描述的行为。

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

请注意，我创建了一个新的记录器，它只是将其日志消息发送到标准输出 (System.out)。

这是 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)

message 1 或 message 2 为什么不显示在 JUnit 输出的标准输出 部分？

谢谢！

Answer 1

正如您间接建议的那样，junit 测试运行程序在测试运行时将 stdout 和 stderr 重定向到单独的流。您的记录器通常在此重定向发生之前初始化，这意味着它使用常规 System.out/System.err 记录到控制台。

通过查看 JunitTestRunner 类的源代码可以很容易地看出这一点。

编辑： 我查看了一些源代码，因为你的问题让我很好奇。我不知道您使用的是哪个 TestRunner，答案可能就在那里；流重定向等不是 junit 框架的一部分，而是由 ant/eclipse/maven/idea 实现的。 看起来你 addHandler 没有任何效果 whatsovever ，所以我怀疑有什么东西在拦截它（如果 all 日志记录是由父记录器完成的，你的输出将是合乎逻辑的）。

Answer 2

krosenvold's comments 引导我找到正确答案（谢谢！）。

似乎 stdout 实际上被重定向到另一个 (JUnit) 流。然而，真正的问题是，直到之后 stdout 被重置为其原始输出流之后，StreamHandler 的缓冲区才被刷新（导致日志消息没有出现在 JUnit 的 stdout 输出中）。将代码更改为以下代码会产生正确的行为。

@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();
}

产量

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)