From ccaf111696aac9c246b9ec4f969cb6a8d4f5b39e Mon Sep 17 00:00:00 2001 From: Charles Gagnon Date: Fri, 20 Aug 2021 13:23:36 -0700 Subject: [PATCH] Add more Azure account logging (#16847) * logging 1 * More logging * more logging * Handle each tenant separately. * cleanup --- .../src/account-provider/auths/azureAuth.ts | 13 ++-- .../account-provider/azureAccountProvider.ts | 1 + extensions/azurecore/src/utils/Logger.ts | 73 ++++++++++++++++++- .../browser/accountDialog.ts | 8 +- 4 files changed, 85 insertions(+), 10 deletions(-) diff --git a/extensions/azurecore/src/account-provider/auths/azureAuth.ts b/extensions/azurecore/src/account-provider/auths/azureAuth.ts index f19550129b..0287e101bb 100644 --- a/extensions/azurecore/src/account-provider/auths/azureAuth.ts +++ b/extensions/azurecore/src/account-provider/auths/azureAuth.ts @@ -231,6 +231,7 @@ export abstract class AzureAuth implements vscode.Disposable { * @param refreshToken */ public async refreshToken(tenant: Tenant, resource: Resource, refreshToken: RefreshToken | undefined): Promise { + Logger.pii('Refreshing token', [{ name: 'token', objOrArray: refreshToken }], []); if (refreshToken) { const postData: RefreshTokenPostData = { grant_type: 'refresh_token', @@ -333,7 +334,6 @@ export abstract class AzureAuth implements vscode.Disposable { const tenantUri = url.resolve(this.metadata.settings.armResource.endpoint, 'tenants?api-version=2019-11-01'); try { const tenantResponse = await this.makeGetRequest(tenantUri, token.token); - Logger.pii('getTenants', tenantResponse.data); const tenants: Tenant[] = tenantResponse.data.value.map((tenantInfo: TenantResponse) => { return { id: tenantInfo.tenantId, @@ -362,7 +362,7 @@ export abstract class AzureAuth implements vscode.Disposable { private async saveToken(tenant: Tenant, resource: Resource, accountKey: azdata.AccountKey, { accessToken, refreshToken, expiresOn }: OAuthTokenResponse) { const msg = localize('azure.cacheErrorAdd', "Error when adding your account to the cache."); if (!tenant.id || !resource.id) { - Logger.pii('Tenant ID or resource ID was undefined', tenant, resource); + Logger.pii('Tenant ID or resource ID was undefined', [], [], tenant, resource); throw new AzureAuthError(msg, 'Adding account to cache failed', undefined); } try { @@ -380,7 +380,7 @@ export abstract class AzureAuth implements vscode.Disposable { const parseMsg = localize('azure.cacheErrorParse', "Error when parsing your account from the cache"); if (!tenant.id || !resource.id) { - Logger.pii('Tenant ID or resource ID was undefined', tenant, resource); + Logger.pii('Tenant ID or resource ID was undefined', [], [], tenant, resource); throw new AzureAuthError(getMsg, 'Getting account from cache failed', undefined); } @@ -398,6 +398,7 @@ export abstract class AzureAuth implements vscode.Disposable { try { if (!accessTokenString) { + Logger.log('No access token found'); return undefined; } const accessToken: AccessToken = JSON.parse(accessTokenString); @@ -405,7 +406,7 @@ export abstract class AzureAuth implements vscode.Disposable { if (refreshTokenString) { refreshToken = JSON.parse(refreshTokenString); } - + Logger.pii('GetSavedToken ', [{ name: 'access', objOrArray: accessToken }, { name: 'refresh', objOrArray: refreshToken }], [], `expiresOn=${expiresOn}`); return { accessToken, refreshToken, expiresOn }; @@ -568,7 +569,7 @@ export abstract class AzureAuth implements vscode.Disposable { // Intercept response and print out the response for future debugging const response = await axios.post(url, qs.stringify(postData), config); - Logger.pii(url, postData, response.data); + Logger.pii('POST request ', [{ name: 'data', objOrArray: postData }, { name: 'response', objOrArray: response.data }], [], url); return response; } @@ -582,7 +583,7 @@ export abstract class AzureAuth implements vscode.Disposable { }; const response = await axios.get(url, config); - Logger.pii(url, response.data); + Logger.pii('GET request ', [{ name: 'response', objOrArray: response.data.value ?? response.data }], [], url,); return response; } diff --git a/extensions/azurecore/src/account-provider/azureAccountProvider.ts b/extensions/azurecore/src/account-provider/azureAccountProvider.ts index 66a17d3991..5bd38b9858 100644 --- a/extensions/azurecore/src/account-provider/azureAccountProvider.ts +++ b/extensions/azurecore/src/account-provider/azureAccountProvider.ts @@ -114,6 +114,7 @@ export class AzureAccountProvider implements azdata.AccountProvider, vscode.Disp private async _getAccountSecurityToken(account: AzureAccount, tenantId: string, resource: azdata.AzureResource): Promise { await this.initCompletePromise; const azureAuth = this.getAuthMethod(undefined); + Logger.pii(`Getting account security token for ${JSON.stringify(account.key)} (tenant ${tenantId}). Auth Method = ${azureAuth.userFriendlyName}`, [], []); return azureAuth?.getAccountSecurityToken(account, tenantId, resource); } diff --git a/extensions/azurecore/src/utils/Logger.ts b/extensions/azurecore/src/utils/Logger.ts index 37893bb677..08237c59fd 100644 --- a/extensions/azurecore/src/utils/Logger.ts +++ b/extensions/azurecore/src/utils/Logger.ts @@ -3,21 +3,39 @@ * Licensed under the Source EULA. See License.txt in the project root for license information. *--------------------------------------------------------------------------------------------*/ +import * as vscode from 'vscode'; +import * as loc from '../localizedConstants'; + export class Logger { + + public static channel: vscode.OutputChannel = vscode.window.createOutputChannel(loc.extensionName); + private static _piiLogging: boolean = false; static log(msg: any, ...vals: any[]) { const fullMessage = `${msg} - ${vals.map(v => JSON.stringify(v)).join(' - ')}`; - console.log(fullMessage); + this.channel.appendLine(fullMessage); } static error(msg: any, ...vals: any[]) { const fullMessage = `${msg} - ${vals.map(v => JSON.stringify(v)).join(' - ')}`; - console.error(fullMessage); + this.channel.appendLine(fullMessage); } - static pii(msg: any, ...vals: any[]) { + /** + * Logs a message containing PII (when enabled). Provides the ability to sanitize or shorten values to hide information or reduce the amount logged. + * @param msg The initial message to log + * @param objsToSanitize Set of objects we want to sanitize + * @param stringsToShorten Set of strings to shorten + * @param vals Any other values to add on to the end of the log message + */ + static pii(msg: any, objsToSanitize: { name: string, objOrArray: any | any[] }[], stringsToShorten: { name: string, value: string }[], ...vals: any[]) { if (this.piiLogging) { + msg = [ + msg, + ...objsToSanitize.map(obj => `${obj.name}=${sanitize(obj.objOrArray)}`), + ...stringsToShorten.map(str => `${str.name}=${shorten(str.value)}`) + ].join(' '); Logger.log(msg, vals); } } @@ -30,3 +48,52 @@ export class Logger { return this._piiLogging; } } + +/** + * Sanitizes a given object for logging to the output window, removing/shortening any PII or unneeded values + * @param objOrArray The object to sanitize for output logging + * @returns The stringified version of the sanitized object + */ +function sanitize(objOrArray: any): string { + if (Array.isArray(objOrArray)) { + return JSON.stringify(objOrArray.map(o => sanitizeImpl(o))); + } else { + return sanitizeImpl(objOrArray); + } +} + +function sanitizeImpl(obj: any): string { + obj = Object.assign({}, obj); + delete obj.domains; // very long and not really useful + // shorten all tokens since we don't usually need the exact values and there's security concerns if they leaked + shortenIfExists(obj, 'token'); + shortenIfExists(obj, 'refresh_token'); + shortenIfExists(obj, 'access_token'); + return JSON.stringify(obj); +} + +/** + * Shortens the given string property on an object if it exists, otherwise does nothing + * @param obj The object possibly containing the property + * @param property The name of the property to shorten - if it exists + */ +function shortenIfExists(obj: any, property: string): void { + if (obj[property]) { + obj[property] = shorten(obj[property]); + } +} + +/** + * Shortens a given string - if it's longer than 6 characters will return the first 3 characters + * followed by a ... followed by the last 3 characters. Returns the original string if 6 characters + * or less. + * @param str The string to shorten + * @returns Shortened string in the form 'xxx...xxx' + */ +function shorten(str?: string): string | undefined { + // Don't shorten if adding the ... wouldn't make the string shorter + if (!str || str.length < 10) { + return str; + } + return `${str.substr(0, 3)}...${str.slice(-3)}`; +} diff --git a/src/sql/workbench/services/accountManagement/browser/accountDialog.ts b/src/sql/workbench/services/accountManagement/browser/accountDialog.ts index 6fba302da7..2d510e9bea 100644 --- a/src/sql/workbench/services/accountManagement/browser/accountDialog.ts +++ b/src/sql/workbench/services/accountManagement/browser/accountDialog.ts @@ -305,8 +305,10 @@ export class AccountDialog extends Modal { // PRIVATE HELPERS ///////////////////////////////////////////////////// private addProvider(newProvider: AccountProviderAddedEventParams) { + this.logService.debug(`Adding new provider ${newProvider.addedProvider.id}`); // Skip adding the provider if it already exists if (this._providerViewsMap.get(newProvider.addedProvider.id)) { + this.logService.debug(`Provider ${newProvider.addedProvider.id} is already registered!`); return; } @@ -364,14 +366,17 @@ export class AccountDialog extends Modal { this.layout(); + this.logService.debug(`Storing view for provider ${newProvider.addedProvider.id}`); // Store the view for the provider and action this._providerViewsMap.set(newProvider.addedProvider.id, { view: providerView, addAccountAction: addAccountAction }); } private removeProvider(removedProvider: azdata.AccountProviderMetadata) { + this.logService.debug(`Removing provider ${removedProvider.id}`); // Skip removing the provider if it doesn't exist const providerView = this._providerViewsMap.get(removedProvider.id); if (!providerView || !providerView.view) { + this.logService.warn(`Provider ${removedProvider.id} doesn't exist while removing`); return; } @@ -381,6 +386,7 @@ export class AccountDialog extends Modal { // Remove the list view from our internal map this._providerViewsMap.delete(removedProvider.id); + this.logService.debug(`Provider ${removedProvider.id} removed`); this.layout(); } @@ -427,8 +433,8 @@ export class AccountDialog extends Modal { } private async runAddAccountAction() { + this.logService.debug(`Adding account - providers ${JSON.stringify(Iterable.consume(this._providerViewsMap.keys()))}`); const vals = Iterable.consume(this._providerViewsMap.values())[0]; - let pickedValue: string | undefined; if (vals.length === 0) { this._notificationService.error(localize('accountDialog.noCloudsRegistered', "You have no clouds enabled. Go to Settings -> Search Azure Account Configuration -> Enable at least one cloud"));