记一次tomcat部署错误导致的项目自动宕机问题

一、项目背景

所在的公司专注交通行业，刚巧参与到一个很老的项目，前后端不分离jsp版本的项目，让人极其上火的项目，听同事说这项目还会自动宕机，而且没找到原因

二、项目入手

拿到这个项目，首先做的是个版本迭代，这个过程中发现项目存在很多很多问题和bug。
其中要命的一个问题是，log4j配置的日志不生效，原因是log4j和lo4j2依赖冲突，项目配置的是log4j版本，却有log4j2的依赖进来，所以用maven helper这个插件找到冲突的依赖，排除掉就可以了。
其次居然log4j配置居然只有控制台输出，没有分离日志并输出日志文件，果断加上INFO和ERROR级别的日志输出：

# info日志输出到文件
log4j.logger.infoFile=INFO
log4j.appender.infoFile=org.apache.log4j.RollingFileAppender
log4j.appender.infoFile.append=true
log4j.appender.infoFile.layout=org.apache.log4j.PatternLayout
log4j.appender.infoFile.layout.ConversionPattern=%-d{yyyy-MM-dd HH:mm:ss,SSS}-[%t]-[%5p] (%F:%L) - %m%n
log4j.appender.infoFile.Threshold=INFO
log4j.appender.infoFile.File=/logs/xxx/xxx-info.log
log4j.appender.infoFile.MaxFileSize=2048KB
log4j.appender.infoFile.filter.infoFilter = org.apache.log4j.varia.LevelRangeFilter
log4j.appender.infoFile.filter.infoFilter.LevelMin=INFO
log4j.appender.infoFile.filter.infoFilter.LevelMax=INFO# error日志输出到文件
log4j.logger.errorFile=ERROR
log4j.appender.errorFile=org.apache.log4j.RollingFileAppender
log4j.appender.errorFile.append=true
log4j.appender.errorFile.layout=org.apache.log4j.PatternLayout
log4j.appender.errorFile.layout.ConversionPattern=%-d{yyyy-MM-dd HH:mm:ss,SSS}-[%t]-[%5p] (%F:%L) - %m%n
log4j.appender.errorFile.Threshold=ERROR
log4j.appender.errorFile.File=/logs/xxx/xxx-error.log
log4j.appender.errorFile.MaxFileSize=2048KB
log4j.appender.errorFile.filter.errorFilter = org.apache.log4j.varia.LevelRangeFilter
log4j.appender.errorFile.filter.errorFilter.LevelMin=ERROR
log4j.appender.errorFile.filter.errorFilter.LevelMax=ERROR

三、问题排查

这里用到的指令主要是top、jstack、jstat和jvisualvm。
首先tomcat服务配置JVM参数：-XX:+HeapDumpOnOutOfMemoryError和-XX:HeapDumpPath=/xxx，该指令在发生堆溢出时自动输出dump文件到指定位置，可供分析。
跑起来后，top看了一下cpu和内存占用情况，果然发现某个进程的cpu占用会阶段性地猛增，拿到这个进程的pid，随后：top -p ，随后"H"获取该进程的每个线程情况，找出cpu占用最高的线程pid，拿着这个线程pid转为16进制，执行：jstack <进程pid> | grep -A 10 <线程pid16进制>，可定位到该线程的堆栈信息，最后如下：

会发现这个线程在等待，线程被阻塞了，之后在代码里面找这个叫"myScheduler"的东东，发现是spring定时任务的执行线程池配置，起初也怀疑是不是线程池配置的有问题，但是砍了配置，明显不是这里的问题：

线程池配置没问题，但是不代表问题不在这，接着去找代码内使用spring定时任务去干了啥，最后发现跟mqtt有关系，由于这玩意我也没怎么用过，只知道是可以跟硬件互发消息的MQ队列。
恰巧这个时候error日志不断输出：

这个错用过mqtt的应该知道，client连接mqtt服务器的时候，如果clientId重复了的话，会连接不上，而且一直在不断地重试…但是很奇怪，为何会重复呢？本地都没有起服务，而且只有开发服务器上起了这一个服务，怎么会重复呢…这里先不管了
随后使用jstat -gc 1000 10循环打印该服务的gc情况，一看就发现了问题，eden区占用上涨很快，导致频繁发生YGC，因为对该项目的代码也不熟，而且代码写的极烂，所以根本就没想过马上就从代码入手。
几方面排查联系起来，就想起来用jvisualvm工具看看，打开后：

可以看到实时线程居然达到了2.5w+…瞬间懵逼，而且看到了熟悉的"myScheduler"，这里基本可以确定就是mqtt连接不上的锅，但是为什么会连不上呢…clientId明明没有重复，而且项目启动一段时间后，再访问会很卡，不久后就宕机了，而且并没有输出dump文件。
mqtt的控制面板看起来连接也是正常的没有问题：

最后想起来，同事在部署项目的时候，有个奇怪的问题：项目因为css取静态资源的问题，不能配contextPath，也懒得再整。
配置写在server.xml内，Host节点下定义Context应用节点，指定docBase指向项目目录，跑起来后发现无路径跟有项目名称contextPath都可以访问，这里怀疑一个war被部署了两次…如果是这样的话，也就可以解释为啥会不断重连了…

四、解决方案

最后server.xml发现Host容器的appBase配置为webapps，但是Context容器的docBase配置的项目目录也在webapps下面，Host容器包含Context容器，所以这么配置的话，项目会被部署两次…原因是tomcat加载完appBase="webapps"之后又去加载了docBase指定的webapps目录下的项目…所以这是个部署事故…理论知识的重要性，此乃前人留下的巨坑。

所以tomcat常用的方法是：

1. 单独部署应用
   即在$TOMCAT_HOME/conf/Catalina/localhost目录下定义项目的xml，例如app.xml，里面：

<Context docBase="xxx/xxx/app" path="/" reloadable="true" />

切记项目目录不要再扔到webapps目录下面去

2. server.xml配置
   server.xml内定义Context节点即可，docBase指定项目路径，切记不要再扔到webapps目录下面去，否则项目会被部署两次

3. war或者解压后的war部署
   直接将war包或者解压后的war包扔到在webapps目录下即可

本项目的处理比较粗暴，直接删了tomcat/webapps目录下的ROOT目录，并且把项目的war包重命名为ROOT.war，直接就覆盖了tomcat的内置应用，再也不用担心它会部署两次了