ReplayStateRandomizedPropertyTest failed on message event subprocess #7778
Assignees
Labels
kind/bug
Categorizes an issue or PR as a bug
kind/flake
Categorizes issue or PR as related to a flaky test
scope/broker
Marks an issue or PR to appear in the broker section of the changelog
version:1.3.4
Marks an issue as being completely or in parts released in 1.3.4
Comments
deepthidevaki
added
the
kind/flake
npepinpe
added
kind/bug
npepinpe
changed the title
|
I tried to reproduce it locally with the given seed. On version The test fails on version
Edit: 🤔 the seed of a different version may result in a different test case. If the process generator changes over the versions then it may create a different process for the same seed. |
|
Let's put aside the issue of the generator versions (which, yeah, we should talk about 😅) - do we suspect this is a real bug that still occurs in 1.2.0? And what would be the impact? |
|
I checked the test case again. It is a bug in the process generator. The event subprocess should be triggered but the process instance passed already all wait states.
|
npepinpe
added
kind/flake
saig0
changed the title
|
Please also look at the info/cases provided in #8266 |
|
I did some more digging into this test. The only way I could reproduce this was by checking out the stable 1.0 branch and use the seeds mentioned in this issue.
Since it's been a while since this specific issue occurred, and the ones of Nico and Ole are not reproducible (and don't seem to be flaky), there's not much else I can do. If this issue occurs again we should tackle it sooner so we won't have the reproduction challenges. Closing as discussed with @npepinpe |
|
It happened again I think, or at least something quite similar. I've saved the build forever, so please delete it once done: https://ci.zeebe.camunda.cloud/job/camunda-cloud/job/zeebe/job/staging/1517/ Test and seed: shouldRestoreStateAtEachStepInExecution[TestDataRecord{processSeed=3582242324797643651, executionPathSeed=-4134109124413832626}] – ReplayStateRandomizedPropertyTest(random-testrun) FailuresLogs |
|
EDIT: Please ignore, it works as expected |
|
This is then a bug, correct? Could you evaluate its severity so we can triage it as such? |
|
Ah no sorry, it's clearly Friday. The |
|
Potentially interesting diff is the It feels like we may have a race condition in when we collect the state to compare. If that would be the case, then it makes sense that the replayed state is a bit further than the processing state. It would also mean that this is not a bug, but just a flaky test. The test code seems to match my idea here, because it pauses the engine (which in turn pauses the stream processor), but doesn't verify that the stream processor has fully paused before collecting the state. The pausing of the stream processor just means it will finish processing the current command and then halt when it should normally read the next command. I think this could easily cause problems depending on how much of the command was already processed (resulting in a few state changes, but not yet all), assuming the state collection happens on the same db transaction. Which I think it does (only the query api uses its own separate transaction context). So I see 2 solutions:
I'll end my day here, but just wanted to quickly note my findings. |
|
@korthout lets talk about that next week |
|
Possibly another case: https://ci.zeebe.camunda.cloud/job/camunda-cloud/job/zeebe/job/zell-merge-appender/3/ |
9 tasks
ghost
closed this as
This was referenced Feb 1, 2022
ghost
pushed a commit
that referenced
this issue
Feb 1, 2022
8702: [Backport stable/1.3] Unflake ReplayStateRandomizedPropertyTest r=saig0 a=korthout ## Description <!-- Please explain the changes you made here. --> Backports #8698 to `stable/1.3`. Was manually cherry-picked, but no conflicts had to be resolved. ## Related issues <!-- Which issues are closed by this PR or are related --> closes #7778 Co-authored-by: Nico Korthout <nico.korthout@camunda.com> Co-authored-by: Nico Korthout <korthout@users.noreply.github.com>
ghost
pushed a commit
that referenced
this issue
Feb 1, 2022
8703: [Backport stable/1.2] Unflake ReplayStateRandomizedPropertyTest r=saig0 a=korthout ## Description <!-- Please explain the changes you made here. --> Backports #8698 to `stable/1.2`. Was manually cherry-picked, conflicts needed to be resolved in a9e2096. ## Related issues <!-- Which issues are closed by this PR or are related --> closes #7778 Co-authored-by: Nico Korthout <nico.korthout@camunda.com> Co-authored-by: Nico Korthout <korthout@users.noreply.github.com>
npepinpe
added
the
version:1.3.4
This issue was closed.
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Summary
Failures
shouldRestoreStateAtEachStepInExecution[TestDataRecord{processSeed=5617794289662345787, executionPathSeed=5385515384750986693}] – ReplayStateRandomizedPropertyTest(java-testrun)
Hypotheses
Logs
Logs
Standard Output 11:47:45.280 [Broker-0-LogStream-1] DEBUG io.camunda.zeebe.logstreams - Configured log appender back pressure at partition 1 as AppenderVegasCfg{initialLimit=1024, maxConcurrency=32768, alphaLimit=0.7, betaLimit=0.95}. Window limiting is disabled 11:47:45.344 [Broker-0-StreamProcessor-1] DEBUG io.camunda.zeebe.logstreams - Recovering state of partition 1 from snapshot 11:47:45.344 [Broker-0-StreamProcessor-1] INFO org.camunda.feel.FeelEngine - Engine created. [value-mapper: CompositeValueMapper(List(io.camunda.zeebe.el.impl.feel.MessagePackValueMapper@3d02db8c)), function-provider: io.camunda.zeebe.el.impl.feel.FeelFunctionProvider@33c5225c, clock: io.camunda.zeebe.el.impl.ZeebeFeelEngineClock@37fab0fc, configuration: Configuration(false)] 11:47:45.344 [Broker-0-StreamProcessor-1] INFO io.camunda.zeebe.logstreams - Recovered state of partition 1 from snapshot at position -1 11:47:45.345 [Broker-0-StreamProcessor-1] INFO org.camunda.feel.FeelEngine - Engine created. [value-mapper: CompositeValueMapper(List(io.camunda.zeebe.el.impl.feel.MessagePackValueMapper@72f82867)), function-provider: io.camunda.zeebe.el.impl.feel.FeelFunctionProvider@590d530f, clock: io.camunda.zeebe.el.impl.ZeebeFeelEngineClock@43405db0, configuration: Configuration(false)] 11:47:45.345 [Broker-0-StreamProcessor-1] INFO org.camunda.feel.FeelEngine - Engine created. [value-mapper: CompositeValueMapper(List(io.camunda.zeebe.el.impl.feel.MessagePackValueMapper@215f7874)), function-provider: io.camunda.zeebe.el.impl.feel.FeelFunctionProvider@12d7d728, clock: io.camunda.zeebe.el.impl.ZeebeFeelEngineClock@21f16b56, configuration: Configuration(false)] 11:47:45.345 [Broker-0-StreamProcessor-1] INFO org.camunda.feel.FeelEngine - Engine created. [value-mapper: CompositeValueMapper(List(io.camunda.zeebe.el.impl.feel.MessagePackValueMapper@601d0f05)), function-provider: io.camunda.zeebe.el.impl.feel.FeelFunctionProvider@3a5b57aa, clock: io.camunda.zeebe.el.impl.ZeebeFeelEngineClock@1699a95e, configuration: Configuration(false)] 11:47:45.492 [] INFO io.camunda.zeebe.logstreams - Paused processing for stream stream-1 11:47:45.492 [Broker-0-StreamProcessor-1] DEBUG io.camunda.zeebe.logstreams - Paused processing for partition 1 11:47:45.493 [] DEBUG io.camunda.zeebe.util.buffer - Close stream processor 11:47:45.493 [Broker-0-StreamProcessor-1] DEBUG io.camunda.zeebe.logstreams - Closed stream processor controller Broker-0-StreamProcessor-1. 11:47:45.521 [] INFO io.camunda.zeebe.logstreams - Closed stream stream-1 11:47:45.582 [Broker-0-StreamProcessor-1] DEBUG io.camunda.zeebe.logstreams - Recovering state of partition 1 from snapshot 11:47:45.582 [Broker-0-StreamProcessor-1] INFO org.camunda.feel.FeelEngine - Engine created. [value-mapper: CompositeValueMapper(List(io.camunda.zeebe.el.impl.feel.MessagePackValueMapper@703700f0)), function-provider: io.camunda.zeebe.el.impl.feel.FeelFunctionProvider@7ef0f086, clock: io.camunda.zeebe.el.impl.ZeebeFeelEngineClock@7acf6b80, configuration: Configuration(false)] 11:47:45.583 [Broker-0-StreamProcessor-1] INFO io.camunda.zeebe.logstreams - Recovered state of partition 1 from snapshot at position -1 11:47:45.583 [Broker-0-StreamProcessor-1] INFO org.camunda.feel.FeelEngine - Engine created. [value-mapper: CompositeValueMapper(List(io.camunda.zeebe.el.impl.feel.MessagePackValueMapper@3fcdfabd)), function-provider: io.camunda.zeebe.el.impl.feel.FeelFunctionProvider@77355d34, clock: io.camunda.zeebe.el.impl.ZeebeFeelEngineClock@e38e794, configuration: Configuration(false)] 11:47:45.583 [Broker-0-StreamProcessor-1] INFO org.camunda.feel.FeelEngine - Engine created. [value-mapper: CompositeValueMapper(List(io.camunda.zeebe.el.impl.feel.MessagePackValueMapper@f2a1eb8)), function-provider: io.camunda.zeebe.el.impl.feel.FeelFunctionProvider@5fe205f2, clock: io.camunda.zeebe.el.impl.ZeebeFeelEngineClock@2e32fc7, configuration: Configuration(false)] 11:47:45.584 [Broker-0-StreamProcessor-1] INFO org.camunda.feel.FeelEngine - Engine created. [value-mapper: CompositeValueMapper(List(io.camunda.zeebe.el.impl.feel.MessagePackValueMapper@4b2e7c48)), function-provider: io.camunda.zeebe.el.impl.feel.FeelFunctionProvider@142e744b, clock: io.camunda.zeebe.el.impl.ZeebeFeelEngineClock@5bac3ea9, configuration: Configuration(false)] 11:47:45.585 [Broker-0-StreamProcessor-1] INFO io.camunda.zeebe.processor - Processor starts reprocessing, until last source event position 55 11:47:45.603 [Broker-0-StreamProcessor-1] INFO io.camunda.zeebe.processor - Processor finished reprocessing at event position 57 11:47:45.911 [] INFO io.camunda.zeebe.logstreams - Paused processing for stream stream-1 11:47:45.911 [Broker-0-StreamProcessor-1] DEBUG io.camunda.zeebe.logstreams - Paused processing for partition 1 11:47:45.913 [] DEBUG io.camunda.zeebe.util.buffer - Close stream processor 11:47:45.913 [Broker-0-StreamProcessor-1] DEBUG io.camunda.zeebe.logstreams - Closed stream processor controller Broker-0-StreamProcessor-1. 11:47:45.941 [] INFO io.camunda.zeebe.logstreams - Closed stream stream-1 11:47:46.002 [Broker-0-StreamProcessor-1] DEBUG io.camunda.zeebe.logstreams - Recovering state of partition 1 from snapshot 11:47:46.003 [Broker-0-StreamProcessor-1] INFO org.camunda.feel.FeelEngine - Engine created. [value-mapper: CompositeValueMapper(List(io.camunda.zeebe.el.impl.feel.MessagePackValueMapper@c686370)), function-provider: io.camunda.zeebe.el.impl.feel.FeelFunctionProvider@2af9c8d, clock: io.camunda.zeebe.el.impl.ZeebeFeelEngineClock@6900800, configuration: Configuration(false)] 11:47:46.003 [Broker-0-StreamProcessor-1] INFO io.camunda.zeebe.logstreams - Recovered state of partition 1 from snapshot at position -1 11:47:46.003 [Broker-0-StreamProcessor-1] INFO org.camunda.feel.FeelEngine - Engine created. [value-mapper: CompositeValueMapper(List(io.camunda.zeebe.el.impl.feel.MessagePackValueMapper@439296b6)), function-provider: io.camunda.zeebe.el.impl.feel.FeelFunctionProvider@cae1e57, clock: io.camunda.zeebe.el.impl.ZeebeFeelEngineClock@721bb0bb, configuration: Configuration(false)] 11:47:46.004 [Broker-0-StreamProcessor-1] INFO org.camunda.feel.FeelEngine - Engine created. [value-mapper: CompositeValueMapper(List(io.camunda.zeebe.el.impl.feel.MessagePackValueMapper@74cd66f0)), function-provider: io.camunda.zeebe.el.impl.feel.FeelFunctionProvider@23bd69f9, clock: io.camunda.zeebe.el.impl.ZeebeFeelEngineClock@5f1d977f, configuration: Configuration(false)] 11:47:46.004 [Broker-0-StreamProcessor-1] INFO org.camunda.feel.FeelEngine - Engine created. [value-mapper: CompositeValueMapper(List(io.camunda.zeebe.el.impl.feel.MessagePackValueMapper@702c7a4f)), function-provider: io.camunda.zeebe.el.impl.feel.FeelFunctionProvider@6fc9685c, clock: io.camunda.zeebe.el.impl.ZeebeFeelEngineClock@27f336fd, configuration: Configuration(false)] 11:47:46.005 [Broker-0-StreamProcessor-1] INFO io.camunda.zeebe.processor - Processor starts reprocessing, until last source event position 73 11:47:46.022 [Broker-0-StreamProcessor-1] INFO io.camunda.zeebe.processor - Processor finished reprocessing at event position 74 11:47:46.330 [] INFO io.camunda.zeebe.logstreams - Paused processing for stream stream-1 11:47:46.330 [Broker-0-StreamProcessor-1] DEBUG io.camunda.zeebe.logstreams - Paused processing for partition 1 11:47:46.331 [] DEBUG io.camunda.zeebe.util.buffer - Close stream processor 11:47:46.331 [Broker-0-StreamProcessor-1] DEBUG io.camunda.zeebe.logstreams - Closed stream processor controller Broker-0-StreamProcessor-1. 11:47:46.359 [] INFO io.camunda.zeebe.logstreams - Closed stream stream-1 11:47:46.419 [Broker-0-StreamProcessor-1] DEBUG io.camunda.zeebe.logstreams - Recovering state of partition 1 from snapshot 11:47:46.420 [Broker-0-StreamProcessor-1] INFO org.camunda.feel.FeelEngine - Engine created. [value-mapper: CompositeValueMapper(List(io.camunda.zeebe.el.impl.feel.MessagePackValueMapper@63f3147)), function-provider: io.camunda.zeebe.el.impl.feel.FeelFunctionProvider@8f8cff0, clock: io.camunda.zeebe.el.impl.ZeebeFeelEngineClock@cc75a37, configuration: Configuration(false)] 11:47:46.420 [Broker-0-StreamProcessor-1] INFO io.camunda.zeebe.logstreams - Recovered state of partition 1 from snapshot at position -1 11:47:46.421 [Broker-0-StreamProcessor-1] INFO org.camunda.feel.FeelEngine - Engine created. [value-mapper: CompositeValueMapper(List(io.camunda.zeebe.el.impl.feel.MessagePackValueMapper@49c5c5cb)), function-provider: io.camunda.zeebe.el.impl.feel.FeelFunctionProvider@368f60bd, clock: io.camunda.zeebe.el.impl.ZeebeFeelEngineClock@7846aed3, configuration: Configuration(false)] 11:47:46.421 [Broker-0-StreamProcessor-1] INFO org.camunda.feel.FeelEngine - Engine created. [value-mapper: CompositeValueMapper(List(io.camunda.zeebe.el.impl.feel.MessagePackValueMapper@4ee6550e)), function-provider: io.camunda.zeebe.el.impl.feel.FeelFunctionProvider@29ea3a84, clock: io.camunda.zeebe.el.impl.ZeebeFeelEngineClock@642d3d8c, configuration: Configuration(false)] 11:47:46.421 [Broker-0-StreamProcessor-1] INFO org.camunda.feel.FeelEngine - Engine created. [value-mapper: CompositeValueMapper(List(io.camunda.zeebe.el.impl.feel.MessagePackValueMapper@295037ec)), function-provider: io.camunda.zeebe.el.impl.feel.FeelFunctionProvider@55e259ed, clock: io.camunda.zeebe.el.impl.ZeebeFeelEngineClock@2da467cf, configuration: Configuration(false)] 11:47:46.422 [Broker-0-StreamProcessor-1] INFO io.camunda.zeebe.processor - Processor starts reprocessing, until last source event position 97 11:47:46.442 [Broker-0-StreamProcessor-1] INFO io.camunda.zeebe.processor - Processor finished reprocessing at event position 101 11:47:46.746 [] INFO io.camunda.zeebe.logstreams - Paused processing for stream stream-1 11:47:46.746 [Broker-0-StreamProcessor-1] DEBUG io.camunda.zeebe.logstreams - Paused processing for partition 1 11:47:46.747 [] DEBUG io.camunda.zeebe.util.buffer - Close stream processor 11:47:46.748 [Broker-0-StreamProcessor-1] DEBUG io.camunda.zeebe.logstreams - Closed stream processor controller Broker-0-StreamProcessor-1. 11:47:46.775 [] INFO io.camunda.zeebe.logstreams - Closed stream stream-1 11:47:46.836 [Broker-0-StreamProcessor-1] DEBUG io.camunda.zeebe.logstreams - Recovering state of partition 1 from snapshot 11:47:46.836 [Broker-0-StreamProcessor-1] INFO org.camunda.feel.FeelEngine - Engine created. [value-mapper: CompositeValueMapper(List(io.camunda.zeebe.el.impl.feel.MessagePackValueMapper@1a8d7ca)), function-provider: io.camunda.zeebe.el.impl.feel.FeelFunctionProvider@f6f298f, clock: io.camunda.zeebe.el.impl.ZeebeFeelEngineClock@b50bcba, configuration: Configuration(false)] 11:47:46.837 [Broker-0-StreamProcessor-1] INFO io.camunda.zeebe.logstreams - Recovered state of partition 1 from snapshot at position -1 11:47:46.837 [Broker-0-StreamProcessor-1] INFO org.camunda.feel.FeelEngine - Engine created. [value-mapper: CompositeValueMapper(List(io.camunda.zeebe.el.impl.feel.MessagePackValueMapper@4e5223b4)), function-provider: io.camunda.zeebe.el.impl.feel.FeelFunctionProvider@903ab33, clock: io.camunda.zeebe.el.impl.ZeebeFeelEngineClock@7fd6c8cd, configuration: Configuration(false)] 11:47:46.838 [Broker-0-StreamProcessor-1] INFO org.camunda.feel.FeelEngine - Engine created. [value-mapper: CompositeValueMapper(List(io.camunda.zeebe.el.impl.feel.MessagePackValueMapper@716d1ee1)), function-provider: io.camunda.zeebe.el.impl.feel.FeelFunctionProvider@2e7ddcfb, clock: io.camunda.zeebe.el.impl.ZeebeFeelEngineClock@3ab3b034, configuration: Configuration(false)] 11:47:46.838 [Broker-0-StreamProcessor-1] INFO org.camunda.feel.FeelEngine - Engine created. [value-mapper: CompositeValueMapper(List(io.camunda.zeebe.el.impl.feel.MessagePackValueMapper@73ea970f)), function-provider: io.camunda.zeebe.el.impl.feel.FeelFunctionProvider@6a691585, clock: io.camunda.zeebe.el.impl.ZeebeFeelEngineClock@2a338637, configuration: Configuration(false)] 11:47:46.839 [Broker-0-StreamProcessor-1] INFO io.camunda.zeebe.processor - Processor starts reprocessing, until last source event position 97 11:47:46.859 [Broker-0-StreamProcessor-1] INFO io.camunda.zeebe.processor - Processor finished reprocessing at event position 101 11:47:47.163 [] INFO io.camunda.zeebe.logstreams - Paused processing for stream stream-1 11:47:47.164 [Broker-0-StreamProcessor-1] DEBUG io.camunda.zeebe.logstreams - Paused processing for partition 1 11:47:47.165 [] DEBUG io.camunda.zeebe.util.buffer - Close stream processor 11:47:47.165 [Broker-0-StreamProcessor-1] DEBUG io.camunda.zeebe.logstreams - Closed stream processor controller Broker-0-StreamProcessor-1. 11:47:47.193 [] INFO io.camunda.zeebe.logstreams - Closed stream stream-1 11:47:47.254 [Broker-0-StreamProcessor-1] DEBUG io.camunda.zeebe.logstreams - Recovering state of partition 1 from snapshot 11:47:47.255 [Broker-0-StreamProcessor-1] INFO org.camunda.feel.FeelEngine - Engine created. [value-mapper: CompositeValueMapper(List(io.camunda.zeebe.el.impl.feel.MessagePackValueMapper@444fe643)), function-provider: io.camunda.zeebe.el.impl.feel.FeelFunctionProvider@4a8800ba, clock: io.camunda.zeebe.el.impl.ZeebeFeelEngineClock@4eb78d33, configuration: Configuration(false)] 11:47:47.255 [Broker-0-StreamProcessor-1] INFO io.camunda.zeebe.logstreams - Recovered state of partition 1 from snapshot at position -1 11:47:47.256 [Broker-0-StreamProcessor-1] INFO org.camunda.feel.FeelEngine - Engine created. [value-mapper: CompositeValueMapper(List(io.camunda.zeebe.el.impl.feel.MessagePackValueMapper@bb50a81)), function-provider: io.camunda.zeebe.el.impl.feel.FeelFunctionProvider@3073884a, clock: io.camunda.zeebe.el.impl.ZeebeFeelEngineClock@3af4c32e, configuration: Configuration(false)] 11:47:47.256 [Broker-0-StreamProcessor-1] INFO org.camunda.feel.FeelEngine - Engine created. [value-mapper: CompositeValueMapper(List(io.camunda.zeebe.el.impl.feel.MessagePackValueMapper@48d81f56)), function-provider: io.camunda.zeebe.el.impl.feel.FeelFunctionProvider@6b9af5ce, clock: io.camunda.zeebe.el.impl.ZeebeFeelEngineClock@4787012f, configuration: Configuration(false)] 11:47:47.256 [Broker-0-StreamProcessor-1] INFO org.camunda.feel.FeelEngine - Engine created. [value-mapper: CompositeValueMapper(List(io.camunda.zeebe.el.impl.feel.MessagePackValueMapper@5b764742)), function-provider: io.camunda.zeebe.el.impl.feel.FeelFunctionProvider@53dcd1d5, clock: io.camunda.zeebe.el.impl.ZeebeFeelEngineClock@6fd46ae5, configuration: Configuration(false)] 11:47:47.257 [Broker-0-StreamProcessor-1] INFO io.camunda.zeebe.processor - Processor starts reprocessing, until last source event position 97 11:47:47.276 [Broker-0-StreamProcessor-1] INFO io.camunda.zeebe.processor - Processor finished reprocessing at event position 101 11:47:47.584 [] INFO io.camunda.zeebe.logstreams - Paused processing for stream stream-1 11:47:47.584 [Broker-0-StreamProcessor-1] DEBUG io.camunda.zeebe.logstreams - Paused processing for partition 1 11:47:47.585 [] DEBUG io.camunda.zeebe.util.buffer - Close stream processor 11:47:47.585 [Broker-0-StreamProcessor-1] DEBUG io.camunda.zeebe.logstreams - Closed stream processor controller Broker-0-StreamProcessor-1. 11:47:47.613 [] INFO io.camunda.zeebe.logstreams - Closed stream stream-1 11:47:47.673 [Broker-0-StreamProcessor-1] DEBUG io.camunda.zeebe.logstreams - Recovering state of partition 1 from snapshot 11:47:47.673 [Broker-0-StreamProcessor-1] INFO org.camunda.feel.FeelEngine - Engine created. [value-mapper: CompositeValueMapper(List(io.camunda.zeebe.el.impl.feel.MessagePackValueMapper@157810bb)), function-provider: io.camunda.zeebe.el.impl.feel.FeelFunctionProvider@1e46bdf5, clock: io.camunda.zeebe.el.impl.ZeebeFeelEngineClock@16a5bfe5, configuration: Configuration(false)] 11:47:47.674 [Broker-0-StreamProcessor-1] INFO io.camunda.zeebe.logstreams - Recovered state of partition 1 from snapshot at position -1 11:47:47.674 [Broker-0-StreamProcessor-1] INFO org.camunda.feel.FeelEngine - Engine created. [value-mapper: CompositeValueMapper(List(io.camunda.zeebe.el.impl.feel.MessagePackValueMapper@4fae9ea7)), function-provider: io.camunda.zeebe.el.impl.feel.FeelFunctionProvider@1a06a221, clock: io.camunda.zeebe.el.impl.ZeebeFeelEngineClock@31041d81, configuration: Configuration(false)] 11:47:47.674 [Broker-0-StreamProcessor-1] INFO org.camunda.feel.FeelEngine - Engine created. [value-mapper: CompositeValueMapper(List(io.camunda.zeebe.el.impl.feel.MessagePackValueMapper@ae5c6d3)), function-provider: io.camunda.zeebe.el.impl.feel.FeelFunctionProvider@31853a8e, clock: io.camunda.zeebe.el.impl.ZeebeFeelEngineClock@1ebd8135, configuration: Configuration(false)] 11:47:47.675 [Broker-0-StreamProcessor-1] INFO org.camunda.feel.FeelEngine - Engine created. [value-mapper: CompositeValueMapper(List(io.camunda.zeebe.el.impl.feel.MessagePackValueMapper@fc47f76)), function-provider: io.camunda.zeebe.el.impl.feel.FeelFunctionProvider@2b33e303, clock: io.camunda.zeebe.el.impl.ZeebeFeelEngineClock@337aeda1, configuration: Configuration(false)] 11:47:47.676 [Broker-0-StreamProcessor-1] INFO io.camunda.zeebe.processor - Processor starts reprocessing, until last source event position 109 11:47:47.696 [Broker-0-StreamProcessor-1] INFO io.camunda.zeebe.processor - Processor finished reprocessing at event position 110 11:47:48.113 [] INFO io.camunda.zeebe.logstreams - Paused processing for stream stream-1 11:47:48.113 [Broker-0-StreamProcessor-1] DEBUG io.camunda.zeebe.logstreams - Paused processing for partition 1 11:47:48.114 [] DEBUG io.camunda.zeebe.util.buffer - Close stream processor 11:47:48.114 [Broker-0-StreamProcessor-1] DEBUG io.camunda.zeebe.logstreams - Closed stream processor controller Broker-0-StreamProcessor-1. 11:47:48.142 [] INFO io.camunda.zeebe.logstreams - Closed stream stream-1 11:47:48.201 [Broker-0-StreamProcessor-1] DEBUG io.camunda.zeebe.logstreams - Recovering state of partition 1 from snapshot 11:47:48.201 [Broker-0-StreamProcessor-1] INFO org.camunda.feel.FeelEngine - Engine created. [value-mapper: CompositeValueMapper(List(io.camunda.zeebe.el.impl.feel.MessagePackValueMapper@1ddbb873)), function-provider: io.camunda.zeebe.el.impl.feel.FeelFunctionProvider@131c45b8, clock: io.camunda.zeebe.el.impl.ZeebeFeelEngineClock@1723d303, configuration: Configuration(false)] 11:47:48.202 [Broker-0-StreamProcessor-1] INFO io.camunda.zeebe.logstreams - Recovered state of partition 1 from snapshot at position -1 11:47:48.202 [Broker-0-StreamProcessor-1] INFO org.camunda.feel.FeelEngine - Engine created. [value-mapper: CompositeValueMapper(List(io.camunda.zeebe.el.impl.feel.MessagePackValueMapper@52214f83)), function-provider: io.camunda.zeebe.el.impl.feel.FeelFunctionProvider@12f96d94, clock: io.camunda.zeebe.el.impl.ZeebeFeelEngineClock@63b9dbf6, configuration: Configuration(false)] 11:47:48.203 [Broker-0-StreamProcessor-1] INFO org.camunda.feel.FeelEngine - Engine created. [value-mapper: CompositeValueMapper(List(io.camunda.zeebe.el.impl.feel.MessagePackValueMapper@6a8ba749)), function-provider: io.camunda.zeebe.el.impl.feel.FeelFunctionProvider@320eb0cc, clock: io.camunda.zeebe.el.impl.ZeebeFeelEngineClock@6b42eed4, configuration: Configuration(false)] 11:47:48.203 [Broker-0-StreamProcessor-1] INFO org.camunda.feel.FeelEngine - Engine created. [value-mapper: CompositeValueMapper(List(io.camunda.zeebe.el.impl.feel.MessagePackValueMapper@4689fe21)), function-provider: io.camunda.zeebe.el.impl.feel.FeelFunctionProvider@718fa856, clock: io.camunda.zeebe.el.impl.ZeebeFeelEngineClock@3640ee7b, configuration: Configuration(false)] 11:47:48.204 [Broker-0-StreamProcessor-1] INFO io.camunda.zeebe.processor - Processor starts reprocessing, until last source event position 140 11:47:48.226 [Broker-0-StreamProcessor-1] INFO io.camunda.zeebe.processor - Processor finished reprocessing at event position 141 11:47:48.534 [] INFO io.camunda.zeebe.logstreams - Paused processing for stream stream-1 11:47:48.534 [Broker-0-StreamProcessor-1] DEBUG io.camunda.zeebe.logstreams - Paused processing for partition 1 11:47:48.535 [] DEBUG io.camunda.zeebe.util.buffer - Close stream processor 11:47:48.536 [Broker-0-StreamProcessor-1] DEBUG io.camunda.zeebe.logstreams - Closed stream processor controller Broker-0-StreamProcessor-1. 11:47:48.563 [] INFO io.camunda.zeebe.logstreams - Closed stream stream-1 11:47:48.625 [Broker-0-StreamProcessor-1] DEBUG io.camunda.zeebe.logstreams - Recovering state of partition 1 from snapshot 11:47:48.625 [Broker-0-StreamProcessor-1] INFO org.camunda.feel.FeelEngine - Engine created. [value-mapper: CompositeValueMapper(List(io.camunda.zeebe.el.impl.feel.MessagePackValueMapper@3d1e5bea)), function-provider: io.camunda.zeebe.el.impl.feel.FeelFunctionProvider@33d9b239, clock: io.camunda.zeebe.el.impl.ZeebeFeelEngineClock@37e6309a, configuration: Configuration(false)] 11:47:48.626 [Broker-0-StreamProcessor-1] INFO io.camunda.zeebe.logstreams - Recovered state of partition 1 from snapshot at position -1 11:47:48.626 [Broker-0-StreamProcessor-1] INFO org.camunda.feel.FeelEngine - Engine created. [value-mapper: CompositeValueMapper(List(io.camunda.zeebe.el.impl.feel.MessagePackValueMapper@72e4b802)), function-provider: io.camunda.zeebe.el.impl.feel.FeelFunctionProvider@3d6a7cbf, clock: io.camunda.zeebe.el.impl.ZeebeFeelEngineClock@43dc4951, configuration: Configuration(false)] 11:47:48.626 [Broker-0-StreamProcessor-1] INFO org.camunda.feel.FeelEngine - Engine created. [value-mapper: CompositeValueMapper(List(io.camunda.zeebe.el.impl.feel.MessagePackValueMapper@45b8d350)), function-provider: io.camunda.zeebe.el.impl.feel.FeelFunctionProvider@12cb474d, clock: io.camunda.zeebe.el.impl.ZeebeFeelEngineClock@7c2a5e2f, configuration: Configuration(false)] 11:47:48.627 [Broker-0-StreamProcessor-1] INFO org.camunda.feel.FeelEngine - Engine created. [value-mapper: CompositeValueMapper(List(io.camunda.zeebe.el.impl.feel.MessagePackValueMapper@5d9d163a)), function-provider: io.camunda.zeebe.el.impl.feel.FeelFunctionProvider@5ebc7c8a, clock: io.camunda.zeebe.el.impl.ZeebeFeelEngineClock@1685b93f, configuration: Configuration(false)] 11:47:48.628 [Broker-0-StreamProcessor-1] INFO io.camunda.zeebe.processor - Processor starts reprocessing, until last source event position 225 11:47:48.658 [Broker-0-StreamProcessor-1] INFO io.camunda.zeebe.processor - Processor finished reprocessing at event position 226 11:47:48.962 [] INFO io.camunda.zeebe.logstreams - Paused processing for stream stream-1 11:47:48.962 [Broker-0-StreamProcessor-1] DEBUG io.camunda.zeebe.logstreams - Paused processing for partition 1 11:47:48.963 [] DEBUG io.camunda.zeebe.util.buffer - Close stream processor 11:47:48.963 [Broker-0-StreamProcessor-1] DEBUG io.camunda.zeebe.logstreams - Closed stream processor controller Broker-0-StreamProcessor-1. 11:47:48.991 [] INFO io.camunda.zeebe.logstreams - Closed stream stream-1 11:47:49.051 [Broker-0-StreamProcessor-1] DEBUG io.camunda.zeebe.logstreams - Recovering state of partition 1 from snapshot 11:47:49.051 [Broker-0-StreamProcessor-1] INFO org.camunda.feel.FeelEngine - Engine created. [value-mapper: CompositeValueMapper(List(io.camunda.zeebe.el.impl.feel.MessagePackValueMapper@61a60eed)), function-provider: io.camunda.zeebe.el.impl.feel.FeelFunctionProvider@6f61eca9, clock: io.camunda.zeebe.el.impl.ZeebeFeelEngineClock@6b5e659d, configuration: Configuration(false)] 11:47:49.052 [Broker-0-StreamProcessor-1] INFO io.camunda.zeebe.logstreams - Recovered state of partition 1 from snapshot at position -1 11:47:49.052 [Broker-0-StreamProcessor-1] INFO org.camunda.feel.FeelEngine - Engine created. [value-mapper: CompositeValueMapper(List(io.camunda.zeebe.el.impl.feel.MessagePackValueMapper@2e5ce692)), function-provider: io.camunda.zeebe.el.impl.feel.FeelFunctionProvider@7f5c54d2, clock: io.camunda.zeebe.el.impl.ZeebeFeelEngineClock@1f38eb34, configuration: Configuration(false)] 11:47:49.053 [Broker-0-StreamProcessor-1] INFO org.camunda.feel.FeelEngine - Engine created. [value-mapper: CompositeValueMapper(List(io.camunda.zeebe.el.impl.feel.MessagePackValueMapper@7d207c3)), function-provider: io.camunda.zeebe.el.impl.feel.FeelFunctionProvider@4e7319dd, clock: io.camunda.zeebe.el.impl.ZeebeFeelEngineClock@53943e05, configuration: Configuration(false)] 11:47:49.053 [Broker-0-StreamProcessor-1] INFO org.camunda.feel.FeelEngine - Engine created. [value-mapper: CompositeValueMapper(List(io.camunda.zeebe.el.impl.feel.MessagePackValueMapper@bad0e08)), function-provider: io.camunda.zeebe.el.impl.feel.FeelFunctionProvider@1cd6eca1, clock: io.camunda.zeebe.el.impl.ZeebeFeelEngineClock@4a3da317, configuration: Configuration(false)] 11:47:49.054 [Broker-0-StreamProcessor-1] INFO io.camunda.zeebe.processor - Processor starts reprocessing, until last source event position 225 11:47:49.087 [Broker-0-StreamProcessor-1] INFO io.camunda.zeebe.processor - Processor finished reprocessing at event position 226 11:47:54.294 [] INFO io.camunda.zeebe.test - Test failed, following records were exported: 11:47:54.451 [] INFO io.camunda.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 - #001-> -1 -1 - E PROC CREATED - #002->#001 K001 - process.xml->"process_id_28" (version:1) E PROC CREATED - #003->#001 K002 - process.xml->"process..ld_id_0" (version:1) E PROC CREATED - #004->#001 K003 - process.xml->"process..ld_id_4" (version:1) E DEPLOYMENT CREATED - #005->#001 K004 - process.xmlprocess.xmlprocess.xml E DEPLOYMENT FULLY_DISTR - #006->#001 K004 - C PROC_INST_CREATION CREATE - #007-> -1 -1 - new with variables: {=default_correlation_key, boundary_timer_id_15=PT1H, correlationKey=default_correlation_key} E VAR CREATED - #008->#007 K006 - correlationKey->"default_correlation_key" in E VAR CREATED - #009->#007 K007 - boundary_timer_id_15->"PT1H" in E VAR CREATED - #010->#007 K008 - ->"default_correlation_key" in C PROC_INST ACTIVATE - #011->#007 K005 - PROCESS "process_id_28" in E PROC_INST_CREATION CREATED - #012->#007 K009 - new with variables: {=default_correlation_key, boundary_timer_id_15=PT1H, correlationKey=default_correlation_key} E PROC_INST ACTIVATING - #013->#011 K005 - PROCESS "process_id_28" in E PROC_MSG_SUB CREATING - #014->#011 K010 - "message_eventSubProcess_id_29" correlationKey: default_correlation_key @[K005] in (no vars) E PROC_INST ACTIVATED - #015->#011 K005 - PROCESS "process_id_28" in C PROC_INST ACTIVATE - #016->#011 -1 - START_EVENT "id_30" in C MSG_SUB CREATE - #017-> -1 -1 - "message_eventSubProcess_id_29" correlationKey: default_correlation_key @[K005] in (no vars) E PROC_INST ACTIVATING - #018->#016 K011 - START_EVENT "id_30" in E PROC_INST ACTIVATED - #019->#016 K011 - START_EVENT "id_30" in C PROC_INST COMPLETE - #020->#016 K011 - START_EVENT "id_30" in E MSG_SUB CREATED - #021->#017 K012 - "message_eventSubProcess_id_29" correlationKey: default_correlation_key @[K005] in (no vars) C PROC_MSG_SUB CREATE - #022-> -1 -1 - "message_eventSubProcess_id_29" @[K005] in (no vars) E PROC_INST COMPLETING - #023->#020 K011 - START_EVENT "id_30" in E PROC_INST COMPLETED - #024->#020 K011 - START_EVENT "id_30" in E PROC_INST SEQ_FLOW_TAKEN - #025->#020 K013 - SEQUENCE_FLOW "sequenc..68c0308" in C PROC_INST ACTIVATE - #026->#020 K014 - CALL_ACTIVITY "call_ac..ty_id_0" in E PROC_MSG_SUB CREATED - #027->#022 K010 - "message_eventSubProcess_id_29" correlationKey: default_correlation_key @[K005] in (no vars) E PROC_INST ACTIVATING - #028->#026 K014 - CALL_ACTIVITY "call_ac..ty_id_0" in E PROC_INST ACTIVATED - #029->#026 K014 - CALL_ACTIVITY "call_ac..ty_id_0" in C PROC_INST ACTIVATE - #030->#026 K015 - PROCESS "process..ld_id_0" in E VAR CREATED - #031->#026 K016 - boundary_timer_id_15->"PT1H" in E VAR CREATED - #032->#026 K017 - correlationKey->"default_correlation_key" in E VAR CREATED - #033->#026 K018 - ->"default_correlation_key" in E PROC_INST ACTIVATING - #034->#030 K015 - PROCESS "process..ld_id_0" in E PROC_INST ACTIVATED - #035->#030 K015 - PROCESS "process..ld_id_0" in C PROC_INST ACTIVATE - #036->#030 -1 - START_EVENT "startEv..332a443" in E PROC_INST ACTIVATING - #037->#036 K019 - START_EVENT "startEv..332a443" in E PROC_INST ACTIVATED - #038->#036 K019 - START_EVENT "startEv..332a443" in C PROC_INST COMPLETE - #039->#036 K019 - START_EVENT "startEv..332a443" in E PROC_INST COMPLETING - #040->#039 K019 - START_EVENT "startEv..332a443" in E PROC_INST COMPLETED - #041->#039 K019 - START_EVENT "startEv..332a443" in E PROC_INST SEQ_FLOW_TAKEN - #042->#039 K020 - SEQUENCE_FLOW "sequenc..665e725" in C PROC_INST ACTIVATE - #043->#039 K021 - END_EVENT "endEven..9085c15" in E PROC_INST ACTIVATING - #044->#043 K021 - END_EVENT "endEven..9085c15" in E PROC_INST ACTIVATED - #045->#043 K021 - END_EVENT "endEven..9085c15" in E PROC_INST COMPLETING - #046->#043 K021 - END_EVENT "endEven..9085c15" in E PROC_INST COMPLETED - #047->#043 K021 - END_EVENT "endEven..9085c15" in C PROC_INST COMPLETE - #048->#043 K015 - PROCESS "process..ld_id_0" in E PROC_INST COMPLETING - #049->#048 K015 - PROCESS "process..ld_id_0" in E PROC_INST COMPLETED - #050->#048 K015 - PROCESS "process..ld_id_0" in C PROC_INST COMPLETE - #051->#048 K014 - CALL_ACTIVITY "call_ac..ty_id_0" in E PROC_INST COMPLETING - #052->#051 K014 - CALL_ACTIVITY "call_ac..ty_id_0" in E PROC_INST COMPLETED - #053->#051 K014 - CALL_ACTIVITY "call_ac..ty_id_0" in E PROC_INST SEQ_FLOW_TAKEN - #054->#051 K022 - SEQUENCE_FLOW "sequenc..cc77cfc" in C PROC_INST ACTIVATE - #055->#051 K023 - EXCLUSIVE_GATEWAY "fork_id_1" in E PROC_INST ACTIVATING - #056->#055 K023 - EXCLUSIVE_GATEWAY "fork_id_1" in E INCIDENT CREATED - #057->#055 K024 - EXTRACT_VALUE_ERROR failed to evaluate expression 'fork_id_1_branch = "edge_id_10"': no variable found for name 'fork_id_1_branch', @"fork_id_1"[K023] in C DEPLOYMENT CREATE - #001-> -1 -1 - E PROC CREATED - #002->#001 K001 - process.xml->"process_id_28" (version:1) E PROC CREATED - #003->#001 K002 - process.xml->"process..ld_id_0" (version:1) E PROC CREATED - #004->#001 K003 - process.xml->"process..ld_id_4" (version:1) E DEPLOYMENT CREATED - #005->#001 K004 - process.xmlprocess.xmlprocess.xml E DEPLOYMENT FULLY_DISTR - #006->#001 K004 - C PROC_INST_CREATION CREATE - #007-> -1 -1 - new with variables: {=default_correlation_key, boundary_timer_id_15=PT1H, correlationKey=default_correlation_key} E VAR CREATED - #008->#007 K006 - correlationKey->"default_correlation_key" in E VAR CREATED - #009->#007 K007 - boundary_timer_id_15->"PT1H" in E VAR CREATED - #010->#007 K008 - ->"default_correlation_key" in C PROC_INST ACTIVATE - #011->#007 K005 - PROCESS "process_id_28" in E PROC_INST_CREATION CREATED - #012->#007 K009 - new with variables: {=default_correlation_key, boundary_timer_id_15=PT1H, correlationKey=default_correlation_key} E PROC_INST ACTIVATING - #013->#011 K005 - PROCESS "process_id_28" in E PROC_MSG_SUB CREATING - #014->#011 K010 - "message_eventSubProcess_id_29" correlationKey: default_correlation_key @[K005] in (no vars) E PROC_INST ACTIVATED - #015->#011 K005 - PROCESS "process_id_28" in C PROC_INST ACTIVATE - #016->#011 -1 - START_EVENT "id_30" in C MSG_SUB CREATE - #017-> -1 -1 - "message_eventSubProcess_id_29" correlationKey: default_correlation_key @[K005] in (no vars) E PROC_INST ACTIVATING - #018->#016 K011 - START_EVENT "id_30" in E PROC_INST ACTIVATED - #019->#016 K011 - START_EVENT "id_30" in C PROC_INST COMPLETE - #020->#016 K011 - START_EVENT "id_30" in E MSG_SUB CREATED - #021->#017 K012 - "message_eventSubProcess_id_29" correlationKey: default_correlation_key @[K005] in (no vars) C PROC_MSG_SUB CREATE - #022-> -1 -1 - "message_eventSubProcess_id_29" @[K005] in (no vars) E PROC_INST COMPLETING - #023->#020 K011 - START_EVENT "id_30" in E PROC_INST COMPLETED - #024->#020 K011 - START_EVENT "id_30" in E PROC_INST SEQ_FLOW_TAKEN - #025->#020 K013 - SEQUENCE_FLOW "sequenc..68c0308" in C PROC_INST ACTIVATE - #026->#020 K014 - CALL_ACTIVITY "call_ac..ty_id_0" in E PROC_MSG_SUB CREATED - #027->#022 K010 - "message_eventSubProcess_id_29" correlationKey: default_correlation_key @[K005] in (no vars) E PROC_INST ACTIVATING - #028->#026 K014 - CALL_ACTIVITY "call_ac..ty_id_0" in E PROC_INST ACTIVATED - #029->#026 K014 - CALL_ACTIVITY "call_ac..ty_id_0" in C PROC_INST ACTIVATE - #030->#026 K015 - PROCESS "process..ld_id_0" in E VAR CREATED - #031->#026 K016 - boundary_timer_id_15->"PT1H" in E VAR CREATED - #032->#026 K017 - correlationKey->"default_correlation_key" in E VAR CREATED - #033->#026 K018 - ->"default_correlation_key" in E PROC_INST ACTIVATING - #034->#030 K015 - PROCESS "process..ld_id_0" in E PROC_INST ACTIVATED - #035->#030 K015 - PROCESS "process..ld_id_0" in C PROC_INST ACTIVATE - #036->#030 -1 - START_EVENT "startEv..332a443" in E PROC_INST ACTIVATING - #037->#036 K019 - START_EVENT "startEv..332a443" in E PROC_INST ACTIVATED - #038->#036 K019 - START_EVENT "startEv..332a443" in C PROC_INST COMPLETE - #039->#036 K019 - START_EVENT "startEv..332a443" in E PROC_INST COMPLETING - #040->#039 K019 - START_EVENT "startEv..332a443" in E PROC_INST COMPLETED - #041->#039 K019 - START_EVENT "startEv..332a443" in E PROC_INST SEQ_FLOW_TAKEN - #042->#039 K020 - SEQUENCE_FLOW "sequenc..665e725" in C PROC_INST ACTIVATE - #043->#039 K021 - END_EVENT "endEven..9085c15" in E PROC_INST ACTIVATING - #044->#043 K021 - END_EVENT "endEven..9085c15" in E PROC_INST ACTIVATED - #045->#043 K021 - END_EVENT "endEven..9085c15" in E PROC_INST COMPLETING - #046->#043 K021 - END_EVENT "endEven..9085c15" in E PROC_INST COMPLETED - #047->#043 K021 - END_EVENT "endEven..9085c15" in C PROC_INST COMPLETE - #048->#043 K015 - PROCESS "process..ld_id_0" in E PROC_INST COMPLETING - #049->#048 K015 - PROCESS "process..ld_id_0" in E PROC_INST COMPLETED - #050->#048 K015 - PROCESS "process..ld_id_0" in C PROC_INST COMPLETE - #051->#048 K014 - CALL_ACTIVITY "call_ac..ty_id_0" in E PROC_INST COMPLETING - #052->#051 K014 - CALL_ACTIVITY "call_ac..ty_id_0" in E PROC_INST COMPLETED - #053->#051 K014 - CALL_ACTIVITY "call_ac..ty_id_0" in E PROC_INST SEQ_FLOW_TAKEN - #054->#051 K022 - SEQUENCE_FLOW "sequenc..cc77cfc" in C PROC_INST ACTIVATE - #055->#051 K023 - EXCLUSIVE_GATEWAY "fork_id_1" in E PROC_INST ACTIVATING - #056->#055 K023 - EXCLUSIVE_GATEWAY "fork_id_1" in E INCIDENT CREATED - #057->#055 K024 - EXTRACT_VALUE_ERROR failed to evaluate expression 'fork_id_1_branch = "edge_id_10"': no variable found for name 'fork_id_1_branch', @"fork_id_1"[K023] in C VAR_DOCUMENT UPDATE - #058-> -1 -1 - VariableDocumentRecord {"variables":{"fork_id_1_branch":"edge_id_10"},"scopeKey":2251799813685253,"updateSemantics":"LOCAL"} E VAR CREATED - #059->#058 K025 - fork_id_1_branch->"edge_id_10" in E VAR_DOCUMENT UPDATED - #060->#058 K026 - VariableDocumentRecord {"variables":{"fork_id_1_branch":"edge_id_10"},"scopeKey":2251799813685253,"updateSemantics":"LOCAL"} C INCIDENT RESOLVE - #061-> -1 K024 - K024 E INCIDENT RESOLVED - #062->#061 K024 - EXTRACT_VALUE_ERROR failed to evaluate expression 'fork_id_1_branch = "edge_id_10"': no variable found for name 'fork_id_1_branch', @"fork_id_1"[K023] in E PROC_INST ACTIVATED - #063->#061 K023 - EXCLUSIVE_GATEWAY "fork_id_1" in E PROC_INST COMPLETING - #064->#061 K023 - EXCLUSIVE_GATEWAY "fork_id_1" in E PROC_INST COMPLETED - #065->#061 K023 - EXCLUSIVE_GATEWAY "fork_id_1" in E PROC_INST SEQ_FLOW_TAKEN - #066->#061 K027 - SEQUENCE_FLOW "edge_id_10" in C PROC_INST ACTIVATE - #067->#061 K028 - RECEIVE_TASK "id_11" in E PROC_INST ACTIVATING - #068->#067 K028 - RECEIVE_TASK "id_11" in E PROC_MSG_SUB CREATING - #069->#067 K029 - "message_id_11" (inter.) correlationKey: default_correlation_key @[K028] in (no vars) E PROC_INST ACTIVATED - #070->#067 K028 - RECEIVE_TASK "id_11" in C MSG_SUB CREATE - #071-> -1 -1 - "message_id_11" (inter.) correlationKey: default_correlation_key @[K028] in (no vars) E MSG_SUB CREATED - #072->#071 K030 - "message_id_11" (inter.) correlationKey: default_correlation_key @[K028] in (no vars) C PROC_MSG_SUB CREATE - #073-> -1 -1 - "message_id_11" (inter.) @[K028] in (no vars) E PROC_MSG_SUB CREATED - #074->#073 K029 - "message_id_11" (inter.) correlationKey: default_correlation_key @[K028] in (no vars) C DEPLOYMENT CREATE - #001-> -1 -1 - E PROC CREATED - #002->#001 K001 - process.xml->"process_id_28" (version:1) E PROC CREATED - #003->#001 K002 - process.xml->"process..ld_id_0" (version:1) E PROC CREATED - #004->#001 K003 - process.xml->"process..ld_id_4" (version:1) E DEPLOYMENT CREATED - #005->#001 K004 - process.xmlprocess.xmlprocess.xml E DEPLOYMENT FULLY_DISTR - #006->#001 K004 - C PROC_INST_CREATION CREATE - #007-> -1 -1 - new with variables: {=default_correlation_key, boundary_timer_id_15=PT1H, correlationKey=default_correlation_key} E VAR CREATED - #008->#007 K006 - correlationKey->"default_correlation_key" in E VAR CREATED - #009->#007 K007 - boundary_timer_id_15->"PT1H" in E VAR CREATED - #010->#007 K008 - ->"default_correlation_key" in C PROC_INST ACTIVATE - #011->#007 K005 - PROCESS "process_id_28" in E PROC_INST_CREATION CREATED - #012->#007 K009 - new with variables: {=default_correlation_key, boundary_timer_id_15=PT1H, correlationKey=default_correlation_key} E PROC_INST ACTIVATING - #013->#011 K005 - PROCESS "process_id_28" in E PROC_MSG_SUB CREATING - #014->#011 K010 - "message_eventSubProcess_id_29" correlationKey: default_correlation_key @[K005] in (no vars) E PROC_INST ACTIVATED - #015->#011 K005 - PROCESS "process_id_28" in C PROC_INST ACTIVATE - #016->#011 -1 - START_EVENT "id_30" in C MSG_SUB CREATE - #017-> -1 -1 - "message_eventSubProcess_id_29" correlationKey: default_correlation_key @[K005] in (no vars) E PROC_INST ACTIVATING - #018->#016 K011 - START_EVENT "id_30" in E PROC_INST ACTIVATED - #019->#016 K011 - START_EVENT "id_30" in C PROC_INST COMPLETE - #020->#016 K011 - START_EVENT "id_30" in E MSG_SUB CREATED - #021->#017 K012 - "message_eventSubProcess_id_29" correlationKey: default_correlation_key @[K005] in (no vars) C PROC_MSG_SUB CREATE - #022-> -1 -1 - "message_eventSubProcess_id_29" @[K005] in (no vars) E PROC_INST COMPLETING - #023->#020 K011 - START_EVENT "id_30" in E PROC_INST COMPLETED - #024->#020 K011 - START_EVENT "id_30" in E PROC_INST SEQ_FLOW_TAKEN - #025->#020 K013 - SEQUENCE_FLOW "sequenc..68c0308" in C PROC_INST ACTIVATE - #026->#020 K014 - CALL_ACTIVITY "call_ac..ty_id_0" in E PROC_MSG_SUB CREATED - #027->#022 K010 - "message_eventSubProcess_id_29" correlationKey: default_correlation_key @[K005] in (no vars) E PROC_INST ACTIVATING - #028->#026 K014 - CALL_ACTIVITY "call_ac..ty_id_0" in E PROC_INST ACTIVATED - #029->#026 K014 - CALL_ACTIVITY "call_ac..ty_id_0" in C PROC_INST ACTIVATE - #030->#026 K015 - PROCESS "process..ld_id_0" in E VAR CREATED - #031->#026 K016 - boundary_timer_id_15->"PT1H" in E VAR CREATED - #032->#026 K017 - correlationKey->"default_correlation_key" in E VAR CREATED - #033->#026 K018 - ->"default_correlation_key" in E PROC_INST ACTIVATING - #034->#030 K015 - PROCESS "process..ld_id_0" in E PROC_INST ACTIVATED - #035->#030 K015 - PROCESS "process..ld_id_0" in C PROC_INST ACTIVATE - #036->#030 -1 - START_EVENT "startEv..332a443" in E PROC_INST ACTIVATING - #037->#036 K019 - START_EVENT "startEv..332a443" in E PROC_INST ACTIVATED - #038->#036 K019 - START_EVENT "startEv..332a443" in C PROC_INST COMPLETE - #039->#036 K019 - START_EVENT "startEv..332a443" in E PROC_INST COMPLETING - #040->#039 K019 - START_EVENT "startEv..332a443" in E PROC_INST COMPLETED - #041->#039 K019 - START_EVENT "startEv..332a443" in E PROC_INST SEQ_FLOW_TAKEN - #042->#039 K020 - SEQUENCE_FLOW "sequenc..665e725" in C PROC_INST ACTIVATE - #043->#039 K021 - END_EVENT "endEven..9085c15" in E PROC_INST ACTIVATING - #044->#043 K021 - END_EVENT "endEven..9085c15" in E PROC_INST ACTIVATED - #045->#043 K021 - END_EVENT "endEven..9085c15" in E PROC_INST COMPLETING - #046->#043 K021 - END_EVENT "endEven..9085c15" in E PROC_INST COMPLETED - #047->#043 K021 - END_EVENT "endEven..9085c15" in C PROC_INST COMPLETE - #048->#043 K015 - PROCESS "process..ld_id_0" in E PROC_INST COMPLETING - #049->#048 K015 - PROCESS "process..ld_id_0" in E PROC_INST COMPLETED - #050->#048 K015 - PROCESS "process..ld_id_0" in C PROC_INST COMPLETE - #051->#048 K014 - CALL_ACTIVITY "call_ac..ty_id_0" in E PROC_INST COMPLETING - #052->#051 K014 - CALL_ACTIVITY "call_ac..ty_id_0" in E PROC_INST COMPLETED - #053->#051 K014 - CALL_ACTIVITY "call_ac..ty_id_0" in E PROC_INST SEQ_FLOW_TAKEN - #054->#051 K022 - SEQUENCE_FLOW "sequenc..cc77cfc" in C PROC_INST ACTIVATE - #055->#051 K023 - EXCLUSIVE_GATEWAY "fork_id_1" in E PROC_INST ACTIVATING - #056->#055 K023 - EXCLUSIVE_GATEWAY "fork_id_1" in E INCIDENT CREATED - #057->#055 K024 - EXTRACT_VALUE_ERROR failed to evaluate expression 'fork_id_1_branch = "edge_id_10"': no variable found for name 'fork_id_1_branch', @"fork_id_1"[K023] in C VAR_DOCUMENT UPDATE - #058-> -1 -1 - VariableDocumentRecord {"variables":{"fork_id_1_branch":"edge_id_10"},"scopeKey":2251799813685253,"updateSemantics":"LOCAL"} E VAR CREATED - #059->#058 K025 - fork_id_1_branch->"edge_id_10" in E VAR_DOCUMENT UPDATED - #060->#058 K026 - VariableDocumentRecord {"variables":{"fork_id_1_branch":"edge_id_10"},"scopeKey":2251799813685253,"updateSemantics":"LOCAL"} C INCIDENT RESOLVE - #061-> -1 K024 - K024 E INCIDENT RESOLVED - #062->#061 K024 - EXTRACT_VALUE_ERROR failed to evaluate expression 'fork_id_1_branch = "edge_id_10"': no variable found for name 'fork_id_1_branch', @"fork_id_1"[K023] in E PROC_INST ACTIVATED - #063->#061 K023 - EXCLUSIVE_GATEWAY "fork_id_1" in E PROC_INST COMPLETING - #064->#061 K023 - EXCLUSIVE_GATEWAY "fork_id_1" in E PROC_INST COMPLETED - #065->#061 K023 - EXCLUSIVE_GATEWAY "fork_id_1" in E PROC_INST SEQ_FLOW_TAKEN - #066->#061 K027 - SEQUENCE_FLOW "edge_id_10" in C PROC_INST ACTIVATE - #067->#061 K028 - RECEIVE_TASK "id_11" in E PROC_INST ACTIVATING - #068->#067 K028 - RECEIVE_TASK "id_11" in E PROC_MSG_SUB CREATING - #069->#067 K029 - "message_id_11" (inter.) correlationKey: default_correlation_key @[K028] in (no vars) E PROC_INST ACTIVATED - #070->#067 K028 - RECEIVE_TASK "id_11" in C MSG_SUB CREATE - #071-> -1 -1 - "message_id_11" (inter.) correlationKey: default_correlation_key @[K028] in (no vars) E MSG_SUB CREATED - #072->#071 K030 - "message_id_11" (inter.) correlationKey: default_correlation_key @[K028] in (no vars) C PROC_MSG_SUB CREATE - #073-> -1 -1 - "message_id_11" (inter.) @[K028] in (no vars) E PROC_MSG_SUB CREATED - #074->#073 K029 - "message_id_11" (inter.) correlationKey: default_correlation_key @[K028] in (no vars) C MSG PUBLISH - #075-> -1 -1 - "message_id_11" correlationKey: default_correlation_key with variables: {correlationKey=default_correlation_key} E MSG PUBLISHED - #076->#075 K031 - "message_id_11" correlationKey: default_correlation_key with variables: {correlationKey=default_correlation_key} E MSG_SUB CORRELATING - #077->#075 K030 - "message_id_11" (inter.) correlationKey: default_correlation_key @[K028] in with variables: {correlationKey=default_correlation_key} C PROC_MSG_SUB CORRELATE - #078-> -1 -1 - "message_id_11" (inter.) correlationKey: default_correlation_key @[K028] in with variables: {correlationKey=default_correlation_key} E PROC_MSG_SUB CORRELATED - #079->#078 K029 - "message_id_11" (inter.) correlationKey: default_correlation_key @[K028] in with variables: {correlationKey=default_correlation_key} E PROC_EVNT TRIGGERING - #080->#078 K032 - @"id_11"[K028] in with variables: {correlationKey=default_correlation_key} C PROC_INST COMPLETE - #081->#078 K028 - RECEIVE_TASK "id_11" in C MSG_SUB CORRELATE - #082-> -1 -1 - "message_id_11" (inter.) @[K028] in (no vars) E PROC_INST COMPLETING - #083->#081 K028 - RECEIVE_TASK "id_11" in E PROC_INST COMPLETED - #084->#081 K028 - RECEIVE_TASK "id_11" in E PROC_INST SEQ_FLOW_TAKEN - #085->#081 K033 - SEQUENCE_FLOW "sequenc..7c235a2" in C PROC_INST ACTIVATE - #086->#081 K034 - SUB_PROCESS "id_12" in E MSG_SUB CORRELATED - #087->#082 K030 - "message_id_11" (inter.) correlationKey: default_correlation_key @[K028] in with variables: {correlationKey=default_correlation_key} E PROC_INST ACTIVATING - #088->#086 K034 - SUB_PROCESS "id_12" in E PROC_INST ACTIVATED - #089->#086 K034 - SUB_PROCESS "id_12" in C PROC_INST ACTIVATE - #090->#086 -1 - START_EVENT "id_13" in E PROC_INST ACTIVATING - #091->#090 K035 - START_EVENT "id_13" in E PROC_INST ACTIVATED - #092->#090 K035 - START_EVENT "id_13" in C PROC_INST COMPLETE - #093->#090 K035 - START_EVENT "id_13" in E PROC_INST COMPLETING - #094->#093 K035 - START_EVENT "id_13" in E PROC_INST COMPLETED - #095->#093 K035 - START_EVENT "id_13" in E PROC_INST SEQ_FLOW_TAKEN - #096->#093 K036 - SEQUENCE_FLOW "sequenc..9a2988f" in C PROC_INST ACTIVATE - #097->#093 K037 - SERVICE_TASK "id_15" in E PROC_INST ACTIVATING - #098->#097 K037 - SERVICE_TASK "id_15" in E TIMER CREATED - #099->#097 K038 - @"boundar..r_id_15"[K037] in due T12:47:46.231 E JOB CREATED - #100->#097 K039 - K039 "job_id_15" @"id_15"[K037] 3 retries, in (no vars) E PROC_INST ACTIVATED - #101->#097 K037 - SERVICE_TASK "id_15" in C DEPLOYMENT CREATE - #001-> -1 -1 - E PROC CREATED - #002->#001 K001 - process.xml->"process_id_28" (version:1) E PROC CREATED - #003->#001 K002 - process.xml->"process..ld_id_0" (version:1) E PROC CREATED - #004->#001 K003 - process.xml->"process..ld_id_4" (version:1) E DEPLOYMENT CREATED - #005->#001 K004 - process.xmlprocess.xmlprocess.xml E DEPLOYMENT FULLY_DISTR - #006->#001 K004 - C PROC_INST_CREATION CREATE - #007-> -1 -1 - new with variables: {=default_correlation_key, boundary_timer_id_15=PT1H, correlationKey=default_correlation_key} E VAR CREATED - #008->#007 K006 - correlationKey->"default_correlation_key" in E VAR CREATED - #009->#007 K007 - boundary_timer_id_15->"PT1H" in E VAR CREATED - #010->#007 K008 - ->"default_correlation_key" in C PROC_INST ACTIVATE - #011->#007 K005 - PROCESS "process_id_28" in E PROC_INST_CREATION CREATED - #012->#007 K009 - new with variables: {=default_correlation_key, boundary_timer_id_15=PT1H, correlationKey=default_correlation_key} E PROC_INST ACTIVATING - #013->#011 K005 - PROCESS "process_id_28" in E PROC_MSG_SUB CREATING - #014->#011 K010 - "message_eventSubProcess_id_29" correlationKey: default_correlation_key @[K005] in (no vars) E PROC_INST ACTIVATED - #015->#011 K005 - PROCESS "process_id_28" in C PROC_INST ACTIVATE - #016->#011 -1 - START_EVENT "id_30" in C MSG_SUB CREATE - #017-> -1 -1 - "message_eventSubProcess_id_29" correlationKey: default_correlation_key @[K005] in (no vars) E PROC_INST ACTIVATING - #018->#016 K011 - START_EVENT "id_30" in E PROC_INST ACTIVATED - #019->#016 K011 - START_EVENT "id_30" in C PROC_INST COMPLETE - #020->#016 K011 - START_EVENT "id_30" in E MSG_SUB CREATED - #021->#017 K012 - "message_eventSubProcess_id_29" correlationKey: default_correlation_key @[K005] in (no vars) C PROC_MSG_SUB CREATE - #022-> -1 -1 - "message_eventSubProcess_id_29" @[K005] in (no vars) E PROC_INST COMPLETING - #023->#020 K011 - START_EVENT "id_30" in E PROC_INST COMPLETED - #024->#020 K011 - START_EVENT "id_30" in E PROC_INST SEQ_FLOW_TAKEN - #025->#020 K013 - SEQUENCE_FLOW "sequenc..68c0308" in C PROC_INST ACTIVATE - #026->#020 K014 - CALL_ACTIVITY "call_ac..ty_id_0" in E PROC_MSG_SUB CREATED - #027->#022 K010 - "message_eventSubProcess_id_29" correlationKey: default_correlation_key @[K005] in (no vars) E PROC_INST ACTIVATING - #028->#026 K014 - CALL_ACTIVITY "call_ac..ty_id_0" in E PROC_INST ACTIVATED - #029->#026 K014 - CALL_ACTIVITY "call_ac..ty_id_0" in C PROC_INST ACTIVATE - #030->#026 K015 - PROCESS "process..ld_id_0" in E VAR CREATED - #031->#026 K016 - boundary_timer_id_15->"PT1H" in E VAR CREATED - #032->#026 K017 - correlationKey->"default_correlation_key" in E VAR CREATED - #033->#026 K018 - ->"default_correlation_key" in E PROC_INST ACTIVATING - #034->#030 K015 - PROCESS "process..ld_id_0" in E PROC_INST ACTIVATED - #035->#030 K015 - PROCESS "process..ld_id_0" in C PROC_INST ACTIVATE - #036->#030 -1 - START_EVENT "startEv..332a443" in E PROC_INST ACTIVATING - #037->#036 K019 - START_EVENT "startEv..332a443" in E PROC_INST ACTIVATED - #038->#036 K019 - START_EVENT "startEv..332a443" in C PROC_INST COMPLETE - #039->#036 K019 - START_EVENT "startEv..332a443" in E PROC_INST COMPLETING - #040->#039 K019 - START_EVENT "startEv..332a443" in E PROC_INST COMPLETED - #041->#039 K019 - START_EVENT "startEv..332a443" in E PROC_INST SEQ_FLOW_TAKEN - #042->#039 K020 - SEQUENCE_FLOW "sequenc..665e725" in C PROC_INST ACTIVATE - #043->#039 K021 - END_EVENT "endEven..9085c15" in E PROC_INST ACTIVATING - #044->#043 K021 - END_EVENT "endEven..9085c15" in E PROC_INST ACTIVATED - #045->#043 K021 - END_EVENT "endEven..9085c15" in E PROC_INST COMPLETING - #046->#043 K021 - END_EVENT "endEven..9085c15" in E PROC_INST COMPLETED - #047->#043 K021 - END_EVENT "endEven..9085c15" in C PROC_INST COMPLETE - #048->#043 K015 - PROCESS "process..ld_id_0" in E PROC_INST COMPLETING - #049->#048 K015 - PROCESS "process..ld_id_0" in E PROC_INST COMPLETED - #050->#048 K015 - PROCESS "process..ld_id_0" in C PROC_INST COMPLETE - #051->#048 K014 - CALL_ACTIVITY "call_ac..ty_id_0" in E PROC_INST COMPLETING - #052->#051 K014 - CALL_ACTIVITY "call_ac..ty_id_0" in E PROC_INST COMPLETED - #053->#051 K014 - CALL_ACTIVITY "call_ac..ty_id_0" in E PROC_INST SEQ_FLOW_TAKEN - #054->#051 K022 - SEQUENCE_FLOW "sequenc..cc77cfc" inThe text was updated successfully, but these errors were encountered: