java传统web项目添加maven管理jar包,log4j无法正常输出日志

本文适合1年以上编程基础的开发人员阅读，非技术创新，可作为故障排除实录参考/收藏。

背景

　　笔者最近在给公司一个老的web项目改造升级，项目使用springmvc+mybatis，由于项目比较久远，没有使用maven管理jar版本，有可能是当时开发任务比较紧迫，不同的同事在不同的时期放入了jar版本各不相同，

看到那么多混乱的jar，真是操心。笔者曾花了大概半个下午的时间，把jar版本整理好，编入pom.xml中,从那个时候，笔者本地项目的jar版本算是交给maven托管了，顿时间心里舒畅了一会儿，心里也计划着和项目组大

家一起统一使用maven管控jar版本混乱的问题。可是事实有时候并不会常常如人所愿。就在部署web项目的时候，问题来了：控制台那么多可爱的日志怎么变少了呢？

原来正常的时候，日志输出大概如下：

而当笔者部署web项目到servlet容器（tomcat）中，问题来了，日志少的捉襟见肘，怎么也难应付平时的项目开发啊，开发测试过程中，怎么能少的了日志。

如此一来，这个maven上的有点让人措手不及，这不有点像邯郸学步，顾着把项目列入现代化管理方式，却失去了初衷：日志功能淡化，开发调试难度增加。

排错过程

本地日志输入代码如下：

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import com.xxx.system.auth.User;
/***
 * 权限校验类
 */

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

    public static void check(HttpSession session)
   {
        User user = (User)session.getAttribute("userData");
       if (user == null) {
        if(logger.isDebugEnabled())
        logger.debug("当前用户session无效!");
        return false;
    }

   }
}

笔者按： 代码片段中使用了slf4j框架，slf4j是一个优秀的slf4j框架，他使用了适配器设计模式，由他来屏蔽不同日志框架的差异性，实现与不同日志框架的协作。

 

　　以上一段简单的代码，在项目中不同地方高频次的调用，却一直不见控制台有日志输出，笔者起初以为是ide在作祟，各种更改ide配置也无效，

把编译好的项目单独放到servlet容器tomcat中，仍不凑效，即便捶胸顿足也无计可施，以上说明问题的根源不是ide，也不是servlet容器，这可憋坏了笔者。

解决方法

log4j一般性的用法如下：

import org.apache.log4j.Logger;
import org.apache.log4j.PropertyConfigurator;

public class LogTest {
    static Logger logger = Logger.getLogger(LogTest.class.getName());

    public static void main(String[] args) {
        PropertyConfigurator.configure("src/log4j.properties");
        logger.debug("Debug ...");
        logger.info("Info ...");
        logger.warn("Warn ...");
        logger.error("Error ...");
    }

}

按图索骥，通过追踪Logger.getLogger源码，在我们面前呈现出一个类LogManager

static
  public
  Logger getLogger(String name) {
    return LogManager.getLogger(name);
  }

Log4jManager代码如下：

package org.apache.log4j;

import org.apache.log4j.spi.LoggerRepository;
import org.apache.log4j.spi.LoggerFactory;
import org.apache.log4j.spi.RepositorySelector;
import org.apache.log4j.spi.DefaultRepositorySelector;
import org.apache.log4j.spi.RootLogger;
import org.apache.log4j.spi.NOPLoggerRepository;
import org.apache.log4j.helpers.Loader;
import org.apache.log4j.helpers.OptionConverter;
import org.apache.log4j.helpers.LogLog;

import java.net.URL;
import java.net.MalformedURLException;

import java.util.Enumeration;
import java.io.StringWriter;
import java.io.PrintWriter;

/**
 * Use the <code>LogManager</code> class to retreive {@link Logger}
 * instances or to operate on the current {@link
 * LoggerRepository}. When the <code>LogManager</code> class is loaded
 * into memory the default initalzation procedure is inititated. The
 * default intialization procedure</a> is described in the <a
 * href="../../../../manual.html#defaultInit">short log4j manual</a>.
 *
 * @author Ceki G&uuml;lc&uuml;
 */
public class LogManager {

    /**
     * @deprecated This variable is for internal use only. It will
     * become package protected in future versions.
     */
    static public final String DEFAULT_CONFIGURATION_FILE = "log4j.properties";

    static final String DEFAULT_XML_CONFIGURATION_FILE = "log4j.xml";

    /**
     * @deprecated This variable is for internal use only. It will
     * become private in future versions.
     */
    static final public String DEFAULT_CONFIGURATION_KEY = "log4j.configuration";

    /**
     * @deprecated This variable is for internal use only. It will
     * become private in future versions.
     */
    static final public String CONFIGURATOR_CLASS_KEY = "log4j.configuratorClass";

    /**
     * @deprecated This variable is for internal use only. It will
     * become private in future versions.
     */
    public static final String DEFAULT_INIT_OVERRIDE_KEY =
            "log4j.defaultInitOverride";

    static private Object guard = null;
    static private RepositorySelector repositorySelector;

    static {
        // By default we use a DefaultRepositorySelector which always returns 'h'.
        Hierarchy h = new Hierarchy(new RootLogger((Level) Level.DEBUG));
        repositorySelector = new DefaultRepositorySelector(h);

        /** Search for the properties file log4j.properties in the CLASSPATH.  */
        String override = OptionConverter.getSystemProperty(DEFAULT_INIT_OVERRIDE_KEY,
                null);

        // if there is no default init override, then get the resource
        // specified by the user or the default config file.
        if (override == null || "false".equalsIgnoreCase(override)) {

            String configurationOptionStr = OptionConverter.getSystemProperty(
                    DEFAULT_CONFIGURATION_KEY,
                    null);

            String configuratorClassName = OptionConverter.getSystemProperty(
                    CONFIGURATOR_CLASS_KEY,
                    null);

            URL url = null;

            // if the user has not specified the log4j.configuration
            // property, we search first for the file "log4j.xml" and then
            // "log4j.properties"
            if (configurationOptionStr == null) {
                url = Loader.getResource(DEFAULT_XML_CONFIGURATION_FILE);
                if (url == null) {
                    url = Loader.getResource(DEFAULT_CONFIGURATION_FILE);
                }
            } else {
                try {
                    url = new URL(configurationOptionStr);
                } catch (MalformedURLException ex) {
                    // so, resource is not a URL:
                    // attempt to get the resource from the class path
                    url = Loader.getResource(configurationOptionStr);
                }
            }

            // If we have a non-null url, then delegate the rest of the
            // configuration to the OptionConverter.selectAndConfigure
            // method.
            if (url != null) {
                LogLog.debug("Using URL [" + url + "] for automatic log4j configuration.");
                try {
                    OptionConverter.selectAndConfigure(url, configuratorClassName,
                            LogManager.getLoggerRepository());
                } catch (NoClassDefFoundError e) {
                    LogLog.warn("Error during default initialization", e);
                }
            } else {
                LogLog.debug("Could not find resource: [" + configurationOptionStr + "].");
            }
        } else {
            LogLog.debug("Default initialization of overridden by " +
                    DEFAULT_INIT_OVERRIDE_KEY + "property.");
        }
    }

    /**
     * Sets <code>LoggerFactory</code> but only if the correct
     * <em>guard</em> is passed as parameter.
     *
     * <p>Initally the guard is null.  If the guard is
     * <code>null</code>, then invoking this method sets the logger
     * factory and the guard. Following invocations will throw a {@link
     * IllegalArgumentException}, unless the previously set
     * <code>guard</code> is passed as the second parameter.
     *
     * <p>This allows a high-level component to set the {@link
     * RepositorySelector} used by the <code>LogManager</code>.
     *
     * <p>For example, when tomcat starts it will be able to install its
     * own repository selector. However, if and when Tomcat is embedded
     * within JBoss, then JBoss will install its own repository selector
     * and Tomcat will use the repository selector set by its container,
     * JBoss.
     */
    static
    public void setRepositorySelector(RepositorySelector selector, Object guard)
            throws IllegalArgumentException {
        if ((LogManager.guard != null) && (LogManager.guard != guard)) {
            throw new IllegalArgumentException(
                    "Attempted to reset the LoggerFactory without possessing the guard.");
        }

        if (selector == null) {
            throw new IllegalArgumentException("RepositorySelector must be non-null.");
        }

        LogManager.guard = guard;
        LogManager.repositorySelector = selector;
    }

    /**
     * This method tests if called from a method that
     * is known to result in class members being abnormally
     * set to null but is assumed to be harmless since the
     * all classes are in the process of being unloaded.
     *
     * @param ex exception used to determine calling stack.
     * @return true if calling stack is recognized as likely safe.
     */
    private static boolean isLikelySafeScenario(final Exception ex) {
        StringWriter stringWriter = new StringWriter();
        ex.printStackTrace(new PrintWriter(stringWriter));
        String msg = stringWriter.toString();
        return msg.indexOf("org.apache.catalina.loader.WebappClassLoader.stop") != -1;
    }

    static
    public LoggerRepository getLoggerRepository() {
        if (repositorySelector == null) {
            repositorySelector = new DefaultRepositorySelector(new NOPLoggerRepository());
            guard = null;
            Exception ex = new IllegalStateException("Class invariant violation");
            String msg =
                    "log4j called after unloading, see http://logging.apache.org/log4j/1.2/faq.html#unload.";
            if (isLikelySafeScenario(ex)) {
                LogLog.debug(msg, ex);
            } else {
                LogLog.error(msg, ex);
            }
        }
        return repositorySelector.getLoggerRepository();
    }

    /**
     * Retrieve the appropriate root logger.
     */
    public
    static Logger getRootLogger() {
        // Delegate the actual manufacturing of the logger to the logger repository.
        return getLoggerRepository().getRootLogger();
    }

    /**
     * Retrieve the appropriate {@link Logger} instance.
     */
    public
    static Logger getLogger(final String name) {
        // Delegate the actual manufacturing of the logger to the logger repository.
        return getLoggerRepository().getLogger(name);
    }

    /**
     * Retrieve the appropriate {@link Logger} instance.
     */
    public
    static Logger getLogger(final Class clazz) {
        // Delegate the actual manufacturing of the logger to the logger repository.
        return getLoggerRepository().getLogger(clazz.getName());
    }

    /**
     * Retrieve the appropriate {@link Logger} instance.
     */
    public
    static Logger getLogger(final String name, final LoggerFactory factory) {
        // Delegate the actual manufacturing of the logger to the logger repository.
        return getLoggerRepository().getLogger(name, factory);
    }

    public
    static Logger exists(final String name) {
        return getLoggerRepository().exists(name);
    }

    public
    static Enumeration getCurrentLoggers() {
        return getLoggerRepository().getCurrentLoggers();
    }

    public
    static void shutdown() {
        getLoggerRepository().shutdown();
    }

    public
    static void resetConfiguration() {
        getLoggerRepository().resetConfiguration();
    }
}

　　笔者本地使用log4j-1.2.16，通过阅读静态域代码了解到，log4j寻找配置文件顺序如下

1、检测当前JVM是否配置log4j.configuration属性，如果有，加载对应的配置文件，也就是说，你可以在JVM启动时加载参数

-Dlog4j.configuration=d:\log4j.properties

或者在程序里注册系统属性

System.setProperty("log4j.configuration","d:\\log4j.properties"); 

　　2、当前jvm环境中log4j.configuration属性查找不到，再从当前类加载路径依次查找log4j.xml、log4j.properties。显然，是要从jar包加载了。笔者用ide导航了一些，果不其然有的jar内置了log4j.xml,

这不是我们希望的结果，而我们需要的从当前web应用类路径加载，问题的症结也便在此：配置文件加载优先级问题，并非maven问题。

公司项目是web项目，显然更适合在Servlet上下文监听器(ServletContextListener)注册这个属性，如果项目比较紧急，到这一步已经基本算是临时性解决问题了，其他的留作后期代码重构再解决。

根本性解决方法

话到此处，有一些洁癖的程序员心里嘀咕着：这一点也不优雅，一点都不适合我的作风，这样不行，肯定有更好的办法。当然，如果能写出精炼、纯粹、直接的代码是最好不过了；好吧，笔者也是这么认为（窃笑中.gif)，能有别人封装好的成熟代码最好不过，

不要重复造*；当然写博文这个时间算是充足，考虑到项目用了spring，以往经常用spring来托管log4j。spring针对log4j 1.x有一个Log4jConfigListener

package org.springframework.web.util;

import javax.servlet.ServletContextEvent;
import javax.servlet.ServletContextListener;

/**
 * Bootstrap listener for custom log4j initialization in a web environment.
 * Delegates to {@link Log4jWebConfigurer} (see its javadoc for configuration details).
 *
 * <b>WARNING: Assumes an expanded WAR file</b>, both for loading the configuration
 * file and for writing the log files. If you want to keep your WAR unexpanded or
 * don't need application-specific log files within the WAR directory, don't use
 * log4j setup within the application (thus, don't use Log4jConfigListener or
 * Log4jConfigServlet). Instead, use a global, VM-wide log4j setup (for example,
 * in JBoss) or JDK 1.4's {@code java.util.logging} (which is global too).
 *
 * <p>This listener should be registered before ContextLoaderListener in {@code web.xml}
 * when using custom log4j initialization.
 *
 * @author Juergen Hoeller
 * @since 13.03.2003
 * @see Log4jWebConfigurer
 * @see org.springframework.web.context.ContextLoaderListener
 * @see WebAppRootListener
 * @deprecated as of Spring 4.2.1, in favor of Apache Log4j 2
 * (following Apache's EOL declaration for log4j 1.x)
 */
@Deprecated
public class Log4jConfigListener implements ServletContextListener {

    @Override
    public void contextInitialized(ServletContextEvent event) {
        Log4jWebConfigurer.initLogging(event.getServletContext());
    }

    @Override
    public void contextDestroyed(ServletContextEvent event) {
        Log4jWebConfigurer.shutdownLogging(event.getServletContext());
    }

}

通过跟踪代码，我们发现spring也是扩展了ServletContextListener监听器接口，采用迂回的方式，返回到我们刚刚提及的Log4jManager类,初始化了日志功能。

当然，在spring4.2.1以后，文档说已经过期，将使用log4j2系列日志，各位酌情使用，时间太晚，笔者没有再继续追下去。

我们只需要在web.xml中配置一个监听器和上下文参数，即可解决问题

  <context-param>
    <param-name>log4jConfigLocation</param-name>
    <param-value>classpath:log4j.properties</param-value>
  </context-param>

 <listener>
    <listener-class>org.springframework.web.util.Log4jConfigListener</listener-class>
  </listener>

当然，通过查看Log4jWebConfigurer的文档注释，我们也可以指定日志的存放路，放到当前应用的上下文路径中。

log4j.appender.myfile.File=${webapp.root}/WEB-INF/demo.log

至此，日志兼容性问题便解决，可爱的log4j日志又在控制台活蹦乱跳了，眼前便豁然开朗。