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.

Sign up for GitHub

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

Jump to bottom

Cannot recover ID generator state for workflow instance event log #17

Closed
ThorbenLindhauer opened this issue Jun 27, 2016 · 2 comments
Closed

Cannot recover ID generator state for workflow instance event log #17

ThorbenLindhauer opened this issue Jun 27, 2016 · 2 comments
Assignees
@meyerdan

Comments

@ThorbenLindhauer
Copy link
Member

ThorbenLindhauer commented Jun 27, 2016 •
edited by meyerdan
Loading

Implement this properly: https://github.com/camunda-tngp/camunda-tngp/blob/master/broker-core/src/main/java/org/camunda/tngp/broker/wf/runtime/WfInstanceIdReader.java

Core problems:

  • events on log may have different types/formats
  • per event, there may be more than one id-holding property, out of which the largest value must be selected

related to camunda-tngp/tasks#2
@meyerdan meyerdan added the ready label Jun 27, 2016
@ThorbenLindhauer
Copy link
Member Author

Pragmatical solution for now: Set initial id to last position in log.

ThorbenLindhauer added a commit that referenced this issue Sep 21, 2016
@ThorbenLindhauer
fix(broker): log id generator recovery
6ae12b7 
- use the last log position on startup to initialize id generator
- this works since we don't expect to have generated more IDs than bytes
  that were written to the log; all we have to guarantee is that the
  recovered id is greater than the last id generated before broker shutdown
- must be refactored once we have symbolic log positions where the above
  assumption might not hold any longer (see #48)

related to #17
@ThorbenLindhauer ThorbenLindhauer removed their assignment Sep 21, 2016
@meyerdan
Copy link
Member

meyerdan commented Oct 13, 2016 •
edited
Loading

Concept for the future: we will completely remove IdGenerators and replace the concept of "Id" with the log position. Now that we have also relatively fast random access on log positions due to the new block index in the log this is optimal since it also removes the need for additional secondary "id indexes". Moreover since, from the point of view of the broker, we get restoring/recovery of the log position for free (provided by log layer) this burden is also removed from the broker.

zeebe-bors-heroku bot pushed a commit that referenced this issue Dec 17, 2018
@zeebe-bors @dependabot-support
Merge #1793 #1795
529e249 
1793: chore(deps): bump version.sbe from 1.10.0 to 1.10.1 r=menski a=dependabot[bot]

Bumps `version.sbe` from 1.10.0 to 1.10.1.

Updates `sbe-tool` from 1.10.0 to 1.10.1
<details>
<summary>Release notes</summary>

*Sourced from [sbe-tool's releases](https://github.com/real-logic/simple-binary-encoding/releases).*

> ## 1.10.1
> * Warnings clean up in code base.
> * Add OS X to Travis for native build.
> * Fix golang generated codec for metadata attributes. [Issue #620](https://github-redirect.dependabot.com/real-logic/simple-binary-encoding/issues/620).
> * Add `Span` support to generated C# codecs. [PR #589](https://github-redirect.dependabot.com/real-logic/simple-binary-encoding/pull/589).
> * Upgrade to Checkstyle 8.15.
> * Upgrade to Gradle 4.10.3.
> * Upgrade to Agrona 0.9.28.
> 
> Java binaries can be found [here...](http://search.maven.org/#search%7Cga%7C1%7Cg%3A%22uk.co.real-logic%22%20sbe)
</details>
<details>
<summary>Commits</summary>

- [`9b8e9c7`](real-logic/simple-binary-encoding@9b8e9c7) 1.10.1 released
- [`b631e14`](real-logic/simple-binary-encoding@b631e14) Update README.md
- [`2ba6320`](real-logic/simple-binary-encoding@2ba6320) [Java] Add OS X native build.
- [`5b12d7c`](real-logic/simple-binary-encoding@5b12d7c) [Java] Tidy up travis script.
- [`8e91221`](real-logic/simple-binary-encoding@8e91221) Merge pull request [#621](https://github-redirect.dependabot.com/real-logic/simple-binary-encoding/issues/621) from ethanf/ethanf/issue-620
- [`16d875d`](real-logic/simple-binary-encoding@16d875d) [golang] Fix code gen for MetaAttributes. Issue [#620](https://github-redirect.dependabot.com/real-logic/simple-binary-encoding/issues/620).
- [`ad844ad`](real-logic/simple-binary-encoding@ad844ad) [Java] Upgrade to Gradle 4.10.3.
- [`f6a7e26`](real-logic/simple-binary-encoding@f6a7e26) [Java] Fix formatting after merge of PR [#589](https://github-redirect.dependabot.com/real-logic/simple-binary-encoding/issues/589).
- [`69d251f`](real-logic/simple-binary-encoding@69d251f) [Java] Upgrade to Checkstyle 8.15.
- [`d996bfb`](real-logic/simple-binary-encoding@d996bfb) [Java] Warnings tidy up.
- Additional commits viewable in [compare view](real-logic/simple-binary-encoding@1.10.0...1.10.1)
</details>
<br />

Updates `sbe-all` from 1.10.0 to 1.10.1
<details>
<summary>Release notes</summary>

*Sourced from [sbe-all's releases](https://github.com/real-logic/simple-binary-encoding/releases).*

> ## 1.10.1
> * Warnings clean up in code base.
> * Add OS X to Travis for native build.
> * Fix golang generated codec for metadata attributes. [Issue #620](https://github-redirect.dependabot.com/real-logic/simple-binary-encoding/issues/620).
> * Add `Span` support to generated C# codecs. [PR #589](https://github-redirect.dependabot.com/real-logic/simple-binary-encoding/pull/589).
> * Upgrade to Checkstyle 8.15.
> * Upgrade to Gradle 4.10.3.
> * Upgrade to Agrona 0.9.28.
> 
> Java binaries can be found [here...](http://search.maven.org/#search%7Cga%7C1%7Cg%3A%22uk.co.real-logic%22%20sbe)
</details>
<details>
<summary>Commits</summary>

- [`9b8e9c7`](real-logic/simple-binary-encoding@9b8e9c7) 1.10.1 released
- [`b631e14`](real-logic/simple-binary-encoding@b631e14) Update README.md
- [`2ba6320`](real-logic/simple-binary-encoding@2ba6320) [Java] Add OS X native build.
- [`5b12d7c`](real-logic/simple-binary-encoding@5b12d7c) [Java] Tidy up travis script.
- [`8e91221`](real-logic/simple-binary-encoding@8e91221) Merge pull request [#621](https://github-redirect.dependabot.com/real-logic/simple-binary-encoding/issues/621) from ethanf/ethanf/issue-620
- [`16d875d`](real-logic/simple-binary-encoding@16d875d) [golang] Fix code gen for MetaAttributes. Issue [#620](https://github-redirect.dependabot.com/real-logic/simple-binary-encoding/issues/620).
- [`ad844ad`](real-logic/simple-binary-encoding@ad844ad) [Java] Upgrade to Gradle 4.10.3.
- [`f6a7e26`](real-logic/simple-binary-encoding@f6a7e26) [Java] Fix formatting after merge of PR [#589](https://github-redirect.dependabot.com/real-logic/simple-binary-encoding/issues/589).
- [`69d251f`](real-logic/simple-binary-encoding@69d251f) [Java] Upgrade to Checkstyle 8.15.
- [`d996bfb`](real-logic/simple-binary-encoding@d996bfb) [Java] Warnings tidy up.
- Additional commits viewable in [compare view](real-logic/simple-binary-encoding@1.10.0...1.10.1)
</details>
<br />

Dependabot will resolve any conflicts with this PR as long as you don't alter it yourself. You can also trigger a rebase manually by commenting `@dependabot rebase`.

[//]: # (dependabot-automerge-start)
[//]: # (dependabot-automerge-end)

---

<details>
<summary>Dependabot commands and options</summary>
<br />

You can trigger Dependabot actions by commenting on this PR:
- `@dependabot rebase` will rebase this PR
- `@dependabot recreate` will recreate this PR, overwriting any edits that have been made to it
- `@dependabot merge` will merge this PR after your CI passes on it
- `@dependabot cancel merge` will cancel a previously requested merge
- `@dependabot reopen` will reopen this PR if it is closed
- `@dependabot ignore this [patch|minor|major] version` will close this PR and stop Dependabot creating any more for this minor/major version (unless you reopen the PR or upgrade to it yourself)
- `@dependabot ignore this dependency` will close this PR and stop Dependabot creating any more for this dependency (unless you reopen the PR or upgrade to it yourself)
- `@dependabot use these labels` will set the current labels as the default for future PRs for this repo and language
- `@dependabot use these reviewers` will set the current reviewers as the default for future PRs for this repo and language
- `@dependabot use these assignees` will set the current assignees as the default for future PRs for this repo and language
- `@dependabot use this milestone` will set the current milestone as the default for future PRs for this repo and language
- `@dependabot badge me` will comment on this PR with code to add a "Dependabot enabled" badge to your readme

Additionally, you can set the following in your Dependabot [dashboard](https://app.dependabot.com):
- Update frequency (including time of day and day of week)
- Automerge options (never/patch/minor, and dev/runtime dependencies)
- Pull request limits (per update run and/or open at any time)
- Out-of-range updates (receive only lockfile updates, if desired)
- Security updates (receive only security updates, if desired)

Finally, you can contact us by mentioning @dependabot.

</details>

1795: chore(deps): bump jackson-bom from 2.9.7 to 2.9.8 r=menski a=dependabot[bot]

Bumps [jackson-bom](https://github.com/FasterXML/jackson-bom) from 2.9.7 to 2.9.8.
<details>
<summary>Commits</summary>

- [`d49d740`](FasterXML/jackson-bom@d49d740) [maven-release-plugin] prepare release jackson-bom-2.9.8
- [`21ae823`](FasterXML/jackson-bom@21ae823) prepare for 2.9.8 release
- [`77a82d0`](FasterXML/jackson-bom@77a82d0) Reverted some of changes from [#17](https://github-redirect.dependabot.com/FasterXML/jackson-bom/issues/17), until I understand why needed (ignore vers...
- [`7370acd`](FasterXML/jackson-bom@7370acd) Merge pull request [#17](https://github-redirect.dependabot.com/FasterXML/jackson-bom/issues/17) from GedMarc/2.9
- [`c658f90`](FasterXML/jackson-bom@c658f90) Export all packages across modules
- [`ed95e05`](FasterXML/jackson-bom@ed95e05) Update `jackson-parent` to get plugin updates needed for Java 9+ module work ...
- [`ee7306b`](FasterXML/jackson-bom@ee7306b) ...
- [`83d95d9`](FasterXML/jackson-bom@83d95d9) Build Fixes, Versions Controlled
- [`bacf92f`](FasterXML/jackson-bom@bacf92f) Jackson JSON - JPMS versioned POMS
- [`440a9dd`](FasterXML/jackson-bom@440a9dd) ...
- Additional commits viewable in [compare view](FasterXML/jackson-bom@jackson-bom-2.9.7...jackson-bom-2.9.8)
</details>
<br />

[![Dependabot compatibility score](https://api.dependabot.com/badges/compatibility_score?dependency-name=com.fasterxml.jackson:jackson-bom&package-manager=maven&previous-version=2.9.7&new-version=2.9.8)](https://dependabot.com/compatibility-score.html?dependency-name=com.fasterxml.jackson:jackson-bom&package-manager=maven&previous-version=2.9.7&new-version=2.9.8)

Dependabot will resolve any conflicts with this PR as long as you don't alter it yourself. You can also trigger a rebase manually by commenting `@dependabot rebase`.

[//]: # (dependabot-automerge-start)
[//]: # (dependabot-automerge-end)

---

<details>
<summary>Dependabot commands and options</summary>
<br />

You can trigger Dependabot actions by commenting on this PR:
- `@dependabot rebase` will rebase this PR
- `@dependabot recreate` will recreate this PR, overwriting any edits that have been made to it
- `@dependabot merge` will merge this PR after your CI passes on it
- `@dependabot cancel merge` will cancel a previously requested merge
- `@dependabot reopen` will reopen this PR if it is closed
- `@dependabot ignore this [patch|minor|major] version` will close this PR and stop Dependabot creating any more for this minor/major version (unless you reopen the PR or upgrade to it yourself)
- `@dependabot ignore this dependency` will close this PR and stop Dependabot creating any more for this dependency (unless you reopen the PR or upgrade to it yourself)
- `@dependabot use these labels` will set the current labels as the default for future PRs for this repo and language
- `@dependabot use these reviewers` will set the current reviewers as the default for future PRs for this repo and language
- `@dependabot use these assignees` will set the current assignees as the default for future PRs for this repo and language
- `@dependabot use this milestone` will set the current milestone as the default for future PRs for this repo and language
- `@dependabot badge me` will comment on this PR with code to add a "Dependabot enabled" badge to your readme

Additionally, you can set the following in your Dependabot [dashboard](https://app.dependabot.com):
- Update frequency (including time of day and day of week)
- Automerge options (never/patch/minor, and dev/runtime dependencies)
- Pull request limits (per update run and/or open at any time)
- Out-of-range updates (receive only lockfile updates, if desired)
- Security updates (receive only security updates, if desired)

Finally, you can contact us by mentioning @dependabot.

</details>

Co-authored-by: dependabot[bot] <support@dependabot.com>
@sdorokhova sdorokhova mentioned this issue Feb 19, 2020
Closed
@Zelldon Zelldon mentioned this issue Mar 25, 2021
Closed
ghost pushed a commit that referenced this issue Mar 31, 2021
@saig0
merge: #6701
4da5c05 
6701: Improve compact log for rejections and error records r=saig0 a=saig0

## Description

* log rejections in the same way as commands and events
* provide more data for root causing a rejection (e.g. value type, intent, position, etc.)
* add summarize for error records
* shrink the terms with `INSTANCE` -> `INST` and `VARIABLE` -> `VAR`
* remove the term `ELEMENT` completely because it is too verbose and redundant (every activate/activating/activated etc. belongs to elements)

<details><summary>Current output</summary>
<p>

```
07:43:02.648 [] INFO  io.zeebe.test - Compact log representation:
--------
	['C'ommand/'E'event/'R'ejection] [valueType] [intent] - #[position]->#[source record position]  P[partitionId]K[key] - [summary of value]
	P9K999 - key; #999 - record position; "ID" element/process id; @"elementid"/[P9K999] - element with ID and key
	Keys are decomposed into partition id and per partition key (e.g. 2251799813685253 -> P1K005). If single partition, the partition is omitted.
	Long IDs are shortened (e.g. 'startEvent_5d56488e-0570-416c-ba2d-36d2a3acea78' -> 'star..acea78'
--------
C DEPLOYMENT             CREATE           - #1-> -1  -1 - process.xml
E PROC                   CREATED          - #2->#1 K01 - process.xml->"process" (version:1)
E DEPLOYMENT             CREATED          - #3->#1 K02 - process.xml
E DEPLOYMENT             FULLY_DISTR      - #4->#1 K02 - 
C MSG                    PUBLISH          - #5-> -1  -1 - "msg1" correlationKey: order-123 (no vars)
E MSG                    PUBLISHED        - #6->#5 K03 - "msg1" correlationKey: order-123 (no vars)
C PROC_INSTANCE_CREATION CREATE           - #7-> -1  -1 - new <process "process"> with variables: {key=order-123}
E VARIABLE               CREATED          - #8->#7 K05 - key->"order-123" in <process [K04]>
E PROC_INSTANCE          ELMNT_ACTIVATING - #9->#7 K04 - PROCESS "process" in <process "process"[K04]>
E PROC_INSTANCE_CREATION CREATED          - #10->#7 K06 - new <process "process"> with variables: {key=order-123}
E PROC_INSTANCE          ELMNT_ACTIVATED  - #11->#9 K04 - PROCESS "process" in <process "process"[K04]>
E PROC_INSTANCE          ELMNT_ACTIVATING - #12->#11 K07 - START_EVENT "startEv..323d1cb" in <process "process"[K04]>
E PROC_INSTANCE          ELMNT_ACTIVATED  - #13->#12 K07 - START_EVENT "startEv..323d1cb" in <process "process"[K04]>
E PROC_INSTANCE          ELMNT_COMPLETING - #14->#13 K07 - START_EVENT "startEv..323d1cb" in <process "process"[K04]>
E PROC_INSTANCE          ELMNT_COMPLETED  - #15->#14 K07 - START_EVENT "startEv..323d1cb" in <process "process"[K04]>
E PROC_INSTANCE          SEQ_FLOW_TAKEN   - #16->#15 K08 - SEQUENCE_FLOW "sequenc..8cfbcaa" in <process "process"[K04]>
C PROC_INSTANCE          ACTIVATE_ELMNT   - #17->#16 K09 - RECEIVE_TASK "task" in <process "process"[K04]>
E PROC_INSTANCE          ELMNT_ACTIVATING - #18->#17 K09 - RECEIVE_TASK "task" in <process "process"[K04]>
E PROC_MSG_SUB           CREATING         - #19->#17  -1 - "taskMsg" (inter.) correlationKey: order-123 @[K09] in <process "process"[K04]> (no vars)
E PROC_MSG_SUB           CREATING         - #20->#17  -1 - "msg2" (inter.) correlationKey: order-123 @[K09] in <process "process"[K04]> (no vars)
E PROC_MSG_SUB           CREATING         - #21->#17  -1 - "msg1" (inter.) correlationKey: order-123 @[K09] in <process "process"[K04]> (no vars)
E PROC_INSTANCE          ELMNT_ACTIVATED  - #22->#17 K09 - RECEIVE_TASK "task" in <process "process"[K04]>
C MSG_SUB                CREATE           - #23-> -1  -1 - "taskMsg" (inter.) correlationKey: order-123 @[K09] in <process "process"[K04]> (no vars)
C MSG_SUB                CREATE           - #24-> -1  -1 - "msg2" (inter.) correlationKey: order-123 @[K09] in <process "process"[K04]> (no vars)
C MSG_SUB                CREATE           - #25-> -1  -1 - "msg1" (inter.) correlationKey: order-123 @[K09] in <process "process"[K04]> (no vars)
E MSG_SUB                CREATED          - #26->#23 K10 - "taskMsg" (inter.) correlationKey: order-123 @[K09] in <process "process"[K04]> (no vars)
C PROC_MSG_SUB           CREATE           - #27-> -1  -1 - "taskMsg" (inter.) @[K09] in <process ?> (no vars)
E MSG_SUB                CREATED          - #28->#24 K11 - "msg2" (inter.) correlationKey: order-123 @[K09] in <process "process"[K04]> (no vars)
C PROC_MSG_SUB           CREATE           - #29-> -1  -1 - "msg2" (inter.) @[K09] in <process ?> (no vars)
E MSG_SUB                CREATED          - #30->#25 K12 - "msg1" (inter.) correlationKey: order-123 @[K09] in <process "process"[K04]> (no vars)
E MSG_SUB                CORRELATING      - #31->#25 K12 - "msg1" (inter.) correlationKey: order-123 @[K09] in <process "process"[K04]> (no vars)
C PROC_MSG_SUB           CORRELATE        - #32-> -1  -1 - "msg1" (inter.) correlationKey: order-123 @[K09] in <process "process"[K04]> (no vars)
E PROC_MSG_SUB           CREATED          - #33->#27  -1 - "taskMsg" (inter.) @[K09] in <process ?> (no vars)
E PROC_MSG_SUB           CREATED          - #34->#29  -1 - "msg2" (inter.) @[K09] in <process ?> (no vars)
E PROC_MSG_SUB           CORRELATED       - #35->#32  -1 - "msg1" (inter.) correlationKey: order-123 @[K09] in <process "process"[K04]> (no vars)
C PROC_INSTANCE          ACTIVATE_ELMNT   - #36->#32  -1 - RECEIVE_TASK "task" in <process "process"[K04]>
C MSG_SUB                CORRELATE        - #37-> -1  -1 - "msg1" (inter.) @[K09] in <process "process"[K04]> (no vars)
PROCESSING_ERROR Expected to process event 'TypedEventImpl{metadata=RecordMetadata{recordType=COMMAND, intentValue=255, intent=ACTIVATE_ELEMENT, requestStreamId=-2147483648, requestId=-1, protocolVersion=3, valueType=PROCESS_INSTANCE, rejectionType=NULL_VAL, rejectionReason=, brokerVersion=1.0.0}, value={"bpmnProcessId":"process","version":1,"processDefinitionKey":2251799813685249,"processInstanceKey":2251799813685252,"elementId":"task","flowScopeKey":2251799813685252,"bpmnElementType":"RECEIVE_TASK","parentProcessInstanceKey":-1,"parentElementInstanceKey":-1}}' without errors, but exception occurred with message 'Not expected to have an active sequence flow count lower then zero!'.#38->#36  -1 - 
E ERROR                  CREATED          - #39->#36  -1 - ErrorRecord {"stacktrace":"java.lang.IllegalStateException: Not expected to have an active sequence flow count lower then zero!\n\tat io.zeebe.engine.state.instance.ElementInstance.decrementActiveSequenceFlows(ElementInstance.java:168)\n\tat io.zeebe.engine.state.appliers.ProcessInstanceElementActivatingApplier.decrementActiveSequenceFlow(ProcessInstanceElementActivatingApplier.java:108)\n\tat io.zeebe.engine.state.appliers.ProcessInstanceElementActivatingApplier.applyState(ProcessInstanceElementActivatingApplier.java:62)\n\tat io.zeebe.engine.state.appliers.ProcessInstanceElementActivatingApplier.applyState(ProcessInstanceElementActivatingApplier.java:26)\n\tat io.zeebe.engine.state.appliers.EventAppliers.applyState(EventAppliers.java:217)\n\tat io.zeebe.engine.processing.streamprocessor.writers.EventApplyingStateWriter.appendFollowUpEvent(EventApplyingStateWriter.java:49)\n\tat io.zeebe.engine.processing.streamprocessor.writers.EventApplyingStateWriter.appendFollowUpEvent(EventApplyingStateWriter.java:39)\n\tat io.zeebe.engine.processing.bpmn.behavior.BpmnStateTransitionBehavior.transitionTo(BpmnStateTransitionBehavior.java:216)\n\tat io.zeebe.engine.processing.bpmn.behavior.BpmnStateTransitionBehavior.transitionToActivating(BpmnStateTransitionBehavior.java:103)\n\tat io.zeebe.engine.processing.bpmn.BpmnStreamProcessor.processEvent(BpmnStreamProcessor.java:146)\n\tat io.zeebe.engine.processing.bpmn.BpmnStreamProcessor.processRecord(BpmnStreamProcessor.java:134)\n\tat io.zeebe.engine.processing.streamprocessor.TypedRecordProcessor.processRecord(TypedRecordProcessor.java:54)\n\tat io.zeebe.engine.processing.streamprocessor.ProcessingStateMachine.lambda$processInTransaction$3(ProcessingStateMachine.java:296)\n\tat io.zeebe.db.impl.rocksdb.transaction.ZeebeTransaction.run(ZeebeTransaction.java:84)\n\tat io.zeebe.engine.processing.streamprocessor.ProcessingStateMachine.processInTransaction(ProcessingStateMachine.java:286)\n\tat io.zeebe.engine.processing.streamprocessor.ProcessingStateMachine.processEvent(ProcessingStateMachine.java:254)\n\tat io.zeebe.engine.processing.streamprocessor.ProcessingStateMachine.tryToReadNextEvent(ProcessingStateMachine.java:219)\n\tat io.zeebe.engine.processing.streamprocessor.ProcessingStateMachine.readNextEvent(ProcessingStateMachine.java:210)\n\tat io.zeebe.util.sched.ActorJob.invoke(ActorJob.java:73)\n\tat io.zeebe.util.sched.ActorJob.execute(ActorJob.java:39)\n\tat io.zeebe.util.sched.ActorTask.execute(ActorTask.java:122)\n\tat io.zeebe.util.sched.ActorThread.executeCurrentTask(ActorThread.java:94)\n\tat io.zeebe.util.sched.ActorThread.doWork(ActorThread.java:78)\n\tat io.zeebe.util.sched.ActorThread.run(ActorThread.java:191)\n","processInstanceKey":2251799813685252,"exceptionMessage":"Not expected to have an active sequence flow count lower then zero!","errorEventPosition":36}
--------
Decomposed keys (for debugging):
 -1 <-> -1
K01 <-> 2251799813685249
K02 <-> 2251799813685250
K03 <-> 2251799813685251
K04 <-> 2251799813685252
K05 <-> 2251799813685253
K06 <-> 2251799813685254
K07 <-> 2251799813685255
K08 <-> 2251799813685256
K09 <-> 2251799813685257
K10 <-> 2251799813685258
K11 <-> 2251799813685259
K12 <-> 2251799813685260
```

<p>
</details>

<details><summary>Output with the changes</summary>
<p>

```
07:38:03.861 [] INFO  io.zeebe.test - Compact log representation:
--------
	['C'ommand/'E'event/'R'ejection] [valueType] [intent] - #[position]->#[source record position]  P[partitionId]K[key] - [summary of value]
	P9K999 - key; #999 - record position; "ID" element/process id; @"elementid"/[P9K999] - element with ID and key
	Keys are decomposed into partition id and per partition key (e.g. 2251799813685253 -> P1K005). If single partition, the partition is omitted.
	Long IDs are shortened (e.g. 'startEvent_5d56488e-0570-416c-ba2d-36d2a3acea78' -> 'star..acea78'
--------
C DEPLOYMENT         CREATE         - #1-> -1  -1 - process.xml
E PROC               CREATED        - #2->#1 K01 - process.xml->"process" (version:1)
E DEPLOYMENT         CREATED        - #3->#1 K02 - process.xml
E DEPLOYMENT         FULLY_DISTR    - #4->#1 K02 - 
C MSG                PUBLISH        - #5-> -1  -1 - "msg1" correlationKey: order-123 (no vars)
E MSG                PUBLISHED      - #6->#5 K03 - "msg1" correlationKey: order-123 (no vars)
C PROC_INST_CREATION CREATE         - #7-> -1  -1 - new <process "process"> with variables: {key=order-123}
E VAR                CREATED        - #8->#7 K05 - key->"order-123" in <process [K04]>
E PROC_INST          ACTIVATING     - #9->#7 K04 - PROCESS "process" in <process "process"[K04]>
E PROC_INST_CREATION CREATED        - #10->#7 K06 - new <process "process"> with variables: {key=order-123}
E PROC_INST          ACTIVATED      - #11->#9 K04 - PROCESS "process" in <process "process"[K04]>
E PROC_INST          ACTIVATING     - #12->#11 K07 - START_EVENT "startEv..b233ada" in <process "process"[K04]>
E PROC_INST          ACTIVATED      - #13->#12 K07 - START_EVENT "startEv..b233ada" in <process "process"[K04]>
E PROC_INST          COMPLETING     - #14->#13 K07 - START_EVENT "startEv..b233ada" in <process "process"[K04]>
E PROC_INST          COMPLETED      - #15->#14 K07 - START_EVENT "startEv..b233ada" in <process "process"[K04]>
E PROC_INST          SEQ_FLOW_TAKEN - #16->#15 K08 - SEQUENCE_FLOW "sequenc..fb40cc7" in <process "process"[K04]>
C PROC_INST          ACTIVATE       - #17->#16 K09 - RECEIVE_TASK "task" in <process "process"[K04]>
E PROC_INST          ACTIVATING     - #18->#17 K09 - RECEIVE_TASK "task" in <process "process"[K04]>
E PROC_MSG_SUB       CREATING       - #19->#17  -1 - "taskMsg" (inter.) correlationKey: order-123 @[K09] in <process "process"[K04]> (no vars)
E PROC_MSG_SUB       CREATING       - #20->#17  -1 - "msg2" (inter.) correlationKey: order-123 @[K09] in <process "process"[K04]> (no vars)
E PROC_MSG_SUB       CREATING       - #21->#17  -1 - "msg1" (inter.) correlationKey: order-123 @[K09] in <process "process"[K04]> (no vars)
E PROC_INST          ACTIVATED      - #22->#17 K09 - RECEIVE_TASK "task" in <process "process"[K04]>
C MSG_SUB            CREATE         - #23-> -1  -1 - "taskMsg" (inter.) correlationKey: order-123 @[K09] in <process "process"[K04]> (no vars)
C MSG_SUB            CREATE         - #24-> -1  -1 - "msg2" (inter.) correlationKey: order-123 @[K09] in <process "process"[K04]> (no vars)
C MSG_SUB            CREATE         - #25-> -1  -1 - "msg1" (inter.) correlationKey: order-123 @[K09] in <process "process"[K04]> (no vars)
E MSG_SUB            CREATED        - #26->#23 K10 - "taskMsg" (inter.) correlationKey: order-123 @[K09] in <process "process"[K04]> (no vars)
C PROC_MSG_SUB       CREATE         - #27-> -1  -1 - "taskMsg" (inter.) @[K09] in <process ?[K04]> (no vars)
E MSG_SUB            CREATED        - #28->#24 K11 - "msg2" (inter.) correlationKey: order-123 @[K09] in <process "process"[K04]> (no vars)
C PROC_MSG_SUB       CREATE         - #29-> -1  -1 - "msg2" (inter.) @[K09] in <process ?[K04]> (no vars)
E MSG_SUB            CREATED        - #30->#25 K12 - "msg1" (inter.) correlationKey: order-123 @[K09] in <process "process"[K04]> (no vars)
E MSG_SUB            CORRELATING    - #31->#25 K12 - "msg1" (inter.) correlationKey: order-123 @[K09] in <process "process"[K04]> (no vars)
C PROC_MSG_SUB       CORRELATE      - #32-> -1  -1 - "msg1" (inter.) correlationKey: order-123 @[K09] in <process "process"[K04]> (no vars)
E PROC_MSG_SUB       CREATED        - #33->#27  -1 - "taskMsg" (inter.) @[K09] in <process ?[K04]> (no vars)
E PROC_MSG_SUB       CREATED        - #34->#29  -1 - "msg2" (inter.) @[K09] in <process ?[K04]> (no vars)
E PROC_MSG_SUB       CORRELATED     - #35->#32  -1 - "msg1" (inter.) correlationKey: order-123 @[K09] in <process "process"[K04]> (no vars)
C PROC_INST          ACTIVATE       - #36->#32  -1 - RECEIVE_TASK "task" in <process "process"[K04]>
C MSG_SUB            CORRELATE      - #37-> -1  -1 - "msg1" (inter.) @[K09] in <process "process"[K04]> (no vars)
R PROC_INST          ACTIVATE       - #38->#36  -1 - RECEIVE_TASK "task" in <process "process"[K04]> !PROCESSING_ERROR (Expected to process event 'TypedEventImpl{metadata=RecordMetadata{recordType=COMMAND, intentValue=..)
E ERROR              CREATED        - #39->#36  -1 - "Not expected to have an active sequence flow count lower then zero!"  in <process ?[K04]> (java.lang.IllegalStateException: Not expected to have an active sequence flow count lower then zer..)
--------
Decomposed keys (for debugging):
 -1 <-> -1
K01 <-> 2251799813685249
K02 <-> 2251799813685250
K03 <-> 2251799813685251
K04 <-> 2251799813685252
K05 <-> 2251799813685253
K06 <-> 2251799813685254
K07 <-> 2251799813685255
K08 <-> 2251799813685256
K09 <-> 2251799813685257
K10 <-> 2251799813685258
K11 <-> 2251799813685259
K12 <-> 2251799813685260
```

<p>
</details>

_The most changes happened on the last two records._

## Related issues


## Definition of Done

_Not all items need to be done depending on the issue and the pull request._

Code changes:
* [ ] The changes are backwards compatibility with previous versions
* [ ] If it fixes a bug then PRs are created to [backport](https://github.com/zeebe-io/zeebe/compare/stable/0.24...develop?expand=1&template=backport_template.md&title=[Backport%200.24]) the fix to the last two minor versions. You can trigger a backport by assigning labels (e.g. `backport stable/0.25`) to the PR, in case that fails you need to create backports manually.

Testing:
* [ ] There are unit/integration tests that verify all acceptance criterias of the issue
* [ ] New tests are written to ensure backwards compatibility with further versions
* [ ] The behavior is tested manually
* [ ] The change has been verified by a QA run
* [ ] The impact of the changes is verified by a benchmark 

Documentation: 
* [ ] The documentation is updated (e.g. BPMN reference, configuration, examples, get-started guides, etc.)
* [ ] New content is added to the [release announcement](https://drive.google.com/drive/u/0/folders/1DTIeswnEEq-NggJ25rm2BsDjcCQpDape)


Co-authored-by: Philipp Ossler <philipp.ossler@gmail.com>
@Zelldon Zelldon mentioned this issue Apr 17, 2021
Merged
9 tasks
@Zelldon Zelldon mentioned this issue Dec 15, 2021
Closed
ghost pushed a commit that referenced this issue Feb 28, 2022
@saig0
merge: #8843
b3f3837 
8843: test(test-util): summarize DMN records r=saig0 a=saig0

## Description

* extend the compact logger that is mainly used to print the records when a test failed
* display DMN resources of deployment record
* summarize decision requirements and decision records
* summarize decision evaluation records

Before:
```
C DEPLOYMENT            CREATE         - #1-> -1  -1 - 
E DECISION_REQUIREMENTS CREATED        - #2->#1 K01 - DecisionRequirementsRecord {"resource":"PD94bWwgdmVyc2lvbj0iMS4wIiBlbmNvZGluZz0iVVRGLTgiPz4KPG...","decisionRequirementsKey":2251799813685249,"decisionRequirementsId":"force_users","resourceName":"/dmn/drg-force-user.dmn","checksum":"4CVEZphbvJhEHAY8+PoEbw==","decisionRequirementsName":"force_users","decisionRequirementsVersion":1,"namespace":"http://camunda.org/schema/1.0/dmn","duplicate":false}
E DECISION              CREATED        - #3->#1 K02 - DecisionRecord {"version":1,"decisionKey":2251799813685250,"decisionId":"jedi_or_sith","decisionName":"Jedi or Sith","decisionRequirementsKey":2251799813685249,"decisionRequirementsId":"force_users","duplicate":false}
E DECISION              CREATED        - #4->#1 K03 - DecisionRecord {"version":1,"decisionKey":2251799813685251,"decisionId":"force_user","decisionName":"Which force user?","decisionRequirementsKey":2251799813685249,"decisionRequirementsId":"force_users","duplicate":false}
E PROC                  CREATED        - #5->#1 K04 - process.xml -> "process" (version:1)
E DEPLOYMENT            CREATED        - #6->#1 K05 - process.xml
E DEPLOYMENT            FULLY_DISTR    - #7->#1 K05 - 

...

E DECISION_EVALUATION   EVALUATED      - #24->#22 K13 - DecisionEvaluationRecord {"decisionKey":2251799813685251,"decisionId":"force_user","decisionName":"Which force user?","decisionRequirementsKey":2251799813685249,"decisionRequirementsId":"force_users","processDefinitionKey":2251799813685252,"bpmnProcessId":"process","processInstanceKey":2251799813685254,"elementId":"task","evaluatedDecisions":[{"decisionKey":2251799813685250,"decisionId":"jedi_or_sith","decisionName":"Jedi or Sith","evaluatedInputs":[{"inputId":"Input_1","inputName":"Lightsaber color","inputValue":"\"blue\""}],"matchedRules":[{"evaluatedOutputs":[{"outputId":"Output_1","outputName":"jedi_or_sith","outputValue":"\"Jedi\""}],"ruleId":"DecisionRule_0zumznl","ruleIndex":1}],"decisionType":"DECISION_TABLE","decisionOutput":"\"Jedi\""},{"decisionKey":2251799813685251,"decisionId":"force_user","decisionName":"Which force user?","evaluatedInputs":[{"inputId":"InputClause_0qnqj25","inputName":"Jedi or Sith","inputValue":"\"Jedi\""},{"inputId":"InputClause_0k64hys","inputName":"Body height","inputValue":"182"}],"matchedRules":[{"evaluatedOutputs":[{"outputId":"OutputClause_0hhe1yo","outputName":"force_user","outputValue":"\"Obi-Wan Kenobi\""}],"ruleId":"DecisionRule_0uin2hk","ruleIndex":2}],"decisionType":"DECISION_TABLE","decisionOutput":"\"Obi-Wan Kenobi\""}],"decisionOutput":"\"Obi-Wan Kenobi\"","elementInstanceKey":2251799813685260,"decisionVersion":1,"evaluationFailureMessage":"","failedDecisionId":""}
```

After:
```
C DEPLOYMENT         CREATE         - #1-> -1  -1 - 
E DRG                CREATED        - #2->#1 K01 - /dmn/drg-force-user.dmn -> "force_users" (version:1)
E DECISION           CREATED        - #3->#1 K02 - "jedi_or_sith" (version:1) of <drg "force_users"[K01]>
E DECISION           CREATED        - #4->#1 K03 - "force_user" (version:1) of <drg "force_users"[K01]>
E PROC               CREATED        - #5->#1 K04 - process.xml -> "process" (version:1)
E DEPLOYMENT         CREATED        - #6->#1 K05 - process.xml, /dmn/drg-force-user.dmn
E DEPLOYMENT         FULLY_DISTR    - #7->#1 K05 - 

...

E DECISION_EVAL      EVALUATED      - #24->#22 K13 - "Obi-Wan Kenobi" of <decision "force_user"[K03]> in <process "process"[K06]> @"task"[K12]
```

<details>
<summary>Full test output</summary>
<pre>
C DEPLOYMENT         CREATE         - #1-> -1  -1 - 
E DRG                CREATED        - #2->#1 K01 - /dmn/drg-force-user.dmn -> "force_users" (version:1)
E DECISION           CREATED        - #3->#1 K02 - "jedi_or_sith" (version:1) of <drg "force_users"[K01]>
E DECISION           CREATED        - #4->#1 K03 - "force_user" (version:1) of <drg "force_users"[K01]>
E PROC               CREATED        - #5->#1 K04 - process.xml -> "process" (version:1)
E DEPLOYMENT         CREATED        - #6->#1 K05 - process.xml, /dmn/drg-force-user.dmn
E DEPLOYMENT         FULLY_DISTR    - #7->#1 K05 - 
C PROC_INST_CREATION CREATE         - #8-> -1  -1 - new <process "process"> with variables: {lightsaberColor=blue, height=182}
E VAR                CREATED        - #9->#8 K07 - height->182 in <process [K06]>
E VAR                CREATED        - #10->#8 K08 - lightsaberColor->"blue" in <process [K06]>
C PROC_INST          ACTIVATE       - #11->#8 K06 - PROCESS "process" in <process "process"[K06]>
E PROC_INST_CREATION CREATED        - #12->#8 K09 - new <process "process"> with variables: {lightsaberColor=blue, height=182}
E PROC_INST          ACTIVATING     - #13->#11 K06 - PROCESS "process" in <process "process"[K06]>
E PROC_INST          ACTIVATED      - #14->#11 K06 - PROCESS "process" in <process "process"[K06]>
C PROC_INST          ACTIVATE       - #15->#11  -1 - START_EVENT "startEv..29dbbd9" in <process "process"[K06]>
E PROC_INST          ACTIVATING     - #16->#15 K10 - START_EVENT "startEv..29dbbd9" in <process "process"[K06]>
E PROC_INST          ACTIVATED      - #17->#15 K10 - START_EVENT "startEv..29dbbd9" in <process "process"[K06]>
C PROC_INST          COMPLETE       - #18->#15 K10 - START_EVENT "startEv..29dbbd9" in <process "process"[K06]>
E PROC_INST          COMPLETING     - #19->#18 K10 - START_EVENT "startEv..29dbbd9" in <process "process"[K06]>
E PROC_INST          COMPLETED      - #20->#18 K10 - START_EVENT "startEv..29dbbd9" in <process "process"[K06]>
E PROC_INST          SEQ_FLOW_TAKEN - #21->#18 K11 - SEQUENCE_FLOW "sequenc..272f6f6" in <process "process"[K06]>
C PROC_INST          ACTIVATE       - #22->#18 K12 - BUSINESS_RULE_TASK "task" in <process "process"[K06]>
E PROC_INST          ACTIVATING     - #23->#22 K12 - BUSINESS_RULE_TASK "task" in <process "process"[K06]>
E DECISION_EVAL      EVALUATED      - #24->#22 K13 - "Obi-Wan Kenobi" of <decision "force_user"[K03]> in <process "process"[K06]> @"task"[K12]
E PROC_EVNT          TRIGGERING     - #25->#22 K14 -  @"task"[K12] in <process K04[K06]> with variables: {result=Obi-Wan Kenobi}
E PROC_INST          ACTIVATED      - #26->#22 K12 - BUSINESS_RULE_TASK "task" in <process "process"[K06]>
C PROC_INST          COMPLETE       - #27->#22 K12 - BUSINESS_RULE_TASK "task" in <process "process"[K06]>
E PROC_INST          COMPLETING     - #28->#27 K12 - BUSINESS_RULE_TASK "task" in <process "process"[K06]>
E VAR                CREATED        - #29->#27 K15 - result->"Obi-Wan Kenobi" in <process [K06]>
E PROC_INST          COMPLETED      - #30->#27 K12 - BUSINESS_RULE_TASK "task" in <process "process"[K06]>
C PROC_INST          COMPLETE       - #31->#27 K06 - PROCESS "process" in <process "process"[K06]>
E PROC_INST          COMPLETING     - #32->#31 K06 - PROCESS "process" in <process "process"[K06]>
E PROC_INST          COMPLETED      - #33->#31 K06 - PROCESS "process" in <process "process"[K06]>
</pre>
</details>

## Related issues

None.



Co-authored-by: Philipp Ossler <philipp.ossler@gmail.com>
zeebe-bors-camunda bot added a commit that referenced this issue Aug 23, 2022
@zeebe-bors-camunda @korthout
merge: #10144
c7967f7 
10144: Add more abbreviations to the compact record logger r=saig0 a=korthout

## Description

<!-- Please explain the changes you made here. -->

While writing an engine test, I encountered some more unabbreviated record value types. This adds a few more abbreviations to create a compact, and easier-to-read record log.

### Before

```
--------
	[Partition] ['C'ommand/'E'event/'R'ejection] [valueType] [intent] - #[position]->#[source record position]  P[partitionId]K[key] - [summary of value]
	P9K999 - key; #999 - record position; "ID" element/process id; `@"elementid"/[P9K999]` - element with ID and key
	Keys are decomposed into partition id and per partition key (e.g. 2251799813685253 -> P1K005). If single partition, the partition is omitted.
	Long IDs are shortened (e.g. 'startEvent_5d56488e-0570-416c-ba2d-36d2a3acea78' -> 'star..acea78'
--------
C DPLY                   CREATE            - #1-> -1  -1 - 
E PROC                   CREATED           - #2->#1 K01 - process.xml -> "process" (version:1)
E DPLY                   CREATED           - #3->#1 K02 - process.xml
E DPLY                   FULLY_DISTRIBUTED - #4->#1 K02 - 
C PROC_INST_CREATION     CREATE            - #5-> -1  -1 - new <process "process"> (default start)  with variables: {x=variable}
E VAR                    CREATED           - #6->#5 K04 - x->"variable" in <process [K03]>
C PROC_INST              ACTIVATE          - #7->#5 K03 - PROCESS "process" in <process "process"[K03]>
E PROC_INST_CREATION     CREATED           - #8->#5 K05 - new <process "process"> (default start)  with variables: {x=variable}
E PROC_INST              ACTIVATING        - #9->#7 K03 - PROCESS "process" in <process "process"[K03]>
E PROC_INST              ACTIVATED         - #10->#7 K03 - PROCESS "process" in <process "process"[K03]>
C PROC_INST              ACTIVATE          - #11->#7  -1 - START_EVENT "startEv..b44a7b4" in <process "process"[K03]>
C PROC_INST_MODIFICATION MODIFY            - #12-> -1 K03 - ProcessInstanceModificationRecord {"processInstanceKey":2251799813685251,"terminateInstructions":[],"activateInstructions":[{"elementId":"B","ancestorScopeKey":-1,"variableInstructions":[{"elementId":"","variables":{"x":"updated"}}]}]}
E PROC_INST              ACTIVATING        - #13->#11 K06 - START_EVENT "startEv..b44a7b4" in <process "process"[K03]>
E PROC_INST              ACTIVATED         - #14->#11 K06 - START_EVENT "startEv..b44a7b4" in <process "process"[K03]>
C PROC_INST              COMPLETE          - #15->#11 K06 - START_EVENT "startEv..b44a7b4" in <process "process"[K03]>
E VAR                    UPDATED           - #16->#12 K04 - x->"updated" in <process [K03]>
C PROC_INST              ACTIVATE          - #17->#12 K07 - USER_TASK "B" in <process "process"[K03]>
E PROC_INST_MODIFICATION MODIFIED          - #18->#12 K03 - ProcessInstanceModificationRecord {"processInstanceKey":2251799813685251,"terminateInstructions":[],"activateInstructions":[{"elementId":"B","ancestorScopeKey":-1,"variableInstructions":[{"elementId":"","variables":{"x":"updated"}}]}]}
E PROC_INST              COMPLETING        - #19->#15 K06 - START_EVENT "startEv..b44a7b4" in <process "process"[K03]>
E PROC_INST              COMPLETED         - #20->#15 K06 - START_EVENT "startEv..b44a7b4" in <process "process"[K03]>
E PROC_INST              SEQ_FLOW_TAKEN    - #21->#15 K08 - SEQUENCE_FLOW "sequenc..25183c6" in <process "process"[K03]>
C PROC_INST              ACTIVATE          - #22->#15 K09 - USER_TASK "A" in <process "process"[K03]>
E PROC_INST              ACTIVATING        - #23->#17 K07 - USER_TASK "B" in <process "process"[K03]>
E JOB                    CREATED           - #24->#17 K10 - K10 "io.camunda.zeebe:userTask" `@"B"[K07]` 1 retries, in <process "process"[K03]> (no vars)
E PROC_INST              ACTIVATED         - #25->#17 K07 - USER_TASK "B" in <process "process"[K03]>
E PROC_INST              ACTIVATING        - #26->#22 K09 - USER_TASK "A" in <process "process"[K03]>
E JOB                    CREATED           - #27->#22 K11 - K11 "io.camunda.zeebe:userTask" `@"A"[K09]` 1 retries, in <process "process"[K03]> (no vars)
E PROC_INST              ACTIVATED         - #28->#22 K09 - USER_TASK "A" in <process "process"[K03]>
```

### After

```
--------
	[Partition] ['C'ommand/'E'event/'R'ejection] [valueType] [intent] - #[position]->#[source record position]  P[partitionId]K[key] - [summary of value]
	P9K999 - key; #999 - record position; "ID" element/process id; `@"elementid"/[P9K999]` - element with ID and key
	Keys are decomposed into partition id and per partition key (e.g. 2251799813685253 -> P1K005). If single partition, the partition is omitted.
	Long IDs are shortened (e.g. 'startEvent_5d56488e-0570-416c-ba2d-36d2a3acea78' -> 'star..acea78'
--------
C DPLY CREATE            - #1-> -1  -1 - 
E PROC CREATED           - #2->#1 K01 - process.xml -> "process" (version:1)
E DPLY CREATED           - #3->#1 K02 - process.xml
E DPLY FULLY_DISTRIBUTED - #4->#1 K02 - 
C CREA CREATE            - #5-> -1  -1 - new <process "process"> (default start)  with variables: {x=variable}
E VAR  CREATED           - #6->#5 K04 - x->"variable" in <process [K03]>
C PI   ACTIVATE          - #7->#5 K03 - PROCESS "process" in <process "process"[K03]>
E CREA CREATED           - #8->#5 K05 - new <process "process"> (default start)  with variables: {x=variable}
E PI   ACTIVATING        - #9->#7 K03 - PROCESS "process" in <process "process"[K03]>
E PI   ACTIVATED         - #10->#7 K03 - PROCESS "process" in <process "process"[K03]>
C PI   ACTIVATE          - #11->#7  -1 - START_EVENT "startEv..ea8bb20" in <process "process"[K03]>
C MOD  MODIFY            - #12-> -1 K03 - ProcessInstanceModificationRecord {"processInstanceKey":2251799813685251,"terminateInstructions":[],"activateInstructions":[{"elementId":"B","ancestorScopeKey":-1,"variableInstructions":[{"elementId":"","variables":{"x":"updated"}}]}]}
E PI   ACTIVATING        - #13->#11 K06 - START_EVENT "startEv..ea8bb20" in <process "process"[K03]>
E PI   ACTIVATED         - #14->#11 K06 - START_EVENT "startEv..ea8bb20" in <process "process"[K03]>
C PI   COMPLETE          - #15->#11 K06 - START_EVENT "startEv..ea8bb20" in <process "process"[K03]>
E VAR  UPDATED           - #16->#12 K04 - x->"updated" in <process [K03]>
C PI   ACTIVATE          - #17->#12 K07 - USER_TASK "B" in <process "process"[K03]>
E MOD  MODIFIED          - #18->#12 K03 - ProcessInstanceModificationRecord {"processInstanceKey":2251799813685251,"terminateInstructions":[],"activateInstructions":[{"elementId":"B","ancestorScopeKey":-1,"variableInstructions":[{"elementId":"","variables":{"x":"updated"}}]}]}
E PI   COMPLETING        - #19->#15 K06 - START_EVENT "startEv..ea8bb20" in <process "process"[K03]>
E PI   COMPLETED         - #20->#15 K06 - START_EVENT "startEv..ea8bb20" in <process "process"[K03]>
E PI   SEQ_FLOW_TAKEN    - #21->#15 K08 - SEQUENCE_FLOW "sequenc..d3f792d" in <process "process"[K03]>
C PI   ACTIVATE          - #22->#15 K09 - USER_TASK "A" in <process "process"[K03]>
E PI   ACTIVATING        - #23->#17 K07 - USER_TASK "B" in <process "process"[K03]>
E JOB  CREATED           - #24->#17 K10 - K10 "io.camunda.zeebe:userTask" `@"B"[K07]` 1 retries, in <process "process"[K03]> (no vars)
E PI   ACTIVATED         - #25->#17 K07 - USER_TASK "B" in <process "process"[K03]>
E PI   ACTIVATING        - #26->#22 K09 - USER_TASK "A" in <process "process"[K03]>
E JOB  CREATED           - #27->#22 K11 - K11 "io.camunda.zeebe:userTask" `@"A"[K09]` 1 retries, in <process "process"[K03]> (no vars)
E PI   ACTIVATED         - #28->#22 K09 - USER_TASK "A" in <process "process"[K03]>
```

## Related issues

<!-- Which issues are closed by this PR or are related -->

while working on #9663 



Co-authored-by: Nico Korthout <nico.korthout@camunda.com>
@Zelldon Zelldon mentioned this issue Aug 25, 2022
Closed
@megglos megglos mentioned this issue Dec 1, 2022
Closed
@Zelldon Zelldon mentioned this issue Feb 3, 2023
Merged
14 tasks
zeebe-bors-camunda bot added a commit that referenced this issue May 9, 2023
@zeebe-bors-camunda @remcowesterhoud
merge: #12697
0458119 
12697: Fix flaky `EmbeddedSubProcessTest` r=koevskinikola a=remcowesterhoud

## Description

<!-- Please explain the changes you made here. -->
The test was flaky because it could occur that the messages got published before the subscription were opened. As the messages have no TTL this means they were not getting correlated, as expected.

Log of a failing run:
```
C DPLY         CREATE            - #1-> -1  -1 - 
E PROC         CREATED           - #2->#1 K01 - process.xml -> "process..process" (version:1)
E DPLY         CREATED           - #3->#1 K02 - process.xml
E DPLY         FULLY_DISTRIBUTED - #4->#1 K02 - 
C CREA         CREATE            - #5-> -1  -1 - new <process "process..process"> with variables: {correlationKey=correlationKey}
E VAR          CREATED           - #6->#5 K04 - correlationKey->"correlationKey" in <process [K03]>
C PI           ACTIVATE          - #7->#5 K03 - PROCESS "process..process" in <process "process..process"[K03]>
E CREA         CREATED           - #8->#5 K05 - new <process "process..process"> with variables: {correlationKey=correlationKey}
E PI           ACTIVATING        - #9->#7 K03 - PROCESS "process..process" in <process "process..process"[K03]>
E PI           ACTIVATED         - #10->#7 K03 - PROCESS "process..process" in <process "process..process"[K03]>
C PI           ACTIVATE          - #11->#7  -1 - START_EVENT "startEv..8897acc" in <process "process..process"[K03]>
E PI           ACTIVATING        - #12->#11 K06 - START_EVENT "startEv..8897acc" in <process "process..process"[K03]>
E PI           ACTIVATED         - #13->#11 K06 - START_EVENT "startEv..8897acc" in <process "process..process"[K03]>
C PI           COMPLETE          - #14->#11 K06 - START_EVENT "startEv..8897acc" in <process "process..process"[K03]>
E PI           COMPLETING        - #15->#14 K06 - START_EVENT "startEv..8897acc" in <process "process..process"[K03]>
E PROC_MSG_SUB CREATING          - #16->#14 K07 - "eventSubProcess" (inter.) correlationKey: correlationKey `@[K03]` in <process "process..process"[K03]> (no vars)
E PI           COMPLETED         - #17->#14 K06 - START_EVENT "startEv..8897acc" in <process "process..process"[K03]>
E PI           SEQ_FLOW_TAKEN    - #18->#14 K08 - SEQUENCE_FLOW "sequenc..b7cb1a6" in <process "process..process"[K03]>
C PI           ACTIVATE          - #19->#14 K09 - SUB_PROCESS "subProcess" in <process "process..process"[K03]>
E PI           ACTIVATING        - #20->#19 K09 - SUB_PROCESS "subProcess" in <process "process..process"[K03]>
E PI           ACTIVATED         - #21->#19 K09 - SUB_PROCESS "subProcess" in <process "process..process"[K03]>
C PI           ACTIVATE          - #22->#19  -1 - START_EVENT "startEv..8b12a7c" in <process "process..process"[K03]>
E PI           ACTIVATING        - #23->#22 K10 - START_EVENT "startEv..8b12a7c" in <process "process..process"[K03]>
E PI           ACTIVATED         - #24->#22 K10 - START_EVENT "startEv..8b12a7c" in <process "process..process"[K03]>
C PI           COMPLETE          - #25->#22 K10 - START_EVENT "startEv..8b12a7c" in <process "process..process"[K03]>
E PI           COMPLETING        - #26->#25 K10 - START_EVENT "startEv..8b12a7c" in <process "process..process"[K03]>
E PROC_MSG_SUB CREATING          - #27->#25 K11 - "boundary" (inter.) correlationKey: correlationKey `@[K09]` in <process "process..process"[K03]> (no vars)
E PI           COMPLETED         - #28->#25 K10 - START_EVENT "startEv..8b12a7c" in <process "process..process"[K03]>
E PI           SEQ_FLOW_TAKEN    - #29->#25 K12 - SEQUENCE_FLOW "sequenc..8c72ad0" in <process "process..process"[K03]>
C PI           ACTIVATE          - #30->#25 K13 - SERVICE_TASK "task" in <process "process..process"[K03]>
E PI           ACTIVATING        - #31->#30 K13 - SERVICE_TASK "task" in <process "process..process"[K03]>
E JOB          CREATED           - #32->#30 K14 - K14 "task" `@"task"[K13]` 3 retries, in <process "process..process"[K03]> (no vars)
E PI           ACTIVATED         - #33->#30 K13 - SERVICE_TASK "task" in <process "process..process"[K03]>
C MSG          PUBLISH           - #34-> -1 K01 - "boundary" correlationKey: correlationKey (no vars)
C MSG          PUBLISH           - #35-> -1 K01 - "eventSubProcess" correlationKey: correlationKey (no vars)
E MSG          PUBLISHED         - #36->#34 K15 - "boundary" correlationKey: correlationKey (no vars)
E MSG          EXPIRED           - #37->#34 K15 - "boundary" correlationKey: correlationKey (no vars)
E MSG          PUBLISHED         - #38->#35 K16 - "eventSubProcess" correlationKey: correlationKey (no vars)
E MSG          EXPIRED           - #39->#35 K16 - "eventSubProcess" correlationKey: correlationKey (no vars)
C MSG_SUB      CREATE            - #40-> -1  -1 - "eventSubProcess" (inter.) correlationKey: correlationKey `@[K03]` in <process "process..process"[K03]> (no vars)
C MSG_SUB      CREATE            - #41-> -1  -1 - "boundary" (inter.) correlationKey: correlationKey `@[K09]` in <process "process..process"[K03]> (no vars)
E MSG_SUB      CREATED           - #42->#40 K17 - "eventSubProcess" (inter.) correlationKey: correlationKey `@[K03]` in <process "process..process"[K03]> (no vars)
C PROC_MSG_SUB CREATE            - #43-> -1  -1 - "eventSubProcess" (inter.) `@[K03]` in <process ?[K03]> (no vars)
E MSG_SUB      CREATED           - #44->#41 K18 - "boundary" (inter.) correlationKey: correlationKey `@[K09]` in <process "process..process"[K03]> (no vars)
C PROC_MSG_SUB CREATE            - #45-> -1  -1 - "boundary" (inter.) `@[K09]` in <process ?[K03]> (no vars)
E PROC_MSG_SUB CREATED           - #46->#43 K07 - "eventSubProcess" (inter.) correlationKey: correlationKey `@[K03]` in <process "process..process"[K03]> (no vars)
E PROC_MSG_SUB CREATED           - #47->#45 K11 - "boundary" (inter.) correlationKey: correlationKey `@[K09]` in <process "process..process"[K03]> (no vars)
```

The test isn't really flaky on 8.2+ anymore. This is a result of batch processing that was introduced recently. However, I believe it's still good to fix it on all versions and keep the test aligned across versions.

## Related issues

<!-- Which issues are closed by this PR or are related -->

closes #11844 



Co-authored-by: Remco Westerhoud <remco@westerhoud.nl>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@meyerdan meyerdan

Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@meyerdan @ThorbenLindhauer