diff --git a/extensions/microsoft-authentication/src/AADHelper.ts b/extensions/microsoft-authentication/src/AADHelper.ts index d06c9e3d97b..18a7e5d07ac 100644 --- a/extensions/microsoft-authentication/src/AADHelper.ts +++ b/extensions/microsoft-authentication/src/AADHelper.ts @@ -6,7 +6,6 @@ import * as vscode from 'vscode'; import * as querystring from 'querystring'; import * as path from 'path'; -import Logger from './logger'; import { isSupportedEnvironment } from './utils'; import { generateCodeChallenge, generateCodeVerifier, randomUUID } from './cryptoUtils'; import { BetterTokenStorage, IDidChangeInOtherWindowEvent } from './betterSecretStorage'; @@ -89,6 +88,7 @@ export class AzureActiveDirectoryService { private _codeVerfifiers = new Map(); constructor( + private readonly _logger: vscode.LogOutputChannel, private readonly _context: vscode.ExtensionContext, private readonly _uriHandler: UriEventHandler, private readonly _tokenStorage: BetterTokenStorage, @@ -98,12 +98,12 @@ export class AzureActiveDirectoryService { } public async initialize(): Promise { - Logger.info('Reading sessions from secret storage...'); + this._logger.info('Reading sessions from secret storage...'); const sessions = await this._tokenStorage.getAll(item => this.sessionMatchesEndpoint(item)); - Logger.info(`Got ${sessions.length} stored sessions`); + this._logger.info(`Got ${sessions.length} stored sessions`); const refreshes = sessions.map(async session => { - Logger.trace(`Read the following stored session with scopes: ${session.scope}`); + this._logger.trace(`Read the following stored session with scopes: ${session.scope}`); const scopes = session.scope.split(' '); const scopeData: IScopeData = { scopes, @@ -130,7 +130,7 @@ export class AzureActiveDirectoryService { }); } else { vscode.window.showErrorMessage(vscode.l10n.t('You have been signed out because reading stored authentication information failed.')); - Logger.error(e); + this._logger.error(e); await this.removeSessionByIToken({ accessToken: undefined, refreshToken: session.refreshToken, @@ -148,7 +148,7 @@ export class AzureActiveDirectoryService { const result = await Promise.allSettled(refreshes); for (const res of result) { if (res.status === 'rejected') { - Logger.error(`Failed to initialize stored data: ${res.reason}`); + this._logger.error(`Failed to initialize stored data: ${res.reason}`); this.clearSessions(); } } @@ -162,9 +162,9 @@ export class AzureActiveDirectoryService { async getSessions(scopes?: string[]): Promise { if (!scopes) { - Logger.info('Getting sessions for all scopes...'); + this._logger.info('Getting sessions for all scopes...'); const sessions = this._tokens.map(token => this.convertToSessionSync(token)); - Logger.info(`Got ${sessions.length} sessions for all scopes...`); + this._logger.info(`Got ${sessions.length} sessions for all scopes...`); return sessions; } @@ -184,10 +184,10 @@ export class AzureActiveDirectoryService { modifiedScopes = modifiedScopes.sort(); let modifiedScopesStr = modifiedScopes.join(' '); - Logger.info(`Getting sessions for the following scopes: ${modifiedScopesStr}`); + this._logger.info(`Getting sessions for the following scopes: ${modifiedScopesStr}`); if (this._refreshingPromise) { - Logger.info('Refreshing in progress. Waiting for completion before continuing.'); + this._logger.info('Refreshing in progress. Waiting for completion before continuing.'); try { await this._refreshingPromise; } catch (e) { @@ -202,7 +202,7 @@ export class AzureActiveDirectoryService { // without an idtoken. if (!matchingTokens.length) { const fallbackOrderedScopes = scopes.sort().join(' '); - Logger.trace(`No session found with idtoken scopes... Using fallback scope list of: ${fallbackOrderedScopes}`); + this._logger.trace(`No session found with idtoken scopes... Using fallback scope list of: ${fallbackOrderedScopes}`); matchingTokens = this._tokens.filter(token => token.scope === fallbackOrderedScopes); if (matchingTokens.length) { modifiedScopesStr = fallbackOrderedScopes; @@ -235,12 +235,12 @@ export class AzureActiveDirectoryService { const itoken = await this.refreshToken(token.refreshToken, scopeData); matchingTokens.push(itoken); } catch (err) { - Logger.error(`Attempted to get a new session for scopes '${scopeData.scopeStr}' using the existing session with scopes '${token.scope}' but it failed due to: ${err.message ?? err}`); + this._logger.error(`Attempted to get a new session for scopes '${scopeData.scopeStr}' using the existing session with scopes '${token.scope}' but it failed due to: ${err.message ?? err}`); } } } - Logger.info(`Got ${matchingTokens.length} sessions for scopes: ${modifiedScopesStr}`); + this._logger.info(`Got ${matchingTokens.length} sessions for scopes: ${modifiedScopesStr}`); return Promise.all(matchingTokens.map(token => this.convertToSession(token, scopeData))); } @@ -269,7 +269,7 @@ export class AzureActiveDirectoryService { tenant: this.getTenantId(scopes), }; - Logger.info(`Logging in for the following scopes: ${scopeData.scopeStr}`); + this._logger.info(`Logging in for the following scopes: ${scopeData.scopeStr}`); const runsRemote = vscode.env.remoteName !== undefined; const runsServerless = vscode.env.remoteName === undefined && vscode.env.uiKind === vscode.UIKind.Web; @@ -287,7 +287,7 @@ export class AzureActiveDirectoryService { this._sessionChangeEmitter.fire({ added: [session], removed: [], changed: [] }); return session; } catch (e) { - Logger.error(`Error creating session for scopes: ${scopeData.scopeStr} Error: ${e}`); + this._logger.error(`Error creating session for scopes: ${scopeData.scopeStr} Error: ${e}`); // If the error was about starting the server, try directly hitting the login endpoint instead if (e.message === 'Error listening to server' || e.message === 'Closed' || e.message === 'Timeout waiting for port') { @@ -392,10 +392,10 @@ export class AzureActiveDirectoryService { } public async removeSessionById(sessionId: string, writeToDisk: boolean = true): Promise { - Logger.info(`Logging out of session '${sessionId}'`); + this._logger.info(`Logging out of session '${sessionId}'`); const tokenIndex = this._tokens.findIndex(token => token.sessionId === sessionId); if (tokenIndex === -1) { - Logger.info(`Session not found '${sessionId}'`); + this._logger.info(`Session not found '${sessionId}'`); return Promise.resolve(undefined); } @@ -410,7 +410,7 @@ export class AzureActiveDirectoryService { } public async clearSessions() { - Logger.info('Logging out of all sessions'); + this._logger.info('Logging out of all sessions'); this._tokens = []; await this._tokenStorage.deleteAll(item => this.sessionMatchesEndpoint(item)); @@ -434,9 +434,9 @@ export class AzureActiveDirectoryService { } const session = this.convertToSessionSync(token); - Logger.info(`Sending change event for session that was removed with scopes: ${token.scope}`); + this._logger.info(`Sending change event for session that was removed with scopes: ${token.scope}`); this._sessionChangeEmitter.fire({ added: [], removed: [session], changed: [] }); - Logger.info(`Logged out of session '${token.sessionId}' with scopes: ${token.scope}`); + this._logger.info(`Logged out of session '${token.sessionId}' with scopes: ${token.scope}`); return session; } @@ -449,7 +449,7 @@ export class AzureActiveDirectoryService { this._refreshTimeouts.set(sessionId, setTimeout(async () => { try { const refreshedToken = await this.refreshToken(refreshToken, scopeData, sessionId); - Logger.info('Triggering change session event...'); + this._logger.info('Triggering change session event...'); this._sessionChangeEmitter.fire({ added: [], removed: [], changed: [this.convertToSessionSync(refreshedToken)] }); } catch (e) { if (e.message !== REFRESH_NETWORK_FAILURE) { @@ -479,7 +479,7 @@ export class AzureActiveDirectoryService { if (json.id_token) { claims = JSON.parse(base64Decode(json.id_token.split('.')[1])); } else { - Logger.info('Attempting to parse access_token instead since no id_token was included in the response.'); + this._logger.info('Attempting to parse access_token instead since no id_token was included in the response.'); claims = JSON.parse(base64Decode(json.access_token.split('.')[1])); } } catch (e) { @@ -526,8 +526,8 @@ export class AzureActiveDirectoryService { private async convertToSession(token: IToken, scopeData: IScopeData): Promise { if (token.accessToken && (!token.expiresAt || token.expiresAt > Date.now())) { token.expiresAt - ? Logger.info(`Token available from cache (for scopes ${token.scope}), expires in ${token.expiresAt - Date.now()} milliseconds`) - : Logger.info('Token available from cache (for scopes ${token.scope})'); + ? this._logger.info(`Token available from cache (for scopes ${token.scope}), expires in ${token.expiresAt - Date.now()} milliseconds`) + : this._logger.info('Token available from cache (for scopes ${token.scope})'); return { id: token.sessionId, accessToken: token.accessToken, @@ -538,7 +538,7 @@ export class AzureActiveDirectoryService { } try { - Logger.info(`Token expired or unavailable (for scopes ${token.scope}), trying refresh`); + this._logger.info(`Token expired or unavailable (for scopes ${token.scope}), trying refresh`); const refreshedToken = await this.refreshToken(token.refreshToken, scopeData, token.sessionId); if (refreshedToken.accessToken) { return { @@ -572,7 +572,7 @@ export class AzureActiveDirectoryService { } private async doRefreshToken(refreshToken: string, scopeData: IScopeData, sessionId?: string): Promise { - Logger.info(`Refreshing token for scopes: ${scopeData.scopeStr}`); + this._logger.info(`Refreshing token for scopes: ${scopeData.scopeStr}`); const postData = querystring.stringify({ refresh_token: refreshToken, client_id: scopeData.clientId, @@ -591,7 +591,7 @@ export class AzureActiveDirectoryService { this.setSessionTimeout(token.sessionId, token.refreshToken, scopeData, token.expiresIn * AzureActiveDirectoryService.REFRESH_TIMEOUT_MODIFIER); } this.setToken(token, scopeData); - Logger.info(`Token refresh success for scopes: ${token.scope}`); + this._logger.info(`Token refresh success for scopes: ${token.scope}`); return token; } catch (e) { if (e.message === REFRESH_NETWORK_FAILURE) { @@ -602,7 +602,7 @@ export class AzureActiveDirectoryService { } throw e; } - Logger.error(`Refreshing token failed (for scopes: ${scopeData.scopeStr}): ${e.message}`); + this._logger.error(`Refreshing token failed (for scopes: ${scopeData.scopeStr}): ${e.message}`); throw e; } } @@ -704,7 +704,7 @@ export class AzureActiveDirectoryService { } private async exchangeCodeForSession(code: string, codeVerifier: string, scopeData: IScopeData): Promise { - Logger.info(`Exchanging login code for token for scopes: ${scopeData.scopeStr}`); + this._logger.info(`Exchanging login code for token for scopes: ${scopeData.scopeStr}`); let token: IToken | undefined; try { const postData = querystring.stringify({ @@ -729,10 +729,10 @@ export class AzureActiveDirectoryService { const endpoint = `${endpointUrl}${scopeData.tenant}/oauth2/v2.0/token`; const json = await this.fetchTokenResponse(endpoint, postData, scopeData); - Logger.info(`Exchanging login code for token (for scopes: ${scopeData.scopeStr}) succeeded!`); + this._logger.info(`Exchanging login code for token (for scopes: ${scopeData.scopeStr}) succeeded!`); token = this.convertToTokenSync(json, scopeData); } catch (e) { - Logger.error(`Error exchanging code for token (for scopes ${scopeData.scopeStr}): ${e}`); + this._logger.error(`Error exchanging code for token (for scopes ${scopeData.scopeStr}): ${e}`); throw e; } @@ -740,7 +740,7 @@ export class AzureActiveDirectoryService { this.setSessionTimeout(token.sessionId, token.refreshToken, scopeData, token.expiresIn * AzureActiveDirectoryService.REFRESH_TIMEOUT_MODIFIER); } this.setToken(token, scopeData); - Logger.info(`Login successful for scopes: ${scopeData.scopeStr}`); + this._logger.info(`Login successful for scopes: ${scopeData.scopeStr}`); return await this.convertToSession(token, scopeData); } @@ -765,7 +765,7 @@ export class AzureActiveDirectoryService { if (!result || result.status > 499) { if (attempts > 3) { - Logger.error(`Fetching token failed for scopes (${scopeData.scopeStr}): ${result ? await result.text() : errorMessage}`); + this._logger.error(`Fetching token failed for scopes (${scopeData.scopeStr}): ${result ? await result.text() : errorMessage}`); break; } // Exponential backoff @@ -789,7 +789,7 @@ export class AzureActiveDirectoryService { //#region storage operations private setToken(token: IToken, scopeData: IScopeData): void { - Logger.info(`Setting token for scopes: ${scopeData.scopeStr}`); + this._logger.info(`Setting token for scopes: ${scopeData.scopeStr}`); const existingTokenIndex = this._tokens.findIndex(t => t.sessionId === token.sessionId); if (existingTokenIndex > -1) { @@ -831,7 +831,7 @@ export class AzureActiveDirectoryService { }); if (!shouldStore) { - Logger.info(`Not storing token for scopes ${scopeData.scopeStr} because it was added in another window`); + this._logger.info(`Not storing token for scopes ${scopeData.scopeStr} because it was added in another window`); return; } } @@ -843,14 +843,14 @@ export class AzureActiveDirectoryService { account: token.account, endpoint: this._loginEndpointUrl, }); - Logger.info(`Stored token for scopes: ${scopeData.scopeStr}`); + this._logger.info(`Stored token for scopes: ${scopeData.scopeStr}`); } private async checkForUpdates(e: IDidChangeInOtherWindowEvent): Promise { for (const key of e.added) { const session = await this._tokenStorage.get(key); if (!session) { - Logger.error('session not found that was apparently just added'); + this._logger.error('session not found that was apparently just added'); return; } @@ -871,9 +871,9 @@ export class AzureActiveDirectoryService { clientId: this.getClientId(scopes), tenant: this.getTenantId(scopes), }; - Logger.info(`Session added in another window with scopes: ${session.scope}`); + this._logger.info(`Session added in another window with scopes: ${session.scope}`); const token = await this.refreshToken(session.refreshToken, scopeData, session.id); - Logger.info(`Sending change event for session that was added with scopes: ${scopeData.scopeStr}`); + this._logger.info(`Sending change event for session that was added with scopes: ${scopeData.scopeStr}`); this._sessionChangeEmitter.fire({ added: [this.convertToSessionSync(token)], removed: [], changed: [] }); return; } catch (e) { @@ -893,7 +893,7 @@ export class AzureActiveDirectoryService { continue; } - Logger.info(`Session removed in another window with scopes: ${value.scope}`); + this._logger.info(`Session removed in another window with scopes: ${value.scope}`); await this.removeSessionById(value.id, false); } diff --git a/extensions/microsoft-authentication/src/extension.ts b/extensions/microsoft-authentication/src/extension.ts index 9858785b5cf..96265e9ffd8 100644 --- a/extensions/microsoft-authentication/src/extension.ts +++ b/extensions/microsoft-authentication/src/extension.ts @@ -36,7 +36,12 @@ async function initAzureCloudAuthProvider(context: vscode.ExtensionContext, tele settingValue += '/'; } - const azureEnterpriseAuthProvider = new AzureActiveDirectoryService(context, uriHandler, tokenStorage, settingValue); + const azureEnterpriseAuthProvider = new AzureActiveDirectoryService( + vscode.window.createOutputChannel(vscode.l10n.t('Microsoft Sovereign Cloud Authentication'), { log: true }), + context, + uriHandler, + tokenStorage, + settingValue); await azureEnterpriseAuthProvider.initialize(); authProviderName ||= uri.authority; @@ -98,7 +103,11 @@ export async function activate(context: vscode.ExtensionContext) { const betterSecretStorage = new BetterTokenStorage('microsoft.login.keylist', context); - const loginService = new AzureActiveDirectoryService(context, uriHandler, betterSecretStorage); + const loginService = new AzureActiveDirectoryService( + vscode.window.createOutputChannel(vscode.l10n.t('Microsoft Authentication'), { log: true }), + context, + uriHandler, + betterSecretStorage); await loginService.initialize(); context.subscriptions.push(vscode.authentication.registerAuthenticationProvider('microsoft', 'Microsoft', {