背景:
最近打算将主要几个项目配置负载均衡策略,由于当前业务用户不多,不存在并发流量问题,我们目的只是为了实现不停机部署以及进程级别的故障转移而已。
通过Jenkins动态传入端口选项参数,启动多实例项目,配合nginx的upstream策略将对应域名请求分发到不同端口。当然,首先我们得考虑项目中的服务状态以及资源共享问题,确保多实例部署不会对业务流程造成影响。
这些操作配置不难,重点还是在于要充分考虑同一项目多实例会不会带来新的问题。比如,这次我就没考虑到 日志共享 时的滚动问题。
文章目录
一、问题来源
开发环境:
JDK:1.8
操作系统:CentOS 7.4
web框架:SpringBoot 1.5.9
日志框架:Logback 1.1.11
问题描述:
我们负载均衡的两个相同项目(端口9990和8099)是用的是同样的Logback配置,写入的日志名称以及滚定策略都是一模一样。
两个项目启动运行时都没问题,日志都是顺序合并打印在stdout.log文件中,但是在第二天00:00:00这个时间点后,两个项目都去尝试将之前一天的stdout.log改名为stdout.log.2019-10-28.log,然后再创建新的stdout.log。
最终结果是这样:
首先日志文件stdout.log和stdout.log.2019-10-28.log都是正常生成,8099端口这个项目正常在新的stdout.log中打印,但是9990端口的这个项目日志却在stdout.log.2019-10-28.log这个文件打印,并且2019-10-28这一天的日志内容(原stdout.log)消失了,也就是说stdout.log.2019-10-28.log现在只有9990端口29号的日志内容了,28号的日志文件都被覆盖了。
这种现象乍一看比较诡异,日志滚动过程中到底发生了什么导致这种现象发生呢?我们直接看源码来分析下吧!
注: 我在此强调一下,跟踪源码时不要太抠细节,我们接触的开源框架背后都是一个团队数年以上不停迭代更新的产物,蕴含大量的抽象层次、设计模式、功能模块、历史兼容等。我们一般只需要聚焦自己的关注点,慢慢展开分析,遇到看不懂的很正常,先不要深挖。
二、源码跟踪
在跟踪源码之前我们需要明确一点:
并不是每天到达0点时,项目就会自动去重命名备份旧日志,产生新的日志。而是每有一条日志打印时,都会去判断是否需要滚动,发现满足条件后才执行滚动操作。也就是第二天0点后的第一条日志打印时,此刻才会触发滚动操作。
项目Logback部分配置:
logback-spring.xml:
<?xml version="1.0" encoding="UTF-8"?>
<configuration>
<property name="LOG_PATH" value="/home/dev/log/xxx" />
<appender name="FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">
<File>${LOG_PATH}/stdout.log</File>
<encoder>
<pattern>%date [%level] [%thread] %logger{60} [%file : %line] %msg%n</pattern>
</encoder>
<rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
<!-- 添加.gz 历史日志会启用压缩 大大缩小日志文件所占空间 -->
<fileNamePattern>${LOG_PATH}/stdout.log.%d{yyyy-MM-dd}.log</fileNamePattern>
<maxHistory>30</maxHistory><!-- 保留30天日志 -->
</rollingPolicy>
</appender>
<root level="INFO">
<appender-ref ref="CONSOLE"/>
<appender-ref ref="FILE"/>
</root>
</configuration>
上面只配置根节点Logger[ROOT]
的打印级别(INFO)以及两个appender,所有类都按照其配置打印日志。
Debug入口:com.xxx.controller.xxxController:
private static final Logger logger = LoggerFactory.getLogger(this.getClass());
logger.info("Logback源码跟踪");
从logger.info
方法开始debug。
ch.qos.logback.classic.Logger:
public void info(String msg) {
filterAndLog_0_Or3Plus(FQCN, null, Level.INFO, msg, null, null);
}
private void filterAndLog_0_Or3Plus(final String localFQCN, final Marker marker, final Level level, final String msg, final Object[] params,
final Throwable t) {
final FilterReply decision = loggerContext.getTurboFilterChainDecision_0_3OrMore(marker, this, level, msg, params, t);
if (decision == FilterReply.NEUTRAL) {
if (effectiveLevelInt > level.levelInt) {
return;
}
} else if (decision == FilterReply.DENY) {
return;
}
buildLoggingEventAndAppend(localFQCN, marker, level, msg, params, t);
}
private void buildLoggingEventAndAppend(final String localFQCN, final Marker marker, final Level level, final String msg, final Object