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

ice_image發表於2021-03-12
JVM

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，然後修改程式，將全形輸入法下的空格剔除，再次進行轉換，服務正常。

相關文章