Caused by: java.sql.SQLException: Connection not established

Hi Team,

A user reported a production problem on CN forum: https://forum.cuba-platform.cn/t/topic/2078

Basically, the issue happens after the server started up for half day or one day. They are using CUBA 7.1.1. Deployed separately for frontend blocks and backend blocks, each has 2 servers, using Wildfly as container, apache for LB.

Could you please help check what is the problem?

Below is part of the log, full log can be found in the link of original post in CN forum:

(Incoming-1,cubaCluster,hlw-ajyth168-server-14363) 2022-04-21 16:33:21.835 DEBUG [Incoming-1,cubaCluster,hlw-ajyth168-server-14363] com.haulmont.cuba.core.app.ClusterManager - Received message: class com.haulmont.cuba.security.app.UserSessions$UserSessionInfo: 930bc3aa-9740-653b-1159-b9f95149a315 [sghgscssbd], since: Thu Apr 21 16:24:24 CST 2022, lastUsed: Thu Apr 21 16:33:24 CST 2022 (56472 bytes)
2022-04-21 16:33:22,141 INFO  [stdout] (default task-28) 2022-04-21 16:33:22.141 DEBUG [default task-28/ajyth-core/sgwcxhdl] com.haulmont.cuba.core.app.RdbmsStore - load: metaClass=constructionsaftymgt_Project, id=null, view=impc.aj.constructionsaftymgt.entity.Project/project-view
2022-04-21 16:33:22,143 INFO  [stdout] (ClusterManagerMessageSender-16) 2022-04-21 16:33:22.143 DEBUG [ClusterManagerMessageSender-16] com.haulmont.cuba.core.app.ClusterManager - Sending message: class com.haulmont.cuba.security.app.UserSessions$UserSessionInfo: f3af44ce-10b6-b246-d3b4-94b41264143f [sgwcxhdl], since: Thu Apr 21 16:29:47 CST 2022, lastUsed: Thu Apr 21 16:33:22 CST 2022 (58288 bytes)
2022-04-21 16:33:22,755 INFO  [stdout] (cuba_core_scheduler-8) 2022-04-21 16:33:22.755 ERROR [cuba_core_scheduler-8] org.springframework.scheduling.support.TaskUtils$LoggingErrorHandler - Unexpected error occurred in scheduled task.
2022-04-21 16:33:22,755 INFO  [stdout] (cuba_core_scheduler-8) org.eclipse.persistence.exceptions.DatabaseException: 
2022-04-21 16:33:22,755 INFO  [stdout] (cuba_core_scheduler-8) Internal Exception: java.sql.SQLException: Connection not established
2022-04-21 16:33:22,755 INFO  [stdout] (cuba_core_scheduler-8) Error Code: -79730
2022-04-21 16:33:22,755 INFO  [stdout] (cuba_core_scheduler-8) 	at org.eclipse.persistence.exceptions.DatabaseException.sqlException(DatabaseException.java:342) ~[org.eclipse.persistence.core-2.7.3-6-cuba.jar:na]
2022-04-21 16:33:22,755 INFO  [stdout] (cuba_core_scheduler-8) 	at org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.processExceptionForCommError(DatabaseAccessor.java:1694) ~[org.eclipse.persistence.core-2.7.3-6-cuba.jar:na]
2022-04-21 16:33:22,755 INFO  [stdout] (cuba_core_scheduler-8) 	at org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.basicRollbackTransaction(DatabaseAccessor.java:1792) ~[org.eclipse.persistence.core-2.7.3-6-cuba.jar:na]
2022-04-21 16:33:22,755 INFO  [stdout] (cuba_core_scheduler-8) 	at org.eclipse.persistence.internal.databaseaccess.DatasourceAccessor.rollbackTransaction(DatasourceAccessor.java:690) ~[org.eclipse.persistence.core-2.7.3-6-cuba.jar:na]
2022-04-21 16:33:22,755 INFO  [stdout] (cuba_core_scheduler-8) 	at org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.rollbackTransaction(DatabaseAccessor.java:1776) ~[org.eclipse.persistence.core-2.7.3-6-cuba.jar:na]
2022-04-21 16:33:22,755 INFO  [stdout] (cuba_core_scheduler-8) 	at org.eclipse.persistence.internal.sessions.AbstractSession.basicRollbackTransaction(AbstractSession.java:828) ~[org.eclipse.persistence.core-2.7.3-6-cuba.jar:na]
2022-04-21 16:33:22,755 INFO  [stdout] (cuba_core_scheduler-8) 	at org.eclipse.persistence.sessions.server.ClientSession.basicRollbackTransaction(ClientSession.java:209) ~[org.eclipse.persistence.core-2.7.3-6-cuba.jar:na]
2022-04-21 16:33:22,755 INFO  [stdout] (cuba_core_scheduler-8) 	at org.eclipse.persistence.internal.sessions.AbstractSession.rollbackTransaction(AbstractSession.java:3965) ~[org.eclipse.persistence.core-2.7.3-6-cuba.jar:na]
2022-04-21 16:33:22,755 INFO  [stdout] (cuba_core_scheduler-8) 	at org.eclipse.persistence.internal.sessions.UnitOfWorkImpl.rollbackTransaction(UnitOfWorkImpl.java:4815) ~[org.eclipse.persistence.core-2.7.3-6-cuba.jar:na]
2022-04-21 16:33:22,755 INFO  [stdout] (cuba_core_scheduler-8) 	at org.eclipse.persistence.internal.sessions.RepeatableWriteUnitOfWork.rollbackTransaction(RepeatableWriteUnitOfWork.java:534) ~[org.eclipse.persistence.core-2.7.3-6-cuba.jar:na]
2022-04-21 16:33:22,755 INFO  [stdout] (cuba_core_scheduler-8) 	at org.eclipse.persistence.internal.sessions.UnitOfWorkImpl.release(UnitOfWorkImpl.java:4615) ~[org.eclipse.persistence.core-2.7.3-6-cuba.jar:na]
2022-04-21 16:33:22,755 INFO  [stdout] (cuba_core_scheduler-8) 	at org.eclipse.persistence.internal.jpa.transaction.EntityTransactionImpl.rollback(EntityTransactionImpl.java:189) ~[org.eclipse.persistence.jpa-2.7.3-6-cuba.jar:na]
2022-04-21 16:33:22,755 INFO  [stdout] (cuba_core_scheduler-8) 	at org.springframework.orm.jpa.JpaTransactionManager.doRollback(JpaTransactionManager.java:559) ~[spring-orm-5.1.6.RELEASE.jar:5.1.6.RELEASE]
2022-04-21 16:33:22,755 INFO  [stdout] (cuba_core_scheduler-8) 	at org.springframework.transaction.support.AbstractPlatformTransactionManager.processRollback(AbstractPlatformTransactionManager.java:838) ~[spring-tx-5.1.6.RELEASE.jar:5.1.6.RELEASE]
2022-04-21 16:33:22,755 INFO  [stdout] (cuba_core_scheduler-8) 	at org.springframework.transaction.support.AbstractPlatformTransactionManager.rollback(AbstractPlatformTransactionManager.java:812) ~[spring-tx-5.1.6.RELEASE.jar:5.1.6.RELEASE]
2022-04-21 16:33:22,755 INFO  [stdout] (cuba_core_scheduler-8) 	at com.haulmont.cuba.core.sys.TransactionImpl.end(TransactionImpl.java:125) ~[cuba-core-7.1.1.jar:7.1.1]
2022-04-21 16:33:22,755 INFO  [stdout] (cuba_core_scheduler-8) 	at com.haulmont.cuba.core.app.scheduling.DbBasedCoordinator.begin(DbBasedCoordinator.java:76) ~[cuba-core-7.1.1.jar:7.1.1]
2022-04-21 16:33:22,755 INFO  [stdout] (cuba_core_scheduler-8) 	at com.haulmont.cuba.core.app.scheduling.Scheduling.processScheduledTasks(Scheduling.java:113) ~[cuba-core-7.1.1.jar:7.1.1]
2022-04-21 16:33:22,755 INFO  [stdout] (cuba_core_scheduler-8) 	at com.haulmont.cuba.core.app.scheduling.Scheduling.processScheduledTasks(Scheduling.java:95) ~[cuba-core-7.1.1.jar:7.1.1]
2022-04-21 16:33:22,755 INFO  [stdout] (cuba_core_scheduler-8) 	at sun.reflect.GeneratedMethodAccessor194.invoke(Unknown Source) ~[na:na]
2022-04-21 16:33:22,755 INFO  [stdout] (cuba_core_scheduler-8) 	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.8.0_161]
2022-04-21 16:33:22,755 INFO  [stdout] (cuba_core_scheduler-8) 	at java.lang.reflect.Method.invoke(Method.java:498) ~[na:1.8.0_161]
2022-04-21 16:33:22,755 INFO  [stdout] (cuba_core_scheduler-8) 	at org.springframework.scheduling.support.ScheduledMethodRunnable.run(ScheduledMethodRunnable.java:84) ~[spring-context-5.1.6.RELEASE.jar:5.1.6.RELEASE]
2022-04-21 16:33:22,755 INFO  [stdout] (cuba_core_scheduler-8) 	at org.springframework.scheduling.support.DelegatingErrorHandlingRunnable.run(DelegatingErrorHandlingRunnable.java:54) ~[spring-context-5.1.6.RELEASE.jar:5.1.6.RELEASE]
2022-04-21 16:33:22,755 INFO  [stdout] (cuba_core_scheduler-8) 	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [na:1.8.0_161]
2022-04-21 16:33:22,755 INFO  [stdout] (cuba_core_scheduler-8) 	at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308) [na:1.8.0_161]
2022-04-21 16:33:22,755 INFO  [stdout] (cuba_core_scheduler-8) 	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180) [na:1.8.0_161]
2022-04-21 16:33:22,756 INFO  [stdout] (cuba_core_scheduler-8) 	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294) [na:1.8.0_161]
2022-04-21 16:33:22,756 INFO  [stdout] (cuba_core_scheduler-8) 	at com.haulmont.cuba.core.sys.CubaThreadPoolTaskScheduler$TaskDecorator.run(CubaThreadPoolTaskScheduler.java:121) [cuba-global-7.1.1.jar:7.1.1]
2022-04-21 16:33:22,756 INFO  [stdout] (cuba_core_scheduler-8) 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [na:1.8.0_161]
2022-04-21 16:33:22,756 INFO  [stdout] (cuba_core_scheduler-8) 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [na:1.8.0_161]
2022-04-21 16:33:22,756 INFO  [stdout] (cuba_core_scheduler-8) 	at java.lang.Thread.run(Thread.java:748) [na:1.8.0_161]
2022-04-21 16:33:22,756 INFO  [stdout] (cuba_core_scheduler-8) Caused by: java.sql.SQLException: Connection not established
2022-04-21 16:33:22,756 INFO  [stdout] (cuba_core_scheduler-8) 	at com.informix.util.IfxErrMsg.getSQLException(IfxErrMsg.java:408) ~[na:na]
2022-04-21 16:33:22,756 INFO  [stdout] (cuba_core_scheduler-8) 	at com.informix.jdbc.IfxSqliConnect.rollback(IfxSqliConnect.java:2140) ~[na:na]
2022-04-21 16:33:22,756 INFO  [stdout] (cuba_core_scheduler-8) 	at org.jboss.jca.adapters.jdbc.BaseWrapperManagedConnection.jdbcRollback(BaseWrapperManagedConnection.java:1106) ~[na:na]
2022-04-21 16:33:22,756 INFO  [stdout] (cuba_core_scheduler-8) 	at org.jboss.jca.adapters.jdbc.WrappedConnection.rollback(WrappedConnection.java:924) ~[na:na]
2022-04-21 16:33:22,756 INFO  [stdout] (cuba_core_scheduler-8) 	at com.haulmont.cuba.core.sys.jdbc.ProxyConnection.rollback(ProxyConnection.java:68) ~[cuba-core-7.1.1.jar:7.1.1]
2022-04-21 16:33:22,756 INFO  [stdout] (cuba_core_scheduler-8) 	at org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.basicRollbackTransaction(DatabaseAccessor.java:1786) ~[org.eclipse.persistence.core-2.7.3-6-cuba.jar:na]
2022-04-21 16:33:22,756 INFO  [stdout] (cuba_core_scheduler-8) 	... 29 common frames omitted

Hi Bryan,

Quick googling for error -79730 on Informix gave me this page:

It has a recommendation (whatever it means):

Upgrade to the next fixpack - 12.10.xC9

Not sure it is related to CUBA.

Regards,
Konstantin

Hi Konstantin,

Thank you! I will forward the information to the customer to check.

Today, I tried to upgrade the latest database driver, but the problem still exists. From the log, the first time this problem occurred was after a scheduled task was executed. How can I determine which task the scheduled task of this Cuba is now? I suspect there is a bug in this scheduled task. Please help us. We have been scolded by users for several days 20220427外网日志.rar (1.6 MB) Attachments are completion logs, 165 and 166 are front-end blocks, 167 and 168 are back-end blocks, and errors appear on 167

Hi Konstantin,
Is there any way we can find the task information the cuba_core_scheduler-8 is executing that throws the exception?

The customer is still having this problem.

Thanks!

You can get a detailed information on execution of scheduled tasks if you set the TRACE level for the com.haulmont.cuba.core.app.scheduling logging category. But be aware that it logs a lot of information, so turn it on only for a limited period of time.

1 Like