Skip to content
New issue

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

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

Already on GitHub? Sign in to your account

[Regression] Terminate end events - Command 'COMPLETE' rejected with code 'PROCESSING_ERROR' #876

Closed
namero999 opened this issue Sep 1, 2023 · 5 comments · Fixed by #930
Assignees
Labels
area/reliability Relates to reliability kind/bug Categorizes issue or PR as related to a bug. severity/high Marks a bug as having a noticeable impact on the user with no known workaround support

Comments

@namero999
Copy link

namero999 commented Sep 1, 2023

There seems to be an issue with terminate end events and multiple tokens.

This test (code below) passes with 8.1.8 but fails with 8.2.12

The BPMN starts with a parallel gateway, with a token waiting for a timeout to expire while the rest of the process continues. Both end events are terminate events. The issue seems related to the presence of terminate events and multiple tokens in the process, because commenting out the "timeout" branch makes the test pass with 8.2.12 as well.

image

The issue arises when completing the last service task before the terminate end event.

INTERNAL: Command 'COMPLETE' rejected with code 'PROCESSING_ERROR': Expected to process record 'TypedRecordImpl{metadata=RecordMetadata{recordType=COMMAND, valueType=JOB, intent=COMPLETE}, value={"deadline":-1,"worker":"","retries":-1,"retryBackoff":0,"recurringTime":-1,"type":"","customHeaders":[packed value (length=1)],"variables":"gA==","errorMessage":"","errorCode":"","bpmnProcessId":"","processDefinitionVersion":-1,"processDefinitionKey":-1,"processInstanceKey":-1,"elementId":"","elementInstanceKey":-1}}' without errors, but exception occurred with message 'Expected the child count to be positive but was -1'.

Test code
import io.camunda.zeebe.client.ZeebeClient;
import io.camunda.zeebe.client.api.response.ActivatedJob;
import io.camunda.zeebe.client.api.response.DeploymentEvent;
import io.camunda.zeebe.client.api.response.ProcessInstanceEvent;
import io.camunda.zeebe.model.bpmn.Bpmn;
import io.camunda.zeebe.model.bpmn.BpmnModelInstance;
import io.camunda.zeebe.model.bpmn.builder.AbstractFlowNodeBuilder;
import io.camunda.zeebe.process.test.api.ZeebeTestEngine;
import io.camunda.zeebe.process.test.assertions.BpmnAssert;
import io.camunda.zeebe.process.test.assertions.ProcessInstanceAssert;
import io.camunda.zeebe.process.test.extension.ZeebeProcessTest;
import lombok.SneakyThrows;
import org.junit.jupiter.api.Test;
import java.time.Duration;
import static java.time.Duration.ofSeconds;

@ZeebeProcessTest
public class PlanTest {

  protected ZeebeTestEngine engine;
  protected ZeebeClient client;

  @Test
  public void planTest() {

    AbstractFlowNodeBuilder builder = Bpmn.createExecutableProcess("plan_run_1").startEvent("PLAN_START").name("PLAN_START");

    builder = addPlanExecutionTimeout(builder); // Try to comment this line with 8.2.12 -> test passes

    builder = builder.serviceTask("plan-started").zeebeJobType(PLAN_STARTED_JOB_TYPE);

    builder = builder.serviceTask("debug").zeebeJobType(DEBUG_JOB_TYPE);

    builder = builder.serviceTask("plan-ended").zeebeJobType(PLAN_ENDED_JOB_TYPE);

    BpmnModelInstance modelInstance = builder.endEvent("PLAN_END").name("PLAN_END").terminate().done();

    debugBpmn(modelInstance);

    DeploymentEvent deploymentEvent =
      client.newDeployResourceCommand()
            .addProcessModel(modelInstance, "plan.bpmn")
            .send()
            .join();

    BpmnAssert.assertThat(deploymentEvent).containsProcessesByResourceName("plan.bpmn");

    ProcessInstanceEvent processInstanceEvent =
      client.newCreateInstanceCommand()
            .bpmnProcessId("plan_run_1")
            .latestVersion()
            .send()
            .join();

    waitForIdleState();

    ProcessInstanceAssert processInstanceAssert = BpmnAssert.assertThat(processInstanceEvent)
                                                            .isStarted()
                                                            .isActive()
                                                            .isNotCompleted()
                                                            .isNotTerminated()
                                                            .hasPassedElement("PLAN_START");

    ActivatedJob planStartedJob = activate(PLAN_STARTED_JOB_TYPE);
    complete(planStartedJob);

    ActivatedJob debugJob = activate(DEBUG_JOB_TYPE);
    complete(debugJob);

    ActivatedJob planEndedJob = activate(PLAN_ENDED_JOB_TYPE);
    complete(planEndedJob);

    processInstanceAssert.hasPassedElement("PLAN_END")
                         .hasNotPassedElement("plan-timeout")
                         .hasNoIncidents()
                         .isCompleted();

  }

  private AbstractFlowNodeBuilder addPlanExecutionTimeout(AbstractFlowNodeBuilder builder) {
    return builder.parallelGateway()
                  .intermediateCatchEvent()
                  .timerWithDuration("P2D")
                  .serviceTask("plan-timeout")
                  .name("plan-timeout")
                  .zeebeJobType(PLAN_TIMEOUT_JOB_TYPE)
                  .endEvent()
                  .name("TIMER_END")
                  .terminate()
                  .moveToLastGateway();
  }

  @SneakyThrows
  public void waitForIdleState() {
    engine.waitForIdleState(ofSeconds(2));
  }

  public ActivatedJob activate(String jobType) {
    return client.newActivateJobsCommand()
                 .jobType(jobType)
                 .maxJobsToActivate(1)
                 .send()
                 .join()
                 .getJobs()
                 .get(0);
  }

  public void complete(ActivatedJob job) {
    client.newCompleteCommand(job.getKey()).send().join();
    waitForIdleState();
  }

}
Process
<?xml version="1.0" encoding="UTF-8" standalone="no"?>
<definitions xmlns:bpmndi="http://www.omg.org/spec/BPMN/20100524/DI" xmlns:dc="http://www.omg.org/spec/DD/20100524/DC" xmlns:di="http://www.omg.org/spec/DD/20100524/DI" xmlns:ns0="http://camunda.org/schema/zeebe/1.0" id="definitions_85054af5-7e06-429f-8e06-88060c51cb49" targetNamespace="http://www.omg.org/spec/BPMN/20100524/MODEL" xmlns="http://www.omg.org/spec/BPMN/20100524/MODEL">
  <process id="plan_run_1" isExecutable="true">
    <startEvent id="PLAN_START" name="PLAN_START">
      <outgoing>sequenceFlow_2d8cd683-bc0e-43bf-8245-b86578cf8f78</outgoing>
    </startEvent>
    <parallelGateway id="parallelGateway_0cfa600b-077a-4a0d-90f5-4509b2424ab1">
      <incoming>sequenceFlow_2d8cd683-bc0e-43bf-8245-b86578cf8f78</incoming>
      <outgoing>sequenceFlow_3e10a946-cded-491d-b911-9dfebae162de</outgoing>
      <outgoing>sequenceFlow_fb2a1859-39f8-44d1-883f-36aebfb7324a</outgoing>
    </parallelGateway>
    <sequenceFlow id="sequenceFlow_2d8cd683-bc0e-43bf-8245-b86578cf8f78" sourceRef="PLAN_START" targetRef="parallelGateway_0cfa600b-077a-4a0d-90f5-4509b2424ab1"/>
    <intermediateCatchEvent id="intermediateCatchEvent_97c3f283-6a79-4ef2-b8c6-b31ad464bc81">
      <incoming>sequenceFlow_3e10a946-cded-491d-b911-9dfebae162de</incoming>
      <outgoing>sequenceFlow_a4400a1c-50a8-4314-959f-cd4a1eaf1f10</outgoing>
      <timerEventDefinition id="timerEventDefinition_e08de9c2-8d2d-4bbf-b9c8-a872a4d3c7d7">
        <timeDuration id="timeDuration_f58df4e6-1c49-4d50-a9b9-647111031e28">P2D</timeDuration>
      </timerEventDefinition>
    </intermediateCatchEvent>
    <sequenceFlow id="sequenceFlow_3e10a946-cded-491d-b911-9dfebae162de" sourceRef="parallelGateway_0cfa600b-077a-4a0d-90f5-4509b2424ab1" targetRef="intermediateCatchEvent_97c3f283-6a79-4ef2-b8c6-b31ad464bc81"/>
    <serviceTask id="plan-timeout" name="plan-timeout">
      <extensionElements>
        <ns0:taskDefinition type="orchestration:plan-timeout"/>
      </extensionElements>
      <incoming>sequenceFlow_a4400a1c-50a8-4314-959f-cd4a1eaf1f10</incoming>
      <outgoing>sequenceFlow_16cf3d78-cc9e-41df-beec-d959a6bcd538</outgoing>
    </serviceTask>
    <sequenceFlow id="sequenceFlow_a4400a1c-50a8-4314-959f-cd4a1eaf1f10" sourceRef="intermediateCatchEvent_97c3f283-6a79-4ef2-b8c6-b31ad464bc81" targetRef="plan-timeout"/>
    <endEvent id="endEvent_34811f66-4a17-4424-8620-5efc0bbdaf95" name="TIMER_END">
      <incoming>sequenceFlow_16cf3d78-cc9e-41df-beec-d959a6bcd538</incoming>
      <terminateEventDefinition id="terminateEventDefinition_1d018d25-000a-44e4-8919-01a57b945a26"/>
    </endEvent>
    <sequenceFlow id="sequenceFlow_16cf3d78-cc9e-41df-beec-d959a6bcd538" sourceRef="plan-timeout" targetRef="endEvent_34811f66-4a17-4424-8620-5efc0bbdaf95"/>
    <serviceTask id="plan-started" name="plan-started">
      <extensionElements>
        <ns0:taskDefinition type="orchestration:plan-started"/>
      </extensionElements>
      <incoming>sequenceFlow_fb2a1859-39f8-44d1-883f-36aebfb7324a</incoming>
      <outgoing>sequenceFlow_ff2c78fb-6538-454b-9e25-6b9498c5c028</outgoing>
    </serviceTask>
    <sequenceFlow id="sequenceFlow_fb2a1859-39f8-44d1-883f-36aebfb7324a" sourceRef="parallelGateway_0cfa600b-077a-4a0d-90f5-4509b2424ab1" targetRef="plan-started"/>
    <serviceTask id="debug" name="debug">
      <extensionElements>
        <ns0:taskDefinition type="orchestration:samples:debug"/>
      </extensionElements>
      <incoming>sequenceFlow_ff2c78fb-6538-454b-9e25-6b9498c5c028</incoming>
      <outgoing>sequenceFlow_1fb33309-3b14-4023-87c5-9caaeb91e31d</outgoing>
    </serviceTask>
    <sequenceFlow id="sequenceFlow_ff2c78fb-6538-454b-9e25-6b9498c5c028" sourceRef="plan-started" targetRef="debug"/>
    <serviceTask id="plan-ended" name="plan-ended">
      <extensionElements>
        <ns0:taskDefinition type="orchestration:plan-ended"/>
      </extensionElements>
      <incoming>sequenceFlow_1fb33309-3b14-4023-87c5-9caaeb91e31d</incoming>
      <outgoing>sequenceFlow_8cf1e434-7c86-4ef1-84f6-667265a62485</outgoing>
    </serviceTask>
    <sequenceFlow id="sequenceFlow_1fb33309-3b14-4023-87c5-9caaeb91e31d" sourceRef="debug" targetRef="plan-ended"/>
    <endEvent id="PLAN_END" name="PLAN_END">
      <incoming>sequenceFlow_8cf1e434-7c86-4ef1-84f6-667265a62485</incoming>
      <terminateEventDefinition id="terminateEventDefinition_48ac0456-d9b9-44a9-94f2-2278fdd12503"/>
    </endEvent>
    <sequenceFlow id="sequenceFlow_8cf1e434-7c86-4ef1-84f6-667265a62485" sourceRef="plan-ended" targetRef="PLAN_END"/>
  </process>
  <bpmndi:BPMNDiagram id="BPMNDiagram_67c4cca4-3aba-4a1f-8715-425ea279c866">
    <bpmndi:BPMNPlane bpmnElement="plan_run_1" id="BPMNPlane_0c806bbd-0e7f-45f4-acdb-642cb1791fac">
      <bpmndi:BPMNShape bpmnElement="PLAN_START" id="BPMNShape_0af995e0-7927-4ae4-8ae5-ea94eb30fb96">
        <dc:Bounds height="36.0" width="36.0" x="100.0" y="100.0"/>
      </bpmndi:BPMNShape>
      <bpmndi:BPMNShape bpmnElement="parallelGateway_0cfa600b-077a-4a0d-90f5-4509b2424ab1" id="BPMNShape_36b7cdf1-8272-4df3-bac0-984c8b89660a">
        <dc:Bounds height="50.0" width="50.0" x="186.0" y="93.0"/>
      </bpmndi:BPMNShape>
      <bpmndi:BPMNEdge bpmnElement="sequenceFlow_2d8cd683-bc0e-43bf-8245-b86578cf8f78" id="BPMNEdge_5e8e25a6-c66e-4c77-b02a-eee3b96fb353">
        <di:waypoint x="136.0" y="118.0"/>
        <di:waypoint x="186.0" y="118.0"/>
      </bpmndi:BPMNEdge>
      <bpmndi:BPMNShape bpmnElement="intermediateCatchEvent_97c3f283-6a79-4ef2-b8c6-b31ad464bc81" id="BPMNShape_9a3ab357-0486-441c-a746-1e03838119f1">
        <dc:Bounds height="36.0" width="36.0" x="286.0" y="100.0"/>
      </bpmndi:BPMNShape>
      <bpmndi:BPMNEdge bpmnElement="sequenceFlow_3e10a946-cded-491d-b911-9dfebae162de" id="BPMNEdge_5a3f75b8-7a68-4616-b86a-06b30093f173">
        <di:waypoint x="236.0" y="118.0"/>
        <di:waypoint x="286.0" y="118.0"/>
      </bpmndi:BPMNEdge>
      <bpmndi:BPMNShape bpmnElement="plan-timeout" id="BPMNShape_f816c150-89f7-4d3b-ba52-f2410638f34c">
        <dc:Bounds height="80.0" width="100.0" x="372.0" y="78.0"/>
      </bpmndi:BPMNShape>
      <bpmndi:BPMNEdge bpmnElement="sequenceFlow_a4400a1c-50a8-4314-959f-cd4a1eaf1f10" id="BPMNEdge_65679ade-75e8-41b9-aef3-168aa33e7cfc">
        <di:waypoint x="322.0" y="118.0"/>
        <di:waypoint x="372.0" y="118.0"/>
      </bpmndi:BPMNEdge>
      <bpmndi:BPMNShape bpmnElement="endEvent_34811f66-4a17-4424-8620-5efc0bbdaf95" id="BPMNShape_131c432d-c412-4a1c-bc6c-96ebe40b83a8">
        <dc:Bounds height="36.0" width="36.0" x="522.0" y="100.0"/>
      </bpmndi:BPMNShape>
      <bpmndi:BPMNEdge bpmnElement="sequenceFlow_16cf3d78-cc9e-41df-beec-d959a6bcd538" id="BPMNEdge_e7273a75-4fe3-4012-bff8-bd6b2d85d987">
        <di:waypoint x="472.0" y="118.0"/>
        <di:waypoint x="522.0" y="118.0"/>
      </bpmndi:BPMNEdge>
      <bpmndi:BPMNShape bpmnElement="plan-started" id="BPMNShape_6f468d74-1c04-442d-b7d8-397fef2aa3ac">
        <dc:Bounds height="80.0" width="100.0" x="286.0" y="186.0"/>
      </bpmndi:BPMNShape>
      <bpmndi:BPMNEdge bpmnElement="sequenceFlow_fb2a1859-39f8-44d1-883f-36aebfb7324a" id="BPMNEdge_2819fe39-908d-49b5-9e44-4dbd138fa235">
        <di:waypoint x="211.0" y="143.0"/>
        <di:waypoint x="211.0" y="226.0"/>
        <di:waypoint x="286.0" y="226.0"/>
      </bpmndi:BPMNEdge>
      <bpmndi:BPMNShape bpmnElement="debug" id="BPMNShape_a44ca66e-6d46-405a-beb0-0085d4182996">
        <dc:Bounds height="80.0" width="100.0" x="436.0" y="186.0"/>
      </bpmndi:BPMNShape>
      <bpmndi:BPMNEdge bpmnElement="sequenceFlow_ff2c78fb-6538-454b-9e25-6b9498c5c028" id="BPMNEdge_d2cbf2d1-170c-4de8-a57e-af7b6ceb77aa">
        <di:waypoint x="386.0" y="226.0"/>
        <di:waypoint x="436.0" y="226.0"/>
      </bpmndi:BPMNEdge>
      <bpmndi:BPMNShape bpmnElement="plan-ended" id="BPMNShape_173eb8f5-a8be-4f5c-8405-3072331f302d">
        <dc:Bounds height="80.0" width="100.0" x="586.0" y="186.0"/>
      </bpmndi:BPMNShape>
      <bpmndi:BPMNEdge bpmnElement="sequenceFlow_1fb33309-3b14-4023-87c5-9caaeb91e31d" id="BPMNEdge_6b24d478-ea1b-43b6-8d36-a1ec626361fa">
        <di:waypoint x="536.0" y="226.0"/>
        <di:waypoint x="586.0" y="226.0"/>
      </bpmndi:BPMNEdge>
      <bpmndi:BPMNShape bpmnElement="PLAN_END" id="BPMNShape_fb97711c-e31b-4772-a4db-6a6ccc62832c">
        <dc:Bounds height="36.0" width="36.0" x="736.0" y="208.0"/>
      </bpmndi:BPMNShape>
      <bpmndi:BPMNEdge bpmnElement="sequenceFlow_8cf1e434-7c86-4ef1-84f6-667265a62485" id="BPMNEdge_5c6478c5-be8c-4aff-80d6-1d61c4b010b2">
        <di:waypoint x="686.0" y="226.0"/>
        <di:waypoint x="736.0" y="226.0"/>
      </bpmndi:BPMNEdge>
    </bpmndi:BPMNPlane>
  </bpmndi:BPMNDiagram>
</definitions>

Environment

  • OS: MacOS 13.5.1, Java 19
  • Version: zeebe-process-test 8.2.12

@namero999 namero999 added the kind/bug Categorizes issue or PR as related to a bug. label Sep 1, 2023
@korthout
Copy link
Member

korthout commented Sep 6, 2023

Team triage:

  • We acknowledge that this might be a regression
  • Requires the team to reproduce and investigate
  • Regression might exist as a bug in Zeebe, not just in ZPT
  • In any case, regression is already released
  • Impact: Complete Job command is rejected, process instance appears to stay active
  • In that case, it would be a high-severity bug
  • We should also pinpoint in which version this regressed

@korthout
Copy link
Member

Another reproducible example is provided in #893

@namero999
Copy link
Author

Has there been triaging of this issue? We'd like to know if it's a problem on our end of an acknowledged (potentially serious) bug in the testing library or zeebe.

@remcowesterhoud
Copy link
Contributor

Thanks for reaching out again @namero999. I can confirm that this is not an issue in Zeebe. There appears to be bug in the in memory transaction management of this library. I haven't quite pinpointed it yet, but I hope this lowers your concerns.

@remcowesterhoud
Copy link
Contributor

remcowesterhoud commented Oct 10, 2023

Just found the problem and created a PR to fix it. It'll be part of the next patch releases (8.3.1, 8.2.17 and 8.1.18).

@remcowesterhoud remcowesterhoud added area/reliability Relates to reliability severity/high Marks a bug as having a noticeable impact on the user with no known workaround and removed regression labels Oct 10, 2023
@ghost ghost closed this as completed in a917e26 Oct 10, 2023
ghost pushed a commit that referenced this issue Oct 11, 2023
933: Backport 876 to stable/8.2 r=nicpuppa a=remcowesterhoud

#876 

Co-authored-by: Remco Westerhoud <[email protected]>
ghost pushed a commit that referenced this issue Oct 11, 2023
934: Backport 876 to stable/8.1 r=nicpuppa a=remcowesterhoud

#876 

Co-authored-by: Remco Westerhoud <[email protected]>
ghost pushed a commit that referenced this issue Oct 11, 2023
932: Backport 876 stable/8.3 r=nicpuppa a=remcowesterhoud

#876 

Co-authored-by: Remco Westerhoud <[email protected]>
This issue was closed.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
area/reliability Relates to reliability kind/bug Categorizes issue or PR as related to a bug. severity/high Marks a bug as having a noticeable impact on the user with no known workaround support
Projects
None yet
Development

Successfully merging a pull request may close this issue.

3 participants