postgresql – Play Framework 2.5请求随机超时

症状

运行一段时间后,我们的后端将停止为其大多数端点提供响应.它会开始表现得像黑洞那样.一旦进入这种状态,如果我们不采取任何行动,它将留在那里.

更新

我们可以使用我们在后端处于非响应状态时进行的数据库转储来重现此行为.

基础设施设置

我们在AWS上运行Play 2.5,在具有RDS上的PostgreSQL数据库的负载均衡器后面的EC2实例上运行.我们使用slick-pg作为数据库连接器.

我们知道什么

这里有一些我们到目前为止所发现的事情.

关于HTTP请求

我们的日志和调试向我们显示请求正在通过过滤器.此外,我们看到对于身份验证(我们使用Silhoutte),应用程序能够执行数据库查询以接收该请求的标识.但是,控制器动作永远不会被调用.

后端正在响应HEAD请求.进一步的日志记录向我们表明,似乎控制器使用注入服务(我们使用googles guice),其方法不再被调用.没有注入服务的控制器似乎工作正常.

关于EC2实例

不幸的是,我们无法从那个获得太多信息.我们正在使用boxfuse,它为我们提供了一个不可变的基础设施.我们即将将其更改为基于docker的部署,并且可能很快就能提供更多信息.不过,我们有New Relic设置来监控我们的服务器.我们在那里找不到任何可疑的东西.内存和CPU使用情况看起来很好.

尽管如此,这种设置仍然为我们提供了每个部署的新EC2实例.即使在重新部署之后,该问题至少在大多数时间内仍然存在.最终可以通过重新部署来解决这个问题.

更奇怪的是,我们可以在AWS上运行本地连接到数据库的后端,一切都可以正常工作.

所以我们很难说问题出在哪里.似乎数据库不能与任何EC2实例一起使用(直到它最终将与新的实例一起使用),而是使用我们的本地机器.

关于数据库

db是此设置中唯一的有状态实体,因此我们认为问题应该以某种方式与之相关.

由于我们有生产和暂存环境,因此当后者不再工作时,我们可以将生产数据库转储到暂存中.我们发现这确实立即解决了这个问题.不幸的是,我们无法从某个腐败的数据库中获取快照,将其转储到暂存环境中,看看是否会立即破坏它.当后端没有响应时,我们有一个db的快照.当我们将其转储到我们的暂存环境时,后端将立即停止响应.

根据AWS控制台,数据库的连接数大约为20,这是正常的.

TL; DR

>我们的后端最终开始表现为某个端点的黑洞
>请求未到达控制器操作
> EC2中的新实例可能会解决此问题,但不一定如此
>本地与相同的数据库一切正常
>将一个有效的数据库转储到它可以解决问题
> EC2实例的CPU和内存使用情况以及与DB的连接数看起来都很好
>我们可以使用我们在后端没有响应时进行的db转储重现行为(请参阅更新2)
>使用新的光滑线程池设置,我们将在重新启动数据库后重新启动我的ec2实例,从而获得ThreadPoolExecutor异常. (见更新3)

更新1

回应marcospereira：

以ApplicationController.scala为例：

package controllers

import scala.concurrent.ExecutionContext.Implicits.global
import scala.concurrent.Future

import akka.actor.ActorRef
import com.google.inject.Inject
import com.google.inject.name.Named
import com.mohiva.play.silhouette.api.Silhouette
import play.api.i18n.{ I18nSupport,MessagesApi }
import play.api.mvc.Action
import play.api.mvc.Controller

import jobs.jobproviders.BatchJobChecker.UpdateBasedOnResourceAvailability
import utils.auth.JobProviderEnv

/**
 * The basic application controller.
 *
 * @param messagesApi The Play messages API.
 * @param webJarAssets The webjar assets implementation.
 */
class ApplicationController @Inject() (
  val messagesApi: MessagesApi,silhouette: Silhouette[JobProviderEnv],implicit val webJarAssets: WebJarAssets,@Named("batch-job-checker") batchJobChecker: ActorRef
)
    extends Controller with I18nSupport {


  def index = Action.async { implicit request =>
    Future.successful(Ok)
  }

  def admin = Action.async { implicit request =>
    Future.successful(Ok(views.html.admin.index.render))
  }


  def taskChecker = silhouette.SecuredAction.async {
    batchJobChecker ! UpdateBasedOnResourceAvailability
    Future.successful(Ok)
  }

}

索引和管理员工作正常.然而,taskchecker将显示奇怪的行为.

更新2

我们现在能够重现这个问题！我们发现上次我们的后端没有响应时我们进行了数据库转储.当我们将其转储到我们的临时数据库时,后端将立即停止响应.

我们开始使用Thread.getAllStackTraces.keySet.size在我们的一个过滤器中记录线程数,发现有50到60个线程正在运行.

更新3

作为@AxelFontaine suggested,我们为数据库启用了MultiAZ部署故障转移.我们通过故障转移重新启动了数据库.在重新启动之前,期间和之后,后端没有响应.

在重新启动之后,我们注意到与db的连接数保持为0.此外,我们不再获得任何身份验证日志(在我们这样做之前,身份验证步骤甚至可以生成db请求并获得响应).

重新启动EC2实例后,我们现在开始了

play.api.UnexpectedException：意外异常[RejectedExecutionException：任务slick.backend.DatabaseComponent$DatabaseDef$$anon$2@76d6ac53从java.util.concurrent.ThreadPoolExecutor@6ea1d0ce中被拒绝[正在运行,池大小= 4,活动线程= 4,排队tasks = 5,已完成的任务= 157]]

(我们之前没有得到那些)

对于我们的请求以及需要访问数据库的后台作业.我们的光滑设置现在包括

numThreads = 4
queueSize = 5
maxConnections = 10
connectionTimeout = 5000
validationTimeout = 5000

正如建议here

更新4

在我们得到更新3中描述的异常后,后端现在再次正常运行.我们没有为此做任何事情.这是后端第一次在没有我们参与的情况下从这个州恢复过来.

myapp = {
  database = {
    driver = org.h2.Driver
    url = "jdbc:h2:./test"
    user = "sa"
    password = ""

    // The number of threads determines how many things you can *run* in parallel
    // the number of connections determines you many things you can *keep in memory* at the same time
    // on the database server.
    // numThreads = (core_count (hyperthreading included))
    numThreads = 4

    // queueSize = ((core_count * 2) + effective_spindle_count)
    // on a MBP 13,this is 2 cores * 2 (hyperthreading not included) + 1 hard disk
    queueSize = 5

    // https://groups.google.com/forum/#!topic/scalaquery/Ob0R28o45eM
    // make larger than numThreads + queueSize
    maxConnections = 10

    connectionTimeout = 5000
    validationTimeout = 5000
  }
}

import play.api.libs.concurrent.Futures._

class PostAction @Inject()(messagesApi: MessagesApi)(
    implicit ec: ExecutionContext)
    extends ActionBuilder[PostRequest]
    with HttpVerbs {

  type PostRequestBlock[A] = PostRequest[A] => Future[Result]

  private val logger = org.slf4j.LoggerFactory.getLogger(this.getClass)

  override def invokeBlock[A](request: Request[A],block: PostRequestBlock[A]): Future[Result] = {
    if (logger.isTraceEnabled()) {
      logger.trace(s"invokeBlock: request = $request")
    }

    val messages = messagesApi.preferred(request)
    val future = block(new PostRequest(request,messages))

    future.map { result =>
      request.method match {
        case GET | HEAD =>
          result.withHeaders("Cache-Control" -> s"max-age: 100")
        case other =>
          result
      }
    }
  }
}