今天服务器上报错, 想先去看一下日志进行排查, 结果发现日志很久都没有输出过了. 从上午排查到下午, 刚刚解决, 因此记录一下, 但现在也只是知其然, 并不知其所以然, 所以如果大家有什么想法请在下方评论.
先说一下环境, 服务器是 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 http://www.slf4j.org/codes.html#multiple_bindings 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
- // http://jira.qos.ch/browse/SLF4J-328
- 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 掉, 就解决了这个问题.
现在看问题, 更加关注源代码, 因为这可以让我们更加快速定位问题, 并且也能据此大致猜出其解决方案. 希望大家能一起看看源代码, 如果你有什么发现, 可以在下方留言, 我将和你一起讨论.
有兴趣的话可以关注我的公众号或者头条号, 说不定会有意外的惊喜.
来源: https://www.cnblogs.com/death00/p/11571202.html