Add retry mechanism to call RS history API (#747)

* Changed OrderSender.sendOrder to return the sent submissionId (as optional)

* Added sentSubmissionId to PartnerMetadata record, and renamed uniqueId to receivedSubmissionId. Also, overloaded record constructor to only take receivedSubmissionId

* Updated tests

* Added missed import and fixed more tests

* Fixed test

* Fixed e2e test

* Refactored to split RS endpoint logic to its own ReportStreamEndpointClient class

* Added custom exception for ReportStreamEndpointClient

* Refactored for separation of concerns and clarity

* Further refactoring in preparation to call the history API

* Added implementation for http get method

* Added call to history API to update receiver metadata

* Added missing application context registration for ReportStreamEndpointClient

* Removed unused line

* Import missing class

* Added some comments

* Added methods to partially update PartnerMetadata and making sure to read existing metadata before updating

* Added tests for PartnerMetadataOrchestrator

* Some code cleaning

* Fixed test

* Added tests for PartnerMetadata changes

* Added tests for requestHistoryEndpoint + some cleanup

* Cleaned up naming and add logging

* Implemented updateMetadataForReceivedOrder and getMetadata

* Refactored PartnerMetadata.withSentSubmissionFields to split into separate methods for each parameter

* Changed logic to make sure to save sentSubmissionId into metadata file even if not able to retrieve receiver

* Fixed tests

* Added tests for updateMetadataForReceivedOrder + validation logic

* Added test to cover logic for missing receiver in getMetadata

* Added todo comment

* Added logging

* Added RetryTask class to help add retry mechanism when calling the history API to get receiver

* Added tests

* Missed import

* Refactored string comparison

* Made improvements based on Jeff's feedback

* Simplified logic by using try/catch instead of checking for expected format

* Added null check

* Simplified logic by catching exception instead of checking for expected format

* Return if sentSubmissionId is null given we can't update the metadata

* Fixed wrong commit

* Fixed failing tests

* Update etor/src/main/java/gov/hhs/cdc/trustedintermediary/etor/metadata/PartnerMetadataOrchestrator.java

Co-authored-by: halprin <[email protected]>

* Fixed exception

* test case for single param constructor

* single param contructor for PartnerMetadataException

* super with sigle param

* Added missing mock return value for requestHistoryEndpoint

* Fixed failing test

* Cleanup

* Refactored RetryTask to be synchronous

* Added test assertions

* Added error logging if not able to save metadata after retries

* Refactored happy path test to get more coverage

* Added a test and refactored to simplify

* Added test for exception use case

* Added javadocs

* Cleanup based on feedback

* Refactored retry implementation to return T and throw an exception in case of too many failed retries

* Fixed call, still need to fix test

* Fixed and added tests

* Committed by mistake

* Added test and javadocs for RetryFailedException

---------

Co-authored-by: halprin <[email protected]>
Co-authored-by: jorge Lopez <[email protected]>

app/src/main/java/gov/hhs/cdc/trustedintermediary/external/javalin/App.java

@@ -17,6 +17,7 @@
 import gov.hhs.cdc.trustedintermediary.external.slf4j.DeployedLogger;
 import gov.hhs.cdc.trustedintermediary.external.slf4j.LocalLogger;
 import gov.hhs.cdc.trustedintermediary.organizations.OrganizationsSettings;
+import gov.hhs.cdc.trustedintermediary.utils.SyncRetryTask;
 import gov.hhs.cdc.trustedintermediary.wrappers.AuthEngine;
 import gov.hhs.cdc.trustedintermediary.wrappers.Cache;
 import gov.hhs.cdc.trustedintermediary.wrappers.HapiFhir;
@@ -87,5 +88,6 @@ private static void registerClasses() {
         ApplicationContext.register(
                 OrganizationsSettings.class, OrganizationsSettings.getInstance());
         ApplicationContext.register(MetricMetadata.class, LoggingMetricMetadata.getInstance());
+        ApplicationContext.register(SyncRetryTask.class, SyncRetryTask.getInstance());
     }
 }

etor/src/main/java/gov/hhs/cdc/trustedintermediary/etor/orders/SendOrderUseCase.java

@@ -3,8 +3,11 @@
 import gov.hhs.cdc.trustedintermediary.etor.metadata.EtorMetadataStep;
 import gov.hhs.cdc.trustedintermediary.etor.metadata.PartnerMetadataException;
 import gov.hhs.cdc.trustedintermediary.etor.metadata.PartnerMetadataOrchestrator;
+import gov.hhs.cdc.trustedintermediary.utils.RetryFailedException;
+import gov.hhs.cdc.trustedintermediary.utils.SyncRetryTask;
 import gov.hhs.cdc.trustedintermediary.wrappers.Logger;
 import gov.hhs.cdc.trustedintermediary.wrappers.MetricMetadata;
+import java.util.concurrent.Callable;
 import javax.inject.Inject;
 
 /** The overall logic to receive, convert to OML, and subsequently send a lab order. */
@@ -15,6 +18,7 @@ public class SendOrderUseCase {
     @Inject MetricMetadata metadata;
     @Inject PartnerMetadataOrchestrator partnerMetadataOrchestrator;
     @Inject Logger logger;
+    @Inject SyncRetryTask retryTask;
 
     private SendOrderUseCase() {}
 
@@ -62,11 +66,15 @@ private void saveSentOrderSubmissionId(String receivedSubmissionId, String sentS
                     "Received and/or sent submissionId is null so not saving metadata for sent order");
             return;
         }
-
+        Callable<Void> task =
+                () -> {
+                    partnerMetadataOrchestrator.updateMetadataForSentOrder(
+                            receivedSubmissionId, sentSubmissionId);
+                    return null;
+                };
         try {
-            partnerMetadataOrchestrator.updateMetadataForSentOrder(
-                    receivedSubmissionId, sentSubmissionId);
-        } catch (PartnerMetadataException e) {
+            retryTask.retry(task, 3, 1000);
+        } catch (RetryFailedException e) {
             logger.logError(
                     "Unable to update metadata for received submissionId "
                             + receivedSubmissionId

etor/src/test/groovy/gov/hhs/cdc/trustedintermediary/etor/orders/SendOrderUsecaseTest.groovy

@@ -3,74 +3,122 @@ package gov.hhs.cdc.trustedintermediary.etor.orders
 import gov.hhs.cdc.trustedintermediary.OrderMock
 import gov.hhs.cdc.trustedintermediary.context.TestApplicationContext
 import gov.hhs.cdc.trustedintermediary.etor.metadata.EtorMetadataStep
+import gov.hhs.cdc.trustedintermediary.etor.metadata.PartnerMetadataException
 import gov.hhs.cdc.trustedintermediary.etor.metadata.PartnerMetadataOrchestrator
+import gov.hhs.cdc.trustedintermediary.utils.RetryFailedException
+import gov.hhs.cdc.trustedintermediary.utils.SyncRetryTask
+import gov.hhs.cdc.trustedintermediary.wrappers.Logger
 import gov.hhs.cdc.trustedintermediary.wrappers.MetricMetadata
 import spock.lang.Specification
 
+import java.util.concurrent.Callable
+
 class SendOrderUsecaseTest extends Specification {
 
+    def mockOrchestrator = Mock(PartnerMetadataOrchestrator)
+    def mockConverter = Mock(OrderConverter)
+    def mockSender = Mock(OrderSender)
+    def mockLogger = Mock(Logger)
+    def mockRetryTask = Mock(SyncRetryTask)
+
     def setup() {
         TestApplicationContext.reset()
         TestApplicationContext.init()
         TestApplicationContext.register(SendOrderUseCase, SendOrderUseCase.getInstance())
         TestApplicationContext.register(MetricMetadata, Mock(MetricMetadata))
-        TestApplicationContext.register(PartnerMetadataOrchestrator, Mock(PartnerMetadataOrchestrator))
+        TestApplicationContext.register(PartnerMetadataOrchestrator, mockOrchestrator)
+        TestApplicationContext.register(OrderConverter, mockConverter)
+        TestApplicationContext.register(OrderSender, mockSender)
+        TestApplicationContext.register(Logger, mockLogger)
+        TestApplicationContext.register(SyncRetryTask, mockRetryTask)
     }
 
     def "send sends successfully"() {
         given:
-        def mockOrder = new OrderMock(null, null, null)
+        def receivedSubmissionId = "receivedId"
+        def sentSubmissionId = "sentId"
 
-        def mockConverter = Mock(OrderConverter)
-        TestApplicationContext.register(OrderConverter, mockConverter)
+        def sendOrder = SendOrderUseCase.getInstance()
+        def mockOrder = new OrderMock(null, null, null)
+        def mockOmlOrder = Mock(Order)
 
-        def mockSender = Mock(OrderSender)
-        TestApplicationContext.register(OrderSender, mockSender)
+        mockRetryTask.retry({ it.call(); true }, _, _) >> { Callable<Void> task, int retries, int delay -> task.call(); true }
 
         TestApplicationContext.injectRegisteredImplementations()
 
         when:
-        SendOrderUseCase.getInstance().convertAndSend(mockOrder, _ as String)
+        sendOrder.convertAndSend(mockOrder, receivedSubmissionId)
 
         then:
-        1 * mockConverter.convertMetadataToOmlOrder(mockOrder)
-        1 * mockConverter.addContactSectionToPatientResource(_)
-        1 * mockSender.sendOrder(_) >> Optional.empty()
+        1 * mockConverter.convertMetadataToOmlOrder(mockOrder) >> mockOmlOrder
+        1 * mockConverter.addContactSectionToPatientResource(mockOmlOrder) >> mockOmlOrder
+        1 * mockSender.sendOrder(mockOmlOrder) >> Optional.of(sentSubmissionId)
+        1 * sendOrder.metadata.put(_, EtorMetadataStep.ORDER_CONVERTED_TO_OML)
+        1 * sendOrder.metadata.put(_, EtorMetadataStep.CONTACT_SECTION_ADDED_TO_PATIENT)
+        1 * mockOrchestrator.updateMetadataForReceivedOrder(receivedSubmissionId, _ as String)
+        1 * mockOrchestrator.updateMetadataForSentOrder(receivedSubmissionId, sentSubmissionId)
     }
 
-    def "metadata is registered for converting to OML and for adding the contact section to an order"() {
+    def "send fails to send"() {
         given:
-        TestApplicationContext.register(OrderConverter, Mock(OrderConverter))
+        mockSender.sendOrder(_) >> { throw new UnableToSendOrderException("DogCow", new NullPointerException()) }
+        TestApplicationContext.injectRegisteredImplementations()
 
-        def mockSender = Mock(OrderSender)
-        mockSender.sendOrder(_) >> Optional.empty()
-        TestApplicationContext.register(OrderSender, mockSender)
+        when:
+        SendOrderUseCase.getInstance().convertAndSend(Mock(Order), _ as String)
 
+        then:
+        thrown(UnableToSendOrderException)
+    }
+
+    def "convertAndSend should log warnings for null receivedSubmissionId"() {
+        given:
+        mockSender.sendOrder(_) >> Optional.of("sentSubmissionId")
         TestApplicationContext.injectRegisteredImplementations()
 
         when:
-        SendOrderUseCase.getInstance().convertAndSend(new OrderMock(null, null, null), _ as String)
+        SendOrderUseCase.getInstance().convertAndSend(Mock(Order), null)
 
         then:
-        1 * SendOrderUseCase.getInstance().metadata.put(_, EtorMetadataStep.ORDER_CONVERTED_TO_OML)
-        1 * SendOrderUseCase.getInstance().metadata.put(_, EtorMetadataStep.CONTACT_SECTION_ADDED_TO_PATIENT)
+        2 * mockLogger.logWarning(_)
+        0 * mockOrchestrator.updateMetadataForReceivedOrder(_, _)
     }
 
-    def "send fails to send"() {
+    def "convertAndSend logs error and continues when updateMetadataForReceivedOrder throws exception"() {
         given:
-        def mockOrder = new OrderMock(null, null, null)
-        def mockConverter = Mock(OrderConverter)
-        def mockSender = Mock(OrderSender)
-        mockSender.sendOrder(_) >> { throw new UnableToSendOrderException("DogCow", new NullPointerException()) }
+        def order = Mock(Order)
+        def omlOrder = Mock(Order)
+        def receivedSubmissionId = "receivedId"
+        mockOrchestrator.updateMetadataForReceivedOrder(receivedSubmissionId, _ as String) >> { throw new PartnerMetadataException("Error") }
+        TestApplicationContext.injectRegisteredImplementations()
 
-        TestApplicationContext.register(OrderConverter, mockConverter)
-        TestApplicationContext.register(OrderSender, mockSender)
+        when:
+        SendOrderUseCase.getInstance().convertAndSend(order, receivedSubmissionId)
+
+        then:
+        1 * mockLogger.logError(_, _)
+        1 * mockConverter.convertMetadataToOmlOrder(order) >> omlOrder
+        1 * mockConverter.addContactSectionToPatientResource(omlOrder) >> omlOrder
+        1 * mockSender.sendOrder(omlOrder) >> Optional.of("sentId")
+        1 * mockRetryTask.retry(_, _, _)
+        noExceptionThrown()
+    }
+
+    def "convertAndSend logs error and continues when retryTask throws exception"() {
+        given:
+        def order = Mock(Order)
+        def omlOrder = Mock(Order)
         TestApplicationContext.injectRegisteredImplementations()
 
         when:
-        SendOrderUseCase.getInstance().convertAndSend(mockOrder, _ as String)
+        SendOrderUseCase.getInstance().convertAndSend(order, "receivedId")
 
         then:
-        thrown(UnableToSendOrderException)
+        1 * mockConverter.convertMetadataToOmlOrder(order) >> omlOrder
+        1 * mockConverter.addContactSectionToPatientResource(omlOrder) >> omlOrder
+        1 * mockSender.sendOrder(omlOrder) >> Optional.of("sentId")
+        1 * mockRetryTask.retry(_, _, _) >> { throw new RetryFailedException("Error", new Exception()) }
+        1 * mockLogger.logError(_, _)
+        noExceptionThrown()
     }
 }

shared/src/main/java/gov/hhs/cdc/trustedintermediary/utils/RetryFailedException.java

@@ -0,0 +1,12 @@
+package gov.hhs.cdc.trustedintermediary.utils;
+
+/**
+ * Custom exception that wraps the last exception thrown after the maximum number of retries has
+ * been reached. It could also be thrown in the case of a InterruptedException.
+ */
+public class RetryFailedException extends Exception {
+
+    public RetryFailedException(String message, Throwable cause) {
+        super(message, cause);
+    }
+}

shared/src/main/java/gov/hhs/cdc/trustedintermediary/utils/SyncRetryTask.java

@@ -0,0 +1,48 @@
+package gov.hhs.cdc.trustedintermediary.utils;
+
+import gov.hhs.cdc.trustedintermediary.wrappers.Logger;
+import java.util.concurrent.Callable;
+import javax.inject.Inject;
+
+/**
+ * Provides a reusable utility for retrying a task with a specified number of retries and wait time
+ * between retries.
+ */
+public class SyncRetryTask {
+    private static final SyncRetryTask INSTANCE = new SyncRetryTask();
+    @Inject Logger logger;
+
+    public static SyncRetryTask getInstance() {
+        return INSTANCE;
+    }
+
+    private SyncRetryTask() {}
+
+    public <T> T retry(Callable<T> task, int maxRetries, long waitTime)
+            throws RetryFailedException {
+        Exception lastException = null;
+        int attempt = 0;
+
+        while (attempt < maxRetries) {
+            try {
+                return task.call();
+            } catch (Exception e) {
+                lastException = e;
+                attempt++;
+
+                logger.logWarning("Attempt {}: Retrying in {}s", attempt, waitTime * 2 / 1000);
+
+                try {
+                    Thread.sleep(waitTime);
+                } catch (InterruptedException ie) {
+                    Thread.currentThread().interrupt(); // Restore interrupted status
+                    throw new RetryFailedException("Thread interrupted during retries", ie);
+                }
+
+                waitTime *= 2;
+            }
+        }
+
+        throw new RetryFailedException("Failed after " + maxRetries + " retries", lastException);
+    }
+}

shared/src/test/groovy/gov/hhs/cdc/trustedintermediary/utils/RetryFailedExceptionTest.groovy

@@ -0,0 +1,18 @@
+package gov.hhs.cdc.trustedintermediary.utils
+
+import spock.lang.Specification
+
+class RetryFailedExceptionTest extends Specification {
+    def "test constructor"() {
+        given:
+        def message = "DogCow"
+
+        when:
+        def innerException = new IOException()
+        def exception = new RetryFailedException(message, innerException)
+
+        then:
+        exception.getMessage() == message
+        exception.getCause() == innerException
+    }
+}

shared/src/test/groovy/gov/hhs/cdc/trustedintermediary/utils/SyncRetryTaskTest.groovy

@@ -0,0 +1,46 @@
+package gov.hhs.cdc.trustedintermediary.utils
+
+import gov.hhs.cdc.trustedintermediary.context.TestApplicationContext
+import spock.lang.Specification
+
+import java.util.concurrent.Callable
+
+class SyncRetryTaskTest extends Specification {
+
+    def setup() {
+        TestApplicationContext.reset()
+        TestApplicationContext.init()
+        TestApplicationContext.register(SyncRetryTask, SyncRetryTask.getInstance())
+        TestApplicationContext.injectRegisteredImplementations()
+    }
+
+    def "scheduleRetry should retry the task until it succeeds"() {
+        given:
+        def maxRetries = 3
+        def waitTime = 10
+        Callable<Void> mockTask = Mock(Callable)
+
+        when:
+        def result = SyncRetryTask.getInstance().retry(mockTask, maxRetries, waitTime)
+
+        then:
+        (1..maxRetries - 1) * mockTask.call() >> { throw new Exception("Fail") }
+        1 * mockTask.call() >> null // Succeeds on the last attempt
+        result == null
+    }
+
+    def "scheduleRetry should give up after max retries and throw RetryFailedException"() {
+        given:
+        def maxRetries = 3
+        def waitTime = 10
+        Callable<Void> mockTask = Mock(Callable)
+
+        when:
+        SyncRetryTask.getInstance().retry(mockTask, maxRetries, waitTime)
+
+        then:
+        maxRetries * mockTask.call() >> { throw new Exception("Fail") }
+        def exception = thrown(RetryFailedException)
+        exception.getCause().getClass() == Exception
+    }
+}