前提:
公司项目用的是nginx+tomcat+java,线上环境和线下环境版本配置都是一样,采用的是jenkins自动化部署。
问题:
前段时间突然发现浏览器访问一个页面,后端日志会出现重复的两条日志记录一模一样,请求时间都是一样的,经过测试发现所有的请求都会有两条重复的日志记录。如下图:
排查:
1、一开始认为是前端重复请求了,查看nginx访问日志,发现刷新一次页面的确nginx会出现两条请求记录,一次是OPTIONS请求,一次是GET请求,但是监控tomcat日志,发现刷新一次页面有4次请求,两次完全相同(包括时间)的OPTIONS和两次完全相同的GET请求。
2、排除前端页面问题以后,开始怀疑是nginx重复请求导致,于是直接通过IP+tomcat端口访问,发现还是会有完全一模一样的两条日志。然后通过IP+端口测试其他几个后端api,都会出现一样的问题。
3、排查nginx和前端以后,把问题锁定在了tomcat环境上面,于是开始一步一步排查:
a、对比了线上和线下的tomcat版本、java版本以及diff对比了线上和线下的实例配置文件,都是完全一样的。
b、百度搜索以后,有网友说重复请求问题是因为在tomcat的默认的server.xml里面,错误的配置了Host或者Context标签导致两个对象同时持有日志文件,导致重复加载。
①如果新增了Host,那Host/appBase的值是不能和其他Host/appBase的值一样的。比如appBase都是webapps,那么两个Host会导致webapps下面的工程被加载两遍。
②如果配置了Context标签那么就一定要配置name属性值为:工程名(/web-sys),或者配置path值为工程名(/web-sys),否则就会引起重复加载工程的问题。
③<Alias>标签,允许我们把多个域名配置在一个Host下面,例如:xxx.com、xxx.cn、xxx.com.cn,都可以配置在一个Host下面
需要配置成下面这样:
<Host name="www.xxx.com" appBase="mywebapps" autoDeploy="true" unpackWARs="true">
<Alias>www.xxx.cn</Alias>
<Alias>www.xxx.com.cn</Alias>
<Context docBase="web-sys" path="" name="/web-sys"/>
</Host>
我对比了我的server.xml文件,于是添加了name属性,然后删除了默认的ROOT目录,进行了一番测试,结果还是会出现显示两条重复日志的问题。
4、经过上面的排查以后,开始有点迷茫,于是把线上的实例war包直接拷贝到了本地环境,然后修改了数据库信息,经测试还是会有同样的问题。此时瞬间又找到了方向,应该是war包封装过程中的问题。
5、于是去查看jenkins 线上和线下构建过程,发现配置文件有个redis参数不一样、log4j2.xml日志级别不一样,swagger开启状态不一样,然后马上把新建一个实例,把jenkins构建过程改成和本地测试环境一样,重新构建部署到生产环境,访问测试终于正常了。
6、这次终于找到了原因,于是依次对上面几个不同的参数一个一个修改发布测试,最后发现是因为log4j2.xml里面少了additivity="false"这个属性导致。(一旦一个日志输出到一个Logger,这个Logger的additivity设置为false,那么这个日志不会再继续向父Logger进行传递,忽略其他Logger的additivity的设置。)
7、最后再去排查为何会少一个属性,才发现是jenkins构建过程中,使用sed命令替换时,使用了.*通配符去替换日志等级level="DEBUG",导致把additivity="false"替换为了空。
<Logger name="cn.amd5.community" level="DEBUG" additivity="false">
<AppenderRef ref="Console"/>
<AppenderRef ref="DailyLogFile"/>
</Logger>
加上additivity="false"以后,重启实例,测试正常,如下图: