为何测试中添加的Appender日志事件级别从ERROR变为OFF？

我知道断言被测单元的日志语句并非良好实践，但仍编写了如下测试代码。执行后发现添加的Appender上的日志事件级别从ERROR变为OFF，出现断言错误：预期级别为OFF，但实际为ERROR，请问原因是什么？

被测单元代码 #

package sample;

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

public class App {
   private static Logger logger = LoggerFactory.getLogger(App.class);

   public void doSomething() {
      logger.error("Cannot do something");
   }
}

测试代码 #

package sample;

import org.apache.logging.log4j.Level;
import org.apache.logging.log4j.LogManager;
import org.apache.logging.log4j.core.Appender;
import org.apache.logging.log4j.core.LogEvent;
import org.apache.logging.log4j.core.Logger;
import org.junit.jupiter.api.Test;
import org.mockito.ArgumentCaptor;
import static org.junit.jupiter.api.Assertions.assertEquals;
import static org.mockito.Mockito.*;

public class TestApp {

  @Test
  public void testDoSomething() {
    App app = new App();

    Appender mockedAppender = mock(Appender.class);
    when(mockedAppender.getName()).thenReturn("MockAppender");
    when(mockedAppender.isStarted()).thenReturn(true);
    when(mockedAppender.isStopped()).thenReturn(false);
    ArgumentCaptor<LogEvent>  logEventCaptor = ArgumentCaptor.forClass(LogEvent.class);
    Logger appLogger = (Logger)LogManager.getLogger(App.class);
    appLogger.addAppender(mockedAppender);
    app.doSomething();

    verify(mockedAppender).append(logEventCaptor.capture());
    LogEvent logEvent = logEventCaptor.getValue();
    assertEquals(logEvent.getLevel(), Level.ERROR);

    appLogger.removeAppender(mockedAppender);
  }
}

错误信息 #

expected: <OFF> but was: <ERROR>
Expected :OFF
Actual   :ERROR
<Click to see difference>

org.opentest4j.AssertionFailedError: expected: <OFF> but was: <ERROR>
    at org.junit.jupiter.api.Assertions.fail(Assertions.java:55)
    at org.junit.jupiter.api.Assertions.failNotEqual(Assertions.java:62)
    at org.junit.jupiter.api.AssertEquals.assertEquals(AssertEquals.java:182)
    at org.junit.jupiter.api.AssertEquals.assertEquals(AssertEquals.java:177)

核心原因 #

问题根源在于Log4j的LogEvent对象采用池化复用机制。为了提升性能，Log4j会使用ReusableLogEvent这类可复用的事件对象，当日志事件处理完成后，框架会自动重置该对象的所有属性（包括将级别设置为OFF）。你在verify操作后再获取捕获的LogEvent时，原有的ERROR级别已经被重置，但测试断言逻辑却拿到了被重置后的OFF值，导致断言结果与实际日志发出时的状态矛盾。

另外注意：错误信息显示预期为OFF、实际为ERROR，这说明你的测试代码中可能存在断言顺序写反的情况（比如误写为assertEquals(Level.OFF, logEvent.getLevel())），但核心问题仍是LogEvent的复用重置。

解决方案 #

要解决这个问题，关键是在LogEvent被重置前，保存好需要验证的属性值，或者用不可变对象封装原始事件状态：

方案1：立即提取目标属性 #

在捕获LogEvent后，立刻提取需要验证的级别（或其他属性），避免后续被框架重置：

verify(mockedAppender).append(logEventCaptor.capture());
// 立即获取级别，保存原始状态
Level capturedLevel = logEventCaptor.getValue().getLevel();
// 断言实际日志级别为ERROR
assertEquals(Level.ERROR, capturedLevel);

方案2：用ImmutableLogEvent封装原始事件 #

使用Log4j提供的ImmutableLogEvent将捕获的事件包装为不可变对象，永久保留原始事件的所有属性：

import org.apache.logging.log4j.core.impl.ImmutableLogEvent;

// ...

verify(mockedAppender).append(logEventCaptor.capture());
// 封装为不可变对象，避免后续被重置
LogEvent immutableEvent = new ImmutableLogEvent(logEventCaptor.getValue());
assertEquals(Level.ERROR, immutableEvent.getLevel());

额外提示 #

• Log4j的对象池化复用是性能优化的设计，并非bug，测试时需要适配这种机制。
• 若频繁需要测试日志行为，建议使用专门的日志测试库（如log4j-testing、slf4j-test），这类库已经封装了事件状态保存的逻辑，能简化测试代码。

内容的提问来源于stack exchange，提问作者user3477071