From c86fdfc26ec032dafec1819fe863634b38d09b1d Mon Sep 17 00:00:00 2001 From: Philipp Fromme Date: Thu, 26 Mar 2026 10:01:10 +0100 Subject: [PATCH 01/11] fix(log): sort execution log entries by causal order Sort log entries not only by timestamp but also by causal priority when timestamps are equal. This ensures entries appear in a logically correct sequence even when the engine produces identical timestamps for related lifecycle events. Causal ordering is always applied for global status entries and only between related entries (same elementId or identity key) for runtime entries, preserving insertion order for unrelated entries. --- lib/ExecutionLog.js | 139 +++++++- lib/types.ts | 1 + test/ExecutionLog.spec.js | 684 +++++++++++++++++++++++++++++++++++++- 3 files changed, 821 insertions(+), 3 deletions(-) diff --git a/lib/ExecutionLog.js b/lib/ExecutionLog.js index 704136b..a7727f9 100644 --- a/lib/ExecutionLog.js +++ b/lib/ExecutionLog.js @@ -94,6 +94,7 @@ function pickUserTaskData(item, overrides) { return { state: item.state || '', name: item.name, + elementId: item.elementId, userTaskKey: item.userTaskKey, creationDate: item.creationDate, completionDate: item.completionDate, @@ -399,6 +400,125 @@ export function formatElementType(type) { .replace(/\b\w/g, c => c.toUpperCase()); } +/** + * Determine a sort-order priority for an execution log entry so that entries + * sharing the same timestamp are placed in a causally correct sequence. + * + * Priority levels (lower = earlier): + * 0 – deployed status (must precede all other entries) + * 1 – instance-started status (must precede runtime entries) + * 2 – element-instance ACTIVE (element entered before its child + * jobs / tasks / message subscriptions start) + * 3 – start execution listener job CREATED + * 4 – start execution listener job terminal + * 5 – created states: regular job CREATED, user-task CREATED, + * message-subscription CREATED + * 6 – terminal states: regular job completed / failed, + * message-subscription CORRELATED, user-task completed + * 7 – end execution listener job CREATED + * 8 – end execution listener job terminal + * 9 – element-instance terminal (COMPLETED, TERMINATED, …) — element + * exits only after its child items have finished + * 10 – terminal status entries (completed, incident, terminated, + * canceled) — always placed after all runtime entries + * + * @param {ExecutionLogEntry} entry + * + * @returns {number} + */ +export function getEntryOrder(entry) { + if (entry.type === EXECUTION_LOG_ENTRY_TYPE.STATUS) { + if (entry.status === EXECUTION_LOG_ENTRY_STATUS.DEPLOYED) { + return 0; + } + + if (entry.status === EXECUTION_LOG_ENTRY_STATUS.INSTANCE_STARTED) { + return 1; + } + + return 10; + } + + if (entry.type === EXECUTION_LOG_ENTRY_TYPE.ELEMENT_INSTANCE) { + return entry.data.state === 'ACTIVE' ? 2 : 9; + } + + if (entry.type === EXECUTION_LOG_ENTRY_TYPE.JOB) { + const isListener = entry.data.kind === 'EXECUTION_LISTENER'; + + if (isListener && entry.data.listenerEventType === 'START') { + return entry.data.state === 'CREATED' ? 3 : 4; + } + + if (isListener && entry.data.listenerEventType === 'END') { + return entry.data.state === 'CREATED' ? 7 : 8; + } + + return entry.data.state === 'CREATED' ? 5 : 6; + } + + if (entry.type === EXECUTION_LOG_ENTRY_TYPE.USER_TASK) { + return entry.data.state === 'CREATED' ? 5 : 6; + } + + if (entry.type === EXECUTION_LOG_ENTRY_TYPE.MESSAGE_SUBSCRIPTION) { + return entry.data.messageSubscriptionState === 'CREATED' ? 5 : 6; + } + + return 6; +} + +/** + * Check whether two execution log entries belong to the same element + * lifecycle and should therefore be causally ordered when they share a + * timestamp. + * + * Entries are considered related when they share an `elementId` (linking + * element-instance, job, and message-subscription entries for the same BPMN + * element) or, for same-type entries without a common `elementId`, when they + * share an identity key (`jobKey`, `userTaskKey`, or + * `messageSubscriptionKey`). + * + * @param {ExecutionLogEntry} a + * @param {ExecutionLogEntry} b + * + * @returns {boolean} + */ +export function areRelated(a, b) { + const elementIdA = /** @type {{ elementId?: string }} */ (a.data)?.elementId; + const elementIdB = /** @type {{ elementId?: string }} */ (b.data)?.elementId; + + if (elementIdA && elementIdB) { + return elementIdA === elementIdB; + } + + if (a.type === b.type) { + if (a.type === EXECUTION_LOG_ENTRY_TYPE.JOB) { + const aData = /** @type {ExecutionLogJobData} */ (a.data); + const bData = /** @type {ExecutionLogJobData} */ (b.data); + + return !!(aData?.jobKey && aData.jobKey === bData?.jobKey); + } + + if (a.type === EXECUTION_LOG_ENTRY_TYPE.USER_TASK) { + const aData = /** @type {ExecutionLogUserTaskData} */ (a.data); + const bData = /** @type {ExecutionLogUserTaskData} */ (b.data); + + return !!(aData?.userTaskKey && aData.userTaskKey === bData?.userTaskKey); + } + + if (a.type === EXECUTION_LOG_ENTRY_TYPE.MESSAGE_SUBSCRIPTION) { + const aData = /** @type {ExecutionLogMessageSubscriptionData} */ (a.data); + const bData = /** @type {ExecutionLogMessageSubscriptionData} */ (b.data); + + return !!(aData?.messageSubscriptionKey && + aData.messageSubscriptionKey === bData?.messageSubscriptionKey); + } + } + + return false; +} + export default class ExecutionLog { /** @@ -661,8 +781,23 @@ export default class ExecutionLog { } } - // 6. Sort chronologically - entries.sort((a, b) => a.timestamp - b.timestamp); + // 6. Sort chronologically, with causal tiebreaking for equal timestamps. + // Causal ordering is always applied for global status entries (deployed, + // instance-started) and only between related entries (same element + // lifecycle) for runtime entries. + entries.sort((a, b) => { + const timeDiff = a.timestamp - b.timestamp; + if (timeDiff !== 0) return timeDiff; + + const orderA = getEntryOrder(a); + const orderB = getEntryOrder(b); + + if (orderA <= 1 || orderB <= 1 || orderA >= 10 || orderB >= 10 || areRelated(a, b)) { + return orderA - orderB; + } + + return 0; + }); this._entries = entries; } diff --git a/lib/types.ts b/lib/types.ts index 03af712..47aa697 100644 --- a/lib/types.ts +++ b/lib/types.ts @@ -236,6 +236,7 @@ export type ExecutionLogJobData = { export type ExecutionLogUserTaskData = { state: string; name?: string; + elementId?: string; userTaskKey?: string; creationDate?: string; completionDate?: string; diff --git a/test/ExecutionLog.spec.js b/test/ExecutionLog.spec.js index 4a60a51..4e526f2 100644 --- a/test/ExecutionLog.spec.js +++ b/test/ExecutionLog.spec.js @@ -1,7 +1,9 @@ import ExecutionLog, { EXECUTION_LOG_ENTRY_STATUS, EXECUTION_LOG_ENTRY_TYPE, - formatElementType + areRelated, + formatElementType, + getEntryOrder } from '../lib/ExecutionLog'; import { TASK_EXECUTION_FINISHED_REASON } from '../lib/TaskExecution'; @@ -836,6 +838,686 @@ describe('ExecutionLog', function() { ]); }); + + it('should place deployed before instance-started at same timestamp', function() { + + // given + const timestamp = createMockTimestamp(); + + // when + executionLog.setDeployResponse(createDeployResponse(), timestamp); + executionLog.setStartInstanceResponse(createStartInstanceResponse(), timestamp); + + // then + const entries = executionLog.getEntries(); + const types = entries.map(e => e.status || e.type); + + expect(types).to.deep.equal([ + 'deployed', + 'instance-started' + ]); + }); + + + it('should place instance-started before job and element-instance entries at same timestamp', function() { + + // given + const timestamp = createMockTimestamp(); + + const job = createJobDetails({ + state: 'CREATED', + creationTime: createMockDate() + }); + + const elementInstance = createElementInstanceDetails({ + state: 'ACTIVE', + startDate: createMockDate() + }); + + // when + executionLog.setStartInstanceResponse(createStartInstanceResponse(), timestamp); + executionLog.setPolledResult(createPolledResult({ + jobsResponse: createGetProcessInstanceJobsResponse({ + response: { items: [ job ] } + }), + elementInstancesResponse: createGetProcessInstanceElementInstancesResponse({ + response: { items: [ elementInstance ] } + }) + }), timestamp); + + // then + const entries = executionLog.getEntries(); + const types = entries.map(e => e.status || `${e.type}:${e.data?.state}`); + + expect(types[0]).to.equal('instance-started'); + expect(types).to.include('job:CREATED'); + expect(types).to.include('element-instance:ACTIVE'); + expect(types.indexOf('instance-started')).to.be.lessThan(types.indexOf('job:CREATED')); + expect(types.indexOf('instance-started')).to.be.lessThan(types.indexOf('element-instance:ACTIVE')); + }); + + + it('should place element-instance ACTIVE before job CREATED at same timestamp', function() { + + // given + const timestamp = createMockTimestamp(); + const startDate = createMockDate(); + + const job = createJobDetails({ + state: 'CREATED', + creationTime: startDate + }); + + const elementInstance = createElementInstanceDetails({ + state: 'ACTIVE', + startDate + }); + + // when + executionLog.setPolledResult(createPolledResult({ + jobsResponse: createGetProcessInstanceJobsResponse({ + response: { items: [ job ] } + }), + elementInstancesResponse: createGetProcessInstanceElementInstancesResponse({ + response: { items: [ elementInstance ] } + }) + }), timestamp); + + // then + const entries = executionLog.getEntries(); + const types = entries.map(e => `${e.type}:${e.data?.state}`); + + expect(types.indexOf('element-instance:ACTIVE')).to.be.lessThan(types.indexOf('job:CREATED')); + }); + + + it('should place element-instance ACTIVE before user-task CREATED at same timestamp', function() { + + // given + const timestamp = createMockTimestamp(); + const startDate = createMockDate(); + + const userTask = createUserTaskDetails({ + elementId: 'UserTask_1', + state: 'CREATED', + creationDate: startDate + }); + + const elementInstance = createElementInstanceDetails({ + elementId: 'UserTask_1', + state: 'ACTIVE', + startDate + }); + + // when + executionLog.setPolledResult(createPolledResult({ + userTasksResponse: createGetProcessInstanceUserTasksResponse({ + response: { items: [ userTask ] } + }), + elementInstancesResponse: createGetProcessInstanceElementInstancesResponse({ + response: { items: [ elementInstance ] } + }) + }), timestamp); + + // then + const entries = executionLog.getEntries(); + const types = entries.map(e => `${e.type}:${e.data?.state}`); + + expect(types.indexOf('element-instance:ACTIVE')).to.be.lessThan(types.indexOf('user-task:CREATED')); + }); + + + it('should place element-instance ACTIVE before message-subscription CREATED at same timestamp', function() { + + // given + const timestamp = createMockTimestamp(); + const startDate = createMockDate(); + + const subscription = createMessageSubscriptionDetails({ + messageSubscriptionState: 'CREATED' + }); + + const elementInstance = createElementInstanceDetails({ + state: 'ACTIVE', + startDate + }); + + // when + executionLog.setPolledResult(createPolledResult({ + messageSubscriptionsResponse: createGetProcessInstanceMessageSubscriptionsResponse({ + response: { items: [ subscription ] } + }), + elementInstancesResponse: createGetProcessInstanceElementInstancesResponse({ + response: { items: [ elementInstance ] } + }) + }), timestamp); + + // then + const entries = executionLog.getEntries(); + const types = entries.map(e => + e.type === 'message-subscription' + ? `${e.type}:${e.data?.messageSubscriptionState}` + : `${e.type}:${e.data?.state}` + ); + + expect(types.indexOf('element-instance:ACTIVE')).to.be.lessThan( + types.indexOf('message-subscription:CREATED') + ); + }); + + + it('should place job CREATED before job COMPLETED at same timestamp', function() { + + // given + const timestamp = createMockTimestamp(); + const time = createMockDate(); + + const job = createJobDetails({ + state: 'COMPLETED', + creationTime: time, + endTime: time + }); + + // when + executionLog.setPolledResult(createPolledResult({ + jobsResponse: createGetProcessInstanceJobsResponse({ + response: { items: [ job ] } + }) + }), timestamp); + + // then + const entries = executionLog.getEntries(); + const jobEntries = entries.filter(e => e.type === 'job'); + + expect(jobEntries).to.have.length(2); + expect(jobEntries[0].data.state).to.equal('CREATED'); + expect(jobEntries[1].data.state).to.equal('COMPLETED'); + }); + + + it('should place message-subscription CREATED before CORRELATED at same timestamp', function() { + + // given + const timestamp = createMockTimestamp(); + + const subscription = createMessageSubscriptionDetails({ + messageSubscriptionState: 'CORRELATED' + }); + + const elementInstance = createElementInstanceDetails({ + state: 'COMPLETED', + startDate: createMockDate(), + endDate: createMockDate() + }); + + // when + executionLog.setPolledResult(createPolledResult({ + messageSubscriptionsResponse: createGetProcessInstanceMessageSubscriptionsResponse({ + response: { items: [ subscription ] } + }), + elementInstancesResponse: createGetProcessInstanceElementInstancesResponse({ + response: { items: [ elementInstance ] } + }) + }), timestamp); + + // then + const entries = executionLog.getEntries(); + const msgEntries = entries.filter(e => e.type === 'message-subscription'); + + expect(msgEntries).to.have.length(2); + expect(msgEntries[0].data.messageSubscriptionState).to.equal('CREATED'); + expect(msgEntries[1].data.messageSubscriptionState).to.equal('CORRELATED'); + }); + + + it('should place message-subscription CORRELATED before element-instance COMPLETED at same timestamp', function() { + + // given + const timestamp = createMockTimestamp(); + const endDate = createMockDate(ONE_SECOND_MS); + + const subscription = createMessageSubscriptionDetails({ + messageSubscriptionState: 'CORRELATED' + }); + + const elementInstance = createElementInstanceDetails({ + state: 'COMPLETED', + startDate: createMockDate(), + endDate + }); + + // when + executionLog.setPolledResult(createPolledResult({ + messageSubscriptionsResponse: createGetProcessInstanceMessageSubscriptionsResponse({ + response: { items: [ subscription ] } + }), + elementInstancesResponse: createGetProcessInstanceElementInstancesResponse({ + response: { items: [ elementInstance ] } + }) + }), timestamp); + + // then + const entries = executionLog.getEntries(); + const types = entries.map(e => + e.type === 'message-subscription' + ? `${e.type}:${e.data?.messageSubscriptionState}` + : `${e.type}:${e.data?.state}` + ); + + expect(types.indexOf('message-subscription:CORRELATED')).to.be.lessThan( + types.indexOf('element-instance:COMPLETED') + ); + }); + + + it('should place user-task COMPLETED before element-instance COMPLETED at same timestamp', function() { + + // given + const timestamp = createMockTimestamp(); + const endDate = createMockDate(ONE_SECOND_MS); + + const userTask = createUserTaskDetails({ + elementId: 'UserTask_1', + state: 'COMPLETED', + creationDate: createMockDate(), + completionDate: endDate + }); + + const elementInstance = createElementInstanceDetails({ + elementId: 'UserTask_1', + state: 'COMPLETED', + startDate: createMockDate(), + endDate + }); + + // when + executionLog.setPolledResult(createPolledResult({ + userTasksResponse: createGetProcessInstanceUserTasksResponse({ + response: { items: [ userTask ] } + }), + elementInstancesResponse: createGetProcessInstanceElementInstancesResponse({ + response: { items: [ elementInstance ] } + }) + }), timestamp); + + // then + const entries = executionLog.getEntries(); + const types = entries.map(e => `${e.type}:${e.data?.state}`); + + expect(types.indexOf('user-task:COMPLETED')).to.be.lessThan( + types.indexOf('element-instance:COMPLETED') + ); + }); + + + it('should place job completed before element-instance completed at same timestamp', function() { + + // given + const timestamp = createMockTimestamp(); + const endTime = createMockDate(ONE_SECOND_MS); + + const job = createJobDetails({ + state: 'COMPLETED', + creationTime: createMockDate(), + endTime + }); + + const elementInstance = createElementInstanceDetails({ + state: 'COMPLETED', + startDate: createMockDate(), + endDate: endTime + }); + + // when + executionLog.setPolledResult(createPolledResult({ + jobsResponse: createGetProcessInstanceJobsResponse({ + response: { items: [ job ] } + }), + elementInstancesResponse: createGetProcessInstanceElementInstancesResponse({ + response: { items: [ elementInstance ] } + }) + }), timestamp); + + // then + const entries = executionLog.getEntries(); + const types = entries.map(e => e.status || `${e.type}:${e.data?.state}`); + + const jobCompletedIdx = types.indexOf('job:COMPLETED'); + const eiCompletedIdx = types.indexOf('element-instance:COMPLETED'); + + expect(jobCompletedIdx).to.be.greaterThan(-1); + expect(eiCompletedIdx).to.be.greaterThan(-1); + expect(jobCompletedIdx).to.be.lessThan(eiCompletedIdx); + }); + + + it('should NOT reorder unrelated entries at the same timestamp', function() { + + // given - two jobs from different elements sharing the same end timestamp + const timestamp = createMockTimestamp(); + const endTime = createMockDate(ONE_SECOND_MS); + + const jobA = createJobDetails({ + jobKey: 'job-a', + elementId: 'ServiceTask_A', + state: 'COMPLETED', + creationTime: createMockDate(), + endTime + }); + + const jobB = createJobDetails({ + jobKey: 'job-b', + elementId: 'ServiceTask_B', + state: 'CREATED', + creationTime: endTime + }); + + // when + executionLog.setPolledResult(createPolledResult({ + jobsResponse: createGetProcessInstanceJobsResponse({ + response: { items: [ jobA, jobB ] } + }) + }), timestamp); + + // then — job A COMPLETED (at endTime) and job B CREATED (at endTime) + // share the same timestamp but are unrelated, so insertion order is + // preserved (job A COMPLETED before job B CREATED). + const entries = executionLog.getEntries(); + const atEndTime = entries + .filter(e => e.timestamp === new Date(endTime).getTime()) + .map(e => `${e.data?.elementId}:${e.data?.state}`); + + expect(atEndTime.indexOf('ServiceTask_A:COMPLETED')).to.be.lessThan( + atEndTime.indexOf('ServiceTask_B:CREATED') + ); + }); + + + it('should place start execution listener COMPLETED before regular job CREATED at same timestamp', function() { + + // given + const timestamp = createMockTimestamp(); + const time = createMockDate(); + + const listenerJob = createJobDetails({ + jobKey: 'listener-1', + elementId: 'ServiceTask_1', + state: 'COMPLETED', + kind: 'EXECUTION_LISTENER', + listenerEventType: 'START', + creationTime: time, + endTime: time + }); + + const regularJob = createJobDetails({ + jobKey: 'regular-1', + elementId: 'ServiceTask_1', + state: 'CREATED', + kind: 'BPMN_ELEMENT', + listenerEventType: 'UNSPECIFIED', + creationTime: time + }); + + // when + executionLog.setPolledResult(createPolledResult({ + jobsResponse: createGetProcessInstanceJobsResponse({ + response: { items: [ regularJob, listenerJob ] } + }) + }), timestamp); + + // then + const entries = executionLog.getEntries(); + const jobEntries = entries + .filter(e => e.type === 'job' && e.timestamp === new Date(time).getTime()) + .map(e => `${e.data?.kind}:${e.data?.listenerEventType}:${e.data?.state}`); + + const listenerCompleted = jobEntries.indexOf('EXECUTION_LISTENER:START:COMPLETED'); + const regularCreated = jobEntries.indexOf('BPMN_ELEMENT:UNSPECIFIED:CREATED'); + + expect(listenerCompleted).to.be.greaterThan(-1); + expect(regularCreated).to.be.greaterThan(-1); + expect(listenerCompleted).to.be.lessThan(regularCreated); + }); + + + it('should place regular job COMPLETED before end execution listener CREATED at same timestamp', function() { + + // given + const timestamp = createMockTimestamp(); + const time = createMockDate(); + + const regularJob = createJobDetails({ + jobKey: 'regular-1', + elementId: 'ServiceTask_1', + state: 'COMPLETED', + kind: 'BPMN_ELEMENT', + listenerEventType: 'UNSPECIFIED', + creationTime: time, + endTime: time + }); + + const listenerJob = createJobDetails({ + jobKey: 'listener-1', + elementId: 'ServiceTask_1', + state: 'COMPLETED', + kind: 'EXECUTION_LISTENER', + listenerEventType: 'END', + creationTime: time, + endTime: time + }); + + // when + executionLog.setPolledResult(createPolledResult({ + jobsResponse: createGetProcessInstanceJobsResponse({ + response: { items: [ listenerJob, regularJob ] } + }) + }), timestamp); + + // then + const entries = executionLog.getEntries(); + const jobEntries = entries + .filter(e => e.type === 'job' && e.timestamp === new Date(time).getTime()) + .map(e => `${e.data?.kind}:${e.data?.listenerEventType}:${e.data?.state}`); + + const regularCompleted = jobEntries.indexOf('BPMN_ELEMENT:UNSPECIFIED:COMPLETED'); + const endListenerCreated = jobEntries.indexOf('EXECUTION_LISTENER:END:CREATED'); + + expect(regularCompleted).to.be.greaterThan(-1); + expect(endListenerCreated).to.be.greaterThan(-1); + expect(regularCompleted).to.be.lessThan(endListenerCreated); + }); + + }); + + + describe('getEntryOrder', function() { + + it('should return 0 for deployed status', function() { + expect(getEntryOrder({ + type: EXECUTION_LOG_ENTRY_TYPE.STATUS, + status: EXECUTION_LOG_ENTRY_STATUS.DEPLOYED, + timestamp: 0 + })).to.equal(0); + }); + + + it('should return 1 for instance-started status', function() { + expect(getEntryOrder({ + type: EXECUTION_LOG_ENTRY_TYPE.STATUS, + status: EXECUTION_LOG_ENTRY_STATUS.INSTANCE_STARTED, + timestamp: 0 + })).to.equal(1); + }); + + + it('should return 2 for active element instances', function() { + expect(getEntryOrder({ + type: EXECUTION_LOG_ENTRY_TYPE.ELEMENT_INSTANCE, + data: { state: 'ACTIVE' }, + timestamp: 0 + })).to.equal(2); + }); + + + it('should return 3 for start execution listener job CREATED', function() { + expect(getEntryOrder({ + type: EXECUTION_LOG_ENTRY_TYPE.JOB, + data: { state: 'CREATED', kind: 'EXECUTION_LISTENER', listenerEventType: 'START' }, + timestamp: 0 + })).to.equal(3); + }); + + + it('should return 4 for start execution listener job COMPLETED', function() { + expect(getEntryOrder({ + type: EXECUTION_LOG_ENTRY_TYPE.JOB, + data: { state: 'COMPLETED', kind: 'EXECUTION_LISTENER', listenerEventType: 'START' }, + timestamp: 0 + })).to.equal(4); + }); + + + it('should return 5 for regular job CREATED', function() { + expect(getEntryOrder({ + type: EXECUTION_LOG_ENTRY_TYPE.JOB, + data: { state: 'CREATED', kind: 'BPMN_ELEMENT' }, + timestamp: 0 + })).to.equal(5); + }); + + + it('should return 5 for user-task CREATED', function() { + expect(getEntryOrder({ + type: EXECUTION_LOG_ENTRY_TYPE.USER_TASK, + data: { state: 'CREATED' }, + timestamp: 0 + })).to.equal(5); + }); + + + it('should return 5 for message-subscription CREATED', function() { + expect(getEntryOrder({ + type: EXECUTION_LOG_ENTRY_TYPE.MESSAGE_SUBSCRIPTION, + data: { messageSubscriptionState: 'CREATED' }, + timestamp: 0 + })).to.equal(5); + }); + + + it('should return 6 for regular job COMPLETED', function() { + expect(getEntryOrder({ + type: EXECUTION_LOG_ENTRY_TYPE.JOB, + data: { state: 'COMPLETED', kind: 'BPMN_ELEMENT' }, + timestamp: 0 + })).to.equal(6); + }); + + + it('should return 6 for user-task COMPLETED', function() { + expect(getEntryOrder({ + type: EXECUTION_LOG_ENTRY_TYPE.USER_TASK, + data: { state: 'COMPLETED' }, + timestamp: 0 + })).to.equal(6); + }); + + + it('should return 6 for message-subscription CORRELATED', function() { + expect(getEntryOrder({ + type: EXECUTION_LOG_ENTRY_TYPE.MESSAGE_SUBSCRIPTION, + data: { messageSubscriptionState: 'CORRELATED' }, + timestamp: 0 + })).to.equal(6); + }); + + + it('should return 10 for other status entries', function() { + expect(getEntryOrder({ + type: EXECUTION_LOG_ENTRY_TYPE.STATUS, + status: EXECUTION_LOG_ENTRY_STATUS.COMPLETED, + timestamp: 0 + })).to.equal(10); + }); + + + it('should return 7 for end execution listener job CREATED', function() { + expect(getEntryOrder({ + type: EXECUTION_LOG_ENTRY_TYPE.JOB, + data: { state: 'CREATED', kind: 'EXECUTION_LISTENER', listenerEventType: 'END' }, + timestamp: 0 + })).to.equal(7); + }); + + + it('should return 8 for end execution listener job COMPLETED', function() { + expect(getEntryOrder({ + type: EXECUTION_LOG_ENTRY_TYPE.JOB, + data: { state: 'COMPLETED', kind: 'EXECUTION_LISTENER', listenerEventType: 'END' }, + timestamp: 0 + })).to.equal(8); + }); + + + it('should return 9 for completed element instances', function() { + expect(getEntryOrder({ + type: EXECUTION_LOG_ENTRY_TYPE.ELEMENT_INSTANCE, + data: { state: 'COMPLETED' }, + timestamp: 0 + })).to.equal(9); + }); + + }); + + + describe('areRelated', function() { + + it('should return true for entries sharing the same elementId', function() { + const a = { type: EXECUTION_LOG_ENTRY_TYPE.ELEMENT_INSTANCE, data: { elementId: 'Task_1', state: 'ACTIVE' }, timestamp: 0 }; + const b = { type: EXECUTION_LOG_ENTRY_TYPE.JOB, data: { elementId: 'Task_1', state: 'CREATED' }, timestamp: 0 }; + + expect(areRelated(a, b)).to.be.true; + }); + + + it('should return false for entries with different elementIds', function() { + const a = { type: EXECUTION_LOG_ENTRY_TYPE.JOB, data: { elementId: 'Task_A', state: 'COMPLETED' }, timestamp: 0 }; + const b = { type: EXECUTION_LOG_ENTRY_TYPE.JOB, data: { elementId: 'Task_B', state: 'CREATED' }, timestamp: 0 }; + + expect(areRelated(a, b)).to.be.false; + }); + + + it('should return true for same-type job entries sharing jobKey', function() { + const a = { type: EXECUTION_LOG_ENTRY_TYPE.JOB, data: { jobKey: '42', state: 'CREATED' }, timestamp: 0 }; + const b = { type: EXECUTION_LOG_ENTRY_TYPE.JOB, data: { jobKey: '42', state: 'COMPLETED' }, timestamp: 0 }; + + expect(areRelated(a, b)).to.be.true; + }); + + + it('should return true for same-type user-task entries sharing userTaskKey', function() { + const a = { type: EXECUTION_LOG_ENTRY_TYPE.USER_TASK, data: { userTaskKey: '7', state: 'CREATED' }, timestamp: 0 }; + const b = { type: EXECUTION_LOG_ENTRY_TYPE.USER_TASK, data: { userTaskKey: '7', state: 'COMPLETED' }, timestamp: 0 }; + + expect(areRelated(a, b)).to.be.true; + }); + + + it('should return true for same-type message-subscription entries sharing messageSubscriptionKey', function() { + const a = { type: EXECUTION_LOG_ENTRY_TYPE.MESSAGE_SUBSCRIPTION, data: { messageSubscriptionKey: '3', messageSubscriptionState: 'CREATED' }, timestamp: 0 }; + const b = { type: EXECUTION_LOG_ENTRY_TYPE.MESSAGE_SUBSCRIPTION, data: { messageSubscriptionKey: '3', messageSubscriptionState: 'CORRELATED' }, timestamp: 0 }; + + expect(areRelated(a, b)).to.be.true; + }); + + + it('should return false for entries without elementId or matching keys', function() { + const a = { type: EXECUTION_LOG_ENTRY_TYPE.USER_TASK, data: { userTaskKey: '1', state: 'CREATED' }, timestamp: 0 }; + const b = { type: EXECUTION_LOG_ENTRY_TYPE.ELEMENT_INSTANCE, data: { state: 'ACTIVE' }, timestamp: 0 }; + + expect(areRelated(a, b)).to.be.false; + }); + }); From 7a99de3b303a9034cbe8edc918775c19de13f762 Mon Sep 17 00:00:00 2001 From: Philipp Fromme Date: Thu, 26 Mar 2026 10:01:56 +0100 Subject: [PATCH 02/11] fix(log): do not show active entries for completed items --- lib/components/Output/ExecutionLog.jsx | 35 ++++++- test/components/Output/ExecutionLog.spec.js | 105 ++++++++++++++++++++ 2 files changed, 137 insertions(+), 3 deletions(-) diff --git a/lib/components/Output/ExecutionLog.jsx b/lib/components/Output/ExecutionLog.jsx index 051bf62..da0c932 100644 --- a/lib/components/Output/ExecutionLog.jsx +++ b/lib/components/Output/ExecutionLog.jsx @@ -334,24 +334,53 @@ function getEntryDuration(entry) { function getActiveEntries(entries, isTaskExecuting) { if (!isTaskExecuting) return []; + const completedJobKeys = new Set(); + const completedUserTaskKeys = new Set(); + const completedMessageSubKeys = new Set(); + + for (const entry of entries) { + if (entry.type === EXECUTION_LOG_ENTRY_TYPE.JOB && entry.data.state !== JOB_STATES.CREATED && entry.data.jobKey) { + completedJobKeys.add(entry.data.jobKey); + } else if (entry.type === EXECUTION_LOG_ENTRY_TYPE.USER_TASK && entry.data.state !== USER_TASK_STATES.CREATED && entry.data.userTaskKey) { + completedUserTaskKeys.add(entry.data.userTaskKey); + } else if (entry.type === EXECUTION_LOG_ENTRY_TYPE.MESSAGE_SUBSCRIPTION && entry.data.messageSubscriptionState !== 'CREATED' && entry.data.messageSubscriptionKey) { + completedMessageSubKeys.add(entry.data.messageSubscriptionKey); + } + } + const activeEntries = []; for (const entry of entries) { - if (entry.type === EXECUTION_LOG_ENTRY_TYPE.JOB && entry.data.state === JOB_STATES.CREATED) { + if (entry.type === EXECUTION_LOG_ENTRY_TYPE.JOB + && entry.data.state === JOB_STATES.CREATED + && entry.data.jobKey + && !completedJobKeys.has(entry.data.jobKey)) { + activeEntries.push({ label: 'Waiting for job to be completed', secondaryLabel: entry.data.type }); - } else if (entry.type === EXECUTION_LOG_ENTRY_TYPE.USER_TASK && entry.data.state === USER_TASK_STATES.CREATED) { + + } else if (entry.type === EXECUTION_LOG_ENTRY_TYPE.USER_TASK + && entry.data.state === USER_TASK_STATES.CREATED + && entry.data.userTaskKey + && !completedUserTaskKeys.has(entry.data.userTaskKey)) { + activeEntries.push({ label: 'Waiting for user task to be completed', secondaryLabel: entry.data.name || entry.data.elementId }); - } else if (entry.type === EXECUTION_LOG_ENTRY_TYPE.MESSAGE_SUBSCRIPTION && entry.data.messageSubscriptionState === 'CREATED') { + + } else if (entry.type === EXECUTION_LOG_ENTRY_TYPE.MESSAGE_SUBSCRIPTION + && entry.data.messageSubscriptionState === 'CREATED' + && entry.data.messageSubscriptionKey + && !completedMessageSubKeys.has(entry.data.messageSubscriptionKey)) { + activeEntries.push({ label: 'Waiting for message to be correlated', secondaryLabel: entry.data.messageName }); + } } diff --git a/test/components/Output/ExecutionLog.spec.js b/test/components/Output/ExecutionLog.spec.js index 65b3e06..0ba4f00 100644 --- a/test/components/Output/ExecutionLog.spec.js +++ b/test/components/Output/ExecutionLog.spec.js @@ -976,6 +976,111 @@ describe('ExecutionLog', function() { expect(activeEntries).to.have.length(3); }); + + it('should NOT show active entry for job that has a completed entry', function() { + + // given + const entries = [ + createJobEntry(createJobDetails({ jobKey: '42' }), createMockTimestamp(), { state: 'CREATED' }), + createJobEntry(createJobDetails({ jobKey: '42' }), createMockTimestamp(ONE_SECOND_MS), { state: 'COMPLETED' }) + ]; + + // when + const { container } = renderExecutionLog({ entries, isTaskExecuting: true }); + + // then + const activeEntries = container.querySelectorAll('.execution-log__entry-wrapper--active'); + expect(activeEntries).to.have.length(0); + }); + + + it('should NOT show active entry for job that has a failed entry', function() { + + // given + const entries = [ + createJobEntry(createJobDetails({ jobKey: '42' }), createMockTimestamp(), { state: 'CREATED' }), + createJobEntry(createJobDetails({ jobKey: '42' }), createMockTimestamp(ONE_SECOND_MS), { state: 'FAILED' }) + ]; + + // when + const { container } = renderExecutionLog({ entries, isTaskExecuting: true }); + + // then + const activeEntries = container.querySelectorAll('.execution-log__entry-wrapper--active'); + expect(activeEntries).to.have.length(0); + }); + + + it('should NOT show active entry for user task that has a completed entry', function() { + + // given + const entries = [ + createUserTaskEntry({ state: 'CREATED', userTaskKey: '7', name: 'Foo' }), + createUserTaskEntry({ state: 'COMPLETED', userTaskKey: '7', name: 'Foo' }) + ]; + + // when + const { container } = renderExecutionLog({ entries, isTaskExecuting: true }); + + // then + const activeEntries = container.querySelectorAll('.execution-log__entry-wrapper--active'); + expect(activeEntries).to.have.length(0); + }); + + + it('should NOT show active entry for message subscription that has been correlated', function() { + + // given + const entries = [ + createMessageSubscriptionEntry({ + messageName: 'Foo', + messageSubscriptionKey: '3', + messageSubscriptionState: 'CREATED' + }), + createMessageSubscriptionEntry({ + messageName: 'Foo', + messageSubscriptionKey: '3', + messageSubscriptionState: 'CORRELATED' + }) + ]; + + // when + const { container } = renderExecutionLog({ entries, isTaskExecuting: true }); + + // then + const activeEntries = container.querySelectorAll('.execution-log__entry-wrapper--active'); + expect(activeEntries).to.have.length(0); + }); + + + it('should only show active entries for items still pending when mixed with completed', function() { + + // given — job completed, user task still pending, message subscription correlated + const entries = [ + createJobEntry(createJobDetails({ jobKey: '1' }), createMockTimestamp(), { state: 'CREATED' }), + createJobEntry(createJobDetails({ jobKey: '1' }), createMockTimestamp(ONE_SECOND_MS), { state: 'COMPLETED' }), + createUserTaskEntry({ state: 'CREATED', userTaskKey: '2', name: 'Pending Task' }), + createMessageSubscriptionEntry({ + messageName: 'Msg', + messageSubscriptionKey: '3', + messageSubscriptionState: 'CREATED' + }), + createMessageSubscriptionEntry({ + messageName: 'Msg', + messageSubscriptionKey: '3', + messageSubscriptionState: 'CORRELATED' + }) + ]; + + // when + const { container } = renderExecutionLog({ entries, isTaskExecuting: true }); + + // then — only user task should be active + const activeEntries = container.querySelectorAll('.execution-log__entry-wrapper--active'); + expect(activeEntries).to.have.length(1); + expect(activeEntries[0].textContent).to.include('Waiting for user task to be completed'); + }); + }); From c5528c7a80e9a7c94bdf94cbe372613d6a8c67aa Mon Sep 17 00:00:00 2001 From: Philipp Fromme Date: Fri, 27 Mar 2026 10:39:43 +0100 Subject: [PATCH 03/11] chore(log): remove timestamp override in favor of causal sorting Reverts https://github.com/camunda/task-testing/pull/88 which was a fix for only one of the ordering issues. --- lib/ExecutionLog.js | 11 ----------- test/ExecutionLog.spec.js | 20 +------------------- 2 files changed, 1 insertion(+), 30 deletions(-) diff --git a/lib/ExecutionLog.js b/lib/ExecutionLog.js index a7727f9..af322bd 100644 --- a/lib/ExecutionLog.js +++ b/lib/ExecutionLog.js @@ -602,17 +602,6 @@ export default class ExecutionLog { timestamp }; - // Prefer server-side process instance startDate over the client-side timestamp - if (this._startInstanceResponse && result.processInstanceResponse?.success) { - const serverStartDate = toTimestamp( - result.processInstanceResponse.response?.items?.[0]?.startDate - ); - - if (serverStartDate) { - this._startInstanceResponse.timestamp = serverStartDate; - } - } - this._updateEntries(); } diff --git a/test/ExecutionLog.spec.js b/test/ExecutionLog.spec.js index 4e526f2..53d359e 100644 --- a/test/ExecutionLog.spec.js +++ b/test/ExecutionLog.spec.js @@ -800,19 +800,13 @@ describe('ExecutionLog', function() { // when executionLog.setDeployResponse(createDeployResponse(), createMockTimestamp()); - executionLog.setStartInstanceResponse(createStartInstanceResponse(), createMockTimestamp(ONE_SECOND_MS * 3)); + executionLog.setStartInstanceResponse(createStartInstanceResponse(), createMockTimestamp(ONE_SECOND_MS)); executionLog.setPolledResult(createPolledResult({ jobsResponse: createGetProcessInstanceJobsResponse({ response: { items: [ job ] } }), elementInstancesResponse: createGetProcessInstanceElementInstancesResponse({ response: { items: [ elementInstance ] } - }), - processInstanceResponse: createGetProcessInstanceResponse({ - response: { - items: [ createProcessInstanceDetails({ startDate: createMockDate(ONE_SECOND_MS) }) ], - page: { totalItems: 1 } - } }) }), createMockTimestamp(ONE_SECOND_MS * 6)); @@ -824,18 +818,6 @@ describe('ExecutionLog', function() { for (let i = 1; i < timestamps.length; i++) { expect(timestamps[i]).to.be.at.least(timestamps[i - 1]); } - - // Verify instance-started comes before element-instance entries - const types = entries.map(e => e.status || `${e.type}:${e.data?.state}`); - - expect(types).to.deep.equal([ - 'deployed', - 'instance-started', - 'element-instance:ACTIVE', - 'job:CREATED', - 'job:COMPLETED', - 'element-instance:COMPLETED' - ]); }); From 2eb9bd11b8e4b28ecfba1e8bf66b9e410536bace Mon Sep 17 00:00:00 2001 From: Philipp Fromme Date: Fri, 27 Mar 2026 11:21:01 +0100 Subject: [PATCH 04/11] chore: update example Adds call activity to example --- demo/App.jsx | 17 +++--- .../fixtures/{diagram.bpmn => diagram_1.bpmn} | 58 +++++++++++++------ demo/fixtures/diagram_2.bpmn | 42 ++++++++++++++ demo/fixtures/{form.form => form_1.form} | 0 4 files changed, 90 insertions(+), 27 deletions(-) rename demo/fixtures/{diagram.bpmn => diagram_1.bpmn} (97%) create mode 100644 demo/fixtures/diagram_2.bpmn rename demo/fixtures/{form.form => form_1.form} (100%) diff --git a/demo/App.jsx b/demo/App.jsx index 3e51d06..825068b 100644 --- a/demo/App.jsx +++ b/demo/App.jsx @@ -7,8 +7,9 @@ import 'camunda-bpmn-js/dist/assets/camunda-cloud-modeler.css'; import TaskTesting from '../lib'; -import diagram from './fixtures/diagram.bpmn'; -import form from './fixtures/form.form'; +import diagram1 from './fixtures/diagram_1.bpmn'; +import diagram2 from './fixtures/diagram_2.bpmn'; +import form1 from './fixtures/form_1.form'; import connectorTemplates from './fixtures/connectorTemplates.json'; import defaultConfig from './fixtures/config'; @@ -57,7 +58,7 @@ function App() { useEffect(() => { async function importXml() { - await modeler.importXML(diagram); + await modeler.importXML(diagram1); modeler.get('canvas').zoom('fit-viewport'); } @@ -76,11 +77,11 @@ function App() { const deploy = useCallback(async () => { const { xml } = await modeler.saveXML(); - const resources = [ { name: 'diagram.bpmn', content: xml } ]; - - if (form) { - resources.push({ name: 'form.form', content: form }); - } + const resources = [ + { name: 'diagram_1.bpmn', content: xml }, + { name: 'diagram_2.bpmn', content: diagram2 }, + { name: 'form.form', content: form1 } + ]; const response = await fetch('/api/deploy', { method: 'POST', diff --git a/demo/fixtures/diagram.bpmn b/demo/fixtures/diagram_1.bpmn similarity index 97% rename from demo/fixtures/diagram.bpmn rename to demo/fixtures/diagram_1.bpmn index de0b258..4604cfb 100644 --- a/demo/fixtures/diagram.bpmn +++ b/demo/fixtures/diagram_1.bpmn @@ -1,5 +1,5 @@ - + Flow_0nufm4k @@ -294,13 +294,25 @@ - Flow_0xcmxua + Flow_0vs7ni0 Flow_0ek248u - + + + + + + + + + + + Flow_0xcmxua + Flow_0vs7ni0 + Flow_06cqvxh @@ -323,6 +335,9 @@ + + + @@ -370,9 +385,6 @@ - - - @@ -387,10 +399,6 @@ - - - - @@ -407,14 +415,22 @@ + + + + - + - - + + + + + + @@ -424,8 +440,8 @@ - - + + @@ -433,7 +449,11 @@ - + + + + + @@ -474,8 +494,8 @@ - - + + @@ -525,4 +545,4 @@ - \ No newline at end of file + diff --git a/demo/fixtures/diagram_2.bpmn b/demo/fixtures/diagram_2.bpmn new file mode 100644 index 0000000..25e4657 --- /dev/null +++ b/demo/fixtures/diagram_2.bpmn @@ -0,0 +1,42 @@ + + + + + Flow_0uujfd4 + + + + Flow_0rfmhb9 + + + + + + + Flow_0uujfd4 + Flow_0rfmhb9 + + + + + + + + + + + + + + + + + + + + + + + + + diff --git a/demo/fixtures/form.form b/demo/fixtures/form_1.form similarity index 100% rename from demo/fixtures/form.form rename to demo/fixtures/form_1.form From b3448c08185888fdbf9a278a9f2ba382af753749 Mon Sep 17 00:00:00 2001 From: Philipp Fromme Date: Fri, 27 Mar 2026 14:41:11 +0100 Subject: [PATCH 05/11] refactor(log): replace magic numbers with named constants MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Introduce an `ENTRY_ORDER` enum to replace bare numeric literals (0–10) in `getEntryOrder`, making the causal ordering of execution log entries self-documenting. --- lib/ExecutionLog.js | 155 ++++++++++++++++++++++++------------ test/ExecutionLog.spec.js | 160 +++++++++++++++++++++++++++++--------- 2 files changed, 227 insertions(+), 88 deletions(-) diff --git a/lib/ExecutionLog.js b/lib/ExecutionLog.js index af322bd..98812c5 100644 --- a/lib/ExecutionLog.js +++ b/lib/ExecutionLog.js @@ -45,6 +45,26 @@ export const EXECUTION_LOG_ENTRY_STATUS = /** @type {const} */ ({ CANCELED: 'canceled' }); +/** + * Named orders representing the causal order of execution log entries. Lower + * values are earlier in the lifecycle. Used by {@link getEntryOrder} to assign + * an order to each entry so that entries sharing a timestamp can be placed in a + * causally correct sequence. + */ +export const ENTRY_ORDER = /** @type {const} */ ({ + DEPLOYED: 0, + INSTANCE_STARTED: 1, + ELEMENT_ACTIVE: 2, + START_LISTENER_CREATED: 3, + START_LISTENER_TERMINAL: 4, + WORK_CREATED: 5, + WORK_TERMINAL: 6, + END_LISTENER_CREATED: 7, + END_LISTENER_TERMINAL: 8, + ELEMENT_TERMINAL: 9, + STATUS_TERMINAL: 10 +}); + /** * Parse a date string into a millisecond timestamp. * @@ -401,26 +421,24 @@ export function formatElementType(type) { } /** - * Determine a sort-order priority for an execution log entry so that entries - * sharing the same timestamp are placed in a causally correct sequence. - * - * Priority levels (lower = earlier): - * 0 – deployed status (must precede all other entries) - * 1 – instance-started status (must precede runtime entries) - * 2 – element-instance ACTIVE (element entered before its child - * jobs / tasks / message subscriptions start) - * 3 – start execution listener job CREATED - * 4 – start execution listener job terminal - * 5 – created states: regular job CREATED, user-task CREATED, - * message-subscription CREATED - * 6 – terminal states: regular job completed / failed, - * message-subscription CORRELATED, user-task completed - * 7 – end execution listener job CREATED - * 8 – end execution listener job terminal - * 9 – element-instance terminal (COMPLETED, TERMINATED, …) — element - * exits only after its child items have finished - * 10 – terminal status entries (completed, incident, terminated, - * canceled) — always placed after all runtime entries + * Determine the {@link ENTRY_ORDER} for an execution log entry so that entries + * are placed in a causally correct sequence. Status entries (deployed, + * instance-started, terminal) are always pinned to their canonical position + * regardless of timestamp. For all other entries the order is used as a + * tiebreaker when timestamps are equal. + * + * Entry order mapping (lower = earlier in the lifecycle): + * ENTRY_ORDER.DEPLOYED – deployed status + * ENTRY_ORDER.INSTANCE_STARTED – instance-started status + * ENTRY_ORDER.ELEMENT_ACTIVE – element-instance ACTIVE + * ENTRY_ORDER.START_LISTENER_CREATED – start execution listener job CREATED + * ENTRY_ORDER.START_LISTENER_TERMINAL – start execution listener job terminal + * ENTRY_ORDER.WORK_CREATED – regular job / user-task / message-subscription CREATED + * ENTRY_ORDER.WORK_TERMINAL – regular job / user-task / message-subscription terminal + * ENTRY_ORDER.END_LISTENER_CREATED – end execution listener job CREATED + * ENTRY_ORDER.END_LISTENER_TERMINAL – end execution listener job terminal + * ENTRY_ORDER.ELEMENT_TERMINAL – element-instance terminal (COMPLETED, TERMINATED, …) + * ENTRY_ORDER.STATUS_TERMINAL – terminal status entries (completed, incident, …) * * @param {ExecutionLogEntry} entry * @@ -429,54 +447,53 @@ export function formatElementType(type) { export function getEntryOrder(entry) { if (entry.type === EXECUTION_LOG_ENTRY_TYPE.STATUS) { if (entry.status === EXECUTION_LOG_ENTRY_STATUS.DEPLOYED) { - return 0; + return ENTRY_ORDER.DEPLOYED; } if (entry.status === EXECUTION_LOG_ENTRY_STATUS.INSTANCE_STARTED) { - return 1; + return ENTRY_ORDER.INSTANCE_STARTED; } - return 10; + return ENTRY_ORDER.STATUS_TERMINAL; } if (entry.type === EXECUTION_LOG_ENTRY_TYPE.ELEMENT_INSTANCE) { - return entry.data.state === 'ACTIVE' ? 2 : 9; + return entry.data.state === 'ACTIVE' ? ENTRY_ORDER.ELEMENT_ACTIVE : ENTRY_ORDER.ELEMENT_TERMINAL; } if (entry.type === EXECUTION_LOG_ENTRY_TYPE.JOB) { const isListener = entry.data.kind === 'EXECUTION_LISTENER'; if (isListener && entry.data.listenerEventType === 'START') { - return entry.data.state === 'CREATED' ? 3 : 4; + return entry.data.state === 'CREATED' ? ENTRY_ORDER.START_LISTENER_CREATED : ENTRY_ORDER.START_LISTENER_TERMINAL; } if (isListener && entry.data.listenerEventType === 'END') { - return entry.data.state === 'CREATED' ? 7 : 8; + return entry.data.state === 'CREATED' ? ENTRY_ORDER.END_LISTENER_CREATED : ENTRY_ORDER.END_LISTENER_TERMINAL; } - return entry.data.state === 'CREATED' ? 5 : 6; + return entry.data.state === 'CREATED' ? ENTRY_ORDER.WORK_CREATED : ENTRY_ORDER.WORK_TERMINAL; } if (entry.type === EXECUTION_LOG_ENTRY_TYPE.USER_TASK) { - return entry.data.state === 'CREATED' ? 5 : 6; + return entry.data.state === 'CREATED' ? ENTRY_ORDER.WORK_CREATED : ENTRY_ORDER.WORK_TERMINAL; } if (entry.type === EXECUTION_LOG_ENTRY_TYPE.MESSAGE_SUBSCRIPTION) { - return entry.data.messageSubscriptionState === 'CREATED' ? 5 : 6; + return entry.data.messageSubscriptionState === 'CREATED' ? ENTRY_ORDER.WORK_CREATED : ENTRY_ORDER.WORK_TERMINAL; } - return 6; + return ENTRY_ORDER.WORK_TERMINAL; } /** - * Check whether two execution log entries belong to the same element - * lifecycle and should therefore be causally ordered when they share a - * timestamp. - * - * Entries are considered related when they share an `elementId` (linking - * element-instance, job, and message-subscription entries for the same BPMN - * element) or, for same-type entries without a common `elementId`, when they - * share an identity key (`jobKey`, `userTaskKey`, or + * Check whether two execution log entries are causally related and should + * therefore be ordered by {@link ENTRY_ORDER} when they share a timestamp. + * + * Runtime entries are considered related when they share an `elementId` + * (linking element-instance, job, and message-subscription entries for the + * same BPMN element) or, for same-type entries without a common `elementId`, + * when they share an identity key (`jobKey`, `userTaskKey`, or * `messageSubscriptionKey`). * * @param {ExecutionLogEntry} a @@ -484,7 +501,7 @@ export function getEntryOrder(entry) { * * @returns {boolean} */ -export function areRelated(a, b) { +export function areEntriesRelated(a, b) { const elementIdA = /** @type {{ elementId?: string }} */ (a.data)?.elementId; const elementIdB = /** @type {{ elementId?: string }} */ (b.data)?.elementId; @@ -519,6 +536,42 @@ export function areRelated(a, b) { return false; } +/** + * Compare two entries by timestamp (ascending). + * + * @param {ExecutionLogEntry} a + * @param {ExecutionLogEntry} b + * + * @returns {number} + */ +export function compareEntryTimestamps(a, b) { + return a.timestamp - b.timestamp; +} + +/** + * Check whether two entries have the same timestamp. + * + * @param {ExecutionLogEntry} a + * @param {ExecutionLogEntry} b + * + * @returns {boolean} + */ +export function areEntryTimestampsEqual(a, b) { + return a.timestamp === b.timestamp; +} + +/** + * Compare two entries by their causal {@link ENTRY_ORDER} (ascending). + * + * @param {ExecutionLogEntry} a + * @param {ExecutionLogEntry} b + * + * @returns {number} + */ +export function compareEntryOrders(a, b) { + return getEntryOrder(a) - getEntryOrder(b); +} + export default class ExecutionLog { /** @@ -771,18 +824,16 @@ export default class ExecutionLog { } // 6. Sort chronologically, with causal tiebreaking for equal timestamps. - // Causal ordering is always applied for global status entries (deployed, - // instance-started) and only between related entries (same element - // lifecycle) for runtime entries. + // Status entries (deployed, instance-started, terminal) are always pinned + // to their canonical position regardless of timestamp, because engine + // timestamps can arrive slightly out of causal order. entries.sort((a, b) => { - const timeDiff = a.timestamp - b.timestamp; - if (timeDiff !== 0) return timeDiff; - - const orderA = getEntryOrder(a); - const orderB = getEntryOrder(b); - - if (orderA <= 1 || orderB <= 1 || orderA >= 10 || orderB >= 10 || areRelated(a, b)) { - return orderA - orderB; + if (isStatusEntry(a) || isStatusEntry(b)) { + return compareEntryOrders(a, b); + } else if (!areEntryTimestampsEqual(a, b)) { + return compareEntryTimestamps(a, b); + } else if (areEntriesRelated(a, b)) { + return compareEntryOrders(a, b); } return 0; @@ -791,3 +842,7 @@ export default class ExecutionLog { this._entries = entries; } } + +function isStatusEntry(entry) { + return entry.type === EXECUTION_LOG_ENTRY_TYPE.STATUS; +} \ No newline at end of file diff --git a/test/ExecutionLog.spec.js b/test/ExecutionLog.spec.js index 53d359e..29f519f 100644 --- a/test/ExecutionLog.spec.js +++ b/test/ExecutionLog.spec.js @@ -1,7 +1,10 @@ import ExecutionLog, { EXECUTION_LOG_ENTRY_STATUS, EXECUTION_LOG_ENTRY_TYPE, - areRelated, + ENTRY_ORDER, + areEntriesRelated, + compareEntryOrders, + compareEntryTimestamps, formatElementType, getEntryOrder } from '../lib/ExecutionLog'; @@ -879,6 +882,47 @@ describe('ExecutionLog', function() { }); + it('should place instance-started before user-task CREATED even when user-task has earlier timestamp', function() { + + // given — the user-task creationDate is *before* the instance-started + // timestamp, which can happen due to engine timestamp jitter. + const instanceStartedTimestamp = createMockTimestamp(ONE_SECOND_MS * 2); + + const userTask = createUserTaskDetails({ + elementId: 'UserTask_1', + state: 'CREATED', + creationDate: createMockDate(ONE_SECOND_MS) + }); + + const elementInstance = createElementInstanceDetails({ + elementId: 'UserTask_1', + state: 'ACTIVE', + startDate: createMockDate(ONE_SECOND_MS) + }); + + // when + executionLog.setStartInstanceResponse( + createStartInstanceResponse(), instanceStartedTimestamp + ); + executionLog.setPolledResult(createPolledResult({ + userTasksResponse: createGetProcessInstanceUserTasksResponse({ + response: { items: [ userTask ] } + }), + elementInstancesResponse: createGetProcessInstanceElementInstancesResponse({ + response: { items: [ elementInstance ] } + }) + }), createMockTimestamp(ONE_SECOND_MS * 3)); + + // then + const entries = executionLog.getEntries(); + const types = entries.map(e => e.status || `${e.type}:${e.data?.state}`); + + expect(types.indexOf('instance-started')).to.be.lessThan( + types.indexOf('user-task:CREATED') + ); + }); + + it('should place element-instance ACTIVE before job CREATED at same timestamp', function() { // given @@ -1314,150 +1358,150 @@ describe('ExecutionLog', function() { describe('getEntryOrder', function() { - it('should return 0 for deployed status', function() { + it('should return ENTRY_ORDER.DEPLOYED for deployed status', function() { expect(getEntryOrder({ type: EXECUTION_LOG_ENTRY_TYPE.STATUS, status: EXECUTION_LOG_ENTRY_STATUS.DEPLOYED, timestamp: 0 - })).to.equal(0); + })).to.equal(ENTRY_ORDER.DEPLOYED); }); - it('should return 1 for instance-started status', function() { + it('should return ENTRY_ORDER.INSTANCE_STARTED for instance-started status', function() { expect(getEntryOrder({ type: EXECUTION_LOG_ENTRY_TYPE.STATUS, status: EXECUTION_LOG_ENTRY_STATUS.INSTANCE_STARTED, timestamp: 0 - })).to.equal(1); + })).to.equal(ENTRY_ORDER.INSTANCE_STARTED); }); - it('should return 2 for active element instances', function() { + it('should return ENTRY_ORDER.ELEMENT_ACTIVE for active element instances', function() { expect(getEntryOrder({ type: EXECUTION_LOG_ENTRY_TYPE.ELEMENT_INSTANCE, data: { state: 'ACTIVE' }, timestamp: 0 - })).to.equal(2); + })).to.equal(ENTRY_ORDER.ELEMENT_ACTIVE); }); - it('should return 3 for start execution listener job CREATED', function() { + it('should return ENTRY_ORDER.START_LISTENER_CREATED for start execution listener job CREATED', function() { expect(getEntryOrder({ type: EXECUTION_LOG_ENTRY_TYPE.JOB, data: { state: 'CREATED', kind: 'EXECUTION_LISTENER', listenerEventType: 'START' }, timestamp: 0 - })).to.equal(3); + })).to.equal(ENTRY_ORDER.START_LISTENER_CREATED); }); - it('should return 4 for start execution listener job COMPLETED', function() { + it('should return ENTRY_ORDER.START_LISTENER_TERMINAL for start execution listener job COMPLETED', function() { expect(getEntryOrder({ type: EXECUTION_LOG_ENTRY_TYPE.JOB, data: { state: 'COMPLETED', kind: 'EXECUTION_LISTENER', listenerEventType: 'START' }, timestamp: 0 - })).to.equal(4); + })).to.equal(ENTRY_ORDER.START_LISTENER_TERMINAL); }); - it('should return 5 for regular job CREATED', function() { + it('should return ENTRY_ORDER.WORK_CREATED for regular job CREATED', function() { expect(getEntryOrder({ type: EXECUTION_LOG_ENTRY_TYPE.JOB, data: { state: 'CREATED', kind: 'BPMN_ELEMENT' }, timestamp: 0 - })).to.equal(5); + })).to.equal(ENTRY_ORDER.WORK_CREATED); }); - it('should return 5 for user-task CREATED', function() { + it('should return ENTRY_ORDER.WORK_CREATED for user-task CREATED', function() { expect(getEntryOrder({ type: EXECUTION_LOG_ENTRY_TYPE.USER_TASK, data: { state: 'CREATED' }, timestamp: 0 - })).to.equal(5); + })).to.equal(ENTRY_ORDER.WORK_CREATED); }); - it('should return 5 for message-subscription CREATED', function() { + it('should return ENTRY_ORDER.WORK_CREATED for message-subscription CREATED', function() { expect(getEntryOrder({ type: EXECUTION_LOG_ENTRY_TYPE.MESSAGE_SUBSCRIPTION, data: { messageSubscriptionState: 'CREATED' }, timestamp: 0 - })).to.equal(5); + })).to.equal(ENTRY_ORDER.WORK_CREATED); }); - it('should return 6 for regular job COMPLETED', function() { + it('should return ENTRY_ORDER.WORK_TERMINAL for regular job COMPLETED', function() { expect(getEntryOrder({ type: EXECUTION_LOG_ENTRY_TYPE.JOB, data: { state: 'COMPLETED', kind: 'BPMN_ELEMENT' }, timestamp: 0 - })).to.equal(6); + })).to.equal(ENTRY_ORDER.WORK_TERMINAL); }); - it('should return 6 for user-task COMPLETED', function() { + it('should return ENTRY_ORDER.WORK_TERMINAL for user-task COMPLETED', function() { expect(getEntryOrder({ type: EXECUTION_LOG_ENTRY_TYPE.USER_TASK, data: { state: 'COMPLETED' }, timestamp: 0 - })).to.equal(6); + })).to.equal(ENTRY_ORDER.WORK_TERMINAL); }); - it('should return 6 for message-subscription CORRELATED', function() { + it('should return ENTRY_ORDER.WORK_TERMINAL for message-subscription CORRELATED', function() { expect(getEntryOrder({ type: EXECUTION_LOG_ENTRY_TYPE.MESSAGE_SUBSCRIPTION, data: { messageSubscriptionState: 'CORRELATED' }, timestamp: 0 - })).to.equal(6); + })).to.equal(ENTRY_ORDER.WORK_TERMINAL); }); - it('should return 10 for other status entries', function() { + it('should return ENTRY_ORDER.STATUS_TERMINAL for other status entries', function() { expect(getEntryOrder({ type: EXECUTION_LOG_ENTRY_TYPE.STATUS, status: EXECUTION_LOG_ENTRY_STATUS.COMPLETED, timestamp: 0 - })).to.equal(10); + })).to.equal(ENTRY_ORDER.STATUS_TERMINAL); }); - it('should return 7 for end execution listener job CREATED', function() { + it('should return ENTRY_ORDER.END_LISTENER_CREATED for end execution listener job CREATED', function() { expect(getEntryOrder({ type: EXECUTION_LOG_ENTRY_TYPE.JOB, data: { state: 'CREATED', kind: 'EXECUTION_LISTENER', listenerEventType: 'END' }, timestamp: 0 - })).to.equal(7); + })).to.equal(ENTRY_ORDER.END_LISTENER_CREATED); }); - it('should return 8 for end execution listener job COMPLETED', function() { + it('should return ENTRY_ORDER.END_LISTENER_TERMINAL for end execution listener job COMPLETED', function() { expect(getEntryOrder({ type: EXECUTION_LOG_ENTRY_TYPE.JOB, data: { state: 'COMPLETED', kind: 'EXECUTION_LISTENER', listenerEventType: 'END' }, timestamp: 0 - })).to.equal(8); + })).to.equal(ENTRY_ORDER.END_LISTENER_TERMINAL); }); - it('should return 9 for completed element instances', function() { + it('should return ENTRY_ORDER.ELEMENT_TERMINAL for completed element instances', function() { expect(getEntryOrder({ type: EXECUTION_LOG_ENTRY_TYPE.ELEMENT_INSTANCE, data: { state: 'COMPLETED' }, timestamp: 0 - })).to.equal(9); + })).to.equal(ENTRY_ORDER.ELEMENT_TERMINAL); }); }); - describe('areRelated', function() { + describe('areEntriesRelated', function() { it('should return true for entries sharing the same elementId', function() { const a = { type: EXECUTION_LOG_ENTRY_TYPE.ELEMENT_INSTANCE, data: { elementId: 'Task_1', state: 'ACTIVE' }, timestamp: 0 }; const b = { type: EXECUTION_LOG_ENTRY_TYPE.JOB, data: { elementId: 'Task_1', state: 'CREATED' }, timestamp: 0 }; - expect(areRelated(a, b)).to.be.true; + expect(areEntriesRelated(a, b)).to.be.true; }); @@ -1465,7 +1509,7 @@ describe('ExecutionLog', function() { const a = { type: EXECUTION_LOG_ENTRY_TYPE.JOB, data: { elementId: 'Task_A', state: 'COMPLETED' }, timestamp: 0 }; const b = { type: EXECUTION_LOG_ENTRY_TYPE.JOB, data: { elementId: 'Task_B', state: 'CREATED' }, timestamp: 0 }; - expect(areRelated(a, b)).to.be.false; + expect(areEntriesRelated(a, b)).to.be.false; }); @@ -1473,7 +1517,7 @@ describe('ExecutionLog', function() { const a = { type: EXECUTION_LOG_ENTRY_TYPE.JOB, data: { jobKey: '42', state: 'CREATED' }, timestamp: 0 }; const b = { type: EXECUTION_LOG_ENTRY_TYPE.JOB, data: { jobKey: '42', state: 'COMPLETED' }, timestamp: 0 }; - expect(areRelated(a, b)).to.be.true; + expect(areEntriesRelated(a, b)).to.be.true; }); @@ -1481,7 +1525,7 @@ describe('ExecutionLog', function() { const a = { type: EXECUTION_LOG_ENTRY_TYPE.USER_TASK, data: { userTaskKey: '7', state: 'CREATED' }, timestamp: 0 }; const b = { type: EXECUTION_LOG_ENTRY_TYPE.USER_TASK, data: { userTaskKey: '7', state: 'COMPLETED' }, timestamp: 0 }; - expect(areRelated(a, b)).to.be.true; + expect(areEntriesRelated(a, b)).to.be.true; }); @@ -1489,7 +1533,7 @@ describe('ExecutionLog', function() { const a = { type: EXECUTION_LOG_ENTRY_TYPE.MESSAGE_SUBSCRIPTION, data: { messageSubscriptionKey: '3', messageSubscriptionState: 'CREATED' }, timestamp: 0 }; const b = { type: EXECUTION_LOG_ENTRY_TYPE.MESSAGE_SUBSCRIPTION, data: { messageSubscriptionKey: '3', messageSubscriptionState: 'CORRELATED' }, timestamp: 0 }; - expect(areRelated(a, b)).to.be.true; + expect(areEntriesRelated(a, b)).to.be.true; }); @@ -1497,7 +1541,47 @@ describe('ExecutionLog', function() { const a = { type: EXECUTION_LOG_ENTRY_TYPE.USER_TASK, data: { userTaskKey: '1', state: 'CREATED' }, timestamp: 0 }; const b = { type: EXECUTION_LOG_ENTRY_TYPE.ELEMENT_INSTANCE, data: { state: 'ACTIVE' }, timestamp: 0 }; - expect(areRelated(a, b)).to.be.false; + expect(areEntriesRelated(a, b)).to.be.false; + }); + + }); + + + describe('compareEntryTimestamps', function() { + + it('should return negative when a is earlier', function() { + const a = { timestamp: 100 }; + const b = { timestamp: 200 }; + + expect(compareEntryTimestamps(a, b)).to.be.below(0); + }); + + + it('should return positive when a is later', function() { + const a = { timestamp: 300 }; + const b = { timestamp: 100 }; + + expect(compareEntryTimestamps(a, b)).to.be.above(0); + }); + + + it('should return 0 for equal timestamps', function() { + const a = { timestamp: 100 }; + const b = { timestamp: 100 }; + + expect(compareEntryTimestamps(a, b)).to.equal(0); + }); + + }); + + + describe('compareEntryOrders', function() { + + it('should order entries by order', function() { + const a = { type: EXECUTION_LOG_ENTRY_TYPE.ELEMENT_INSTANCE, data: { elementId: 'Task_1', state: 'ACTIVE' }, timestamp: 0 }; + const b = { type: EXECUTION_LOG_ENTRY_TYPE.JOB, data: { elementId: 'Task_1', state: 'CREATED', kind: 'BPMN_ELEMENT' }, timestamp: 0 }; + + expect(compareEntryOrders(a, b)).to.be.below(0); }); }); From d3dd021658cea237d1340c5b342d390825a64abf Mon Sep 17 00:00:00 2001 From: Philipp Fromme Date: Sat, 28 Mar 2026 14:23:14 +0100 Subject: [PATCH 06/11] fix(log): show waiting states outside of log Related to https://github.com/camunda/camunda-modeler/issues/5805 --- lib/components/Output/ExecutionLog.jsx | 141 +-------- lib/components/Output/Output.jsx | 135 +++++++- lib/style/style.scss | 27 ++ test/ExecutionLog.spec.js | 2 - test/components/Output/ExecutionLog.spec.js | 280 ----------------- test/components/Output/Output.spec.js | 322 +++++++++++++++++++- 6 files changed, 478 insertions(+), 429 deletions(-) diff --git a/lib/components/Output/ExecutionLog.jsx b/lib/components/Output/ExecutionLog.jsx index da0c932..7855fdc 100644 --- a/lib/components/Output/ExecutionLog.jsx +++ b/lib/components/Output/ExecutionLog.jsx @@ -8,14 +8,9 @@ import React, { useState } from 'react'; import { ChevronRight, - ChevronDown, - Email, - Launch, - TaskComplete + ChevronDown } from '@carbon/icons-react'; -import { Link } from '@carbon/react'; - import classNames from 'classnames'; import { @@ -24,8 +19,6 @@ import { formatElementType, } from '../../ExecutionLog'; -import { getTasklistUrl } from '../../utils/getTasklistUrl'; - const STATUS_LABELS = { deploying: 'Deploying process', deployed: 'Process deployed', @@ -390,11 +383,9 @@ function getActiveEntries(entries, isTaskExecuting) { /** * @param {Object} props * @param {ExecutionLogEntry[]} props.entries - * @param {string} [props.tasklistBaseUrl] - * @param {string|null} [props.currentOperateUrl] * @param {boolean} [props.isTaskExecuting] */ -export function ExecutionLog({ entries, tasklistBaseUrl, currentOperateUrl, isTaskExecuting }) { +export function ExecutionLog({ entries, isTaskExecuting }) { if (!entries.length) { return (
@@ -435,21 +426,6 @@ export function ExecutionLog({ entries, tasklistBaseUrl, currentOperateUrl, isTa )) } - - -
); } @@ -579,116 +555,3 @@ function LogEntry({ entry }) { ); } - -function JobCallToAction({ entries, currentOperateUrl, isTaskExecuting }) { - if (!isTaskExecuting) { - return null; - } - - const hasPendingExecutionListenerJob = entries.some( - entry => entry.type === EXECUTION_LOG_ENTRY_TYPE.JOB - && entry.data.state !== 'COMPLETED' - ); - - if (!hasPendingExecutionListenerJob) { - return null; - } - - return ( -
-
- - Waiting for job completion -
-

- Ensure the corresponding job is completed to continue the test execution. -

- { currentOperateUrl && ( - - Open in Operate - - ) } -
- ); -} - -function MessageSubscriptionCallToAction({ entries, currentOperateUrl, isTaskExecuting }) { - if (!isTaskExecuting) { - return null; - } - - const hasActiveSubscription = entries.some( - entry => entry.type === EXECUTION_LOG_ENTRY_TYPE.MESSAGE_SUBSCRIPTION - && entry.data.messageSubscriptionState === 'CREATED' - ); - - if (!hasActiveSubscription) { - return null; - } - - return ( -
-
- - Waiting for message correlation -
-

- Ensure the required message is correlated to continue the test execution. -

- { currentOperateUrl && ( - - Open in Operate - - ) } -
- ); -} - -function UserTaskCallToAction({ entries, tasklistBaseUrl, isTaskExecuting }) { - if (!isTaskExecuting) { - return null; - } - - const userTask = entries.find( - entry => entry.type === EXECUTION_LOG_ENTRY_TYPE.USER_TASK - && entry.data.state === USER_TASK_STATES.CREATED - ); - - if (!userTask) { - return null; - } - - const tasklistUrl = getTasklistUrl(tasklistBaseUrl, userTask.data.userTaskKey); - - return ( -
-
- - Waiting for user task completion -
-

- Complete the user task to continue the test execution. -

- { tasklistUrl && ( - - Open in Tasklist - - ) } -
- ); -} diff --git a/lib/components/Output/Output.jsx b/lib/components/Output/Output.jsx index 8472766..b176ca5 100644 --- a/lib/components/Output/Output.jsx +++ b/lib/components/Output/Output.jsx @@ -6,6 +6,9 @@ * @import { * ElementOutput, * ExecutionLogEntry, + * ExecutionLogJobEntry, + * ExecutionLogUserTaskEntry, + * ExecutionLogMessageSubscriptionEntry, * TaskExecutionState * } from '../../types'; */ @@ -35,6 +38,8 @@ import { ExecutionLog } from './ExecutionLog'; import { PluginContext } from '../shared/plugins'; import Tooltip from '../shared/Tooltip'; import { SCOPES, pickVariables } from '../../utils/variables'; +import { EXECUTION_LOG_ENTRY_TYPE } from '../../ExecutionLog'; +import { getTasklistUrl } from '../../utils/getTasklistUrl'; /** * @param {Object} props @@ -108,7 +113,11 @@ export default function Output({ return (
{ - isTaskExecuting && + isTaskExecuting && } { !isTaskExecuting && output && ( 0 ? ( ) : ( @@ -319,13 +326,114 @@ function EmptyState() { ); } -function ExecutingBanner({ currentOperateUrl }) { +/** + * Get the waiting context describing what the execution is currently blocked on. + * Returns null if nothing is being waited on. + * + * @param {ExecutionLogEntry[]} [entries] + * @param {string} [tasklistBaseUrl] + * @param {string|null} [currentOperateUrl] + * + * @returns {{ title: string, description: React.ReactNode, linkUrl: string|null, linkLabel: string } | null} + */ +export function getWaitingContext(entries, tasklistBaseUrl, currentOperateUrl) { + if (!entries || !entries.length) { + return null; + } + + const terminalUserTaskKeys = new Set( + /** @type {ExecutionLogUserTaskEntry[]} */ (entries + .filter(entry => entry.type === EXECUTION_LOG_ENTRY_TYPE.USER_TASK + && entry.data.state !== 'CREATED')) + .map(entry => entry.data.userTaskKey) + ); + + const pendingUserTask = /** @type {ExecutionLogUserTaskEntry|undefined} */ (entries.find( + entry => entry.type === EXECUTION_LOG_ENTRY_TYPE.USER_TASK + && entry.data.state === 'CREATED' + && !terminalUserTaskKeys.has(entry.data.userTaskKey) + )); + + if (pendingUserTask) { + const name = pendingUserTask.data.name || pendingUserTask.data.elementId; + const tasklistUrl = getTasklistUrl(tasklistBaseUrl || '', pendingUserTask.data.userTaskKey || ''); + + return { + title: 'Waiting for user task completion', + description: name + ? <>Complete the { name } user task to continue the test execution. + : 'Complete the user task to continue the test execution.', + linkUrl: tasklistUrl || null, + linkLabel: 'Open in Tasklist' + }; + } + + const correlatedSubscriptionKeys = new Set( + /** @type {ExecutionLogMessageSubscriptionEntry[]} */ (entries + .filter(entry => entry.type === EXECUTION_LOG_ENTRY_TYPE.MESSAGE_SUBSCRIPTION + && entry.data.messageSubscriptionState !== 'CREATED')) + .map(entry => entry.data.messageSubscriptionKey) + ); + + const activeSubscription = /** @type {ExecutionLogMessageSubscriptionEntry|undefined} */ (entries.find( + entry => entry.type === EXECUTION_LOG_ENTRY_TYPE.MESSAGE_SUBSCRIPTION + && entry.data.messageSubscriptionState === 'CREATED' + && !correlatedSubscriptionKeys.has(entry.data.messageSubscriptionKey) + )); + + if (activeSubscription) { + const messageName = activeSubscription.data.messageName; + + return { + title: 'Waiting for message correlation', + description: messageName + ? <>Ensure the { messageName } message is correlated to continue the test execution. + : 'Ensure the required message is correlated to continue the test execution.', + linkUrl: currentOperateUrl || null, + linkLabel: 'Open in Operate' + }; + } + + const terminalJobKeys = new Set( + /** @type {ExecutionLogJobEntry[]} */ (entries + .filter(entry => entry.type === EXECUTION_LOG_ENTRY_TYPE.JOB + && entry.data.state !== 'CREATED')) + .map(entry => entry.data.jobKey) + ); + + const pendingJob = /** @type {ExecutionLogJobEntry|undefined} */ (entries.find( + entry => entry.type === EXECUTION_LOG_ENTRY_TYPE.JOB + && entry.data.state === 'CREATED' + && !terminalJobKeys.has(entry.data.jobKey) + )); + + if (pendingJob) { + const jobType = pendingJob.data.type; + + return { + title: 'Waiting for job completion', + description: jobType + ? <>Ensure the { jobType } job is completed to continue the test execution. + : 'Ensure the corresponding job is completed to continue the test execution.', + linkUrl: currentOperateUrl || null, + linkLabel: 'Open in Operate' + }; + } + + return null; +} + +function ExecutingBanner({ currentOperateUrl, entries, tasklistBaseUrl }) { + const waitingContext = getWaitingContext(entries, tasklistBaseUrl, currentOperateUrl); + return (
- Running test... + + { waitingContext ? waitingContext.title : 'Running test...' } +
{ currentOperateUrl && ( ) }
+ { waitingContext && ( +
+ { waitingContext.description && ( +

{ waitingContext.description }

+ ) } + { waitingContext.linkUrl && waitingContext.linkUrl !== currentOperateUrl && ( + + { waitingContext.linkLabel } + + ) } +
+ ) }
); } diff --git a/lib/style/style.scss b/lib/style/style.scss index 4de238a..398d796 100644 --- a/lib/style/style.scss +++ b/lib/style/style.scss @@ -273,6 +273,16 @@ border-radius: 4px; margin: 12px 12px 0; + .cds--inline-loading__animation { + margin-inline-end: 2px; + + .cds--loading--small { + block-size: 14px; + inline-size: 14px; + line-height: 14px; + } + } + &.output__banner--success { background-color: var(--color-success-bg); border: 1px solid var(--color-success-border); @@ -362,6 +372,18 @@ min-width: 0; } + .output__banner-tag { + color: var(--color-text-secondary); + white-space: nowrap; + overflow: clip visible; + text-overflow: ellipsis; + min-width: 0; + border-radius: 4px; + background-color: var(--color-bg-light); + padding: 2px 4px; + font-size: 12px; + } + .output__banner-timing { color: var(--color-text-secondary); white-space: nowrap; @@ -393,6 +415,11 @@ .output__banner-details-content { margin: 0; color: var(--color-text-secondary); + font-size: 14px; + } + + .output__banner-details-link { + margin-top: 6px; } } diff --git a/test/ExecutionLog.spec.js b/test/ExecutionLog.spec.js index 29f519f..be154fb 100644 --- a/test/ExecutionLog.spec.js +++ b/test/ExecutionLog.spec.js @@ -17,7 +17,6 @@ import { createGetProcessInstanceElementInstancesResponse, createGetProcessInstanceJobsResponse, createGetProcessInstanceMessageSubscriptionsResponse, - createGetProcessInstanceResponse, createGetProcessInstanceUserTasksResponse, createGetProcessInstanceVariablesResponse, createElementInstanceDetails, @@ -26,7 +25,6 @@ import { createMessageSubscriptionDetails, createMockDate, createMockTimestamp, - createProcessInstanceDetails, createUserTaskDetails, ONE_SECOND_MS, DEFAULT_PROCESS_INSTANCE_KEY, diff --git a/test/components/Output/ExecutionLog.spec.js b/test/components/Output/ExecutionLog.spec.js index 0ba4f00..67a5203 100644 --- a/test/components/Output/ExecutionLog.spec.js +++ b/test/components/Output/ExecutionLog.spec.js @@ -1084,282 +1084,6 @@ describe('ExecutionLog', function() { }); - describe('job CTA', function() { - - it('should render CTA for created job while executing', function() { - - // given - const entries = [ - createJobEntry(createJobDetails(), createMockTimestamp(), { - state: 'CREATED', - type: 'io.camunda:http-json:1' - }) - ]; - - // when - const { container } = renderExecutionLog({ - entries, - isTaskExecuting: true, - currentOperateUrl: 'https://operate.example.com' - }); - - // then - expect(container.querySelector('.execution-log__cta-link')).to.exist; - expect(container.querySelector('.execution-log__cta-link').textContent).to.include('Open in Operate'); - expect(container.querySelector('.execution-log__cta-link').getAttribute('href')).to.equal('https://operate.example.com'); - }); - - - it('should NOT render Operate link when currentOperateUrl is not set', function() { - - // given - const entries = [ - createJobEntry(createJobDetails(), createMockTimestamp(), { - state: 'CREATED', - type: 'io.camunda:http-json:1' - }) - ]; - - // when - const { container } = renderExecutionLog({ - entries, - isTaskExecuting: true - }); - - // then - expect(container.querySelector('.execution-log__cta')).to.exist; - expect(container.querySelector('.execution-log__cta-link')).to.not.exist; - }); - - - it('should NOT render CTA when not executing', function() { - - // given - const entries = [ - createJobEntry(createJobDetails(), createMockTimestamp(), { - state: 'CREATED', - type: 'io.camunda:http-json:1' - }) - ]; - - // when - const { container } = renderExecutionLog({ - entries, - isTaskExecuting: false, - currentOperateUrl: 'https://operate.example.com' - }); - - // then - expect(container.querySelector('.execution-log__cta-link')).to.not.exist; - }); - - - it('should NOT render CTA when job is completed', function() { - - // given - const entries = [ - createJobEntry(createJobDetails(), createMockTimestamp(), { - state: 'COMPLETED', - type: 'io.camunda:http-json:1' - }) - ]; - - // when - const { container } = renderExecutionLog({ - entries, - isTaskExecuting: true, - currentOperateUrl: 'https://operate.example.com' - }); - - // then - expect(container.querySelector('.execution-log__cta-link')).to.not.exist; - }); - - }); - - - describe('message subscription CTA', function() { - - it('should render CTA for created message subscription while executing', function() { - - // given - const entries = [ - createMessageSubscriptionEntry({ - messageSubscriptionState: 'CREATED' - }) - ]; - - // when - const { container } = renderExecutionLog({ - entries, - isTaskExecuting: true, - currentOperateUrl: 'https://operate.example.com' - }); - - // then - expect(container.querySelector('.execution-log__cta-link')).to.exist; - expect(container.querySelector('.execution-log__cta-link').textContent).to.include('Open in Operate'); - expect(container.querySelector('.execution-log__cta-link').getAttribute('href')).to.equal('https://operate.example.com'); - }); - - - it('should NOT render Operate link when currentOperateUrl is not set', function() { - - // given - const entries = [ - createMessageSubscriptionEntry({ - messageSubscriptionState: 'CREATED' - }) - ]; - - // when - const { container } = renderExecutionLog({ - entries, - isTaskExecuting: true - }); - - // then - expect(container.querySelector('.execution-log__cta')).to.exist; - expect(container.querySelector('.execution-log__cta-link')).to.not.exist; - }); - - - it('should NOT render CTA when not executing', function() { - - // given - const entries = [ - createMessageSubscriptionEntry({ - messageSubscriptionState: 'CREATED' - }) - ]; - - // when - const { container } = renderExecutionLog({ - entries, - isTaskExecuting: false, - currentOperateUrl: 'https://operate.example.com' - }); - - // then - expect(container.querySelector('.execution-log__cta')).to.not.exist; - }); - - - it('should NOT render CTA when message is correlated', function() { - - // given - const entries = [ - createMessageSubscriptionEntry({ - messageSubscriptionState: 'CORRELATED' - }) - ]; - - // when - const { container } = renderExecutionLog({ - entries, - isTaskExecuting: true, - currentOperateUrl: 'https://operate.example.com' - }); - - // then - expect(container.querySelector('.execution-log__cta')).to.not.exist; - }); - - }); - - - describe('user task CTA', function() { - - it('should render CTA for created user task while executing', function() { - - // given - const entries = [ - createUserTaskEntry({ - state: 'CREATED', - userTaskKey: '1' - }) - ]; - - // when - const { container } = renderExecutionLog({ - entries, - isTaskExecuting: true, - tasklistBaseUrl: 'https://tasklist.example.com' - }); - - // then - expect(container.querySelector('.execution-log__cta')).to.exist; - expect(container.querySelector('.execution-log__cta-link')).to.exist; - expect(container.querySelector('.execution-log__cta-link').textContent).to.include('Open in Tasklist'); - expect(container.querySelector('.execution-log__cta-link').getAttribute('href')).to.equal('https://tasklist.example.com/1'); - }); - - - it('should NOT render tasklist link when tasklistBaseUrl is not set', function() { - - // given - const entries = [ - createUserTaskEntry({ - state: 'CREATED', - userTaskKey: '1' - }) - ]; - - // when - const { container } = renderExecutionLog({ - entries, - isTaskExecuting: true - }); - - // then - expect(container.querySelector('.execution-log__cta')).to.exist; - expect(container.querySelector('.execution-log__cta-link')).to.not.exist; - }); - - - it('should NOT render CTA when not executing', function() { - - // given - const entries = [ - createUserTaskEntry({ - state: 'CREATED', - userTaskKey: '1' - }) - ]; - - // when - const { container } = renderExecutionLog({ - entries, - isTaskExecuting: false - }); - - // then - expect(container.querySelector('.execution-log__cta')).to.not.exist; - }); - - - it('should NOT render CTA when user task is completed', function() { - - // given - const entries = [ - createUserTaskEntry({ - state: 'COMPLETED' - }) - ]; - - // when - const { container } = renderExecutionLog({ - entries, - isTaskExecuting: true - }); - - // then - expect(container.querySelector('.execution-log__cta')).to.not.exist; - }); - - }); - - describe('multiple entries', function() { it('should render multiple entries in order', function() { @@ -1478,16 +1202,12 @@ describe('ExecutionLog', function() { function renderExecutionLog(props = {}) { const { entries = [], - tasklistBaseUrl, - currentOperateUrl, isTaskExecuting = false } = props; return render( ); diff --git a/test/components/Output/Output.spec.js b/test/components/Output/Output.spec.js index 7f5eabb..2564d65 100644 --- a/test/components/Output/Output.spec.js +++ b/test/components/Output/Output.spec.js @@ -9,12 +9,21 @@ import React from 'react'; import { render } from '@testing-library/react'; -import Output from '../../../lib/components/Output/Output'; +import Output, { getWaitingContext } from '../../../lib/components/Output/Output'; + +import { + createJobEntry, + EXECUTION_LOG_ENTRY_TYPE +} from '../../../lib/ExecutionLog'; import { SCOPES } from '../../../lib/utils/variables'; import { PluginContext, usePluginsProviderValue } from '../../../lib/components/shared/plugins'; import { pickVariables } from '../../../lib/utils/variables'; -import { createIncidentDetails } from '../../helpers/responses'; +import { + createIncidentDetails, + createJobDetails, + createMockTimestamp +} from '../../helpers/responses'; describe('Output', function() { @@ -416,6 +425,286 @@ describe('Output', function() { }); + +describe('getWaitingContext', function() { + + it('should return null for empty entries', function() { + expect(getWaitingContext([], null, null)).to.be.null; + expect(getWaitingContext(undefined, null, null)).to.be.null; + }); + + + it('should return job context for pending job', function() { + + // given + const entries = [ + createJobEntry(createJobDetails(), createMockTimestamp(), { + state: 'CREATED', + type: 'io.camunda:http-json:1' + }) + ]; + + // when + const context = getWaitingContext(entries, null, 'https://operate.example.com'); + + // then + expect(context).to.exist; + expect(context.title).to.equal('Waiting for job completion'); + expect(context.description).to.exist; + expect(context.linkUrl).to.equal('https://operate.example.com'); + expect(context.linkLabel).to.equal('Open in Operate'); + }); + + + it('should return null for completed job', function() { + + // given + const entries = [ + createJobEntry(createJobDetails(), createMockTimestamp(), { + state: 'COMPLETED', + type: 'io.camunda:http-json:1' + }) + ]; + + // when + const context = getWaitingContext(entries, null, 'https://operate.example.com'); + + // then + expect(context).to.be.null; + }); + + + it('should return null for failed job', function() { + + // given + const entries = [ + createJobEntry(createJobDetails(), createMockTimestamp(), { + state: 'FAILED', + type: 'io.camunda:http-json:1' + }) + ]; + + // when + const context = getWaitingContext(entries, null, 'https://operate.example.com'); + + // then + expect(context).to.be.null; + }); + + + it('should skip CREATED job when a FAILED entry exists for the same jobKey', function() { + + // given + const entries = [ + createJobEntry(createJobDetails(), createMockTimestamp(), { + state: 'CREATED', + type: 'io.camunda:http-json:1', + jobKey: '100' + }), + createJobEntry(createJobDetails(), createMockTimestamp(), { + state: 'FAILED', + type: 'io.camunda:http-json:1', + jobKey: '100' + }) + ]; + + // when + const context = getWaitingContext(entries, null, 'https://operate.example.com'); + + // then + expect(context).to.be.null; + }); + + + it('should skip job with CREATED entry when a COMPLETED entry exists for the same jobKey', function() { + + // given + const entries = [ + createJobEntry(createJobDetails(), createMockTimestamp(), { + state: 'CREATED', + type: 'io.camunda:listener-job:1', + jobKey: '100' + }), + createJobEntry(createJobDetails(), createMockTimestamp(), { + state: 'COMPLETED', + type: 'io.camunda:listener-job:1', + jobKey: '100' + }), + createJobEntry(createJobDetails(), createMockTimestamp(), { + state: 'CREATED', + type: 'io.camunda:http-json:1', + jobKey: '200' + }) + ]; + + // when + const context = getWaitingContext(entries, null, 'https://operate.example.com'); + + // then + expect(context).to.exist; + expect(context.title).to.equal('Waiting for job completion'); + expect(context.description).to.exist; + }); + + + it('should return null when all jobs have matching COMPLETED entries', function() { + + // given + const entries = [ + createJobEntry(createJobDetails(), createMockTimestamp(), { + state: 'CREATED', + type: 'io.camunda:listener-job:1', + jobKey: '100' + }), + createJobEntry(createJobDetails(), createMockTimestamp(), { + state: 'COMPLETED', + type: 'io.camunda:listener-job:1', + jobKey: '100' + }) + ]; + + // when + const context = getWaitingContext(entries, null, 'https://operate.example.com'); + + // then + expect(context).to.be.null; + }); + + + it('should return job context without link when no operateUrl', function() { + + // given + const entries = [ + createJobEntry(createJobDetails(), createMockTimestamp(), { + state: 'CREATED', + type: 'io.camunda:http-json:1' + }) + ]; + + // when + const context = getWaitingContext(entries, null, null); + + // then + expect(context).to.exist; + expect(context.linkUrl).to.be.null; + }); + + + it('should return message subscription context', function() { + + // given + const entries = [ + createMessageSubscriptionEntry({ + messageSubscriptionState: 'CREATED' + }) + ]; + + // when + const context = getWaitingContext(entries, null, 'https://operate.example.com'); + + // then + expect(context).to.exist; + expect(context.title).to.equal('Waiting for message correlation'); + expect(context.description).to.exist; + expect(context.linkUrl).to.equal('https://operate.example.com'); + expect(context.linkLabel).to.equal('Open in Operate'); + }); + + + it('should return null for correlated message', function() { + + // given + const entries = [ + createMessageSubscriptionEntry({ + messageSubscriptionState: 'CORRELATED' + }) + ]; + + // when + const context = getWaitingContext(entries, null, 'https://operate.example.com'); + + // then + expect(context).to.be.null; + }); + + + it('should return user task context', function() { + + // given + const entries = [ + createUserTaskEntry({ + state: 'CREATED', + userTaskKey: '1' + }) + ]; + + // when + const context = getWaitingContext(entries, 'https://tasklist.example.com', null); + + // then + expect(context).to.exist; + expect(context.title).to.equal('Waiting for user task completion'); + expect(context.description).to.exist; + expect(context.linkUrl).to.equal('https://tasklist.example.com/1'); + expect(context.linkLabel).to.equal('Open in Tasklist'); + }); + + + it('should return null for completed user task', function() { + + // given + const entries = [ + createUserTaskEntry({ + state: 'COMPLETED' + }) + ]; + + // when + const context = getWaitingContext(entries, 'https://tasklist.example.com', null); + + // then + expect(context).to.be.null; + }); + + + it('should return user task context without link when no tasklistBaseUrl', function() { + + // given + const entries = [ + createUserTaskEntry({ + state: 'CREATED', + userTaskKey: '1' + }) + ]; + + // when + const context = getWaitingContext(entries, null, null); + + // then + expect(context).to.exist; + expect(context.linkUrl).to.be.null; + }); + + + it('should prioritize user task over message and job', function() { + + // given + const entries = [ + createJobEntry(createJobDetails(), createMockTimestamp(), { state: 'CREATED' }), + createMessageSubscriptionEntry({ messageSubscriptionState: 'CREATED' }), + createUserTaskEntry({ state: 'CREATED', userTaskKey: '1' }) + ]; + + // when + const context = getWaitingContext(entries, null, null); + + // then + expect(context.title).to.equal('Waiting for user task completion'); + }); + +}); + + function renderWithProps(props = {}) { const { element, @@ -457,4 +746,31 @@ const Wrapper = (props) => { { props.children } ); -}; \ No newline at end of file +}; + +function createUserTaskEntry(data, timestamp = 0) { + return { + type: EXECUTION_LOG_ENTRY_TYPE.USER_TASK, + data: { + state: 'CREATED', + name: 'Foo', + userTaskKey: '1', + ...data + }, + timestamp + }; +} + +function createMessageSubscriptionEntry(data, timestamp = 0) { + return { + type: EXECUTION_LOG_ENTRY_TYPE.MESSAGE_SUBSCRIPTION, + data: { + messageName: 'Message_1', + elementId: 'Event_1', + messageSubscriptionState: 'CREATED', + messageSubscriptionKey: '1', + ...data + }, + timestamp + }; +} \ No newline at end of file From f54f2a3cf24b388c26b61a24a1d6434240c2091b Mon Sep 17 00:00:00 2001 From: Philipp Fromme Date: Mon, 30 Mar 2026 12:07:17 +0200 Subject: [PATCH 07/11] fix: clarify user task instance --- lib/components/Output/ExecutionLog.jsx | 6 +++--- test/components/Output/ExecutionLog.spec.js | 6 +++--- 2 files changed, 6 insertions(+), 6 deletions(-) diff --git a/lib/components/Output/ExecutionLog.jsx b/lib/components/Output/ExecutionLog.jsx index 7855fdc..d5c25d7 100644 --- a/lib/components/Output/ExecutionLog.jsx +++ b/lib/components/Output/ExecutionLog.jsx @@ -70,11 +70,11 @@ function getJobLabel(data) { function getUserTaskLabel(data) { if (data.state === USER_TASK_STATES.COMPLETED) { - return 'User task completed'; + return 'User task instance completed'; } else if (data.state === USER_TASK_STATES.CANCELED) { - return 'User task canceled'; + return 'User task instance canceled'; } else if (data.state === USER_TASK_STATES.CREATED) { - return 'User task created'; + return 'User task instance created'; } } diff --git a/test/components/Output/ExecutionLog.spec.js b/test/components/Output/ExecutionLog.spec.js index 67a5203..842a161 100644 --- a/test/components/Output/ExecutionLog.spec.js +++ b/test/components/Output/ExecutionLog.spec.js @@ -529,7 +529,7 @@ describe('ExecutionLog', function() { const { queryByText } = renderExecutionLog({ entries }); // then - expect(queryByText('User task created')).to.exist; + expect(queryByText('User task instance created')).to.exist; }); @@ -546,7 +546,7 @@ describe('ExecutionLog', function() { const { queryByText } = renderExecutionLog({ entries }); // then - expect(queryByText('User task completed')).to.exist; + expect(queryByText('User task instance completed')).to.exist; }); @@ -563,7 +563,7 @@ describe('ExecutionLog', function() { const { queryByText } = renderExecutionLog({ entries }); // then - expect(queryByText('User task canceled')).to.exist; + expect(queryByText('User task instance canceled')).to.exist; }); From beab61afc64316ebf4abe272d851d5d01e9944b7 Mon Sep 17 00:00:00 2001 From: Philipp Fromme Date: Mon, 30 Mar 2026 13:25:47 +0200 Subject: [PATCH 08/11] chore(CHANGELOG): update --- CHANGELOG.md | 4 +++- 1 file changed, 3 insertions(+), 1 deletion(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index b32d56a..ef9c3c2 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -8,7 +8,9 @@ ___Note:__ Yet to be released changes appear here._ ## 4.0.0 -* `FIX`: show CTAs for child elements inside subprocesses ([#92](https://github.com/camunda/task-testing/pull/92)) +* `FIX`: show waiting states for child elements inside subprocesses ([#92](https://github.com/camunda/task-testing/pull/92)) +* `FIX`: fix execution log order by using causal ordering for state entries and related entries with same timestamp ([#91](https://github.com/camunda/task-testing/pull/91)) +* `FIX`: move waiting states out of log so they are always visible when existing ([#91](https://github.com/camunda/task-testing/pull/91)) ### Breaking Changes From 064a16b4891ca6a58bcbf20d5fbfb687638c63bf Mon Sep 17 00:00:00 2001 From: Philipp Fromme Date: Mon, 30 Mar 2026 13:34:09 +0200 Subject: [PATCH 09/11] fix: use insertion index as final tiebreaker --- lib/ExecutionLog.js | 29 ++++++++++++++++------------- 1 file changed, 16 insertions(+), 13 deletions(-) diff --git a/lib/ExecutionLog.js b/lib/ExecutionLog.js index 98812c5..0fbd520 100644 --- a/lib/ExecutionLog.js +++ b/lib/ExecutionLog.js @@ -826,20 +826,23 @@ export default class ExecutionLog { // 6. Sort chronologically, with causal tiebreaking for equal timestamps. // Status entries (deployed, instance-started, terminal) are always pinned // to their canonical position regardless of timestamp, because engine - // timestamps can arrive slightly out of causal order. - entries.sort((a, b) => { - if (isStatusEntry(a) || isStatusEntry(b)) { - return compareEntryOrders(a, b); - } else if (!areEntryTimestampsEqual(a, b)) { - return compareEntryTimestamps(a, b); - } else if (areEntriesRelated(a, b)) { - return compareEntryOrders(a, b); - } - - return 0; - }); + // timestamps can arrive slightly out of causal order. Insertion index is + // used as a deterministic final tiebreaker to guarantee a strict total + // order. + this._entries = entries + .map((entry, index) => /** @type {[number, ExecutionLogEntry]} */ ([ index, entry ])) + .sort(([ indexA, entryA ], [ indexB, entryB ]) => { + if (isStatusEntry(entryA) || isStatusEntry(entryB)) { + return compareEntryOrders(entryA, entryB); + } else if (!areEntryTimestampsEqual(entryA, entryB)) { + return compareEntryTimestamps(entryA, entryB); + } else if (areEntriesRelated(entryA, entryB)) { + return compareEntryOrders(entryA, entryB); + } - this._entries = entries; + return indexA - indexB; + }) + .map(([ , entry ]) => entry); } } From 10e3887147202e26683a1cff0b157216c9239f38 Mon Sep 17 00:00:00 2001 From: Philipp Fromme Date: Mon, 30 Mar 2026 15:50:52 +0200 Subject: [PATCH 10/11] fix(log): consider containment order --- lib/ExecutionLog.js | 74 +++++++++- test/ExecutionLog.spec.js | 245 +++++++++++++++++++++++++++++++- test/fixtures/subprocesses.bpmn | 117 +++++++++++++++ 3 files changed, 434 insertions(+), 2 deletions(-) create mode 100644 test/fixtures/subprocesses.bpmn diff --git a/lib/ExecutionLog.js b/lib/ExecutionLog.js index 0fbd520..8875b63 100644 --- a/lib/ExecutionLog.js +++ b/lib/ExecutionLog.js @@ -572,6 +572,71 @@ export function compareEntryOrders(a, b) { return getEntryOrder(a) - getEntryOrder(b); } +/** + * Check whether element `ancestorId` is an ancestor of element `descendantId` + * by walking up the parent chain in the element registry. + * + * @param {Object|null} elementRegistry + * @param {string} ancestorId + * @param {string} descendantId + * + * @returns {boolean} + */ +export function isAncestor(elementRegistry, ancestorId, descendantId) { + if (!elementRegistry || !ancestorId || !descendantId || ancestorId === descendantId) { + return false; + } + + const descendant = elementRegistry.get(descendantId); + + if (!descendant) { + return false; + } + + let current = descendant.parent; + + while (current) { + if (current.id === ancestorId) { + return true; + } + + current = current.parent; + } + + return false; +} + +/** + * Compare two element-instance entries by containment. When one element is an + * ancestor of the other, the ancestor's ACTIVE entry sorts first and its + * terminal entry sorts last. Returns 0 when neither entry is an + * element-instance or no containment relationship exists. + * + * @param {Object|null} elementRegistry + * @param {ExecutionLogEntry} a + * @param {ExecutionLogEntry} b + * + * @returns {number} + */ +export function compareContainmentOrder(elementRegistry, a, b) { + if (!isElementInstanceEntry(a) || !isElementInstanceEntry(b)) { + return 0; + } + + const idA = /** @type {ExecutionLogElementInstanceData} */ (a.data).elementId; + const idB = /** @type {ExecutionLogElementInstanceData} */ (b.data).elementId; + + if (isAncestor(elementRegistry, idA, idB)) { + return getEntryOrder(a) === ENTRY_ORDER.ELEMENT_ACTIVE ? -1 : 1; + } + + if (isAncestor(elementRegistry, idB, idA)) { + return getEntryOrder(b) === ENTRY_ORDER.ELEMENT_ACTIVE ? 1 : -1; + } + + return 0; +} + export default class ExecutionLog { /** @@ -829,6 +894,8 @@ export default class ExecutionLog { // timestamps can arrive slightly out of causal order. Insertion index is // used as a deterministic final tiebreaker to guarantee a strict total // order. + const elementRegistry = this._elementRegistry; + this._entries = entries .map((entry, index) => /** @type {[number, ExecutionLogEntry]} */ ([ index, entry ])) .sort(([ indexA, entryA ], [ indexB, entryB ]) => { @@ -840,7 +907,8 @@ export default class ExecutionLog { return compareEntryOrders(entryA, entryB); } - return indexA - indexB; + return compareContainmentOrder(elementRegistry, entryA, entryB) + || (indexA - indexB); }) .map(([ , entry ]) => entry); } @@ -848,4 +916,8 @@ export default class ExecutionLog { function isStatusEntry(entry) { return entry.type === EXECUTION_LOG_ENTRY_TYPE.STATUS; +} + +function isElementInstanceEntry(entry) { + return entry.type === EXECUTION_LOG_ENTRY_TYPE.ELEMENT_INSTANCE; } \ No newline at end of file diff --git a/test/ExecutionLog.spec.js b/test/ExecutionLog.spec.js index be154fb..4838184 100644 --- a/test/ExecutionLog.spec.js +++ b/test/ExecutionLog.spec.js @@ -3,14 +3,20 @@ import ExecutionLog, { EXECUTION_LOG_ENTRY_TYPE, ENTRY_ORDER, areEntriesRelated, + compareContainmentOrder, compareEntryOrders, compareEntryTimestamps, formatElementType, - getEntryOrder + getEntryOrder, + isAncestor } from '../lib/ExecutionLog'; import { TASK_EXECUTION_FINISHED_REASON } from '../lib/TaskExecution'; +import { bootstrapModeler, inject } from './helpers/modeler'; + +import subprocessesXML from './fixtures/subprocesses.bpmn'; + import { createDeployResponse, createStartInstanceResponse, @@ -1351,6 +1357,201 @@ describe('ExecutionLog', function() { expect(regularCompleted).to.be.lessThan(endListenerCreated); }); + + describe('containment ordering', function() { + + beforeEach(bootstrapModeler(subprocessesXML)); + + let executionLog; + + beforeEach(inject(function(injector) { + executionLog = new ExecutionLog(injector); + })); + + + it('should place sub-process COMPLETED after child COMPLETED at same timestamp', function() { + + // given + const timestamp = createMockTimestamp(); + const time = createMockDate(); + + const subProcess = createElementInstanceDetails({ + elementId: 'SubProcess_2', + elementInstanceKey: 'ei-1', + type: 'SUB_PROCESS', + state: 'COMPLETED', + startDate: time, + endDate: time + }); + + const childTask = createElementInstanceDetails({ + elementId: 'Task_1', + elementInstanceKey: 'ei-2', + type: 'TASK', + state: 'COMPLETED', + startDate: time, + endDate: time + }); + + // when + executionLog.setPolledResult(createPolledResult({ + elementInstancesResponse: createGetProcessInstanceElementInstancesResponse({ + response: { items: [ subProcess, childTask ] } + }) + }), timestamp); + + // then + const entries = executionLog.getEntries(); + const terminalEntries = entries + .filter(e => e.type === 'element-instance' && e.data?.state !== 'ACTIVE') + .map(e => e.data?.elementId); + + expect(terminalEntries.indexOf('Task_1')).to.be.lessThan( + terminalEntries.indexOf('SubProcess_2') + ); + }); + + + it('should place sub-process ACTIVE before child ACTIVE at same timestamp', function() { + + // given + const timestamp = createMockTimestamp(); + const time = createMockDate(); + + const childTask = createElementInstanceDetails({ + elementId: 'Task_1', + elementInstanceKey: 'ei-2', + type: 'TASK', + state: 'ACTIVE', + startDate: time + }); + + const subProcess = createElementInstanceDetails({ + elementId: 'SubProcess_2', + elementInstanceKey: 'ei-1', + type: 'SUB_PROCESS', + state: 'ACTIVE', + startDate: time + }); + + // when + executionLog.setPolledResult(createPolledResult({ + elementInstancesResponse: createGetProcessInstanceElementInstancesResponse({ + response: { items: [ childTask, subProcess ] } + }) + }), timestamp); + + // then + const entries = executionLog.getEntries(); + const activeEntries = entries + .filter(e => e.type === 'element-instance' && e.data?.state === 'ACTIVE') + .map(e => e.data?.elementId); + + expect(activeEntries.indexOf('SubProcess_2')).to.be.lessThan( + activeEntries.indexOf('Task_1') + ); + }); + + + it('should order deeply nested grandchild before child before ancestor for terminal entries', function() { + + // given + const timestamp = createMockTimestamp(); + const time = createMockDate(); + + const outerSubProcess = createElementInstanceDetails({ + elementId: 'SubProcess_1', + elementInstanceKey: 'ei-1', + type: 'SUB_PROCESS', + state: 'COMPLETED', + startDate: time, + endDate: time + }); + + const innerSubProcess = createElementInstanceDetails({ + elementId: 'SubProcess_2', + elementInstanceKey: 'ei-2', + type: 'SUB_PROCESS', + state: 'COMPLETED', + startDate: time, + endDate: time + }); + + const task = createElementInstanceDetails({ + elementId: 'Task_1', + elementInstanceKey: 'ei-3', + type: 'TASK', + state: 'COMPLETED', + startDate: time, + endDate: time + }); + + // when — items arrive in reverse causal order + executionLog.setPolledResult(createPolledResult({ + elementInstancesResponse: createGetProcessInstanceElementInstancesResponse({ + response: { items: [ outerSubProcess, innerSubProcess, task ] } + }) + }), timestamp); + + // then + const entries = executionLog.getEntries(); + const terminalEntries = entries + .filter(e => e.type === 'element-instance' && e.data?.state !== 'ACTIVE') + .map(e => e.data?.elementId); + + expect(terminalEntries).to.deep.equal([ + 'Task_1', + 'SubProcess_2', + 'SubProcess_1' + ]); + }); + + + it('should not reorder unrelated element instances at same timestamp', function() { + + // given — two elements in the same sub-process, neither is ancestor of the other + const timestamp = createMockTimestamp(); + const time = createMockDate(); + + const task = createElementInstanceDetails({ + elementId: 'Task_1', + elementInstanceKey: 'ei-1', + type: 'TASK', + state: 'COMPLETED', + startDate: time, + endDate: time + }); + + const endEvent = createElementInstanceDetails({ + elementId: 'EndEvent_3', + elementInstanceKey: 'ei-2', + type: 'END_EVENT', + state: 'COMPLETED', + startDate: time, + endDate: time + }); + + // when + executionLog.setPolledResult(createPolledResult({ + elementInstancesResponse: createGetProcessInstanceElementInstancesResponse({ + response: { items: [ task, endEvent ] } + }) + }), timestamp); + + // then — no containment relationship, insertion order preserved + const entries = executionLog.getEntries(); + const terminalEntries = entries + .filter(e => e.type === 'element-instance' && e.data?.state !== 'ACTIVE') + .map(e => e.data?.elementId); + + expect(terminalEntries).to.deep.equal([ + 'Task_1', + 'EndEvent_3' + ]); + }); + + }); + }); @@ -1545,6 +1746,48 @@ describe('ExecutionLog', function() { }); + describe('isAncestor', function() { + + beforeEach(bootstrapModeler(subprocessesXML)); + + + it('should return true when first element is parent of second', inject(function(elementRegistry) { + expect(isAncestor(elementRegistry, 'SubProcess_1', 'SubProcess_2')).to.be.true; + })); + + + it('should return true when first element is grandparent of second', inject(function(elementRegistry) { + expect(isAncestor(elementRegistry, 'SubProcess_1', 'Task_1')).to.be.true; + })); + + + it('should return false when elements are siblings', inject(function(elementRegistry) { + expect(isAncestor(elementRegistry, 'Task_1', 'EndEvent_3')).to.be.false; + })); + + + it('should return false when second is ancestor of first (reverse)', inject(function(elementRegistry) { + expect(isAncestor(elementRegistry, 'Task_1', 'SubProcess_2')).to.be.false; + })); + + + it('should return false for same element', inject(function(elementRegistry) { + expect(isAncestor(elementRegistry, 'SubProcess_1', 'SubProcess_1')).to.be.false; + })); + + + it('should return false when elementRegistry is null', function() { + expect(isAncestor(null, 'SubProcess_1', 'Task_1')).to.be.false; + }); + + + it('should return false when descendant is not in registry', inject(function(elementRegistry) { + expect(isAncestor(elementRegistry, 'SubProcess_1', 'Unknown_1')).to.be.false; + })); + + }); + + describe('compareEntryTimestamps', function() { it('should return negative when a is earlier', function() { diff --git a/test/fixtures/subprocesses.bpmn b/test/fixtures/subprocesses.bpmn new file mode 100644 index 0000000..9061430 --- /dev/null +++ b/test/fixtures/subprocesses.bpmn @@ -0,0 +1,117 @@ + + + + + Flow_16e7ve4 + + + Flow_16e7ve4 + Flow_1ig8wce + + Flow_1farui8 + + + Flow_1farui8 + Flow_1330ko8 + + Flow_143pihd + + + Flow_143pihd + Flow_10cx8ih + + + + Flow_10cx8ih + + + + + + Flow_1330ko8 + + + + + + Flow_1ig8wce + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + From f74fd560c9bcdf32a0f21fed8ac2184317a62bc5 Mon Sep 17 00:00:00 2001 From: Philipp Fromme Date: Mon, 30 Mar 2026 16:23:52 +0200 Subject: [PATCH 11/11] chore: simplify --- lib/ExecutionLog.js | 93 ++++++++++++++++++++++++--------------- test/ExecutionLog.spec.js | 33 +++++++------- 2 files changed, 73 insertions(+), 53 deletions(-) diff --git a/lib/ExecutionLog.js b/lib/ExecutionLog.js index 8875b63..c84739b 100644 --- a/lib/ExecutionLog.js +++ b/lib/ExecutionLog.js @@ -46,10 +46,10 @@ export const EXECUTION_LOG_ENTRY_STATUS = /** @type {const} */ ({ }); /** - * Named orders representing the causal order of execution log entries. Lower - * values are earlier in the lifecycle. Used by {@link getEntryOrder} to assign - * an order to each entry so that entries sharing a timestamp can be placed in a - * causally correct sequence. + * Named orders representing the lifecycle position of execution log entries. + * Lower values are earlier in the lifecycle. Used by {@link getEntryOrder} to + * assign an order to each entry so that entries sharing a timestamp can be + * placed in the correct sequence. */ export const ENTRY_ORDER = /** @type {const} */ ({ DEPLOYED: 0, @@ -422,8 +422,8 @@ export function formatElementType(type) { /** * Determine the {@link ENTRY_ORDER} for an execution log entry so that entries - * are placed in a causally correct sequence. Status entries (deployed, - * instance-started, terminal) are always pinned to their canonical position + * are placed in the correct lifecycle sequence. Status entries (deployed, + * instance-started, terminal) are always pinned to their lifecycle position * regardless of timestamp. For all other entries the order is used as a * tiebreaker when timestamps are equal. * @@ -487,8 +487,8 @@ export function getEntryOrder(entry) { } /** - * Check whether two execution log entries are causally related and should - * therefore be ordered by {@link ENTRY_ORDER} when they share a timestamp. + * Check whether two execution log entries are related and should therefore be + * ordered by {@link ENTRY_ORDER} when they share a timestamp. * * Runtime entries are considered related when they share an `elementId` * (linking element-instance, job, and message-subscription entries for the @@ -501,7 +501,7 @@ export function getEntryOrder(entry) { * * @returns {boolean} */ -export function areEntriesRelated(a, b) { +export function areRelated(a, b) { const elementIdA = /** @type {{ elementId?: string }} */ (a.data)?.elementId; const elementIdB = /** @type {{ elementId?: string }} */ (b.data)?.elementId; @@ -544,7 +544,7 @@ export function areEntriesRelated(a, b) { * * @returns {number} */ -export function compareEntryTimestamps(a, b) { +export function compareByTimestamp(a, b) { return a.timestamp - b.timestamp; } @@ -556,19 +556,19 @@ export function compareEntryTimestamps(a, b) { * * @returns {boolean} */ -export function areEntryTimestampsEqual(a, b) { +export function haveSameTimestamp(a, b) { return a.timestamp === b.timestamp; } /** - * Compare two entries by their causal {@link ENTRY_ORDER} (ascending). + * Compare two entries by their {@link ENTRY_ORDER} lifecycle position (ascending). * * @param {ExecutionLogEntry} a * @param {ExecutionLogEntry} b * * @returns {number} */ -export function compareEntryOrders(a, b) { +export function compareByOrder(a, b) { return getEntryOrder(a) - getEntryOrder(b); } @@ -577,8 +577,8 @@ export function compareEntryOrders(a, b) { * by walking up the parent chain in the element registry. * * @param {Object|null} elementRegistry - * @param {string} ancestorId - * @param {string} descendantId + * @param {string} [ancestorId] + * @param {string} [descendantId] * * @returns {boolean} */ @@ -618,7 +618,7 @@ export function isAncestor(elementRegistry, ancestorId, descendantId) { * * @returns {number} */ -export function compareContainmentOrder(elementRegistry, a, b) { +export function compareByContainment(elementRegistry, a, b) { if (!isElementInstanceEntry(a) || !isElementInstanceEntry(b)) { return 0; } @@ -888,32 +888,53 @@ export default class ExecutionLog { } } - // 6. Sort chronologically, with causal tiebreaking for equal timestamps. - // Status entries (deployed, instance-started, terminal) are always pinned - // to their canonical position regardless of timestamp, because engine - // timestamps can arrive slightly out of causal order. Insertion index is - // used as a deterministic final tiebreaker to guarantee a strict total - // order. + // 6. Sort by timestamp, with lifecycle-order tiebreaking for equal + // timestamps. Status entries are always pinned to their lifecycle position + // regardless of timestamp, because engine timestamps can arrive slightly + // out of order. Insertion index is used as a final tiebreaker to guarantee + // a strict total order. const elementRegistry = this._elementRegistry; - this._entries = entries - .map((entry, index) => /** @type {[number, ExecutionLogEntry]} */ ([ index, entry ])) - .sort(([ indexA, entryA ], [ indexB, entryB ]) => { - if (isStatusEntry(entryA) || isStatusEntry(entryB)) { - return compareEntryOrders(entryA, entryB); - } else if (!areEntryTimestampsEqual(entryA, entryB)) { - return compareEntryTimestamps(entryA, entryB); - } else if (areEntriesRelated(entryA, entryB)) { - return compareEntryOrders(entryA, entryB); - } + this._entries = stableSort(entries, (entryA, entryB) => { + + // Status entries → lifecycle order + if (isStatusEntry(entryA) || isStatusEntry(entryB)) { + return compareByOrder(entryA, entryB); + } + + // Different timestamp → chronological order + if (!haveSameTimestamp(entryA, entryB)) { + return compareByTimestamp(entryA, entryB); + } + + // Same timestamp and related → lifecycle order + if (areRelated(entryA, entryB)) { + return compareByOrder(entryA, entryB); + } - return compareContainmentOrder(elementRegistry, entryA, entryB) - || (indexA - indexB); - }) - .map(([ , entry ]) => entry); + // Parent-child relationship → containment order + return compareByContainment(elementRegistry, entryA, entryB); + }); } } +/** + * Sort items using a comparator, with insertion order as a stable tiebreaker. + * + * @template T + * + * @param {T[]} items + * @param {(a: T, b: T) => number} compareFn + * + * @returns {T[]} + */ +function stableSort(items, compareFn) { + return items + .map((item, index) => /** @type {[number, T]} */ ([ index, item ])) + .sort(([ indexA, a ], [ indexB, b ]) => compareFn(a, b) || (indexA - indexB)) + .map(([ , item ]) => item); +} + function isStatusEntry(entry) { return entry.type === EXECUTION_LOG_ENTRY_TYPE.STATUS; } diff --git a/test/ExecutionLog.spec.js b/test/ExecutionLog.spec.js index 4838184..31c9b20 100644 --- a/test/ExecutionLog.spec.js +++ b/test/ExecutionLog.spec.js @@ -2,10 +2,9 @@ import ExecutionLog, { EXECUTION_LOG_ENTRY_STATUS, EXECUTION_LOG_ENTRY_TYPE, ENTRY_ORDER, - areEntriesRelated, - compareContainmentOrder, - compareEntryOrders, - compareEntryTimestamps, + areRelated, + compareByOrder, + compareByTimestamp, formatElementType, getEntryOrder, isAncestor @@ -1694,13 +1693,13 @@ describe('ExecutionLog', function() { }); - describe('areEntriesRelated', function() { + describe('areRelated', function() { it('should return true for entries sharing the same elementId', function() { const a = { type: EXECUTION_LOG_ENTRY_TYPE.ELEMENT_INSTANCE, data: { elementId: 'Task_1', state: 'ACTIVE' }, timestamp: 0 }; const b = { type: EXECUTION_LOG_ENTRY_TYPE.JOB, data: { elementId: 'Task_1', state: 'CREATED' }, timestamp: 0 }; - expect(areEntriesRelated(a, b)).to.be.true; + expect(areRelated(a, b)).to.be.true; }); @@ -1708,7 +1707,7 @@ describe('ExecutionLog', function() { const a = { type: EXECUTION_LOG_ENTRY_TYPE.JOB, data: { elementId: 'Task_A', state: 'COMPLETED' }, timestamp: 0 }; const b = { type: EXECUTION_LOG_ENTRY_TYPE.JOB, data: { elementId: 'Task_B', state: 'CREATED' }, timestamp: 0 }; - expect(areEntriesRelated(a, b)).to.be.false; + expect(areRelated(a, b)).to.be.false; }); @@ -1716,7 +1715,7 @@ describe('ExecutionLog', function() { const a = { type: EXECUTION_LOG_ENTRY_TYPE.JOB, data: { jobKey: '42', state: 'CREATED' }, timestamp: 0 }; const b = { type: EXECUTION_LOG_ENTRY_TYPE.JOB, data: { jobKey: '42', state: 'COMPLETED' }, timestamp: 0 }; - expect(areEntriesRelated(a, b)).to.be.true; + expect(areRelated(a, b)).to.be.true; }); @@ -1724,7 +1723,7 @@ describe('ExecutionLog', function() { const a = { type: EXECUTION_LOG_ENTRY_TYPE.USER_TASK, data: { userTaskKey: '7', state: 'CREATED' }, timestamp: 0 }; const b = { type: EXECUTION_LOG_ENTRY_TYPE.USER_TASK, data: { userTaskKey: '7', state: 'COMPLETED' }, timestamp: 0 }; - expect(areEntriesRelated(a, b)).to.be.true; + expect(areRelated(a, b)).to.be.true; }); @@ -1732,7 +1731,7 @@ describe('ExecutionLog', function() { const a = { type: EXECUTION_LOG_ENTRY_TYPE.MESSAGE_SUBSCRIPTION, data: { messageSubscriptionKey: '3', messageSubscriptionState: 'CREATED' }, timestamp: 0 }; const b = { type: EXECUTION_LOG_ENTRY_TYPE.MESSAGE_SUBSCRIPTION, data: { messageSubscriptionKey: '3', messageSubscriptionState: 'CORRELATED' }, timestamp: 0 }; - expect(areEntriesRelated(a, b)).to.be.true; + expect(areRelated(a, b)).to.be.true; }); @@ -1740,7 +1739,7 @@ describe('ExecutionLog', function() { const a = { type: EXECUTION_LOG_ENTRY_TYPE.USER_TASK, data: { userTaskKey: '1', state: 'CREATED' }, timestamp: 0 }; const b = { type: EXECUTION_LOG_ENTRY_TYPE.ELEMENT_INSTANCE, data: { state: 'ACTIVE' }, timestamp: 0 }; - expect(areEntriesRelated(a, b)).to.be.false; + expect(areRelated(a, b)).to.be.false; }); }); @@ -1788,13 +1787,13 @@ describe('ExecutionLog', function() { }); - describe('compareEntryTimestamps', function() { + describe('compareByTimestamp', function() { it('should return negative when a is earlier', function() { const a = { timestamp: 100 }; const b = { timestamp: 200 }; - expect(compareEntryTimestamps(a, b)).to.be.below(0); + expect(compareByTimestamp(a, b)).to.be.below(0); }); @@ -1802,7 +1801,7 @@ describe('ExecutionLog', function() { const a = { timestamp: 300 }; const b = { timestamp: 100 }; - expect(compareEntryTimestamps(a, b)).to.be.above(0); + expect(compareByTimestamp(a, b)).to.be.above(0); }); @@ -1810,19 +1809,19 @@ describe('ExecutionLog', function() { const a = { timestamp: 100 }; const b = { timestamp: 100 }; - expect(compareEntryTimestamps(a, b)).to.equal(0); + expect(compareByTimestamp(a, b)).to.equal(0); }); }); - describe('compareEntryOrders', function() { + describe('compareByOrder', function() { it('should order entries by order', function() { const a = { type: EXECUTION_LOG_ENTRY_TYPE.ELEMENT_INSTANCE, data: { elementId: 'Task_1', state: 'ACTIVE' }, timestamp: 0 }; const b = { type: EXECUTION_LOG_ENTRY_TYPE.JOB, data: { elementId: 'Task_1', state: 'CREATED', kind: 'BPMN_ELEMENT' }, timestamp: 0 }; - expect(compareEntryOrders(a, b)).to.be.below(0); + expect(compareByOrder(a, b)).to.be.below(0); }); });