Жизненный цикл запроса-ответа в Play (Scala) 2.4.X

Question

Несколько дней назад я столкнулся с проблемой, когда клиент получал ответ от игрового приложения через 20 секунд. У меня есть новая реликвия, установленная на производственном сервере, которая постоянно рассказывает об RPM, среднем времени отклика, использовании процессора и памяти и т. Д. Согласно новому времени реликвийного ответа не превышало 500 миллисекунд, но я подтвердил, что клиент получил ответ через 20 секунд , Чтобы выложить больше, я добавил журналы, в которых говорится о времени, которое требуется для запроса запроса в игровом приложении. Я добавил журналы Фильтра согласно следующему:

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 для всех запросов. Ниже приводятся мои наблюдения:

1. В соответствии с игрой-приложением-протоколом максимальное время воспроизведения приложения было принято в ответ 68 миллисекунд.
2. В соответствии с максимальным временем отклика TCPDUMP для любого запроса было около 10 секунд.
3. Согласно новому времени реликвии максимума отклика был около 84 миллисекунды (как это очень близко к журналам, которые я добавил, мы можем игнорировать эту)

Насколько я знаю, фильтр один из последних этап жизненного цикла запроса-ответа. Поэтому, если журналы в фильтре говорят, что для этого запроса требуется 68 миллисекунд, а TCPDUMP утверждает, что ответ был отправлен через 10 секунд, что вызвало задержку в ответе на запрос?

Я понимаю, что в многопоточной среде существует возможность переключения контекста после выполнения конкретной инструкции. Но контекстный переключатель не должен вызывать такую ​​задержку. В соответствии с новой реликвией во время этого теста нагрузки было менее 50 нитей.

Может кто-нибудь объяснить, что может вызвать это? Вы можете предоставить глубокое понимание жизненного цикла запроса-ответа.

Answer 1

Я смог исправить проблему выше, увеличив предел FD. FD вызывал поздний ответ.