JOC Cockpit should close database connection when a session is completed

Current Situation

• JOC Cockpit makes use of a connection pool which translates to the fact that operations such as "open" and "close" connection do not open a physical connection, but use a logical connection from the connection pool.
• Under some condition, e.g. if a user does not log out and a session timeout occurs, a connection to the database that has been created for the session seems not to be closed.
  • After some timeout the DBMS will abort a connection. MySQL in the below example is configured to use wait_timeout=28800, i.e. 8 hours.
    • When aborting an idle connection then the respective MySQL message is: "Aborted connection 189 to db: 'scheduler112' user: 'scheduler' host: 'apmacwin' (Got an error reading communication packets)", see linked article for details.
  • The JOC Cockpit connection pool tries to re-use the connection which results in an error. The hibernate configuration for JOC Cockpit by default includes the settings maxIdleTime=14400 and maxConnectionAge=14400 which corresponds to 4 hours. However, these idle timeout settings apply only if a logical "close" connection operation is performed by the JOC Cockpit towards the connection pool.
  • Therefore the default settings of the connection pool to close/renew connections earlier than the DMBS seems to be fine. However, consider the problem for connection id 189 from the below logs: first MySQL aborts the connection, then the connection pool tries to re-use it:
    • The JOC Cockpit log states (timestamps in UTC+2):

      2018-10-20 21:12:25,537 WARN  p1129670968-1289 o.h.e.j.s.SqlExceptionHelper                 - SQL Error: 0, SQLState: 08
      2018-10-20 21:12:25,537 ERROR p1129670968-1289 o.h.e.j.s.SqlExceptionHelper                 - (conn=189) Connection reset by peer: socket write error
      2018-10-20 21:12:25,547 INFO  p1129670968-1289 c.s.j.c.JOCDefaultResponse                   - 
      REQUEST: ./orders/overview/summary
      PARAMS: {"jobschedulerId":"apmacwin_4444","orders":[],"excludeOrders":[],"compact":false,"processingStates":[],"types":[],"dateFrom":"0d","timeZone":"Europe/Berlin","folders":[],"limit":10000,"historyStates":[],"historyIds":[]}
      USER: root
      2018-10-20 21:12:25,547 ERROR p1129670968-1289 c.s.j.c.JOCDefaultResponse                   - com.sos.hibernate.exceptions.SOSHibernateInvalidSessionException: Unable to acquire JDBC Connection: 0 (conn=189) Connection reset by peer: socket write error [Select count(*) from com.sos.jitl.reporting.db.DBItemReportTrigger where  schedulerId=:schedulerId and  startTime>= :startTimeFrom and  resultError = 1]
      com.sos.hibernate.exceptions.SOSHibernateInvalidSessionException: Unable to acquire JDBC Connection: 0 (conn=189) Connection reset by peer: socket write error [Select count(*) from com.sos.jitl.reporting.db.DBItemReportTrigger where  schedulerId=:schedulerId and  startTime>= :startTimeFrom and  resultError = 1]
      	at com.sos.hibernate.classes.SOSHibernateSession.throwException(SOSHibernateSession.java:1434)
      	at com.sos.hibernate.classes.SOSHibernateSession.getResultList(SOSHibernateSession.java:553)
      	at com.sos.jitl.reporting.db.ReportTriggerDBLayer.getCountSchedulerOrderHistoryListFromTo(ReportTriggerDBLayer.java:241)
      	at com.sos.joc.orders.impl.OrdersResourceOverviewSummaryImpl.postOrdersOverviewSummary(OrdersResourceOverviewSummaryImpl.java:84)
      	at com.sos.joc.orders.impl.OrdersResourceOverviewSummaryImpl.postOrdersOverviewSummary(OrdersResourceOverviewSummaryImpl.java:31)
      	at sun.reflect.GeneratedMethodAccessor738.invoke(Unknown Source)
      	at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
      	at java.lang.reflect.Method.invoke(Unknown Source)
      	at org.glassfish.jersey.server.model.internal.ResourceMethodInvocationHandlerFactory$1.invoke(ResourceMethodInvocationHandlerFactory.java:81)
      	at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher$1.run(AbstractJavaResourceMethodDispatcher.java:144)
      	at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.invoke(AbstractJavaResourceMethodDispatcher.java:161)
      	at org.glassfish.jersey.server.model.internal.JavaResourceMethodDispatcherProvider$ResponseOutInvoker.doDispatch(JavaResourceMethodDispatcherProvider.java:160)
      	at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.dispatch(AbstractJavaResourceMethodDispatcher.java:99)
      	at org.glassfish.jersey.server.model.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:389)
      	at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:347)
      	at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:102)
      	at org.glassfish.jersey.server.ServerRuntime$2.run(ServerRuntime.java:326)
      	at org.glassfish.jersey.internal.Errors$1.call(Errors.java:271)
      	at org.glassfish.jersey.internal.Errors$1.call(Errors.java:267)
      	at org.glassfish.jersey.internal.Errors.process(Errors.java:315)
      	at org.glassfish.jersey.internal.Errors.process(Errors.java:297)
      	at org.glassfish.jersey.internal.Errors.process(Errors.java:267)
      	at org.glassfish.jersey.process.internal.RequestScope.runInScope(RequestScope.java:317)
      	at org.glassfish.jersey.server.ServerRuntime.process(ServerRuntime.java:305)
      	at org.glassfish.jersey.server.ApplicationHandler.handle(ApplicationHandler.java:1154)
      	at org.glassfish.jersey.servlet.WebComponent.serviceImpl(WebComponent.java:473)
      	at org.glassfish.jersey.servlet.WebComponent.service(WebComponent.java:427)
      	at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:388)
      	at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:341)
      	at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:228)
      	at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:857)
      	at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:535)
      	at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:146)
      	at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:548)
      	at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:132)
      	at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:257)
      	at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1595)
      	at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:255)
      	at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1340)
      	at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:203)
      	at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:473)
      	at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1564)
      	at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:201)
      	at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1242)
      	at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:144)
      	at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:220)
      	at org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.java:126)
      	at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:132)
      	at org.eclipse.jetty.server.Server.handle(Server.java:503)
      	at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:364)
      	at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:260)
      	at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:305)
      	at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:103)
      	at org.eclipse.jetty.io.ChannelEndPoint$2.run(ChannelEndPoint.java:118)
      	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.runTask(EatWhatYouKill.java:333)
      	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:310)
      	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:168)
      	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:126)
      	at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:366)
      	at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:765)
      	at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:683)
      	at java.lang.Thread.run(Unknown Source)
      Caused by: org.hibernate.exception.JDBCConnectionException: Unable to acquire JDBC Connection
      	at org.hibernate.exception.internal.SQLExceptionTypeDelegate.convert(SQLExceptionTypeDelegate.java:48)
      	at org.hibernate.exception.internal.StandardSQLExceptionConverter.convert(StandardSQLExceptionConverter.java:42)
      	at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:111)
      	at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:97)
      	at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.acquireConnectionIfNeeded(LogicalConnectionManagedImpl.java:102)
      	at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.getPhysicalConnection(LogicalConnectionManagedImpl.java:129)
      	at org.hibernate.engine.jdbc.internal.StatementPreparerImpl.connection(StatementPreparerImpl.java:47)
      	at org.hibernate.engine.jdbc.internal.StatementPreparerImpl$5.doPrepare(StatementPreparerImpl.java:146)
      	at org.hibernate.engine.jdbc.internal.StatementPreparerImpl$StatementPreparationTemplate.prepareStatement(StatementPreparerImpl.java:172)
      	at org.hibernate.engine.jdbc.internal.StatementPreparerImpl.prepareQueryStatement(StatementPreparerImpl.java:148)
      	at org.hibernate.loader.Loader.prepareQueryStatement(Loader.java:1940)
      	at org.hibernate.loader.Loader.executeQueryStatement(Loader.java:1909)
      	at org.hibernate.loader.Loader.executeQueryStatement(Loader.java:1887)
      	at org.hibernate.loader.Loader.doQuery(Loader.java:932)
      	at org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:349)
      	at org.hibernate.loader.Loader.doList(Loader.java:2615)
      	at org.hibernate.loader.Loader.doList(Loader.java:2598)
      	at org.hibernate.loader.Loader.listIgnoreQueryCache(Loader.java:2430)
      	at org.hibernate.loader.Loader.list(Loader.java:2425)
      	at org.hibernate.loader.hql.QueryLoader.list(QueryLoader.java:502)
      	at org.hibernate.hql.internal.ast.QueryTranslatorImpl.list(QueryTranslatorImpl.java:370)
      	at org.hibernate.engine.query.spi.HQLQueryPlan.performList(HQLQueryPlan.java:216)
      	at org.hibernate.internal.StatelessSessionImpl.list(StatelessSessionImpl.java:461)
      	at org.hibernate.query.internal.AbstractProducedQuery.doList(AbstractProducedQuery.java:1441)
      	at org.hibernate.query.internal.AbstractProducedQuery.list(AbstractProducedQuery.java:1410)
      	at org.hibernate.Query.getResultList(Query.java:427)
      	at com.sos.hibernate.classes.SOSHibernateSession.getResultList(SOSHibernateSession.java:548)
      	... 60 more
      Caused by: java.sql.SQLNonTransientConnectionException: (conn=189) Connection reset by peer: socket write error
      	at org.mariadb.jdbc.internal.util.exceptions.ExceptionMapper.get(ExceptionMapper.java:175)
      	at org.mariadb.jdbc.internal.util.exceptions.ExceptionMapper.getException(ExceptionMapper.java:110)
      	at org.mariadb.jdbc.internal.util.exceptions.ExceptionMapper.throwException(ExceptionMapper.java:75)
      	at org.mariadb.jdbc.MariaDbConnection.setTransactionIsolation(MariaDbConnection.java:943)
      	at com.mchange.v2.c3p0.impl.NewProxyConnection.setTransactionIsolation(NewProxyConnection.java:833)
      	at org.hibernate.c3p0.internal.C3P0ConnectionProvider.getConnection(C3P0ConnectionProvider.java:75)
      	at org.hibernate.internal.NonContextualJdbcConnectionAccess.obtainConnection(NonContextualJdbcConnectionAccess.java:35)
      	at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.acquireConnectionIfNeeded(LogicalConnectionManagedImpl.java:99)
      	... 82 more
      Caused by: java.sql.SQLException: Connection reset by peer: socket write error
      	at org.mariadb.jdbc.internal.protocol.AbstractQueryProtocol.handleIoException(AbstractQueryProtocol.java:1786)
      	at org.mariadb.jdbc.internal.protocol.AbstractQueryProtocol.executeQuery(AbstractQueryProtocol.java:202)
      	at org.mariadb.jdbc.internal.protocol.AbstractQueryProtocol.executeQuery(AbstractQueryProtocol.java:176)
      	at org.mariadb.jdbc.internal.protocol.AbstractQueryProtocol.setTransactionIsolation(AbstractQueryProtocol.java:1305)
      	at org.mariadb.jdbc.MariaDbConnection.setTransactionIsolation(MariaDbConnection.java:941)
      	... 86 more
      Caused by: java.net.SocketException: Connection reset by peer: socket write error
      	at java.net.SocketOutputStream.socketWrite0(Native Method)
      	at java.net.SocketOutputStream.socketWrite(Unknown Source)
      	at java.net.SocketOutputStream.write(Unknown Source)
      	at org.mariadb.jdbc.internal.io.output.StandardPacketOutputStream.flushBuffer(StandardPacketOutputStream.java:110)
      	at org.mariadb.jdbc.internal.io.output.AbstractPacketOutputStream.flush(AbstractPacketOutputStream.java:172)
      	at org.mariadb.jdbc.internal.protocol.AbstractQueryProtocol.executeQuery(AbstractQueryProtocol.java:196)
      	... 89 more
      

    • The MySQL error log states (timestamps in UTC+0):

      2018-10-20T19:11:00.110187Z 189 [Note] Aborted connection 189 to db: 'scheduler112' user: 'scheduler' host: 'apmacwin' (Got an error reading communication packets)
      

Desired Behavior

• JOC Cockpit should close a logical connection to the pool in case that a session is terminated, i.e. in case of a user logout and in case of a session timeout. This will allow the connection pool to consider the connection being idle and to apply respective settings to close/renew connections in good time.