聊聊線上高延遲請求排查，你學會了嗎？
前幾天排查了一個業務接口執行高延遲的問題，也挺有參考意義的，分享一下排查過程。
現象是業務反饋有一個接口業務邏輯其實很簡單，但是調用一次耗時，如下圖所示：
圖片
排查應用運行狀態
首先第一步需要查看當時的應用運行狀態，包含當時的日志、JVM 的各種監控等。
因為我們接入了 OpenTelemetry，所以 trace 和日志是可以關聯起來的。
點擊鏈路系統旁邊的日志按鈕可以直接跳轉。
可以通過 trace_id 查詢到相關日志：
圖片
通過日志可以看出耗時大約在 4s 多一點，然后結合代碼發現這兩段日志分別是在進入一個核心業務方法之前和方法內打印的。
圖片
而第一行日志是在一個自定義限流器中打印的，這個限流器是使用 Guava 的 RateLimiter實現的。
我的第一反應是不是這個限流器當時限流了，從而導致阻塞了；但查看了當時的 QPS 發現完全低于限流器的配置，所以基本可以排除它的嫌疑了。
JVM 監控
圖片
圖片
之后我們查詢當時的 JVM 監控發現當時的 GC 頻繁，而堆內存也正好發生了一次回收，初步判斷是 GC 導致的本次問題。
但為啥會導致頻繁的 GC 呢，還需要繼續排查。
內存排查
我們在應用診斷中集成了 Pyroscope的持續剖析，可以實時查看內存的占用情況。
圖片
圖片
通過內存分析發現有大量的 JSON 序列化占用了大量的內存，同時還發現 Pod 已經被重啟好幾次了：
圖片
圖片
查看原因發現是 Pod OOM 導致的。
因此非常有可能是 GC 導致的，恰好那段時間發生了 GC 內存也有明顯變化。
圖片
圖片
圖片
最后再通過 arthas 確認了 GC 非常頻繁，可以確認目前的資源是是非常緊張的，咨詢業務之后得知該應用本身占用的資源就比較大，沒有太多優化空間，所以最終決定還是加配置。
圖片
圖片
還是提高硬件效率最高，目前運行半個月之后 Pod 內存表現穩定，沒有出現一次 OOM 的異常。
總結
雖然最后的處理的方式是簡單粗暴的，但其中的過程還是有意義的，遇到不同的情況也有不同的處理方式。
比如在排查過程中發現內存消耗異常，通過內存分析發現代碼可以優化，那就優化代碼邏輯。
如果是堆內存占用不大，但是 Pod 還是 OOM 導致重啟，那就要看看 JVM 的內存分配是否合理，應該多預留一些內存給堆外使用。
但這個過程需要有完善的可觀測系統的支撐，比如日志、監控等，如果沒有這些數據，再回頭排查問題就會比較困難。
