RE: Database timeout

Thomas Reimer, geändert vor 13 Jahren.

Database timeout

Youngling Beiträge: 9 Beitrittsdatum: 11.11.10 Neueste Beiträge
Hi,

I recognized a problem concerning database connection handling. After some hours of Klaros inactivity at night I always get the following exceptions at first login in the next morning:

08:24:46,927 ERROR JDBCTransaction:95 - JDBC begin failed
com.mysql.jdbc.exceptions.jdbc4.CommunicationsException: The last packet successfully received from the server was 53.510.109 milliseconds ago.  The last packet sent successfully to the server was 53.510.110 milliseconds ago. is longer than the server configured value of 'wait_timeout'. You should consider either expiring and/or testing connection validity before use in your application, increasing the server configured values for client timeouts, or using the Connector/J connection property 'autoReconnect=true' to avoid this problem.
    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:409)
    at com.mysql.jdbc.SQLError.createCommunicationsException(SQLError.java:1118)
    at com.mysql.jdbc.MysqlIO.send(MysqlIO.java:3321)
    at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:1940)
    at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2113)
    at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2562)
    at com.mysql.jdbc.ConnectionImpl.setAutoCommit(ConnectionImpl.java:4956)
    at org.apache.commons.dbcp.DelegatingConnection.setAutoCommit(DelegatingConnection.java:331)
    at org.apache.commons.dbcp.PoolingDataSource$PoolGuardConnectionWrapper.setAutoCommit(PoolingDataSource.java:317)
    at org.hibernate.transaction.JDBCTransaction.begin(JDBCTransaction.java:91)
    at org.hibernate.impl.SessionImpl.beginTransaction(SessionImpl.java:1463)
    at org.springframework.orm.hibernate3.HibernateTransactionManager.doBegin(HibernateTransactionManager.java:558)
    at org.springframework.transaction.support.AbstractPlatformTransactionManager.getTransaction(AbstractPlatformTransactionManager.java:374)
    at org.jboss.seam.ioc.spring.SpringTransaction.begin(SpringTransaction.java:67)
    at org.jboss.seam.jsf.SeamPhaseListener.begin(SeamPhaseListener.java:593)
    at org.jboss.seam.jsf.SeamPhaseListener.begin(SeamPhaseListener.java:583)
    at org.jboss.seam.jsf.SeamPhaseListener.handleTransactionsBeforePhase(SeamPhaseListener.java:327)
    at org.jboss.seam.jsf.SeamPhaseListener.beforeServletPhase(SeamPhaseListener.java:144)
    at org.jboss.seam.jsf.SeamPhaseListener.beforePhase(SeamPhaseListener.java:118)
    at com.sun.faces.lifecycle.Phase.handleBeforePhase(Phase.java:214)
    at com.sun.faces.lifecycle.Phase.doPhase(Phase.java:96)
    at com.sun.faces.lifecycle.LifecycleImpl.render(LifecycleImpl.java:139)
    at de.verit.klaros.web.beans.application.lifecycle.LifecycleImpl.render(LifecycleImpl.java:96)
    at com.icesoft.faces.webapp.http.core.JsfLifecycleExecutor.apply(JsfLifecycleExecutor.java:19)
    at com.icesoft.faces.context.View$2$1.respond(View.java:48)
    at com.icesoft.faces.webapp.http.servlet.ServletRequestResponse.respondWith(ServletRequestResponse.java:201)
    at com.icesoft.faces.context.View$2.serve(View.java:77)
    at com.icesoft.faces.context.View.servePage(View.java:149)
    at com.icesoft.faces.webapp.http.core.MultiViewServer.service(MultiViewServer.java:67)
    at com.icesoft.faces.webapp.http.common.ServerProxy.service(ServerProxy.java:11)
    at com.icesoft.faces.webapp.http.servlet.MainSessionBoundServlet$4.service(MainSessionBoundServlet.java:149)
    at com.icesoft.faces.webapp.http.common.standard.PathDispatcherServer.service(PathDispatcherServer.java:24)
    at com.icesoft.faces.webapp.http.servlet.BasicAdaptingServlet.service(BasicAdaptingServlet.java:16)
    at com.icesoft.faces.webapp.http.servlet.PathDispatcher.service(PathDispatcher.java:23)
    at com.icesoft.faces.webapp.http.servlet.SessionDispatcher.service(SessionDispatcher.java:53)
    at com.icesoft.faces.webapp.http.servlet.PathDispatcher.service(PathDispatcher.java:23)
    at com.icesoft.faces.webapp.http.servlet.MainServlet.service(MainServlet.java:131)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:717)
    at de.verit.klaros.web.servlet.ExceptionHandlingPersistentFacesServlet.service(ExceptionHandlingPersistentFacesServlet.java:51)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:290)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
    at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:233)
    at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191)
    at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:128)
    at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102)
    at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)
    at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:293)
    at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:856)
    at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(Http11Protocol.java:583)
    at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:454)
    at java.lang.Thread.run(Thread.java:662)
Caused by: java.net.SocketException: Broken pipe
    at java.net.SocketOutputStream.socketWrite0(Native Method)
    at java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:92)
    at java.net.SocketOutputStream.write(SocketOutputStream.java:136)
    at java.io.BufferedOutputStream.flushBuffer(BufferedOutputStream.java:65)
    at java.io.BufferedOutputStream.flush(BufferedOutputStream.java:123)
    at com.mysql.jdbc.MysqlIO.send(MysqlIO.java:3302)
    ... 48 more
08:24:48,708 ERROR Exceptions:86 - handled and logged exception
java.lang.IllegalStateException: Could not start transaction
    at org.jboss.seam.jsf.SeamPhaseListener.begin(SeamPhaseListener.java:598)
    at org.jboss.seam.jsf.SeamPhaseListener.begin(SeamPhaseListener.java:583)
    at org.jboss.seam.jsf.SeamPhaseListener.handleTransactionsBeforePhase(SeamPhaseListener.java:327)
    at org.jboss.seam.jsf.SeamPhaseListener.beforeServletPhase(SeamPhaseListener.java:144)
    at org.jboss.seam.jsf.SeamPhaseListener.beforePhase(SeamPhaseListener.java:118)
    at com.sun.faces.lifecycle.Phase.handleBeforePhase(Phase.java:214)
    at com.sun.faces.lifecycle.Phase.doPhase(Phase.java:96)
    at com.sun.faces.lifecycle.LifecycleImpl.render(LifecycleImpl.java:139)
    at de.verit.klaros.web.beans.application.lifecycle.LifecycleImpl.render(LifecycleImpl.java:96)
    at com.icesoft.faces.webapp.http.core.JsfLifecycleExecutor.apply(JsfLifecycleExecutor.java:19)
    at com.icesoft.faces.context.View$2$1.respond(View.java:48)
    at com.icesoft.faces.webapp.http.servlet.ServletRequestResponse.respondWith(ServletRequestResponse.java:201)
    at com.icesoft.faces.context.View$2.serve(View.java:77)
    at com.icesoft.faces.context.View.servePage(View.java:149)
    at com.icesoft.faces.webapp.http.core.MultiViewServer.service(MultiViewServer.java:67)
    at com.icesoft.faces.webapp.http.common.ServerProxy.service(ServerProxy.java:11)
    at com.icesoft.faces.webapp.http.servlet.MainSessionBoundServlet$4.service(MainSessionBoundServlet.java:149)
    at com.icesoft.faces.webapp.http.common.standard.PathDispatcherServer.service(PathDispatcherServer.java:24)
    at com.icesoft.faces.webapp.http.servlet.BasicAdaptingServlet.service(BasicAdaptingServlet.java:16)
    at com.icesoft.faces.webapp.http.servlet.PathDispatcher.service(PathDispatcher.java:23)
    at com.icesoft.faces.webapp.http.servlet.SessionDispatcher.service(SessionDispatcher.java:53)
    at com.icesoft.faces.webapp.http.servlet.PathDispatcher.service(PathDispatcher.java:23)
    at com.icesoft.faces.webapp.http.servlet.MainServlet.service(MainServlet.java:131)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:717)
    at de.verit.klaros.web.servlet.ExceptionHandlingPersistentFacesServlet.service(ExceptionHandlingPersistentFacesServlet.java:51)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:290)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
    at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:233)
    at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191)
    at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:128)
    at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102)
    at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)
    at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:293)
    at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:856)
    at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(Http11Protocol.java:583)
    at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:454)
    at java.lang.Thread.run(Thread.java:662)
Caused by: org.springframework.transaction.CannotCreateTransactionException: Could not open Hibernate Session for transaction; nested exception is org.hibernate.TransactionException: JDBC begin failed:
    at org.springframework.orm.hibernate3.HibernateTransactionManager.doBegin(HibernateTransactionManager.java:599)
    at org.springframework.transaction.support.AbstractPlatformTransactionManager.getTransaction(AbstractPlatformTransactionManager.java:374)
    at org.jboss.seam.ioc.spring.SpringTransaction.begin(SpringTransaction.java:67)
    at org.jboss.seam.jsf.SeamPhaseListener.begin(SeamPhaseListener.java:593)
    ... 36 more
Caused by: org.hibernate.TransactionException: JDBC begin failed:
    at org.hibernate.transaction.JDBCTransaction.begin(JDBCTransaction.java:96)
    at org.hibernate.impl.SessionImpl.beginTransaction(SessionImpl.java:1463)
    at org.springframework.orm.hibernate3.HibernateTransactionManager.doBegin(HibernateTransactionManager.java:558)
    ... 39 more
Caused by: com.mysql.jdbc.exceptions.jdbc4.CommunicationsException: The last packet successfully received from the server was 53.510.109 milliseconds ago.  The last packet sent successfully to the server was 53.510.110 milliseconds ago. is longer than the server configured value of 'wait_timeout'. You should consider either expiring and/or testing connection validity before use in your application, increasing the server configured values for client timeouts, or using the Connector/J connection property 'autoReconnect=true' to avoid this problem.
    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:409)
    at com.mysql.jdbc.SQLError.createCommunicationsException(SQLError.java:1118)
    at com.mysql.jdbc.MysqlIO.send(MysqlIO.java:3321)
    at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:1940)
    at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2113)
    at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2562)
    at com.mysql.jdbc.ConnectionImpl.setAutoCommit(ConnectionImpl.java:4956)
    at org.apache.commons.dbcp.DelegatingConnection.setAutoCommit(DelegatingConnection.java:331)
    at org.apache.commons.dbcp.PoolingDataSource$PoolGuardConnectionWrapper.setAutoCommit(PoolingDataSource.java:317)
    at org.hibernate.transaction.JDBCTransaction.begin(JDBCTransaction.java:91)
    ... 41 more
Caused by: java.net.SocketException: Broken pipe
    at java.net.SocketOutputStream.socketWrite0(Native Method)
    at java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:92)
    at java.net.SocketOutputStream.write(SocketOutputStream.java:136)
    at java.io.BufferedOutputStream.flushBuffer(BufferedOutputStream.java:65)
    at java.io.BufferedOutputStream.flush(BufferedOutputStream.java:123)
    at com.mysql.jdbc.MysqlIO.send(MysqlIO.java:3302)
    ... 48 more


I already added these settings to the file 'hibernate.properties':

...
hibernate.connection.url=jdbc:mysql://a.b.c.d:3306/klaros_db?autoReconnect=true
hibernate.connection.autoReconnect=true
hibernate.connection.autoReconnectForPools=true
...


...but that doesn't seem to help. After this exception occurs the connection is established again and after getting two internal errors in Klaros I can continue working normally.

So my question: Is there any opportunity to avoid running into database connection timeout?

Regards,
Thomas
thumbnail
Torsten Stolpmann, geändert vor 13 Jahren.

RE: Database timeout (Antwort)

Jedi Council Member Beiträge: 759 Beitrittsdatum: 12.02.09 Neueste Beiträge
Hi Thomas,

this problem cannot be solved at the client (Klaros) side. MySQL servers have the nasty habit to invalidate client sessions after a configurable timeout (default 8 hours).

To remedy this, you have to configure a bigger timeout in your MySQL Server instance (/etc/mysql.ini) like shown in the attached screenshot. The value shown amounts to 7 days. You have to restart mysql and Klaros afterwards.

Thanks for bringing this issue up again, as this issue has not yet been answered in the forum.

Regards,

Torsten
Thomas Reimer, geändert vor 13 Jahren.

RE: Database timeout

Youngling Beiträge: 9 Beitrittsdatum: 11.11.10 Neueste Beiträge
Hi Torsten,

thanks for your quick reply. My problem is that I cannot change the timeout setting of mysql since the server is a public one with many clients. Due to this I wondered whether it would be possible to insert a little function into Klaros which sends "keepalive requests" - let's say every 30 minutes - to the database server to keep the session open all the time.

What do you think? Could that be a possible solution for the timeout problem?

Regards,
Thomas
thumbnail
Torsten Stolpmann, geändert vor 13 Jahren.

RE: Database timeout (Antwort)

Jedi Council Member Beiträge: 759 Beitrittsdatum: 12.02.09 Neueste Beiträge
Hi Thomas,

I see your pain. Yet I fear this may not be sufficient to solve this completely since database sessions are pooled inside Klaros (actually Hibernate is doing this), so individual sessions may still time out if they are pooled and unused long enough.

Nonetheless I opened an improvement issue (KLAROS-1075 - Send keepalive database requests periodically) to track progress on this.

In the meantime you may consider switching to PostgreSQL.

Thanks for your input!

Regards,

Torsten
thumbnail
Torsten Stolpmann, geändert vor 13 Jahren.

RE: Database timeout

Jedi Council Member Beiträge: 759 Beitrittsdatum: 12.02.09 Neueste Beiträge
Hi Thomas,

we enabled a proper connection pooling in the upcoming 3.2.2 release. This should finally solve your session timeout problems.

Regards,

Torsten
Thomas Reimer, geändert vor 13 Jahren.

RE: Database timeout

Youngling Beiträge: 9 Beitrittsdatum: 11.11.10 Neueste Beiträge
Hi Torsten,

now the connection handling works much better. We experienced no timeouts since update to release 3.2.2 anymore. Thanks for the quick solving!

Regards,
Thomas