diff --git a/api/src/main/java/ca/bc/gov/educ/penreg/api/orchestrator/PenReqBatchStudentOrchestrator.java b/api/src/main/java/ca/bc/gov/educ/penreg/api/orchestrator/PenReqBatchStudentOrchestrator.java index 7444d49c..463daf0d 100644 --- a/api/src/main/java/ca/bc/gov/educ/penreg/api/orchestrator/PenReqBatchStudentOrchestrator.java +++ b/api/src/main/java/ca/bc/gov/educ/penreg/api/orchestrator/PenReqBatchStudentOrchestrator.java @@ -29,12 +29,14 @@ import ca.bc.gov.educ.penreg.api.struct.PenRequestBatchStudentSagaData; import ca.bc.gov.educ.penreg.api.struct.PenRequestValidationIssue; import ca.bc.gov.educ.penreg.api.util.JsonUtil; +import ca.bc.gov.educ.penreg.api.util.Stopwatch; import com.fasterxml.jackson.core.JsonProcessingException; import com.fasterxml.jackson.core.type.TypeReference; import com.fasterxml.jackson.databind.ObjectMapper; import java.io.IOException; import java.util.List; import java.util.Optional; +import java.util.UUID; import java.util.concurrent.TimeoutException; import java.util.stream.Collectors; import lombok.Getter; @@ -111,12 +113,18 @@ public void populateStepsToExecuteMap() { * @throws JsonProcessingException the json processing exception */ protected void validateStudentDemographics(final Event event, final Saga saga, final PenRequestBatchStudentSagaData penRequestBatchStudentSagaData) throws IOException, InterruptedException, TimeoutException { + UUID sagaId = saga.getSagaId(); + Stopwatch validateStudentDemographics = new Stopwatch("validateStudentDemographics", sagaId); + Stopwatch updateAttachedSagaWithEvents = new Stopwatch("updateAttachedSagaWithEvents", sagaId); + validateStudentDemographics.start(); final var scrubbedSagaData = this.getPenRequestBatchStudentOrchestratorService() .scrubPayload(penRequestBatchStudentSagaData); final SagaEvent eventStates = this.createEventState(saga, event.getEventType(), event.getEventOutcome(), event.getEventPayload()); saga.setSagaState(VALIDATE_STUDENT_DEMOGRAPHICS.toString()); saga.setPayload(JsonUtil.getJsonStringFromObject(scrubbedSagaData)); // update the payload with scrubbed values to use it in the saga process... + updateAttachedSagaWithEvents.start(); this.getSagaService().updateAttachedSagaWithEvents(saga, eventStates); + updateAttachedSagaWithEvents.stop(); final var validationPayload = validationMapper.toStudentDemogValidationPayload(scrubbedSagaData); validationPayload.setTransactionID(saga.getSagaId().toString()); @@ -133,6 +141,8 @@ protected void validateStudentDemographics(final Event event, final Saga saga, f log.error("event payload is not present this should not have happened. :: {}", saga.getSagaId()); } + validateStudentDemographics.stop(); + } /** @@ -148,6 +158,12 @@ protected void validateStudentDemographics(final Event event, final Saga saga, f * @throws TimeoutException the timeout exception */ protected void processPenMatchResults(final Event event, final Saga saga, final PenRequestBatchStudentSagaData penRequestBatchStudentSagaData) throws IOException, InterruptedException, TimeoutException { + UUID sagaId = saga.getSagaId(); + Stopwatch processPenMatchResults = new Stopwatch("processPenMatchResults", sagaId); + Stopwatch updateAttachedSaga = new Stopwatch("updateAttachedSagaWithEvents", sagaId); + Stopwatch updateAttachedEntityDuringSaga = new Stopwatch("updateAttachedEntityDuringSagaProcess", sagaId); + processPenMatchResults.start(); + final Optional eventOptional; if (penRequestBatchStudentSagaData.getIsPENMatchResultsProcessed() == null || !penRequestBatchStudentSagaData.getIsPENMatchResultsProcessed()) { // this is necessary to check, to avoid duplicate execution during replay process. @@ -156,13 +172,19 @@ protected void processPenMatchResults(final Event event, final Saga saga, final final var penMatchResult = JsonUtil.getJsonObjectFromString(PenMatchResult.class, event.getEventPayload()); penRequestBatchStudentSagaData.setPenMatchResult(penMatchResult); // update the original payload with response from PEN_MATCH_API saga.setPayload(JsonUtil.getJsonStringFromObject(penRequestBatchStudentSagaData)); // save the updated payload to DB... + + updateAttachedSaga.start(); this.getSagaService().updateAttachedSagaWithEvents(saga, eventStates); + updateAttachedSaga.stop(); eventOptional = this.getPenRequestBatchStudentOrchestratorService().processPenMatchResult(saga, penRequestBatchStudentSagaData, penMatchResult); penRequestBatchStudentSagaData.setIsPENMatchResultsProcessed(true); saga.setPayload(JsonUtil.getJsonStringFromObject(penRequestBatchStudentSagaData)); // save the updated payload to DB... + + updateAttachedEntityDuringSaga.start(); this.getSagaService().updateAttachedEntityDuringSagaProcess(saga); + updateAttachedEntityDuringSaga.stop(); } else { eventOptional = Optional.of(Event.builder().sagaId(saga.getSagaId()) .eventType(PROCESS_PEN_MATCH_RESULTS).eventOutcome(PEN_MATCH_RESULTS_PROCESSED).eventPayload(penRequestBatchStudentSagaData.getPenMatchResult().getPenStatus()) @@ -177,6 +199,8 @@ protected void processPenMatchResults(final Event event, final Saga saga, final .build()); } + processPenMatchResults.stop(); + } @@ -188,11 +212,21 @@ protected void processPenMatchResults(final Event event, final Saga saga, final * @param penRequestBatchStudentSagaData the pen request batch student saga data */ protected void processPenMatch(final Event event, final Saga saga, final PenRequestBatchStudentSagaData penRequestBatchStudentSagaData) { + UUID sagaId = saga.getSagaId(); + Stopwatch processPenMatch = new Stopwatch("processPenMatch", sagaId); + Stopwatch updateAttachedSagaWithEvents = new Stopwatch("updateAttachedSagaWithEvents", sagaId); + Stopwatch saveDemogValidationResults = new Stopwatch("saveDemogValidationResults", sagaId); + processPenMatch.start(); + final SagaEvent eventStates = this.createEventState(saga, event.getEventType(), event.getEventOutcome(), event.getEventPayload()); saga.setSagaState(PROCESS_PEN_MATCH.toString()); + updateAttachedSagaWithEvents.start(); this.getSagaService().updateAttachedSagaWithEvents(saga, eventStates); + updateAttachedSagaWithEvents.stop(); // need to persist the validation warnings from response payload. + saveDemogValidationResults.start(); this.saveDemogValidationResults(event, penRequestBatchStudentSagaData); + saveDemogValidationResults.stop(); final var eventPayload = JsonUtil.getJsonString(penMatchSagaMapper.toPenMatchStudent(penRequestBatchStudentSagaData)); if (eventPayload.isPresent()) { final Event nextEvent = Event.builder().sagaId(saga.getSagaId()) @@ -206,6 +240,8 @@ protected void processPenMatch(final Event event, final Saga saga, final PenRequ log.error("event payload is not present this should not have happened. :: {}", saga.getSagaId()); } + processPenMatch.stop(); + } /** @@ -226,6 +262,10 @@ private void completePenRequestBatchStudentSaga(final Event event, final Saga sa * @param sagaData the saga data */ protected void saveDemogValidationResults(final Event event, final PenRequestBatchStudentSagaData sagaData) { + UUID sagaId = event.getSagaId(); + Stopwatch saveDemogValidationResults = new Stopwatch("saveDemogValidationResults", sagaId); + Stopwatch saveDemogValidationResultsAndUpdateStudentStatus = new Stopwatch("saveDemogValidationResultsAndUpdateStudentStatus", sagaId); + saveDemogValidationResults.start(); if (event.getEventType() == VALIDATE_STUDENT_DEMOGRAPHICS && StringUtils.isNotBlank(event.getEventPayload()) && !StringUtils.equalsIgnoreCase(VALIDATION_SUCCESS_NO_ERROR_WARNING.toString(), event.getEventPayload())) { @@ -241,11 +281,15 @@ protected void saveDemogValidationResults(final Event event, final PenRequestBat final var validationResults = new ObjectMapper().readValue(event.getEventPayload(), responseType); if (!validationResults.isEmpty()) { final var mappedEntities = validationResults.stream().map(issueMapper::toModel).collect(Collectors.toList()); + saveDemogValidationResultsAndUpdateStudentStatus.start(); this.getPenRequestBatchStudentOrchestratorService().saveDemogValidationResultsAndUpdateStudentStatus(mappedEntities, statusCode, sagaData.getPenRequestBatchStudentID()); + saveDemogValidationResultsAndUpdateStudentStatus.stop(); } } catch (final JsonProcessingException ex) { log.error("json exception for :: {} {}", event.getSagaId().toString(), ex); } + + saveDemogValidationResults.stop(); } } } diff --git a/api/src/main/java/ca/bc/gov/educ/penreg/api/util/Stopwatch.java b/api/src/main/java/ca/bc/gov/educ/penreg/api/util/Stopwatch.java new file mode 100644 index 00000000..ee2f2943 --- /dev/null +++ b/api/src/main/java/ca/bc/gov/educ/penreg/api/util/Stopwatch.java @@ -0,0 +1,25 @@ +package ca.bc.gov.educ.penreg.api.util; + +import java.util.UUID; +import lombok.extern.slf4j.Slf4j; + +@Slf4j +public class Stopwatch { + private long startTime; + private final String functionName; + private final UUID sagaId; + + public Stopwatch(String functionName, UUID sagaId) { + this.functionName = functionName; + this.sagaId = sagaId; + } + + public void start() { + startTime = System.nanoTime(); + } + + public void stop() { + long endTime = System.nanoTime(); + log.info("function :: {} took {} milliseconds for sagaId {}", this.functionName, (endTime - this.startTime) / 10000000, this.sagaId); + } +}