問題描述

• 線上突然出現Dubbo超時調用，時間剛好為Consumer端設置的超時時間。
• 有好幾個不同的接口都報超時了
• 第1次調用超時，第2次（或第3次）重試調用非常快（正常水平）
• Dubbo調用超時的情況集中出現了3次，每次都是過一會自動恢復

排查

排查日志

看到調用超時，首先就拿著traceId去服務提供方查日志。 奇怪的是，在服務提供方的業務日志里面，只有正常的調用日志（耗時正常），沒有超時調用的日志。 從正常的調用日志里面看，一切都是正常的，看不出所以然。 給人的感覺就是超時那次請求的調用沒有達到服務提供方。

此時系統活動情況

通過系統歷史監控，我們發現除了gc比平時稍微高一點外（也在正常水位），沒有其他的異常；CPU、內存、網絡等指標都在正常范圍。

查看Dubbo線程活動情況

第2次系統集中超時報警的做的第一件事就是登錄到那臺服務器查看dubbo線程活動情況：看下能不能找到阻塞在哪一行代碼。很遺憾，所有的dubbo線程都沒有阻塞，都是正常的WAITING狀態。

并沒有明顯表明阻塞在某段代碼，這可難倒我們了：如果沒有阻塞的話，為什么dubbo調用方會報超時？繼續看代碼

該接口是否存在阻塞的代碼？

硬著頭皮重新看代碼每一個分支，突然發現底層的一個方法中有http調用！會不會是這個http調用導致的超時？如果是的話，那么不同的接口調用超時的情況就說的通了，因為上層大部分接口都會調用這個底層方法。

懷揣著激動的心，仔細看了http調用的邏輯：用的是JDK提供的HttpURLConnection，其中只用了HttpURLConnection#getContentLength方法，并且也在finally代碼塊中將這個連接關閉了。好像也不是這個引起的，起初還以為getContentLength會把文件給下載下來，但是看了接口文檔以后發現只會去讀頭信息中的ContentLength。

/*** Returns the value of the {@code content-length} header field.* <p>* <b>Note</b>: {@link #getContentLengthLong() getContentLengthLong()}* should be preferred over this method, since it returns a {@code long}* instead and is therefore more portable.</p>** @return the content length of the resource that this connection's URL* references, {@code -1} if the content length is not known,* or if the content length is greater than Integer.MAX_VALUE.*/public int getContentLength() {long l = getContentLengthLong();if (l &gt; Integer.MAX_VALUE)return -1;return (int) l;}

代碼阻塞的情況可能性也不大，因為重試請求不會超時：如果代碼阻塞，那么重試請求大概率也會超時。

數據訪問層是否有異常情況

既然代碼沒有阻塞，那么有沒有可能是數據訪問層的異常造成的呢？畢竟不止一個接口存在超時的問題，如果是底層數據訪問層的異常導致，那么也說得通。

重點排查了mysql，但結果是令人失望的：并沒有慢SQL；并且dubbo超時期間，mysql實例的CPU和內存水位都是正常的。

除了mysql、redis實例本身指標正常外，基于上面同樣的理由：如果數據訪問層有問題，那么重試基本上也會超時。所以數據訪問層導致超時的線索也被排除。

有沒有可能是Dubbo層面的問題

排查再次陷入僵局，逼迫著我們重新梳理排查思路：

除了代碼阻塞

除了數據訪問層異常

除了超時請求，其他請求的日志都是正常的

那么還有可能會導致超時呢？會不會是Dubbo本身異常導致的？

此時有一個關鍵的線索進入我們的視野：超時的那次請求去哪兒了？

在服務提供方的日志里面沒有超時請求的的日志，只有重試請求成功的業務日志。太奇怪了，就算超時總的留下日志的吧，日志都不留，欺負我胖虎嗎？！

到這里想到超時的請求可能是一個突破口，于是開始看Dubbo的相關的源碼和文檔。

從官方文檔中的服務端調用鏈一層層往下查

在AllChannelHandler源碼中看到了令人興奮的注釋：

興奮之余，為了避免理解偏差，還特地用百度翻譯了一下

滿了，那么服務端不會返回，直到客戶端超時！這不是正式我們碰到的問題嗎？！ 并且此時還沒有進入業務代碼，所以沒有打印業務日志，這樣就可以解釋為什么沒有服務提供方沒有超時請求的日志了。

別激動，這里明明有返回threadpool is exhausted異常信息，怎么能說沒有返回呢？ 別急，這是另外一個項目引用的dubbo，版本是2.6.2。 回到出問題的那個項目，查看dubbo版本：2.8.6，查看AllChannelHandler源碼：是的在2.8.6版本中，并沒有這個返回錯誤

題好像找到了，OK，剩下的就是驗證了。

驗證

準備

• 將DubboServerHandler線程池的最大線程數調到5
• 使用Apache Bench進行壓測：200請求、并發10個線程

case1：復現問題

• Dubbo使用2.8.6版本
• 預期：部分請求超時報錯，重試耗時正常
• 壓測結果符合預期：部分接口報錯超時，并且重試請求耗時正常

case2：驗證猜想

• Dubbo使用2.6.2版本
• 預期：部分請求報錯線程池耗盡threadpool is exhausted，并且重試大概率也會報該錯誤
• 壓測結果符合預期

至此，基本判定線上Dubbo調用超時的問題就是因為線程池耗盡引起的。

這個超時問題前前后后查了一周左右，排查過程中試了很多排查方向，為了敘述方便就沒有展開。

避坑指南

合理設置Dubbo線程池大小。默認是200

合理設置超時時間。如果真出現了Dubbo調用超時的情況，合理的超時時間能夠避免服務調用方被打爆

Dubbo接口必須有返回值。從AllChannelHandler#received的源碼和注釋中可以看到只有有返回值的接口才會返回線程池耗盡的錯誤信息；其它的情況則不會將錯誤信息返回給調用方，直到調用方超時。

總結

以上是生活随笔為你收集整理的dubbo官方文档_不可忽视的Dubbo线程池的全部內容，希望文章能夠幫你解決所遇到的問題。

如果覺得生活随笔網站內容還不錯，歡迎將生活随笔推薦給好友。