Microsoft/vscode
1
0
Fork 0
mirror of https://github.com/microsoft/vscode.git synced 2026-05-01 22:12:26 +01:00
Code Issues Packages Projects Releases Wiki Activity

Logger per auth provider (#179896)

Browse Source 
So that we can have an output channel for each.
This commit is contained in:
Tyler James Leonhardt
2023-04-13 11:26:36 -07:00
committed by GitHub
parent c9071ead5e
commit b0d7acec38
2 changed files with 51 additions and 42 deletions
Download Patch File Download Diff File Expand all files Collapse all files

80
extensions/microsoft-authentication/src/AADHelper.ts
View File

@@ -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<string, string>();
constructor(
private readonly _logger: vscode.LogOutputChannel,
private readonly _context: vscode.ExtensionContext,
private readonly _uriHandler: UriEventHandler,
private readonly _tokenStorage: BetterTokenStorage<IStoredSession>,
@@ -98,12 +98,12 @@ export class AzureActiveDirectoryService {
}
public async initialize(): Promise<void> {
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<vscode.AuthenticationSession[]> {
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<vscode.AuthenticationSession | undefined> {
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<vscode.AuthenticationSession> {
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<IToken> {
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<vscode.AuthenticationSession> {
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<IStoredSession>): Promise<void> {
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);
}