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个。
有人可以解释什么可以导致此?欢迎您提出对请求响应生命周期的深入了解。