Command rejected with code 'COMPLETE'

Hi Team,

I am getting one exception in broker and in spring client occasionally. but I don’t know why it’s coming.

zeebe : 0.21.1
spring zeebe client : 0.7.1

client logs:


io.zeebe.client.api.command.ClientStatusException: Command rejected with code 'COMPLETE': Expected to complete job with key '2251799818233058', but no such job was found
        at io.zeebe.client.impl.ZeebeClientFutureImpl.transformExecutionException(ZeebeClientFutureImpl.java:93)
        at io.zeebe.client.impl.ZeebeClientFutureImpl.join(ZeebeClientFutureImpl.java:50)
        at com.xxxx.business.workflow.component.handler.service.impl.ComponentWorkflowHandlerServiceImpl.sendVendorRequest(ComponentWorkflowHandlerServiceImpl.java:617)
        at com.xxxx.business.workflow.component.handler.service.impl.ComponentWorkflowHandlerServiceImpl$$FastClassBySpringCGLIB$$f9512a9d.invoke(<generated>)
        at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:218)
        at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:750)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163)
        at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:295)
        at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:98)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
        at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:689)
        at com.xxxx.business.workflow.component.handler.service.impl.ComponentWorkflowHandlerServiceImpl$$EnhancerBySpringCGLIB$$aa38d5dc.sendVendorRequest(<generated>)
        at com.xxxx.business.workflow.component.handler.config.ZeebeConfig.sendVendorRequest(ZeebeConfig.java:93)
        at jdk.internal.reflect.GeneratedMethodAccessor307.invoke(Unknown Source)
        at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.base/java.lang.reflect.Method.invoke(Method.java:566)
        at io.zeebe.spring.client.bean.MethodInfo.invoke(MethodInfo.java:31)
        at io.zeebe.spring.client.config.processor.ZeebeWorkerPostProcessor.lambda$null$1(ZeebeWorkerPostProcessor.java:49)
        at io.zeebe.client.impl.worker.JobRunnableFactory.executeJob(JobRunnableFactory.java:44)
        at io.zeebe.client.impl.worker.JobRunnableFactory.lambda$create$0(JobRunnableFactory.java:39)
        at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
        at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
        at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304)
        at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
        at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
        at java.base/java.lang.Thread.run(Thread.java:834)
Caused by: java.util.concurrent.ExecutionException: io.grpc.StatusRuntimeException: NOT_FOUND: Command rejected with code 'COMPLETE': Expected to complete job with key '2251799818233058', but no such job was found
        at java.base/java.util.concurrent.CompletableFuture.reportGet(CompletableFuture.java:395)
        at java.base/java.util.concurrent.CompletableFuture.get(CompletableFuture.java:1999)
        at io.zeebe.client.impl.ZeebeClientFutureImpl.join(ZeebeClientFutureImpl.java:48)
        ... 24 common frames omitted
Caused by: io.grpc.StatusRuntimeException: NOT_FOUND: Command rejected with code 'COMPLETE': Expected to complete job with key '2251799818233058', but no such job was found
        at io.grpc.Status.asRuntimeException(Status.java:533)
        at io.grpc.stub.ClientCalls$StreamObserverToCallListenerAdapter.onClose(ClientCalls.java:442)
        at io.grpc.PartialForwardingClientCallListener.onClose(PartialForwardingClientCallListener.java:39)
        at io.grpc.ForwardingClientCallListener.onClose(ForwardingClientCallListener.java:23)
        at io.grpc.ForwardingClientCallListener$SimpleForwardingClientCallListener.onClose(ForwardingClientCallListener.java:40)
        at io.grpc.internal.CensusStatsModule$StatsClientInterceptor$1$1.onClose(CensusStatsModule.java:700)
        at io.grpc.PartialForwardingClientCallListener.onClose(PartialForwardingClientCallListener.java:39)
        at io.grpc.ForwardingClientCallListener.onClose(ForwardingClientCallListener.java:23)
        at io.grpc.ForwardingClientCallListener$SimpleForwardingClientCallListener.onClose(ForwardingClientCallListener.java:40)
        at io.grpc.internal.CensusTracingModule$TracingClientInterceptor$1$1.onClose(CensusTracingModule.java:399)
        at io.grpc.internal.ClientCallImpl.closeObserver(ClientCallImpl.java:510)
        at io.grpc.internal.ClientCallImpl.access$300(ClientCallImpl.java:66)
        at io.grpc.internal.ClientCallImpl$ClientStreamListenerImpl.close(ClientCallImpl.java:630)
        at io.grpc.internal.ClientCallImpl$ClientStreamListenerImpl.access$700(ClientCallImpl.java:518)
        at io.grpc.internal.ClientCallImpl$ClientStreamListenerImpl$1StreamClosed.runInternal(ClientCallImpl.java:692)
        at io.grpc.internal.ClientCallImpl$ClientStreamListenerImpl$1StreamClosed.runInContext(ClientCallImpl.java:681)
        at io.grpc.internal.ContextRunnable.run(ContextRunnable.java:37)
        at io.grpc.internal.SerializingExecutor.run(SerializingExecutor.java:123)
        ... 3 common frames omitted

2020-01-14 06:40:44.695  WARN [xxxx-component-workflow-handler,,,] 11 --- [pool-8-thread-1] io.zeebe.client.job.worker               : Worker component-workflow-handler-1 failed to handle job with key 2251799818233058 of type sendVendorRequest, sending fail command to broker

com.xxxx.model.workflow.WorkflowException: failed to send vendor request (sendVendorRequest), job key:2251799818233058 Instance Key : 2251799818232708
        at com.xxxx.business.workflow.component.handler.service.impl.ComponentWorkflowHandlerServiceImpl.sendVendorRequest(ComponentWorkflowHandlerServiceImpl.java:623)
        at com.xxxx.business.workflow.component.handler.service.impl.ComponentWorkflowHandlerServiceImpl$$FastClassBySpringCGLIB$$f9512a9d.invoke(<generated>)
        at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:218)
        at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:750)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163)
        at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:295)
        at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:98)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
        at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:689)
        at com.xxxx.business.workflow.component.handler.service.impl.ComponentWorkflowHandlerServiceImpl$$EnhancerBySpringCGLIB$$aa38d5dc.sendVendorRequest(<generated>)
        at com.xxxx.business.workflow.component.handler.config.ZeebeConfig.sendVendorRequest(ZeebeConfig.java:93)
        at jdk.internal.reflect.GeneratedMethodAccessor307.invoke(Unknown Source)
        at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.base/java.lang.reflect.Method.invoke(Method.java:566)
        at io.zeebe.spring.client.bean.MethodInfo.invoke(MethodInfo.java:31)
        at io.zeebe.spring.client.config.processor.ZeebeWorkerPostProcessor.lambda$null$1(ZeebeWorkerPostProcessor.java:49)
        at io.zeebe.client.impl.worker.JobRunnableFactory.executeJob(JobRunnableFactory.java:44)
        at io.zeebe.client.impl.worker.JobRunnableFactory.lambda$create$0(JobRunnableFactory.java:39)
        at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
        at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
        at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304)
        at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
        at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
        at java.base/java.lang.Thread.run(Thread.java:834)
Caused by: io.zeebe.client.api.command.ClientStatusException: Command rejected with code 'COMPLETE': Expected to complete job with key '2251799818233058', but no such job was found
        at io.zeebe.client.impl.ZeebeClientFutureImpl.transformExecutionException(ZeebeClientFutureImpl.java:93)
        at io.zeebe.client.impl.ZeebeClientFutureImpl.join(ZeebeClientFutureImpl.java:50)
        at com.xxxx.business.workflow.component.handler.service.impl.ComponentWorkflowHandlerServiceImpl.sendVendorRequest(ComponentWorkflowHandlerServiceImpl.java:617)
        ... 23 common frames omitted
Caused by: java.util.concurrent.ExecutionException: io.grpc.StatusRuntimeException: NOT_FOUND: Command rejected with code 'COMPLETE': Expected to complete job with key '2251799818233058', but no such job was found
        at java.base/java.util.concurrent.CompletableFuture.reportGet(CompletableFuture.java:395)
        at java.base/java.util.concurrent.CompletableFuture.get(CompletableFuture.java:1999)
        at io.zeebe.client.impl.ZeebeClientFutureImpl.join(ZeebeClientFutureImpl.java:48)
        ... 24 common frames omitted
Caused by: io.grpc.StatusRuntimeException: NOT_FOUND: Command rejected with code 'COMPLETE': Expected to complete job with key '2251799818233058', but no such job was found
        at io.grpc.Status.asRuntimeException(Status.java:533)
        at io.grpc.stub.ClientCalls$StreamObserverToCallListenerAdapter.onClose(ClientCalls.java:442)
        at io.grpc.PartialForwardingClientCallListener.onClose(PartialForwardingClientCallListener.java:39)
        at io.grpc.ForwardingClientCallListener.onClose(ForwardingClientCallListener.java:23)
        at io.grpc.ForwardingClientCallListener$SimpleForwardingClientCallListener.onClose(ForwardingClientCallListener.java:40)
        at io.grpc.internal.CensusStatsModule$StatsClientInterceptor$1$1.onClose(CensusStatsModule.java:700)
        at io.grpc.PartialForwardingClientCallListener.onClose(PartialForwardingClientCallListener.java:39)
        at io.grpc.ForwardingClientCallListener.onClose(ForwardingClientCallListener.java:23)
        at io.grpc.ForwardingClientCallListener$SimpleForwardingClientCallListener.onClose(ForwardingClientCallListener.java:40)
        at io.grpc.internal.CensusTracingModule$TracingClientInterceptor$1$1.onClose(CensusTracingModule.java:399)
        at io.grpc.internal.ClientCallImpl.closeObserver(ClientCallImpl.java:510)
        at io.grpc.internal.ClientCallImpl.access$300(ClientCallImpl.java:66)
        at io.grpc.internal.ClientCallImpl$ClientStreamListenerImpl.close(ClientCallImpl.java:630)
        at io.grpc.internal.ClientCallImpl$ClientStreamListenerImpl.access$700(ClientCallImpl.java:518)
        at io.grpc.internal.ClientCallImpl$ClientStreamListenerImpl$1StreamClosed.runInternal(ClientCallImpl.java:692)
        at io.grpc.internal.ClientCallImpl$ClientStreamListenerImpl$1StreamClosed.runInContext(ClientCallImpl.java:681)
        at io.grpc.internal.ContextRunnable.run(ContextRunnable.java:37)
        at io.grpc.internal.SerializingExecutor.run(SerializingExecutor.java:123)
        ... 3 common frames omitted

2020-01-14 06:40:44.731 ERROR [xxxx-component-workflow-handler,,,] 11 --- [pool-8-thread-1] .s.i.ComponentWorkflowHandlerServiceImpl : failed to validate fulfillmentItem (validateFulfillmentItem), job key :2251799818232957 Instance Key : 2251799818232774

io.zeebe.client.api.command.ClientStatusException: Command rejected with code 'COMPLETE': Expected to complete job with key '2251799818232957', but no such job was found
        at io.zeebe.client.impl.ZeebeClientFutureImpl.transformExecutionException(ZeebeClientFutureImpl.java:93)
        at io.zeebe.client.impl.ZeebeClientFutureImpl.join(ZeebeClientFutureImpl.java:50)
        at com.xxxx.business.workflow.component.handler.service.impl.ComponentWorkflowHandlerServiceImpl.validateFulfillmentItem(ComponentWorkflowHandlerServiceImpl.java:396)
        at com.xxxx.business.workflow.component.handler.service.impl.ComponentWorkflowHandlerServiceImpl$$FastClassBySpringCGLIB$$f9512a9d.invoke(<generated>)
        at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:218)
        at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:750)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163)
        at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:295)
        at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:98)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
        at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:689)
        at com.xxxx.business.workflow.component.handler.service.impl.ComponentWorkflowHandlerServiceImpl$$EnhancerBySpringCGLIB$$aa38d5dc.validateFulfillmentItem(<generated>)
        at com.xxxx.business.workflow.component.handler.config.ZeebeConfig.validationTask(ZeebeConfig.java:69)
        at jdk.internal.reflect.GeneratedMethodAccessor301.invoke(Unknown Source)
        at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.base/java.lang.reflect.Method.invoke(Method.java:566)
        at io.zeebe.spring.client.bean.MethodInfo.invoke(MethodInfo.java:31)
        at io.zeebe.spring.client.config.processor.ZeebeWorkerPostProcessor.lambda$null$1(ZeebeWorkerPostProcessor.java:49)
        at io.zeebe.client.impl.worker.JobRunnableFactory.executeJob(JobRunnableFactory.java:44)
        at io.zeebe.client.impl.worker.JobRunnableFactory.lambda$create$0(JobRunnableFactory.java:39)
        at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
        at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
        at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304)
        at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
        at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
        at java.base/java.lang.Thread.run(Thread.java:834)
Caused by: java.util.concurrent.ExecutionException: io.grpc.StatusRuntimeException: NOT_FOUND: Command rejected with code 'COMPLETE': Expected to complete job with key '2251799818232957', but no such job was found
        at java.base/java.util.concurrent.CompletableFuture.reportGet(CompletableFuture.java:395)
        at java.base/java.util.concurrent.CompletableFuture.get(CompletableFuture.java:1999)
        at io.zeebe.client.impl.ZeebeClientFutureImpl.join(ZeebeClientFutureImpl.java:48)
        ... 24 common frames omitted
Caused by: io.grpc.StatusRuntimeException: NOT_FOUND: Command rejected with code 'COMPLETE': Expected to complete job with key '2251799818232957', but no such job was found
        at io.grpc.Status.asRuntimeException(Status.java:533)
        at io.grpc.stub.ClientCalls$StreamObserverToCallListenerAdapter.onClose(ClientCalls.java:442)
        at io.grpc.PartialForwardingClientCallListener.onClose(PartialForwardingClientCallListener.java:39)
        at io.grpc.ForwardingClientCallListener.onClose(ForwardingClientCallListener.java:23)
        at io.grpc.ForwardingClientCallListener$SimpleForwardingClientCallListener.onClose(ForwardingClientCallListener.java:40)
        at io.grpc.internal.CensusStatsModule$StatsClientInterceptor$1$1.onClose(CensusStatsModule.java:700)
        at io.grpc.PartialForwardingClientCallListener.onClose(PartialForwardingClientCallListener.java:39)
        at io.grpc.ForwardingClientCallListener.onClose(ForwardingClientCallListener.java:23)
        at io.grpc.ForwardingClientCallListener$SimpleForwardingClientCallListener.onClose(ForwardingClientCallListener.java:40)
        at io.grpc.internal.CensusTracingModule$TracingClientInterceptor$1$1.onClose(CensusTracingModule.java:399)
        at io.grpc.internal.ClientCallImpl.closeObserver(ClientCallImpl.java:510)
        at io.grpc.internal.ClientCallImpl.access$300(ClientCallImpl.java:66)
        at io.grpc.internal.ClientCallImpl$ClientStreamListenerImpl.close(ClientCallImpl.java:630)
        at io.grpc.internal.ClientCallImpl$ClientStreamListenerImpl.access$700(ClientCallImpl.java:518)
        at io.grpc.internal.ClientCallImpl$ClientStreamListenerImpl$1StreamClosed.runInternal(ClientCallImpl.java:692)
        at io.grpc.internal.ClientCallImpl$ClientStreamListenerImpl$1StreamClosed.runInContext(ClientCallImpl.java:681)
        at io.grpc.internal.ContextRunnable.run(ContextRunnable.java:37)
        at io.grpc.internal.SerializingExecutor.run(SerializingExecutor.java:123)
        ... 3 common frames omitted

2020-01-14 06:40:44.740  WARN [xxxx-component-workflow-handler,,,] 11 --- [pool-8-thread-1] io.zeebe.client.job.worker               : Worker component-workflow-handler-1 failed to handle job with key 2251799818232957 of type ValidationTask, sending fail command to broker

com.xxxx.model.workflow.WorkflowException: failed to validate fulfillmentItem (validateFulfillmentItem), job key :2251799818232957 Instance Key : 2251799818232774
        at com.xxxx.business.workflow.component.handler.service.impl.ComponentWorkflowHandlerServiceImpl.validateFulfillmentItem(ComponentWorkflowHandlerServiceImpl.java:403)
        at com.xxxx.business.workflow.component.handler.service.impl.ComponentWorkflowHandlerServiceImpl$$FastClassBySpringCGLIB$$f9512a9d.invoke(<generated>)
        at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:218)
        at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:750)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163)
        at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:295)
        at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:98)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
        at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:689)
        at com.xxxx.business.workflow.component.handler.service.impl.ComponentWorkflowHandlerServiceImpl$$EnhancerBySpringCGLIB$$aa38d5dc.validateFulfillmentItem(<generated>)
        at com.xxxx.business.workflow.component.handler.config.ZeebeConfig.validationTask(ZeebeConfig.java:69)
        at jdk.internal.reflect.GeneratedMethodAccessor301.invoke(Unknown Source)
        at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.base/java.lang.reflect.Method.invoke(Method.java:566)
        at io.zeebe.spring.client.bean.MethodInfo.invoke(MethodInfo.java:31)
        at io.zeebe.spring.client.config.processor.ZeebeWorkerPostProcessor.lambda$null$1(ZeebeWorkerPostProcessor.java:49)
        at io.zeebe.client.impl.worker.JobRunnableFactory.executeJob(JobRunnableFactory.java:44)
        at io.zeebe.client.impl.worker.JobRunnableFactory.lambda$create$0(JobRunnableFactory.java:39)
        at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
        at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
        at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304)
        at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
        at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
        at java.base/java.lang.Thread.run(Thread.java:834)
Caused by: io.zeebe.client.api.command.ClientStatusException: Command rejected with code 'COMPLETE': Expected to complete job with key '2251799818232957', but no such job was found
        at io.zeebe.client.impl.ZeebeClientFutureImpl.transformExecutionException(ZeebeClientFutureImpl.java:93)
        at io.zeebe.client.impl.ZeebeClientFutureImpl.join(ZeebeClientFutureImpl.java:50)
        at com.xxxx.business.workflow.component.handler.service.impl.ComponentWorkflowHandlerServiceImpl.validateFulfillmentItem(ComponentWorkflowHandlerServiceImpl.java:396)
        ... 23 common frames omitted
Caused by: java.util.concurrent.ExecutionException: io.grpc.StatusRuntimeException: NOT_FOUND: Command rejected with code 'COMPLETE': Expected to complete job with key '2251799818232957', but no such job was found
        at java.base/java.util.concurrent.CompletableFuture.reportGet(CompletableFuture.java:395)
        at java.base/java.util.concurrent.CompletableFuture.get(CompletableFuture.java:1999)
        at io.zeebe.client.impl.ZeebeClientFutureImpl.join(ZeebeClientFutureImpl.java:48)
        ... 24 common frames omitted
Caused by: io.grpc.StatusRuntimeException: NOT_FOUND: Command rejected with code 'COMPLETE': Expected to complete job with key '2251799818232957', but no such job was found
        at io.grpc.Status.asRuntimeException(Status.java:533)
        at io.grpc.stub.ClientCalls$StreamObserverToCallListenerAdapter.onClose(ClientCalls.java:442)
        at io.grpc.PartialForwardingClientCallListener.onClose(PartialForwardingClientCallListener.java:39)
        at io.grpc.ForwardingClientCallListener.onClose(ForwardingClientCallListener.java:23)
        at io.grpc.ForwardingClientCallListener$SimpleForwardingClientCallListener.onClose(ForwardingClientCallListener.java:40)
        at io.grpc.internal.CensusStatsModule$StatsClientInterceptor$1$1.onClose(CensusStatsModule.java:700)
        at io.grpc.PartialForwardingClientCallListener.onClose(PartialForwardingClientCallListener.java:39)
        at io.grpc.ForwardingClientCallListener.onClose(ForwardingClientCallListener.java:23)
        at io.grpc.ForwardingClientCallListener$SimpleForwardingClientCallListener.onClose(ForwardingClientCallListener.java:40)
        at io.grpc.internal.CensusTracingModule$TracingClientInterceptor$1$1.onClose(CensusTracingModule.java:399)
        at io.grpc.internal.ClientCallImpl.closeObserver(ClientCallImpl.java:510)
        at io.grpc.internal.ClientCallImpl.access$300(ClientCallImpl.java:66)
        at io.grpc.internal.ClientCallImpl$ClientStreamListenerImpl.close(ClientCallImpl.java:630)
        at io.grpc.internal.ClientCallImpl$ClientStreamListenerImpl.access$700(ClientCallImpl.java:518)
        at io.grpc.internal.ClientCallImpl$ClientStreamListenerImpl$1StreamClosed.runInternal(ClientCallImpl.java:692)
        at io.grpc.internal.ClientCallImpl$ClientStreamListenerImpl$1StreamClosed.runInContext(ClientCallImpl.java:681)
        at io.grpc.internal.ContextRunnable.run(ContextRunnable.java:37)
        at io.grpc.internal.SerializingExecutor.run(SerializingExecutor.java:123)
        ... 3 common frames omitted

broker logs:

1/14/2020 2:35:18 PM2020-01-14 09:05:18.612 [io.zeebe.gateway.impl.broker.BrokerRequestManager] [10.42.211.69:26501-zb-actors-0] ERROR io.zeebe.gateway - Error handling gRPC request
1/14/2020 2:35:18 PMio.grpc.StatusRuntimeException: NOT_FOUND: Command rejected with code 'COMPLETE': Expected to complete job with key '2251799817346157', but no such job was found
1/14/2020 2:35:18 PM	at io.grpc.Status.asRuntimeException(Status.java:524) ~[grpc-api-1.24.0.jar:1.24.0]
1/14/2020 2:35:18 PM	at io.zeebe.gateway.EndpointManager.convertThrowable(EndpointManager.java:291) ~[zeebe-gateway-0.21.1.jar:0.21.1]
1/14/2020 2:35:18 PM	at io.zeebe.gateway.EndpointManager.lambda$sendRequest$3(EndpointManager.java:269) ~[zeebe-gateway-0.21.1.jar:0.21.1]
1/14/2020 2:35:18 PM	at io.zeebe.gateway.impl.broker.BrokerRequestManager.lambda$sendRequest$1(BrokerRequestManager.java:101) ~[zeebe-gateway-0.21.1.jar:0.21.1]
1/14/2020 2:35:18 PM	at io.zeebe.gateway.impl.broker.BrokerRequestManager.lambda$sendRequest$3(BrokerRequestManager.java:121) ~[zeebe-gateway-0.21.1.jar:0.21.1]
1/14/2020 2:35:18 PM	at io.zeebe.gateway.impl.broker.BrokerRequestManager.lambda$sendRequestInternal$5(BrokerRequestManager.java:159) ~[zeebe-gateway-0.21.1.jar:0.21.1]
1/14/2020 2:35:18 PM	at io.zeebe.util.sched.future.FutureContinuationRunnable.run(FutureContinuationRunnable.java:27) [zeebe-util-0.21.1.jar:0.21.1]
1/14/2020 2:35:18 PM	at io.zeebe.util.sched.ActorJob.invoke(ActorJob.java:76) [zeebe-util-0.21.1.jar:0.21.1]
1/14/2020 2:35:18 PM	at io.zeebe.util.sched.ActorJob.execute(ActorJob.java:39) [zeebe-util-0.21.1.jar:0.21.1]
1/14/2020 2:35:18 PM	at io.zeebe.util.sched.ActorTask.execute(ActorTask.java:127) [zeebe-util-0.21.1.jar:0.21.1]
1/14/2020 2:35:18 PM	at io.zeebe.util.sched.ActorThread.executeCurrentTask(ActorThread.java:107) [zeebe-util-0.21.1.jar:0.21.1]
1/14/2020 2:35:18 PM	at io.zeebe.util.sched.ActorThread.doWork(ActorThread.java:91) [zeebe-util-0.21.1.jar:0.21.1]
1/14/2020 2:35:18 PM	at io.zeebe.util.sched.ActorThread.run(ActorThread.java:195) [zeebe-util-0.21.1.jar:0.21.1]
1/14/2020 2:35:18 PMCaused by: io.zeebe.gateway.cmd.BrokerRejectionException: Command (COMPLETE) rejected (NOT_FOUND): Expected to complete job with key '2251799817346157', but no such job was found
1/14/2020 2:35:18 PM	... 10 more
1/14/2020 2:35:18 PM2020-01-14 09:05:18.639 [io.zeebe.gateway.impl.broker.BrokerRequestManager] [10.42.211.69:26501-zb-actors-1] ERROR io.zeebe.gateway - Error handling gRPC request
1/14/2020 2:35:18 PMio.grpc.StatusRuntimeException: NOT_FOUND: Command rejected with code 'COMPLETE': Expected to complete job with key '2251799817346028', but no such job was found
1/14/2020 2:35:18 PM	at io.grpc.Status.asRuntimeException(Status.java:524) ~[grpc-api-1.24.0.jar:1.24.0]
1/14/2020 2:35:18 PM	at io.zeebe.gateway.EndpointManager.convertThrowable(EndpointManager.java:291) ~[zeebe-gateway-0.21.1.jar:0.21.1]
1/14/2020 2:35:18 PM	at io.zeebe.gateway.EndpointManager.lambda$sendRequest$3(EndpointManager.java:269) ~[zeebe-gateway-0.21.1.jar:0.21.1]
1/14/2020 2:35:18 PM	at io.zeebe.gateway.impl.broker.BrokerRequestManager.lambda$sendRequest$1(BrokerRequestManager.java:101) ~[zeebe-gateway-0.21.1.jar:0.21.1]
1/14/2020 2:35:18 PM	at io.zeebe.gateway.impl.broker.BrokerRequestManager.lambda$sendRequest$3(BrokerRequestManager.java:121) ~[zeebe-gateway-0.21.1.jar:0.21.1]
1/14/2020 2:35:18 PM	at io.zeebe.gateway.impl.broker.BrokerRequestManager.lambda$sendRequestInternal$5(BrokerRequestManager.java:159) ~[zeebe-gateway-0.21.1.jar:0.21.1]
1/14/2020 2:35:18 PM	at io.zeebe.util.sched.future.FutureContinuationRunnable.run(FutureContinuationRunnable.java:27) [zeebe-util-0.21.1.jar:0.21.1]
1/14/2020 2:35:18 PM	at io.zeebe.util.sched.ActorJob.invoke(ActorJob.java:76) [zeebe-util-0.21.1.jar:0.21.1]
1/14/2020 2:35:18 PM	at io.zeebe.util.sched.ActorJob.execute(ActorJob.java:39) [zeebe-util-0.21.1.jar:0.21.1]
1/14/2020 2:35:18 PM	at io.zeebe.util.sched.ActorTask.execute(ActorTask.java:127) [zeebe-util-0.21.1.jar:0.21.1]
1/14/2020 2:35:18 PM	at io.zeebe.util.sched.ActorThread.executeCurrentTask(ActorThread.java:107) [zeebe-util-0.21.1.jar:0.21.1]
1/14/2020 2:35:18 PM	at io.zeebe.util.sched.ActorThread.doWork(ActorThread.java:91) [zeebe-util-0.21.1.jar:0.21.1]
1/14/2020 2:35:18 PM	at io.zeebe.util.sched.ActorThread.run(ActorThread.java:195) [zeebe-util-0.21.1.jar:0.21.1]
1/14/2020 2:35:18 PMCaused by: io.zeebe.gateway.cmd.BrokerRejectionException: Command (COMPLETE) rejected (NOT_FOUND): Expected to complete job with key '2251799817346028', but no such job was found
1/14/2020 2:35:18 PM	... 10 more
1/14/2020 2:35:18 PM2020-01-14 09:05:18.661 [io.zeebe.gateway.impl.broker.BrokerRequestManager] [10.42.211.69:26501-zb-actors-1] ERROR io.zeebe.gateway - Error handling gRPC request
1/14/2020 2:35:18 PMio.grpc.StatusRuntimeException: NOT_FOUND: Command rejected with code 'FAIL': Expected to fail activated job with key '2251799817346028', but it does not exist
1/14/2020 2:35:18 PM	at io.grpc.Status.asRuntimeException(Status.java:524) ~[grpc-api-1.24.0.jar:1.24.0]
1/14/2020 2:35:18 PM	at io.zeebe.gateway.EndpointManager.convertThrowable(EndpointManager.java:291) ~[zeebe-gateway-0.21.1.jar:0.21.1]
1/14/2020 2:35:18 PM	at io.zeebe.gateway.EndpointManager.lambda$sendRequest$3(EndpointManager.java:269) ~[zeebe-gateway-0.21.1.jar:0.21.1]
1/14/2020 2:35:18 PM	at io.zeebe.gateway.impl.broker.BrokerRequestManager.lambda$sendRequest$1(BrokerRequestManager.java:101) ~[zeebe-gateway-0.21.1.jar:0.21.1]
1/14/2020 2:35:18 PM	at io.zeebe.gateway.impl.broker.BrokerRequestManager.lambda$sendRequest$3(BrokerRequestManager.java:121) ~[zeebe-gateway-0.21.1.jar:0.21.1]
1/14/2020 2:35:18 PM	at io.zeebe.gateway.impl.broker.BrokerRequestManager.lambda$sendRequestInternal$5(BrokerRequestManager.java:159) ~[zeebe-gateway-0.21.1.jar:0.21.1]
1/14/2020 2:35:18 PM	at io.zeebe.util.sched.future.FutureContinuationRunnable.run(FutureContinuationRunnable.java:27) [zeebe-util-0.21.1.jar:0.21.1]
1/14/2020 2:35:18 PM	at io.zeebe.util.sched.ActorJob.invoke(ActorJob.java:76) [zeebe-util-0.21.1.jar:0.21.1]
1/14/2020 2:35:18 PM	at io.zeebe.util.sched.ActorJob.execute(ActorJob.java:39) [zeebe-util-0.21.1.jar:0.21.1]
1/14/2020 2:35:18 PM	at io.zeebe.util.sched.ActorTask.execute(ActorTask.java:127) [zeebe-util-0.21.1.jar:0.21.1]
1/14/2020 2:35:18 PM	at io.zeebe.util.sched.ActorThread.executeCurrentTask(ActorThread.java:107) [zeebe-util-0.21.1.jar:0.21.1]
1/14/2020 2:35:18 PM	at io.zeebe.util.sched.ActorThread.doWork(ActorThread.java:91) [zeebe-util-0.21.1.jar:0.21.1]
1/14/2020 2:35:18 PM	at io.zeebe.util.sched.ActorThread.run(ActorThread.java:195) [zeebe-util-0.21.1.jar:0.21.1]
1/14/2020 2:35:18 PMCaused by: io.zeebe.gateway.cmd.BrokerRejectionException: Command (FAIL) rejected (NOT_FOUND): Expected to fail activated job with key '2251799817346028', but it does not exist
1/14/2020 2:35:18 PM	... 10 more
1 Like

Hi @regojoyson, this is consistent with a worker attempting to complete a job that got retried and completed in the meantime by another worker…

1 Like

Do you have multiple replicas of the worker?

@salaboy @jwulf no I am having only one instance .

@salaboy @jwulf

I found on the issue in spring Zeebe. I have only one job worker and the max job active is 2 for that job

Here some time the job worker will receive the same job twice but while sending the complete command it will throw an exception in one request and another request will be successful. but the problem is it will perform all the logic which I have written execute twice.

so how to overcome this? and is this still existing issue?

if I run multiple instances then it will be nightmare for us.

Thanks & Regards,
Sam

@regojoyson that does sounds like a problem. Can you help us to reproduce the issue that you are mentioning? How are you checking that is the same job twice? In general, we suggest to make the Workers to be idempotent, that means that you need to make sure that running the same operations twice doesn’t end up creating the wrong state for the entire system.
Just checking… which versions of Zeebe Broker and Zeebe Spring are you using? to make sure that we are not talking about a solved issue.

Cheers

@regojoyson after checking with the team, what might be happening is that you have a very long running job that is timing out and then being locked again by the worker. If you want to solve those kind of situations you might need to extend the timeout period depending on the type of job that you are executing. Check the docs here for that: https://docs.zeebe.io/reference/grpc.html#input-activatejobsrequest

@salaboy

I am using zeebe 0.22.1 and spring zeebe 0.22.0. And I will share code samples later by EOD.

Because I am sending some mail to through one job worker so sometimes it will send twice, so later I put some debug log on it then I figured out the issue due to zeebe it’s calling twice.

But if I put max job active 1 this problem will not come. only when the max jobs active is 2.

@regojoyson but how much time is the job taking in general?

@salaboy only twice… one job will pass without error and another duplicate job will fail while sending the complete command to broker.

here is sample

Jobs:

@Component("component-workflow-jobs")
public class ZeebeConfig {

	// component workflow handler service
	@Autowired
	private ComponentWorkflowHandlerService componentWorkflowHandlerService;

	@ZeebeWorker(type = "validateScopeOfWork")
	public void validateScopeOfWork(final JobClient client, final ActivatedJob job) {
   // Get the Component Workflow Model from the Payload
		ComponentWorkflowModel componentWorkflowModel = 
    job.getVariablesAsType(ComponentWorkflowModel.class);	
// logic here

//complete
client.newCompleteCommand(job.getKey()).variables(componentWorkflowModel).send().join();


	}
	@ZeebeWorker(type = "sendNotification")
	public void sendNotification(final JobClient client, final ActivatedJob job) {
	  // Get the Component Workflow Model from the Payload
		ComponentWorkflowModel componentWorkflowModel = 
    job.getVariablesAsType(ComponentWorkflowModel.class);	
// logic here

//complete
client.newCompleteCommand(job.getKey()).variables(componentWorkflowModel).send().join();

	}
        	@ZeebeWorker(type = "closeOrder")
	public void closeOrder(final JobClient client, final ActivatedJob job) {
		
  // Get the Component Workflow Model from the Payload
		ComponentWorkflowModel componentWorkflowModel = 
    job.getVariablesAsType(ComponentWorkflowModel.class);	
// logic here

//complete
client.newCompleteCommand(job.getKey()).variables(componentWorkflowModel).send().join();


	}
}

Properties:

zeebe.broker.contactPoint=xxxxxx:26500
zeebe.worker.name=component-workflow-handler-1
zeebe.worker.defaultName = default-worker
zeebe.client.broker.contactPoint:xxxxxxxt:26500
zeebe.client.security.plaintext=true

Can you nail down exactly what is happening please.

I would log out timestamps to build a timeline like this:

hh:mm:ss:ms - Worker requests two jobs
hh:mm:ss:ms - Worker gets one job (job 1 instance 1)
hh:mm:ss:ms - Worker handler invoked
hh:mm:ss:ms - Worker requests two jobs
hh:mm:ss:ms - Worker gets one job (job 1 instance 2)
hh:mm:ss:ms - Worker handler invoked
hh:mm:ss:ms - Worker handler completes instance 1
hh:mm:ss:ms - Worker handler completes instance 2

At the moment it is not clear whether it is being given the same job twice in the same activateJobs call, or in subsequent calls. You want to nail it down to the exact sequence of events, so we know where to look for the cause. It could be application-level, client lib, gateway, or broker.

1 Like

@jwulf

This issue happening rarely 2 or 3 times in a week.
Next time if I get issue I will post the same.

2 Likes

Boo to intermittent Heisenbugs!

If you can log also the amount of time that it takes the Job to complete that will be helpful. It might be the case that you are sending a request to a mail server that is never finishing (or at least from the client side) and the worker unlocks the job as it also time out after a while.

1 Like