记一次SpringBoot项目启动卡住问题排查记录

本人花费半年的时间总结的《Java面试指南》已拿腾讯等大厂offer,已开源在github ,欢迎star!

本文GitHub https://github.com/OUYANGSIHAI/JavaInterview 已收录,这是我花了6个月总结的一线大厂Java面试总结,本人已拿大厂offer,欢迎star

原文链接:blog.ouyangsihai.cn >> 记一次SpringBoot项目启动卡住问题排查记录

点击上方“后端技术精选”,选择“置顶公众号”

技术文章第一时间送达!

作者:陈凯玲 来源:https://url.cn/5UWhBvB

一个spring boot开发的项目,spring boot版本是1.5.7,携带的spring版本是4.1.3。开发反馈,突然在本地启动不起来了,表象特征就是在本地IDEA上运行时,进程卡住也不退出,应用启动时加载相关组件的日志也不输出。症状如下图:

记一次SpringBoot项目启动卡住问题排查记录

问题分析

因为没有有用的日志信息,所以不能从日志这个层面上排查问题。但是像这种没有输出日志的话,一般情况下,肯定是程序内部启动流程卡在什么地方了,只能通过打印下当前线程堆栈信息了解下。一般情况下,在服务器环境,我们会使用java工具包中的jstack 工具来查看:如jstack pid(应用java进程)。

但是,在IDEA本地开发的话,IDEA内置了一个工具,可以直接查看当前应用的线程上线文信息,如:

记一次SpringBoot项目启动卡住问题排查记录

注意下面那个箭头指向的像照相机一样的图标,故图思意,就是打印当前线程快照的的意思。

点击后,就出现了右边那些线程上下文信息了,可以看到有很多的线程,我们主要关注下main线程,线程状态确实是waiting的,接着点击箭头所指向的main线程,可以看到如下内容:

  1. "main@1" prio=5 tid=0x1 nid=NA waiting1. java.lang.Thread.State: WAITING1. at sun.misc.Unsafe.park(Unsafe.java:-1)1. at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)1. at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:836)1. at java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireSharedInterruptibly(AbstractQueuedSynchronizer.java:997)1. at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireSharedInterruptibly(AbstractQueuedSynchronizer.java:1304)1. at java.util.concurrent.CountDownLatch.await(CountDownLatch.java:231)1. at org.springframework.boot.autoconfigure.BackgroundPreinitializer.onApplicationEvent(BackgroundPreinitializer.java:63)1. at org.springframework.boot.autoconfigure.BackgroundPreinitializer.onApplicationEvent(BackgroundPreinitializer.java:45)1. at org.springframework.context.event.SimpleApplicationEventMulticaster.doInvokeListener(SimpleApplicationEventMulticaster.java:172)1. at org.springframework.context.event.SimpleApplicationEventMulticaster.invokeListener(SimpleApplicationEventMulticaster.java:158)1. at org.springframework.context.event.SimpleApplicationEventMulticaster.multicastEvent(SimpleApplicationEventMulticaster.java:139)1. at org.springframework.context.event.SimpleApplicationEventMulticaster.multicastEvent(SimpleApplicationEventMulticaster.java:127)1. at org.springframework.boot.context.event.EventPublishingRunListener.finished(EventPublishingRunListener.java:115)1. at org.springframework.boot.SpringApplicationRunListeners.callFinishedListener(SpringApplicationRunListeners.java:79)1. at org.springframework.boot.SpringApplicationRunListeners.finished(SpringApplicationRunListeners.java:72)1. at org.springframework.boot.SpringApplication.handleRunFailure(SpringApplication.java:745)1. at org.springframework.boot.SpringApplication.run(SpringApplication.java:314)1. at org.springframework.boot.builder.SpringApplicationBuilder.run(SpringApplicationBuilder.java:134)1. - locked 0xea6 (a java.util.concurrent.atomic.AtomicBoolean)1. at org.springframework.cloud.bootstrap.BootstrapApplicationListener.bootstrapServiceContext(BootstrapApplicationListener.java:175)1. at org.springframework.cloud.bootstrap.BootstrapApplicationListener.onApplicationEvent(BootstrapApplicationListener.java:98)1. at org.springframework.cloud.bootstrap.BootstrapApplicationListener.onApplicationEvent(BootstrapApplicationListener.java:64)1. at org.springframework.context.event.SimpleApplicationEventMulticaster.doInvokeListener(SimpleApplicationEventMulticaster.java:172)1. at org.springframework.context.event.SimpleApplicationEventMulticaster.invokeListener(SimpleApplicationEventMulticaster.java:165)1. at org.springframework.context.event.SimpleApplicationEventMulticaster.multicastEvent(SimpleApplicationEventMulticaster.java:139)1. at org.springframework.context.event.SimpleApplicationEventMulticaster.multicastEvent(SimpleApplicationEventMulticaster.java:127)1. at org.springframework.boot.context.event.EventPublishingRunListener.environmentPrepared(EventPublishingRunListener.java:74)1. at org.springframework.boot.SpringApplicationRunListeners.environmentPrepared(SpringApplicationRunListeners.java:54)1. at org.springframework.boot.SpringApplication.prepareEnvironment(SpringApplication.java:325)1. at org.springframework.boot.SpringApplication.run(SpringApplication.java:296)1. at cn.keking.project.customerManagement.KekingCustomerManagement.main(KekingCustomerManagement.java:36)
    java.lang.Thread.State: WAITING

at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)

at java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireSharedInterruptibly(AbstractQueuedSynchronizer.java:997)

at java.util.concurrent.CountDownLatch.await(CountDownLatch.java:231)

at org.springframework.boot.autoconfigure.BackgroundPreinitializer.onApplicationEvent(BackgroundPreinitializer.java:45)

at org.springframework.context.event.SimpleApplicationEventMulticaster.invokeListener(SimpleApplicationEventMulticaster.java:158)

at org.springframework.context.event.SimpleApplicationEventMulticaster.multicastEvent(SimpleApplicationEventMulticaster.java:127)

at org.springframework.boot.SpringApplicationRunListeners.callFinishedListener(SpringApplicationRunListeners.java:79)

at org.springframework.boot.SpringApplication.handleRunFailure(SpringApplication.java:745)

at org.springframework.boot.builder.SpringApplicationBuilder.run(SpringApplicationBuilder.java:134)

at org.springframework.cloud.bootstrap.BootstrapApplicationListener.bootstrapServiceContext(BootstrapApplicationListener.java:175)

at org.springframework.cloud.bootstrap.BootstrapApplicationListener.onApplicationEvent(BootstrapApplicationListener.java:64)

at org.springframework.context.event.SimpleApplicationEventMulticaster.invokeListener(SimpleApplicationEventMulticaster.java:165)

at org.springframework.context.event.SimpleApplicationEventMulticaster.multicastEvent(SimpleApplicationEventMulticaster.java:127)

at org.springframework.boot.SpringApplicationRunListeners.environmentPrepared(SpringApplicationRunListeners.java:54)

at org.springframework.boot.SpringApplication.run(SpringApplication.java:296)

可以看到是通过CountDownLatch.await()阻塞了线程,接着看下面那行,所在代码块如下:

  1. privatestaticfinalCountDownLatch preinitializationComplete = newCountDownLatch(1);
  2. 1. `@Override`1. `publicvoid onApplicationEvent(SpringApplicationEventevent) {`1. `if(eventinstanceofApplicationEnvironmentPreparedEvent) {`1. `if(preinitializationStarted.compareAndSet(false, true)) {`1. ` performPreinitialization();`1. `}`1. `}`1. `if(eventinstanceofApplicationReadyEvent|| eventinstanceofApplicationFailedEvent) {`1. `try{`1. ` preinitializationComplete.await();`1. `}`1. `catch(InterruptedException ex) {`1. `Thread.currentThread().interrupt();`1. `}`1. `}`1. `}`

publicvoid onApplicationEvent(SpringApplicationEventevent) {

if(preinitializationStarted.compareAndSet(false, true)) {

}

if(eventinstanceofApplicationReadyEvent|| eventinstanceofApplicationFailedEvent) {

preinitializationComplete.await();

catch(InterruptedException ex) {

}

}

这是spring boot中的一个安全初始化资源的一个类,代码所示为监听SpringApplicationEvent事件,可以肯定的是,它的逻辑执行到了 preinitializationComplete.await();这里,导致了线程阻塞了。

正常情况下,spring会触发ApplicationEnvironmentPreparedEvent事件完成资源的初始化,这里先不深究Spring为什么这么做,主要通过程序逻辑看下为什么卡这里了,在preinitializationComplete.await();所在行打个断点,看下event对象里的信息,如下:

记一次SpringBoot项目启动卡住问题排查记录

原来event是一个Spring上下文初始化失败的异常事件对象,对象里包含了具体的异常信息,如箭头所指,关键异常信息如:

NoSuchMethodError:“org.springframework.util.ObjectUtils.unwrapOptional(Ljava/lang/Object;)Ljava/lang/Object;”

假设问题

通过上面的分析,基本定位到Spring boot应用启动卡住这个表象背后的真实原因了,而且也定位到了异常信息。

出现NoSuchMethodError异常,是因为调用方法的时候,找不到方法了。一般出现在两个有关联的jar包,但是版本对不上了,也就是常说的jar版本依赖冲突。查看了下,ObjectUtils是spring-core包里的一个类,当前的4.1.3版本确实没有这个unwrapOptional方法,spring-core-5.x的版本才新增了这个方法。因为之前的依赖是没有问题,为什么现在spring上下文会调用5.x的版本的方法呢?

所以先假设近期有开发在pom.xml里添加了新的的依赖,导致了这个问题。

小心求证

有了找问题的方向就好办了,因为代码都是git管理维护的,所以查看下pom.xml文件近期的提交记录即可,查看后,确实发现了近期对pom.xml有改动,添加了一个依赖:

  1. dependency1. groupIdorg.springframework/groupId1. artifactIdspring-context/artifactId1. version5.1.6.RELEASE/version1. /dependency
    groupIdorg.springframework/groupId

version5.1.6.RELEASE/version

这里还涉及到一点Maven依赖优先级的问题,在pom.xml里直接这样添加的依赖优先于其他jar中pom.xml依赖的,也就是说,即使spring boot1.5.7自带了Spring-context.4.1.3,但是这样指定后,应用最后依赖的还是5.1.6的版本。

具体的Maven依赖关系,可以参考我的博文《关于Maven的使用,这些你都了解了么?》。结合之前的分析,八九不离十了就是因为加了这个依赖导致的问题,spring-context.5.1.6配合spring-core.4.1.3肯定得出问题啊。直接移除这个依赖,然后启动系统一切正常,日志打印了Spring加载上线文的信息。

问题总结

定位这个问题的关键在于要了解java中线程堆栈的知识,在没有足够异常日志情况下通过线程快照排查问题。

在定位到问题后,如NoSuchMethodError这样的异常,需要平时的经验积累来假设问题的真实原因,然后在追本溯源验明问题所在根本原因。找问题本质一定要这种循序渐进的思路。

举例,出现这种问题,如果你直接去搜索引擎搜:“Spring boot应用启动卡住了”,是搜不出来什么东西的,但是当你发现了是由于jar冲突。去搜索引擎搜索:

NoSuchMethodError:**”org.springframework.util.ObjectUtils.unwrapOptional(Ljava/lang/Object;)Ljava/lang/Object;”**”。就会有很多的内容,很容易解决问题。

END

Java面试题专栏

记一次SpringBoot项目启动卡住问题排查记录

欢迎长按下图关注公众号后端技术精选

记一次SpringBoot项目启动卡住问题排查记录

原文始发于微信公众号(后端技术精选):

本人花费半年的时间总结的《Java面试指南》已拿腾讯等大厂offer,已开源在github ,欢迎star!

本文GitHub https://github.com/OUYANGSIHAI/JavaInterview 已收录,这是我花了6个月总结的一线大厂Java面试总结,本人已拿大厂offer,欢迎star

原文链接:blog.ouyangsihai.cn >> 记一次SpringBoot项目启动卡住问题排查记录


 上一篇
SpringBoot基本配置详解 SpringBoot基本配置详解
SpringBoot项目有一些基本的配置,比如启动图案(banner),比如默认配置文件application.properties,以及相关的默认配置项。 示例项目代码在:https://github.com/laolunsi/sprin
下一篇 
惊人!Spring5 AOP 默认使用 CGLIB ?从现象到源码的深度分析 惊人!Spring5 AOP 默认使用 CGLIB ?从现象到源码的深度分析
Spring5 AOP 默认使用 Cglib 了?我第一次听到这个说法是在一个微信群里: 真的假的?查阅文档刚看到这个说法的时候,我是保持怀疑态度的。 大家都知道 Spring5 之前的版本 AOP 在默认情况下是使用 JDK 动态代理的,