Skip to content
New issue

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

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

Already on GitHub? Sign in to your account

Add more abbreviations to the compact record logger #10144

Merged
merged 1 commit into from
Aug 23, 2022

Conversation

korthout
Copy link
Member

Description

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            - #01-> -1  -1 - 
E PROC                   CREATED           - #02->#01 K01 - process.xml -> "process" (version:1)
E DPLY                   CREATED           - #03->#01 K02 - process.xml
E DPLY                   FULLY_DISTRIBUTED - #04->#01 K02 - 
C PROC_INST_CREATION     CREATE            - #05-> -1  -1 - new <process "process"> (default start)  with variables: {x=variable}
E VAR                    CREATED           - #06->#05 K04 - x->"variable" in <process [K03]>
C PROC_INST              ACTIVATE          - #07->#05 K03 - PROCESS "process" in <process "process"[K03]>
E PROC_INST_CREATION     CREATED           - #08->#05 K05 - new <process "process"> (default start)  with variables: {x=variable}
E PROC_INST              ACTIVATING        - #09->#07 K03 - PROCESS "process" in <process "process"[K03]>
E PROC_INST              ACTIVATED         - #10->#07 K03 - PROCESS "process" in <process "process"[K03]>
C PROC_INST              ACTIVATE          - #11->#07  -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            - #01-> -1  -1 - 
E PROC CREATED           - #02->#01 K01 - process.xml -> "process" (version:1)
E DPLY CREATED           - #03->#01 K02 - process.xml
E DPLY FULLY_DISTRIBUTED - #04->#01 K02 - 
C CREA CREATE            - #05-> -1  -1 - new <process "process"> (default start)  with variables: {x=variable}
E VAR  CREATED           - #06->#05 K04 - x->"variable" in <process [K03]>
C PI   ACTIVATE          - #07->#05 K03 - PROCESS "process" in <process "process"[K03]>
E CREA CREATED           - #08->#05 K05 - new <process "process"> (default start)  with variables: {x=variable}
E PI   ACTIVATING        - #09->#07 K03 - PROCESS "process" in <process "process"[K03]>
E PI   ACTIVATED         - #10->#07 K03 - PROCESS "process" in <process "process"[K03]>
C PI   ACTIVATE          - #11->#07  -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

while working on #9663

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 the fix to the last two minor versions. You can trigger a backport by assigning labels (e.g. backport stable/1.3) 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
  • If the PR changes how BPMN processes are validated (e.g. support new BPMN element) then the Camunda modeling team should be informed to adjust the BPMN linting.

Please refer to our review guidelines.

While writing an engine test, I encountered some more unabbreviated
record value types. This adds a few more abbreviations to create a
compacted, easier to read record log.
@korthout korthout marked this pull request as ready for review August 22, 2022 15:37
@korthout korthout requested a review from saig0 August 22, 2022 15:39
@korthout korthout self-assigned this Aug 22, 2022
@github-actions
Copy link
Contributor

Test Results

   848 files  ±    0     848 suites  ±0   1h 36m 31s ⏱️ - 3m 14s
6 296 tests  - 273  6 285 ✔️  - 273  11 💤 ±0  0 ±0 
6 480 runs   - 273  6 469 ✔️  - 273  11 💤 ±0  0 ±0 

Results for commit 4f99311. ± Comparison against base commit f4342f5.

Copy link
Member

@saig0 saig0 left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@korthout LGTM 👍

@saig0
Copy link
Member

saig0 commented Aug 23, 2022

bors merge

@zeebe-bors-camunda
Copy link
Contributor

Build succeeded:

@zeebe-bors-camunda zeebe-bors-camunda bot merged commit c7967f7 into main Aug 23, 2022
@zeebe-bors-camunda zeebe-bors-camunda bot deleted the korthout-more-record-logger-abbreviations branch August 23, 2022 05:44
@backport-action
Copy link
Collaborator

Successfully created backport PR #10148 for stable/1.3.

@backport-action
Copy link
Collaborator

Successfully created backport PR #10149 for stable/8.0.

zeebe-bors-camunda bot added a commit that referenced this pull request Aug 23, 2022
10148: [Backport stable/1.3] Add more abbreviations to the compact record logger r=korthout a=backport-action

# Description
Backport of #10144 to `stable/1.3`.

relates to #999 #999 #9663

Co-authored-by: Nico Korthout <nico.korthout@camunda.com>
zeebe-bors-camunda bot added a commit that referenced this pull request Aug 23, 2022
10149: [Backport stable/8.0] Add more abbreviations to the compact record logger r=korthout a=backport-action

# Description
Backport of #10144 to `stable/8.0`.

relates to #999 #999 #9663

Co-authored-by: Nico Korthout <nico.korthout@camunda.com>
zeebe-bors-camunda bot added a commit that referenced this pull request Aug 24, 2022
10170: Print record timestamp in compact record logger r=korthout a=korthout

## Description

<!-- Please explain the changes you made here. -->
When troubleshooting issues (or writing tests) for Timer related topics, we're often interested in both the Timer record's Duedate, as well as the actual time that the record was written, i.e. the record's Timestamp.

This PR adds the Timestamp to the compact record logger when there are Timer records on the recorded log.

While working on this, I also noticed that the compact record logger's Legend could be improved to only include Partition related info when the partition is actually printed as well (i.e. when there are multiple partitions).

This is another PR in a series of QoL improvements I've recently made to the compact record logger.
- #10156 
- #10144 
- #9885

### 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 K1 - process.xml -> "process" (version:1)
E TIME CREATED           - #3->#1 K3 -  `@"start_1"[-1]`  in <process "K1"[?]> due T15:10:34.329
E DPLY CREATED           - #4->#1 K2 - process.xml
E DPLY FULLY_DISTRIBUTED - #5->#1 K2 - 
```

### After

With Timer records:
```
--------
	[Timestamp] ['C'ommand/'E'event/'R'ejection] [valueType] [intent] - #[position]->#[source record position] 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'
--------
15:28:01 C DPLY CREATE            - #1->-1 -1 - 
15:28:02 E PROC CREATED           - #2->#1 K1 - process.xml -> "process" (version:1)
15:28:02 E TIME CREATED           - #3->#1 K3 -  `@"start_1"[-1]`  in <process "K1"[?]> due T15:28:03.087
15:28:02 E DPLY CREATED           - #4->#1 K2 - process.xml
15:28:02 E DPLY FULLY_DISTRIBUTED - #5->#1 K2 - 
```

Without Timer records:
```
--------
	['C'ommand/'E'event/'R'ejection] [valueType] [intent] - #[position]->#[source record position] 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 - 
```

When there are multiple partitions:
```
--------
	[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'
--------
1 C DPLY CREATE            - #1->-1   -1 - 
1 E PROC CREATED           - #2->#1 P1K1 - process.bpmn -> "shouldR..ecovery" (version:1)
1 E DPLY CREATED           - #3->#1 P1K2 - process.bpmn
1 E DSTR DISTRIBUTING      - #4->#1 P1K2 - on partition 2
1 E DSTR DISTRIBUTING      - #5->#1 P1K2 - on partition 3
1 C DSTR COMPLETE          - #6->-1 P1K2 - on partition 2
1 C DSTR COMPLETE          - #7->-1 P1K2 - on partition 3
1 E DSTR COMPLETED         - #8->#6 P1K2 - on partition 2
1 E DSTR COMPLETED         - #9->#7 P1K2 - on partition 3
1 E DPLY FULLY_DISTRIBUTED - #10->#7 P1K2 - 
2 C DPLY DISTRIBUTE        - #1->-1 P1K2 - process.bpmn
2 E DPLY DISTRIBUTED       - #2->#1 P1K2 - process.bpmn
3 C DPLY DISTRIBUTE        - #1->-1 P1K2 - process.bpmn
3 E DPLY DISTRIBUTED       - #2->#1 P1K2 - process.bpmn
```

## Related issues

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

relates to #10169



Co-authored-by: Nico Korthout <nico.korthout@camunda.com>
zeebe-bors-camunda bot added a commit that referenced this pull request Aug 24, 2022
10176: [Backport stable/8.0] Print record timestamp in compact record logger r=korthout a=backport-action

# Description
Backport of #10170 to `stable/8.0`.

relates to #10156 #10144 #9885 #10169

Co-authored-by: Nico Korthout <nico.korthout@camunda.com>
zeebe-bors-camunda bot added a commit that referenced this pull request Aug 24, 2022
10175: [Backport stable/1.3] Print record timestamp in compact record logger r=korthout a=backport-action

# Description
Backport of #10170 to `stable/1.3`.

relates to #10156 #10144 #9885 #10169

Co-authored-by: Nico Korthout <nico.korthout@camunda.com>
@saig0 saig0 added release/8.0.8 version:1.3.14 Marks an issue as being completely or in parts released in 1.3.14 labels Sep 1, 2022
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
version:1.3.14 Marks an issue as being completely or in parts released in 1.3.14
Projects
None yet
Development

Successfully merging this pull request may close these issues.

None yet

3 participants