1
幾天後,我遇到了客戶端在20秒後收到來自應用程序響應的問題。我在生產服務器上設置了新的文件,它不斷告知RPM,平均響應時間,CPU和內存使用情況等。根據新文件響應時間不超過500毫秒,但我證實客戶端在20秒後正在接收響應。爲了挖掘更多,我添加了日誌,以說明在播放應用程序中爲請求提供服務所需的時間。我添加日誌過濾器按照以下內容:Play(Scala)中的請求響應生命週期2.4.X
val noCache = Filter { (next, rh) =>
val startTime = System.currentTimeMillis
next(rh).map { result =>
val requestTime = System.currentTimeMillis - startTime
Logger.warn(s"${rh.method} ${rh.uri} took ${requestTime}ms and returned ${result.header.status}")
result.withHeaders(
PRAGMA -> "no-cache",
CACHE_CONTROL -> "no-cache, no-store, must-revalidate, max-age=0",
EXPIRES -> serverTime
)
}
}
private def serverTime = {
val calendar = Calendar.getInstance()
val dateFormat = new SimpleDateFormat(
"EEE, dd MMM yyyy HH:mm:ss z")
dateFormat.setTimeZone(calendar.getTimeZone)
dateFormat.format(calendar.getTime())
}
在我的負載測試,我送3K左右的併發請求以播放應用程序,並捕獲TCPDUMP所有請求。以下是我的觀察結果:
- 根據play-application-log,max app play app的響應時間爲68毫秒。
- 根據TCPDUMP響應任何請求所需的最長時間約爲10秒。
- 按照新的遺物最大響應時間約爲84毫秒(因爲這是非常接近我說,我們可以忽略這個日誌)
據我所知過濾器是最後一個在請求 - 響應生命週期階段。因此,如果Filter中的日誌表示該請求需要68毫秒並且TCPDUMP聲稱響應在10秒後發送,那麼響應請求的延遲是什麼?
我知道在多線程環境中,在特定的語句執行後可能會發生上下文切換。但是上下文切換不應該造成這麼大的延遲。根據新的文獻,在這次負載測試中,線程少於50個。
有人可以解釋什麼可以導致此?歡迎您提出對請求響應生命週期的深入瞭解。