如何對記錄器中的消息進行JUnit聲明

Question

我有一些測試代碼調用Java記錄器來報告其狀態。 在JUnit測試代碼中，我想驗證是否在此記錄器中創建了正確的日誌條目。大意如下的內容：

methodUnderTest(bool x){ 
    if(x) 
     logger.info("x happened") 
} 

@Test tester(){ 
    // perhaps setup a logger first. 
    methodUnderTest(true); 
    assertXXXXXX(loggedLevel(),Level.INFO); 
} 

我想，這可能是與一個特別改裝的記錄器（或處理，或格式化）來完成，但我寧願重新使用已經存在的解決方案。 （說實話，我不清楚如何從記錄器獲取logRecord，但假設這是可能的。）

Answer 1

非常感謝這些（令人驚訝的）快速和有益的答案;他們爲我的解決方案提供了正確的方式。

代碼庫是我想要使用它，使用java.util.logging作爲它的記錄器機制，並且我不覺得在這些代碼中有足夠的空間來將它完全更改爲log4j或記錄器接口/外觀。但基於這些建議，我'破解'了一個j.u.l.handler擴展，並且作爲一種享受。

以下是一個簡短的總結。擴展java.util.logging.Handler：

class LogHandler extends Handler 
{ 
    Level lastLevel = Level.FINEST; 

    public Level checkLevel() { 
     return lastLevel; 
    }  

    public void publish(LogRecord record) { 
     lastLevel = record.getLevel(); 
    } 

    public void close(){} 
    public void flush(){} 
} 

很明顯，你可以存儲你喜歡/想/從LogRecord需要這麼多，還是將它們全部推入堆棧，直到你得到溢出。

在對的JUnit測試的準備，爲您營造一個java.util.logging.Logger並添加這樣一個新LogHandler它：

@Test tester() { 
    Logger logger = Logger.getLogger("my junit-test logger"); 
    LogHandler handler = new LogHandler(); 
    handler.setLevel(Level.ALL); 
    logger.setUseParentHandlers(false); 
    logger.addHandler(handler); 
    logger.setLevel(Level.ALL); 

到setUseParentHandlers()的調用是沉默正常的處理程序，使（此JUnit的測試運行）不會發生不必要的記錄。做任何你的代碼下測試需要使用這個記錄器，運行測試和assertEquality：

libraryUnderTest.setLogger(logger); 
    methodUnderTest(true); // see original question. 
    assertEquals("Log level as expected?", Level.INFO, handler.checkLevel()); 
} 

（當然，你將這項工作的很大一部分進入一個@Before方法，使各種其他改進，但這將會使這個演示文稿變得混亂。）

Answer 2

實際上，您正在測試依賴類的副作用。對於單元測試你只需要驗證

logger.info()

調用了正確的參數。因此，使用模擬框架來模擬記錄器，這將允許您測試自己的類的行爲。

Answer 3

嘲笑是一種選擇，雖然它會很難，因爲記錄器通常是私有靜態最終 - 所以設置模擬記錄器不會是小菜一碟，或者需要修改被測試的類。

您可以創建一個自定義的Appender（或者其他名稱），並通過一個僅測試配置文件或運行時（依賴於日誌框架的方式）註冊它。 然後你可以得到appender（靜態的，如果在配置文件中聲明，或者通過它的當前引用，如果你插入運行時），並驗證它的內容。

Answer 4

如從別人提到你可以使用模擬框架。爲了做到這一點，你必須在你的課堂上暴露記錄器（儘管我會優先考慮將它打包爲私有的，而不是創建公共設置器）。

另一種解決方案是手動創建假記錄器。你必須編寫假記錄器（更多的夾具代碼），但在這種情況下，我希望增強的可讀性對測試框架保存的代碼進行測試。

我會做這樣的事情：

class FakeLogger implements ILogger { 
    public List<String> infos = new ArrayList<String>(); 
    public List<String> errors = new ArrayList<String>(); 

    public void info(String message) { 
     infos.add(message); 
    } 

    public void error(String message) { 
     errors.add(message); 
    } 
} 

class TestMyClass { 
    private MyClass myClass;   
    private FakeLogger logger;   

    @Before 
    public void setUp() throws Exception { 
     myClass = new MyClass(); 
     logger = new FakeLogger(); 
     myClass.logger = logger; 
    } 

    @Test 
    public void testMyMethod() { 
     myClass.myMethod(true); 

     assertEquals(1, logger.infos.size()); 
    } 
} 

Answer 5

我需要幾次爲好。我已經在下面放了一個小樣本，您可以根據自己的需要進行調整。基本上，你創建自己的Appender並將其添加到你想要的記錄器。如果你想收集的一切，根記錄器是一個良好的開端，但你可以用更具體的，如果你願意的話。當你完成後別忘了刪除Appender，否則你可能會造成內存泄漏。下面，我在測試中完成的，但setUp或@Before和tearDown或@After可能是更好的地方，根據您的需要。

此外，執行下面收集在內存中的List一切。如果你登錄了很多，你可能會考慮增加一個過濾器下降無聊的條目，或寫日誌到一個臨時文件在磁盤上（提示：LoggingEvent是Serializable，所以你應該能夠只序列化的事件對象，如果你的日誌消息是。）

import org.apache.log4j.AppenderSkeleton; 
import org.apache.log4j.Level; 
import org.apache.log4j.Logger; 
import org.apache.log4j.spi.LoggingEvent; 
import org.junit.Test; 

import java.util.ArrayList; 
import java.util.List; 

import static org.hamcrest.CoreMatchers.is; 
import static org.junit.Assert.assertThat; 

public class MyTest { 
    @Test 
    public void test() { 
     final TestAppender appender = new TestAppender(); 
     final Logger logger = Logger.getRootLogger(); 
     logger.addAppender(appender); 
     try { 
      Logger.getLogger(MyTest.class).info("Test"); 
     } 
     finally { 
      logger.removeAppender(appender); 
     } 

     final List<LoggingEvent> log = appender.getLog(); 
     final LoggingEvent firstLogEntry = log.get(0); 
     assertThat(firstLogEntry.getLevel(), is(Level.INFO)); 
     assertThat((String) firstLogEntry.getMessage(), is("Test")); 
     assertThat(firstLogEntry.getLoggerName(), is("MyTest")); 
    } 
} 

class TestAppender extends AppenderSkeleton { 
    private final List<LoggingEvent> log = new ArrayList<LoggingEvent>(); 

    @Override 
    public boolean requiresLayout() { 
     return false; 
    } 

    @Override 
    protected void append(final LoggingEvent loggingEvent) { 
     log.add(loggingEvent); 
    } 

    @Override 
    public void close() { 
    } 

    public List<LoggingEvent> getLog() { 
     return new ArrayList<LoggingEvent>(log); 
    } 
} 

Answer 6

這是我爲logback做的。在我的TestNG的單元測試類的父

然後創建了一個方法：

我創建了一個TestAppender類

​​

我在限定的的logback-的test.xml文件src/test/resources我添加了一個測試appender：

<appender name="TEST" class="com.intuit.icn.TestAppender"> 
    <encoder> 
     <pattern>%m%n</pattern> 
    </encoder> 
</appender> 

並將此appender添加到roo牛逼的appender：

<root> 
    <level value="error" /> 
    <appender-ref ref="STDOUT" /> 
    <appender-ref ref="TEST" /> 
</root> 

現在，從我的父測試類擴展，我可以得到的附加器，並獲得記錄的最後一條消息，並確認該消息，水平，拋出我的測試類。

ILoggingEvent lastEvent = testAppender.getLastEvent(); 
assertEquals(lastEvent.getMessage(), "..."); 
assertEquals(lastEvent.getLevel(), Level.WARN); 
assertEquals(lastEvent.getThrowableProxy().getMessage(), "..."); 

Answer 7

另一種選擇是模擬Appender並驗證消息是否記錄到了這個appender。舉例Log4j的1.2.x版本的Mockito和：

import static org.junit.Assert.assertEquals; 
import static org.mockito.Mockito.mock; 
import static org.mockito.Mockito.verify; 

import org.apache.log4j.Appender; 
import org.apache.log4j.Level; 
import org.apache.log4j.Logger; 
import org.apache.log4j.spi.LoggingEvent; 
import org.junit.After; 
import org.junit.Before; 
import org.junit.Test; 
import org.mockito.ArgumentCaptor; 

public class MyTest { 

    private final Appender appender = mock(Appender.class); 
    private final Logger logger = Logger.getRootLogger(); 

    @Before 
    public void setup() { 
     logger.addAppender(appender); 
    } 

    @Test 
    public void test() { 
     // when 
     Logger.getLogger(MyTest.class).info("Test"); 

     // then 
     ArgumentCaptor<LoggingEvent> argument = ArgumentCaptor.forClass(LoggingEvent.class); 
     verify(appender).doAppend(argument.capture()); 
     assertEquals(Level.INFO, argument.getValue().getLevel()); 
     assertEquals("Test", argument.getValue().getMessage()); 
     assertEquals("MyTest", argument.getValue().getLoggerName()); 
    } 

    @After 
    public void cleanup() { 
     logger.removeAppender(appender); 
    } 
} 

Answer 8

另一個想法值得一提的，雖然這是一個老話題，正在創造一個CDI製作這樣的嘲諷變得容易注入你的記錄。（而這也給沒有申報「整個記錄聲明」了的好處，但這是題外話）

例子：

創建記錄器注入：

public class CdiResources { 
    @Produces @LoggerType 
    public Logger createLogger(final InjectionPoint ip) { 
     return Logger.getLogger(ip.getMember().getDeclaringClass()); 
    } 
} 

的預選賽：

@Qualifier 
@Retention(RetentionPolicy.RUNTIME) 
@Target({TYPE, METHOD, FIELD, PARAMETER}) 
public @interface LoggerType { 
} 

在你的產品代碼使用記錄儀：

public class ProductionCode { 
    @Inject 
    @LoggerType 
    private Logger logger; 

    public void logSomething() { 
     logger.info("something"); 
    } 
} 

測試在測試代碼記錄器（產生EasyMock的例子）：

@TestSubject 
private ProductionCode productionCode = new ProductionCode(); 

@Mock 
private Logger logger; 

@Test 
public void testTheLogger() { 
    logger.info("something"); 
    replayAll(); 
    productionCode.logSomething(); 
} 

Answer 9

通過@ RonaldBlaschke的解決方案的啓發，我想出了這個：

public class Log4JTester extends ExternalResource { 
    TestAppender appender; 

    @Override 
    protected void before() { 
     appender = new TestAppender(); 
     final Logger rootLogger = Logger.getRootLogger(); 
     rootLogger.addAppender(appender); 
    } 

    @Override 
    protected void after() { 
     final Logger rootLogger = Logger.getRootLogger(); 
     rootLogger.removeAppender(appender); 
    } 

    public void assertLogged(Matcher<String> matcher) { 
     for(LoggingEvent event : appender.events) { 
      if(matcher.matches(event.getMessage())) { 
       return; 
      } 
     } 
     fail("No event matches " + matcher); 
    } 

    private static class TestAppender extends AppenderSkeleton { 

     List<LoggingEvent> events = new ArrayList<LoggingEvent>(); 

     @Override 
     protected void append(LoggingEvent event) { 
      events.add(event); 
     } 

     @Override 
     public void close() { 

     } 

     @Override 
     public boolean requiresLayout() { 
      return false; 
     } 
    } 

} 

...它允許你要做到：

@Rule public Log4JTester logTest = new Log4JTester(); 

@Test 
public void testFoo() { 
    user.setStatus(Status.PREMIUM); 
    logTest.assertLogged(
     stringContains("Note added to account: premium customer")); 
} 

你也許可以讓一個更聰明的方式使用hamcrest，但我已經把它忘在此。

Answer 10

使用Jmockit（1.21）我能夠寫這個簡單的測試。 該測試確保只調用一次特定的ERROR消息。

@Test 
public void testErrorMessage() { 
    final org.slf4j.Logger logger = org.slf4j.LoggerFactory.getLogger(MyConfig.class); 

    new Expectations(logger) {{ 
     //make sure this error is happens just once. 
     logger.error("Something went wrong..."); 
     times = 1; 
    }}; 

    new MyTestObject().runSomethingWrong("aaa"); //SUT that eventually cause the error in the log.  
} 

Answer 11

嘲諷追加程序可以幫助捕獲日誌行。 查找樣本上：http://clearqa.blogspot.co.uk/2016/12/test-log-lines.html

// Fully working test at: https://github.com/njaiswal/logLineTester/blob/master/src/test/java/com/nj/Utils/UtilsTest.java 

@Test 
public void testUtilsLog() throws InterruptedException { 

    Logger utilsLogger = (Logger) LoggerFactory.getLogger("com.nj.utils"); 

    final Appender mockAppender = mock(Appender.class); 
    when(mockAppender.getName()).thenReturn("MOCK"); 
    utilsLogger.addAppender(mockAppender); 

    final List<String> capturedLogs = Collections.synchronizedList(new ArrayList<>()); 
    final CountDownLatch latch = new CountDownLatch(3); 

    //Capture logs 
    doAnswer((invocation) -> { 
     LoggingEvent loggingEvent = invocation.getArgumentAt(0, LoggingEvent.class); 
     capturedLogs.add(loggingEvent.getFormattedMessage()); 
     latch.countDown(); 
     return null; 
    }).when(mockAppender).doAppend(any()); 

    //Call method which will do logging to be tested 
    Application.main(null); 

    //Wait 5 seconds for latch to be true. That means 3 log lines were logged 
    assertThat(latch.await(5L, TimeUnit.SECONDS), is(true)); 

    //Now assert the captured logs 
    assertThat(capturedLogs, hasItem(containsString("One"))); 
    assertThat(capturedLogs, hasItem(containsString("Two"))); 
    assertThat(capturedLogs, hasItem(containsString("Three"))); 
} 

Answer 12

至於我，你可以通過使用JUnit與Mockito簡化您的測試。它 我建議以下解決方案：

import org.apache.log4j.Appender; 
import org.apache.log4j.Level; 
import org.apache.log4j.LogManager; 
import org.apache.log4j.spi.LoggingEvent; 
import org.junit.After; 
import org.junit.Before; 
import org.junit.Test; 
import org.junit.runner.RunWith; 
import org.mockito.ArgumentCaptor; 
import org.mockito.Captor; 
import org.mockito.InjectMocks; 
import org.mockito.Mock; 
import org.mockito.runners.MockitoJUnitRunner; 

import java.util.List; 

import static org.assertj.core.api.Assertions.assertThat; 
import static org.assertj.core.api.Assertions.tuple; 
import static org.mockito.Mockito.times; 

@RunWith(MockitoJUnitRunner.class) 
public class MyLogTest { 
    private static final String FIRST_MESSAGE = "First message"; 
    private static final String SECOND_MESSAGE = "Second message"; 
    @Mock private Appender appender; 
    @Captor private ArgumentCaptor<LoggingEvent> captor; 
    @InjectMocks private MyLog; 

    @Before 
    public void setUp() { 
     LogManager.getRootLogger().addAppender(appender); 
    } 

    @After 
    public void tearDown() { 
     LogManager.getRootLogger().removeAppender(appender); 
    } 

    @Test 
    public void shouldLogExactlyTwoMessages() { 
     testedClass.foo(); 

     then(appender).should(times(2)).doAppend(captor.capture()); 
     List<LoggingEvent> loggingEvents = captor.getAllValues(); 
     assertThat(loggingEvents).extracting("level", "renderedMessage").containsExactly(
       tuple(Level.INFO, FIRST_MESSAGE) 
       tuple(Level.INFO, SECOND_MESSAGE) 
     ); 
    } 
} 

這就是爲什麼我們有一個與不同的消息數量

Answer 13

使用下面的代碼測試好的靈活性。我爲我的彈簧集成測試使用相同的代碼，我使用日誌記錄進行日誌記錄。使用方法assertJobIsScheduled來聲明日誌中打印的文本。

import ch.qos.logback.classic.Logger; 
import ch.qos.logback.classic.spi.LoggingEvent; 
import ch.qos.logback.core.Appender; 

private Logger rootLogger; 
final Appender mockAppender = mock(Appender.class); 

@Before 
public void setUp() throws Exception { 
    initMocks(this); 
    when(mockAppender.getName()).thenReturn("MOCK"); 
    rootLogger = (Logger) LoggerFactory.getLogger(ch.qos.logback.classic.Logger.ROOT_LOGGER_NAME); 
    rootLogger.addAppender(mockAppender); 
} 

private void assertJobIsScheduled(final String matcherText) { 
    verify(mockAppender).doAppend(argThat(new ArgumentMatcher() { 
     @Override 
     public boolean matches(final Object argument) { 
      return ((LoggingEvent)argument).getFormattedMessage().contains(matcherText); 
     } 
    })); 
} 

Answer 14

對於log4j2解決方案略有不同，因爲AppenderSkeleton不再可用。此外，如果您期待多個日誌記錄消息，則使用Mockito或類似的庫創建帶有ArgumentCaptor的Appender將不起作用，因爲MutableLogEvent會在多個日誌消息中重複使用。我發現log4j2最好的解決辦法是：

private static MockedAppender mockedAppender; 
private static Logger logger; 

@Before 
public void setup() { 
    mockedAppender.message.clear(); 
} 

/** 
* For some reason mvn test will not work if this is @Before, but in eclipse it works! As a 
* result, we use @BeforeClass. 
*/ 
@BeforeClass 
public static void setupClass() { 
    mockedAppender = new MockedAppender(); 
    logger = (Logger)LogManager.getLogger(MatchingMetricsLogger.class); 
    logger.addAppender(mockedAppender); 
    logger.setLevel(Level.INFO); 
} 

@AfterClass 
public static void teardown() { 
    logger.removeAppender(mockedAppender); 
} 

@Test 
public void test() { 
    // do something that causes logs 
    for (String e : mockedAppender.message) { 
     // add asserts for the log messages 
    } 
} 

private static class MockedAppender extends AbstractAppender { 

    List<String> message = new ArrayList<>(); 

    protected MockedAppender() { 
     super("MockedAppender", null, null); 
    } 

    @Override 
    public void append(LogEvent event) { 
     message.add(event.getMessage().getFormattedMessage()); 
    } 
} 

Answer 15

如果您正在使用java.util.logging.Logger這篇文章可能是非常有益的，它會創建一個新的處理程序，並在日誌輸出斷言： http://octodecillion.com/blog/jmockit-test-logging/

Answer 16

有兩種你可能試圖測試的東西。

• 當我的程序的操作員感興趣的事件時，我的程序是否執行適當的日誌記錄操作，它可以通知操作員該事件。
• 當我的程序執行日誌操作時，它生成的日誌消息是否具有正確的文本。

這兩件事實際上是不同的東西，所以可以單獨測試。然而，測試第二個（短信文本）是有問題的，我建議不要這樣做。對消息文本的測試最終將包括檢查一個文本字符串（預期的消息文本）是否與日誌代碼中使用的文本字符串相同，或者可以平分派生。

• 那些測試根本不測試程序邏輯，它們只測試一個資源（一個字符串）是否等同於另一個資源。
• 測試是脆弱的;即使對日誌消息格式進行了微小的調整也會破壞您的測試。
• 測試與日誌界面的國際化（翻譯）不兼容。測試假定只有一個可能的消息文本，因此只有一種可能的人類語言。

需要注意的是有你的程序代碼（實現一些業務邏輯，也許）直接調用文本記錄界面設計差（但不幸的是非常黎民）。負責業務邏輯的代碼也決定了一些日誌記錄策略和日誌消息的文本。它將業務邏輯與用戶界面代碼混合在一起（是的，日誌消息是程序用戶界面的一部分）。這些東西應該是分開的。

因此，我建議業務邏輯不會直接生成日誌消息文本。而是讓它委託給一個日誌記錄對象。

• 日誌記錄對象的類應該提供一個合適的內部API，您的業務對象可以用它來表示使用域模型對象發生的事件，而不是文本字符串。
• 您的日誌記錄類的實現負責生成這些域對象的文本表示形式，並呈現適當的事件文本描述，然後將該文本消息轉發到低級日誌記錄框架（如JUL，log4j或slf4j） 。
• 您的業務邏輯僅負責調用記錄器類的內部API的正確方法，傳遞正確的域對象以描述發生的實際事件。
• 您的具體日誌記錄類implements和interface，它描述了您的業務邏輯可能使用的內部API。
• 您的實現業務邏輯並且必須執行日誌記錄的類具有對要委派的日誌記錄對象的引用。參考的類別是摘要interface。
• 使用依賴注入來設置對記錄器的引用。

然後，您可以測試你的業務邏輯類正確地講述事件日誌接口，通過創建一個模擬記錄儀，它實現了內部記錄API，並在測試的建立階段使用依賴注入。

像這樣：

public class MyService {// The class we want to test 
    private final MyLogger logger; 

    public MyService(MyLogger logger) { 
     this.logger = Objects.requireNonNull(logger); 
    } 

    public void performTwiddleOperation(Foo foo) {// The method we want to test 
     ...// The business logic 
     logger.performedTwiddleOperation(foo); 
    } 
}; 

public interface MyLogger { 
    public void performedTwiddleOperation(Foo foo); 
    ... 
}; 

public final class MySl4jLogger: implements MyLogger { 
    ... 

    @Override 
    public void performedTwiddleOperation(Foo foo) { 
     logger.info("twiddled foo " + foo.getId()); 
    } 
} 

public final void MyProgram { 
    public static void main(String[] argv) { 
     ... 
     MyLogger logger = new MySl4jLogger(...); 
     MyService service = new MyService(logger); 
     startService(service);// or whatever you must do 
     ... 
    } 
} 

public class MyServiceTest { 
    ... 

    static final class MyMockLogger: implements MyLogger { 
     private Food.id id; 
     private int nCallsPerformedTwiddleOperation; 
     ... 

     @Override 
     public void performedTwiddleOperation(Foo foo) { 
      id = foo.id; 
      ++nCallsPerformedTwiddleOperation; 
     } 

     void assertCalledPerformedTwiddleOperation(Foo.id id) { 
      assertEquals("Called performedTwiddleOperation", 1, nCallsPerformedTwiddleOperation); 
      assertEquals("Called performedTwiddleOperation with correct ID", id, this.id); 
     } 
    }; 

    @Test 
    public void testPerformTwiddleOperation_1() { 
     // Setup 
     MyMockLogger logger = new MyMockLogger(); 
     MyService service = new MyService(logger); 
     Foo.Id id = new Foo.Id(...); 
     Foo foo = new Foo(id, 1); 

     // Execute 
     service.performedTwiddleOperation(foo); 

     // Verify 
     ... 
     logger.assertCalledPerformedTwiddleOperation(id); 
    } 
}