Spontaneous closing of the connection by BoneCP connection pool

[David Katuscak]

Application (1 test component) is using BoneCP connection pool. All the things are usually working fine (getting connection, releasing, ....) but sometimes in the random time happen that some connection is spontaneously closed.

This is the output from log4j:

-----------------------------------------------------------------------------------------------
com.mysql.jdbc.exceptions.jdbc4.MySQLNonTransientConnectionException: No operations allowed after connection closed.
at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:39)
at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:27)
at java.lang.reflect.Constructor.newInstance(Constructor.java:513)
at com.mysql.jdbc.Util.handleNewInstance(Util.java:411)
at com.mysql.jdbc.Util.getInstance(Util.java:386)
at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:1013)
at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:987)
at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:982)
at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:927)
at com.mysql.jdbc.ConnectionImpl.throwConnectionClosedException(ConnectionImpl.java:1205)
at com.mysql.jdbc.ConnectionImpl.checkClosed(ConnectionImpl.java:1197)
at com.mysql.jdbc.ConnectionImpl.createStatement(ConnectionImpl.java:2483)
at com.mysql.jdbc.ConnectionImpl.createStatement(ConnectionImpl.java:2465)
at com.radar.database.Connection.createStatement(Connection.java:218)
at com.jolbox.bonecp.ConnectionHandle.createStatement(ConnectionHandle.java:718)
at com.arbitrage.live.factor.FactorComponent.calculateOverallFactors(FactorComponent.java:181)
at com.arbitrage.live.factor.FactorComponent.access$1000(FactorComponent.java:28)
at com.arbitrage.live.factor.FactorComponent$ProcessMatches.run(FactorComponent.java:139)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441)
at java.util.concurrent.FutureTask$Sync.innerRunAndReset(FutureTask.java:317)
at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:150)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$101(ScheduledThreadPoolExecutor.java:98)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.runPeriodic(ScheduledThreadPoolExecutor.java:180)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:204)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
at java.lang.Thread.run(Thread.java:662)

-----------------------------------------------------------------------------------------------

So I don't know if it is bug, or just some configuration issue about liveness of the connection.
Idle timeout is set to 60 seconds, min connections = 2, max connections = 5.

When the connection was closed, it was normally used by 1 thread of application, so it wasn't in the pool, so I think that it should not be closed spontaneously.

Thanks for reply.

[Wallace Wadge (wwadge)]

Hi,

Can you post your full config please?

[David Katuscak (katuscak-d)]

Hi,

constructor looks like this:

public BoneCPConnectionPool(Database database, ConnectionPoolConfig config) throws SQLException {
  this.database = database;
  this.config = config;

  BoneCPConfig cf = new BoneCPConfig();
  cf.setDatasourceBean(new DataSourceImpl(database));
  cf.setMinConnectionsPerPartition(config.getMinConnections());
  cf.setMaxConnectionsPerPartition(config.getMaxConnections());

  TimeInterval idleTimeout = config.getIdleTimeout();
  cf.setIdleMaxAge(idleTimeout.toMillis(), TimeUnit.MILLISECONDS);

  cf.setPartitionCount(1);

  pool = new BoneCP(cf);
 }
-----------------------------------------------------------------------------
We are using MySQL 5.1 and MinConnections is set to 2, MaxConnections to 5 and IdleTimeout is 60 seconds. No other changes in config.

[Pierre (darkstuff)]

Same problem here, plus if I print statistics i have more free connections than created and a negative number of leased.

[Sverre Boschman (sverre-boschman)]

Disable the connection tracking feature (disableConnectionTracking = true) as workaround.

Looks like the finalizeReferent method from ConnectionPartition.trackConnectionFinalizer() kicks in when it is not supposed to. I see this method killing off connections that are in use (worker thread: getConnection, Thread.sleep(), closeConnection; while the thread sleeps for a few millis the finalizeReferent can close the connection). Of course it only happens 'sometimes' (must be some sort of concurrency issue/race condition/gc issue with the ReferenceQueue), so it is a pain to debug.

[Pierre (darkstuff)]

Thank you very much Sverre, it seems to work!

[Wallace Wadge (wwadge)]

Wow - the beauty of open source in action! That must have been really tough to track down.

Of course it doesn't yet explain why that kicks in but now I can finally zoom in on the issue.

[Sverre Boschman (sverre-boschman)]

The issues related to the connection tracking feature we found so far:

1) Spontaneaus closing of connections
ConnectionHandle.close(), line 505:
+ Reference<ConnectionHandle> ref = pool.getFinalizableRefs().remove(this.connection);
+ ref.clear();
Explanation: GC still kicks in on the FinalizableWeakReference, removing it from the internal BoneCP hashmap only is not enough; so finalize (method finalizeReferent) can still trigger for a correctly closed ConnectionHandle.

2) Pool exhaustion after finilizer runs
ConnectionPartition.trackConnectionFinalizer, line 165
+ ConnectionPartition.this.setUnableToCreateMoreTransactions(false);
+ pool.maybeSignalForMoreConnections(ConnectionPartition.this);
Explanation: connections are getting closed, but the PoolWatchThread never gets notified to create new connections to fill the pool again. If threads are already waiting to get a connection from the pool (DefaultConnectionStrategy, line 82) they will never get one (unless a new thread asking for a connection triggers the PoolWatchThread).

3) Recreating a ConnectionHandle in the ConnectionHandle.close does not add connection tracking for this newly created handle
ConnectionHandle.recreateConnectionHandle, line 293:
+ handle.originatingPartition.trackConnectionFinalizer(handle);

[Pierre (darkstuff)]

The problem n. 2 pointed out by Sverre seems the behaviour I just described in https://bugs.launchpad.net/bonecp/+bug/1246660 but in my config I have config.setDisableConnectionTracking(true);

[Andrew Conner (andrewconner)]

We're seeing this too on 0.8.0.RELEASE (on Play 2.1). It's very random, so hard to isolate in what situations it happens. Sometimes we get a flood of them, other times it's just as few as once. Last night we had one during our lowest daily traffic time.

We've seen it even with `disableConnectionTracking=true`

The stack:
com.mysql.jdbc.exceptions.jdbc4.MySQLNonTransientConnectionException: No operations allowed after connection closed.
sun.reflect.NativeConstructorAccessorImpl.newInstance0(NativeConstructorAccessorImpl.java:-2)
sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:57)
sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
java.lang.reflect.Constructor.newInstance(Constructor.java:526)
com.mysql.jdbc.Util.handleNewInstance(Util.java:411)
com.mysql.jdbc.Util.getInstance(Util.java:386)
com.mysql.jdbc.SQLError.createSQLException(SQLError.java:1015)
com.mysql.jdbc.SQLError.createSQLException(SQLError.java:989)
com.mysql.jdbc.SQLError.createSQLException(SQLError.java:975)
com.mysql.jdbc.SQLError.createSQLException(SQLError.java:920)
com.mysql.jdbc.ConnectionImpl.throwConnectionClosedException(ConnectionImpl.java:1304)
com.mysql.jdbc.ConnectionImpl.checkClosed(ConnectionImpl.java:1296)
com.mysql.jdbc.ConnectionImpl.setAutoCommit(ConnectionImpl.java:5287)
com.jolbox.bonecp.ConnectionHandle.setAutoCommit(ConnectionHandle.java:1292)
play.api.db.BoneCPApi$$anon$1.onCheckOut(DB.scala:328)
com.jolbox.bonecp.AbstractConnectionStrategy.postConnection(AbstractConnectionStrategy.java:75)
com.jolbox.bonecp.AbstractConnectionStrategy.getConnection(AbstractConnectionStrategy.java:92)
com.jolbox.bonecp.BoneCP.getConnection(BoneCP.java:553)
com.jolbox.bonecp.BoneCPDataSource.getConnection(BoneCPDataSource.java:131)
scala.slick.session.Database$$anon$1.createConnection(Database.scala:82)
scala.slick.session.BaseSession.conn$lzycompute(Session.scala:207)
scala.slick.session.BaseSession.conn(Session.scala:207)
scala.slick.session.Session$$anon$1.conn(Session.scala:110)
...

[Wallace Wadge (wwadge)]

I'm curious: is there anyone who has received this *not* on MySQL ? One thing that might happen is:
- There's a setting in mysql that times out idle connections. It defaults to 8 hours
- If for some reason the idle test connection function is not working right, the pool ends up with a connection that it thinks is ok, but one which the server has closed off and thus blows up.

Can you try disabling this mysql timeout?

[Eishay Smith (eishay)]

We just made this change (wait_timeout=one week, while we're bouncing the application every 2-3 days). We'll let you know if we see it again.

[Eishay Smith (eishay)]

We did update wait_timeout to be one week but the errors still happen. Apparently changing that config param does not have any effect.

[Wallace Wadge (wwadge)]

Is it related to this bug that I have just merged in perhaps:
https://bugs.launchpad.net/bonecp/+bug/1247826

(I can build a snapshot release if it helps)

[Andrew Conner (andrewconner)]

We'd love that.

[Steven (stevenp)]

We'd love that. :D

[Wallace Wadge (wwadge)]

0.8.1-SNAPSHOT released

[Wallace Wadge (wwadge)]

Can anyone confirm if this has now been solved please?

[Pierre (darkstuff)]

I can't see 0.8.1 in maven (through Intellij) repository

[Wallace Wadge (wwadge)]

it's in the snapshot repo:
https://oss.sonatype.org/content/repositories/snapshots/com/jolbox/bonecp/

[Andrew Conner (andrewconner)]

Thanks Wallace. We're running it in production now and will update if we notice this again.

[Andrew Conner (andrewconner)]

We are still getting this exception. Most recently, the service was only running for an hour before it happened.

[James Lang (sit1way-s)]

Getting this also in production on 0.8.1-SNAPSHOT with disableConnectionTracking set to true.

1) Shutdown Play app.
2) Restart MySQL
3) Start Play app.

So we have 2 freshly started services, and yet within 30 minutes of starting play app, Fatal error, "No operations allowed after connection closed" followed by same error randomly from there on out, in bunches, or singly.

@wwadge
> If for some reason the idle test connection function is not working right, the pool ends up with a connection that it thinks is ok, but one which the server has closed off and thus blows up.

That the error occurs well before the 8 hour MySQL idle timeout would seem to indicate that the problem lies elsewhere, no?

[Wallace Wadge (wwadge)]

Good to hear that at least that route is not it though the source of error still eludes me.

Just for a test, can you also disable statement caching let's see if that other major feature is what's killing it :-(

[James Lang (sit1way-s)]

@wwadge just want to say thanks for providing bonecp, when it works it's quite awesome ;-)

Now, I don't believe that we Play users have a means to disable statement caching; check out the exposed bonecp config options:
https://github.com/playframework/playframework/blob/master/framework/src/play-jdbc/src/main/scala/play/api/db/DB.scala#L371

I'm curious to know if it's only Play 2.2.x using a MySQL database on >= bonecp 0.8.0?

Have seen some Postgres grumblings around similar issues, but not sure it that was resolved for them with the 0.8.0 release.

Trimming down one's pool size does minimize the bug's affect (while benchmarking I left 96 max connections config option in place and got many, many more fatal closed connection errors during the day), but it would be nice to set max connections to a high number and therefore be able to handle bursty traffic on demand without fear of this issue popping up when traffic lessens.

FWIW, nearly 45 minutes and so far no connection errors during quiet hours pre-EST business day...let's see if the trend continues.

[Wallace Wadge (wwadge)]

I'm determined to fix this, whatever it takes.

Curious to know why they have also set maxConnectionAge:
https://github.com/playframework/playframework/blob/master/framework/src/play-jdbc/src/main/scala/play/api/db/DB.scala#L379

idleMaxAge is meant to kill off any idle connections while maxConnectionAge says: recently used or not, kill it off.

Can you set that to zero please? I'm trying to trim out any non-essential features here.

[James Lang (sit1way-s)]

@wwadge, good to hear the desire to right the ship.

I'll try to set maxConnectionAge to 0 as suggested.

Should note that prior to launching Play 2.2.1 app with 0.8.1-snapshot, I did not restart MySQL (thought I did), so perhaps there were a couple of idle connections that MySQL was on the verge of (8 hour idle timeout) closing?

After shutting down Play, restarting MySQL, and starting Play with maxConnectionAge set to current Play 60 minute default, have gone nearly 2 hours error free. Going to leave "flawed" config in place for a bit longer and see if/when next transient connection error occurs.

Hopefully 0.8.1 prepared statement fix is the solution in the end.

Will post back results a bit later.

Thanks again for providing a crucial component in our stack.

[James Lang (sit1way-s)]

@wwadge the errors persisted without maxConnectionAge set to 0, am getting that in place right now.

Will see how it goes.

[James Lang (sit1way-s)]

Looks like maxConnectionAge=0 does the trick, 12 hours in production and zero transient connection errors.

If this trend holds 0.8.1-snapshot may therefore not be necessary, only turning off max connection age.

Of course, the prepared statement cache fix seems reason enough to upgrade.

Will post back if transient connection issue is indeed solved, looking good so far

[Andrew Conner (andrewconner)]

Interestingly, we've had that setting on for a while and still occasionally get the issue.

Here's our configuration:

  idleMaxAge=10 minutes
  idleConnectionTestPeriod=30 seconds
  connectionTimeout=2 seconds
  connectionTestStatement="SELECT 1"
  maxConnectionAge=0
  partitionCount=4
  maxConnectionsPerPartition=6
  minConnectionsPerPartition=4
  setLogStatementsEnabled=true
  acquireRetryAttempts=10
  acquireRetryDelay=5 seconds

[James Lang (sit1way-s)]

@andrew are you guys on 0.8.1-snapshot? I am no longer seeing the transient connection issue with snapshot + maxConnectionAge=0, which is awesome, get improvements of 0.8 branch and stability, best of both worlds ;-)

Curious about your partitionCount setting. How many CPU cores do you have available on the machine/instance where your database lives?

I was under the impression that partitionCount relates to number of cores; play by default sets the count to 2, while I have set it to 1 given that I have allocated a single CPU core to the CentOS VM that MySQL runs on.

Maybe setting a higher partitionCount than number of available cores could cause issues? @wwadge will likely have the answer for that one.

Here's the config I'm using:
db.default.partitionCount=1
db.default.minConnectionsPerPartition=4
db.default.maxConnectionsPerPartition=32
db.default.maxConnectionAge=0
db.default.acquireIncrement=4

which is probably a bit overzealous, 32 connections should be able to serve I don't know how many requests/second, a lot more than current server load requires that's for sure.

[Wallace Wadge (wwadge)]

The partitionCount is unlikely to have an effect and yes you did well to set it to number of cores in your system.

I still haven't managed to reproduce the problem in a test case but I'll keep trying :-(

[Andrew Conner (andrewconner)]

Yep, we're on 0.8.1-SNAPSHOT. It seems like we have less issues than before, but not completely sure — they're certainly still happening occasionally (couple / few times a week).

[Andrew Conner (andrewconner)]

To update this, we're still getting it. On 0.8.1-SNAPSHOT, maxConnectionAge=0, disableConnectionTracking=true.

Sorry I've been unable to provide more details — it seems quite random.

[Wendy (wai-lam)]

wow am I glad to have found this thread. I've been running into the same issue for a long time. I have 0.8.0-rc2, play 2.0.2, and mysql. I get

com.mysql.jdbc.exceptions.jdbc4.MySQLNonTransientConnectionException: Connection.close() has already been called. Invalid operation in this state.

all the time.

This is my setting db.default.maxConnectionsPerPartition=60
db.default.minConnectionsPerPartition=15
db.default.idleMaxAgeInSeconds=15
db.default.idleConnectionTestPeriodInMinutes=1
db.default.connectionTimeoutInMs=1
db.default.connectionTestStatement="SELECT 1"
db.default.maxConnectionAgeInSeconds=1

During testing, I seem to hit this issue every few hours or so.

[Wendy (wai-lam)]

btw my error log is slightly different

oaused by: com.mysql.jdbc.exceptions.jdbc4.MySQLNonTransientConnectionException: Connection.close() has already been called. Invalid operation in this state.
 at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
 at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:57)
 at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
 at java.lang.reflect.Constructor.newInstance(Constructor.java:526)
 at com.mysql.jdbc.Util.handleNewInstance(Util.java:406)
 at com.mysql.jdbc.Util.getInstance(Util.java:381)
 at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:984)
 at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:956)
 at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:926)
 at com.mysql.jdbc.ConnectionImpl.getMutex(ConnectionImpl.java:3018)
 at com.mysql.jdbc.ConnectionImpl.setAutoCommit(ConnectionImpl.java:4827)
 at com.jolbox.bonecp.ConnectionHandle.setAutoCommit(ConnectionHandle.java:1266)
 at play.api.db.BoneCPApi$$anon$1.onCheckOut(DB.scala:326)
 at com.jolbox.bonecp.AbstractConnectionStrategy.postConnection(AbstractConnectionStrategy.java:75)
 at com.jolbox.bonecp.AbstractConnectionStrategy.getConnection(AbstractConnectionStrategy.java:92)
 at com.jolbox.bonecp.BoneCP.getConnection(BoneCP.java:549)
 at com.jolbox.bonecp.BoneCPDataSource.getConnection(BoneCPDataSource.java:131)
 at play.db.ebean.EbeanPlugin$WrappingDatasource.getConnection(EbeanPlugin.java:146)
 at com.avaje.ebeaninternal.server.transaction.TransactionManager.createQueryTransaction(TransactionManager.java:339)
 ... 33 more

could it be a mysql connector problem? I use 5.1.22

[Wendy (wai-lam)]

I tried the new snapshot and only had db.default.maxConnectionAgeInSeconds=0 setting. I ran into the issue within 1 hour.

[Wendy (wai-lam)]

I don't know if it's just play or what. But it seems like maxConnectionAgeInSeconds doesn't really work. I noticed my connections were not killed even if I set it to 10 seconds or something. I changed it to maxConnectionAge and notice that it actually takes in those configurations.

[Wallace Wadge (wwadge)]

@Wendy So with the new config, is the issue still coming up for you?

I can also confirm that so far all the reports re this were on MySql :-/

[James Lang (sit1way-s)]

@Wendy just do the suggested solution:
db.default.maxConnectionAge=0

Not sure what positive affect db.default.maxConnectionAgeInSeconds would have given that Play effectively forces a timeout within 60 minutes with the under the hood maxConnectionAge default.

The above should solve the problem, seems to do so for everyone on Play 2.2.x using MySQL

good luck!

[Franck (alci)]

We also encounter the problem, on a quite different configurations: custom app (not Play), Postgresql or Oracle, bonecp 0.8.0-RELEASE.
I think we introduced the problems when we added a maxConnectionAgeInSeconds in our config file.

We encounter two types of problems: connections are closed when we try to use it, and/or lots of connections are created and never closed, exhausting the max connections of the database.

Removing the maxConnectionAgeInSeconds hopefully solved the issue (still testing... no so easy to reproduce, tests refuse to fail, only production sites do :-)

[Matt Sgarlata (matt-sgarlata)]

I can reliably duplicate this issue after running many commands to create indexes using Spring. I am running 0.8.1 snapshot with maxConnectionAge = 0. I'm not sure if this will be of any help, but based on the email thread I see here so far it seems any clues at all may be helpful.

[Jake W. (delight-wjk)]

I got a similar issue with Microsoft SQL Server:

    com.microsoft.sqlserver.jdbc.SQLServerException: The connection is closed.

Then I set this:

    dataSource.setDisableConnectionTracking(true);

Seems working at the moment (didn't see the same issue so far)

[David Alvarado (davidalv909)]

Another MS Sql Server case of random database exceptions. Original configuration:
 * Play 2.2.0, anorm, Scala with default settings
 * Default version of bonecp that comes with Play 2.2.0
 * MS Sql Server running on Azure VM

I was getting occasional random "SQLException: Timed out waiting for a free available connection." exceptions. Then based on this thread: https://groups.google.com/forum/#!topic/play-framework/7PBnjiXkNuU , I upgraded to:

 * bonecp: 0.8.0.RELEASE
 * Added: db.default.maxConnectionAge=0 and db.default.connectionTestStatement="SELECT 1"

This seemed to help with the above exception, but now I still occasionally get exceptions. Most recently, "SQLServerException: The connection is closed." Stack trace attached.

I will try upgrading to the latest snapshot and also setDisableConnectionTracking(true)

[Micael Paquier (micael-paquier)]

I also get this problem with Play Framework 2.1.4, mySQL.

Has anybody found a definitive solution? For the moment, I do the following:

 * Wrote some code in Global.scala to take into account the setDisableConnectionTracking=true
 * Use the 0.8.0-RELEASE version
 * Use the following DB config:
db.default.partitionCount=1
db.default.maxConnectionsPerPartition=7
db.default.minConnectionsPerPartition=7
db.default.acquireIncrement=1
db.default.acquireRetryAttempts=1
db.default.acquireRetryDelay=5 seconds
db.default.connectionTimeout=30 seconds
db.default.idleMaxAge=1 minutes
db.default.idleConnectionTestPeriod=30 seconds
db.default.connectionTestStatement="SELECT 1"
db.default.maxConnectionAge=0
db.default.autoReconnect=true

I haven't seen the bug anymore for a few hours but I am not totally sure it is fixed with this.

[Tushar Jain (tushar-jain)]

Hi,

What's the latest update on this bug? We're running into it too and are wondering if a root cause has been identified and if a fix is on it's way.

Thanks!

[Shane Pitts (yhane)]

I have also been trying to track this down for the last few months. We are on a gallera cluster, mariadb. I have not tried the 0.8.1 Snapshot, but it looks like from the comments that it may not have provided the fix?

Each time this error is thrown, a connection seems to be "lost" to the pool, and I start going negative on the leased statistics

Current stats on one production server:
Total Connections Requested: 57691
Total Created Connections: 24
Cache Hit Ratio: 0
Total Leased Connections: -1
Total Free Connections: 25
Connection Wait Time Avg: 0.0108
Statements Prepared: 17594
Statements Executed: 91571

Config:
db.default.partitionCount=4
db.default.minConnectionsPerPartition=2
db.default.maxConnectionsPerPartition=25
db.default.maxConnectionAge=0
db.default.acquireIncrement=4

com.mysql.jdbc.exceptions.jdbc4.MySQLNonTransientConnectionException: No operations allowed after connection closed.
        at sun.reflect.GeneratedConstructorAccessor31.newInstance(Unknown Source)
        at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:27)
        at java.lang.reflect.Constructor.newInstance(Constructor.java:513)
        at com.mysql.jdbc.Util.handleNewInstance(Util.java:411)
        at com.mysql.jdbc.Util.getInstance(Util.java:386)
        at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:1014)
        at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:988)
        at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:974)
        at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:919)
        at com.mysql.jdbc.ConnectionImpl.throwConnectionClosedException(ConnectionImpl.java:1269)
        at com.mysql.jdbc.ConnectionImpl.checkClosed(ConnectionImpl.java:1261)
        at com.mysql.jdbc.ConnectionImpl.prepareStatement(ConnectionImpl.java:4261)
        at com.mysql.jdbc.ConnectionImpl.prepareStatement(ConnectionImpl.java:4227)
        at com.jolbox.bonecp.ConnectionHandle.prepareStatement(ConnectionHandle.java:1024)
        at com.zaneray.foundation.sql.SQLCreator.getPreparedStatement(SQLCreator.java:96)

[Alex Turner (armtuk)]

Can confirm that we're seeing this on PostgreSQL 9.2.7 with BoneCP 0.8.0.RELEASE on Play 2.2.3 Scala 2.10.

2014-07-02 09:11:17,764 [^[[37minfo^[[0m] [play-akka.actor.default-dispatcher-5] - *** ERROR *** Failed with un-trapped internal exception (p1) org.postgresql.jdbc2.AbstractJdbc2Connection.checkClosed(AbstractJdbc2Connection.java:714)org.postgresql.jdbc2.AbstractJdbc2Connection.setAutoCommit(AbstractJdbc2Connection.java:661)
com.jolbox.bonecp.ConnectionHandle.setAutoCommit(ConnectionHandle.java:1292)play.api.db.BoneCPApi$$anon$1.onCheckOut(DB.scala:329)com.jolbox.bonecp.AbstractConnectionStrategy.postConnection(AbstractConnectionStrategy.java:75)
com.jolbox.bonecp.AbstractConnectionStrategy.getConnection(AbstractConnectionStrategy.java:92)com.jolbox.bonecp.BoneCP.getConnection(BoneCP.java:553)com.jolbox.bonecp.BoneCPDataSource.getConnection(BoneCPDataSource.java:131)scala.slick.jdbc.PlayDatabase.createConnection(PlayDatabase.scala:8)
scala.slick.jdbc.JdbcBackend$BaseSession.conn$lzycompute(JdbcBackend.scala:302)
scala.slick.jdbc.JdbcBackend$BaseSession.conn(JdbcBackend.scala:302)scala.slick.jdbc.JdbcBackend$SessionDef$class.prepareStatement(JdbcBackend.scala:123)scala.slick.jdbc.JdbcBackend$BaseSession.prepareStatement(JdbcBackend.scala:297)scala.slick.jdbc.StatementInvoker.results(StatementInvoker.scala:28)
scala.slick.jdbc.StatementInvoker.iteratorTo(StatementInvoker.scala:16)
scala.slick.jdbc.Invoker$class.foreach(Invoker.scala:97)
scala.slick.jdbc.StatementInvoker.foreach(StatementInvoker.scala:9)
scala.slick.jdbc.Invoker$class.firstOption(Invoker.scala:44)
scala.slick.jdbc.StatementInvoker.firstOption(StatementInvoker.scala:9)
scala.slick.jdbc.UnitInvoker$class.firstOption(Invoker.scala:155)
scala.slick.driver.JdbcInvokerComponent$UnitQueryInvoker.firstOption(JdbcInvokerComponent.scala:50)
services.sql.NpUserSlickDAOService$$anonfun$findById$1.apply(NpUserSlickDAOService.scala:22)
services.sql.NpUserSlickDAOService$$anonfun$findById$1.apply(NpUserSlickDAOService.scala:22)
services.sql.EnvironmentDrivenPlaySlickSessionService$$anonfun$withSession$2.apply(DBSessionService.scala:47)
services.sql.EnvironmentDrivenPlaySlickSessionService$$anonfun$withSession$2.apply(DBSessionService.scala:45)
scala.slick.backend.DatabaseComponent$DatabaseDef$class.withSession(DatabaseComponent.scala:31)
scala.slick.jdbc.PlayDatabase.withSession(PlayDatabase.scala:6)
... (more internal stuff)

We're currently just using the default BoneCP configuration, and see this about 2-4 times daily on each of our Play servers. Traffic is low, only about 1000 requests per day for database driven requests at least. Looking at graphs across monitoring, there doesn't seem to be any correlation in terms of a load spike or a network event or a system event like log rotation etc.

Looking at the monitoring, this event is positively correlated with a GC event. Of three events we saw today, all three occurred at the same time as GC.

[Steven (stevenp)]

This problem has a big impact on my application, no workaround seems have effect, should I revert to 0.71 ??
Seems that there is no interest into fixing this issue.. there is something planned about this ?

[Brian KimJohnson (briankimjohnson)]

As a result of this issue , my company reverted to 0.7.1 ​and it has been
much more stable.

On Tue, Sep 9, 2014 at 12:08 PM, Steven <email address hidden> wrote:

> This problem has a big impact on my application, no workaround seems have
> effect, should I revert to 0.71 ??
> Seems that there is no interest into fixing this issue.. there is
> something planned about this ?
>
> --
> You received this bug notification because you are subscribed to the bug
> report.
> https://bugs.launchpad.net/bugs/1243551
>
> Title:
> Spontaneous closing of the connection by BoneCP connection pool
>
> Status in BoneCP - Java Database Connection Pool:
> Triaged
>
> Bug description:
> Application (1 test component) is using BoneCP connection pool. All
> the things are usually working fine (getting connection, releasing,
> ....) but sometimes in the random time happen that some connection is
> spontaneously closed.
>
> This is the output from log4j:
>
>
> -----------------------------------------------------------------------------------------------
> com.mysql.jdbc.exceptions.jdbc4.MySQLNonTransientConnectionException: No
> operations allowed after connection closed.
> at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
> at
> sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:39)
> at
> sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:27)
> at java.lang.reflect.Constructor.newInstance(Constructor.java:513)
> at com.mysql.jdbc.Util.handleNewInstance(Util.java:411)
> at com.mysql.jdbc.Util.getInstance(Util.java:386)
> at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:1013)
> at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:987)
> at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:982)
> at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:927)
> at
> com.mysql.jdbc.ConnectionImpl.throwConnectionClosedException(ConnectionImpl.java:1205)
> at com.mysql.jdbc.ConnectionImpl.checkClosed(ConnectionImpl.java:1197)
> at
> com.mysql.jdbc.ConnectionImpl.createStatement(ConnectionImpl.java:2483)
> at
> com.mysql.jdbc.ConnectionImpl.createStatement(ConnectionImpl.java:2465)
> at com.radar.database.Connection.createStatement(Connection.java:218)
> at
> com.jolbox.bonecp.ConnectionHandle.createStatement(ConnectionHandle.java:718)
> at
> com.arbitrage.live.factor.FactorComponent.calculateOverallFactors(FactorComponent.java:181)
> at
> com.arbitrage.live.factor.FactorComponent.access$1000(FactorComponent.java:28)
> at
> com.arbitrage.live.factor.FactorComponent$ProcessMatches.run(FactorComponent.java:139)
> at
> java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441)
> at
> java.util.concurrent.FutureTask$Sync.innerRunAndReset(FutureTask.java:317)
> at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:150)
> at
> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$101(ScheduledThreadPoolExecutor.java:98)
> at
> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.runPeriodic(ScheduledThreadPoolExecutor.java:...

[Tarun Kumar (tarunsamrai)]

Is this issue fixed in any latest release of bonecp? We are using 0.8.0-RELEASE version with postgres 9.4.7 and connections get closed abruptly at random times. We use following config:

<property name="connectionTestStatement" value="SELECT NOW()" />
<property name="idleConnectionTestPeriodInMinutes" value="1" />
<property name="idleMaxAgeInMinutes" value="5" />
<property name="maxConnectionsPerPartition" value="20" />
<property name="minConnectionsPerPartition" value="1"/>
<property name="poolAvailabilityThreshold" value="5"/>
<property name="partitionCount" value="2" />
<property name="acquireIncrement" value="4" />
<property name="statementsCacheSize" value="50" />

Please note that we did not set maxConnectionAge or maxConnectionAgeInSeconds to 0 as I see from the source code that the default value is 0.

Please suggest if there is any workaround or a version in which this has been fixed.

[Wallace Wadge (wwadge)]

Hi,

As noted on github and elsewhere, this project is now considered deprecated (for years at this point) in favour of hikaricp. Please migrate to it at your earliest convenience.