Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

org.hibernate.QueryTimeoutException: Unable to acquire JDBC Connection #3280

Open
fviale opened this issue Aug 1, 2018 · 5 comments
Open

org.hibernate.QueryTimeoutException: Unable to acquire JDBC Connection #3280

fviale opened this issue Aug 1, 2018 · 5 comments
Labels
severity:minor type:bug

Comments

@fviale
Copy link
Member

fviale commented Aug 1, 2018

This serious issue freezes the scheduler, where all database operation seems to be dangling forever.
Attached is a resulting thread dump, and some scheduler logs.
@fviale
Copy link
Member Author

fviale commented Aug 1, 2018

Scheduler logs:

[2018-07-31 02:08:24,083 ner Thread INFO         o.o.p.c.SessionsCleaner] cleaning session started, 0 existing session(s) 
[2018-07-31 02:08:24,083 ner Thread INFO         o.o.p.c.SessionsCleaner] cleaning session ended, 0 session(s) removed
[2018-07-31 02:08:51,378 "peps_q01" INFO            o.o.p.r.n.NodeSource] [peps_q01] Pinging alive nodes : 31
[2018-07-31 02:09:10,537 "peps_q02" INFO            o.o.p.r.n.NodeSource] [peps_q02] Pinging alive nodes : 24
[2018-07-31 02:09:55,538 "peps_q02" INFO            o.o.p.r.n.NodeSource] [peps_q02] Pinging alive nodes : 24
[2018-07-31 02:10:00,022 f467972cd] WARN    o.h.e.j.s.SqlExceptionHelper] SQL Warning Code: -1100, SQLState: 02000
[2018-07-31 02:10:00,023 f467972cd] WARN    o.h.e.j.s.SqlExceptionHelper] no data
[2018-07-31 02:10:00,023 f467972cd] WARN    o.h.e.j.s.SqlExceptionHelper] SQL Warning Code: -1100, SQLState: 02000
[2018-07-31 02:10:00,023 f467972cd] WARN    o.h.e.j.s.SqlExceptionHelper] no data
[2018-07-31 02:10:21,378 "peps_q01" INFO            o.o.p.r.n.NodeSource] [peps_q01] Pinging alive nodes : 31
[2018-07-31 02:10:40,539 "peps_q02" INFO            o.o.p.r.n.NodeSource] [peps_q02] Pinging alive nodes : 24
[2018-07-31 02:11:00,039 8245da750] WARN    o.h.e.j.s.SqlExceptionHelper] SQL Error: 0, SQLState: null
[2018-07-31 02:11:00,039 8245da750] ERROR   o.h.e.j.s.SqlExceptionHelper] Timeout after 60023ms of waiting for a connection.
[2018-07-31 02:11:00,040 8245da750] WARN       o.o.p.d.TransactionHelper] Database operation failed
org.hibernate.QueryTimeoutException: Unable to acquire JDBC Connection
	at org.hibernate.exception.internal.SQLExceptionTypeDelegate.convert(SQLExceptionTypeDelegate.java:66)
	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:87)
	at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.getPhysicalConnection(LogicalConnectionManagedImpl.java:109)
	at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.getConnectionForTransactionManagement(LogicalConnectionManagedImpl.java:227)
	at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.begin(LogicalConnectionManagedImpl.java:234)
	at org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl$TransactionDriverControlImpl.begin(JdbcResourceLocalTransactionCoordinatorImpl.java:214)
	at org.hibernate.engine.transaction.internal.TransactionImpl.begin(TransactionImpl.java:52)
	at org.hibernate.internal.SessionImpl.beginTransaction(SessionImpl.java:1525)
	at org.ow2.proactive.db.TransactionHelper.tryExecuteTransaction(TransactionHelper.java:120)
	at org.ow2.proactive.db.TransactionHelper.tryExecuteTransactionLoop(TransactionHelper.java:96)
	at org.ow2.proactive.db.TransactionHelper.executeReadOnlyTransaction(TransactionHelper.java:60)
	at org.ow2.proactive.scheduler.core.db.SchedulerDBManager.executeReadOnlyTransaction(SchedulerDBManager.java:1726)
	at org.ow2.proactive.scheduler.core.db.SchedulerDBManager.getJobsToRemove(SchedulerDBManager.java:756)
	at org.ow2.proactive.scheduler.core.SchedulingService$HousekeepingRunner.run(SchedulingService.java:1153)
	at it.sauronsoftware.cron4j.RunnableTask.execute(Unknown Source)
	at it.sauronsoftware.cron4j.TaskExecutor$Runner.run(Unknown Source)
	at java.lang.Thread.run(Thread.java:748)
Caused by: java.sql.SQLTimeoutException: Timeout after 60023ms of waiting for a connection.
	at com.zaxxer.hikari.pool.BaseHikariPool.getConnection(BaseHikariPool.java:233)
	at com.zaxxer.hikari.pool.BaseHikariPool.getConnection(BaseHikariPool.java:183)
	at com.zaxxer.hikari.HikariDataSource.getConnection(HikariDataSource.java:93)
	at org.hibernate.hikaricp.internal.HikariCPConnectionProvider.getConnection(HikariCPConnectionProvider.java:77)
	at org.hibernate.internal.AbstractSessionImpl$NonContextualJdbcConnectionAccess.obtainConnection(AbstractSessionImpl.java:386)
	at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.acquireConnectionIfNeeded(LogicalConnectionManagedImpl.java:84)
	... 15 more
[2018-07-31 02:11:00,042 8245da750] WARN       o.o.p.d.TransactionHelper] Database operation failed. Automatic retry in 1000 ms (attempt 0)
org.hibernate.QueryTimeoutException: Unable to acquire JDBC Connection
	at org.hibernate.exception.internal.SQLExceptionTypeDelegate.convert(SQLExceptionTypeDelegate.java:66)
	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:87)
	at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.getPhysicalConnection(LogicalConnectionManagedImpl.java:109)
	at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.getConnectionForTransactionManagement(LogicalConnectionManagedImpl.java:227)
	at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.begin(LogicalConnectionManagedImpl.java:234)
	at org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl$TransactionDriverControlImpl.begin(JdbcResourceLocalTransactionCoordinatorImpl.java:214)
	at org.hibernate.engine.transaction.internal.TransactionImpl.begin(TransactionImpl.java:52)
	at org.hibernate.internal.SessionImpl.beginTransaction(SessionImpl.java:1525)
	at org.ow2.proactive.db.TransactionHelper.tryExecuteTransaction(TransactionHelper.java:120)
	at org.ow2.proactive.db.TransactionHelper.tryExecuteTransactionLoop(TransactionHelper.java:96)
	at org.ow2.proactive.db.TransactionHelper.executeReadOnlyTransaction(TransactionHelper.java:60)
	at org.ow2.proactive.scheduler.core.db.SchedulerDBManager.executeReadOnlyTransaction(SchedulerDBManager.java:1726)
	at org.ow2.proactive.scheduler.core.db.SchedulerDBManager.getJobsToRemove(SchedulerDBManager.java:756)
	at org.ow2.proactive.scheduler.core.SchedulingService$HousekeepingRunner.run(SchedulingService.java:1153)
	at it.sauronsoftware.cron4j.RunnableTask.execute(Unknown Source)
	at it.sauronsoftware.cron4j.TaskExecutor$Runner.run(Unknown Source)
	at java.lang.Thread.run(Thread.java:748)
Caused by: java.sql.SQLTimeoutException: Timeout after 60023ms of waiting for a connection.
	at com.zaxxer.hikari.pool.BaseHikariPool.getConnection(BaseHikariPool.java:233)
	at com.zaxxer.hikari.pool.BaseHikariPool.getConnection(BaseHikariPool.java:183)
	at com.zaxxer.hikari.HikariDataSource.getConnection(HikariDataSource.java:93)
	at org.hibernate.hikaricp.internal.HikariCPConnectionProvider.getConnection(HikariCPConnectionProvider.java:77)
	at org.hibernate.internal.AbstractSessionImpl$NonContextualJdbcConnectionAccess.obtainConnection(AbstractSessionImpl.java:386)
	at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.acquireConnectionIfNeeded(LogicalConnectionManagedImpl.java:84)
	... 15 more
[2018-07-31 02:11:06,379 "peps_q01" INFO            o.o.p.r.n.NodeSource] [peps_q01] Pinging alive nodes : 31
[2018-07-31 02:11:25,540 "peps_q02" INFO            o.o.p.r.n.NodeSource] [peps_q02] Pinging alive nodes : 24
[2018-07-31 02:12:01,044 8245da750] WARN    o.h.e.j.s.SqlExceptionHelper] SQL Error: 0, SQLState: null
[2018-07-31 02:12:01,044 8245da750] ERROR   o.h.e.j.s.SqlExceptionHelper] Timeout after 60001ms of waiting for a connection.
[2018-07-31 02:12:01,044 8245da750] WARN       o.o.p.d.TransactionHelper] Database operation failed
org.hibernate.QueryTimeoutException: Unable to acquire JDBC Connection
	at org.hibernate.exception.internal.SQLExceptionTypeDelegate.convert(SQLExceptionTypeDelegate.java:66)
	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:87)
	at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.getPhysicalConnection(LogicalConnectionManagedImpl.java:109)
	at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.getConnectionForTransactionManagement(LogicalConnectionManagedImpl.java:227)
	at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.begin(LogicalConnectionManagedImpl.java:234)
	at org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl$TransactionDriverControlImpl.begin(JdbcResourceLocalTransactionCoordinatorImpl.java:214)
	at org.hibernate.engine.transaction.internal.TransactionImpl.begin(TransactionImpl.java:52)
	at org.hibernate.internal.SessionImpl.beginTransaction(SessionImpl.java:1525)
	at org.ow2.proactive.db.TransactionHelper.tryExecuteTransaction(TransactionHelper.java:120)
	at org.ow2.proactive.db.TransactionHelper.tryExecuteTransactionLoop(TransactionHelper.java:96)
	at org.ow2.proactive.db.TransactionHelper.executeReadOnlyTransaction(TransactionHelper.java:60)
	at org.ow2.proactive.scheduler.core.db.SchedulerDBManager.executeReadOnlyTransaction(SchedulerDBManager.java:1726)
	at org.ow2.proactive.scheduler.core.db.SchedulerDBManager.getJobsToRemove(SchedulerDBManager.java:756)
	at org.ow2.proactive.scheduler.core.SchedulingService$HousekeepingRunner.run(SchedulingService.java:1153)
	at it.sauronsoftware.cron4j.RunnableTask.execute(Unknown Source)
	at it.sauronsoftware.cron4j.TaskExecutor$Runner.run(Unknown Source)
	at java.lang.Thread.run(Thread.java:748)
Caused by: java.sql.SQLTimeoutException: Timeout after 60001ms of waiting for a connection.
	at com.zaxxer.hikari.pool.BaseHikariPool.getConnection(BaseHikariPool.java:233)
	at com.zaxxer.hikari.pool.BaseHikariPool.getConnection(BaseHikariPool.java:183)
	at com.zaxxer.hikari.HikariDataSource.getConnection(HikariDataSource.java:93)
	at org.hibernate.hikaricp.internal.HikariCPConnectionProvider.getConnection(HikariCPConnectionProvider.java:77)
	at org.hibernate.internal.AbstractSessionImpl$NonContextualJdbcConnectionAccess.obtainConnection(AbstractSessionImpl.java:386)
	at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.acquireConnectionIfNeeded(LogicalConnectionManagedImpl.java:84)
	... 15 more
[2018-07-31 02:12:01,045 8245da750] WARN       o.o.p.d.TransactionHelper] Database operation failed. Automatic retry in 2000 ms (attempt 1)
org.hibernate.QueryTimeoutException: Unable to acquire JDBC Connection
	at org.hibernate.exception.internal.SQLExceptionTypeDelegate.convert(SQLExceptionTypeDelegate.java:66)
	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:87)
	at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.getPhysicalConnection(LogicalConnectionManagedImpl.java:109)
	at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.getConnectionForTransactionManagement(LogicalConnectionManagedImpl.java:227)
	at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.begin(LogicalConnectionManagedImpl.java:234)
	at org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl$TransactionDriverControlImpl.begin(JdbcResourceLocalTransactionCoordinatorImpl.java:214)
	at org.hibernate.engine.transaction.internal.TransactionImpl.begin(TransactionImpl.java:52)
	at org.hibernate.internal.SessionImpl.beginTransaction(SessionImpl.java:1525)
	at org.ow2.proactive.db.TransactionHelper.tryExecuteTransaction(TransactionHelper.java:120)
	at org.ow2.proactive.db.TransactionHelper.tryExecuteTransactionLoop(TransactionHelper.java:96)
	at org.ow2.proactive.db.TransactionHelper.executeReadOnlyTransaction(TransactionHelper.java:60)
	at org.ow2.proactive.scheduler.core.db.SchedulerDBManager.executeReadOnlyTransaction(SchedulerDBManager.java:1726)
	at org.ow2.proactive.scheduler.core.db.SchedulerDBManager.getJobsToRemove(SchedulerDBManager.java:756)
	at org.ow2.proactive.scheduler.core.SchedulingService$HousekeepingRunner.run(SchedulingService.java:1153)
	at it.sauronsoftware.cron4j.RunnableTask.execute(Unknown Source)
	at it.sauronsoftware.cron4j.TaskExecutor$Runner.run(Unknown Source)
	at java.lang.Thread.run(Thread.java:748)
Caused by: java.sql.SQLTimeoutException: Timeout after 60001ms of waiting for a connection.
	at com.zaxxer.hikari.pool.BaseHikariPool.getConnection(BaseHikariPool.java:233)
	at com.zaxxer.hikari.pool.BaseHikariPool.getConnection(BaseHikariPool.java:183)
	at com.zaxxer.hikari.HikariDataSource.getConnection(HikariDataSource.java:93)
	at org.hibernate.hikaricp.internal.HikariCPConnectionProvider.getConnection(HikariCPConnectionProvider.java:77)
	at org.hibernate.internal.AbstractSessionImpl$NonContextualJdbcConnectionAccess.obtainConnection(AbstractSessionImpl.java:386)
	at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.acquireConnectionIfNeeded(LogicalConnectionManagedImpl.java:84)
	... 15 more
[2018-07-31 02:12:10,541 "peps_q02" INFO            o.o.p.r.n.NodeSource] [peps_q02] Pinging alive nodes : 24
[2018-07-31 02:12:36,379 "peps_q01" INFO            o.o.p.r.n.NodeSource] [peps_q01] Pinging alive nodes : 31
[2018-07-31 02:13:03,046 8245da750] WARN    o.h.e.j.s.SqlExceptionHelper] SQL Error: 0, SQLState: null
[2018-07-31 02:13:03,046 8245da750] ERROR   o.h.e.j.s.SqlExceptionHelper] Timeout after 60001ms of waiting for a connection.
[2018-07-31 02:13:03,046 8245da750] WARN       o.o.p.d.TransactionHelper] Database operation failed
org.hibernate.QueryTimeoutException: Unable to acquire JDBC Connection
	at org.hibernate.exception.internal.SQLExceptionTypeDelegate.convert(SQLExceptionTypeDelegate.java:66)
	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:87)
	at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.getPhysicalConnection(LogicalConnectionManagedImpl.java:109)
	at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.getConnectionForTransactionManagement(LogicalConnectionManagedImpl.java:227)
	at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.begin(LogicalConnectionManagedImpl.java:234)
	at org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl$TransactionDriverControlImpl.begin(JdbcResourceLocalTransactionCoordinatorImpl.java:214)
	at org.hibernate.engine.transaction.internal.TransactionImpl.begin(TransactionImpl.java:52)
	at org.hibernate.internal.SessionImpl.beginTransaction(SessionImpl.java:1525)
	at org.ow2.proactive.db.TransactionHelper.tryExecuteTransaction(TransactionHelper.java:120)
	at org.ow2.proactive.db.TransactionHelper.tryExecuteTransactionLoop(TransactionHelper.java:96)
	at org.ow2.proactive.db.TransactionHelper.executeReadOnlyTransaction(TransactionHelper.java:60)
	at org.ow2.proactive.scheduler.core.db.SchedulerDBManager.executeReadOnlyTransaction(SchedulerDBManager.java:1726)
	at org.ow2.proactive.scheduler.core.db.SchedulerDBManager.getJobsToRemove(SchedulerDBManager.java:756)
	at org.ow2.proactive.scheduler.core.SchedulingService$HousekeepingRunner.run(SchedulingService.java:1153)
	at it.sauronsoftware.cron4j.RunnableTask.execute(Unknown Source)
	at it.sauronsoftware.cron4j.TaskExecutor$Runner.run(Unknown Source)
	at java.lang.Thread.run(Thread.java:748)
Caused by: java.sql.SQLTimeoutException: Timeout after 60001ms of waiting for a connection.
	at com.zaxxer.hikari.pool.BaseHikariPool.getConnection(BaseHikariPool.java:233)
	at com.zaxxer.hikari.pool.BaseHikariPool.getConnection(BaseHikariPool.java:183)
	at com.zaxxer.hikari.HikariDataSource.getConnection(HikariDataSource.java:93)
	at org.hibernate.hikaricp.internal.HikariCPConnectionProvider.getConnection(HikariCPConnectionProvider.java:77)
	at org.hibernate.internal.AbstractSessionImpl$NonContextualJdbcConnectionAccess.obtainConnection(AbstractSessionImpl.java:386)
	at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.acquireConnectionIfNeeded(LogicalConnectionManagedImpl.java:84)
	... 15 more
[2018-07-31 02:13:03,047 8245da750] WARN       o.o.p.d.TransactionHelper] Database operation failed. Automatic retry in 4000 ms (attempt 2)
org.hibernate.QueryTimeoutException: Unable to acquire JDBC Connection
	at org.hibernate.exception.internal.SQLExceptionTypeDelegate.convert(SQLExceptionTypeDelegate.java:66)
	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:87)
	at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.getPhysicalConnection(LogicalConnectionManagedImpl.java:109)
	at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.getConnectionForTransactionManagement(LogicalConnectionManagedImpl.java:227)
	at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.begin(LogicalConnectionManagedImpl.java:234)
	at org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl$TransactionDriverControlImpl.begin(JdbcResourceLocalTransactionCoordinatorImpl.java:214)
	at org.hibernate.engine.transaction.internal.TransactionImpl.begin(TransactionImpl.java:52)
	at org.hibernate.internal.SessionImpl.beginTransaction(SessionImpl.java:1525)
	at org.ow2.proactive.db.TransactionHelper.tryExecuteTransaction(TransactionHelper.java:120)
	at org.ow2.proactive.db.TransactionHelper.tryExecuteTransactionLoop(TransactionHelper.java:96)
	at org.ow2.proactive.db.TransactionHelper.executeReadOnlyTransaction(TransactionHelper.java:60)
	at org.ow2.proactive.scheduler.core.db.SchedulerDBManager.executeReadOnlyTransaction(SchedulerDBManager.java:1726)
	at org.ow2.proactive.scheduler.core.db.SchedulerDBManager.getJobsToRemove(SchedulerDBManager.java:756)
	at org.ow2.proactive.scheduler.core.SchedulingService$HousekeepingRunner.run(SchedulingService.java:1153)
	at it.sauronsoftware.cron4j.RunnableTask.execute(Unknown Source)
	at it.sauronsoftware.cron4j.TaskExecutor$Runner.run(Unknown Source)
	at java.lang.Thread.run(Thread.java:748)
Caused by: java.sql.SQLTimeoutException: Timeout after 60001ms of waiting for a connection.
	at com.zaxxer.hikari.pool.BaseHikariPool.getConnection(BaseHikariPool.java:233)
	at com.zaxxer.hikari.pool.BaseHikariPool.getConnection(BaseHikariPool.java:183)
	at com.zaxxer.hikari.HikariDataSource.getConnection(HikariDataSource.java:93)
	at org.hibernate.hikaricp.internal.HikariCPConnectionProvider.getConnection(HikariCPConnectionProvider.java:77)
	at org.hibernate.internal.AbstractSessionImpl$NonContextualJdbcConnectionAccess.obtainConnection(AbstractSessionImpl.java:386)
	at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.acquireConnectionIfNeeded(LogicalConnectionManagedImpl.java:84)
	... 15 more
[2018-07-31 02:13:24,084 ner Thread INFO         o.o.p.c.SessionsCleaner] cleaning session started, 0 existing session(s) 
[2018-07-31 02:13:24,084 ner Thread INFO         o.o.p.c.SessionsCleaner] cleaning session ended, 0 session(s) removed
[2018-07-31 02:13:40,542 "peps_q02" INFO            o.o.p.r.n.NodeSource] [peps_q02] Pinging alive nodes : 24
[2018-07-31 02:14:06,380 "peps_q01" INFO            o.o.p.r.n.NodeSource] [peps_q01] Pinging alive nodes : 31
[2018-07-31 02:14:07,050 8245da750] WARN    o.h.e.j.s.SqlExceptionHelper] SQL Error: 0, SQLState: null
[2018-07-31 02:14:07,050 8245da750] ERROR   o.h.e.j.s.SqlExceptionHelper] Timeout after 60001ms of waiting for a connection.
[2018-07-31 02:14:07,050 8245da750] WARN       o.o.p.d.TransactionHelper] Database operation failed
org.hibernate.QueryTimeoutException: Unable to acquire JDBC Connection
	at org.hibernate.exception.internal.SQLExceptionTypeDelegate.convert(SQLExceptionTypeDelegate.java:66)
	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:87)
	at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.getPhysicalConnection(LogicalConnectionManagedImpl.java:109)
	at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.getConnectionForTransactionManagement(LogicalConnectionManagedImpl.java:227)
	at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.begin(LogicalConnectionManagedImpl.java:234)
	at org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl$TransactionDriverControlImpl.begin(JdbcResourceLocalTransactionCoordinatorImpl.java:214)
	at org.hibernate.engine.transaction.internal.TransactionImpl.begin(TransactionImpl.java:52)
	at org.hibernate.internal.SessionImpl.beginTransaction(SessionImpl.java:1525)
	at org.ow2.proactive.db.TransactionHelper.tryExecuteTransaction(TransactionHelper.java:120)
	at org.ow2.proactive.db.TransactionHelper.tryExecuteTransactionLoop(TransactionHelper.java:96)
	at org.ow2.proactive.db.TransactionHelper.executeReadOnlyTransaction(TransactionHelper.java:60)
	at org.ow2.proactive.scheduler.core.db.SchedulerDBManager.executeReadOnlyTransaction(SchedulerDBManager.java:1726)
	at org.ow2.proactive.scheduler.core.db.SchedulerDBManager.getJobsToRemove(SchedulerDBManager.java:756)
	at org.ow2.proactive.scheduler.core.SchedulingService$HousekeepingRunner.run(SchedulingService.java:1153)
	at it.sauronsoftware.cron4j.RunnableTask.execute(Unknown Source)
	at it.sauronsoftware.cron4j.TaskExecutor$Runner.run(Unknown Source)
	at java.lang.Thread.run(Thread.java:748)
Caused by: java.sql.SQLTimeoutException: Timeout after 60001ms of waiting for a connection.
	at com.zaxxer.hikari.pool.BaseHikariPool.getConnection(BaseHikariPool.java:233)
	at com.zaxxer.hikari.pool.BaseHikariPool.getConnection(BaseHikariPool.java:183)
	at com.zaxxer.hikari.HikariDataSource.getConnection(HikariDataSource.java:93)
	at org.hibernate.hikaricp.internal.HikariCPConnectionProvider.getConnection(HikariCPConnectionProvider.java:77)
	at org.hibernate.internal.AbstractSessionImpl$NonContextualJdbcConnectionAccess.obtainConnection(AbstractSessionImpl.java:386)
	at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.acquireConnectionIfNeeded(LogicalConnectionManagedImpl.java:84)
	... 15 more
[2018-07-31 02:14:07,051 8245da750] WARN       o.o.p.d.TransactionHelper] Database operation failed. Automatic retry in 8000 ms (attempt 3)
org.hibernate.QueryTimeoutException: Unable to acquire JDBC Connection
	at org.hibernate.exception.internal.SQLExceptionTypeDelegate.convert(SQLExceptionTypeDelegate.java:66)
	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:87)
	at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.getPhysicalConnection(LogicalConnectionManagedImpl.java:109)
	at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.getConnectionForTransactionManagement(LogicalConnectionManagedImpl.java:227)
	at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.begin(LogicalConnectionManagedImpl.java:234)
	at org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl$TransactionDriverControlImpl.begin(JdbcResourceLocalTransactionCoordinatorImpl.java:214)
	at org.hibernate.engine.transaction.internal.TransactionImpl.begin(TransactionImpl.java:52)
	at org.hibernate.internal.SessionImpl.beginTransaction(SessionImpl.java:1525)
	at org.ow2.proactive.db.TransactionHelper.tryExecuteTransaction(TransactionHelper.java:120)
	at org.ow2.proactive.db.TransactionHelper.tryExecuteTransactionLoop(TransactionHelper.java:96)
	at org.ow2.proactive.db.TransactionHelper.executeReadOnlyTransaction(TransactionHelper.java:60)
	at org.ow2.proactive.scheduler.core.db.SchedulerDBManager.executeReadOnlyTransaction(SchedulerDBManager.java:1726)
	at org.ow2.proactive.scheduler.core.db.SchedulerDBManager.getJobsToRemove(SchedulerDBManager.java:756)
	at org.ow2.proactive.scheduler.core.SchedulingService$HousekeepingRunner.run(SchedulingService.java:1153)
	at it.sauronsoftware.cron4j.RunnableTask.execute(Unknown Source)
	at it.sauronsoftware.cron4j.TaskExecutor$Runner.run(Unknown Source)
	at java.lang.Thread.run(Thread.java:748)
Caused by: java.sql.SQLTimeoutException: Timeout after 60001ms of waiting for a connection.
	at com.zaxxer.hikari.pool.BaseHikariPool.getConnection(BaseHikariPool.java:233)
	at com.zaxxer.hikari.pool.BaseHikariPool.getConnection(BaseHikariPool.java:183)
	at com.zaxxer.hikari.HikariDataSource.getConnection(HikariDataSource.java:93)
	at org.hibernate.hikaricp.internal.HikariCPConnectionProvider.getConnection(HikariCPConnectionProvider.java:77)
	at org.hibernate.internal.AbstractSessionImpl$NonContextualJdbcConnectionAccess.obtainConnection(AbstractSessionImpl.java:386)
	at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.acquireConnectionIfNeeded(LogicalConnectionManagedImpl.java:84)
	... 15 more
[2018-07-31 02:14:25,543 "peps_q02" INFO            o.o.p.r.n.NodeSource] [peps_q02] Pinging alive nodes : 24
[2018-07-31 02:15:10,544 "peps_q02" INFO            o.o.p.r.n.NodeSource] [peps_q02] Pinging alive nodes : 24
[2018-07-31 02:15:15,052 8245da750] WARN    o.h.e.j.s.SqlExceptionHelper] SQL Error: 0, SQLState: null
[2018-07-31 02:15:15,052 8245da750] ERROR   o.h.e.j.s.SqlExceptionHelper] Timeout after 60001ms of waiting for a connection.
[2018-07-31 02:15:15,052 8245da750] WARN       o.o.p.d.TransactionHelper] Database operation failed
org.hibernate.QueryTimeoutException: Unable to acquire JDBC Connection
	at org.hibernate.exception.internal.SQLExceptionTypeDelegate.convert(SQLExceptionTypeDelegate.java:66)
	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:87)
	at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.getPhysicalConnection(LogicalConnectionManagedImpl.java:109)
	at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.getConnectionForTransactionManagement(LogicalConnectionManagedImpl.java:227)
	at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.begin(LogicalConnectionManagedImpl.java:234)
	at org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl$TransactionDriverControlImpl.begin(JdbcResourceLocalTransactionCoordinatorImpl.java:214)
	at org.hibernate.engine.transaction.internal.TransactionImpl.begin(TransactionImpl.java:52)
	at org.hibernate.internal.SessionImpl.beginTransaction(SessionImpl.java:1525)
	at org.ow2.proactive.db.TransactionHelper.tryExecuteTransaction(TransactionHelper.java:120)
	at org.ow2.proactive.db.TransactionHelper.tryExecuteTransactionLoop(TransactionHelper.java:96)
	at org.ow2.proactive.db.TransactionHelper.executeReadOnlyTransaction(TransactionHelper.java:60)
	at org.ow2.proactive.scheduler.core.db.SchedulerDBManager.executeReadOnlyTransaction(SchedulerDBManager.java:1726)
	at org.ow2.proactive.scheduler.core.db.SchedulerDBManager.getJobsToRemove(SchedulerDBManager.java:756)
	at org.ow2.proactive.scheduler.core.SchedulingService$HousekeepingRunner.run(SchedulingService.java:1153)
	at it.sauronsoftware.cron4j.RunnableTask.execute(Unknown Source)
	at it.sauronsoftware.cron4j.TaskExecutor$Runner.run(Unknown Source)
	at java.lang.Thread.run(Thread.java:748)
Caused by: java.sql.SQLTimeoutException: Timeout after 60001ms of waiting for a connection.
	at com.zaxxer.hikari.pool.BaseHikariPool.getConnection(BaseHikariPool.java:233)
	at com.zaxxer.hikari.pool.BaseHikariPool.getConnection(BaseHikariPool.java:183)
	at com.zaxxer.hikari.HikariDataSource.getConnection(HikariDataSource.java:93)
	at org.hibernate.hikaricp.internal.HikariCPConnectionProvider.getConnection(HikariCPConnectionProvider.java:77)
	at org.hibernate.internal.AbstractSessionImpl$NonContextualJdbcConnectionAccess.obtainConnection(AbstractSessionImpl.java:386)
	at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.acquireConnectionIfNeeded(LogicalConnectionManagedImpl.java:84)
	... 15 more
[2018-07-31 02:15:15,052 8245da750] WARN       o.o.p.d.TransactionHelper] Database operation failed. Automatic retry in 16000 ms (attempt 4)
org.hibernate.QueryTimeoutException: Unable to acquire JDBC Connection
	at org.hibernate.exception.internal.SQLExceptionTypeDelegate.convert(SQLExceptionTypeDelegate.java:66)
	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:87)
	at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.getPhysicalConnection(LogicalConnectionManagedImpl.java:109)
	at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.getConnectionForTransactionManagement(LogicalConnectionManagedImpl.java:227)
	at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.begin(LogicalConnectionManagedImpl.java:234)
	at org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl$TransactionDriverControlImpl.begin(JdbcResourceLocalTransactionCoordinatorImpl.java:214)
	at org.hibernate.engine.transaction.internal.TransactionImpl.begin(TransactionImpl.java:52)
	at org.hibernate.internal.SessionImpl.beginTransaction(SessionImpl.java:1525)
	at org.ow2.proactive.db.TransactionHelper.tryExecuteTransaction(TransactionHelper.java:120)
	at org.ow2.proactive.db.TransactionHelper.tryExecuteTransactionLoop(TransactionHelper.java:96)
	at org.ow2.proactive.db.TransactionHelper.executeReadOnlyTransaction(TransactionHelper.java:60)
	at org.ow2.proactive.scheduler.core.db.SchedulerDBManager.executeReadOnlyTransaction(SchedulerDBManager.java:1726)
	at org.ow2.proactive.scheduler.core.db.SchedulerDBManager.getJobsToRemove(SchedulerDBManager.java:756)
	at org.ow2.proactive.scheduler.core.SchedulingService$HousekeepingRunner.run(SchedulingService.java:1153)
	at it.sauronsoftware.cron4j.RunnableTask.execute(Unknown Source)
	at it.sauronsoftware.cron4j.TaskExecutor$Runner.run(Unknown Source)
	at java.lang.Thread.run(Thread.java:748)
Caused by: java.sql.SQLTimeoutException: Timeout after 60001ms of waiting for a connection.
	at com.zaxxer.hikari.pool.BaseHikariPool.getConnection(BaseHikariPool.java:233)
	at com.zaxxer.hikari.pool.BaseHikariPool.getConnection(BaseHikariPool.java:183)
	at com.zaxxer.hikari.HikariDataSource.getConnection(HikariDataSource.java:93)
	at org.hibernate.hikaricp.internal.HikariCPConnectionProvider.getConnection(HikariCPConnectionProvider.java:77)
	at org.hibernate.internal.AbstractSessionImpl$NonContextualJdbcConnectionAccess.obtainConnection(AbstractSessionImpl.java:386)
	at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.acquireConnectionIfNeeded(LogicalConnectionManagedImpl.java:84)
	... 15 more
[2018-07-31 02:15:36,380 "peps_q01" INFO            o.o.p.r.n.NodeSource] [peps_q01] Pinging alive nodes : 31
[2018-07-31 02:15:55,545 "peps_q02" INFO            o.o.p.r.n.NodeSource] [peps_q02] Pinging alive nodes : 24
[2018-07-31 02:16:31,056 8245da750] WARN    o.h.e.j.s.SqlExceptionHelper] SQL Error: 0, SQLState: null
[2018-07-31 02:16:31,056 8245da750] ERROR   o.h.e.j.s.SqlExceptionHelper] Timeout after 60003ms of waiting for a connection.
[2018-07-31 02:16:31,056 8245da750] WARN       o.o.p.d.TransactionHelper] Database operation failed
org.hibernate.QueryTimeoutException: Unable to acquire JDBC Connection
	at org.hibernate.exception.internal.SQLExceptionTypeDelegate.convert(SQLExceptionTypeDelegate.java:66)
	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:87)
	at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.getPhysicalConnection(LogicalConnectionManagedImpl.java:109)
	at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.getConnectionForTransactionManagement(LogicalConnectionManagedImpl.java:227)
	at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.begin(LogicalConnectionManagedImpl.java:234)
	at org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl$TransactionDriverControlImpl.begin(JdbcResourceLocalTransactionCoordinatorImpl.java:214)
	at org.hibernate.engine.transaction.internal.TransactionImpl.begin(TransactionImpl.java:52)
	at org.hibernate.internal.SessionImpl.beginTransaction(SessionImpl.java:1525)
	at org.ow2.proactive.db.TransactionHelper.tryExecuteTransaction(TransactionHelper.java:120)
	at org.ow2.proactive.db.TransactionHelper.tryExecuteTransactionLoop(TransactionHelper.java:96)
	at org.ow2.proactive.db.TransactionHelper.executeReadOnlyTransaction(TransactionHelper.java:60)
	at org.ow2.proactive.scheduler.core.db.SchedulerDBManager.executeReadOnlyTransaction(SchedulerDBManager.java:1726)
	at org.ow2.proactive.scheduler.core.db.SchedulerDBManager.getJobsToRemove(SchedulerDBManager.java:756)
	at org.ow2.proactive.scheduler.core.SchedulingService$HousekeepingRunner.run(SchedulingService.java:1153)
	at it.sauronsoftware.cron4j.RunnableTask.execute(Unknown Source)
	at it.sauronsoftware.cron4j.TaskExecutor$Runner.run(Unknown Source)
	at java.lang.Thread.run(Thread.java:748)
Caused by: java.sql.SQLTimeoutException: Timeout after 60003ms of waiting for a connection.
	at com.zaxxer.hikari.pool.BaseHikariPool.getConnection(BaseHikariPool.java:233)
	at com.zaxxer.hikari.pool.BaseHikariPool.getConnection(BaseHikariPool.java:183)
	at com.zaxxer.hikari.HikariDataSource.getConnection(HikariDataSource.java:93)
	at org.hibernate.hikaricp.internal.HikariCPConnectionProvider.getConnection(HikariCPConnectionProvider.java:77)
	at org.hibernate.internal.AbstractSessionImpl$NonContextualJdbcConnectionAccess.obtainConnection(AbstractSessionImpl.java:386)
	at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.acquireConnectionIfNeeded(LogicalConnectionManagedImpl.java:84)
	... 15 more
[2018-07-31 02:16:31,057 8245da750] WARN       o.o.p.d.TransactionHelper] Database operation failed. Automatic retry in 32000 ms (attempt 5)
org.hibernate.QueryTimeoutException: Unable to acquire JDBC Connection
	at org.hibernate.exception.internal.SQLExceptionTypeDelegate.convert(SQLExceptionTypeDelegate.java:66)
	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:87)
	at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.getPhysicalConnection(LogicalConnectionManagedImpl.java:109)
	at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.getConnectionForTransactionManagement(LogicalConnectionManagedImpl.java:227)
	at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.begin(LogicalConnectionManagedImpl.java:234)
	at org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl$TransactionDriverControlImpl.begin(JdbcResourceLocalTransactionCoordinatorImpl.java:214)
	at org.hibernate.engine.transaction.internal.TransactionImpl.begin(TransactionImpl.java:52)
	at org.hibernate.internal.SessionImpl.beginTransaction(SessionImpl.java:1525)
	at org.ow2.proactive.db.TransactionHelper.tryExecuteTransaction(TransactionHelper.java:120)
	at org.ow2.proactive.db.TransactionHelper.tryExecuteTransactionLoop(TransactionHelper.java:96)
	at org.ow2.proactive.db.TransactionHelper.executeReadOnlyTransaction(TransactionHelper.java:60)
	at org.ow2.proactive.scheduler.core.db.SchedulerDBManager.executeReadOnlyTransaction(SchedulerDBManager.java:1726)
	at org.ow2.proactive.scheduler.core.db.SchedulerDBManager.getJobsToRemove(SchedulerDBManager.java:756)
	at org.ow2.proactive.scheduler.core.SchedulingService$HousekeepingRunner.run(SchedulingService.java:1153)
	at it.sauronsoftware.cron4j.RunnableTask.execute(Unknown Source)
	at it.sauronsoftware.cron4j.TaskExecutor$Runner.run(Unknown Source)
	at java.lang.Thread.run(Thread.java:748)
Caused by: java.sql.SQLTimeoutException: Timeout after 60003ms of waiting for a connection.
	at com.zaxxer.hikari.pool.BaseHikariPool.getConnection(BaseHikariPool.java:233)
	at com.zaxxer.hikari.pool.BaseHikariPool.getConnection(BaseHikariPool.java:183)
	at com.zaxxer.hikari.HikariDataSource.getConnection(HikariDataSource.java:93)
	at org.hibernate.hikaricp.internal.HikariCPConnectionProvider.getConnection(HikariCPConnectionProvider.java:77)
	at org.hibernate.internal.AbstractSessionImpl$NonContextualJdbcConnectionAccess.obtainConnection(AbstractSessionImpl.java:386)
	at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.acquireConnectionIfNeeded(LogicalConnectionManagedImpl.java:84)
	... 15 more
[2018-07-31 02:17:03,057 8245da750] WARN       o.o.p.d.TransactionHelper] Maximum number of transaction retries exceeded, giving up. Last exception is: 
org.hibernate.QueryTimeoutException: Unable to acquire JDBC Connection
	at org.hibernate.exception.internal.SQLExceptionTypeDelegate.convert(SQLExceptionTypeDelegate.java:66)
	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:87)
	at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.getPhysicalConnection(LogicalConnectionManagedImpl.java:109)
	at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.getConnectionForTransactionManagement(LogicalConnectionManagedImpl.java:227)
	at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.begin(LogicalConnectionManagedImpl.java:234)
	at org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl$TransactionDriverControlImpl.begin(JdbcResourceLocalTransactionCoordinatorImpl.java:214)
	at org.hibernate.engine.transaction.internal.TransactionImpl.begin(TransactionImpl.java:52)
	at org.hibernate.internal.SessionImpl.beginTransaction(SessionImpl.java:1525)
	at org.ow2.proactive.db.TransactionHelper.tryExecuteTransaction(TransactionHelper.java:120)
	at org.ow2.proactive.db.TransactionHelper.tryExecuteTransactionLoop(TransactionHelper.java:96)
	at org.ow2.proactive.db.TransactionHelper.executeReadOnlyTransaction(TransactionHelper.java:60)
	at org.ow2.proactive.scheduler.core.db.SchedulerDBManager.executeReadOnlyTransaction(SchedulerDBManager.java:1726)
	at org.ow2.proactive.scheduler.core.db.SchedulerDBManager.getJobsToRemove(SchedulerDBManager.java:756)
	at org.ow2.proactive.scheduler.core.SchedulingService$HousekeepingRunner.run(SchedulingService.java:1153)
	at it.sauronsoftware.cron4j.RunnableTask.execute(Unknown Source)
	at it.sauronsoftware.cron4j.TaskExecutor$Runner.run(Unknown Source)
	at java.lang.Thread.run(Thread.java:748)
Caused by: java.sql.SQLTimeoutException: Timeout after 60003ms of waiting for a connection.
	at com.zaxxer.hikari.pool.BaseHikariPool.getConnection(BaseHikariPool.java:233)
	at com.zaxxer.hikari.pool.BaseHikariPool.getConnection(BaseHikariPool.java:183)
	at com.zaxxer.hikari.HikariDataSource.getConnection(HikariDataSource.java:93)
	at org.hibernate.hikaricp.internal.HikariCPConnectionProvider.getConnection(HikariCPConnectionProvider.java:77)
	at org.hibernate.internal.AbstractSessionImpl$NonContextualJdbcConnectionAccess.obtainConnection(AbstractSessionImpl.java:386)
	at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.acquireConnectionIfNeeded(LogicalConnectionManagedImpl.java:84)
	... 15 more
[2018-07-31 02:17:03,057 8245da750] ERROR    o.o.p.s.c.SchedulingService] Error performing HOUSEKEEPING of jobs
org.ow2.proactive.db.DatabaseManagerException: org.hibernate.QueryTimeoutException: Unable to acquire JDBC Connection
	at org.ow2.proactive.db.TransactionHelper.tryExecuteTransactionLoop(TransactionHelper.java:111)
	at org.ow2.proactive.db.TransactionHelper.executeReadOnlyTransaction(TransactionHelper.java:60)
	at org.ow2.proactive.scheduler.core.db.SchedulerDBManager.executeReadOnlyTransaction(SchedulerDBManager.java:1726)
	at org.ow2.proactive.scheduler.core.db.SchedulerDBManager.getJobsToRemove(SchedulerDBManager.java:756)
	at org.ow2.proactive.scheduler.core.SchedulingService$HousekeepingRunner.run(SchedulingService.java:1153)
	at it.sauronsoftware.cron4j.RunnableTask.execute(Unknown Source)
	at it.sauronsoftware.cron4j.TaskExecutor$Runner.run(Unknown Source)
	at java.lang.Thread.run(Thread.java:748)
Caused by: org.hibernate.QueryTimeoutException: Unable to acquire JDBC Connection
	at org.hibernate.exception.internal.SQLExceptionTypeDelegate.convert(SQLExceptionTypeDelegate.java:66)
	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:87)
	at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.getPhysicalConnection(LogicalConnectionManagedImpl.java:109)
	at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.getConnectionForTransactionManagement(LogicalConnectionManagedImpl.java:227)
	at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.begin(LogicalConnectionManagedImpl.java:234)
	at org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl$TransactionDriverControlImpl.begin(JdbcResourceLocalTransactionCoordinatorImpl.java:214)
	at org.hibernate.engine.transaction.internal.TransactionImpl.begin(TransactionImpl.java:52)
	at org.hibernate.internal.SessionImpl.beginTransaction(SessionImpl.java:1525)
	at org.ow2.proactive.db.TransactionHelper.tryExecuteTransaction(TransactionHelper.java:120)
	at org.ow2.proactive.db.TransactionHelper.tryExecuteTransactionLoop(TransactionHelper.java:96)
	... 7 more
Caused by: java.sql.SQLTimeoutException: Timeout after 60003ms of waiting for a connection.
	at com.zaxxer.hikari.pool.BaseHikariPool.getConnection(BaseHikariPool.java:233)
	at com.zaxxer.hikari.pool.BaseHikariPool.getConnection(BaseHikariPool.java:183)
	at com.zaxxer.hikari.HikariDataSource.getConnection(HikariDataSource.java:93)
	at org.hibernate.hikaricp.internal.HikariCPConnectionProvider.getConnection(HikariCPConnectionProvider.java:77)
	at org.hibernate.internal.AbstractSessionImpl$NonContextualJdbcConnectionAccess.obtainConnection(AbstractSessionImpl.java:386)
	at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.acquireConnectionIfNeeded(LogicalConnectionManagedImpl.java:84)
	... 15 more

This goes on forever

@fviale
Copy link
Member Author

fviale commented Aug 1, 2018

Thread dump:

thread_dump_database_issue.log.txt

@paraita
Copy link
Contributor

paraita commented Aug 13, 2018

I managed to reproduce the issue. By submitting a few hundred jobs simultaneously (2 sessions at the same time), the problem would come up after ~20 minutes:

export SESSIONID=`curl --request POST \
  --url http://localhost:8080/rest/scheduler/login \
  --header 'content-type: application/x-www-form-urlencoded' \
  --data 'username=$PA_USERNAME&password=$PA_PASSWORD'`
for i in `seq 1 350`; do curl --header "sessionid:$SESSIONID" \
      --form "file=@/home/paraita/job.xml;type=application/xml" \
      http://localhost:8080/rest/scheduler/submit; echo""; sleep 1; done

It is required to log into the scheduler web portal and use it to display the pending jobs or the problem wouldn't happen.
I pinpoint the root cause in the scheduling-api repo. There seem to be a problem in the input stream because each of the lambda call is done in a sperate thread (we're using a parallel stream) so 1) we exhaut all Hibernate Connections and 2) the assumption that all items in the input streams being unique is false (hence the concurrency error).

One quick fix would be to remove the parallel stream and use a regular one. (I didn't notice any sensible slow down in doing so).
It would be interesting to find why we had the 2) assumption.

@paraita
Copy link
Contributor

paraita commented Aug 16, 2018 •
edited
Loading

I found the root cause. The Scheduler is relying on Hibernate for the persistence (with its own context). The scheduling-api is also relying on Hibernate but uses another Hibernate context. The probability to have one job accessed at the same time in both contexts is really small, but tends to increase depending on 2 factors:

  • The lambda accessing the stream of jobs when there's a long list of jobs, and the polling frequency of the RM portal towards this lambda
  • The scheduling loop locking jobs under heavy loads

From the Hibernate doc, it is possible to have multiple EntityManagers but they shouldn't be mapping the same entities, the common practice is to separate those contexts into different units.

I believe using a regular stream inside the lambda will mitigate a lot the exception.
Having a smaller page size combined with a lower polling frequency will also mitigate a lot the probability of triggering the exception.

@paraita paraita mentioned this issue Aug 16, 2018
Merged
@fviale
Copy link
Member Author

fviale commented Mar 5, 2019

Reduced the severity as it did not reappear.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
severity:minor type:bug
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@paraita @fviale