【发布时间】:2017-06-17 03:15:28
【问题描述】:
在我们的 scala/play 应用程序中,我们有一个通常需要大约一秒钟才能响应的请求。大约 2-4% 的请求需要大约 61 秒来响应 - 并且 webproxy 会超时请求 (504)。 61 秒看起来有点像超时。
我正在尝试从日志中获取更多信息,但它们在这 61 秒内保持沉默。我尝试将 play 和 io.netty 设置为 DEBUG 级别,但没有找到任何东西。一个成功的响应,然后是下一个请求(1.4 秒间隔)看起来像
2017-01-31 13:13:09,931 - [DEBUG] - from com.xxx.api.controllers.Api in monolith-akka.actor.default-dispatcher-34
new Result created - .. ..
2017-01-31 13:13:11,318 - [DEBUG] - from com.xxx.api.controllers.Api in monolith-
akka.actor.default-dispatcher-34
Upload media - .. ..
下一个请求之后的响应与 61 秒间隔看起来像
2017-01-31 13:12:08,624 - [DEBUG] - from com.xxx.api.controllers.Api in monolith-akka.actor.default-dispatcher-31
new Result created - .. ..
2017-01-31 13:13:09,892 - [DEBUG] - from com.xxx.controllers.Api in monolith-akka.actor.default-dispatcher-34
Upload media - .. ..
有没有人对配置 logback.xml 有任何建议,告诉我 13:12:08 到 13:13:09 之间发生了什么。
【问题讨论】:
-
代码中哪里有日志?
-
uploadMedia()为控制器实现方式,参考routes配置。 上传媒体 .. 是方法中的第一条语句,new Result created .. 是方法中的最后一条语句。 -
在我能找到的所有日志上将级别设置为 TRACE,我已将延迟缩小到以下两行,这表明延迟发生在 Play 框架内。
xx:x5:45,640 play.core.server.netty.PlayRequestHandler in netty-event-loop-1 Http request received by nettyxx:x6:45,630 play.api.mvc.Action in monolith-akka.actor.default-dispatcher-23 Invoking action with request
标签: scala playframework netty logback