环境描述:
操作系统:centos、windows
java服务,使用springboot,web项目
现象:日志中不停的输出错误日志
2023-12-23 17:37:32.402|ERROR|main|org.springframework.boot.diagnostics.LoggingFailureAnalysisReporter.report:40|
***************************
APPLICATION FAILED TO START
***************************
Description:
Web server failed to start. Port 1666 was already in use.
Action:
Identify and stop the process that's listening on port 1666 or configure this application to listen on another port.
2023-12-23 17:37:32.461|ERROR|quickSearch|com.Xxx.service.UploadFileService.dealQuickSearch:360|
org.mybatis.spring.MyBatisSystemException: nested exception is org.apache.ibatis.exceptions.PersistenceException:
### Error querying database. Cause: org.springframework.jdbc.CannotGetJdbcConnectionException: Failed to obtain JDBC Connection; nested exception is java.sql.SQLException: HikariDataSource HikariDataSource (null) has been closed.
### The error may exist in com/XXX/service/mapper/UploadFileDao.java (best guess)
### The error may involve com.Xxxx.mapper.UploadFileDao.selectList
### The error occurred while executing a query
### Cause: org.springframework.jdbc.CannotGetJdbcConnectionException: Failed to obtain JDBC Connection; nested exception is java.sql.SQLException: HikariDataSource HikariDataSource (null) has been closed.
原因:因为我的service实现SmartInitializingSingleton这个类,在afterSingletonsInstantiated方法中启动一个后台处理线程,是一个后台处理任务的死循环的线程。这个线程里面会有数据库的查询。
猜测的原因,这个问题比较明显,应该是启动springboot的时候,web服务的端口1666已经被占用,启动失败。但是由于后台起了一个死循环的线程,导致整个进程无法因为结束(进程一直在)。这个占用1666端口的进程,其实也是同一个jar包启动的,导致从表面上看,web服务的功能是正常的,但是不停的输出错误日志(因为后台线程的死循环里一直查询数据库)。而这个报错又比较奇怪。后来直接通过ps命令查看进程,发现确实存在多个进程。
问题复现:先将多个进程都kill,然后手动启动一个进程,完全正常;再使用同样的命令启动,结果就出现了上面的错误日志。
解决方法:思路是(1)能否判断springweb启动成功以后,再启动后台线程?(2)能否通过判断springweb启动失败,去关闭该线程?
(2)基于2的思路先尝试了一下,因为看到如下错误日志:
|ERROR|main|org.springframework.boot.diagnostics.LoggingFailureAnalysisReporter.report:40|
我就想着看看LoggingFailureAnalysisReporter是如何打印错误日志的,结果发现它实现了一个FailureAnalysisReporter接口,通过下面这个方法调用的(FailureAnalyzers类中):
private boolean report(FailureAnalysis analysis, ClassLoader classLoader) {
List<FailureAnalysisReporter> reporters = SpringFactoriesLoader.loadFactories(FailureAnalysisReporter.class,
classLoader);
if (analysis == null || reporters.isEmpty()) {
return false;
}
for (FailureAnalysisReporter reporter : reporters) {
reporter.report(analysis);
}
return true;
}
然后我自然而然就想到自己执行死循环的service也实现这个接口,在report的时候,设置一个本地变量,表示springweb启动失败,然后停止这个线程。
@Override
public void afterSingletonsInstantiated() {
// 启动后台处理线程
final Thread thread = new Thread(() -> {
try {
autoUpdate();
} catch (Exception e) {
log.error("处理的线程出现错误", e);
}
});
thread.setName("quickSearch");
thread.start();
}
// 启动失败的时候,设置为false
@Override
public void report(FailureAnalysis analysis) {
this.isWebStartSuccess = false;
}
// 状态变量
private volatile boolean isWebStartSuccess = true;
// 死循环的线程
public void autoUpdate() {
while(true) {
if (!isWebStartSuccess) {
return;
}
}
}
结果发现这个report方法跟本没被调用(原因下一篇再分析)。
然后我就采用了思路(1),问题就变成了:怎么能在springweb启动后再启动某个线程呢?
我再往上查了一下,有人采用在springboot启动类的main方法的第一行后面启动线程。我先再该行代码出增加了一行日志,发现如果端口冲突,springweb启动失败,这一行日志确实没有输出,然后就将这个死循环的线程,放在这里启动,主要代码就变成了:
public static void main(String[] args) {
SpringApplication.run(XxxxApplication.class, args);
startAutoUpdateThread();
}
public static void startAutoUpdateThread() {
final UploadFileService bean = SpringApplicationContext.getBean(UploadFileService.class);
new Thread(() -> bean.autoUpdate()).start();
}
这样处理以后,发现问题是解决了。但是不知道这样是否可能造成其他问题。