Add more logging and add recovery from bad state (microsoft#5319)

Part of microsoft#5277

Author: alexr00

scripts/prepare-nightly-build.js

@@ -1,3 +1,8 @@
+/*---------------------------------------------------------------------------------------------
+ *  Copyright (c) Microsoft Corporation. All rights reserved.
+ *  Licensed under the MIT License. See License.txt in the project root for license information.
+ *--------------------------------------------------------------------------------------------*/
+
 const fs = require('fs');
 const argv = require('minimist')(process.argv.slice(2));
 
@@ -15,6 +20,7 @@ function prependZero(number) {
 
 // update name, publisher and description
 // calculate version
+// If the format of the patch version is ever changed, the isPreRelease utility function should be updated.
 let patch = argv['v'];
 if (typeof patch !== 'string') {
 	const date = new Date();

src/common/utils.ts

@@ -8,7 +8,7 @@ import { sep } from 'path';
 import dayjs from 'dayjs';
 import * as relativeTime from 'dayjs/plugin/relativeTime';
 import * as updateLocale from 'dayjs/plugin/updateLocale';
-import type { Disposable, Event, Uri } from 'vscode';
+import type { Disposable, Event, ExtensionContext, Uri } from 'vscode';
 // TODO: localization for webview needed
 
 dayjs.extend(relativeTime.default, {
@@ -710,6 +710,19 @@ export class UriIterator implements IKeyIterator<Uri> {
 	}
 }
 
+export function isPreRelease(context: ExtensionContext): boolean {
+	const uri = context.extensionUri;
+	const path = uri.path;
+	const lastIndexOfDot = path.lastIndexOf('.');
+	if (lastIndexOfDot === -1) {
+		return false;
+	}
+	const patchVersion = path.substr(lastIndexOfDot + 1);
+	// The patch version of release versions should never be more than 1 digit since it is only used for recovery releases.
+	// The patch version of pre-release is the date + time. 
+	return patchVersion.length > 1;
+}
+
 class TernarySearchTreeNode<K, V> {
 	segment!: string;
 	value: V | undefined;

src/view/reviewManager.ts

@@ -25,7 +25,7 @@ import {
 } from '../common/settingKeys';
 import { ITelemetry } from '../common/telemetry';
 import { fromPRUri, fromReviewUri, KnownMediaExtensions, PRUriParams, Schemes, toReviewUri } from '../common/uri';
-import { formatError, groupBy, onceEvent } from '../common/utils';
+import { formatError, groupBy, isPreRelease, onceEvent } from '../common/utils';
 import { FOCUS_REVIEW_MODE } from '../constants';
 import { GitHubCreatePullRequestLinkProvider } from '../github/createPRLinkProvider';
 import { FolderRepositoryManager } from '../github/folderRepositoryManager';
@@ -267,9 +267,40 @@ export class ReviewManager {
 		}
 	}
 
+	private hasShownLogRequest: boolean = false;
 	private async validateStatueAndSetContext(silent: boolean, updateLayout: boolean) {
-		await this.validateState(silent, updateLayout);
-		await vscode.commands.executeCommand('setContext', 'github:stateValidated', true);
+		// TODO @alexr00: There's a bug where validateState never returns sometimes. It's not clear what's causing this.
+		// This is a temporary workaround to ensure that the validateStatueAndSetContext promise always resolves.
+		// Additional logs have been added, and the issue is being tracked here: https://github.com/microsoft/vscode-pull-request-git/issues/5277
+		let timeout: NodeJS.Timeout | undefined;
+		const timeoutPromise = new Promise<void>(resolve => {
+			timeout = setTimeout(() => {
+				if (timeout) {
+					clearTimeout(timeout);
+					timeout = undefined;
+					Logger.error('Timeout occurred while validating state.', ReviewManager.ID);
+					if (!this.hasShownLogRequest && isPreRelease(this._context)) {
+						this.hasShownLogRequest = true;
+						vscode.window.showErrorMessage(vscode.l10n.t('A known error has occurred refreshing the repository state. Please share logs from "GitHub Pull Request" in the [tracking issue]({0}).', 'https://github.com/microsoft/vscode-pull-request-github/issues/5277'));
+					}
+				}
+				resolve();
+			}, 1000 * 60 * 2);
+		});
+
+		const validatePromise = new Promise<void>(resolve => {
+			this.validateState(silent, updateLayout).then(() => {
+				vscode.commands.executeCommand('setContext', 'github:stateValidated', true).then(() => {
+					if (timeout) {
+						clearTimeout(timeout);
+						timeout = undefined;
+					}
+					resolve();
+				});
+			});
+		});
+
+		return Promise.race([validatePromise, timeoutPromise]);
 	}
 
 	private async offerIgnoreBranch(currentBranchName): Promise<boolean> {
@@ -388,8 +419,10 @@ export class ReviewManager {
 		const previousPrNumber = this._prNumber;
 		let pr = await this.resolvePullRequest(matchingPullRequestMetadata);
 		if (!pr) {
+			Logger.appendLine(`Unable to resolve PR #${matchingPullRequestMetadata.prNumber}`, ReviewManager.ID);
 			return;
 		}
+		Logger.appendLine(`Resolved PR #${matchingPullRequestMetadata.prNumber}, state is ${pr.state}`, ReviewManager.ID);
 
 		// Check if the PR is open, if not, check if there's another PR from the same branch on GitHub
 		if (pr.state !== GithubItemStateEnum.Open) {
@@ -416,14 +449,14 @@ export class ReviewManager {
 			.get<{ merged: boolean, closed: boolean }>(USE_REVIEW_MODE, { merged: true, closed: false });
 
 		if (pr.isClosed && !useReviewConfiguration.closed) {
-			await this.clear(true);
 			Logger.appendLine('This PR is closed', ReviewManager.ID);
+			await this.clear(true);
 			return;
 		}
 
 		if (pr.isMerged && !useReviewConfiguration.merged) {
-			await this.clear(true);
 			Logger.appendLine('This PR is merged', ReviewManager.ID);
+			await this.clear(true);
 			return;
 		}
 
@@ -471,6 +504,7 @@ export class ReviewManager {
 				this._changesSinceLastReviewProgress.endProgress();
 			})
 		);
+		Logger.appendLine(`Register in memory content provider`, ReviewManager.ID);
 		await this.registerGitHubInMemContentProvider();
 
 		this.statusBarItem.text = '$(git-pull-request) ' + vscode.l10n.t('Pull Request #{0}', pr.number);