奇怪的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)

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

谢谢!

Answer 1

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

通过查看JunitTestRunner类的源代码,可以很容易地看到这一点.

编辑: 我看了一些源代码,因为你的问题让我很好奇.我不知道你使用的是哪个TestRunner,答案可能就在那里; 流重定向等不是junit框架的一部分,而是由ant/eclipse/maven/idea实现.它看起来像你addHandler操作没有任何影响whatsovever,所以我怀疑的东西是拦截它(如果您的输出将是合乎逻辑 的所有记录是由家长记录器完成).

Answer 2

克罗森沃尔德的评论让我得到了正确答案(谢谢!).

看起来好像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();
}

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)