From 5abe6baecb189a95b717a333a016bbe5ad562a5c Mon Sep 17 00:00:00 2001 From: Filip Hrisafov Date: Thu, 30 Nov 2023 17:56:47 +0100 Subject: [PATCH] Add debug logging when processing events in the event registry --- .../CmmnEventRegistryEventConsumer.java | 75 ++++++++++++------ .../BpmnEventRegistryEventConsumer.java | 77 ++++++++++++------- .../eventregistry/api/EventConsumerInfo.java | 13 ++++ .../api/EventRegistryProcessingInfo.java | 8 ++ .../impl/DefaultEventRegistry.java | 29 ++++++- .../event/FlowableEventRegistryEvent.java | 10 +++ ...DefaultInboundEventProcessingPipeline.java | 27 ++++++- 7 files changed, 183 insertions(+), 56 deletions(-) diff --git a/modules/flowable-cmmn-engine/src/main/java/org/flowable/cmmn/engine/impl/eventregistry/CmmnEventRegistryEventConsumer.java b/modules/flowable-cmmn-engine/src/main/java/org/flowable/cmmn/engine/impl/eventregistry/CmmnEventRegistryEventConsumer.java index 3ce17ce7dd1..3fefd3df842 100644 --- a/modules/flowable-cmmn-engine/src/main/java/org/flowable/cmmn/engine/impl/eventregistry/CmmnEventRegistryEventConsumer.java +++ b/modules/flowable-cmmn-engine/src/main/java/org/flowable/cmmn/engine/impl/eventregistry/CmmnEventRegistryEventConsumer.java @@ -19,6 +19,7 @@ import org.flowable.cmmn.api.CmmnRuntimeService; import org.flowable.cmmn.api.repository.CaseDefinition; +import org.flowable.cmmn.api.runtime.CaseInstance; import org.flowable.cmmn.api.runtime.CaseInstanceBuilder; import org.flowable.cmmn.api.runtime.CaseInstanceQuery; import org.flowable.cmmn.api.runtime.PlanItemInstanceState; @@ -76,6 +77,9 @@ protected EventRegistryProcessingInfo eventReceived(EventInstance eventInstance) Collection correlationKeys = generateCorrelationKeys(eventInstance.getCorrelationParameterInstances()); List eventSubscriptions = findEventSubscriptions(ScopeTypes.CMMN, eventInstance, correlationKeys); + if (LOGGER.isDebugEnabled()) { + LOGGER.debug("Found {} for {}", eventSubscriptions, eventInstance); + } CmmnRuntimeService cmmnRuntimeService = cmmnEngineConfiguration.getCmmnRuntimeService(); for (EventSubscription eventSubscription : eventSubscriptions) { EventConsumerInfo eventConsumerInfo = new EventConsumerInfo(eventSubscription.getId(), eventSubscription.getSubScopeId(), @@ -93,39 +97,37 @@ protected EventRegistryProcessingInfo eventReceived(EventInstance eventInstance) protected boolean handleEventSubscription(CmmnRuntimeService cmmnRuntimeService, EventSubscription eventSubscription, EventInstance eventInstance, Collection correlationKeys, EventConsumerInfo eventConsumerInfo) { - if (eventSubscription.getSubScopeId() != null) { + String planItemInstanceId = eventSubscription.getSubScopeId(); + if (planItemInstanceId != null) { // When a subscope id is set, this means that a plan item instance is waiting for the event - PlanItemInstanceEntity planItemInstanceEntity = (PlanItemInstanceEntity) cmmnRuntimeService.createPlanItemInstanceQuery().planItemInstanceId(eventSubscription.getSubScopeId()).singleResult(); + PlanItemInstanceEntity planItemInstanceEntity = (PlanItemInstanceEntity) cmmnRuntimeService.createPlanItemInstanceQuery().planItemInstanceId( + planItemInstanceId).singleResult(); CmmnModel cmmnModel = cmmnEngineConfiguration.getCmmnRepositoryService().getCmmnModel(planItemInstanceEntity.getCaseDefinitionId()); PlanItem planItem = cmmnModel.findPlanItemByPlanItemDefinitionId(planItemInstanceEntity.getPlanItemDefinitionId()); if (PlanItemInstanceState.ACTIVE.equals(planItemInstanceEntity.getState()) || (planItem != null && planItem.getPlanItemDefinition() instanceof EventListener && PlanItemInstanceState.AVAILABLE.equals(planItemInstanceEntity.getState()))) { - - cmmnRuntimeService.createPlanItemInstanceTransitionBuilder(eventSubscription.getSubScopeId()) + + if (LOGGER.isDebugEnabled()) { + LOGGER.debug("Triggering {} with {}", planItemInstanceEntity, eventInstance); + } + cmmnRuntimeService.createPlanItemInstanceTransitionBuilder(planItemInstanceId) .transientVariable(EventConstants.EVENT_INSTANCE, eventInstance) .trigger(); } else { + if (LOGGER.isDebugEnabled()) { + LOGGER.debug("Ignoring {} because {} was not in the right state", eventInstance, planItemInstanceEntity); + } return false; } - } else if (eventSubscription.getScopeDefinitionId() != null - && eventSubscription.getScopeId() == null - && eventSubscription.getSubScopeId() == null) { + } else if (eventSubscription.getScopeDefinitionId() != null && eventSubscription.getScopeId() == null) { // If there is no scope/subscope id set, but there is a scope definition id set, it's an event that starts a case - CaseInstanceBuilder caseInstanceBuilder = cmmnRuntimeService.createCaseInstanceBuilder() - .caseDefinitionId(eventSubscription.getScopeDefinitionId()) - .transientVariable(EventConstants.EVENT_INSTANCE, eventInstance); - - if (eventInstance.getTenantId() != null && !Objects.equals(CmmnEngineConfiguration.NO_TENANT_ID, eventInstance.getTenantId())) { - caseInstanceBuilder.overrideCaseDefinitionTenantId(eventInstance.getTenantId()); - } - if (correlationKeys != null) { String startCorrelationConfiguration = getStartCorrelationConfiguration(eventSubscription); @@ -182,7 +184,7 @@ protected boolean handleEventSubscription(CmmnRuntimeService cmmnRuntimeService, return true; } - startCaseInstance(caseInstanceBuilder, correlationKeyWithAllParameters.getValue(), ReferenceTypes.EVENT_CASE); + startCaseInstance(cmmnRuntimeService, eventSubscription, eventInstance, correlationKeyWithAllParameters); return true; } finally { @@ -197,14 +199,14 @@ protected boolean handleEventSubscription(CmmnRuntimeService cmmnRuntimeService, } } else { - startCaseInstance(caseInstanceBuilder, correlationKeyWithAllParameters.getValue(), ReferenceTypes.EVENT_CASE); + startCaseInstance(cmmnRuntimeService, eventSubscription, eventInstance, correlationKeyWithAllParameters); return true; } } } - startCaseInstance(caseInstanceBuilder, null, null); + startCaseInstance(cmmnRuntimeService, eventSubscription, eventInstance, null); } return true; @@ -225,19 +227,42 @@ protected long countCaseInstances(CmmnRuntimeService cmmnRuntimeService, EventIn return caseInstanceQuery.count(); } - protected void startCaseInstance(CaseInstanceBuilder caseInstanceBuilder, String referenceId, String referenceType) { + protected void startCaseInstance(CmmnRuntimeService cmmnRuntimeService, EventSubscription eventSubscription, EventInstance eventInstance, + CorrelationKey correlationKey) { + CaseInstanceBuilder caseInstanceBuilder = cmmnRuntimeService.createCaseInstanceBuilder() + .caseDefinitionId(eventSubscription.getScopeDefinitionId()) + .transientVariable(EventConstants.EVENT_INSTANCE, eventInstance); - if (referenceId != null) { - caseInstanceBuilder.referenceId(referenceId); + if (eventInstance.getTenantId() != null && !Objects.equals(CmmnEngineConfiguration.NO_TENANT_ID, eventInstance.getTenantId())) { + caseInstanceBuilder.overrideCaseDefinitionTenantId(eventInstance.getTenantId()); } - if (referenceType != null) { - caseInstanceBuilder.referenceType(referenceType); + + if (correlationKey != null) { + caseInstanceBuilder.referenceId(correlationKey.getValue()) + .referenceType(ReferenceTypes.EVENT_CASE); } + boolean debugLoggingEnabled = LOGGER.isDebugEnabled(); if (cmmnEngineConfiguration.isEventRegistryStartCaseInstanceAsync()) { - caseInstanceBuilder.startAsync(); + if (debugLoggingEnabled) { + LOGGER.debug("Async starting case instance for {} with {}", eventSubscription, eventInstance); + } + + CaseInstance caseInstance = caseInstanceBuilder.startAsync(); + + if (debugLoggingEnabled) { + LOGGER.debug("Started {} async for {} with {}", caseInstance, eventSubscription, eventInstance); + } } else { - caseInstanceBuilder.start(); + if (debugLoggingEnabled) { + LOGGER.debug("Starting case instance for {} with {}", eventSubscription, eventInstance); + } + + CaseInstance caseInstance = caseInstanceBuilder.start(); + + if (debugLoggingEnabled) { + LOGGER.debug("Started {} for {} with {}", caseInstance, eventSubscription, eventInstance); + } } } diff --git a/modules/flowable-engine/src/main/java/org/flowable/engine/impl/eventregistry/BpmnEventRegistryEventConsumer.java b/modules/flowable-engine/src/main/java/org/flowable/engine/impl/eventregistry/BpmnEventRegistryEventConsumer.java index 203d25ed013..0c6bc24f85b 100644 --- a/modules/flowable-engine/src/main/java/org/flowable/engine/impl/eventregistry/BpmnEventRegistryEventConsumer.java +++ b/modules/flowable-engine/src/main/java/org/flowable/engine/impl/eventregistry/BpmnEventRegistryEventConsumer.java @@ -31,6 +31,7 @@ import org.flowable.engine.RuntimeService; import org.flowable.engine.impl.cfg.ProcessEngineConfigurationImpl; import org.flowable.engine.repository.ProcessDefinition; +import org.flowable.engine.runtime.ProcessInstance; import org.flowable.engine.runtime.ProcessInstanceBuilder; import org.flowable.engine.runtime.ProcessInstanceQuery; import org.flowable.eventregistry.api.EventConsumerInfo; @@ -74,6 +75,9 @@ protected EventRegistryProcessingInfo eventReceived(EventInstance eventInstance) Collection correlationKeys = generateCorrelationKeys(eventInstance.getCorrelationParameterInstances()); List eventSubscriptions = findEventSubscriptions(ScopeTypes.BPMN, eventInstance, correlationKeys); + if (LOGGER.isDebugEnabled()) { + LOGGER.debug("Found {} for {}", eventSubscriptions, eventInstance); + } RuntimeService runtimeService = processEngineConfiguration.getRuntimeService(); for (EventSubscription eventSubscription : eventSubscriptions) { EventConsumerInfo eventConsumerInfo = new EventConsumerInfo(eventSubscription.getId(), eventSubscription.getExecutionId(), @@ -88,31 +92,22 @@ protected EventRegistryProcessingInfo eventReceived(EventInstance eventInstance) protected void handleEventSubscription(RuntimeService runtimeService, EventSubscription eventSubscription, EventInstance eventInstance, Collection correlationKeys, EventConsumerInfo eventConsumerInfo) { - if (eventSubscription.getExecutionId() != null) { + String executionId = eventSubscription.getExecutionId(); + if (executionId != null) { // When an executionId is set, this means that the process instance is waiting at that step for an event Map transientVariableMap = new HashMap<>(); transientVariableMap.put(EventConstants.EVENT_INSTANCE, eventInstance); - runtimeService.trigger(eventSubscription.getExecutionId(), null, transientVariableMap); + if (LOGGER.isDebugEnabled()) { + LOGGER.debug("Triggering execution {} with {}", executionId, eventInstance); + } + runtimeService.trigger(executionId, null, transientVariableMap); - } else if (eventSubscription.getProcessDefinitionId() != null - && eventSubscription.getProcessInstanceId() == null && eventSubscription.getExecutionId() == null) { + } else if (eventSubscription.getProcessDefinitionId() != null && eventSubscription.getProcessInstanceId() == null) { // If there is no execution/process instance set, but a definition id is set, this means that it's a start event - ProcessInstanceBuilder processInstanceBuilder = runtimeService.createProcessInstanceBuilder() - .processDefinitionId(eventSubscription.getProcessDefinitionId()) - .transientVariable(EventConstants.EVENT_INSTANCE, eventInstance); - - if (StringUtils.isNotEmpty(eventSubscription.getActivityId())) { - processInstanceBuilder.startEventId(eventSubscription.getActivityId()); - } - - if (eventInstance.getTenantId() != null && !Objects.equals(ProcessEngineConfiguration.NO_TENANT_ID, eventInstance.getTenantId())) { - processInstanceBuilder.overrideProcessDefinitionTenantId(eventInstance.getTenantId()); - } - if (correlationKeys != null) { String startCorrelationConfiguration = getStartCorrelationConfiguration(eventSubscription); @@ -170,7 +165,7 @@ protected void handleEventSubscription(RuntimeService runtimeService, EventSubsc return; } - startProcessInstance(processInstanceBuilder, correlationKeyWithAllParameters.getValue(), ReferenceTypes.EVENT_PROCESS); + startProcessInstance(runtimeService, eventSubscription, eventInstance, correlationKeyWithAllParameters); return; } finally { @@ -188,7 +183,7 @@ protected void handleEventSubscription(RuntimeService runtimeService, EventSubsc } else { - startProcessInstance(processInstanceBuilder, correlationKeyWithAllParameters.getValue(), ReferenceTypes.EVENT_PROCESS); + startProcessInstance(runtimeService, eventSubscription, eventInstance, correlationKeyWithAllParameters); return; } @@ -196,8 +191,10 @@ protected void handleEventSubscription(RuntimeService runtimeService, EventSubsc } - startProcessInstance(processInstanceBuilder, null, null); + startProcessInstance(runtimeService, eventSubscription, eventInstance, null); + } else { + LOGGER.warn("Ignoring {}. It was acquired by the bpmn event consumer, but it is not used", eventSubscription); } } @@ -217,19 +214,47 @@ protected long countProcessInstances(RuntimeService runtimeService, EventInstanc return processInstanceQuery.count(); } - protected void startProcessInstance(ProcessInstanceBuilder processInstanceBuilder, String referenceId, String referenceType) { + protected void startProcessInstance(RuntimeService runtimeService, EventSubscription eventSubscription, EventInstance eventInstance, + CorrelationKey correlationKey) { + ProcessInstanceBuilder processInstanceBuilder = runtimeService.createProcessInstanceBuilder() + .processDefinitionId(eventSubscription.getProcessDefinitionId()) + .transientVariable(EventConstants.EVENT_INSTANCE, eventInstance); - if (referenceId != null) { - processInstanceBuilder.referenceId(referenceId); + if (StringUtils.isNotEmpty(eventSubscription.getActivityId())) { + processInstanceBuilder.startEventId(eventSubscription.getActivityId()); } - if (referenceType != null) { - processInstanceBuilder.referenceType(referenceType); + + if (eventInstance.getTenantId() != null && !Objects.equals(ProcessEngineConfiguration.NO_TENANT_ID, eventInstance.getTenantId())) { + processInstanceBuilder.overrideProcessDefinitionTenantId(eventInstance.getTenantId()); } + if (correlationKey != null) { + processInstanceBuilder + .referenceId(correlationKey.getValue()) + .referenceType(ReferenceTypes.EVENT_PROCESS); + } + + boolean debugLoggingEnabled = LOGGER.isDebugEnabled(); if (processEngineConfiguration.isEventRegistryStartProcessInstanceAsync()) { - processInstanceBuilder.startAsync(); + if (debugLoggingEnabled) { + LOGGER.debug("Async starting process instance for {} with {}", eventSubscription, eventInstance); + } + + ProcessInstance processInstance = processInstanceBuilder.startAsync(); + + if (debugLoggingEnabled) { + LOGGER.debug("Started {} async for {} with {}", processInstance, eventSubscription, eventInstance); + } } else { - processInstanceBuilder.start(); + if (debugLoggingEnabled) { + LOGGER.debug("Starting process instance for {} with {}", eventSubscription, eventInstance); + } + + ProcessInstance processInstance = processInstanceBuilder.start(); + + if (debugLoggingEnabled) { + LOGGER.debug("Started {} for {} with {}", processInstance, eventSubscription, eventInstance); + } } } diff --git a/modules/flowable-event-registry-api/src/main/java/org/flowable/eventregistry/api/EventConsumerInfo.java b/modules/flowable-event-registry-api/src/main/java/org/flowable/eventregistry/api/EventConsumerInfo.java index 9af9e05834e..4317dacbe88 100644 --- a/modules/flowable-event-registry-api/src/main/java/org/flowable/eventregistry/api/EventConsumerInfo.java +++ b/modules/flowable-event-registry-api/src/main/java/org/flowable/eventregistry/api/EventConsumerInfo.java @@ -12,6 +12,8 @@ */ package org.flowable.eventregistry.api; +import java.util.StringJoiner; + public class EventConsumerInfo { protected String eventSubscriptionId; @@ -59,4 +61,15 @@ public boolean isHasExistingInstancesForUniqueCorrelation() { public void setHasExistingInstancesForUniqueCorrelation(boolean hasExistingInstancesForUniqueCorrelation) { this.hasExistingInstancesForUniqueCorrelation = hasExistingInstancesForUniqueCorrelation; } + + @Override + public String toString() { + return new StringJoiner(", ", getClass().getSimpleName() + "[", "]") + .add("eventSubscriptionId='" + eventSubscriptionId + "'") + .add("subScopeId='" + subScopeId + "'") + .add("scopeType='" + scopeType + "'") + .add("scopeDefinitionId='" + scopeDefinitionId + "'") + .add("hasExistingInstancesForUniqueCorrelation=" + hasExistingInstancesForUniqueCorrelation) + .toString(); + } } diff --git a/modules/flowable-event-registry-api/src/main/java/org/flowable/eventregistry/api/EventRegistryProcessingInfo.java b/modules/flowable-event-registry-api/src/main/java/org/flowable/eventregistry/api/EventRegistryProcessingInfo.java index 501222aebfc..f2b952f69a5 100644 --- a/modules/flowable-event-registry-api/src/main/java/org/flowable/eventregistry/api/EventRegistryProcessingInfo.java +++ b/modules/flowable-event-registry-api/src/main/java/org/flowable/eventregistry/api/EventRegistryProcessingInfo.java @@ -14,6 +14,7 @@ import java.util.ArrayList; import java.util.List; +import java.util.StringJoiner; public class EventRegistryProcessingInfo { @@ -38,4 +39,11 @@ public List getEventConsumerInfos() { public void setEventConsumerInfos(List eventConsumerInfos) { this.eventConsumerInfos = eventConsumerInfos; } + + @Override + public String toString() { + return new StringJoiner(", ", getClass().getSimpleName() + "[", "]") + .add("eventConsumerInfos=" + eventConsumerInfos) + .toString(); + } } diff --git a/modules/flowable-event-registry/src/main/java/org/flowable/eventregistry/impl/DefaultEventRegistry.java b/modules/flowable-event-registry/src/main/java/org/flowable/eventregistry/impl/DefaultEventRegistry.java index da49b0b575c..b0c8addd3a3 100644 --- a/modules/flowable-event-registry/src/main/java/org/flowable/eventregistry/impl/DefaultEventRegistry.java +++ b/modules/flowable-event-registry/src/main/java/org/flowable/eventregistry/impl/DefaultEventRegistry.java @@ -20,6 +20,7 @@ import org.flowable.eventregistry.api.EventRegistry; import org.flowable.eventregistry.api.EventRegistryEvent; import org.flowable.eventregistry.api.EventRegistryEventConsumer; +import org.flowable.eventregistry.api.EventRegistryNonMatchingEventConsumer; import org.flowable.eventregistry.api.EventRegistryProcessingInfo; import org.flowable.eventregistry.api.InboundEvent; import org.flowable.eventregistry.api.InboundEventProcessor; @@ -27,12 +28,16 @@ import org.flowable.eventregistry.api.runtime.EventInstance; import org.flowable.eventregistry.model.ChannelModel; import org.flowable.eventregistry.model.InboundChannelModel; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; /** * @author Joram Barrez */ public class DefaultEventRegistry implements EventRegistry { + protected final Logger logger = LoggerFactory.getLogger(getClass()); + protected EventRegistryEngineConfiguration engineConfiguration; protected CorrelationKeyGenerator> correlationKeyGenerator; @@ -80,8 +85,15 @@ public void eventReceived(InboundChannelModel channelModel, InboundEvent event) public void sendEventToConsumers(EventRegistryEvent eventRegistryEvent) { Collection engineEventRegistryEventConsumers = engineConfiguration.getEventRegistryEventConsumers().values(); EventRegistryProcessingInfo eventRegistryProcessingInfo = null; + boolean debugLoggingEnabled = logger.isDebugEnabled(); for (EventRegistryEventConsumer eventConsumer : engineEventRegistryEventConsumers) { + if (debugLoggingEnabled) { + logger.debug("Sending {} to event consumer {}", eventRegistryEvent, eventConsumer); + } EventRegistryProcessingInfo processingInfo = eventConsumer.eventReceived(eventRegistryEvent); + if (debugLoggingEnabled) { + logger.debug("Event consumer {} processed event {} with result {}", eventConsumer, eventRegistryEvent, processingInfo); + } if (processingInfo != null && processingInfo.getEventConsumerInfos() != null && !processingInfo.getEventConsumerInfos().isEmpty()) { if (eventRegistryProcessingInfo == null) { eventRegistryProcessingInfo = new EventRegistryProcessingInfo(); @@ -90,10 +102,19 @@ public void sendEventToConsumers(EventRegistryEvent eventRegistryEvent) { } } - if ((eventRegistryProcessingInfo == null || !eventRegistryProcessingInfo.eventHandled()) && - engineConfiguration.getNonMatchingEventConsumer() != null) { - - engineConfiguration.getNonMatchingEventConsumer().handleNonMatchingEvent(eventRegistryEvent, eventRegistryProcessingInfo); + if (eventRegistryProcessingInfo == null || !eventRegistryProcessingInfo.eventHandled()) { + + EventRegistryNonMatchingEventConsumer nonMatchingEventConsumer = engineConfiguration.getNonMatchingEventConsumer(); + if (nonMatchingEventConsumer != null) { + if (debugLoggingEnabled) { + logger.debug("No event consumer consumed event {}. Handling it with {}", eventRegistryEvent, nonMatchingEventConsumer); + } + nonMatchingEventConsumer.handleNonMatchingEvent(eventRegistryEvent, eventRegistryProcessingInfo); + } else if (debugLoggingEnabled) { + logger.debug("No event consumer consumed event {}", eventRegistryEvent); + } + } else if (debugLoggingEnabled) { + logger.debug("{} was consumed with {}", eventRegistryEvent, eventRegistryProcessingInfo); } } diff --git a/modules/flowable-event-registry/src/main/java/org/flowable/eventregistry/impl/event/FlowableEventRegistryEvent.java b/modules/flowable-event-registry/src/main/java/org/flowable/eventregistry/impl/event/FlowableEventRegistryEvent.java index 02781ee4e0a..e80ece42442 100644 --- a/modules/flowable-event-registry/src/main/java/org/flowable/eventregistry/impl/event/FlowableEventRegistryEvent.java +++ b/modules/flowable-event-registry/src/main/java/org/flowable/eventregistry/impl/event/FlowableEventRegistryEvent.java @@ -12,6 +12,8 @@ */ package org.flowable.eventregistry.impl.event; +import java.util.StringJoiner; + import org.flowable.eventregistry.api.EventRegistryEvent; import org.flowable.eventregistry.api.runtime.EventInstance; @@ -49,4 +51,12 @@ public void setType(String type) { public EventInstance getEventObject() { return eventInstance; } + + @Override + public String toString() { + return new StringJoiner(", ", getClass().getSimpleName() + "[", "]") + .add("type='" + type + "'") + .add("eventInstance=" + eventInstance) + .toString(); + } } diff --git a/modules/flowable-event-registry/src/main/java/org/flowable/eventregistry/impl/pipeline/DefaultInboundEventProcessingPipeline.java b/modules/flowable-event-registry/src/main/java/org/flowable/eventregistry/impl/pipeline/DefaultInboundEventProcessingPipeline.java index 1959b72fcce..76c4ed86c20 100644 --- a/modules/flowable-event-registry/src/main/java/org/flowable/eventregistry/impl/pipeline/DefaultInboundEventProcessingPipeline.java +++ b/modules/flowable-event-registry/src/main/java/org/flowable/eventregistry/impl/pipeline/DefaultInboundEventProcessingPipeline.java @@ -31,6 +31,8 @@ import org.flowable.eventregistry.impl.runtime.EventInstanceImpl; import org.flowable.eventregistry.model.EventModel; import org.flowable.eventregistry.model.InboundChannelModel; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; /** * @author Joram Barrez @@ -38,6 +40,8 @@ */ public class DefaultInboundEventProcessingPipeline implements InboundEventProcessingPipeline { + protected final Logger logger = LoggerFactory.getLogger(getClass()); + protected EventRepositoryService eventRepositoryService; protected InboundEventDeserializer inboundEventDeserializer; protected InboundEventKeyDetector inboundEventKeyDetector; @@ -63,6 +67,11 @@ public DefaultInboundEventProcessingPipeline(EventRepositoryService eventReposit @Override public Collection run(InboundChannelModel inboundChannel, InboundEvent inboundEvent) { + boolean debugLoggingEnabled = logger.isDebugEnabled(); + if (debugLoggingEnabled) { + logger.debug("Running inbound pipeline for inbound {} channel {}. Inbound event: {}", inboundChannel.getChannelType(), inboundChannel.getKey(), inboundEvent); + } + T deserializedBody = deserialize(inboundEvent.getBody()); FlowableEventInfo event = new FlowableEventInfoImpl<>(inboundEvent, deserializedBody, inboundChannel); @@ -76,6 +85,11 @@ public Collection run(InboundChannelModel inboundChannel, In multiTenant = true; } + if (debugLoggingEnabled) { + logger.debug("Detected event {} and tenant {} for inbound {} channel {}. Inbound event: {}", eventKey, tenantId, inboundChannel.getChannelType(), + inboundChannel.getKey(), inboundEvent); + } + EventModel eventModel = multiTenant ? eventRepositoryService.getEventModelByKey(eventKey, tenantId) : eventRepositoryService.getEventModelByKey(eventKey); EventInstanceImpl eventInstance = new EventInstanceImpl( @@ -84,7 +98,18 @@ public Collection run(InboundChannelModel inboundChannel, In tenantId ); - return transform(eventInstance); + if (debugLoggingEnabled) { + logger.debug("Transforming {} for inbound {} channel {}. Inbound event: {}", eventInstance, inboundChannel.getChannelType(), + inboundChannel.getKey(), inboundEvent); + } + Collection registryEvents = transform(eventInstance); + + if (debugLoggingEnabled) { + logger.debug("Transformed {} to {} for inbound {} channel {}. Inbound event: {}", eventInstance, registryEvents, inboundChannel.getChannelType(), + inboundChannel.getKey(), inboundEvent); + } + + return registryEvents; } public T deserialize(Object rawEvent) {