Tomcat catalina.out出现大量意外DEBUG日志的问题咨询

问题描述 #

使用Tomcat 8.0.30时，catalina.out中记录了大量org.apache.activemq.ActiveMQSession的DEBUG日志，这些日志未输出到应用配置的service.log，而是出现在容器日志中。尽管在log4j.xml已将org.apache包的日志级别设置为WARN，但这类DEBUG日志仍持续生成。

相关日志片段 #

07:00:17.729 [queue://company.generic.local-6] DEBUG org.apache.activemq.ActiveMQSession - ID:us03dv4vafpc01.ilnx.com-36014-1659188569211-3:1:9 Transaction Commit :null
07:00:17.728 [queue://company.generic.local-4] DEBUG org.apache.activemq.ActiveMQSession - ID:us03dv4vafpc01.ilnx.com-36014-1659188569211-3:1:7 Transaction Commit :null
07:00:17.729 [queue://company.generic.local-8] DEBUG org.apache.activemq.ActiveMQSession - ID:us03dv4vafpc01.ilnx.com-36014-1659188569211-3:1:10 Transaction Commit :null
... 12 lines omitted ...
07:00:19.318 [queue://company.generic.local-9] DEBUG org.apache.activemq.ActiveMQSession - ID:us03dv4vafpc01.ilnx.com-36014-1659188569211-3:1:3 Transaction Commit :null
... 236 lines omitted ...
07:00:19.729 [queue://company.generic.local-2] DEBUG org.apache.activemq.ActiveMQSession - ID:us03dv4vafpc01.ilnx.com-36014-1659188569211-3:1:5 Transaction Commit :null

启动脚本片段 #

CATALINA_HOME=${CATALINA_HOME:-/opt/tomcat8
CATALINA_BASE=${CATALINA_BASE:-/opt/${SERVICE}}
CATALINA_OUT=${CATALINA_OUT:-/var/log/catalina.out}
export CATALINA_HOME CATALINA_BASE CATALINA_OUT
CATALINA_OPT="CATALINA_OPT -Dlog4j.configuration=file:/opt/log4j.xml"
export CATALINA_OPT

exec &>> ${CATALINA_OUT}
...
EXECUTABLE="$CATALINA_HOME/bin/catalina.sh"
nohup "$EXECUTABLE" run -XX:OnOutOfMemoryError="kill -9 %p"

log4j.xml配置片段 #

<?xml version="1.0" encoding="UTF-8"?>
<!DOCTYPE log4j:configuration SYSTEM "log4j.dtd">
<log4j:configuration xmlns:log4j="http://jakarta.apache.org/log4j/">
<appender class="org.apache.log4j.RollingFileAppender" name="file">
    <param name="File" value="/var/log/service.log"/>
    <layout class="org.apache.log4j.EnhancedPatternLayout">
      ....
    </layout>
  </appender> 

  <logger name="org.apache">
    <level value="warn"/>
  </logger>
  <root>
    <priority value="warn"/>
    <appender-ref ref="file"/>
  </root>
</log4j:configuration>

原因分析 #

1. 启动参数错误：脚本中使用了CATALINA_OPT而非正确的CATALINA_OPTS，且参数拼接方式错误（CATALINA_OPT="CATALINA_OPT -D..."会导致参数值变成字符串"CATALINA_OPT -D..."，而非追加参数），导致应用未正确加载指定的log4j配置。
2. 日志输出重定向：exec &>> ${CATALINA_OUT}将进程的所有标准输出和标准错误都重定向到catalina.out，如果ActiveMQ直接使用System.out/System.err输出日志，会绕过应用的log4j配置直接写入该文件。
3. Tomcat内置日志框架冲突：Tomcat默认使用JULI（Java Util Logging的扩展）作为日志组件，ActiveMQ的日志可能被JULI接管，而非应用的log4j，此时应用的log4j配置无法控制这部分日志。
4. ActiveMQ自身日志配置优先级：ActiveMQ可能自带日志配置文件（如jar包内的log4j.properties），其优先级高于应用外部指定的log4j配置，导致应用的级别设置不生效。

解决方法 #

1. 修正启动参数 #

将启动脚本中的CATALINA_OPT改为CATALINA_OPTS，并正确拼接参数：

CATALINA_OPTS="$CATALINA_OPTS -Dlog4j.configuration=file:/opt/log4j.xml"
export CATALINA_OPTS

确保Tomcat启动时能正确加载应用的log4j配置。

2. 控制Tomcat的JULI日志 #

编辑Tomcat的conf/logging.properties文件，添加以下配置来限制ActiveMQ的日志级别：

org.apache.activemq.level = WARN
org.apache.activemq.handlers = java.util.logging.FileHandler

这会让Tomcat的内置日志框架将ActiveMQ的日志级别设为WARN，避免DEBUG日志输出。

3. 精确配置log4j中的ActiveMQ日志 #

在应用的log4j.xml中，针对org.apache.activemq单独配置日志级别，比全局的org.apache更精确：

<logger name="org.apache.activemq">
  <level value="warn"/>
  <appender-ref ref="file"/>
</logger>

确保ActiveMQ的日志被应用的log4j接管并输出到指定的service.log，同时屏蔽DEBUG级别。

4. 移除不必要的输出重定向 #

启动脚本中的exec &>> ${CATALINA_OUT}会额外将所有控制台输出写入catalina.out，而catalina.sh本身已经会处理Tomcat的日志输出。如果不需要这部分额外重定向，可以移除该语句，避免重复日志或无关日志进入catalina.out。

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