0
votes

I have a Play Application running using HikariCP jdbc connection pool.

The application will run fine for a while but after a short period of time it will shut down the connection pool meaning I can no longer use the application.

SBT build:

name := "virtual-betting"
version := "1.0"

lazy val root = (project in file(".")).enablePlugins(PlayJava).settings(javacOptions ++= Seq("-source", "1.8", "-target", "1.8"))

scalaVersion := "2.11.8"

libraryDependencies ++= Seq(
  javaJdbc,
  javaJpa,
  javaJpa.exclude("org.hibernate.javax.persistence", "hibernate-jpa-2.1-api"),
  "org.hibernate" % "hibernate-core" % "5.1.0.Final",
  "org.hibernate" % "hibernate-entitymanager" % "5.1.0.Final",
  "com.typesafe.play" % "play-java-jpa_2.11" % "2.5.3",
  "org.springframework" % "spring-context" % "4.2.4.RELEASE",
  "org.webjars" % "bootstrap" % "3.3.4",
  "mysql" % "mysql-connector-java" % "5.1.42",
  cache,
  javaWs,
  "org.jsoup" % "jsoup" % "1.7.2",
  "org.apache.commons" % "commons-email" % "1.4",
  "org.apache.cxf" % "cxf-rt-rs-client" % "3.1.6",
  "com.google.code.gson" % "gson" % "2.7",
  "com.squareup.okhttp3" % "okhttp" % "3.4.1"
)

fork in run := false


fork in run := true

application.conf:

## Database Connection Pool
# https://www.playframework.com/documentation/latest/SettingsJDBC
# ~~~~~
# Play doesn't require a JDBC database to run, but you can easily enable one.
#
# libraryDependencies += jdbc
#

play.db {
  # The combination of these two settings results in "db.default" as the
  # default JDBC pool:
  config = "db"
  default = "default"

  pool = "hikaricp"
  # Play uses HikariCP as the default connection pool.  You can override
  # settings by changing the prototype:

  prototype {
    pool = "hikaricp"

    # Sets a fixed JDBC connection pool size of 50
    hikaricp.minimumIdle = 0
    hikaricp.maximumPoolSize = 30
    hikaricp.connectionTimeout = 30000
    hikaricp.idleTimeout = 600000
    hikaricp.maxLifetime = 1800000
    hikaricp.leakDetectionThreshold = 5000
    hikaricp.connectionTestQuery = "SELECT 1"
    hikaricp.readOnly = false

    hikari.dataSourceClassName = com.mysql.jdbc.jdbc2.optional.MysqlDataSource
    # The database url
    #url = "jdbc:mysql://localhost:3306/madduxsp_sportsbook?autoReconnect=true&useUnicode=true&characterEncoding=UTF-8"

    registerMBeans = true
    poolName = "sportsbook_pool"
  }
}

db.default.driver=com.mysql.jdbc.Driver
db.default.url="jdbc:mysql://localhost:3306/madduxsp_sportsbook_new?autoReconnect=true&useUnicode=true&characterEncoding=UTF-8"
db.default.username=root
db.default.password=mypassword
db.default.jndiName=DefaultDS
jpa.default=defaultPersistenceUnit

application.secret="mysecret"

spring.context.location=application-context.xml

I've written some code to keep the DB connection alive, that works, in case it is shut down due to inactivity.

My DbKeepAliveService:

package services;

import play.Logger;
import play.db.jpa.JPAApi;
import util.DbKeepAliveTask;

import javax.inject.Inject;
import javax.inject.Singleton;
import java.util.Timer;

@Singleton
public class DbKeepAliveService {

    private final JPAApi jpa;

    @Inject
    public DbKeepAliveService(JPAApi jpa) {
        this.jpa = jpa;

        DbKeepAliveTask dbKeepAliveTask = new DbKeepAliveTask(jpa);
        Logger.info("Application has started");

        Timer timer = new Timer("dbKeepAlive", true);
        timer.schedule(dbKeepAliveTask, 0, 1200000);
    }
}

Except this doesn't work. Here are my logs:

2017-05-06 06:12:15,010 [INFO] from application in dbKeepAlive - Keeping database connection alive...
2017-05-06 06:32:15,010 [INFO] from application in dbKeepAlive - Keeping database connection alive...
2017-05-06 06:52:15,010 [INFO] from application in dbKeepAlive - Keeping database connection alive...
2017-05-06 06:58:35,894 [INFO] from application in Thread-8 - Application shutdown...
2017-05-06 06:58:36,054 [INFO] from application in Thread-8 - Shutting down connection pool.

Does anyone have any ideas why it might keep shutting down the Db Connection pool? I suspect it is something to do with my configuration but I honestly can't be sure.

I also read it could be to do with not running the application in Production mode but I've set the secret.

I run the application using the following command:

./bin/virtual-betting -Dconfig.file=conf/production.conf -Dplay.crypto.secret="mysecret" &

With the play.crypto.secret property set in the conf/production.conf file.

Been looking at this for a long time so help is majorly appreciated!

3

3 Answers

6
votes

Looking at the logs you have provided indicates that the reason for the database connection pool shutting down is because the application (play) has shut down.

As stated in the Play documentation:

When you run the start command, Play forks a new JVM and runs the default Netty HTTP server. The standard output stream is redirected to the Play console, so you can monitor its status.

The server's process id is displayed at bootstrap and written to the RUNNING_PID file. To kill a running Play server, it is enough to send a SIGTERM to the process to properly shutdown the application.

If you type Ctrl+D, the Play console will quit, but the created server process will continue running in background. The forked JVM’s standard output stream is then closed, and logging can be read from the logs/application.log file.

Therefore it's possible that either the process has received a SIGTERM signal, the Play application was started with play run instead of play start and someone used Ctrl+D on the console or perhaps the server is killing the process because it is running low on memory which may or may not indicate a memory leak in your application see OOM killer:

Under desperately low memory conditions, the out-of-memory (OOM) killer kicks in and picks a process to kill using a set of heuristics which has evolved over time.

I would recommend you profile your application / monitor the server memory (you could also check server logs to see if the kernel has killed any processes).

If you are able to extend HikariCPModule and override the close method you could add a logger call to print the current thread stacktrace and verify what is actually invoking close eg. shutdown hook or something else.

  override def close(dataSource: DataSource) = {
    Logger.info("Shutting down connection pool.")
    Thread.dumpStack()
    dataSource match {
      case ds: HikariDataSource => ds.close()
      case _ => sys.error("Unable to close data source: not a HikariDataSource")
    }

Enabling DEBUG logging for "com.zaxxer.hikari" and for Play may help further diagnose what's wrong with the database setup / application.

Good luck!

2
votes

So I found out a while back what my problem was. It was really really dumb.

I wasn't starting my app with the nohup command. As a consequence the app was being terminated by the OS with a SIGTERM message.

It was nothing to do with my app at all...

So basically, nohup with piping out the output to dev > null

Live and learn.

0
votes

You may want to remove the minimumIdle configuration as it is recommended to set to default by HikariCP

hikaricp.minimumIdle = 0

HikariCP reference

Also do check if your connection pool size of 30 is good enough or not.