龙空技术网

log4j日志不输出的问题

健程之道 162

前言:

而今小伙伴们对“log4net无法输出日志”大体比较看重,朋友们都想要分析一些“log4net无法输出日志”的相关文章。那么小编也在网上网罗了一些有关“log4net无法输出日志””的相关知识,希望兄弟们能喜欢,同学们一起来学习一下吧!

今天服务器上报错,想先去看一下日志进行排查,结果发现日志很久都没有输出过了。从上午排查到下午,刚刚解决,因此记录一下,但现在也只是知其然,并不知其所以然,所以如果大家有什么想法请在下方评论。

先说一下环境,服务器是linux,项目是运行在tomcat下的Spring项目,日志用的是log4j。

首先,从10月13号开始便没有新的日志文件了。假设日志名为log.txt(如果你设置了DailyRollingFileAppender,那么你当天的日志文件就是log.txt),先备份该文件到其他目录下,然后删除该文件,重新启动tomcat。这是为了确认你的log4j配置是否有问题,因为这是最容易出错的地方。很遗憾,我不是这里出的问题,因为项目重启后,日志文件又重新生成了,但很奇怪的是,日志文件是空的,其大小为0.

感觉自己碰上了很神奇的问题,因此我在自己的本地进行调试,启动项目后发现,正常的项目启动日志是有的:

15:13:48:0253 INFO [RMI TCP Connection(3)-127.0.0.1] -Root WebApplicationContext: initialization completed in 18479 ms

但我自己的一些日志输出是不显示的,比如:

private static final Logger log = LoggerFactory.getLogger(MyDomain.class);log.info("show info log");

show info log这句话就不打印,现在证明,我的日志配置没有问题,服务器也找到了我的日志文件,但应该是我自己的Logger是不对应正确的日志输出的,因为我的console(控制台)有显示。

接下来,我就是开始看源码了。先是LoggerFactory.getLogger(Class clazz)方法:

 public static Logger getLogger(Class<?> clazz) { Logger logger = getLogger(clazz.getName()); if (DETECT_LOGGER_NAME_MISMATCH) { Class<?> autoComputedCallingClass = Util.getCallingClass(); if (autoComputedCallingClass != null && nonMatchingClasses(clazz, autoComputedCallingClass)) { Util.report(String.format("Detected logger name mismatch. Given name: \"%s\"; computed name: \"%s\".", logger.getName(), autoComputedCallingClass.getName())); Util.report("See " + LOGGER_NAME_MISMATCH_URL + " for an explanation"); } } return logger; }

好吧,没什么用,看不出我的logger变成了,继续看getLogger(String name)方法:

 public static Logger getLogger(String name) { ILoggerFactory iLoggerFactory = getILoggerFactory(); return iLoggerFactory.getLogger(name); }

这时我在return iLoggerFactory.getLogger(name);这行打了断点,我看到了这样的东西:

为什么我的iLoggerFactory是用的logback中的实现?其实也是怪我自己大意,我其实依赖了一个基于Spring Boot的项目(虽然我只是用了里面的一些domain类,但因为设计不当,还没有把这些domain类单独提成一个_项目),而Spring Boot中一般默认就依赖的logback。通过gradle查看项目的依赖树,也证实了我的这一猜想(./gradlew 子项目名称:dependencies):

| +--- org.springframework.boot:spring-boot-starter-web:2.0.2.RELEASE| | +--- org.springframework.boot:spring-boot-starter:2.0.2.RELEASE| | | +--- org.springframework.boot:spring-boot:2.0.2.RELEASE| | | | +--- org.springframework:spring-core:5.0.6.RELEASE (*)| | | | \--- org.springframework:spring-context:5.0.6.RELEASE (*)| | | +--- org.springframework.boot:spring-boot-autoconfigure:2.0.2.RELEASE| | | | \--- org.springframework.boot:spring-boot:2.0.2.RELEASE (*)| | | +--- org.springframework.boot:spring-boot-starter-logging:2.0.2.RELEASE| | | | +--- ch.qos.logback:logback-classic:1.2.3| | | | | +--- ch.qos.logback:logback-core:1.2.3| | | | | \--- org.slf4j:slf4j-api:1.7.25

接下来就好办了,你排除掉ch.qos.logback的依赖就可以了,在你的build.gradle中增加:

configurations { compile.exclude group: 'ch.qos.logback'}

这个时候你再重新调试一下看看:

完美,现在是log4j中的实现,得到了我想要的操作。当然了,既然我知道之前项目中的slf4j是logback实现了,那么我自然也可以换成logback的配置,但这就需要我将项目换成用Spring Boot启动,这个改动有点大,如果以后有必要的话,我再将这个exclude删除,换成Spring Boot的形式。

这次Spring Boot帮我们默认启用的是logback,那么有没有什么简单方法可以知道呢?如果你的项目出现了以下的日志输出,说明你的项目当前有不止一个SLF4J的实现组件:

SLF4J: Class path contains multiple SLF4J bindings.SLF4J: Found binding in [jar:file:/project.war/WEB-INF/lib/logback-classic-1.2.3.jar!/org/slf4j/impl/StaticLoggerBinder.class]SLF4J: Found binding in [jar:file:/project.war/WEB-INF/lib/slf4j-log4j12-1.7.21.jar!/org/slf4j/impl/StaticLoggerBinder.class]SLF4J: See  for an explanation.SLF4J: Actual binding is of type [ch.qos.logback.classic.util.ContextSelectorStaticBinder]

因为在org.slf4j.LoggerFactory的bind方法中有关于这方面的输出:

 private final static void bind() { try { Set<URL> staticLoggerBinderPathSet = null; // skip check under android, see also //  if (!isAndroid()) { // 查找你的当前项目有几个slf4j的实现 staticLoggerBinderPathSet = findPossibleStaticLoggerBinderPathSet(); // 如果多余一个就打印 reportMultipleBindingAmbiguity(staticLoggerBinderPathSet); } // the next line does the binding // 这个是具体选了哪一个实现(重点关注) StaticLoggerBinder.getSingleton(); INITIALIZATION_STATE = SUCCESSFUL_INITIALIZATION; reportActualBinding(staticLoggerBinderPathSet); fixSubstituteLoggers(); replayEvents(); // release all resources in SUBST_FACTORY SUBST_FACTORY.clear(); } catch (NoClassDefFoundError ncde) { String msg = ncde.getMessage(); if (messageContainsOrgSlf4jImplStaticLoggerBinder(msg)) { INITIALIZATION_STATE = NOP_FALLBACK_INITIALIZATION; Util.report("Failed to load class \"org.slf4j.impl.StaticLoggerBinder\"."); Util.report("Defaulting to no-operation (NOP) logger implementation"); Util.report("See " + NO_STATICLOGGERBINDER_URL + " for further details."); } else { failedBinding(ncde); throw ncde; } } catch (java.lang.NoSuchMethodError nsme) { String msg = nsme.getMessage(); if (msg != null && msg.contains("org.slf4j.impl.StaticLoggerBinder.getSingleton()")) { INITIALIZATION_STATE = FAILED_INITIALIZATION; Util.report("slf4j-api 1.6.x (or later) is incompatible with this binding."); Util.report("Your binding is version 1.5.5 or earlier."); Util.report("Upgrade your binding to version 1.6.x."); } throw nsme; } catch (Exception e) { failedBinding(e); throw new IllegalStateException("Unexpected initialization failure", e); } }

特别要注意的是StaticLoggerBinder.getSingleton();这行代码,StaticLoggerBinder在logback-classic和slf4j-log4j12这两个jar包各有一个,因此,Spring boot是自动选择logback-classic(虽然我在本地运行的时候还是默认进入的slf4j-log4j12,但是会提醒我Source code does not match the bytecode,因此我判断依旧进的是logback-classic),所以只要把logback给exclude掉,就解决了这个问题。

现在看问题,更加关注源代码,因为这可以让我们更加快速定位问题,并且也能据此大致猜出其解决方案。希望大家能一起看看源代码,如果你有什么发现,可以在下方留言,我将和你一起讨论。

有兴趣的话可以关注我的公众号或者头条号,说不定会有意外的惊喜。

标签: #log4net无法输出日志