声明:迁移自本人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的源码结构如下
这里写图片描述
分析源码
框架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反编译出来看看就知道了。如下图。
这里写图片描述