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 #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>

docs/settings.md

@@ -292,6 +292,14 @@ Default:{<br/>
  }
 
 
+### `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.

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,

src/goEnvironmentStatus.ts

@@ -14,6 +14,7 @@ import { promisify } from 'util';
 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,20 +285,22 @@ export function addGoRuntimeBaseToPATH(newGoRuntimeBase: string) {
  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;
  }
 
  if (!defaultPathEnv) { // cache the default value
  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') {

src/goInstallTools.ts

@@ -14,6 +14,7 @@ import vscode = require('vscode');
 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 @@ export function updateGoVarsFromConfig(): Promise<void> {
  // 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 @@ export function updateGoVarsFromConfig(): Promise<void> {
  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();

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);
+}

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 @@ import {
 } 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 @@ import {
  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 vetDiagnosticCollection: vscode.DiagnosticCollection;
 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 @@ export function activate(ctx: vscode.ExtensionContext) {
  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();

src/utils/pathUtils.ts

@@ -13,6 +13,7 @@ import fs = require('fs');
 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 getCurrentGoRoot(): string {
 }
 
 export function setCurrentGoRoot(goroot: string) {
+ logVerbose(`setCurrentGoRoot(${goroot})`);
  currentGoRoot = goroot;
 }