spring-boot項目啟動遲緩異常排查解決記錄

更新時間：2022年02月25日 16:16:35 作者：kl

這篇文章主要為大家介紹了spring-boot項目啟動遲緩異常排查解決記錄，突然在本地啟動不起來了，表象特征就是在本地IDEA上運行時，進程卡住也不退出，應用啟動時加載相關組件的日志也不輸出

問題背景

一個spring boot開發(fā)的項目，spring boot版本是1.5.7，攜帶的spring版本是4.1.3。開發(fā)反饋，突然在本地啟動不起來了，表象特征就是在本地IDEA上運行時，進程卡住也不退出，應用啟動時加載相關組件的日志也不輸出。癥狀如下圖：

問題分析

因為沒有有用的日志信息，所以不能從日志這個層面上排查問題。但是像這種沒有輸出日志的話，一般情況下，肯定是程序內(nèi)部啟動流程卡在什么地方了，只能通過打印下當前線程堆棧信息了解下。一般情況下，在服務器環(huán)境，我們會使用java工具包中的jstack 工具來查看：如jstack pid（應用java進程）。

但是，在IDEA本地開發(fā)的話，IDEA內(nèi)置了一個工具，可以直接查看當前應用的線程上線文信息，如：

注意下面那個箭頭指向的像照相機一樣的圖標，故圖思意，就是打印當前線程快照的的意思。點擊后，就出現(xiàn)了右邊那些線程上下文信息了，可以看到有很多的線程，我們主要關注下main線程，線程狀態(tài)確實是waiting的，接著點擊箭頭所指向的main線程，可以看到如下內(nèi)容：

"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(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中的一個安全初始化資源的一個類，代碼所示為監(jiān)聽SpringApplicationEvent事件，可以肯定的是，它的邏輯執(zhí)行到了 preinitializationComplete.await();這里，導致了線程阻塞了。正常情況下，spring會觸發(fā)ApplicationEnvironmentPreparedEvent事件完成資源的初始化，這里先不深究Spring為什么這么做，主要通過程序邏輯看下為什么卡這里了，在preinitializationComplete.await();所在行打個斷點，看下event對象里的信息，如下：

原來event是一個Spring上下文初始化失敗的異常事件對象，對象里包含了具體的異常信息，如箭頭所指，關鍵異常信息如：

NoSuchMethodError："org.springframework.util.ObjectUtils.

unwrapOptional(Ljava/lang/Object;)Ljava/lang/Object;"

假設問題

通過上面的分析，基本定位到Spring boot應用啟動卡住這個表象背后的真實原因了，而且也定位到了異常信息。

出現(xiàn)NoSuchMethodError異常，是因為調(diào)用方法的時候，找不到方法了。一般出現(xiàn)在兩個有關聯(lián)的jar包，但是版本對不上了，也就是常說的jar版本依賴沖突。查看了下，ObjectUtils是spring-core包里的一個類，當前的4.1.3版本確實沒有這個unwrapOptional方法，spring-core-5.x的版本才新增了這個方法。因為之前的依賴是沒有問題，為什么現(xiàn)在spring上下文會調(diào)用5.x的版本的方法呢？

所以先假設近期有開發(fā)在pom.xml里添加了新的的依賴，導致了這個問題。

小心求證

有了找問題的方向就好辦了，因為代碼都是git管理維護的，所以查看下pom.xml文件近期的提交記錄即可，查看后，確實發(fā)現(xiàn)了近期對pom.xml有改動，添加了一個依賴：

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

這里還涉及到一點Maven依賴優(yōu)先級的問題，在pom.xml里直接這樣添加的依賴優(yōu)先于其他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肯定得出問題啊。直接移除這個依賴，然后啟動系統(tǒng)一切正常，日志打印了Spring加載上線文的信息。

問題總結

定位這個問題的關鍵在于要了解java中線程堆棧的知識，在沒有足夠異常日志情況下通過線程快照排查問題。在定位到問題后，如NoSuchMethodError這樣的異常，需要平時的經(jīng)驗積累來假設問題的真實原因，然后在追本溯源驗明問題所在根本原因。找問題本質(zhì)一定要這種循序漸進的思路。舉例，出現(xiàn)這種問題，如果你直接去搜索引擎搜：“Spring boot應用啟動卡住了”，是搜不出來什么東西的，但是當你發(fā)現(xiàn)了是由于jar沖突。去搜索引擎搜索：