後端仔的效能優化實戰(3)、Grafana與Prometheus查詢案例

前言

這說不定是你。(暴言)

等等先別離開！看完前面那麼多的資料，你是否與初代艾爾登之王葛孚雷一樣受夠了繁文縟節，我雖不鼓勵你像他一樣脫光衣服還俗成荷萊‧露，但我們可以來看幾個關於Grafana與Prometheus的實際案例，透過圖文說明，你會更清楚它的使用方法，以下文章可能包含多張示例圖片。

壓力測試下的觀測

一張常見的Grafana Dashboard長這樣，透過視覺化的圖表我們可以得知系統的當前 指標的數值，舉例來說，這張圖片是我在本地進行壓力測試的結果。左上你可以看到系統當前RPS、延遲狀況、資料庫的連線池狀況等等，當中左下圖表你可以很清楚地看到，當壓力攀升，active connection開啟提升，與Idle connection形成交叉，代表壓力開始上來，接著在active connection提升至max_connection時，pending connection開始慢慢提升，最後pending connection甚至超出了max_connection數倍，這很明顯得看得出來是資料庫的連線池的數量不夠了，右上的Hikari等待數也印證了這一點。

此外，右邊的Java Heap使用量並沒有太多變化，代表此時瓶頸與GC的關係不大，就此我們便可以往下細查，是否是@Transaction抓住太久，是否資料過多查詢導致此問題…等等，有Grafana可以讓我們在這條效能優化的路徑上面少走不少彎路。

查詢單支API P95延遲

假設你想知道 /api/v1/ticket 這支API的P95延遲(95%的請求都低於這個耗時)，在Grafana裡就會寫成這樣一條PromQL：

histogram_quantile(0.95, sum by (le) (rate(
  http_server_requests_seconds_bucket{uri="/api/v1/ticket"}[5m])))

在壓力測試的情況下，這一支API的延遲不斷上升，最後上升到 480 毫秒，這代表了 5% 的用戶將會經歷 480 或是更高的延遲，這雖然聽起來不高，但重點不是數值，而是我們測量的方法。此外，比數字本身更重要的，是趨勢。如果你看到P95延遲在短時間內持續往上爬(而不是單一尖刺)，通常代表某個資源正在被壓垮——可能是連線池被吃滿、快取失效讓請求都打去DB、或JVM進入頻繁GC。這時候拉幾條線做交叉比對會讓我們更容易找到BottleNeck而不是猜。

一般來說，API延遲的P95可以用這個粗略基準來判斷：

如果你想要知道某隻API的耗時，那麼你已經得到它了，但是，萬一我們想要更進一步了，如果一隻API有多種因素，假如說同時呼叫了內部服務、讀取檔案、敲外部服務呢，你知道API慢之後，你知道哪一個部分慢嗎？下Log一個一個測試嗎？你要產生多少Log為了這件事，會不會反而產生無效的大量資料？

所以，可以的話，我們需要一個更加詳細的分析方法。而這塊，Grafana+Prometheus可以罩你。

查詢某段程式碼的耗時

想要查詢某段程式碼的耗時，我們就避免不了寫點code，首先，我們需要在我們想要監測的區塊注入MeterRegistry這個Bean，程式碼的範例大約像是這樣

class A {
  public void someMethods() {
   // 注入 MeterRegistry

    Timer.Sample coreSample = Timer.start(meterRegistry);
    /////////// 某個耗時操作
    coreSample.stop(meterRegistry.timer("ticket.purchase.core"));

  }
}

如果一來，耗時就可以被記錄了，Prometheus裡面你就可以利用”ticket.purchase.core”這個標籤去查詢到這隻API的耗時。但是這還不夠，還記得我們的API是查詢P95的耗時嗎？為了一致，我們必須要額外做一些設定，讓它支援histogram_quantile()

management:
  metrics:
    distribution:
      percentiles-histogram:
        "[http.server.requests]": true
        "[ticket.purchase.core]": true
      percentiles:
        "[http.server.requests]": [0.5, 0.95, 0.99]
        "[ticket.purchase.core]": [0.5, 0.95, 0.99]

設定完後 我們就可以透過這個PromQL查詢出來某段程式碼的處理耗時

histogram_quantile(0.95, sum by (le) (rate(
  ticket_purchase_core_seconds_bucket[5m])))

這裡有個小地方要注意：我們在程式碼裡命名的是 ticket.purchase.core(用點分隔)，但到 PromQL 查詢時卻變成 ticket_purchase_core_seconds_bucket(用底線分隔，還多了 _seconds_bucket 這個後綴)。這不是打錯，是 Micrometer 把資料交給 Prometheus 時的命名規則轉換——Prometheus 的 metric 名稱不能有點，所以 Micrometer 會自動把點轉成底線，再依照這個指標的單位(這裡是秒)、以及它是不是 histogram，補上 _seconds 跟 _bucket 這類後綴。如果你直接拿程式碼裡的原始名字去查，會查不到任何東西，一定要轉換成 Prometheus 那邊實際的命名格式。

最後是使用結果。

雖然這次實驗結果不是很理想，但這只是舉例，未來可以用這個方法整合prometheus去分析某段程式碼的耗時，這樣我們可以更安心進行評估。