如何解决 log4j2 滚动文件附加程序触发时引发的异常？答案

【问题标题】：How to resolve exception(s) thrown when log4j2 rolling file appender triggers?如何解决 log4j2 滚动文件附加程序触发时引发的异常？
【发布时间】：2017-03-10 11:16:26
【问题描述】：

日志似乎可以正常翻转和存档，但在指定的触发时间或附近，我注意到 tomcat catalina.out 中出现异常（有时一次，有时它以 1/秒的速度淹没日志）。任何帮助表示赞赏。

执行环境：

Tomcat 版本：Apache Tomcat/8.5.3
JVM 版本：1.8.0_92-b14
JVM 供应商：甲骨文公司
操作系统名称：Linux
操作系统版本：2.6.32-642.3.1.el6.x86_64
操作系统架构：amd64

组装的 WAR 似乎在 WEB-INF/lib 中有适当的 jar，包括：

log4j-api-2.6.2.jar
log4j-core-2.6.2.jar
log4j-slf4j-impl-2.6.2.jar
log4j-web-2.6.2.jar

例外：

2016-10-27 16:11:24,002 Log4j2-Log4j2Scheduled-2 ERROR Error running command java.lang.NoClassDefFoundError: org/apache/logging/log4j/core/impl/Log4jLogEvent$Builder
        at org.apache.logging.log4j.core.appender.rolling.PatternProcessor.formatFileName(PatternProcessor.java:234)
        at org.apache.logging.log4j.core.appender.rolling.DefaultRolloverStrategy.purgeAscending(DefaultRolloverStrategy.java:323)
        at org.apache.logging.log4j.core.appender.rolling.DefaultRolloverStrategy.purge(DefaultRolloverStrategy.java:306)
        at org.apache.logging.log4j.core.appender.rolling.DefaultRolloverStrategy.rollover(DefaultRolloverStrategy.java:524)
        at org.apache.logging.log4j.core.appender.rolling.RollingFileManager.rollover(RollingFileManager.java:220)
        at org.apache.logging.log4j.core.appender.rolling.RollingFileManager.rollover(RollingFileManager.java:155)
        at org.apache.logging.log4j.core.appender.rolling.CronTriggeringPolicy.rollover(CronTriggeringPolicy.java:127)
        at org.apache.logging.log4j.core.appender.rolling.CronTriggeringPolicy.access$100(CronTriggeringPolicy.java:40)
        at org.apache.logging.log4j.core.appender.rolling.CronTriggeringPolicy$CronTrigger.run(CronTriggeringPolicy.java:144)
        at org.apache.logging.log4j.core.config.ConfigurationScheduler$CronRunnable.run(ConfigurationScheduler.java:180)
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
        at java.util.concurrent.FutureTask.run(FutureTask.java:266)
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
        at java.lang.Thread.run(Thread.java:745)

异常2：

The web application [my-services] appears to have started a thread named [Log4j2-Log4j2Scheduled-1] but has failed to stop it. This is very likely to create a memory leak. Stack trace of thread:
 sun.misc.Unsafe.park(Native Method)
 java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
 java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078)
 java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1093)
 java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:809)
 java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1067)
 java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
 java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
 java.lang.Thread.run(Thread.java:745)

log4j2.xml

<?xml version="1.0" encoding="UTF-8"?>
<Configuration status="info" name="MyLog" packages="">
  <Properties>
    <Property name="baseDir">/var/log/tomcat</Property>
    <Property name="appName">MyLog</Property>
  </Properties>
  <Appenders>
    <RollingFile name="RollingFile" fileName="${baseDir}/${appName}.log" immediateFlush="true"
      filePattern="${baseDir}/$${date:yyyy}/$${date:MM}/${appName}-$${date:yyyy-MM-dd}-%i.log.gz">
      <PatternLayout pattern="%highlight{%d %p{INFO=INFO_,WARN=WARN_} %c{3.} (%M:%L) [%t] %m%n%ex}{FATAL=Magenta,TRACE=Normal White}" />
      <CronTriggeringPolicy schedule="0 0 0 * * ?"/>
      <DefaultRolloverStrategy>
        <Delete basePath="${baseDir}" maxDepth="2">
          <IfFileName glob="*/${appName}-*log.gz" />
          <IfLastModified age="90d" />
        </Delete>
      </DefaultRolloverStrategy>
    </RollingFile>
    <Console name="Console" target="SYSTEM_OUT">
      <PatternLayout pattern="%highlight{%d %p{INFO=INFO_,WARN=WARN_} %c{3.} (%M:%L) [%t] %m%n%ex}{FATAL=Magenta,TRACE=Normal White}" />
    </Console>
  </Appenders>
  <Loggers>
    <Root level="INFO">
      <AppenderRef ref="RollingFile"/>
      <!--<AppenderRef ref="Console"/>-->
    </Root>
  </Loggers>
</Configuration>

web.xml

<?xml version="1.0" encoding="UTF-8"?>
<web-app version="3.1">
    <display-name>My Services</display-name>

    <!-- log4j2 configuration file -->
    <context-param>
        <param-name>log4jConfiguration</param-name>
        <param-value>log4j2.xml</param-value>
    </context-param>

    <!-- my servlet -->
    <servlet>
        <servlet-name>my-services</servlet-name>
        <servlet-class>org.glassfish.jersey.servlet.ServletContainer</servlet-class>
        <init-param>
            <param-name>jersey.config.server.provider.packages</param-name>
            <param-value>my.package, com.fasterxml.jackson.jaxrs.json</param-value>
        </init-param>
        <load-on-startup>1</load-on-startup>
    </servlet>
    <servlet-mapping>
        <servlet-name>my-services</servlet-name>
        <url-pattern>/rest/*</url-pattern>
    </servlet-mapping>

</web-app>

pom.xml 依赖：

<properties>
    <maven.compiler.source>1.8</maven.compiler.source>
    <maven.compiler.target>1.8</maven.compiler.target>
    <project.build.sourceEncoding>UTF-8</project.build.sourceEncoding>
    <project.reporting.outputEncoding>UTF-8</project.reporting.outputEncoding>

    <!-- version properties -->
    <jersey.version>2.23.1</jersey.version>
    <jackson.version>2.7.2</jackson.version>
    <spring.version>4.1.6.RELEASE</spring.version>
</properties>

<dependencyManagement>
    <dependencies>
        <!-- Spring -->
        <dependency>
            <groupId>org.springframework</groupId>
            <artifactId>spring-framework-bom</artifactId>
            <version>${spring.version}</version>
            <type>pom</type>
            <scope>import</scope>
        </dependency>
        <!-- Logging -->
        <dependency>
            <groupId>org.apache.logging.log4j</groupId>
            <artifactId>log4j-bom</artifactId>
            <version>2.6.2</version>
            <scope>import</scope>
            <type>pom</type>
        </dependency>
        <!-- Jersey and Jackson -->
        <dependency>
            <groupId>javax.servlet</groupId>
            <artifactId>javax.servlet-api</artifactId>
            <version>3.1.0</version>
            <scope>provided</scope>
        </dependency>
        <dependency>
            <groupId>org.glassfish.jersey.containers</groupId>
            <artifactId>jersey-container-servlet-core</artifactId>
            <version>${jersey.version}</version>
        </dependency>
        <dependency>
            <groupId>org.glassfish.jersey.containers</groupId>
            <artifactId>jersey-container-servlet</artifactId>
            <version>${jersey.version}</version>
        </dependency>
        <dependency>
            <groupId>com.fasterxml.jackson.core</groupId>
            <artifactId>jackson-databind</artifactId>
            <version>${jackson.version}</version>
        </dependency>
        <dependency>
            <groupId>com.fasterxml.jackson.jaxrs</groupId>
            <artifactId>jackson-jaxrs-json-provider</artifactId>
            <version>${jackson.version}</version>
        </dependency>
    </dependencies>
</dependencyManagement>

<dependencies>
    <!-- spring framework -->
    <dependency>
        <groupId>org.springframework</groupId>
        <artifactId>spring-core</artifactId>
    </dependency>
    <dependency>
        <groupId>org.springframework</groupId>
        <artifactId>spring-context</artifactId>
    </dependency>

    <!-- Jersey w/Tomcat 8 -->
    <dependency>
        <groupId>javax.servlet</groupId>
        <artifactId>javax.servlet-api</artifactId>
        <scope>provided</scope>
    </dependency>
    <dependency>
        <groupId>org.glassfish.jersey.containers</groupId>
        <artifactId>jersey-container-servlet-core</artifactId>
    </dependency>
    <dependency>
        <groupId>org.glassfish.jersey.containers</groupId>
        <artifactId>jersey-container-servlet</artifactId>
    </dependency>
    <dependency>
        <groupId>com.fasterxml.jackson.core</groupId>
        <artifactId>jackson-databind</artifactId>
    </dependency>
    <dependency>
        <groupId>com.fasterxml.jackson.jaxrs</groupId>
        <artifactId>jackson-jaxrs-json-provider</artifactId>
    </dependency>

    <!-- Logging -->
    <dependency>
        <groupId>org.apache.logging.log4j</groupId>
        <artifactId>log4j-api</artifactId>
    </dependency>
    <dependency>
        <groupId>org.apache.logging.log4j</groupId>
        <artifactId>log4j-core</artifactId>
    </dependency>
    <dependency>
        <groupId>org.apache.logging.log4j</groupId>
        <artifactId>log4j-web</artifactId>
        <scope>runtime</scope>
    </dependency>
    <dependency>
        <groupId>org.apache.logging.log4j</groupId>
        <artifactId>log4j-slf4j-impl</artifactId>
    </dependency>
</dependencies>

【问题讨论】：

从 Tomcat Catalina Engine 中注意到一个可能相关的异常，并将其包含在问题详细信息中。

标签： log4j2 tomcat8

【解决方案1】：

当 Tomcat webapps 关闭时，有一个带有 lo4j2 2.6.2 的 known issue 泄漏线程。我怀疑您看到 ClassNotFoundExceptions 因为孤立线程正在尝试加载类。这很可能是因为您使用CronTriggeringPolicy 强制在午夜滚动日志，但在该策略执行之前重新启动您的 web 应用程序。

已在 lo4j2 2.7 中发布了修复程序。尝试提升你的版本。

【讨论】：

【解决方案2】：

我怀疑您的 Tomcat 服务器 lib 文件夹中有旧版本的 log4j 2。

如果您在网络应用中执行此操作，您会看到什么？这应该告诉您从哪个 jar Log4jLogEvent 加载。

System.out.println(
    Log4jLogEvent.class.getResource( 
        "/org/apache/logging/log4j/core/impl/Log4jLogEvent.class"));

【讨论】：

jar:file:/usr/share/apache-tomcat-8.5.3/webapps/liveservices/WEB-INF/lib/log4j-core-2.6.2.jar!/org/apache/日志记录/log4j/core/impl/Log4jLogEvent.class
如果你用 WinZip 或其他东西查看那个 jar，它是否包含 Log4jLogEvent$Builder 类？
是的，它就在那里。
不知道如何获得 NoClassDefFoundError... 你知道这个错误是什么时候发生的吗？应用是否重新加载？
似乎在日志翻转时发生，现在由 cron 触发策略控制（每天午夜）。总是至少看到一次这个错误，偶尔它会喷出 1/秒。如果我遇到这种情况，我必须重新启动 tomcat 才能阻止它。