Inserting more checks and comments around the login process

Also increased the wait time between retries.

Cyprus has reported problems here and I suspect that repeated retries
could be filling up the log files with garbage and pinging the Directory
once per second.

pom.xml

@@ -10,7 +10,7 @@
     </parent>
     <groupId>de.samply</groupId>
     <artifactId>directory_sync_service</artifactId>
-    <version>1.5.3</version>
+    <version>1.5.4</version>
     <name>directory_sync_service</name>
     <description>Directory sync</description>
     <url>https://github.com/samply/directory_sync_service</url>

src/main/java/de/samply/directory_sync_service/directory/DirectoryApi.java

@@ -46,7 +46,7 @@ public boolean isLoginAvailable() {
     String endpoint = directoryEndpoints.getLoginEndpoint();
 
     if (!directoryCalls.endpointExists(endpoint)) {
-      logger.warn("isAvailable: failing availablity test because " + endpoint + " is not accessible");
+      logger.warn("isLoginAvailable: failing availablity test because " + endpoint + " is not accessible");
       return false;
     }
 

src/main/java/de/samply/directory_sync_service/directory/DirectoryCalls.java

@@ -55,7 +55,7 @@ public void setToken(String token) {
    */
   public boolean endpointExists(String endpoint) {
     String url = urlCombine(baseUrl, endpoint);
-    logger.debug("endpointExists: checking if endpoint exists, URL: " + url);
+    logger.info("endpointExists: checking if endpoint exists, URL: " + url);
     HttpHead request = new HttpHead(url);
 
     boolean returnStatus = true;
@@ -65,7 +65,7 @@ public boolean endpointExists(String endpoint) {
       int statusCode = response.getStatusLine().getStatusCode();
       if (statusCode != 200 && statusCode != 204) {
         // The endpoint neither exists nor has the server responded with allowed methods.
-        logger.warn("endpointExists: statusCode: " + statusCode);
+        logger.warn("endpointExists: failure, statusCode: " + statusCode + ", expected 200 or 204");
         returnStatus = false;
       }
     } catch (Exception e) {

src/main/java/de/samply/directory_sync_service/directory/graphql/DirectoryApiGraphql.java

@@ -71,7 +71,7 @@ public boolean isLoginAvailable() {
       return false;
     }
 
-    logger.debug("DirectoryApiGraphql.isLoginAvailable: login availability test has succeeded");
+    logger.info("DirectoryApiGraphql.isLoginAvailable: login availability test has succeeded");
 
     return true;
   }

src/main/java/de/samply/directory_sync_service/directory/rest/DirectoryApiRest.java

@@ -44,11 +44,13 @@ public DirectoryApiRest(String baseUrl, boolean mockDirectory, String username,
    * Log in to the Directory. You can log in as many times as you like.
    */
   public boolean login() {
-    logger.debug("login: logging  in");
+    logger.info("DirectoryApiRest.login: logging  in");
 
-    if (mockDirectory)
+    if (mockDirectory) {
+      logger.info("DirectoryApiRest.login: mocking login, will not actually contact the Directory");
       // Don't try logging in if we are mocking
       return true;
+    }
 
     return directoryCallsRest.login();
   }

src/main/java/de/samply/directory_sync_service/directory/rest/DirectoryCallsRest.java

@@ -58,10 +58,18 @@ public DirectoryCallsRest(String baseUrl, String username, String password) {
   public boolean login() {
     DirectoryCredentials.LoginResponse loginResponse = (DirectoryCredentials.LoginResponse) post(new DirectoryEndpointsRest().getLoginEndpoint(), DirectoryCredentials.LoginResponse.class, directoryCredentials.generateLoginCredentials());
     if (loginResponse == null) {
-      logger.error("login: failed to log in to Directory");
+      logger.warn("DirectoryCallsRest.login: failed to log in to Directory, loginResponse is null");
       return false;
-    } else
-      directoryCredentials.setToken(loginResponse.token);
+    } else {
+      logger.info("DirectoryCallsRest.login: successfully logged in to Directory, trying to set token");
+      String token = loginResponse.token;
+      if (token == null || token.isEmpty()) {
+        logger.warn("DirectoryCallsRest.login: failed to log in to Directory, token is null or empty");
+        return false;
+      }
+      directoryCredentials.setToken(token);
+      logger.info("DirectoryCallsRest.login: successfully set token");
+    }
     return true;
   }
 
@@ -92,8 +100,12 @@ public Object get(String commandUrl, Class c) {
    */
   public Object post(String commandUrl, Class c, Object o) {
     String response = post(commandUrl, o);
-    if (response == null)
+    if (response == null) {
+      logger.warn("DirectoryCallsRest.post: failed to post to Directory, response is null");
+      logger.warn("DirectoryCallsRest.post: commandUrl: " + commandUrl);
+      logger.warn("DirectoryCallsRest.post: o: " + Util.jsonStringFomObject(o));
       return null;
+    }
     Object body = gson.fromJson(response, c);
 
     return body;

src/main/java/de/samply/directory_sync_service/service/DirectorySyncJob.java

@@ -19,6 +19,8 @@
 @DisallowConcurrentExecution
 public class DirectorySyncJob implements StatefulJob  {
     private static final Logger logger = LogManager.getLogger(DirectorySyncJob.class);
+    private int successCounter = 0;
+    private int failureCounter = 0;
 
     /**
      * Method used by Quartz to start a job.
@@ -54,7 +56,18 @@ public void execute(Configuration configuration) {
         boolean directoryMock = Boolean.parseBoolean(configuration.getDirectoryMock());
         boolean directoryOnlyLogin = Boolean.parseBoolean(configuration.getDirectoryOnlyLogin());
 
-        Sync.syncWithDirectoryFailover(retryMax, retryInterval, fhirStoreUrl, directoryUrl, directoryUserName, directoryUserPass, directoryDefaultCollectionId, directoryAllowStarModel, directoryMinDonors, directoryMaxFacts, directoryMock, directoryOnlyLogin);
+        boolean success = Sync.syncWithDirectoryFailover(retryMax, retryInterval, fhirStoreUrl, directoryUrl, directoryUserName, directoryUserPass, directoryDefaultCollectionId, directoryAllowStarModel, directoryMinDonors, directoryMaxFacts, directoryMock, directoryOnlyLogin);
+
+        if (success) {
+            logger.info("execute: Directory sync succeeded");
+            successCounter++;
+        } else {
+            logger.info("execute: Directory sync failed");
+            failureCounter++;
+        }
+        // Print a warning message once a week if we never have any successful Directory sync runs.
+        if (successCounter == 0 && failureCounter >= 7 && failureCounter%7 == 0)
+            logger.warn("execute: Directory sync appears to be consistently failing, failureCounter=" + failureCounter);
     }
 
     /**

src/main/java/de/samply/directory_sync_service/sync/Sync.java

@@ -39,28 +39,36 @@ public class Sync {
      *
      * @throws IOException
      */
-    public static void syncWithDirectoryFailover(String retryMax, String retryInterval, String fhirStoreUrl, String directoryUrl, String directoryUserName, String directoryUserPass, String directoryDefaultCollectionId, boolean directoryAllowStarModel, int directoryMinDonors, int directoryMaxFacts, boolean directoryMock, boolean directoryOnlyLogin) {
-        for (int retryNum = 0; retryNum < Integer.parseInt(retryMax); retryNum++) {
-            if (retryNum > 0) {
-                try {
-                    Thread.sleep(Integer.parseInt(retryInterval) * 1000L);
-                } catch (InterruptedException e) {
-                    e.printStackTrace();
-                }
-            }
-            logger.info("syncWithDirectoryFailover: retrying sync, attempt " + retryNum + " of " + retryMax);
-            if (syncWithDirectory(fhirStoreUrl, directoryUrl, directoryUserName, directoryUserPass, directoryDefaultCollectionId, directoryAllowStarModel, directoryMinDonors, directoryMaxFacts, directoryMock, directoryOnlyLogin))
+    public static boolean syncWithDirectoryFailover(String retryMax, String retryInterval, String fhirStoreUrl, String directoryUrl, String directoryUserName, String directoryUserPass, String directoryDefaultCollectionId, boolean directoryAllowStarModel, int directoryMinDonors, int directoryMaxFacts, boolean directoryMock, boolean directoryOnlyLogin) {
+        boolean success = false;
+        int retryNum;
+        for (retryNum = 0; retryNum < Integer.parseInt(retryMax); retryNum++) {
+            logger.info("syncWithDirectoryFailover: trying sync, attempt " + retryNum + " of " + retryMax);
+            if (syncWithDirectory(fhirStoreUrl, directoryUrl, directoryUserName, directoryUserPass, directoryDefaultCollectionId, directoryAllowStarModel, directoryMinDonors, directoryMaxFacts, directoryMock, directoryOnlyLogin)) {
+                success = true;
                 break;
+            }
             logger.info("syncWithDirectoryFailover: attempt " + retryNum + " of " + retryMax + " failed");
+            try {
+                // Sleep for 100 seconds before trying again
+                Thread.sleep(Integer.parseInt(retryInterval) * 100000L);
+            } catch (InterruptedException e) {
+                e.printStackTrace();
+            }
         }
+        if (retryNum == Integer.parseInt(retryMax))
+            logger.warn("syncWithDirectoryFailover: reached maximum number of retires(" + Integer.parseInt(retryMax) + "), giving up");
+        logger.info("syncWithDirectoryFailover: done");
+
+        return success;
     }
 
     private static boolean syncWithDirectory(String fhirStoreUrl, String directoryUrl, String directoryUserName, String directoryUserPass, String directoryDefaultCollectionId, boolean directoryAllowStarModel, int directoryMinDonors, int directoryMaxFacts, boolean directoryMock, boolean directoryOnlyLogin) {
         Map<String, String> correctedDiagnoses = null;
         // Re-initialize helper classes every time this method gets called
         FhirApi fhirApi = new FhirApi(fhirStoreUrl);
         DirectoryApi directoryApi = new DirectoryApiGraphql(directoryUrl, directoryMock, directoryUserName, directoryUserPass);
-          if (!directoryApi.isLoginAvailable()) {
+        if (!directoryApi.isLoginAvailable()) {
             logger.warn("syncWithDirectory: Directory GraphQL API is not available, trying REST API");
             directoryApi = new DirectoryApiRest(directoryUrl, directoryMock, directoryUserName, directoryUserPass);
 //            if (!directoryApi.isLoginAvailable()) {