Git - logging improvements

extensions/git/package.json

@@ -2287,6 +2287,30 @@
           "default": [],
           "scope": "resource",
           "markdownDescription": "%config.commandsToLog%"
+        },
+        "git.logLevel": {
+          "type": "string",
+          "default": "Info",
+          "enum": [
+            "Trace",
+            "Debug",
+            "Info",
+            "Warning",
+            "Error",
+            "Critical",
+            "Off"
+          ],
+          "enumDescriptions": [
+            "%config.logLevel.trace%",
+            "%config.logLevel.debug%",
+            "%config.logLevel.info%",
+            "%config.logLevel.warn%",
+            "%config.logLevel.error%",
+            "%config.logLevel.critical%",
+            "%config.logLevel.off%"
+          ],
+          "markdownDescription": "%config.logLevel%",
+          "scope": "window"
         }
       }
     },

extensions/git/package.nls.json

@@ -209,6 +209,21 @@
 	"config.repositoryScanIgnoredFolders": "List of folders that are ignored while scanning for Git repositories when `#git.autoRepositoryDetection#` is set to `true` or `subFolders`.",
 	"config.repositoryScanMaxDepth": "Controls the depth used when scanning workspace folders for Git repositories when `#git.autoRepositoryDetection#` is set to `true` or `subFolders`. Can be set to `-1` for no limit.",
 	"config.useIntegratedAskPass": "Controls whether GIT_ASKPASS should be overwritten to use the integrated version.",
+	"config.logLevel": {
+		"message": "Specifies how much information (if any) to log to the [git output](command:git.showOutput).",
+		"comment": [
+			"{Locked='](command:git.showOutput'}",
+			"Do not translate the 'command:*' part inside of the '(..)'. It is an internal command syntax for VS Code",
+			"Please make sure there is no space between the right bracket and left parenthesis:  ]( this is an internal syntax for links"
+		]
+	},
+	"config.logLevel.trace": "Log all information",
+	"config.logLevel.debug": "Log only debug, information, warning, error, and critical information",
+	"config.logLevel.info": "Log only information, warning, error, and critical information",
+	"config.logLevel.warn": "Log only warning, error, and critical information",
+	"config.logLevel.error": "Log only error, and critical information",
+	"config.logLevel.critical": "Log only critical information",
+	"config.logLevel.off": "Log nothing",
 	"submenu.explorer": "Git",
 	"submenu.commit": "Commit",
 	"submenu.commit.amend": "Amend",

extensions/git/src/askpass.ts

@@ -3,23 +3,24 @@
  *  Licensed under the MIT License. See License.txt in the project root for license information.
  *--------------------------------------------------------------------------------------------*/
 
-import { window, InputBoxOptions, Uri, OutputChannel, Disposable, workspace } from 'vscode';
-import { IDisposable, EmptyDisposable, toDisposable, logTimestamp } from './util';
+import { window, InputBoxOptions, Uri, Disposable, workspace } from 'vscode';
+import { IDisposable, EmptyDisposable, toDisposable } from './util';
 import * as path from 'path';
 import { IIPCHandler, IIPCServer, createIPCServer } from './ipc/ipcServer';
 import { CredentialsProvider, Credentials } from './api/git';
+import { OutputChannelLogger } from './log';
 
 export class Askpass implements IIPCHandler {
 
 	private disposable: IDisposable = EmptyDisposable;
 	private cache = new Map<string, Credentials>();
 	private credentialsProviders = new Set<CredentialsProvider>();
 
-	static async create(outputChannel: OutputChannel, context?: string): Promise<Askpass> {
+	static async create(outputChannelLogger: OutputChannelLogger, context?: string): Promise<Askpass> {
 		try {
 			return new Askpass(await createIPCServer(context));
 		} catch (err) {
-			outputChannel.appendLine(`${logTimestamp()} [error] Failed to create git askpass IPC: ${err}`);
+			outputChannelLogger.logError(`Failed to create git askpass IPC: ${err}`);
 			return new Askpass();
 		}
 	}

extensions/git/src/commands.ts

@@ -5,7 +5,7 @@
 
 import * as os from 'os';
 import * as path from 'path';
-import { Command, commands, Disposable, LineChange, MessageOptions, OutputChannel, Position, ProgressLocation, QuickPickItem, Range, SourceControlResourceState, TextDocumentShowOptions, TextEditor, Uri, ViewColumn, window, workspace, WorkspaceEdit, WorkspaceFolder, TimelineItem, env, Selection, TextDocumentContentProvider } from 'vscode';
+import { Command, commands, Disposable, LineChange, MessageOptions, Position, ProgressLocation, QuickPickItem, Range, SourceControlResourceState, TextDocumentShowOptions, TextEditor, Uri, ViewColumn, window, workspace, WorkspaceEdit, WorkspaceFolder, TimelineItem, env, Selection, TextDocumentContentProvider } from 'vscode';
 import TelemetryReporter from '@vscode/extension-telemetry';
 import * as nls from 'vscode-nls';
 import { Branch, ForcePushMode, GitErrorCodes, Ref, RefType, Status, CommitOptions, RemoteSourcePublisher } from './api/git';
@@ -14,8 +14,8 @@ import { Model } from './model';
 import { Repository, Resource, ResourceGroupType } from './repository';
 import { applyLineChanges, getModifiedRange, intersectDiffWithRange, invertLineChange, toLineRanges } from './staging';
 import { fromGitUri, toGitUri, isGitUri } from './uri';
-import { grep, isDescendant, logTimestamp, pathEquals, relativePath } from './util';
-import { Log, LogLevel } from './log';
+import { grep, isDescendant, pathEquals, relativePath } from './util';
+import { LogLevel, OutputChannelLogger } from './log';
 import { GitTimelineItem } from './timelineProvider';
 import { ApiRepository } from './api/api1';
 import { pickRemoteSource } from './remoteSource';
@@ -310,7 +310,7 @@ export class CommandCenter {
 	constructor(
 		private git: Git,
 		private model: Model,
-		private outputChannel: OutputChannel,
+		private outputChannelLogger: OutputChannelLogger,
 		private telemetryReporter: TelemetryReporter
 	) {
 		this.disposables = Commands.map(({ commandId, key, method, options }) => {
@@ -328,11 +328,25 @@ export class CommandCenter {
 
 	@command('git.setLogLevel')
 	async setLogLevel(): Promise<void> {
-		const createItem = (logLevel: LogLevel) => ({
-			label: LogLevel[logLevel],
-			logLevel,
-			description: Log.logLevel === logLevel ? localize('current', "Current") : undefined
-		});
+		const createItem = (logLevel: LogLevel) => {
+			let description: string | undefined;
+			const defaultDescription = localize('default', "Default");
+			const currentDescription = localize('current', "Current");
+
+			if (logLevel === this.outputChannelLogger.defaultLogLevel && logLevel === this.outputChannelLogger.currentLogLevel) {
+				description = `${defaultDescription} & ${currentDescription} `;
+			} else if (logLevel === this.outputChannelLogger.defaultLogLevel) {
+				description = defaultDescription;
+			} else if (logLevel === this.outputChannelLogger.currentLogLevel) {
+				description = currentDescription;
+			}
+
+			return {
+				label: LogLevel[logLevel],
+				logLevel,
+				description
+			};
+		};
 
 		const items = [
 			createItem(LogLevel.Trace),
@@ -352,8 +366,7 @@ export class CommandCenter {
 			return;
 		}
 
-		Log.logLevel = choice.logLevel;
-		this.outputChannel.appendLine(localize('changed', "{0} Log level changed to: {1}", logTimestamp(), LogLevel[Log.logLevel]));
+		this.outputChannelLogger.setLogLevel(choice.logLevel);
 	}
 
 	@command('git.refresh', { repository: true })
@@ -820,14 +833,14 @@ export class CommandCenter {
 
 	@command('git.stage')
 	async stage(...resourceStates: SourceControlResourceState[]): Promise<void> {
-		this.outputChannel.appendLine(`${logTimestamp()} git.stage ${resourceStates.length}`);
+		this.outputChannelLogger.logDebug(`git.stage ${resourceStates.length} `);
 
 		resourceStates = resourceStates.filter(s => !!s);
 
 		if (resourceStates.length === 0 || (resourceStates[0] && !(resourceStates[0].resourceUri instanceof Uri))) {
 			const resource = this.getSCMResource();
 
-			this.outputChannel.appendLine(`${logTimestamp()} git.stage.getSCMResource ${resource ? resource.resourceUri.toString() : null}`);
+			this.outputChannelLogger.logDebug(`git.stage.getSCMResource ${resource ? resource.resourceUri.toString() : null} `);
 
 			if (!resource) {
 				return;
@@ -870,7 +883,7 @@ export class CommandCenter {
 		const untracked = selection.filter(s => s.resourceGroupType === ResourceGroupType.Untracked);
 		const scmResources = [...workingTree, ...untracked, ...resolved, ...unresolved];
 
-		this.outputChannel.appendLine(`${logTimestamp()} git.stage.scmResources ${scmResources.length}`);
+		this.outputChannelLogger.logDebug(`git.stage.scmResources ${scmResources.length} `);
 		if (!scmResources.length) {
 			return;
 		}
@@ -2809,8 +2822,8 @@ export class CommandCenter {
 
 				const choices = new Map<string, () => void>();
 				const openOutputChannelChoice = localize('open git log', "Open Git Log");
-				const outputChannel = this.outputChannel as OutputChannel;
-				choices.set(openOutputChannelChoice, () => outputChannel.show());
+				const outputChannelLogger = this.outputChannelLogger;
+				choices.set(openOutputChannelChoice, () => outputChannelLogger.showOutputChannel());
 
 				const showCommandOutputChoice = localize('show command output', "Show Command Output");
 				if (err.stderr) {
@@ -2913,10 +2926,10 @@ export class CommandCenter {
 	private getSCMResource(uri?: Uri): Resource | undefined {
 		uri = uri ? uri : (window.activeTextEditor && window.activeTextEditor.document.uri);
 
-		this.outputChannel.appendLine(`${logTimestamp()} git.getSCMResource.uri ${uri && uri.toString()}`);
+		this.outputChannelLogger.logDebug(`git.getSCMResource.uri ${uri && uri.toString()}`);
 
 		for (const r of this.model.repositories.map(r => r.root)) {
-			this.outputChannel.appendLine(`${logTimestamp()} repo root ${r}`);
+			this.outputChannelLogger.logDebug(`repo root ${r}`);
 		}
 
 		if (!uri) {

extensions/git/src/log.ts

@@ -3,7 +3,11 @@
  *  Licensed under the MIT License. See License.txt in the project root for license information.
  *--------------------------------------------------------------------------------------------*/
 
-import { Event, EventEmitter } from 'vscode';
+import * as nls from 'vscode-nls';
+const localize = nls.loadMessageBundle();
+
+import { commands, Disposable, Event, EventEmitter, OutputChannel, window, workspace } from 'vscode';
+import { dispose } from './util';
 
 /**
  * The severity level of a log message
@@ -18,33 +22,93 @@ export enum LogLevel {
 	Off = 7
 }
 
-let _logLevel: LogLevel = LogLevel.Info;
-const _onDidChangeLogLevel = new EventEmitter<LogLevel>();
-
-export const Log = {
-	/**
-	 * Current logging level.
-	 */
-	get logLevel(): LogLevel {
-		return _logLevel;
-	},
-
-	/**
-	 * Current logging level.
-	 */
-	set logLevel(logLevel: LogLevel) {
-		if (_logLevel === logLevel) {
+/**
+ * Output channel logger
+ */
+export class OutputChannelLogger {
+
+	private _onDidChangeLogLevel = new EventEmitter<LogLevel>();
+	readonly onDidChangeLogLevel: Event<LogLevel> = this._onDidChangeLogLevel.event;
+
+	private _currentLogLevel: LogLevel;
+	get currentLogLevel(): LogLevel {
+		return this._currentLogLevel;
+	}
+
+	private _defaultLogLevel: LogLevel;
+	get defaultLogLevel(): LogLevel {
+		return this._defaultLogLevel;
+	}
+
+	private _outputChannel: OutputChannel;
+	private _disposables: Disposable[] = [];
+
+	constructor() {
+		// Output channel
+		this._outputChannel = window.createOutputChannel('Git');
+		commands.registerCommand('git.showOutput', () => this.showOutputChannel());
+		this._disposables.push(this._outputChannel);
+
+		// Initialize log level
+		const config = workspace.getConfiguration('git');
+		const logLevel: keyof typeof LogLevel = config.get('logLevel', 'Info');
+		this._currentLogLevel = this._defaultLogLevel = LogLevel[logLevel] ?? LogLevel.Info;
+
+		this.logInfo(localize('gitLogLevel', "Log level: {0}", LogLevel[this._currentLogLevel]));
+	}
+
+	private log(message: string, logLevel: LogLevel): void {
+		if (logLevel < this._currentLogLevel) {
+			return;
+		}
+
+		this._outputChannel.appendLine(`[${new Date().toISOString()}] [${LogLevel[logLevel].toLowerCase()}] ${message}`);
+	}
+
+	logCritical(message: string): void {
+		this.log(message, LogLevel.Critical);
+	}
+
+	logDebug(message: string): void {
+		this.log(message, LogLevel.Debug);
+	}
+
+	logError(message: string): void {
+		this.log(message, LogLevel.Error);
+	}
+
+	logInfo(message: string): void {
+		this.log(message, LogLevel.Info);
+	}
+
+	logTrace(message: string): void {
+		this.log(message, LogLevel.Trace);
+	}
+
+	logWarning(message: string): void {
+		this.log(message, LogLevel.Warning);
+	}
+
+	logGitCommand(command: string): void {
+		this._outputChannel.appendLine(`[${new Date().toISOString()}] ${command}`);
+	}
+
+	setLogLevel(logLevel: LogLevel): void {
+		if (this._currentLogLevel === logLevel) {
 			return;
 		}
 
-		_logLevel = logLevel;
-		_onDidChangeLogLevel.fire(logLevel);
-	},
+		this._currentLogLevel = logLevel;
+		this._onDidChangeLogLevel.fire(logLevel);
 
-	/**
-	 * An [event](#Event) that fires when the log level has changed.
-	 */
-	get onDidChangeLogLevel(): Event<LogLevel> {
-		return _onDidChangeLogLevel.event;
+		this.logInfo(localize('changed', "Log level changed to: {0}", LogLevel[logLevel]));
 	}
-};
+
+	showOutputChannel(): void {
+		this._outputChannel.show();
+	}
+
+	dispose(): void {
+		this._disposables = dispose(this._disposables);
+	}
+}