Address PR feedback

Author: Avery-Dunn

msal4j-sdk/src/main/java/com/microsoft/aad/msal4j/AcquireTokenSilentSupplier.java

@@ -120,15 +120,15 @@ private boolean shouldRefresh(SilentParameters parameters, AuthenticationResult
         //If forceRefresh is true, no reason to check any other option
         if (parameters.forceRefresh()) {
             setCacheTelemetry(CacheRefreshReason.FORCE_REFRESH);
-            log.debug("Refreshing access token because forceRefresh parameter is true.");
+            log.debug(String.format("Refreshing access token. Cache refresh reason: %s", CacheRefreshReason.FORCE_REFRESH));
             return true;
         }
 
         //If the request contains claims then the token should be refreshed, to ensure that the returned token has the correct claims
         //  Note: these are the types of claims found in (for example) a claims challenge, and do not include client capabilities
         if (parameters.claims() != null) {
             setCacheTelemetry(CacheRefreshReason.CLAIMS);
-            log.debug("Refreshing access token because the claims parameter is not null.");
+            log.debug(String.format("Refreshing access token. Cache refresh reason: %s", CacheRefreshReason.CLAIMS));
             return true;
         }
 
@@ -137,7 +137,7 @@ private boolean shouldRefresh(SilentParameters parameters, AuthenticationResult
         //If the access token is expired or within 5 minutes of becoming expired, refresh it
         if (!StringHelper.isBlank(cachedResult.accessToken()) && cachedResult.expiresOn() < (currTimeStampSec + ACCESS_TOKEN_EXPIRE_BUFFER_IN_SEC)) {
             setCacheTelemetry(CacheRefreshReason.EXPIRED);
-            log.debug("Refreshing access token because it is expired.");
+            log.debug(String.format("Refreshing access token. Cache refresh reason: %s", CacheRefreshReason.EXPIRED));
             return true;
         }
 
@@ -146,14 +146,14 @@ private boolean shouldRefresh(SilentParameters parameters, AuthenticationResult
                 cachedResult.refreshOn() != null && cachedResult.refreshOn() > 0 &&
                 cachedResult.refreshOn() < currTimeStampSec && cachedResult.expiresOn() >= (currTimeStampSec + ACCESS_TOKEN_EXPIRE_BUFFER_IN_SEC)){
             setCacheTelemetry(CacheRefreshReason.PROACTIVE_REFRESH);
-            log.debug("Attempting to refresh access token because it is after the refreshOn time.");
+            log.debug(String.format("Refreshing access token. Cache refresh reason: %s", CacheRefreshReason.PROACTIVE_REFRESH));
             return true;
         }
 
         //If there is a refresh token but no access token, we should use the refresh token to get the access token
         if (StringHelper.isBlank(cachedResult.accessToken()) && !StringHelper.isBlank(cachedResult.refreshToken())) {
             setCacheTelemetry(CacheRefreshReason.NO_CACHED_ACCESS_TOKEN);
-            log.debug("Refreshing access token because it was missing from the cache.");
+            log.debug(String.format("Refreshing access token. Cache refresh reason: %s", CacheRefreshReason.NO_CACHED_ACCESS_TOKEN));
             return true;
         }
 

msal4j-sdk/src/test/java/com/microsoft/aad/msal4j/AcquireTokenSilentlyTest.java

@@ -21,6 +21,7 @@
 import java.util.HashMap;
 import java.util.concurrent.CompletableFuture;
 import java.util.concurrent.ExecutionException;
+import java.util.concurrent.TimeUnit;
 
 
 @TestInstance(TestInstance.Lifecycle.PER_CLASS)
@@ -157,15 +158,31 @@ void testTokenRefreshReasons() throws Exception {
         assertRefreshedToken(result, "nearlyExpiredToken", CacheRefreshReason.EXPIRED, cca.tokenCache.accessTokens.size());
 
         //Attempt to retrieve the cached token, however it is within the 5-minute buffer and should be refreshed.
-        // In this test, it will be replaced with a token that expires in 1 hour
+        // In this test, it will be replaced with a token that expires in 1 hour but has a refresh_in time of 1 second
+        responseParameters.put("access_token", "refreshInToken");
+        responseParameters.put("expires_in", "3600");
+        responseParameters.put("refresh_in", "1");
+        TestHelper.createTokenRequestMock(httpClientMock, TestHelper.getSuccessfulTokenResponse(responseParameters), 200);
+
+        silentParameters = SilentParameters.builder(Collections.singleton("someScopes"), result.account()).build();
+        result = cca.acquireTokenSilently(silentParameters).get();
+
+        assertRefreshedToken(result, "refreshInToken", CacheRefreshReason.EXPIRED, cca.tokenCache.accessTokens.size());
+
+        //Attempt to retrieve the cached token, however it is within the 5-minute buffer and should be refreshed.
+        // In this test, it will be replaced with a token that expires in 1 hour (and does not have a valid refresh_in time)
         responseParameters.put("access_token", "normalToken");
         responseParameters.put("expires_in", "3600");
+        responseParameters.put("refresh_in", "0");
         TestHelper.createTokenRequestMock(httpClientMock, TestHelper.getSuccessfulTokenResponse(responseParameters), 200);
 
+        //refresh_in values are in seconds, so we must wait to guarantee it is past the proactive refresh time
+        TimeUnit.SECONDS.sleep(2);
+
         silentParameters = SilentParameters.builder(Collections.singleton("someScopes"), result.account()).build();
         result = cca.acquireTokenSilently(silentParameters).get();
 
-        assertRefreshedToken(result, "normalToken", CacheRefreshReason.EXPIRED, cca.tokenCache.accessTokens.size());
+        assertRefreshedToken(result, "normalToken", CacheRefreshReason.PROACTIVE_REFRESH, cca.tokenCache.accessTokens.size());
 
         //Force the token to be refreshed
         responseParameters.put("access_token", "forcedRefreshToken");

msal4j-sdk/src/test/java/com/microsoft/aad/msal4j/TestHelper.java

@@ -29,7 +29,7 @@ class TestHelper {
     static String signedAssertion = generateToken();
     private static final String successfulResponseFormat = "{\"access_token\":\"%s\",\"id_token\":\"%s\",\"refresh_token\":\"%s\"," +
             "\"client_id\":\"%s\",\"client_info\":\"%s\"," +
-            "\"expires_on\": %d ,\"expires_in\": %d," +
+            "\"refresh_in\": %d,\"expires_on\": %d,\"expires_in\": %d," +
             "\"token_type\":\"Bearer\"}";
 
     static final String idTokenFormat = "{\"aud\": \"%s\"," +
@@ -87,13 +87,17 @@ static String getSuccessfulTokenResponse(HashMap<String, String> responseValues)
         long expiresOn = responseValues.containsKey("expires_on")
                 ? Long.parseLong(responseValues.get("expires_0n")) :
                 (System.currentTimeMillis() / 1000) + expiresIn;
+        long refreshIn = responseValues.containsKey("refresh_in")
+                ? Long.parseLong(responseValues.get("refresh_in")) :
+                0;
 
         return String.format(successfulResponseFormat,
                 responseValues.getOrDefault("access_token", "access_token"),
                 responseValues.getOrDefault("id_token", ""),
                 responseValues.getOrDefault("refresh_token", "refresh_token"),
                 responseValues.getOrDefault("client_id", "client_id"),
                 responseValues.getOrDefault("client_info", "eyJ1aWQiOiI1OTdmODZjZC0xM2YzLTQ0YzAtYmVjZS1hMWU3N2JhNDMyMjgiLCJ1dGlkIjoiZjY0NWFkOTItZTM4ZC00ZDFhLWI1MTAtZDFiMDlhNzRhOGNhIn0"),
+                refreshIn,
                 expiresOn,
                 expiresIn
         );