Various fixes/improvements (#756)

Avery-Dunn · web-flow · commit 1d81ee5fcf84 · 2023-12-07T10:34:48.000-08:00
* Remove x-client-cpu header

* Improve behavior when futures time out

* Lower log level for silent success

* Improve error logging style
diff --git a/msal4j-sdk/src/main/java/com/microsoft/aad/msal4j/AccountsSupplier.java b/msal4j-sdk/src/main/java/com/microsoft/aad/msal4j/AccountsSupplier.java
@@ -26,9 +26,10 @@ public Set<IAccount> get() {
                     (clientApplication.clientId());
 
         } catch (Exception ex) {
-            clientApplication.log.error(
-                    LogHelper.createMessage("Execution of " + this.getClass() + " failed.",
-                            msalRequest.headers().getHeaderCorrelationIdValue()), ex);
+            clientApplication.log.warn(
+                    LogHelper.createMessage(
+                            String.format("Execution of %s failed: %s", this.getClass(), ex.getMessage()),
+                            msalRequest.headers().getHeaderCorrelationIdValue()));
 
             throw new CompletionException(ex);
         }
diff --git a/msal4j-sdk/src/main/java/com/microsoft/aad/msal4j/AcquireTokenByDeviceCodeFlowSupplier.java b/msal4j-sdk/src/main/java/com/microsoft/aad/msal4j/AcquireTokenByDeviceCodeFlowSupplier.java
@@ -53,7 +53,10 @@ private AuthenticationResult acquireTokenWithDeviceCode(DeviceCode deviceCode,
 
         while (getCurrentSystemTimeInSeconds() < expirationTimeInSeconds) {
             if (deviceCodeFlowRequest.futureReference().get().isCancelled()) {
-                throw new InterruptedException("Acquire token Device Code Flow was interrupted");
+                throw new InterruptedException("Device code flow was cancelled before acquiring a token");
+            }
+            if (deviceCodeFlowRequest.futureReference().get().isCompletedExceptionally()) {
+                throw new InterruptedException("Device code flow had an exception before acquiring a token");
             }
             try {
                 return acquireTokenByAuthorisationGrantSupplier.execute();
diff --git a/msal4j-sdk/src/main/java/com/microsoft/aad/msal4j/AcquireTokenByInteractiveFlowSupplier.java b/msal4j-sdk/src/main/java/com/microsoft/aad/msal4j/AcquireTokenByInteractiveFlowSupplier.java
@@ -209,7 +209,7 @@ private AuthorizationResult getAuthorizationResultFromHttpListener() {
                 expirationTime = TimeUnit.MILLISECONDS.toSeconds(System.currentTimeMillis()) + 1;
             }
 
-            while (result == null && !interactiveRequest.futureReference().get().isCancelled()) {
+            while (result == null && !interactiveRequest.futureReference().get().isDone()) {
                 if (TimeUnit.MILLISECONDS.toSeconds(System.currentTimeMillis()) > expirationTime) {
                     LOG.warn(String.format("Listener timed out after %S seconds, no authorization code was returned from the server during that time.", timeFromParameters));
                     break;
diff --git a/msal4j-sdk/src/main/java/com/microsoft/aad/msal4j/AcquireTokenSilentSupplier.java b/msal4j-sdk/src/main/java/com/microsoft/aad/msal4j/AcquireTokenSilentSupplier.java
@@ -109,7 +109,7 @@ AuthenticationResult execute() throws Exception {
             throw new MsalClientException(AuthenticationErrorMessage.NO_TOKEN_IN_CACHE, AuthenticationErrorCode.CACHE_MISS);
         }
 
-        log.info("Returning token from cache");
+        log.debug("Returning token from cache");
 
         return res;
     }
diff --git a/msal4j-sdk/src/main/java/com/microsoft/aad/msal4j/AuthenticationResultSupplier.java b/msal4j-sdk/src/main/java/com/microsoft/aad/msal4j/AuthenticationResultSupplier.java
@@ -95,7 +95,11 @@ public IAuthenticationResult get() {
                         msalRequest.requestContext().correlationId(),
                         error);
 
-                logException(ex);
+                clientApplication.log.warn(
+                        LogHelper.createMessage(
+                                String.format("Execution of %s failed: %s", this.getClass(), ex.getMessage()),
+                                msalRequest.headers().getHeaderCorrelationIdValue()));
+
                 throw new CompletionException(ex);
             }
         }
@@ -135,26 +139,6 @@ private void logResult(AuthenticationResult result, HttpHeaders headers) {
         }
     }
 
-    private void logException(Exception ex) {
-
-        String logMessage = LogHelper.createMessage(
-                "Execution of " + this.getClass() + " failed.",
-                msalRequest.headers().getHeaderCorrelationIdValue());
-
-        if (ex instanceof MsalClientException) {
-            MsalClientException exception = (MsalClientException) ex;
-            if (exception.errorCode() != null && exception.errorCode().equalsIgnoreCase(AuthenticationErrorCode.CACHE_MISS)) {
-                clientApplication.log.debug(logMessage, ex);
-                return;
-            }
-        } else if (ex instanceof MsalAzureSDKException) {
-            clientApplication.log.debug(ex.getMessage(), ex);
-            return;
-        }
-
-        clientApplication.log.error(logMessage, ex);
-    }
-
     private ApiEvent initializeApiEvent(MsalRequest msalRequest) {
         ApiEvent apiEvent = new ApiEvent(clientApplication.logPii());
         msalRequest.requestContext().telemetryRequestId(
diff --git a/msal4j-sdk/src/main/java/com/microsoft/aad/msal4j/HttpHeaders.java b/msal4j-sdk/src/main/java/com/microsoft/aad/msal4j/HttpHeaders.java
@@ -16,9 +16,6 @@ final class HttpHeaders {
     static final String PRODUCT_VERSION_HEADER_NAME = "x-client-VER";
     static final String PRODUCT_VERSION_HEADER_VALUE = getProductVersion();
 
-    static final String CPU_HEADER_NAME = "x-client-CPU";
-    static final String CPU_HEADER_VALUE = System.getProperty("os.arch");
-
     static final String OS_HEADER_NAME = "x-client-OS";
     static final String OS_HEADER_VALUE = System.getProperty("os.name");
 
@@ -78,7 +75,6 @@ private void initializeHeaders(Map<String, String> extraHttpHeaders) {
         init.accept(PRODUCT_HEADER_NAME, PRODUCT_HEADER_VALUE);
         init.accept(PRODUCT_VERSION_HEADER_NAME, PRODUCT_VERSION_HEADER_VALUE);
         init.accept(OS_HEADER_NAME, OS_HEADER_VALUE);
-        init.accept(CPU_HEADER_NAME, CPU_HEADER_VALUE);
         init.accept(REQUEST_CORRELATION_ID_IN_RESPONSE_HEADER_NAME, REQUEST_CORRELATION_ID_IN_RESPONSE_HEADER_VALUE);
         init.accept(CORRELATION_ID_HEADER_NAME, this.correlationIdHeaderValue);
 
diff --git a/msal4j-sdk/src/main/java/com/microsoft/aad/msal4j/LogHelper.java b/msal4j-sdk/src/main/java/com/microsoft/aad/msal4j/LogHelper.java
@@ -6,8 +6,7 @@
 final class LogHelper {
 
     static String createMessage(String originalMessage, String correlationId) {
-        return String.format("[Correlation ID: %s] " + originalMessage,
-                correlationId);
+        return String.format("[Correlation ID: %s] %s", correlationId, originalMessage);
     }
 
     static String getPiiScrubbedDetails(Throwable ex) {
diff --git a/msal4j-sdk/src/main/java/com/microsoft/aad/msal4j/RemoveAccountRunnable.java b/msal4j-sdk/src/main/java/com/microsoft/aad/msal4j/RemoveAccountRunnable.java
@@ -25,9 +25,10 @@ public void run() {
                     (clientApplication.clientId(), account);
 
         } catch (Exception ex) {
-            clientApplication.log.error(
-                    LogHelper.createMessage("Execution of " + this.getClass() + " failed.",
-                            requestContext.correlationId()), ex);
+            clientApplication.log.warn(
+                    LogHelper.createMessage(
+                            String.format("Execution of %s failed: %s", this.getClass(), ex.getMessage()),
+                            requestContext.correlationId()));
 
             throw new CompletionException(ex);
         }
diff --git a/msal4j-sdk/src/test/java/com/microsoft/aad/msal4j/HttpHeaderTest.java b/msal4j-sdk/src/test/java/com/microsoft/aad/msal4j/HttpHeaderTest.java
@@ -43,7 +43,6 @@ void testHttpHeaderConstructor() {
         assertEquals(httpHeaderMap.get(HttpHeaders.PRODUCT_HEADER_NAME), HttpHeaders.PRODUCT_HEADER_VALUE);
         assertEquals(httpHeaderMap.get(HttpHeaders.PRODUCT_VERSION_HEADER_NAME), HttpHeaders.PRODUCT_VERSION_HEADER_VALUE);
         assertEquals(httpHeaderMap.get(HttpHeaders.OS_HEADER_NAME), HttpHeaders.OS_HEADER_VALUE);
-        assertEquals(httpHeaderMap.get(HttpHeaders.CPU_HEADER_NAME), HttpHeaders.CPU_HEADER_VALUE);
         assertEquals(httpHeaderMap.get(HttpHeaders.APPLICATION_NAME_HEADER_NAME), "app-name");
         assertEquals(httpHeaderMap.get(HttpHeaders.APPLICATION_VERSION_HEADER_NAME), "app-version");
         assertEquals(httpHeaderMap.get(HttpHeaders.CORRELATION_ID_HEADER_NAME), "correlation-id");
@@ -70,7 +69,6 @@ void testHttpHeaderConstructor_valuesNotSet() {
         assertEquals(httpHeaderMap.get(HttpHeaders.PRODUCT_HEADER_NAME), HttpHeaders.PRODUCT_HEADER_VALUE);
         assertEquals(httpHeaderMap.get(HttpHeaders.PRODUCT_VERSION_HEADER_NAME), HttpHeaders.PRODUCT_VERSION_HEADER_VALUE);
         assertEquals(httpHeaderMap.get(HttpHeaders.OS_HEADER_NAME), HttpHeaders.OS_HEADER_VALUE);
-        assertEquals(httpHeaderMap.get(HttpHeaders.CPU_HEADER_NAME), HttpHeaders.CPU_HEADER_VALUE);
         assertNull(httpHeaderMap.get(HttpHeaders.APPLICATION_NAME_HEADER_NAME));
         assertNull(httpHeaderMap.get(HttpHeaders.APPLICATION_VERSION_HEADER_NAME));
         assertNotNull(httpHeaderMap.get(HttpHeaders.CORRELATION_ID_HEADER_NAME));
@@ -163,7 +161,6 @@ void testHttpHeaderConstructor_extraHttpHeadersOverwriteLibraryHeaders() {
         assertEquals(httpHeaderMap.get(HttpHeaders.PRODUCT_HEADER_NAME), HttpHeaders.PRODUCT_HEADER_VALUE);
         assertEquals(httpHeaderMap.get(HttpHeaders.PRODUCT_VERSION_HEADER_NAME), HttpHeaders.PRODUCT_VERSION_HEADER_VALUE);
         assertEquals(httpHeaderMap.get(HttpHeaders.OS_HEADER_NAME), HttpHeaders.OS_HEADER_VALUE);
-        assertEquals(httpHeaderMap.get(HttpHeaders.CPU_HEADER_NAME), HttpHeaders.CPU_HEADER_VALUE);
         assertEquals(httpHeaderMap.get(HttpHeaders.APPLICATION_VERSION_HEADER_NAME), "app-version");
         assertEquals(httpHeaderMap.get(HttpHeaders.CORRELATION_ID_HEADER_NAME), "correlation-id");
 

Original file line number	Diff line number	Diff line change
`@@ -209,7 +209,7 @@ private AuthorizationResult getAuthorizationResultFromHttpListener() {`
`209`	`209`	`expirationTime = TimeUnit.MILLISECONDS.toSeconds(System.currentTimeMillis()) + 1;`
`210`	`210`	`}`
`211`	`211`
`212`		`- while (result == null && !interactiveRequest.futureReference().get().isCancelled()) {`
	`212`	`+ while (result == null && !interactiveRequest.futureReference().get().isDone()) {`
`213`	`213`	`if (TimeUnit.MILLISECONDS.toSeconds(System.currentTimeMillis()) > expirationTime) {`
`214`	`214`	`LOG.warn(String.format("Listener timed out after %S seconds, no authorization code was returned from the server during that time.", timeFromParameters));`
`215`	`215`	`break;`
Original file line number	Diff line number	Diff line change
`@@ -109,7 +109,7 @@ AuthenticationResult execute() throws Exception {`
`109`	`109`	`throw new MsalClientException(AuthenticationErrorMessage.NO_TOKEN_IN_CACHE, AuthenticationErrorCode.CACHE_MISS);`
`110`	`110`	`}`
`111`	`111`
`112`		`- log.info("Returning token from cache");`
	`112`	`+ log.debug("Returning token from cache");`
`113`	`113`
`114`	`114`	`return res;`
`115`	`115`	`}`
Original file line number	Diff line number	Diff line change
`@@ -6,8 +6,7 @@`
`6`	`6`	`final class LogHelper {`
`7`	`7`
`8`	`8`	`static String createMessage(String originalMessage, String correlationId) {`
`9`		`- return String.format("[Correlation ID: %s] " + originalMessage,`
`10`		`- correlationId);`
	`9`	`+ return String.format("[Correlation ID: %s] %s", correlationId, originalMessage);`
`11`	`10`	`}`
`12`	`11`
`13`	`12`	`static String getPiiScrubbedDetails(Throwable ex) {`