Play(Scala)2.4.X中的请求响应生命周期

本文介绍了Play(Scala)2.4.X中的请求响应生命周期的处理方法，对大家解决问题具有一定的参考价值，需要的朋友们下面随着小编来一起学习吧！

问题描述

几天前，我遇到了一个问题，即客户端在20秒后收到来自播放应用程序的响应.我在生产服务器上设置了新的消息，该消息不断告知RPM，平均响应时间，CPU和内存使用情况等.根据新消息，响应时间不超过500毫秒，但我确认客户端在20秒后收到响应.为了挖掘更多信息，我在其中添加了日志，以告知在播放应用程序中处理请求所需的时间.我按照以下步骤添加了日志过滤器:

Few days back, I faced issue where client was receiving response from play application after 20 seconds. I have new relic set on production server which keeps telling about RPM, average response time, CPU and memory usage, etc. As per new relic response time was not exceeding 500 milli-seconds, but I verified that client was receiving response after 20 seconds. To dig out more I added logs in that tells about time required to serve request in play application. I added logs Filter as per following:

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())
  }

在负载测试期间，我向play-app发送了大约3K个并发请求，并捕获了所有请求的TCPDUMP.以下是我的观察:

During my load test, I sent around 3K concurrent requests to play-app and captured TCPDUMP for all requests. Following are my observations:

根据播放应用程序日志，播放应用程序响应所花费的最长时间为68毫秒.
根据TCPDUMP，响应任何请求所需的最长时间为10秒左右.
每个新的文物最大响应时间约为84毫秒(因为这与我添加的日志非常接近，因此我们可以忽略此日志)

据我所知，Filter是请求-响应生命周期的最后阶段之一.那么，如果Filter中的日志显示该请求需要68毫秒，而TCPDUMP声称该响应是在10秒后发送的，那么造成响应请求延迟的原因是什么?

As far as I know Filter is one of the last stage in request-response life cycle. So if logs in Filter says that request needed 68 milli-seconds and TCPDUMP claims that response was sent after 10 seconds then what caused delay in responding the request?

我了解到，在多线程环境中，在执行特定语句后可能会进行上下文切换.但是上下文切换不应引起这么多的延迟.根据此新测试，在此负载测试中，线程数少于50.

I understand that in multi-threading environment there is possibility of context switch after particular statement execution. But context switch should not cause this much delay. As per new relic there were less than 50 threads during this load test.

有人可以解释什么原因吗?欢迎您在请求-响应生命周期中提供深刻的见解.

Can someone explain what can cause this? You are welcome to provide deep insights in request-response life cycle.

relic

Play(Scala)2.4.X中的请求响应生命周期

问题描述

推荐答案