src/goLogging.ts: add go.logging.level and log PATH mutation

go.logging.level determines the extension's debug logging level.
Currently, all log messages go to console.log. Eventually, we
will want to provide an option to output in an OUTPUT channel
or a file.

Add verbose logging to trace how the current GOROOT is determined
and how PATH is mutated.

Update golang/vscode-go#667

Change-Id: I95275ee4843d6cc9f8e34367f832a728ac1ea63f
Reviewed-on: https://go-review.googlesource.com/c/vscode-go/+/256557
Trust: Hyang-Ah Hana Kim <hyangah@gmail.com>
Run-TryBot: Hyang-Ah Hana Kim <hyangah@gmail.com>
TryBot-Result: kokoro <noreply+kokoro@google.com>
Reviewed-by: Suzy Mueller <suzmue@golang.org>
diff --git a/docs/settings.md b/docs/settings.md
index 5969f23..0463534 100644
--- a/docs/settings.md
+++ b/docs/settings.md
@@ -292,6 +292,14 @@
     }
 
 
+### `go.logging.level`
+
+The logging level the extension logs at, defaults to 'error'
+
+Allowed Values:`[off error info verbose]`
+
+Default: `error`
+
 ### `go.overwriteGoplsMiddleware`
 
 This option provides a set of flags which determine if vscode-go should intercept certain commands from gopls. These flags assume the `gopls` settings, which enable codelens from gopls, are also present.
diff --git a/package.json b/package.json
index 9968de4..3bc3086 100644
--- a/package.json
+++ b/package.json
@@ -1563,6 +1563,18 @@
           "default": "off",
           "description": "Trace the communication between VS Code and the Go language server."
         },
+        "go.logging.level": {
+          "type": "string",
+          "default": "error",
+          "enum": [
+            "off",
+            "error",
+            "info",
+            "verbose"
+          ],
+          "description": "The logging level the extension logs at, defaults to 'error'",
+          "scope": "machine-overridable"
+        },
         "go.useGoProxyToCheckForToolUpdates": {
           "type": "boolean",
           "default": true,
diff --git a/src/goEnvironmentStatus.ts b/src/goEnvironmentStatus.ts
index 554fa0f..91c7b8c 100644
--- a/src/goEnvironmentStatus.ts
+++ b/src/goEnvironmentStatus.ts
@@ -14,6 +14,7 @@
 import vscode = require('vscode');
 import WebRequest = require('web-request');
 import { toolInstallationEnvironment } from './goEnv';
+import { logVerbose } from './goLogging';
 import { hideGoStatus, outputChannel, showGoStatus } from './goStatus';
 import { getFromGlobalState, getFromWorkspaceState, updateGlobalState, updateWorkspaceState } from './stateUtils';
 import { getBinPath, getGoConfig, getGoVersion, getTempFilePath, GoVersion, rmdirRecursive } from './util';
@@ -284,13 +285,13 @@
 	if (!newGoRuntimeBase) {
 		return;
 	}
-
 	let pathEnvVar: string;
 	if (process.env.hasOwnProperty('PATH')) {
 		pathEnvVar = 'PATH';
 	} else if (process.platform === 'win32' && process.env.hasOwnProperty('Path')) {
 		pathEnvVar = 'Path';
 	} else {
+		logVerbose(`couldn't find PATH property in process.env`);
 		return;
 	}
 
@@ -298,6 +299,8 @@
 		defaultPathEnv = <string>process.env[pathEnvVar];
 	}
 
+	logVerbose(`addGoRuntimeBase(${newGoRuntimeBase}) when PATH=${defaultPathEnv}`);
+
 	// calling this multiple times will override the previous value.
 	// environmentVariableCollection.clear();
 	if (process.platform !== 'darwin') {
diff --git a/src/goInstallTools.ts b/src/goInstallTools.ts
index 218b58e..3ca1538 100644
--- a/src/goInstallTools.ts
+++ b/src/goInstallTools.ts
@@ -14,6 +14,7 @@
 import { toolExecutionEnvironment, toolInstallationEnvironment } from './goEnv';
 import { addGoRuntimeBaseToPATH, initGoStatusBar } from './goEnvironmentStatus';
 import { getLanguageServerToolPath } from './goLanguageServer';
+import { logVerbose } from './goLogging';
 import { restartLanguageServer } from './goMain';
 import { hideGoStatus, outputChannel, showGoStatus } from './goStatus';
 import {
@@ -345,6 +346,7 @@
 	// FIXIT: if updateGoVarsFromConfig is called again after addGoRuntimeBaseToPATH sets PATH,
 	// the go chosen by getBinPath based on PATH will not change.
 	const goRuntimePath = getBinPath('go', false);
+	logVerbose(`updateGoVarsFromConfig: found 'go' in ${goRuntimePath}`);
 	if (!goRuntimePath) {
 		suggestDownloadGo();
 		return;
@@ -362,6 +364,8 @@
 				vscode.window.showErrorMessage(`Failed to run '${goRuntimePath} env. The config change may not be applied correctly.`);
 				return reject();
 			}
+			logVerbose(`${goRuntimePath} env ...:\n${stdout}`);
+
 			const envOutput = stdout.split('\n');
 			if (!process.env['GOPATH'] && envOutput[0].trim()) {
 				process.env['GOPATH'] = envOutput[0].trim();
diff --git a/src/goLogging.ts b/src/goLogging.ts
new file mode 100644
index 0000000..d032f1f
--- /dev/null
+++ b/src/goLogging.ts
@@ -0,0 +1,75 @@
+/*---------------------------------------------------------
+ * Copyright 2020 The Go Authors. All rights reserved.
+ * Licensed under the MIT License. See LICENSE in the project root for license information.
+ *--------------------------------------------------------*/
+
+'use strict';
+
+// Our log level.
+enum LogLevel {
+	Off = 100,
+	Error = 50,
+	Info = 30,
+	Verbose = 20,
+	// TODO: Trace, Warn level
+}
+
+let currentLogLevel: LogLevel = LogLevel.Error;
+
+const levelMap: { [k: string]: LogLevel } = {
+	off: LogLevel.Off,
+	error: LogLevel.Error,
+	info: LogLevel.Info,
+	verbose: LogLevel.Verbose,
+};
+
+function levelPrefix(l: LogLevel): string {
+	switch (l) {
+		case LogLevel.Off: return 'Go[O]:';
+		case LogLevel.Error: return 'Go[E]:';
+		case LogLevel.Info: return 'Go[I]:';
+		case LogLevel.Verbose: return 'Go[V]:';
+		default: return 'Go[?]:';
+	}
+}
+
+export interface LogConfig {
+	level: string;
+}
+
+export function setLogConfig(cfg: LogConfig) {
+	const logLevel = cfg?.level || 'error';
+	const l = levelMap[logLevel];
+	if (l) {
+		currentLogLevel = l;
+		return;
+	}
+	logError(`setLogLevel requested with invalid log level ${logLevel}, ignoring...`);
+}
+
+// tslint:disable-next-line:no-any
+function log(logLevel: LogLevel, ...args: any[]) {
+	if (logLevel < currentLogLevel) {
+		return;
+	}
+	const p = levelPrefix(logLevel);
+	const a = Array.from(args);
+	a.unshift(p);
+	console.log(...a);
+	// TODO: support logging in vscode output channel.
+}
+
+// tslint:disable-next-line:no-any
+export function logVerbose(...args: any[]) {
+	log(LogLevel.Info, ...args);
+}
+
+// tslint:disable-next-line:no-any
+export function logError(...args: any[]) {
+	log(LogLevel.Error, ...args);
+}
+
+// tslint:disable-next-line:no-any
+export function logInfo(...args: any[]) {
+	log(LogLevel.Info, ...args);
+}
diff --git a/src/goMain.ts b/src/goMain.ts
index 4bc8a79..7b7d714 100644
--- a/src/goMain.ts
+++ b/src/goMain.ts
@@ -8,7 +8,6 @@
 
 import * as path from 'path';
 import vscode = require('vscode');
-import { GoDlvDapDebugSession } from './debugAdapter2/goDlvDebug';
 import { browsePackages } from './goBrowsePackage';
 import { buildCode } from './goBuild';
 import { check, notifyIfGeneratedFile, removeTestStatus } from './goCheck';
@@ -32,6 +31,7 @@
 } from './goInstallTools';
 import { startLanguageServerWithFallback, watchLanguageServerConfiguration } from './goLanguageServer';
 import { lintCode } from './goLint';
+import { logVerbose, setLogConfig } from './goLogging';
 import { GO_MODE } from './goMode';
 import { addTags, removeTags } from './goModifytags';
 import { GO111MODULE, isModSupported } from './goModules';
@@ -61,7 +61,7 @@
 	isGoPathSet,
 	resolvePath,
 } from './util';
-import { clearCacheForTools, envPath, fileExists, getCurrentGoRoot, setCurrentGoRoot } from './utils/pathUtils';
+import { clearCacheForTools, fileExists, getCurrentGoRoot, setCurrentGoRoot } from './utils/pathUtils';
 
 export let buildDiagnosticCollection: vscode.DiagnosticCollection;
 export let lintDiagnosticCollection: vscode.DiagnosticCollection;
@@ -73,12 +73,16 @@
 export let restartLanguageServer = () => { return; };
 
 export function activate(ctx: vscode.ExtensionContext) {
+	const logConfig = getGoConfig()['logging'];
+	setLogConfig(logConfig);
+
 	setGlobalState(ctx.globalState);
 	setWorkspaceState(ctx.workspaceState);
 	setEnvironmentVariableCollection(ctx.environmentVariableCollection);
 
 	const configGOROOT = getGoConfig()['goroot'];
 	if (!!configGOROOT) {
+		logVerbose(`go.goroot = '${configGOROOT}'`);
 		setCurrentGoRoot(resolvePath(configGOROOT));
 	}
 
@@ -316,6 +320,9 @@
 				e.affectsConfiguration('go.testEnvFile')) {
 				updateGoVarsFromConfig();
 			}
+			if (e.affectsConfiguration('go.logging')) {
+				setLogConfig(updatedGoConfig['logging']);
+			}
 			// If there was a change in "toolsGopath" setting, then clear cache for go tools
 			if (getToolsGopath() !== getToolsGopath(false)) {
 				clearCacheForTools();
diff --git a/src/utils/pathUtils.ts b/src/utils/pathUtils.ts
index ab3be8f..74fe93c 100644
--- a/src/utils/pathUtils.ts
+++ b/src/utils/pathUtils.ts
@@ -13,6 +13,7 @@
 import os = require('os');
 import path = require('path');
 import { promisify } from 'util';
+import { logVerbose } from '../goLogging';
 
 let binPathCache: { [bin: string]: string } = {};
 
@@ -104,6 +105,7 @@
 }
 
 export function setCurrentGoRoot(goroot: string) {
+	logVerbose(`setCurrentGoRoot(${goroot})`);
 	currentGoRoot = goroot;
 }