I am running into a weird problem where Workflow instances are randomly failing midstream. Random jobs are not being invoked and I am not able to narrow down the root cause. All the appropriate variables are available and in most of the cases where I am experiencing this failure, certain tasks/jobs are not being triggered at all.
This is the list of jobs for this instance:
ServiceTask_15a9gpd | 2251799815919545 | 2251799815919546 | payment-service | 3 | default | completed | 2019-09-20T02:29:38.606Z | |
---|---|---|---|---|---|---|---|---|
ServiceTask_190tzzn | 2251799815919636 | 2251799815919637 | fetching-items-service | 0 | default | failed | 2019-09-20T02:29:38.685Z |
Or
ServiceTask_15a9gpd | 2251799815895211 | 2251799815895217 | payment-service | 3 | default | completed | 2019-09-20T02:23:37.294Z | |
---|---|---|---|---|---|---|---|---|
ServiceTask_190tzzn | 2251799815895313 | 2251799815895318 | fetching-items-service | 3 | default | completed | 2019-09-20T02:23:39.416Z | |
ServiceTask_1tsa632 | 2251799815895410 | 2251799815895412 | email-service | 3 | default | completed | 2019-09-20T02:23:41.620Z | |
ServiceTask_1taybaf | 2251799815895411 | 2251799815895413 | shipping-service | 0 | default | failed | 2019-09-20T02:23:39.611Z |
As you can see, it is fairly random which jobs are failing. Any advice on what I should be looking for?
I restarted the docker containers, as I had hundreds of these instances stuck and to see what a fresh install would look like. When I run my workflow again, I am getting random failures. Appears to be with my workflow but cannot pinpoint the problem. Here is a sample of the last 5 instances:
2251799813696775 | Active | 2019-09-20T03:17:59.341Z |
---|---|---|
2251799813710800 | Active | 2019-09-20T03:22:00.468Z |
2251799813724581 | Active | 2019-09-20T03:25:57.262Z |
2251799813747871 | Completed | 2019-09-20T03:33:35.492Z |
2251799813750090 | Completed | 2019-09-20T03:34:10.184Z |
When I get these failures, Zeebe monitor also reports these:
zeebe_monitor | java.lang.RuntimeException: Failed to deserialize Protobuf message.
zeebe_monitor | at io.zeebe.hazelcast.connect.java.ZeebeHazelcastMessageListener.onMessage(ZeebeHazelcastMessageListener.java:31) ~[zeebe-hazelcast-connector-0.5.0.jar!/:0.5.0]
zeebe_monitor | at com.hazelcast.client.proxy.ClientTopicProxy$TopicItemHandler.handleTopicEventV10(ClientTopicProxy.java:89) ~[hazelcast-client-3.11.1.jar!/:3.11.1]
zeebe_monitor | at com.hazelcast.client.impl.protocol.codec.TopicAddMessageListenerCodec$AbstractEventHandler.handle(TopicAddMessageListenerCodec.java:147) ~[hazelcast-3.11.1.jar!/:3.11.1]
zeebe_monitor | at com.hazelcast.client.proxy.ClientTopicProxy$TopicItemHandler.handle(ClientTopicProxy.java:77) ~[hazelcast-client-3.11.1.jar!/:3.11.1]
zeebe_monitor | at com.hazelcast.client.spi.impl.listener.AbstractClientListenerService$ClientEventProcessor.run(AbstractClientListenerService.java:368) ~[hazelcast-client-3.11.1.jar!/:3.11.1]
zeebe_monitor | at com.hazelcast.util.executor.StripedExecutor$Worker.process(StripedExecutor.java:226) [hazelcast-3.11.1.jar!/:3.11.1]
zeebe_monitor | at com.hazelcast.util.executor.StripedExecutor$Worker.run(StripedExecutor.java:209) [hazelcast-3.11.1.jar!/:3.11.1]
zeebe_monitor | Caused by: org.springframework.dao.DataIntegrityViolationException: could not execute statement; SQL [n/a]; nested exception is org.hibernate.exception.DataException: could not execute statement
zeebe_monitor | at org.springframework.orm.jpa.vendor.HibernateJpaDialect.convertHibernateAccessException(HibernateJpaDialect.java:300) ~[spring-orm-5.1.4.RELEASE.jar!/:5.1.4.RELEASE]
zeebe_monitor | at org.springframework.orm.jpa.vendor.HibernateJpaDialect.translateExceptionIfPossible(HibernateJpaDialect.java:253) ~[spring-orm-5.1.4.RELEASE.jar!/:5.1.4.RELEASE]
zeebe_monitor | at org.springframework.orm.jpa.JpaTransactionManager.doCommit(JpaTransactionManager.java:536) ~[spring-orm-5.1.4.RELEASE.jar!/:5.1.4.RELEASE]
zeebe_monitor | at org.springframework.transaction.support.AbstractPlatformTransactionManager.processCommit(AbstractPlatformTransactionManager.java:746) ~[spring-tx-5.1.4.RELEASE.jar!/:5.1.4.RELEASE]
zeebe_monitor | at org.springframework.transaction.support.AbstractPlatformTransactionManager.commit(AbstractPlatformTransactionManager.java:714) ~[spring-tx-5.1.4.RELEASE.jar!/:5.1.4.RELEASE]
zeebe_monitor | at org.springframework.transaction.interceptor.TransactionAspectSupport.commitTransactionAfterReturning(TransactionAspectSupport.java:533) ~[spring-tx-5.1.4.RELEASE.jar!/:5.1.4.RELEASE]
zeebe_monitor | at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:304) ~[spring-tx-5.1.4.RELEASE.jar!/:5.1.4.RELEASE]
zeebe_monitor | at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:98) ~[spring-tx-5.1.4.RELEASE.jar!/:5.1.4.RELEASE]
zeebe_monitor | at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186) ~[spring-aop-5.1.4.RELEASE.jar!/:5.1.4.RELEASE]
zeebe_monitor | at org.springframework.dao.support.PersistenceExceptionTranslationInterceptor.invoke(PersistenceExceptionTranslationInterceptor.java:139) ~[spring-tx-5.1.4.RELEASE.jar!/:5.1.4.RELEASE]
zeebe_monitor | at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186) ~[spring-aop-5.1.4.RELEASE.jar!/:5.1.4.RELEASE]
zeebe_monitor | at org.springframework.data.jpa.repository.support.CrudMethodMetadataPostProcessor$CrudMethodMetadataPopulatingMethodInterceptor.invoke(CrudMethodMetadataPostProcessor.java:135) ~[spring-data-jpa-2.1.4.RELEASE.jar!/:2.1.4.RELEASE]
zeebe_monitor | at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186) ~[spring-aop-5.1.4.RELEASE.jar!/:5.1.4.RELEASE]
zeebe_monitor | at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:93) ~[spring-aop-5.1.4.RELEASE.jar!/:5.1.4.RELEASE]
zeebe_monitor | at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186) ~[spring-aop-5.1.4.RELEASE.jar!/:5.1.4.RELEASE]
zeebe_monitor | at org.springframework.data.repository.core.support.SurroundingTransactionDetectorMethodInterceptor.invoke(SurroundingTransactionDetectorMethodInterceptor.java:61) ~[spring-data-commons-2.1.4.RELEASE.jar!/:2.1.4.RELEASE]
zeebe_monitor | at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186) ~[spring-aop-5.1.4.RELEASE.jar!/:5.1.4.RELEASE]
zeebe_monitor | at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:212) ~[spring-aop-5.1.4.RELEASE.jar!/:5.1.4.RELEASE]
zeebe_monitor | at com.sun.proxy.$Proxy97.save(Unknown Source) ~[na:na]
zeebe_monitor | at io.zeebe.monitor.zeebe.ZeebeImportService.importIncident(ZeebeImportService.java:207) ~[classes!/:0.15.0]
zeebe_monitor | at io.zeebe.hazelcast.connect.java.ZeebeHazelcastMessageListener.onMessage(ZeebeHazelcastMessageListener.java:29) ~[zeebe-hazelcast-connector-0.5.0.jar!/:0.5.0]
zeebe_monitor | … 6 common frames omitted
zeebe_monitor | Caused by: org.hibernate.exception.DataException: could not execute statement
zeebe_monitor | at org.hibernate.exception.internal.SQLStateConversionDelegate.convert(SQLStateConversionDelegate.java:118) ~[hibernate-core-5.3.7.Final.jar!/:5.3.7.Final]
zeebe_monitor | at org.hibernate.exception.internal.StandardSQLExceptionConverter.convert(StandardSQLExceptionConverter.java:42) ~[hibernate-core-5.3.7.Final.jar!/:5.3.7.Final]
zeebe_monitor | at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:113) ~[hibernate-core-5.3.7.Final.jar!/:5.3.7.Final]
zeebe_monitor | at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:99) ~[hibernate-core-5.3.7.Final.jar!/:5.3.7.Final]
zeebe_monitor | at org.hibernate.engine.jdbc.internal.ResultSetReturnImpl.executeUpdate(ResultSetReturnImpl.java:178) ~[hibernate-core-5.3.7.Final.jar!/:5.3.7.Final]
zeebe_monitor | at org.hibernate.persister.entity.AbstractEntityPersister.insert(AbstractEntityPersister.java:3171) ~[hibernate-core-5.3.7.Final.jar!/:5.3.7.Final]
zeebe_monitor | at org.hibernate.persister.entity.AbstractEntityPersister.insert(AbstractEntityPersister.java:3686) ~[hibernate-core-5.3.7.Final.jar!/:5.3.7.Final]
zeebe_monitor | at org.hibernate.action.internal.EntityInsertAction.execute(EntityInsertAction.java:90) ~[hibernate-core-5.3.7.Final.jar!/:5.3.7.Final]
zeebe_monitor | at org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:604) ~[hibernate-core-5.3.7.Final.jar!/:5.3.7.Final]
zeebe_monitor | at org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:478) ~[hibernate-core-5.3.7.Final.jar!/:5.3.7.Final]
zeebe_monitor | at org.hibernate.event.internal.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:356) ~[hibernate-core-5.3.7.Final.jar!/:5.3.7.Final]
zeebe_monitor | at org.hibernate.event.internal.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:39) ~[hibernate-core-5.3.7.Final.jar!/:5.3.7.Final]
zeebe_monitor | at org.hibernate.internal.SessionImpl.doFlush(SessionImpl.java:1454) ~[hibernate-core-5.3.7.Final.jar!/:5.3.7.Final]
zeebe_monitor | at org.hibernate.internal.SessionImpl.managedFlush(SessionImpl.java:511) ~[hibernate-core-5.3.7.Final.jar!/:5.3.7.Final]
zeebe_monitor | at org.hibernate.internal.SessionImpl.flushBeforeTransactionCompletion(SessionImpl.java:3283) ~[hibernate-core-5.3.7.Final.jar!/:5.3.7.Final]
zeebe_monitor | at org.hibernate.internal.SessionImpl.beforeTransactionCompletion(SessionImpl.java:2479) ~[hibernate-core-5.3.7.Final.jar!/:5.3.7.Final]
zeebe_monitor | at org.hibernate.engine.jdbc.internal.JdbcCoordinatorImpl.beforeTransactionCompletion(JdbcCoordinatorImpl.java:473) ~[hibernate-core-5.3.7.Final.jar!/:5.3.7.Final]
zeebe_monitor | at org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl.beforeCompletionCallback(JdbcResourceLocalTransactionCoordinatorImpl.java:178) ~[hibernate-core-5.3.7.Final.jar!/:5.3.7.Final]
zeebe_monitor | at org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl.access$300(JdbcResourceLocalTransactionCoordinatorImpl.java:39) ~[hibernate-core-5.3.7.Final.jar!/:5.3.7.Final]
zeebe_monitor | at org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl$TransactionDriverControlImpl.commit(JdbcResourceLocalTransactionCoordinatorImpl.java:271) ~[hibernate-core-5.3.7.Final.jar!/:5.3.7.Final]
zeebe_monitor | at org.hibernate.engine.transaction.internal.TransactionImpl.commit(TransactionImpl.java:98) ~[hibernate-core-5.3.7.Final.jar!/:5.3.7.Final]
zeebe_monitor | at org.springframework.orm.jpa.JpaTransactionManager.doCommit(JpaTransactionManager.java:532) ~[spring-orm-5.1.4.RELEASE.jar!/:5.1.4.RELEASE]
zeebe_monitor | … 24 common frames omitted
zeebe_monitor | Caused by: org.h2.jdbc.JdbcSQLException: Value too long for column “ERROR_MSG_ VARCHAR(255)”: “STRINGDECODE('io.zeebe.client.api.command.InternalClientException: Failed to deserialize json ‘’{”“item”":"“headphones”","“price… (3243)”; SQL statement:
zeebe_monitor | insert into incident (bpmn_process_id_, created_, element_instance_key_, error_msg_, error_type_, job_key_, resolved_, workflow_instance_key_, workflow_key_, key_) values (?, ?, ?, ?, ?, ?, ?, ?, ?, ?) [22001-197]
zeebe_monitor | at org.h2.engine.SessionRemote.done(SessionRemote.java:623) ~[h2-1.4.197.jar!/:na]
zeebe_monitor | at org.h2.command.CommandRemote.executeUpdate(CommandRemote.java:237) ~[h2-1.4.197.jar!/:na]
zeebe_monitor | at org.h2.jdbc.JdbcPreparedStatement.executeUpdateInternal(JdbcPreparedStatement.java:199) ~[h2-1.4.197.jar!/:na]
zeebe_monitor | at org.h2.jdbc.JdbcPreparedStatement.executeUpdate(JdbcPreparedStatement.java:153) ~[h2-1.4.197.jar!/:na]
zeebe_monitor | at com.zaxxer.hikari.pool.ProxyPreparedStatement.executeUpdate(ProxyPreparedStatement.java:61) ~[HikariCP-3.2.0.jar!/:na]
zeebe_monitor | at com.zaxxer.hikari.pool.HikariProxyPreparedStatement.executeUpdate(HikariProxyPreparedStatement.java) ~[HikariCP-3.2.0.jar!/:na]
zeebe_monitor | at org.hibernate.engine.jdbc.internal.ResultSetReturnImpl.executeUpdate(ResultSetReturnImpl.java:175) ~[hibernate-core-5.3.7.Final.jar!/:5.3.7.Final]
zeebe_monitor | … 41 common frames omitted