声明:迁移自本人CSDN博客https://blog.csdn.net/u013365635

笔者在公司的时候,遇到一个问题,2个模块A、B Tomcat中的catalina.out及catalina.20xx-xx-xx.log的日志会快速膨胀直至把所有的docker容器内的硬盘资源消耗完(考虑到容器内硬盘资源有限,日志存储在额外挂载的一个硬盘中)。

1、问题直接原因
分析其中的catalina日志,发现打印都来自于Spring及A、B模块使用的一个入参校验安全框架C。catalina.out中出现类似如下的日志:
03-Sep-2018 04:11:46.898 INFO [NssLinkCheckThread] org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerMapping.register Mapped “{[/parse-zip.do],methods=[POST]}” onto public void com.xxxxxx.xxx.controller.user.XxxxController.parseZip(javax.servlet.http.HttpServletRequest,javax.servlet.http.HttpServletResponse,org.springframework.ui.ModelMap)
直接原因:框架C和Spring打印日志的时候,使用的具体工厂类都来自commons-logging-1.2.jar中的SimpleLog,这些日志打印到了标准错误,标准错误输出到stdout,stdout重定向到了catalina文件

2、分析及解决过程:
SimpleLog.java关键源码

    protected void write(final StringBuffer buffer) {
System.err.println(buffer.toString());
}

定制的catalina.sh关键源码

    eval $_NOHUP "\"$_RUNJAVA\"" "\"$LOGGING_CONFIG\"" $LOGGING_MANAGER $JAVA_OPTS $CATALINA_OPTS \
-classpath "\"$CLASSPATH\"" \
-Dcatalina.base="\"$CATALINA_BASE\"" \
-Dcatalina.home="\"$CATALINA_HOME\"" \
-Djava.io.tmpdir="\"$CATALINA_TMPDIR\"" \
org.apache.catalina.startup.Bootstrap "$@" start \
>> "$CATALINA_OUT" 2>&1 "&"

因为A、B模块及框架C使用的日志门面是commons-logging,Spring内部使用的日志门面也是commons-logging。此时,最好的做法当然就是直接进入这个日志门面的源码进行分析了。
以下代码为反编译后的,想要原始的含注释的代码可在GitHub上获取。此处代码并不复杂,使用IDEA自带的反编译工具获得的源码分析即可。
或者使用luyten反编译,得到的commons-logging-1.2.jar的源码结构如下
catalina.out日志膨胀问题解决实例,日志门面commons-logging的实践-LMLPHP
分析源码
框架C部分业务自研代码

import org.apache.commons.logging.Log;
import org.apache.commons.logging.LogFactory;
......
private static Log log = LogFactory.getLog(AbstractProcessValidate.class);
......

commons-logging-1.2.jar反编译出的类LogFactory问题定位关键源码如下:

    public static LogFactory getFactory() throws LogConfigurationException {
ClassLoader contextClassLoader = getContextClassLoaderInternal();
if (contextClassLoader == null && isDiagnosticsEnabled()) {
logDiagnostic("Context classloader is null.");
} LogFactory factory = getCachedFactory(contextClassLoader);
if (factory != null) {
return factory;
} else {
if (isDiagnosticsEnabled()) {
logDiagnostic("[LOOKUP] LogFactory implementation requested for the first time for context classloader " + objectId(contextClassLoader));
logHierarchy("[LOOKUP] ", contextClassLoader);
} Properties props = getConfigurationFile(contextClassLoader, "commons-logging.properties");
ClassLoader baseClassLoader = contextClassLoader;
String factoryClass;
if (props != null) {
factoryClass = props.getProperty("use_tccl");
if (factoryClass != null && !Boolean.valueOf(factoryClass)) {
baseClassLoader = thisClassLoader;
}
} if (isDiagnosticsEnabled()) {
logDiagnostic("[LOOKUP] Looking for system property [org.apache.commons.logging.LogFactory] to define the LogFactory subclass to use...");
} try {
factoryClass = getSystemProperty("org.apache.commons.logging.LogFactory", (String)null);
if (factoryClass != null) {
if (isDiagnosticsEnabled()) {
logDiagnostic("[LOOKUP] Creating an instance of LogFactory class '" + factoryClass + "' as specified by system property " + "org.apache.commons.logging.LogFactory");
} factory = newFactory(factoryClass, baseClassLoader, contextClassLoader);
} else if (isDiagnosticsEnabled()) {
logDiagnostic("[LOOKUP] No system property [org.apache.commons.logging.LogFactory] defined.");
}
} catch (SecurityException var9) {
if (isDiagnosticsEnabled()) {
logDiagnostic("[LOOKUP] A security exception occurred while trying to create an instance of the custom factory class: [" + trim(var9.getMessage()) + "]. Trying alternative implementations...");
}
} catch (RuntimeException var10) {
if (isDiagnosticsEnabled()) {
logDiagnostic("[LOOKUP] An exception occurred while trying to create an instance of the custom factory class: [" + trim(var10.getMessage()) + "] as specified by a system property.");
} throw var10;
} String factoryClassName;
if (factory == null) {
if (isDiagnosticsEnabled()) {
logDiagnostic("[LOOKUP] Looking for a resource file of name [META-INF/services/org.apache.commons.logging.LogFactory] to define the LogFactory subclass to use...");
} try {
InputStream is = getResourceAsStream(contextClassLoader, "META-INF/services/org.apache.commons.logging.LogFactory");
if (is != null) {
BufferedReader rd;
try {
rd = new BufferedReader(new InputStreamReader(is, "UTF-8"));
} catch (UnsupportedEncodingException var7) {
rd = new BufferedReader(new InputStreamReader(is));
} factoryClassName = rd.readLine();
rd.close();
if (factoryClassName != null && !"".equals(factoryClassName)) {
if (isDiagnosticsEnabled()) {
logDiagnostic("[LOOKUP] Creating an instance of LogFactory class " + factoryClassName + " as specified by file '" + "META-INF/services/org.apache.commons.logging.LogFactory" + "' which was present in the path of the context classloader.");
} factory = newFactory(factoryClassName, baseClassLoader, contextClassLoader);
}
} else if (isDiagnosticsEnabled()) {
logDiagnostic("[LOOKUP] No resource file with name 'META-INF/services/org.apache.commons.logging.LogFactory' found.");
}
} catch (Exception var8) {
if (isDiagnosticsEnabled()) {
logDiagnostic("[LOOKUP] A security exception occurred while trying to create an instance of the custom factory class: [" + trim(var8.getMessage()) + "]. Trying alternative implementations...");
}
}
} if (factory == null) {
if (props != null) {
if (isDiagnosticsEnabled()) {
logDiagnostic("[LOOKUP] Looking in properties file for entry with key 'org.apache.commons.logging.LogFactory' to define the LogFactory subclass to use...");
} factoryClass = props.getProperty("org.apache.commons.logging.LogFactory");
if (factoryClass != null) {
if (isDiagnosticsEnabled()) {
logDiagnostic("[LOOKUP] Properties file specifies LogFactory subclass '" + factoryClass + "'");
} factory = newFactory(factoryClass, baseClassLoader, contextClassLoader);
} else if (isDiagnosticsEnabled()) {
logDiagnostic("[LOOKUP] Properties file has no entry specifying LogFactory subclass.");
}
} else if (isDiagnosticsEnabled()) {
logDiagnostic("[LOOKUP] No properties file available to determine LogFactory subclass from..");
}
} if (factory == null) {
if (isDiagnosticsEnabled()) {
logDiagnostic("[LOOKUP] Loading the default LogFactory implementation 'org.apache.commons.logging.impl.LogFactoryImpl' via the same classloader that loaded this LogFactory class (ie not looking in the context classloader).");
} factory = newFactory("org.apache.commons.logging.impl.LogFactoryImpl", thisClassLoader, contextClassLoader);
} if (factory != null) {
cacheFactory(contextClassLoader, factory);
if (props != null) {
Enumeration names = props.propertyNames(); while(names.hasMoreElements()) {
String name = (String)names.nextElement();
factoryClassName = props.getProperty(name);
factory.setAttribute(name, factoryClassName);
}
}
} return factory;
}
}

源码面前,了无秘密。从这段源码能看出从LogFactory中获取具体日志工厂类实现的顺序,逻辑顺序如下:
step1:
Properties props = getConfigurationFile(contextClassLoader, “commons-logging.properties”);
从属性配置文件commons-logging.properties中读取属性信息
step2:
factoryClass = getSystemProperty(“org.apache.commons.logging.LogFactory”, (String)null);
通过JVM设置的属性值(通常在catalina.sh等脚本中设置)决定使用哪个具体工厂类实例化factory
step3:
InputStream is = getResourceAsStream(contextClassLoader, “META-INF/services/org.apache.commons.logging.LogFactory”);
读取配置文件中设置的值决定使用哪个具体工厂类实例化factory
step4:
factoryClass = props.getProperty(“org.apache.commons.logging.LogFactory”);
根据step1中获取到的props配置的org.apache.commons.logging.LogFactory属性值决定使用哪个具体工厂类实例化factory
step5:
factory = newFactory(“org.apache.commons.logging.impl.LogFactoryImpl”, thisClassLoader, contextClassLoader);
使用LogFactoryImpl中实现的具体工厂类实例化factory,LogFactoryImpl内部涉及多种具体工厂的实现类
以上实例化factory的过程,只要一个实例化成功了,后面的就不再执行了。所以commons-logging门面能灵活地实现使用哪种日志系统。
接着上面step5的LogFactoryImpl讨论,LogFactoryImpl要具体将factory实例化为 “org.apache.commons.logging.impl.Log4JLogger”, “org.apache.commons.logging.impl.Jdk14Logger”, “org.apache.commons.logging.impl.Jdk13LumberjackLogger”, “org.apache.commons.logging.impl.SimpleLog”,”org.apache.commons.logging.impl.NoOpLog” 等中的某一个,关键的决定具体工厂类的函数如下:

    private String findUserSpecifiedLogClassName() {
if (isDiagnosticsEnabled()) {
this.logDiagnostic("Trying to get log class from attribute 'org.apache.commons.logging.Log'");
} String specifiedClass = (String)this.getAttribute("org.apache.commons.logging.Log");
if (specifiedClass == null) {
if (isDiagnosticsEnabled()) {
this.logDiagnostic("Trying to get log class from attribute 'org.apache.commons.logging.log'");
} specifiedClass = (String)this.getAttribute("org.apache.commons.logging.log");
} if (specifiedClass == null) {
if (isDiagnosticsEnabled()) {
this.logDiagnostic("Trying to get log class from system property 'org.apache.commons.logging.Log'");
} try {
specifiedClass = getSystemProperty("org.apache.commons.logging.Log", (String)null);
} catch (SecurityException var4) {
if (isDiagnosticsEnabled()) {
this.logDiagnostic("No access allowed to system property 'org.apache.commons.logging.Log' - " + var4.getMessage());
}
}
} if (specifiedClass == null) {
if (isDiagnosticsEnabled()) {
this.logDiagnostic("Trying to get log class from system property 'org.apache.commons.logging.log'");
} try {
specifiedClass = getSystemProperty("org.apache.commons.logging.log", (String)null);
} catch (SecurityException var3) {
if (isDiagnosticsEnabled()) {
this.logDiagnostic("No access allowed to system property 'org.apache.commons.logging.log' - " + var3.getMessage());
}
}
} if (specifiedClass != null) {
specifiedClass = specifiedClass.trim();
} return specifiedClass;
}

依次试图从变量protected Hashtable attributes = new Hashtable();、环境变量org.apache.commons.logging.Log/org.apache.commons.logging.log中获取属性值决定实例化factory为哪个具体工厂类。
String specifiedClass = (String)this.getAttribute(“org.apache.commons.logging.Log”);
specifiedClass = (String)this.getAttribute(“org.apache.commons.logging.log”);
specifiedClass = getSystemProperty(“org.apache.commons.logging.Log”, (String)null);
specifiedClass = getSystemProperty(“org.apache.commons.logging.log”, (String)null);

3、解决方法
相信有了以上的分析,读者在遇到相似问题的时候,知道怎么去处理了吧。只需要跟着以上各阶段的属性值,配置一个适合自己生产环境的。这过程要考虑到设置属性值的阶段(比如step1~step5中的哪一个)、具体需要的具体工厂类等。
结合笔者生产环境中使用的环境变量,解决方法:catalina.sh设置JVM环境变量 -Dorg.apache.commons.logging.Log=org.apache.commons.logging.impl.NoOpLog即可阻止使用commons-logging的组件的日志打印,且不影响使用slf4j日志门面的组件的日志打印。选择这个属性值设置的原因是这是最后一个有影响的属性值,设置该值不对更早阶段的属性设置有影响。
同时有了上面的分析,应该不难理解为什么加入jcl-over-slf4j-1.6.1.jar这个jar包就能将框架C的日志打印到运行日志了吧,还不明白的话,把jcl-over-slf4j-1.6.1.jar反编译出来看看就知道了。如下图。
catalina.out日志膨胀问题解决实例,日志门面commons-logging的实践-LMLPHP

05-28 19:32