Command rejected with code 'COMPLETE'

regojoyson · January 14, 2020, 9:16am

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

jwulf · January 14, 2020, 12:02pm

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

salaboy · January 15, 2020, 4:53pm

Do you have multiple replicas of the worker?

regojoyson · January 15, 2020, 6:29pm

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

regojoyson · January 29, 2020, 5:43am

@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

salaboy · January 29, 2020, 9:18am

@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

salaboy · January 29, 2020, 9:26am

@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

regojoyson · January 29, 2020, 9:27am

@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.

salaboy · January 29, 2020, 10:47am

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

regojoyson · January 29, 2020, 11:50am

@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

jwulf · January 29, 2020, 2:58pm

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.

regojoyson · January 29, 2020, 3:52pm

@jwulf

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

jwulf · January 29, 2020, 7:03pm

Boo to intermittent Heisenbugs!

salaboy · January 30, 2020, 8:26am

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.

Eetay · May 29, 2020, 7:48pm

@regojoyson
I know this is an old post, but wondering if you ever found out the problem? I’m having same issue with a single zeebe-node client, even after increasing timeouts to 120s

Thanks
Eetay

Eetay · June 4, 2020, 2:34pm

update. Solved by much larger timeouts, required due to other systems. was definitely a timeout-while-worker-is-still-working-the-job problem

jwulf · September 22, 2020, 5:17am

The error:

Command rejected with code ‘COMPLETE’: Expected to complete job with key ‘…’, but no such job was found.

Can be caused by the following conditions:

The process itself was cancelled.
The job was cancelled by a boundary interrupting event on the task or on the subprocess containing the task.
The job was completed (or failed) by another worker instance (which could be this worker in another “thread”).

The third condition happens when the job was activated by the worker with a timeout that is less than the amount of time it took the worker to complete it.

Since the job took longer than the timeout, the broker timed out the worker’s activation and made the job available to another activation request.

The job was then activated by another activation request (which may even be from the same worker). By the time the second activated job is completed, the first activation has completed. Thus the job no longer exists for the second activation to be completed, and the broker will return this error.

There are two things to note about this:

Make sure that the timeout you specify for the worker is sufficient to allow the job to be completed.
Make sure that your job worker handlers are idempotent, as they may be invoked more than once for the same job - even when you have only one worker.

mathygreen · December 20, 2021, 3:36pm

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.

Reliable Permit Solutions, LLC

Nele · December 20, 2021, 5:16pm

Hey @mathygreen ,

As in the thread discussed above this can have various reasons. How long does the job take to complete? Could it be a timeout issue ? Then it would help to increase the timeout period of your worker like discussed above. If that is not the case it would be helpful if you could provide some more information so we can try to reproduce it.

I hope that helps
Cheers
Nele

mathygreen · December 21, 2021, 6:14pm

I am using zeebe 0.22.1 and spring zeebe 0.22.0.

And I will share code samples.

@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

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.