JVM實戰調優(空格引發的服務異常)

ice_image發表於2021-03-12

JVM實戰調優

問題描述

某一個專案中有一個文字轉語音的服務,使用的是科大訊飛的語音轉換服務,需要呼叫三方服務。因其轉換服務是一個耗時操作,官方給的demo使用的是 WebSocket 進行資料轉換操作。專案中使用執行緒池進行呼叫。同時科大訊飛的語音合成有長度限制,官方給出的在[8000位元組,約2000個漢字],所以需要分段合成。

在某一天,客戶反應語音無法播放,經過檢視服務日誌排查,是因為購買的服務到期了,客戶重新購買了其餘的服務,引數發生了改變,以前的引數無法使用。更改了引數之後,更新部署之後,服務恢復正常。又過了幾天,客戶反應語音又無法播放了,經過檢視日誌,發現大部分是成功的,部分發生了失敗。

調優過程

檢視日誌的時候,發現部分失敗的原因是connection fail,通過 jps 找到對應的應用程式程式號。

然後通過 top -Hp PID 檢視了一個CPU和記憶體的佔用率,都是正常的佔用。

因其使用了執行緒池,懷疑是執行緒池佔滿了,用 就 stack pid 檢視執行緒池之後,發現滿了。

"OkHttp ConnectionPool" #48 daemon prio=5 os_prio=0 tid=0x00007f8d90002800 nid=0x2a7a in Object.wait() [0x00007f8dea5a5000]
   java.lang.Thread.State: TIMED_WAITING (on object monitor)
	at java.lang.Object.wait(Native Method)
	at java.lang.Object.wait(Object.java:460)
	at okhttp3.internal.Util.waitMillis(Util.kt:536)
	at okhttp3.internal.Util.lockAndWaitNanos(Util.kt:522)
	- locked <0x000000076e9394f8> (a okhttp3.internal.connection.RealConnectionPool)
	at okhttp3.internal.connection.RealConnectionPool$cleanupRunnable$1.run(RealConnectionPool.kt:49)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	at java.lang.Thread.run(Thread.java:748)

"pool-1-thread-3" #46 prio=5 os_prio=0 tid=0x00007f8dd4013000 nid=0x2a78 waiting on condition [0x00007f8deaaa8000]
   java.lang.Thread.State: WAITING (parking)
	at sun.misc.Unsafe.park(Native Method)
	- parking to wait for  <0x000000076ea3d738> (a java.util.concurrent.CountDownLatch$Sync)
	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 com.baiying.trstts.factory.XfTts.getPcm(XfTts.java:206)
	at com.baiying.trstts.factory.XfTts.text2speechV3(XfTts.java:236)
	at com.baiying.trstts.controller.TextToSpeechControllerV3.lambda$text2Speech$0(TextToSpeechControllerV3.java:56)
	at com.baiying.trstts.controller.TextToSpeechControllerV3$$Lambda$426/909090985.run(Unknown Source)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	at java.lang.Thread.run(Thread.java:748)

通過異常資訊,可以看到是 CountDownLatch 阻塞了整個執行緒,導致其無法結束,通過走查程式碼發現,程式中只是在正常結束的時候會 countDown() 喚醒執行緒,繼續向下執行,在失敗的時候並不會喚醒執行緒,遂在程式中增加了在失敗的時候也會進行 countDown() 喚醒執行緒,程式重新部署之後,程式正常。

為了防止出現問題,這次對程式的日誌進行了監控,將失敗的文章進行了重新轉換,雖然執行緒可以正常結束,但是轉換仍然會出現失敗,經過對文字進行嚴格的分析和多次轉換測試,有一小段文字被擷取了出來,觀察了一會沒有發現異常,通過十六進位制軟體對其進行檢視,才發現兩個字元有區別,兩個字元都是空格,但前一個空格是半形輸入法下的空格十六進位制是20,全形輸入法下的空格是 E38080,然後修改程式,將全形輸入法下的空格剔除,再次進行轉換,服務正常。

相關文章