[Identity] Success logging (Both in Interactive and in DeviceCode) (Azure#11807)

sadasant · web-flow · commit b8a7759d34f6 · 2020-11-09T22:35:12.000Z
This is a very small issue addressing Azure#11672. When I made Azure#11672 I conflated two different issues related to success logging of Identity credentials (at least definitely in my mind I did conflate these two). Since the fix to these issues is very small, in number of lines changed, I thought it would be ok to make a single pull request to address them both. In this pull request, I have: - Changed the success message of InteractiveBrowserCredential to `Authentication Complete. You can close the browser and return to the application.`. - Changed the success logging message of `DeviceCodeCredential` to be similar to: `DeviceCodeCredential succeeded. Scopes: {1} ExpiresOn: {3}`. - When I did this, I decided to change the other logging messages to make them consistent. **Important:** I decided to re-use the existing logging tools, so the messages are more like `ClientCertificateCredential => getToke() => SUCCESS. Scopes: {1}` If approved, Fixes Azure#11672 Feedback appreciated!
diff --git a/sdk/identity/identity/src/credentials/authorizationCodeCredential.browser.ts b/sdk/identity/identity/src/credentials/authorizationCodeCredential.browser.ts
@@ -27,12 +27,12 @@ export class AuthorizationCodeCredential implements TokenCredential {
     options?: TokenCredentialOptions
   );
   constructor() {
-    logger.info(formatError(BrowserNotSupportedError));
+    logger.info(formatError("", BrowserNotSupportedError));
     throw BrowserNotSupportedError;
   }
 
   public getToken(): Promise<AccessToken | null> {
-    logger.getToken.info(formatError(BrowserNotSupportedError));
+    logger.getToken.info(formatError("", BrowserNotSupportedError));
     throw BrowserNotSupportedError;
   }
 }
diff --git a/sdk/identity/identity/src/credentials/authorizationCodeCredential.ts b/sdk/identity/identity/src/credentials/authorizationCodeCredential.ts
@@ -197,7 +197,7 @@ export class AuthorizationCodeCredential implements TokenCredential {
         code,
         message: err.message
       });
-      logger.getToken.info(formatError(err));
+      logger.getToken.info(formatError(scopes, err));
       throw err;
     } finally {
       span.end();
diff --git a/sdk/identity/identity/src/credentials/azureCliCredential.browser.ts b/sdk/identity/identity/src/credentials/azureCliCredential.browser.ts
@@ -9,12 +9,12 @@ const logger = credentialLogger("AzureCliCredential");
 
 export class AzureCliCredential implements TokenCredential {
   constructor() {
-    logger.info(formatError(BrowserNotSupportedError));
+    logger.info(formatError("", BrowserNotSupportedError));
     throw BrowserNotSupportedError;
   }
 
   getToken(): Promise<AccessToken | null> {
-    logger.getToken.info(formatError(BrowserNotSupportedError));
+    logger.getToken.info(formatError("", BrowserNotSupportedError));
     throw BrowserNotSupportedError;
   }
 }
diff --git a/sdk/identity/identity/src/credentials/azureCliCredential.ts b/sdk/identity/identity/src/credentials/azureCliCredential.ts
@@ -75,7 +75,7 @@ export class AzureCliCredential implements TokenCredential {
       // Check to make sure the scope we get back is a valid scope
       if (!scope.match(/^[0-9a-zA-Z-.:/]+$/)) {
         const error = new Error("Invalid scope was specified by the user or calling client");
-        logger.getToken.info(formatError(error));
+        logger.getToken.info(formatError(scopes, error));
         throw error;
       }
 
@@ -93,17 +93,17 @@ export class AzureCliCredential implements TokenCredential {
               const error = new CredentialUnavailable(
                 "Azure CLI could not be found.  Please visit https://aka.ms/azure-cli for installation instructions and then, once installed, authenticate to your Azure account using 'az login'."
               );
-              logger.getToken.info(formatError(error));
+              logger.getToken.info(formatError(scopes, error));
               throw error;
             } else if (isLoginError) {
               const error = new CredentialUnavailable(
                 "Please run 'az login' from a command prompt to authenticate before using this credential."
               );
-              logger.getToken.info(formatError(error));
+              logger.getToken.info(formatError(scopes, error));
               throw error;
             }
             const error = new CredentialUnavailable(obj.stderr);
-            logger.getToken.info(formatError(error));
+            logger.getToken.info(formatError(scopes, error));
             throw error;
           } else {
             responseData = obj.stdout;
@@ -126,7 +126,7 @@ export class AzureCliCredential implements TokenCredential {
             code,
             message: err.message
           });
-          logger.getToken.info(formatError(err));
+          logger.getToken.info(formatError(scopes, err));
           reject(err);
         });
     });
diff --git a/sdk/identity/identity/src/credentials/chainedTokenCredential.ts b/sdk/identity/identity/src/credentials/chainedTokenCredential.ts
@@ -67,7 +67,7 @@ export class ChainedTokenCredential implements TokenCredential {
         if (err instanceof CredentialUnavailable) {
           errors.push(err);
         } else {
-          logger.getToken.info(formatError(err));
+          logger.getToken.info(formatError(scopes, err));
           throw err;
         }
       }
@@ -79,7 +79,7 @@ export class ChainedTokenCredential implements TokenCredential {
         code: CanonicalCode.UNAUTHENTICATED,
         message: err.message
       });
-      logger.getToken.info(formatError(err));
+      logger.getToken.info(formatError(scopes, err));
       throw err;
     }
 
diff --git a/sdk/identity/identity/src/credentials/clientCertificateCredential.browser.ts b/sdk/identity/identity/src/credentials/clientCertificateCredential.browser.ts
@@ -11,12 +11,12 @@ const logger = credentialLogger("ClientCertificateCredential");
 
 export class ClientCertificateCredential implements TokenCredential {
   constructor() {
-    logger.info(formatError(BrowserNotSupportedError));
+    logger.info(formatError("", BrowserNotSupportedError));
     throw BrowserNotSupportedError;
   }
 
   public getToken(): Promise<AccessToken | null> {
-    logger.getToken.info(formatError(BrowserNotSupportedError));
+    logger.getToken.info(formatError("", BrowserNotSupportedError));
     throw BrowserNotSupportedError;
   }
 }
diff --git a/sdk/identity/identity/src/credentials/clientCertificateCredential.ts b/sdk/identity/identity/src/credentials/clientCertificateCredential.ts
@@ -85,7 +85,7 @@ export class ClientCertificateCredential implements TokenCredential {
       const error = new Error(
         "The file at the specified path does not contain a PEM-encoded certificate."
       );
-      logger.info(formatError(error));
+      logger.info(formatError("", error));
       throw error;
     }
 
@@ -187,7 +187,7 @@ export class ClientCertificateCredential implements TokenCredential {
         code,
         message: err.message
       });
-      logger.getToken.info(formatError(err));
+      logger.getToken.info(formatError("", err));
       throw err;
     } finally {
       span.end();
diff --git a/sdk/identity/identity/src/credentials/clientSecretCredential.ts b/sdk/identity/identity/src/credentials/clientSecretCredential.ts
@@ -7,7 +7,7 @@ import { TokenCredentialOptions, IdentityClient } from "../client/identityClient
 import { createSpan } from "../util/tracing";
 import { AuthenticationErrorName } from "../client/errors";
 import { CanonicalCode } from "@opentelemetry/api";
-import { credentialLogger, formatSuccess } from "../util/logging";
+import { credentialLogger, formatError, formatSuccess } from "../util/logging";
 import { getIdentityTokenEndpointSuffix } from "../util/identityTokenEndpoint";
 
 const logger = credentialLogger("ClientSecretCredential");
@@ -97,7 +97,7 @@ export class ClientSecretCredential implements TokenCredential {
         code,
         message: err.message
       });
-      logger.getToken.info(err);
+      logger.getToken.info(formatError(scopes, err));
       throw err;
     } finally {
       span.end();
diff --git a/sdk/identity/identity/src/credentials/deviceCodeCredential.browser.ts b/sdk/identity/identity/src/credentials/deviceCodeCredential.browser.ts
@@ -9,12 +9,12 @@ const logger = credentialLogger("DeviceCodeCredential");
 
 export class DeviceCodeCredential implements TokenCredential {
   constructor() {
-    logger.info(formatError(BrowserNotSupportedError));
+    logger.info(formatError("", BrowserNotSupportedError));
     throw BrowserNotSupportedError;
   }
 
   public getToken(): Promise<AccessToken | null> {
-    logger.getToken.info(formatError(BrowserNotSupportedError));
+    logger.getToken.info(formatError("", BrowserNotSupportedError));
     throw BrowserNotSupportedError;
   }
 }
diff --git a/sdk/identity/identity/src/credentials/deviceCodeCredential.ts b/sdk/identity/identity/src/credentials/deviceCodeCredential.ts
@@ -113,7 +113,10 @@ export class DeviceCodeCredential implements TokenCredential {
    * @param options The options used to configure any requests this
    *                TokenCredential implementation might make.
    */
-  getToken(scopes: string | string[], options?: GetTokenOptions): Promise<AccessToken | null> {
+  async getToken(
+    scopes: string | string[],
+    options?: GetTokenOptions
+  ): Promise<AccessToken | null> {
     const { span } = createSpan("DeviceCodeCredential-getToken", options);
 
     const scopeArray = typeof scopes === "object" ? scopes : [scopes];
@@ -123,12 +126,14 @@ export class DeviceCodeCredential implements TokenCredential {
       scopes: scopeArray
     };
 
-    logger.info("Sending devicecode request");
+    logger.info(`DeviceCodeCredential invoked. Scopes: ${scopeArray.join(", ")}`);
 
-    return this.msalClient.acquireTokenFromCache(scopeArray).catch((e) => {
+    return this.msalClient.acquireTokenFromCache(scopeArray).catch(async (e) => {
       if (e instanceof AuthenticationRequired) {
         try {
-          return this.acquireTokenByDeviceCode(deviceCodeRequest, scopeArray);
+          const token = await this.acquireTokenByDeviceCode(deviceCodeRequest, scopeArray);
+          logger.getToken.info(formatSuccess(scopeArray));
+          return token;
         } catch (err) {
           const code =
             err.name === AuthenticationErrorName
@@ -138,7 +143,7 @@ export class DeviceCodeCredential implements TokenCredential {
             code,
             message: err.message
           });
-          logger.getToken.info(formatError(err));
+          logger.getToken.info(formatError(scopeArray, err));
           throw err;
         } finally {
           span.end();
@@ -155,9 +160,10 @@ export class DeviceCodeCredential implements TokenCredential {
   ): Promise<AccessToken | null> {
     try {
       const deviceResponse = await this.msalClient.acquireTokenByDeviceCode(deviceCodeRequest);
+      const expiresOnTimestamp = deviceResponse.expiresOn.getTime();
       logger.getToken.info(formatSuccess(scopes));
       return {
-        expiresOnTimestamp: deviceResponse.expiresOn.getTime(),
+        expiresOnTimestamp,
         token: deviceResponse.accessToken
       };
     } catch (error) {
diff --git a/sdk/identity/identity/src/credentials/environmentCredential.browser.ts b/sdk/identity/identity/src/credentials/environmentCredential.browser.ts
@@ -11,12 +11,12 @@ const logger = credentialLogger("EnvironmentCredential");
 
 export class EnvironmentCredential implements TokenCredential {
   constructor() {
-    logger.info(formatError(BrowserNotSupportedError));
+    logger.info(formatError("", BrowserNotSupportedError));
     throw BrowserNotSupportedError;
   }
 
   getToken(): Promise<AccessToken | null> {
-    logger.getToken.info(formatError(BrowserNotSupportedError));
+    logger.getToken.info(formatError("", BrowserNotSupportedError));
     throw BrowserNotSupportedError;
   }
 }
diff --git a/sdk/identity/identity/src/credentials/environmentCredential.ts b/sdk/identity/identity/src/credentials/environmentCredential.ts
@@ -144,7 +144,7 @@ export class EnvironmentCredential implements TokenCredential {
             .split("More details:")
             .join("")
         });
-        logger.getToken.info(formatError(authenticationError));
+        logger.getToken.info(formatError(scopes, authenticationError));
         throw authenticationError;
       } finally {
         span.end();
@@ -158,7 +158,7 @@ export class EnvironmentCredential implements TokenCredential {
     const error = new CredentialUnavailable(
       "EnvironmentCredential is unavailable. Environment variables are not fully configured."
     );
-    logger.getToken.info(formatError(error));
+    logger.getToken.info(formatError(scopes, error));
     throw error;
   }
 }
diff --git a/sdk/identity/identity/src/credentials/interactiveBrowserCredential.browser.ts b/sdk/identity/identity/src/credentials/interactiveBrowserCredential.browser.ts
@@ -48,7 +48,7 @@ export class InteractiveBrowserCredential implements TokenCredential {
     this.loginStyle = options.loginStyle || "popup";
     if (["redirect", "popup"].indexOf(this.loginStyle) === -1) {
       const error = new Error(`Invalid loginStyle: ${options.loginStyle}`);
-      logger.info(formatError(error));
+      logger.info(formatError("", error));
       throw error;
     }
 
@@ -102,7 +102,7 @@ export class InteractiveBrowserCredential implements TokenCredential {
             logger.info(`Authentication returned errorCode ${err.errorCode}`);
             break;
           default:
-            logger.info(formatError(`Failed to acquire token: ${err.message}`));
+            logger.info(formatError(authParams.scopes, `Failed to acquire token: ${err.message}`));
             throw err;
         }
       }
@@ -156,10 +156,11 @@ export class InteractiveBrowserCredential implements TokenCredential {
       });
 
       if (authResponse) {
+        const expiresOnTimestamp = authResponse.expiresOn.getTime();
         logger.getToken.info(formatSuccess(scopes));
         return {
           token: authResponse.accessToken,
-          expiresOnTimestamp: authResponse.expiresOn.getTime()
+          expiresOnTimestamp
         };
       } else {
         logger.getToken.info("No response");
@@ -170,7 +171,7 @@ export class InteractiveBrowserCredential implements TokenCredential {
         code: CanonicalCode.UNKNOWN,
         message: err.message
       });
-      logger.getToken.info(formatError(err));
+      logger.getToken.info(formatError(scopes, err));
       throw err;
     } finally {
       span.end();
diff --git a/sdk/identity/identity/src/credentials/interactiveBrowserCredential.ts b/sdk/identity/identity/src/credentials/interactiveBrowserCredential.ts
@@ -92,7 +92,7 @@ export class InteractiveBrowserCredential implements TokenCredential {
       if (e instanceof AuthenticationRequired) {
         return this.acquireTokenFromBrowser(scopeArray);
       } else {
-        logger.getToken.info(formatError(e));
+        logger.getToken.info(formatError(scopes, e));
         throw e;
       }
     });
@@ -136,23 +136,23 @@ export class InteractiveBrowserCredential implements TokenCredential {
 
         try {
           const authResponse = await this.msalClient.acquireTokenByCode(tokenRequest);
-          res.sendStatus(200);
-
+          const successMessage = `Authentication Complete. You can close the browser and return to the application.`;
+          const expiresOnTimestamp = authResponse?.expiresOn.valueOf();
+          res.status(200).send(successMessage);
           logger.getToken.info(formatSuccess(scopeArray));
 
           resolve({
-            expiresOnTimestamp: authResponse.expiresOn.valueOf(),
+            expiresOnTimestamp,
             token: authResponse.accessToken
           });
         } catch (error) {
-          res.status(500).send(error);
-
-          logger.getToken.info(formatError(error));
-          reject(
-            new Error(
-              `Authentication Error "${req.query["error"]}":\n\n${req.query["error_description"]}`
-            )
+          const errorMessage = formatError(
+            scopeArray,
+            `${req.query["error"]}. ${req.query["error_description"]}`
           );
+          res.status(500).send(errorMessage);
+          logger.getToken.info(errorMessage);
+          reject(new Error(errorMessage));
         } finally {
           cleanup();
         }
diff --git a/sdk/identity/identity/src/credentials/managedIdentityCredential/arcMsi.ts b/sdk/identity/identity/src/credentials/managedIdentityCredential/arcMsi.ts
@@ -60,7 +60,7 @@ async function filePathRequest(
   if (response.status !== 401) {
     let message = "";
     if (response.bodyAsText) {
-      message = ` Response: ${response.bodyAsText}`
+      message = ` Response: ${response.bodyAsText}`;
     }
     throw new AuthenticationError(
       response.status,
diff --git a/sdk/identity/identity/src/credentials/managedIdentityCredential/imdsMsi.ts b/sdk/identity/identity/src/credentials/managedIdentityCredential/imdsMsi.ts
@@ -4,7 +4,7 @@
 import { AccessToken, GetTokenOptions, RequestPrepareOptions, RestError } from "@azure/core-http";
 import { CanonicalCode } from "@opentelemetry/api";
 import { IdentityClient } from "../../client/identityClient";
-import { credentialLogger, formatError } from "../../util/logging";
+import { credentialLogger } from "../../util/logging";
 import { createSpan } from "../../util/tracing";
 import { imdsApiVersion, imdsEndpoint } from "./constants";
 import { MSI } from "./models";
@@ -108,9 +108,7 @@ export const imdsMsi: MSI = {
     } catch (err) {
       // createWebResource failed.
       // This error should bubble up to the user.
-      logger.info(
-        formatError(`Error when creating the WebResource for the IMDS endpoint: ${err.message}`)
-      );
+      logger.info(`Error when creating the WebResource for the IMDS endpoint: ${err.message}`);
       span.setStatus({
         code: CanonicalCode.UNKNOWN,
         message: err.message
diff --git a/sdk/identity/identity/src/credentials/managedIdentityCredential/index.browser.ts b/sdk/identity/identity/src/credentials/managedIdentityCredential/index.browser.ts
@@ -14,12 +14,12 @@ export class ManagedIdentityCredential implements TokenCredential {
   constructor(clientId: string, options?: TokenCredentialOptions);
   constructor(options?: TokenCredentialOptions);
   constructor() {
-    logger.info(formatError(BrowserNotSupportedError));
+    logger.info(formatError("", BrowserNotSupportedError));
     throw BrowserNotSupportedError;
   }
 
   public async getToken(): Promise<AccessToken | null> {
-    logger.getToken.info(formatError(BrowserNotSupportedError));
+    logger.getToken.info(formatError("", BrowserNotSupportedError));
     throw BrowserNotSupportedError;
   }
 }
diff --git a/sdk/identity/identity/src/credentials/managedIdentityCredential/index.ts b/sdk/identity/identity/src/credentials/managedIdentityCredential/index.ts
@@ -157,7 +157,7 @@ export class ManagedIdentityCredential implements TokenCredential {
           const error = new CredentialUnavailable(
             "The managed identity endpoint was reached, yet no tokens were received."
           );
-          logger.getToken.info(formatError(error));
+          logger.getToken.info(formatError(scopes, error));
           throw error;
         }
 
@@ -171,7 +171,7 @@ export class ManagedIdentityCredential implements TokenCredential {
         const error = new CredentialUnavailable(
           "The managed identity endpoint is not currently available"
         );
-        logger.getToken.info(formatError(error));
+        logger.getToken.info(formatError(scopes, error));
         throw error;
       }
 
@@ -200,7 +200,7 @@ export class ManagedIdentityCredential implements TokenCredential {
           "ManagedIdentityCredential is unavailable. No managed identity endpoint found."
         );
 
-        logger.getToken.info(formatError(error));
+        logger.getToken.info(formatError(scopes, error));
         throw error;
       }
 
diff --git a/sdk/identity/identity/src/credentials/usernamePasswordCredential.ts b/sdk/identity/identity/src/credentials/usernamePasswordCredential.ts
diff --git a/sdk/identity/identity/src/credentials/visualStudioCodeCredential.browser.ts b/sdk/identity/identity/src/credentials/visualStudioCodeCredential.browser.ts
diff --git a/sdk/identity/identity/src/credentials/visualStudioCodeCredential.ts b/sdk/identity/identity/src/credentials/visualStudioCodeCredential.ts
diff --git a/sdk/identity/identity/src/util/checkTenantId.ts b/sdk/identity/identity/src/util/checkTenantId.ts
diff --git a/sdk/identity/identity/src/util/logging.ts b/sdk/identity/identity/src/util/logging.ts
diff --git a/sdk/identity/identity/test/internal/logger.spec.ts b/sdk/identity/identity/test/internal/logger.spec.ts

Original file line number	Diff line number	Diff line change
`@@ -27,12 +27,12 @@ export class AuthorizationCodeCredential implements TokenCredential {`
`27`	`27`	`options?: TokenCredentialOptions`
`28`	`28`	`);`
`29`	`29`	`constructor() {`
`30`		`- logger.info(formatError(BrowserNotSupportedError));`
	`30`	`+ logger.info(formatError("", BrowserNotSupportedError));`
`31`	`31`	`throw BrowserNotSupportedError;`
`32`	`32`	`}`
`33`	`33`
`34`	`34`	`public getToken(): Promise<AccessToken \| null> {`
`35`		`- logger.getToken.info(formatError(BrowserNotSupportedError));`
	`35`	`+ logger.getToken.info(formatError("", BrowserNotSupportedError));`
`36`	`36`	`throw BrowserNotSupportedError;`
`37`	`37`	`}`
`38`	`38`	`}`
Original file line number	Diff line number	Diff line change
`@@ -9,12 +9,12 @@ const logger = credentialLogger("AzureCliCredential");`
`9`	`9`
`10`	`10`	`export class AzureCliCredential implements TokenCredential {`
`11`	`11`	`constructor() {`
`12`		`- logger.info(formatError(BrowserNotSupportedError));`
	`12`	`+ logger.info(formatError("", BrowserNotSupportedError));`
`13`	`13`	`throw BrowserNotSupportedError;`
`14`	`14`	`}`
`15`	`15`
`16`	`16`	`getToken(): Promise<AccessToken \| null> {`
`17`		`- logger.getToken.info(formatError(BrowserNotSupportedError));`
	`17`	`+ logger.getToken.info(formatError("", BrowserNotSupportedError));`
`18`	`18`	`throw BrowserNotSupportedError;`
`19`	`19`	`}`
`20`	`20`	`}`
Original file line number	Diff line number	Diff line change
`@@ -67,7 +67,7 @@ export class ChainedTokenCredential implements TokenCredential {`
`67`	`67`	`if (err instanceof CredentialUnavailable) {`
`68`	`68`	`errors.push(err);`
`69`	`69`	`} else {`
`70`		`- logger.getToken.info(formatError(err));`
	`70`	`+ logger.getToken.info(formatError(scopes, err));`
`71`	`71`	`throw err;`
`72`	`72`	`}`
`73`	`73`	`}`
`@@ -79,7 +79,7 @@ export class ChainedTokenCredential implements TokenCredential {`
`79`	`79`	`code: CanonicalCode.UNAUTHENTICATED,`
`80`	`80`	`message: err.message`
`81`	`81`	`});`
`82`		`- logger.getToken.info(formatError(err));`
	`82`	`+ logger.getToken.info(formatError(scopes, err));`
`83`	`83`	`throw err;`
`84`	`84`	`}`
`85`	`85`
Original file line number	Diff line number	Diff line change
`@@ -11,12 +11,12 @@ const logger = credentialLogger("ClientCertificateCredential");`
`11`	`11`
`12`	`12`	`export class ClientCertificateCredential implements TokenCredential {`
`13`	`13`	`constructor() {`
`14`		`- logger.info(formatError(BrowserNotSupportedError));`
	`14`	`+ logger.info(formatError("", BrowserNotSupportedError));`
`15`	`15`	`throw BrowserNotSupportedError;`
`16`	`16`	`}`
`17`	`17`
`18`	`18`	`public getToken(): Promise<AccessToken \| null> {`
`19`		`- logger.getToken.info(formatError(BrowserNotSupportedError));`
	`19`	`+ logger.getToken.info(formatError("", BrowserNotSupportedError));`
`20`	`20`	`throw BrowserNotSupportedError;`
`21`	`21`	`}`
`22`	`22`	`}`