remove keytar fallback in keychain and add a ton more logging to microsoft auth. ref #133201

extensions/github-authentication/src/common/keychain.ts

@@ -5,29 +5,12 @@
 
 // keytar depends on a native module shipped in vscode, so this is
 // how we load it
-import type * as keytarType from 'keytar';
 import * as vscode from 'vscode';
 import * as nls from 'vscode-nls';
 import { Log } from './logger';
 
 const localize = nls.loadMessageBundle();
 
-function getKeytar(): Keytar | undefined {
-	try {
-		return require('keytar');
-	} catch (err) {
-		console.log(err);
-	}
-
-	return undefined;
-}
-
-export type Keytar = {
-	getPassword: typeof keytarType['getPassword'];
-	setPassword: typeof keytarType['setPassword'];
-	deletePassword: typeof keytarType['deletePassword'];
-};
-
 export class Keychain {
 	constructor(
 		private readonly context: vscode.ExtensionContext,
@@ -72,25 +55,4 @@ export class Keychain {
 			return Promise.resolve(undefined);
 		}
 	}
-
-	async tryMigrate(): Promise<string | null | undefined> {
-		try {
-			const keytar = getKeytar();
-			if (!keytar) {
-				throw new Error('keytar unavailable');
-			}
-
-			const oldValue = await keytar.getPassword(`${vscode.env.uriScheme}-github.login`, 'account');
-			if (oldValue) {
-				this.Logger.trace('Attempting to migrate from keytar to secret store...');
-				await this.setToken(oldValue);
-				await keytar.deletePassword(`${vscode.env.uriScheme}-github.login`, 'account');
-			}
-
-			return oldValue;
-		} catch (_) {
-			// Ignore
-			return Promise.resolve(undefined);
-		}
-	}
 }

extensions/github-authentication/src/github.ts

@@ -117,7 +117,7 @@ export class GitHubAuthenticationProvider implements vscode.AuthenticationProvid
 		let sessionData: SessionData[];
 		try {
 			this._logger.info('Reading sessions from keychain...');
-			const storedSessions = await this._keychain.getToken() || await this._keychain.tryMigrate();
+			const storedSessions = await this._keychain.getToken();
 			if (!storedSessions) {
 				return [];
 			}

extensions/microsoft-authentication/src/AADHelper.ts

@@ -100,7 +100,7 @@ export class AzureActiveDirectoryService {
 	private _tokens: IToken[] = [];
 	private _refreshTimeouts: Map<string, NodeJS.Timeout> = new Map<string, NodeJS.Timeout>();
 	private _uriHandler: UriEventHandler;
-	private _disposables: vscode.Disposable[] = [];
+	private _disposable: vscode.Disposable;
 
 	// Used to keep track of current requests when not using the local server approach.
 	private _pendingStates = new Map<string, string[]>();
@@ -112,51 +112,59 @@ export class AzureActiveDirectoryService {
 	constructor(private _context: vscode.ExtensionContext) {
 		this._keychain = new Keychain(_context);
 		this._uriHandler = new UriEventHandler();
-		this._disposables.push(vscode.window.registerUriHandler(this._uriHandler));
+		this._disposable = vscode.Disposable.from(
+			vscode.window.registerUriHandler(this._uriHandler),
+			this._context.secrets.onDidChange(() => this.checkForUpdates()));
 	}
 
 	public async initialize(): Promise<void> {
-		const storedData = await this._keychain.getToken() || await this._keychain.tryMigrate();
-		if (storedData) {
-			try {
-				const sessions = this.parseStoredData(storedData);
-				const refreshes = sessions.map(async session => {
-					if (!session.refreshToken) {
-						return Promise.resolve();
-					}
+		Logger.info('Reading sessions from keychain...');
+		const storedData = await this._keychain.getToken();
+		if (!storedData) {
+			Logger.info('No stored sessions found.');
+			return;
+		}
+		Logger.info('Got stored sessions!');
 
-					try {
-						await this.refreshToken(session.refreshToken, session.scope, session.id);
-					} catch (e) {
-						if (e.message === REFRESH_NETWORK_FAILURE) {
-							const didSucceedOnRetry = await this.handleRefreshNetworkError(session.id, session.refreshToken, session.scope);
-							if (!didSucceedOnRetry) {
-								this._tokens.push({
-									accessToken: undefined,
-									refreshToken: session.refreshToken,
-									account: {
-										label: session.account.label ?? session.account.displayName!,
-										id: session.account.id
-									},
-									scope: session.scope,
-									sessionId: session.id
-								});
-								this.pollForReconnect(session.id, session.refreshToken, session.scope);
-							}
-						} else {
-							await this.removeSession(session.id);
+		try {
+			const sessions = this.parseStoredData(storedData);
+			const refreshes = sessions.map(async session => {
+				Logger.trace(`Read the following session from the keychain with the following scopes: ${session.scope}`);
+				if (!session.refreshToken) {
+					Logger.trace(`Session with the following scopes does not have a refresh token so we will not try to refresh it: ${session.scope}`);
+					return Promise.resolve();
+				}
+
+				try {
+					await this.refreshToken(session.refreshToken, session.scope, session.id);
+				} catch (e) {
+					// If we aren't connected to the internet, then wait and try to refresh again later.
+					if (e.message === REFRESH_NETWORK_FAILURE) {
+						const didSucceedOnRetry = await this.handleRefreshNetworkError(session.id, session.refreshToken, session.scope);
+						if (!didSucceedOnRetry) {
+							this._tokens.push({
+								accessToken: undefined,
+								refreshToken: session.refreshToken,
+								account: {
+									label: session.account.label ?? session.account.displayName!,
+									id: session.account.id
+								},
+								scope: session.scope,
+								sessionId: session.id
+							});
+							this.pollForReconnect(session.id, session.refreshToken, session.scope);
 						}
+					} else {
+						await this.removeSession(session.id);
 					}
-				});
+				}
+			});
 
-				await Promise.all(refreshes);
-			} catch (e) {
-				Logger.info('Failed to initialize stored data');
-				await this.clearSessions();
-			}
+			await Promise.all(refreshes);
+		} catch (e) {
+			Logger.error(`Failed to initialize stored data: ${e}`);
+			await this.clearSessions();
 		}
-
-		this._disposables.push(this._context.secrets.onDidChange(() => this.checkForUpdates));
 	}
 
 	private parseStoredData(data: string): IStoredSession[] {
@@ -263,8 +271,8 @@ export class AzureActiveDirectoryService {
 	private async resolveAccessAndIdTokens(token: IToken): Promise<IMicrosoftTokens> {
 		if (token.accessToken && (!token.expiresAt || token.expiresAt > Date.now())) {
 			token.expiresAt
-				? Logger.info(`Token available from cache, expires in ${token.expiresAt - Date.now()} milliseconds`)
-				: Logger.info('Token available from cache');
+				? 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})');
 			return Promise.resolve({
 				accessToken: token.accessToken,
 				idToken: token.idToken
@@ -272,7 +280,7 @@ export class AzureActiveDirectoryService {
 		}
 
 		try {
-			Logger.info('Token expired or unavailable, trying refresh');
+			Logger.info(`Token expired or unavailable (for scopes ${token.scope}), trying refresh`);
 			const refreshedToken = await this.refreshToken(token.refreshToken, token.scope, token.sessionId);
 			if (refreshedToken.accessToken) {
 				return {
@@ -301,17 +309,21 @@ export class AzureActiveDirectoryService {
 	}
 
 	async getSessions(scopes?: string[]): Promise<vscode.AuthenticationSession[]> {
+		Logger.info(`Getting sessions for ${scopes?.join(',') ?? 'all scopes'}...`);
 		if (!scopes) {
-			return this.sessions;
+			const sessions = await this.sessions;
+			Logger.info(`Got ${sessions.length} sessions for all scopes...`);
+			return sessions;
 		}
 
 		const orderedScopes = scopes.sort().join(' ');
 		const matchingTokens = this._tokens.filter(token => token.scope === orderedScopes);
+		Logger.info(`Got ${matchingTokens.length} sessions for ${scopes?.join(',')}...`);
 		return Promise.all(matchingTokens.map(token => this.convertToSession(token)));
 	}
 
 	public async createSession(scope: string): Promise<vscode.AuthenticationSession> {
-		Logger.info('Logging in...');
+		Logger.info(`Logging in for the following scopes: ${scope}`);
 		if (!scope.includes('offline_access')) {
 			Logger.info('Warning: The \'offline_access\' scope was not included, so the generated token will not be able to be refreshed.');
 		}
@@ -360,7 +372,7 @@ export class AzureActiveDirectoryService {
 				}
 				token = await this.exchangeCodeForToken(codeRes.code, codeVerifier, scope);
 				this.setToken(token, scope);
-				Logger.info('Login successful');
+				Logger.info(`Login successful for scopes: ${scope}`);
 				res.writeHead(302, { Location: '/' });
 				const session = await this.convertToSession(token);
 				return session;
@@ -371,7 +383,7 @@ export class AzureActiveDirectoryService {
 				res.end();
 			}
 		} catch (e) {
-			Logger.error(e.message);
+			Logger.error(`Error creating session for scopes: ${scope} 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') {
@@ -387,8 +399,7 @@ export class AzureActiveDirectoryService {
 	}
 
 	public dispose(): void {
-		this._disposables.forEach(disposable => disposable.dispose());
-		this._disposables = [];
+		this._disposable.dispose();
 	}
 
 	private getCallbackEnvironment(callbackUri: vscode.Uri): string {
@@ -550,7 +561,7 @@ export class AzureActiveDirectoryService {
 	}
 
 	private async exchangeCodeForToken(code: string, codeVerifier: string, scope: string): Promise<IToken> {
-		Logger.info('Exchanging login code for token');
+		Logger.info(`Exchanging login code for token for scopes: ${scope}`);
 		try {
 			const postData = querystring.stringify({
 				grant_type: 'authorization_code',
@@ -575,21 +586,21 @@ export class AzureActiveDirectoryService {
 			});
 
 			if (result.ok) {
-				Logger.info('Exchanging login code for token success');
 				const json = await result.json();
+				Logger.info(`Exchanging login code for token (for scopes: ${scope}) succeeded!`);
 				return this.getTokenFromResponse(json, scope);
 			} else {
-				Logger.error('Exchanging login code for token failed');
+				Logger.error(`Exchanging login code for token (for scopes: ${scope}) failed: ${await result.text()}`);
 				throw new Error('Unable to login.');
 			}
 		} catch (e) {
-			Logger.error(e.message);
+			Logger.error(`Error exchanging code for token (for scopes ${scope}): ${e}`);
 			throw e;
 		}
 	}
 
 	private async refreshToken(refreshToken: string, scope: string, sessionId: string): Promise<IToken> {
-		Logger.info('Refreshing token...');
+		Logger.info(`Refreshing token for scopes: ${scope}`);
 		const postData = querystring.stringify({
 			refresh_token: refreshToken,
 			client_id: clientId,
@@ -611,7 +622,7 @@ export class AzureActiveDirectoryService {
 				body: postData
 			});
 		} catch (e) {
-			Logger.error('Refreshing token failed');
+			Logger.error(`Refreshing token failed (for scopes: ${scope}) Error: ${e}`);
 			throw new Error(REFRESH_NETWORK_FAILURE);
 		}
 
@@ -620,14 +631,14 @@ export class AzureActiveDirectoryService {
 				const json = await result.json();
 				const token = this.getTokenFromResponse(json, scope, sessionId);
 				this.setToken(token, scope);
-				Logger.info('Token refresh success');
+				Logger.info(`Token refresh success for scopes: ${token.scope}`);
 				return token;
 			} else {
 				throw new Error('Bad request.');
 			}
 		} catch (e) {
 			vscode.window.showErrorMessage(localize('signOut', "You have been signed out because reading stored authentication information failed."));
-			Logger.error(`Refreshing token failed: ${result.statusText}`);
+			Logger.error(`Refreshing token failed (for scopes: ${scope}): ${result.statusText}`);
 			throw new Error('Refreshing token failed');
 		}
 	}
@@ -668,7 +679,7 @@ export class AzureActiveDirectoryService {
 	private handleRefreshNetworkError(sessionId: string, refreshToken: string, scope: string, attempts: number = 1): Promise<boolean> {
 		return new Promise((resolve, _) => {
 			if (attempts === 3) {
-				Logger.error('Token refresh failed after 3 attempts');
+				Logger.error(`Token refresh (for scopes: ${scope}) failed after 3 attempts`);
 				return resolve(false);
 			}
 

extensions/microsoft-authentication/src/extension.ts

@@ -7,8 +7,6 @@ import * as vscode from 'vscode';
 import { AzureActiveDirectoryService, onDidChangeSessions } from './AADHelper';
 import TelemetryReporter from 'vscode-extension-telemetry';
 
-export const DEFAULT_SCOPES = 'https://management.core.windows.net/.default offline_access';
-
 export async function activate(context: vscode.ExtensionContext) {
 	const { name, version, aiKey } = context.extension.packageJSON as { name: string, version: string, aiKey: string };
 	const telemetryReporter = new TelemetryReporter(name, version, aiKey);

extensions/microsoft-authentication/src/keychain.ts

@@ -3,47 +3,17 @@
  *  Licensed under the MIT License. See License.txt in the project root for license information.
  *--------------------------------------------------------------------------------------------*/
 
-// keytar depends on a native module shipped in vscode, so this is
-// how we load it
-import * as keytarType from 'keytar';
 import * as vscode from 'vscode';
 import Logger from './logger';
 import * as nls from 'vscode-nls';
 
 const localize = nls.loadMessageBundle();
 
-function getKeytar(): Keytar | undefined {
-	try {
-		return require('keytar');
-	} catch (err) {
-		console.log(err);
-	}
-
-	return undefined;
-}
-
-export type Keytar = {
-	getPassword: typeof keytarType['getPassword'];
-	setPassword: typeof keytarType['setPassword'];
-	deletePassword: typeof keytarType['deletePassword'];
-};
-
-const OLD_SERVICE_ID = `${vscode.env.uriScheme}-microsoft.login`;
 const SERVICE_ID = `microsoft.login`;
-const ACCOUNT_ID = 'account';
 
 export class Keychain {
-	private keytar: Keytar;
-
-	constructor(private context: vscode.ExtensionContext) {
-		const keytar = getKeytar();
-		if (!keytar) {
-			throw new Error('System keychain unavailable');
-		}
-
-		this.keytar = keytar;
-	}
 
+	constructor(private context: vscode.ExtensionContext) { }
 
 	async setToken(token: string): Promise<void> {
 
@@ -87,19 +57,4 @@ export class Keychain {
 			return Promise.resolve(undefined);
 		}
 	}
-
-	async tryMigrate(): Promise<string | null> {
-		try {
-			const oldValue = await this.keytar.getPassword(OLD_SERVICE_ID, ACCOUNT_ID);
-			if (oldValue) {
-				await this.setToken(oldValue);
-				await this.keytar.deletePassword(OLD_SERVICE_ID, ACCOUNT_ID);
-			}
-
-			return oldValue;
-		} catch (_) {
-			// Ignore
-			return Promise.resolve(null);
-		}
-	}
 }

extensions/microsoft-authentication/src/logger.ts

@@ -5,7 +5,7 @@
 
 import * as vscode from 'vscode';
 
-type LogLevel = 'Info' | 'Error';
+type LogLevel = 'Trace' | 'Info' | 'Error';
 
 class Log {
 	private output: vscode.OutputChannel;
@@ -24,6 +24,10 @@ class Log {
 		return data.toString();
 	}
 
+	public trace(message: string, data?: any): void {
+		this.logLevel('Trace', message, data);
+	}
+
 	public info(message: string, data?: any): void {
 		this.logLevel('Info', message, data);
 	}