getting weird timeout exception w/ Play! 1.0.3.2

[Mike Grove]

Supporting a legacy application, hence using a rather old version of Play!

I made some what I thought were small changes to the codebase and all
of a sudden I'm getting timeout exceptions very frequently. They seem
to be somewhat random, there's no single sequence of actions that
triggers the exception, but I had narrowed it down to a set of things
that if I do them long enough, I get the exception.

The top level exception thrown out of Play when its trying to begin a
tx when loading a page is:

org.hibernate.exception.GenericJDBCException: Cannot open connection

Further down in the stack are these:

java.sql.SQLException: An attempt by a client to checkout a Connection
has timed out.
com.mchange.v2.resourcepool.TimeoutException: A client timed out while
waiting to acquire a resource from
com.mchange.v2.resourcepool.BasicResourcePool@70e8eeca -- timeout at
awaitAvailable()

I'm using the basic out of the box configuration for the db except for
the connection parameters, which are:

db.pass=
db.user=sa
db.driver=org.hsqldb.jdbcDriver
db.url=jdbc:hsqldb:file:/application/users/db

I'm only using the SQL db for storing the users table, everything else
in my app is stored elsewhere.

I've tried futzing w/ application.session.maxAge, db.pool.timeout, and
hibernate.temp.use_jdbc_metadata_defaults (something I saw on
stackoverflow).

No luck.

Anyone seen this before, or have an idea of configuration I can
twiddle to get it to stop from happening? Or better yet, what the
hell is causing it?

Thanks.

[Nicolas Leroux]

Are you sure it is not a problem with your database?

Nicolas

> --
> You received this message because you are subscribed to the Google Groups "play-framework" group.
> To post to this group, send email to play-fr...@googlegroups.com.
> To unsubscribe from this group, send email to play-framewor...@googlegroups.com.
> For more options, visit this group at http://groups.google.com/group/play-framework?hl=en.
>

[Mike Grove]

On Mon, Sep 12, 2011 at 4:51 PM, Nicolas Leroux
<leroux....@gmail.com> wrote:
> Are you sure it is not a problem with your database?

Pretty sure. It's just the default db provided by Play!, I just
changed the configuration from db=fs to those parameters so I could
control where it was saving the user table.

That's why I'm kind of confused. I've always just used the provided
db for the user table and never had a problem with it.

Cheers,

Mike

[Mike Grove]

Below is the full set of stack traces from Play & Hibernate.

I can reproduce this by clicking back and forth between any two pages
as far as i can tell.

Each page is served by one controller, and then has a bunch of
javascript ajax calls back to the server handled by a different
controller to get some dynamic parts of the page.

Usually I get this trace when the page is initially served, but I have
seen it from time to time with the ajax calls.

The only difference I am aware of between my dev and test environments
is that in dev, I'm using db=fs and on my test box, I have the
configuration I mentioned previously where I'm explicitly stating
where on the disk I want the contents of the db to be stored.

Changing the connection pooling configuration in Play does not seem to
affect anything.

Anyone have any ideas?

Thanks.

Internal Server Error (500)

Oops: PersistenceException
An unexpected error occured caused by exception PersistenceException:
org.hibernate.exception.GenericJDBCException: Cannot open connection

play.exceptions.UnexpectedException: Unexpected Error
at play.Invoker$Invocation.onException(Invoker.java:142)
at play.Invoker$Invocation.run(Invoker.java:183)
at play.server.ServletWrapper$ServletInvocation.run(ServletWrapper.java:463)
at play.Invoker.invokeInThread(Invoker.java:59)
at play.server.ServletWrapper.service(ServletWrapper.java:112)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:91)
at com.caucho.server.dispatch.ServletFilterChain.doFilter(ServletFilterChain.java:103)
at com.caucho.server.webapp.WebAppFilterChain.doFilter(WebAppFilterChain.java:187)
at com.caucho.server.dispatch.ServletInvocation.service(ServletInvocation.java:265)
at com.caucho.server.http.HttpRequest.handleRequest(HttpRequest.java:273)
at com.caucho.server.port.TcpConnection.run(TcpConnection.java:682)
at com.caucho.util.ThreadPool$Item.runTasks(ThreadPool.java:743)
at com.caucho.util.ThreadPool$Item.run(ThreadPool.java:662)
at java.lang.Thread.run(Thread.java:662)
Caused by: javax.persistence.PersistenceException:
org.hibernate.exception.GenericJDBCException: Cannot open connection
at org.hibernate.ejb.AbstractEntityManagerImpl.throwPersistenceException(AbstractEntityManagerImpl.java:614)
at org.hibernate.ejb.TransactionImpl.begin(TransactionImpl.java:41)
at play.db.jpa.JPAPlugin.startTx(JPAPlugin.java:283)
at play.db.jpa.JPAPlugin.beforeInvocation(JPAPlugin.java:246)
at play.Invoker$Invocation.before(Invoker.java:114)
at play.Invoker$Invocation.run(Invoker.java:175)
... 12 more
Caused by: org.hibernate.exception.GenericJDBCException: Cannot open connection
at org.hibernate.exception.SQLStateConverter.handledNonSpecificException(SQLStateConverter.java:126)
at org.hibernate.exception.SQLStateConverter.convert(SQLStateConverter.java:114)
at org.hibernate.exception.JDBCExceptionHelper.convert(JDBCExceptionHelper.java:66)
at org.hibernate.exception.JDBCExceptionHelper.convert(JDBCExceptionHelper.java:52)
at org.hibernate.jdbc.ConnectionManager.openConnection(ConnectionManager.java:449)
at org.hibernate.jdbc.ConnectionManager.getConnection(ConnectionManager.java:167)
at org.hibernate.jdbc.JDBCContext.connection(JDBCContext.java:142)
at org.hibernate.transaction.JDBCTransaction.begin(JDBCTransaction.java:85)
at org.hibernate.impl.SessionImpl.beginTransaction(SessionImpl.java:1354)
at org.hibernate.ejb.TransactionImpl.begin(TransactionImpl.java:38)
... 16 more
Caused by: java.sql.SQLException: An attempt by a client to checkout a
Connection has timed out.
at com.mchange.v2.sql.SqlUtils.toSQLException(SqlUtils.java:106)
at com.mchange.v2.sql.SqlUtils.toSQLException(SqlUtils.java:65)
at com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool.checkoutPooledConnection(C3P0PooledConnectionPool.java:527)
at com.mchange.v2.c3p0.impl.AbstractPoolBackedDataSource.getConnection(AbstractPoolBackedDataSource.java:128)
at org.hibernate.ejb.connection.InjectedDataSourceConnectionProvider.getConnection(InjectedDataSourceConnectionProvider.java:46)
at org.hibernate.jdbc.ConnectionManager.openConnection(ConnectionManager.java:446)
... 21 more
Caused by: com.mchange.v2.resourcepool.TimeoutException: A client

timed out while waiting to acquire a resource from

com.mchange.v2.resourcepool.BasicResourcePool@1c904f75 -- timeout at
awaitAvailable()
at com.mchange.v2.resourcepool.BasicResourcePool.awaitAvailable(BasicResourcePool.java:1317)
at com.mchange.v2.resourcepool.BasicResourcePool.prelimCheckoutResource(BasicResourcePool.java:557)
at com.mchange.v2.resourcepool.BasicResourcePool.checkoutResource(BasicResourcePool.java:477)
at com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool.checkoutPooledConnection(C3P0PooledConnectionPool.java:525)
... 24 more

[Guillaume Bort]

Perhaps you need to increase your database connection pool.

--
Guillaume Bort, http://guillaume.bort.fr

[Mike Grove]

I ended up settling on these configurations:

db.pool.timeout=30000
db.pool.maxSize=300
db.pool.minSize=100

play.pool=3

hibernate.temp.use_jdbc_metadata_defaults=false

This seems to have resolved the issue. It is at least significantly
harder to trigger, I could usually get the exception within about 10
page loads, I've been clicking around randomly for the past ten
minutes and I have not hit the issue.

The last setting I saw on a stackoverflow question as a suggestion for
resolving a timeout issue w/ a stack trace similar to what I was
getting. Not sure if it helped or it was a combination of everything,
or just the pool tweaks.

Cheers,

Mike