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

青旅半醒 2021-08-19 19:26 1097阅读 0赞

点击上方 [Java后端][Java]，选择 设为星标

优质文章，及时送达

![format_png][]

作者 | 陈凯玲

来源 | my.oschina.net/keking/blog/3058921

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

![format_png 1][]

### **问题分析** ###

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

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

![format_png 2][]

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

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

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

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

private static final CountDownLatch preinitializationComplete = new CountDownLatch(1);   @Override public void onApplicationEvent(SpringApplicationEvent event) {    if (event instanceof ApplicationEnvironmentPreparedEvent) {       if (preinitializationStarted.compareAndSet(false, true)) {          performPreinitialization();       }    }    if (event instanceof ApplicationReadyEvent || event instanceof ApplicationFailedEvent) {       try {          preinitializationComplete.await();       }       catch (InterruptedException ex) {          Thread.currentThread().interrupt();       }    } }

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

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

![format_png 3][]

原来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有改动，添加了一个依赖

<dependency>     <groupId>org.springframework</groupId>     <artifactId>spring-context</artifactId>     <version>5.1.6.RELEASE</version> </dependency>

这里还涉及到一点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】

如果看到这里，说明你喜欢这篇文章，请**转发****、点赞**。微信搜索「web\_resource」，关注后回复「进群」或者扫描下方二维码即可进入无广告交流群。

**↓扫描二维码进群↓**

![format_png 4][]

--------------------

**推****荐****阅****读 **

***1.*** [你在公司项目里面看过哪些操蛋的代码？][Link 1]

***2.*** [你知道 Spring Batch 吗？][Spring Batch]

***3.*** [面试题：Lucene、Solr、ElasticSearch][Lucene_Solr_ElasticSearch]

***4. ***[3 分钟带你彻底搞懂 Java 泛型背后的秘密][3 _ Java]

***5.***  [团队开发中 Git 最佳实践][Git]

![format_png 5][]

**喜****欢****文****章****，****点****个****在看 **![format_png 6][]

[Java]: https://blog.csdn.net/qq_37217713/article/details/101445094
[format_png]: /images/20210731/2a10c47af5f8400b8884e4d9494ca8e7.png
[format_png 1]: /images/20210731/86b9f91c95894676a1622fd5966575a7.png
[format_png 2]: /images/20210731/f3a418aa913048cabfb696b6dc87abae.png
[format_png 3]: /images/20210731/281acf66a7404f23ba178e4de81861e2.png
[format_png 4]: /images/20210731/a0a2a376916a4b519555601fb7ae87c0.png
[Link 1]: http://mp.weixin.qq.com/s?__biz=Mzg2MjEwMjI1Mg%3D%3D&chksm=ce0dab1bf97a220da927bb5120fbcf13d1dac380266fcf33af926fdfd6d3fcaed4c44d6c1d8b&idx=1&mid=2247490712&scene=21&sn=601de4d1e3e00360763e3978ecb3549c#wechat_redirect
[Spring Batch]: http://mp.weixin.qq.com/s?__biz=Mzg2MjEwMjI1Mg%3D%3D&chksm=ce0dab1bf97a220dfce5bdf424b75ba73e5a7aaac7c3556f3af69bb25e4e7c5fce8f6526a05b&idx=2&mid=2247490712&scene=21&sn=cf30d4ea72a8f1d41bb739cbd9cf7cfc#wechat_redirect
[Lucene_Solr_ElasticSearch]: http://mp.weixin.qq.com/s?__biz=Mzg2MjEwMjI1Mg%3D%3D&chksm=ce0dab1bf97a220d3175e0b5d75ff5886d6e6a7a556db8d53849e237c377f15b43d2744ac3ec&idx=3&mid=2247490712&scene=21&sn=43d1e0cc83c5206de631af27f711146f#wechat_redirect
[3 _ Java]: http://mp.weixin.qq.com/s?__biz=Mzg2MjEwMjI1Mg%3D%3D&chksm=ce0dabeef97a22f8a54eb5fc998512e1491e425831d4b2c98f63063603edb1aa03081264fe54&idx=3&mid=2247490669&scene=21&sn=134edfa708a8498eac2eccae2c09e441#wechat_redirect
[Git]: https://blog.csdn.net/qq_37217713/article/details/102481709
[format_png 5]: /images/20210731/02ef7a2b00ff4013be55b4e04586ecf6.png
[format_png 6]: /images/20210731/3ae05167445f4680a18a0e2388b8250a.png