Странное поведение при ведении журнала 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 перенаправляют stdout и stderr в отдельный поток во время выполнения теста. Ваш регистратор обычно инициализируется до того, как происходит это перенаправление, что означает, что он использует обычный System.out / System.err для входа в консоль.

Это довольно легко увидеть, посмотрев на источник для класса JunitTestRunner.

Edit: Я посмотрел на некоторые исходные коды, потому что ваш вопрос вызвал у меня любопытство. Я не знаю, какой TestRunner вы используете, и ответ может лежать там; перенаправления потоков и т. д. не являются частью инфраструктуры junit, но реализуются с помощью ant / eclipse / maven / idea. Он выглядит , как будто вы addHandler не работаете, поэтому я подозреваю, что что-то перехватывает его (ваш вывод будет логичным, если all регистрация была выполнена родительским регистратором).

Answer 2

комментарии Крозенволда привели меня к правильному ответу (спасибо!).

Похоже, что stdout фактически перенаправлен в другой (JUnit) поток. Однако реальная проблема заключалась в том, что буфер StreamHandler не сбрасывался до тех пор, пока после того, как stdout не был сброшен в исходный поток вывода (в результате сообщения журнала не отображаются в выводе 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)