測量外部服務請求的執行時間對於效能監控和最佳化至關重要。但是，當對這些外部服務的連線進行池化時，您可能會無意中測量的不僅僅是請求時間。具體來說，如果請求花費的時間太長並且您耗盡了可用連接，則您的自訂邏輯可能會開始包括從池中獲取連接的等待時間。這可能會導致誤導性指標，導致您誤解系統的效能。讓我們深入研究一下這是如何發生的，以及如何避免被自己的指標愚弄。
當池中的所有連線都在使用時，其他請求必須等待，直到連線可用。如果不與實際請求時間分開衡量，此等待時間可能會扭曲您的指標。
如果您的自訂邏輯測量從發出請求到收到回應的總時間，則您將包括等待時間和請求時間。
為了說明如何在連線池環境中被自己的指標所欺騙，讓我們來看一個使用 Spring Boot 和 Apache HttpClient 5 的實際範例。我們將設定一個簡單的 Spring Boot 應用程序，該應用程式向外部服務，測量這些請求的執行時間，並演示連接池耗盡如何導致誤導性指標。
為了模擬外部服務的延遲，我們將使用 httpbin Docker 映像。 Httpbin 提供了一個易於使用的 HTTP 請求和回應服務，我們可以使用它來在請求中建立人為延遲。
@SpringBootApplication
@RestController
public class Server {
public static void main(String... args) {
SpringApplication.run(Server.class, args);
}
class TimeClientHttpRequestInterceptor implements ClientHttpRequestInterceptor {
@Override
public ClientHttpResponse intercept(HttpRequest request, byte[] body, ClientHttpRequestExecution execution)
throws IOException {
var t0 = System.currentTimeMillis();
try {
return execution.execute(request, body);
} finally {
System.out.println("Request took: " + (System.currentTimeMillis() - t0) + "ms");
}
}
}
@Bean
public RestClient restClient() {
var connectionManager = new PoolingHttpClientConnectionManager();
connectionManager.setMaxTotal(2); // Max number of connections in the pool
connectionManager.setDefaultMaxPerRoute(2); // Max number of connections per route
return RestClient.builder()//
.requestFactory(new HttpComponentsClientHttpRequestFactory(
HttpClients.custom().setConnectionManager(connectionManager).build()))
.baseUrl("http://localhost:9091")//
.requestInterceptor(new TimeClientHttpRequestInterceptor()).build();
}
@GetMapping("/")
String hello() {
return restClient().get().uri("/delay/2").retrieve().body(String.class);
}
}
在上面的程式碼中，我們建立了一個請求攔截器 (ClientHttpRequestInterceptor) 來測量我們認為對 httpbin 支援的外部服務的請求的執行時間。
我們也明確地將池設定為非常小的 2 個連接，以便於重現問題。
現在我們只需要啟動httpbin，運行我們的spring boot應用程式並使用ab進行簡單的測試
$ docker run -p 9091:80 kennethreitz/httpbin
ab -n 10 -c 4 http://localhost:8080/ ... Percentage of the requests served within a certain time (ms) 50% 4049 66% 4054 75% 4055 80% 4055 90% 4057 95% 4057 98% 4057 99% 4057 100% 4057 (longest request)
Request took: 2021ms Request took: 2016ms Request took: 2022ms Request took: 4040ms Request took: 4047ms Request took: 4030ms Request took: 4037ms Request took: 4043ms Request took: 4050ms Request took: 4034ms
如果我們看一下數字，我們可以看到，即使我們為外部伺服器人為設定了 2 秒的延遲，但對於大多數請求來說，實際上我們得到了 4 秒的延遲。此外，我們注意到只有第一個請求遵循配置的 2 秒延遲，而後續請求會導致 4 秒的延遲。
在遇到奇怪的程式碼行為時，分析至關重要，因為它可以識別效能瓶頸，發現記憶體洩漏等隱藏問題，並顯示應用程式如何使用系統資源。
這次我們將在進行 ab 負載測試時使用 JFR 分析正在運行的應用程式。
$ jcmd <pid> JFR.start name=app-profile duration=60s filename=app-profile-$(date +%FT%H-%M-%S).jfr
$ ab -n 50 -c 4 http://localhost:8080/ ... Percentage of the requests served within a certain time (ms) 50% 4043 66% 4051 75% 4057 80% 4060 90% 4066 95% 4068 98% 4077 99% 4077 100% 4077 (longest request)
如果我們打開 JFR 檔案並查看火焰圖，我們可以看到大部分執行時間都花在了 HTTP 用戶端上。客戶端的執行時間分為等待我們的外部服務回應和等待從池中取得連線。
這解釋了為什麼我們看到的回應時間是我們為外部伺服器設定的預期固定延遲 2 秒的兩倍。我們配置了 2 個連接的池。然而，在我們的測試中，我們執行 4 個並發請求。因此，只有前 2 個請求將在 2 秒的預期時間內滿足。後續請求將必須等待池釋放連接，從而增加觀察到的回應時間。
如果我們再次查看火焰圖，我們還可以發現為什麼ClientHttpRequestInterceptor 測量的時間並不反映外部伺服器回應的時間，而是反映從池中獲取連接所需的時間加上它所花費的時間向外部伺服器執行實際請求。我們的攔截器實際上包裝了一個堆疊跟踪，最終調用池管理器來獲取連接：PoolingHttpClientConnectionManager
監控任何 HTTP 用戶端的回應時間最好使用其內建指標來完成，因為這些指標是專門為捕獲精確的計時資訊而設計的。它們負責 HTTP 請求生命週期的各個方面，包括連接獲取、資料傳輸和回應處理。這確保了測量結果準確且與客戶的實際表現一致。
以上是指標可能會欺騙您：測量連接池環境中的執行時間的詳細內容。更多資訊請關注PHP中文網其他相關文章！
