Added logs with level INFO with string F_C_CH for each log, for the f…

…low create process.
telstra · Aug 6, 2024 · 9553107 · 9553107
1 parent 1fcbc12
commit 9553107
Show file tree

Hide file tree

Showing 24 changed files with 242 additions and 10 deletions.
diff --git a/...orm-topology/src/main/java/org/openkilda/wfm/topology/flowhs/bolts/FlowCreateHubBolt.java b/...orm-topology/src/main/java/org/openkilda/wfm/topology/flowhs/bolts/FlowCreateHubBolt.java
@@ -118,6 +118,7 @@ protected void activate() {
     @Override
     protected void onRequest(Tuple input) throws PipelineException {
         currentKey = pullKey(input);
+        log.info("F_C_CH FlowCreateHubBolt.onRequest call for the key {},  input: {}", currentKey, input);
         FlowRequest payload = pullValue(input, FIELD_ID_PAYLOAD, FlowRequest.class);
         try {
             service.handleRequest(currentKey, getCommandContext(), payload);
@@ -129,9 +130,14 @@ protected void onRequest(Tuple input) throws PipelineException {
     @Override
     protected void onWorkerResponse(Tuple input) throws PipelineException {
         String operationKey = pullKey(input);
+        log.info("F_C_CH FlowCreateHubBolt.onWorkerResponse, currentKey:{}, getParentKey:{}  input: {}",
+                currentKey, KeyProvider.getParentKey(operationKey), input);
         currentKey = KeyProvider.getParentKey(operationKey);
         SpeakerFlowSegmentResponse flowResponse = pullValue(input, FIELD_ID_PAYLOAD, SpeakerFlowSegmentResponse.class);
         try {
+            log.info("F_C_CH FlowCreateHubBolt.onWorkerResponse, calling handle AsyncResponse currentKey:{},"
+                            + " getParentKey:{}  input: {}",
+                    currentKey, KeyProvider.getParentKey(operationKey), input);
             service.handleAsyncResponse(currentKey, flowResponse);
         } catch (UnknownKeyException e) {
             log.warn("Received a response with unknown key {}.", currentKey);
@@ -140,6 +146,8 @@ protected void onWorkerResponse(Tuple input) throws PipelineException {
 
     @Override
     public void onTimeout(String key, Tuple tuple) {
+        log.info("F_C_CH FlowCreateHubBolt.onTimeout, currentKey:{}, key:{}  tuple: {}",
+                currentKey, key, tuple);
         currentKey = key;
         try {
             service.handleTimeout(key);
@@ -150,6 +158,7 @@ public void onTimeout(String key, Tuple tuple) {
 
     @Override
     public void sendSpeakerRequest(@NonNull SpeakerRequest command) {
+        log.info("F_C_CH FlowCreateHubBolt.sendSpeakerRequest command: {},  currentKey: {}", command, currentKey);
         String commandKey = KeyProvider.joinKeys(command.getCommandId().toString(), currentKey);
 
         Values values = new Values(commandKey, command);
@@ -158,6 +167,7 @@ public void sendSpeakerRequest(@NonNull SpeakerRequest command) {
 
     @Override
     public void sendNorthboundResponse(@NonNull Message message) {
+        log.info("F_C_CH FlowCreateHubBolt.sendNorthboundResponse message: {},  currentKey: {}", message, currentKey);
         emitWithContext(Stream.HUB_TO_NB_RESPONSE_SENDER.name(), getCurrentTuple(), new Values(currentKey, message));
     }
 
@@ -209,6 +219,7 @@ public void sendNotifyFlowMonitor(@NonNull CommandData flowCommand) {
 
     @Override
     public void sendNotifyFlowStats(@NonNull UpdateFlowPathInfo flowPathInfo) {
+        log.info("F_C_CH FlowCreateHubBolt.sendNotifyFlowStats, flowPathInfo{}", flowPathInfo);
         Message message = new InfoMessage(flowPathInfo, System.currentTimeMillis(),
                 getCommandContext().getCorrelationId());
 

diff --git a/...owhs-storm-topology/src/main/java/org/openkilda/wfm/topology/flowhs/bolts/RouterBolt.java b/...owhs-storm-topology/src/main/java/org/openkilda/wfm/topology/flowhs/bolts/RouterBolt.java
@@ -123,6 +123,8 @@ protected void handleInput(Tuple input) {
                 Values values = new Values(key, request.getFlowId(), request);
                 switch (request.getType()) {
                     case CREATE:
+                        log.info("F_C_CH"
+                                + " received flow create req on routerBolt of flowHs topology, key: {}", key);
                         emitWithContext(ROUTER_TO_FLOW_CREATE_HUB.name(), input, values);
                         break;
                     case UPDATE:

diff --git a/...opology/src/main/java/org/openkilda/wfm/topology/flowhs/fsm/common/SpeakerCommandFsm.java b/...opology/src/main/java/org/openkilda/wfm/topology/flowhs/fsm/common/SpeakerCommandFsm.java
@@ -53,6 +53,8 @@ private SpeakerCommandFsm(
     }
 
     protected void processResponse(State from, State to, Event event, SpeakerFlowSegmentResponse response) {
+        log.info("F_C_CH SpeakerCommandFsm.processResponse, from {}, to {}, event {} fire NEXT flowId: {},"
+                + " isSuccess? {}", from, to, event, getRequest().getFlowId(), response.isSuccess());
         if (response.isSuccess()) {
             log.debug("Successfully executed the command {}", response);
             fire(Event.NEXT);
@@ -73,13 +75,17 @@ protected void processResponse(State from, State to, Event event, SpeakerFlowSeg
                 log.debug("About to retry execution of the command {}", response);
                 fire(Event.RETRY);
             } else {
+                log.info("F_C_CH SpeakerCommandFsm.processResponse, from {}, to {}, event {}, FAIL flowId: {}",
+                        from, to, event, getRequest().getFlowId());
                 fireError(giveUpReason);
             }
         }
     }
 
     protected void sendCommand(State from, State to, Event event, SpeakerFlowSegmentResponse response) {
         log.debug("Sending a flow command {} to a speaker", request);
+        log.info("F_C_CH SpeakerCommandFsm.sendCommand Sending a flow command {} to a speaker."
+                + " from {}, to {}, event {}", request, from, to, event);
         // FIXME(surabujin): new commandId must be used for each retry attempt, because in case of timeout new and
         //  ongoing requests can collide on speaker side and there is no way to distinguish responses (stale and actual)
         //  if both of them have same commandId

diff --git a/...in/java/org/openkilda/wfm/topology/flowhs/fsm/common/actions/NotifyFlowMonitorAction.java b/...in/java/org/openkilda/wfm/topology/flowhs/fsm/common/actions/NotifyFlowMonitorAction.java
@@ -28,10 +28,13 @@
 import org.openkilda.wfm.topology.flowhs.fsm.common.FlowProcessingWithHistorySupportFsm;
 import org.openkilda.wfm.topology.flowhs.service.FlowGenericCarrier;
 
+import lombok.extern.slf4j.Slf4j;
+
 import java.util.Collections;
 import java.util.List;
 import java.util.Optional;
 
+@Slf4j
 public class NotifyFlowMonitorAction<T extends FlowProcessingWithHistorySupportFsm<T, S, E, C, ?, ?>, S, E, C>
         extends FlowProcessingWithHistorySupportAction<T, S, E, C> {
     private FlowGenericCarrier carrier;
@@ -43,6 +46,8 @@ public NotifyFlowMonitorAction(PersistenceManager persistenceManager, FlowGeneri
 
     @Override
     protected void perform(S from, S to, E event, C context, T stateMachine) {
+        log.info("F_C_CH NotifyFlowMonitorAction.perform from: {}, to: {}, event: {}, context: {}, stateMachine: {}",
+                from, to, event, context, stateMachine);
         carrier.sendNotifyFlowMonitor(getFlowInfo(stateMachine.getFlowId()));
     }
 

diff --git a/...n/java/org/openkilda/wfm/topology/flowhs/fsm/create/actions/CompleteFlowCreateAction.java b/...n/java/org/openkilda/wfm/topology/flowhs/fsm/create/actions/CompleteFlowCreateAction.java
@@ -50,13 +50,18 @@ public CompleteFlowCreateAction(PersistenceManager persistenceManager,
 
     @Override
     protected void perform(State from, State to, Event event, FlowCreateContext context, FlowCreateFsm stateMachine) {
+        log.info("F_C_CH CompleteFlowCreateAction.perform, from: {}, to: {}, event: {}, context: {}",
+                from, to, event, context);
         String flowId = stateMachine.getFlowId();
         if (!flowRepository.exists(flowId)) {
             throw new FlowProcessingException(ErrorType.NOT_FOUND,
                     "Couldn't complete flow creation. The flow was deleted");
         }
 
         FlowStatus flowStatus = transactionManager.doInTransaction(() -> {
+            log.info("F_C_CH CompleteFlowCreateAction.perform, doInTransaction from: {}, to: {}, event: {}, "
+                            + "context: {}",
+                    from, to, event, context);
             FlowStatus status = FlowStatus.UP;
             FlowPathStatus primaryPathStatus;
             if (stateMachine.isBackUpPrimaryPathComputationWayUsed()) {
@@ -89,11 +94,18 @@ protected void perform(State from, State to, Event event, FlowCreateContext cont
                         + "(back up strategy or max_latency_tier2 value) of building the path was used");
             }
 
+            log.info("F_C_CH CompleteFlowCreateAction.perform, doInTransaction from: {}, to: {}, event: {}, "
+                            + "context: {}, status:{} , primaryPathStatus: {}",
+                    from, to, event, context, status, primaryPathStatus);
+
             return status;
         });
 
         dashboardLogger.onFlowStatusUpdate(flowId, flowStatus);
         saveHistoryWithDump(stateMachine, flowStatus);
+        log.info("F_C_CH CompleteFlowCreateAction.perform, finish from: {}, to: {}, event: {}, "
+                        + "context: {}",
+                from, to, event, context);
     }
 
     private void saveHistoryWithDump(FlowCreateFsm stateMachine, FlowStatus flowStatus) {

diff --git a/...penkilda/wfm/topology/flowhs/fsm/create/actions/EmitIngressRulesVerifyRequestsAction.java b/...penkilda/wfm/topology/flowhs/fsm/create/actions/EmitIngressRulesVerifyRequestsAction.java
@@ -20,9 +20,12 @@
 import org.openkilda.wfm.topology.flowhs.fsm.create.FlowCreateFsm;
 import org.openkilda.wfm.topology.flowhs.fsm.create.FlowCreateFsm.Event;
 import org.openkilda.wfm.topology.flowhs.fsm.create.FlowCreateFsm.State;
+import org.openkilda.wfm.topology.flowhs.model.RequestedFlow;
 
 import lombok.extern.slf4j.Slf4j;
 
+import java.util.Optional;
+
 @Slf4j
 public class EmitIngressRulesVerifyRequestsAction extends EmitVerifyRulesAction {
     public EmitIngressRulesVerifyRequestsAction(SpeakerCommandFsm.Builder speakerCommandFsmBuilder) {
@@ -31,6 +34,10 @@ public EmitIngressRulesVerifyRequestsAction(SpeakerCommandFsm.Builder speakerCom
 
     @Override
     public void perform(State from, State to, Event event, FlowCreateContext context, FlowCreateFsm stateMachine) {
+        log.info("F_C_CH EmitIngressRulesVerifyRequestsAction.perform, flowId from stateMachine: {},"
+                        + "context flowId: {} from: {}, to: {}, event: {}, ",
+                stateMachine.getFlowId(), Optional.ofNullable(context).map(FlowCreateContext::getTargetFlow)
+                        .map(RequestedFlow::getFlowId).orElse(null), from, to, event);
         emitVerifyRequests(stateMachine, stateMachine.getIngressCommands());
         stateMachine.saveActionToHistory("Started validation of installed ingress rules");
     }

diff --git a/...kilda/wfm/topology/flowhs/fsm/create/actions/EmitNonIngressRulesVerifyRequestsAction.java b/...kilda/wfm/topology/flowhs/fsm/create/actions/EmitNonIngressRulesVerifyRequestsAction.java
@@ -21,10 +21,12 @@
 import org.openkilda.wfm.topology.flowhs.fsm.create.FlowCreateFsm;
 import org.openkilda.wfm.topology.flowhs.fsm.create.FlowCreateFsm.Event;
 import org.openkilda.wfm.topology.flowhs.fsm.create.FlowCreateFsm.State;
+import org.openkilda.wfm.topology.flowhs.model.RequestedFlow;
 
 import lombok.extern.slf4j.Slf4j;
 
 import java.util.List;
+import java.util.Optional;
 
 @Slf4j
 public class EmitNonIngressRulesVerifyRequestsAction extends EmitVerifyRulesAction {
@@ -34,10 +36,24 @@ public EmitNonIngressRulesVerifyRequestsAction(SpeakerCommandFsm.Builder speaker
 
     @Override
     public void perform(State from, State to, Event event, FlowCreateContext context, FlowCreateFsm stateMachine) {
+        log.info("F_C_CH EmitNonIngressRulesVerifyRequestsAction.perform"
+                        + " flowId from stateMachine: {}, flowId from context: {}. from {} to {} event {}",
+                stateMachine.getFlowId(), Optional.ofNullable(context).map(FlowCreateContext::getTargetFlow)
+                        .map(RequestedFlow::getFlowId).orElse(null), from, to, event);
         List<FlowSegmentRequestFactory> requestFactories = stateMachine.getNonIngressCommands();
         if (requestFactories.isEmpty()) {
+            log.info("F_C_CH EmitNonIngressRulesVerifyRequestsAction.perform"
+                            + "No need to validate non ingress rules flowId from stateMachine: {},"
+                            + " flowId from context: {}. from {} to {} event {}",
+                    stateMachine.getFlowId(), Optional.ofNullable(context).map(FlowCreateContext::getTargetFlow)
+                            .map(RequestedFlow::getFlowId).orElse(null), from, to, event);
             stateMachine.saveActionToHistory("No need to validate non ingress rules");
         } else {
+            log.info("F_C_CH EmitNonIngressRulesVerifyRequestsAction.perform"
+                            + "Started validation of installed non ingress rules flowId from stateMachine: {},"
+                            + " flowId from context: {}. from {} to {} event {}",
+                    stateMachine.getFlowId(), Optional.ofNullable(context).map(FlowCreateContext::getTargetFlow)
+                            .map(RequestedFlow::getFlowId).orElse(null), from, to, event);
             emitVerifyRequests(stateMachine, requestFactories);
             stateMachine.saveActionToHistory("Started validation of installed non ingress rules");
         }

diff --git a/...main/java/org/openkilda/wfm/topology/flowhs/fsm/create/actions/EmitVerifyRulesAction.java b/...main/java/org/openkilda/wfm/topology/flowhs/fsm/create/actions/EmitVerifyRulesAction.java
@@ -26,12 +26,14 @@
 
 import com.fasterxml.uuid.Generators;
 import com.fasterxml.uuid.NoArgGenerator;
+import lombok.extern.slf4j.Slf4j;
 
 import java.util.Collection;
 import java.util.Collections;
 import java.util.Map;
 import java.util.UUID;
 
+@Slf4j
 abstract class EmitVerifyRulesAction
         extends HistoryRecordingAction<FlowCreateFsm, FlowCreateFsm.State, FlowCreateFsm.Event, FlowCreateContext> {
 
@@ -47,7 +49,7 @@ protected void emitVerifyRequests(
         final Map<UUID, SpeakerCommandObserver> pendingCommands = stateMachine.getPendingCommands();
         for (FlowSegmentRequestFactory factory : requestFactories) {
             FlowSegmentRequest request = factory.makeVerifyRequest(commandIdGenerator.generate());
-
+            log.info("F_C_CH EmitVerifyRulesAction.emitVerifyRequests request: {}", request);
             SpeakerCommandObserver commandObserver = new SpeakerCommandObserver(speakerCommandFsmBuilder,
                     Collections.singleton(ErrorCode.MISSING_OF_FLOWS), request);
             commandObserver.start();

diff --git a/...rc/main/java/org/openkilda/wfm/topology/flowhs/fsm/create/actions/FlowValidateAction.java b/...rc/main/java/org/openkilda/wfm/topology/flowhs/fsm/create/actions/FlowValidateAction.java
@@ -55,6 +55,10 @@ public FlowValidateAction(PersistenceManager persistenceManager, FlowOperationsD
     @Override
     protected Optional<Message> performWithResponse(State from, State to, Event event, FlowCreateContext context,
                                                     FlowCreateFsm stateMachine) throws FlowProcessingException {
+        log.info("F_C_CH FlowValidateAction.performWithResponse, flowId:{}",
+                Optional.ofNullable(context).map(FlowCreateContext::getTargetFlow)
+                        .map(RequestedFlow::getFlowId).orElse(null));
+
         RequestedFlow request = context.getTargetFlow();
         dashboardLogger.onFlowCreate(request.getFlowId(),
                 request.getSrcSwitch(), request.getSrcPort(), request.getSrcVlan(),
@@ -71,8 +75,14 @@ protected Optional<Message> performWithResponse(State from, State to, Event even
             flowValidator.validateFlowIdUniqueness(request.getFlowId());
             flowValidator.validate(request);
         } catch (InvalidFlowException e) {
+            log.error("F_C_CH FlowValidateAction.performWithResponse, validation fail, flowId: {}",
+                    Optional.ofNullable(context.getTargetFlow())
+                            .map(RequestedFlow::getFlowId).orElse(null), e);
             throw new FlowProcessingException(e.getType(), e.getMessage(), e);
         } catch (UnavailableFlowEndpointException e) {
+            log.error("F_C_CH FlowValidateAction.performWithResponse, validation fail, flowId: {}",
+                    Optional.ofNullable(context.getTargetFlow())
+                            .map(RequestedFlow::getFlowId).orElse(null), e);
             throw new FlowProcessingException(ErrorType.DATA_INVALID, e.getMessage(), e);
         }
 
@@ -81,6 +91,9 @@ protected Optional<Message> performWithResponse(State from, State to, Event even
         stateMachine.saveActionToHistory("Flow was validated successfully",
                 event == Event.RETRY ? "Retrying the operation" : null);
 
+        log.info("F_C_CH FlowValidateAction.performWithResponse, validation success, flowId: {}",
+                Optional.ofNullable(context.getTargetFlow())
+                        .map(RequestedFlow::getFlowId).orElse(null));
         return Optional.empty();
     }
 
@@ -92,7 +105,7 @@ protected String getGenericErrorMessage() {
     @Override
     protected void handleError(FlowCreateFsm stateMachine, Exception ex, ErrorType errorType, boolean logTraceback) {
         super.handleError(stateMachine, ex, errorType, logTraceback);
-
+        log.error("F_C_CH, FlowValidateAction.handleError error, ex: {}, errorType: {}", ex, errorType);
         // Notify about failed validation.
         stateMachine.notifyEventListeners(listener ->
                 listener.onFailed(stateMachine.getFlowId(), stateMachine.getErrorReason(), errorType));

diff --git a/...java/org/openkilda/wfm/topology/flowhs/fsm/create/actions/HandleNotCreatedFlowAction.java b/...java/org/openkilda/wfm/topology/flowhs/fsm/create/actions/HandleNotCreatedFlowAction.java
@@ -26,9 +26,12 @@
 import org.openkilda.wfm.topology.flowhs.fsm.create.FlowCreateFsm;
 import org.openkilda.wfm.topology.flowhs.fsm.create.FlowCreateFsm.Event;
 import org.openkilda.wfm.topology.flowhs.fsm.create.FlowCreateFsm.State;
+import org.openkilda.wfm.topology.flowhs.model.RequestedFlow;
 
 import lombok.extern.slf4j.Slf4j;
 
+import java.util.Optional;
+
 @Slf4j
 public class HandleNotCreatedFlowAction extends HistoryRecordingAction<FlowCreateFsm, State, Event, FlowCreateContext> {
     private final FlowRepository flowRepository;
@@ -42,6 +45,10 @@ public HandleNotCreatedFlowAction(PersistenceManager persistenceManager,
 
     @Override
     public void perform(State from, State to, Event event, FlowCreateContext context, FlowCreateFsm stateMachine) {
+        log.info("F_C_CH HandleNotCreatedFlowAction.perform"
+                        + " flowId from stateMachine: {}, flowId from context: {}, from {}, to {} event {}",
+                stateMachine.getFlowId(), Optional.ofNullable(context).map(FlowCreateContext::getTargetFlow)
+                        .map(RequestedFlow::getFlowId).orElse(null), from, to, event);
         String flowId = stateMachine.getFlowId();
         dashboardLogger.onFlowStatusUpdate(flowId, FlowStatus.DOWN);
         flowRepository.updateStatus(flowId, FlowStatus.DOWN, format("Failed to create flow %s", flowId));

diff --git a/.../java/org/openkilda/wfm/topology/flowhs/fsm/create/actions/InstallIngressRulesAction.java b/.../java/org/openkilda/wfm/topology/flowhs/fsm/create/actions/InstallIngressRulesAction.java
@@ -21,9 +21,12 @@
 import org.openkilda.wfm.topology.flowhs.fsm.create.FlowCreateFsm;
 import org.openkilda.wfm.topology.flowhs.fsm.create.FlowCreateFsm.Event;
 import org.openkilda.wfm.topology.flowhs.fsm.create.FlowCreateFsm.State;
+import org.openkilda.wfm.topology.flowhs.model.RequestedFlow;
 
 import lombok.extern.slf4j.Slf4j;
 
+import java.util.Optional;
+
 @Slf4j
 public class InstallIngressRulesAction extends InstallRulesAction {
     public InstallIngressRulesAction(SpeakerCommandFsm.Builder speakerCommandFsmBuilder,
@@ -33,6 +36,10 @@ public InstallIngressRulesAction(SpeakerCommandFsm.Builder speakerCommandFsmBuil
 
     @Override
     protected void perform(State from, State to, Event event, FlowCreateContext context, FlowCreateFsm stateMachine) {
+        log.info("F_C_CH InstallIngressRulesAction.perform, from {}, to {}, event {}, flowId from context: {},"
+                        + " stateMachine flowId: {}",
+                from, to, event, Optional.ofNullable(context).map(FlowCreateContext::getTargetFlow)
+                        .map(RequestedFlow::getFlowId).orElse(null), stateMachine.getFlowId());
         emitInstallRequests(stateMachine, stateMachine.getIngressCommands());
         stateMachine.saveActionToHistory("Commands for installing ingress rules have been sent");
     }

diff --git a/...va/org/openkilda/wfm/topology/flowhs/fsm/create/actions/InstallNonIngressRulesAction.java b/...va/org/openkilda/wfm/topology/flowhs/fsm/create/actions/InstallNonIngressRulesAction.java
@@ -22,10 +22,12 @@
 import org.openkilda.wfm.topology.flowhs.fsm.create.FlowCreateFsm;
 import org.openkilda.wfm.topology.flowhs.fsm.create.FlowCreateFsm.Event;
 import org.openkilda.wfm.topology.flowhs.fsm.create.FlowCreateFsm.State;
+import org.openkilda.wfm.topology.flowhs.model.RequestedFlow;
 
 import lombok.extern.slf4j.Slf4j;
 
 import java.util.List;
+import java.util.Optional;
 
 @Slf4j
 public class InstallNonIngressRulesAction extends InstallRulesAction {
@@ -36,6 +38,11 @@ public InstallNonIngressRulesAction(SpeakerCommandFsm.Builder fsmBuilder,
 
     @Override
     protected void perform(State from, State to, Event event, FlowCreateContext context, FlowCreateFsm stateMachine) {
+        log.info("F_C_CH InstallNonIngressRulesAction.perform from {}, to {}, event {}, flowId from context: {},"
+                        + " flowId from stateMachine: {}", from, to, event, Optional.ofNullable(context)
+                        .map(FlowCreateContext::getTargetFlow)
+                        .map(RequestedFlow::getFlowId).orElse(null),
+                stateMachine.getFlowId());
         List<FlowSegmentRequestFactory> requestFactories = stateMachine.getNonIngressCommands();
         if (requestFactories.isEmpty()) {
             stateMachine.saveActionToHistory("No need to install non ingress rules");