src/goInstallTools,goTelemetry: add TelemetryReporter

TelemetryReporter buffers counter updates and periodically
invokes a go program (vscgo) that writes the counter to the
disk.

installVCSGO in goInstallTools.ts installs vscgo.
If vscgo installation fails, TelemetryReporter will keep
holding the counter in memory. The buffer is a set keyed
by the counter and we expect there is a finite set of counters.

That installs the vscgo binary in the extension path.
The location was chosen so that when users update the
extension, a new version can be installed. VS Code will
manage the extension path and delete the directory when
the extension is uninstalled or the version is no
longer used.

The extension operates in four different modes
and we need to choose how to build the vscgo.
The extension includes the vscgo main package source
file in it.

1) golang.go, stable/rc releases: PRODUCTION mode. try to
install from the remote source (proxy) so its checksum
is verified and build version and telemetry counter file
matches the extension version. The source repo needs
to be tagged. In case of failure, we attempt to fallback to the
build with the source code included in the extension.

2) golang.go-nightly, preview release: PRODUCTION mode.
Nightly is released daily automatically. Tagging the repo
everyday is not practical. Moreover, the nightly extension
does not use semver but encodes the release timestamp,
so it is not compatible with go commands.
Installing from @master or @latest isn't ideal either since
vscgo functionality is tied with the extension version.
The telemetry data will be labeled with `devel` version.

3) golang.go, preview release: PRODUCTION mode. Used for
local testing during development (e.g. npm run package &
code --install-extension). The version will include `-dev`.
We want to build from the local source included in the
extension since there is no usable tag in the remote origin.
The telemetry data will be labeled with `devel` version.

4) golang.go, preview release: DEVELOPMENT mode. Used for
local testing using the launch.json configuration.
VS Code will use the project source code as the extension
path. Build vscgo from the project repo on disk. The
telemetry data will be labeled with `devel` version.

5) golang.go, preview release: TEST mode. Currently same
as 4. No telemetry data is materialized. Tests
that are designed for telemetry testing write test data in
temporary text file for inspection during tests.

For golang/vscode-go#3023

Change-Id: Ic408e7b296fdcb9ed33b68293ea82f5e29a81515
Reviewed-on: https://go-review.googlesource.com/c/vscode-go/+/549244
Commit-Queue: Hyang-Ah Hana Kim <hyangah@gmail.com>
Reviewed-by: Suzy Mueller <suzmue@golang.org>
TryBot-Result: kokoro <noreply+kokoro@google.com>

.gitignore

@@ -1,6 +1,7 @@
+bin/
 out/
 dist/
 node_modules/
 .vscode-test/
 .DS_Store
-.user-data-dir-test/
+.user-data-dir-test/

package.json

@@ -36,7 +36,7 @@
     "gopls"
   ],
   "scripts": {
-    "clean": "rm -rf ./dist/* && rm -rf ./out/* && rm *.vsix",
+    "clean": "rm -rf ./dist/* && rm -rf ./out/* && rm -rf ./bin/* && rm *.vsix",
     "package": "npx vsce package",
     "vscode:prepublish": "npm run compile",
     "bundle": "esbuild src/goMain.ts debugAdapter=src/debugAdapter/goDebug.ts --bundle --outdir=dist --external:vscode --format=cjs --platform=node",

src/goInstallTools.ts

@@ -30,10 +30,18 @@ import {
 	GoVersion,
 	rmdirRecursive
 } from './util';
-import { getEnvPath, getCurrentGoRoot, setCurrentGoRoot } from './utils/pathUtils';
+import {
+	getEnvPath,
+	getCurrentGoRoot,
+	setCurrentGoRoot,
+	correctBinname,
+	executableFileExists
+} from './utils/pathUtils';
 import util = require('util');
 import vscode = require('vscode');
 import { RestartReason } from './language/goLanguageServer';
+import { telemetryReporter } from './goTelemetry';
+import { allToolsInformation } from './goToolsInformation';
 
 const STATUS_BAR_ITEM_NAME = 'Go Tools';
 
@@ -781,3 +789,48 @@ export async function listOutdatedTools(configuredGoVersion: GoVersion | undefin
 	);
 	return oldTools.filter((tool): tool is Tool => !!tool);
 }
+
+// installVSCGO is a special program released and installed with the Go extension.
+// Unlike other tools, it is installed under the extension path (which is cleared
+// when a new version is installed).
+export async function installVSCGO(
+	extensionId: string,
+	extensionVersion: string,
+	extensionPath: string,
+	isPreview: boolean,
+	forceInstall = false
+): Promise<string> {
+	// golang.go stable, golang.go-nightly stable -> install once per version.
+	// golang.go dev through launch.json -> install every time.
+	const progPath = path.join(extensionPath, 'bin', correctBinname('vscgo'));
+
+	if (!forceInstall && executableFileExists(progPath)) {
+		return progPath; // reuse existing executable.
+	}
+	telemetryReporter.add('vscgo_install', 1);
+	const mkdir = util.promisify(fs.mkdir);
+	await mkdir(path.dirname(progPath), { recursive: true });
+	const execFile = util.promisify(cp.execFile);
+
+	const cwd = path.join(extensionPath, 'vscgo');
+	const env = toolExecutionEnvironment();
+	env['GOBIN'] = path.dirname(progPath);
+
+	// build from source acquired from the module proxy if this is a non-preview version.
+	if (extensionId === 'golang.go' && !isPreview && !extensionVersion.includes('-dev.')) {
+		const importPath = allToolsInformation['vscgo'].importPath;
+		try {
+			const args = ['install', `${importPath}@v${extensionVersion}`];
+			await execFile(getBinPath('go'), args, { cwd, env });
+			return progPath;
+		} catch (e) {
+			telemetryReporter.add('vscgo_install_fail', 1);
+			console.log(`failed to install ${importPath}@v${extensionVersion};\n${e}`);
+			console.log('falling back to install the dev version packaged in the extension');
+		}
+	}
+	// build from the source included in vsix or test extension.
+	const args = ['install', '.'];
+	await execFile(getBinPath('go'), args, { cwd, env }); // throw error in case of failure.
+	return progPath;
+}

src/goMain.ts

@@ -8,7 +8,7 @@
 
 'use strict';
 
-import { getGoConfig } from './config';
+import { extensionInfo, getGoConfig } from './config';
 import { browsePackages } from './goBrowsePackage';
 import { buildCode } from './goBuild';
 import { notifyIfGeneratedFile, removeTestStatus } from './goCheck';
@@ -32,15 +32,21 @@ import * as goGenerateTests from './goGenerateTests';
 import { goGetPackage } from './goGetPackage';
 import { addImport, addImportToWorkspace } from './goImport';
 import { installCurrentPackage } from './goInstall';
-import { offerToInstallTools, promptForMissingTool, updateGoVarsFromConfig, suggestUpdates } from './goInstallTools';
+import {
+	offerToInstallTools,
+	promptForMissingTool,
+	updateGoVarsFromConfig,
+	suggestUpdates,
+	installVSCGO
+} from './goInstallTools';
 import { RestartReason, showServerOutputChannel, watchLanguageServerConfiguration } from './language/goLanguageServer';
 import { lintCode } from './goLint';
 import { setLogConfig } from './goLogging';
 import { GO_MODE } from './goMode';
-import { GO111MODULE, goModInit, isModSupported } from './goModules';
+import { GO111MODULE, goModInit } from './goModules';
 import { playgroundCommand } from './goPlayground';
 import { GoRunTestCodeLensProvider } from './goRunTestCodelens';
-import { disposeGoStatusBar, expandGoStatusBar, outputChannel, updateGoStatusBar } from './goStatus';
+import { disposeGoStatusBar, expandGoStatusBar, updateGoStatusBar } from './goStatus';
 
 import { vetCode } from './goVet';
 import {
@@ -52,7 +58,7 @@ import {
 	updateGlobalState
 } from './stateUtils';
 import { cancelRunningTests, showTestOutput } from './testUtils';
-import { cleanupTempDir, getBinPath, getToolsGopath, isGoPathSet } from './util';
+import { cleanupTempDir, getBinPath, getToolsGopath } from './util';
 import { clearCacheForTools } from './utils/pathUtils';
 import { WelcomePanel } from './welcome';
 import vscode = require('vscode');
@@ -67,6 +73,7 @@ import { GoExtensionContext } from './context';
 import * as commands from './commands';
 import { toggleVulncheckCommandFactory } from './goVulncheck';
 import { GoTaskProvider } from './goTaskProvider';
+import { telemetryReporter } from './goTelemetry';
 
 const goCtx: GoExtensionContext = {};
 
@@ -76,6 +83,7 @@ export async function activate(ctx: vscode.ExtensionContext): Promise<ExtensionA
 		return;
 	}
 
+	const start = Date.now();
 	setGlobalState(ctx.globalState);
 	setWorkspaceState(ctx.workspaceState);
 	setEnvironmentVariableCollection(ctx.environmentVariableCollection);
@@ -96,6 +104,18 @@ export async function activate(ctx: vscode.ExtensionContext): Promise<ExtensionA
 
 	await updateGoVarsFromConfig(goCtx);
 
+	// for testing or development mode, always rebuild vscgo.
+	const forceInstall = ctx.extensionMode !== vscode.ExtensionMode.Production;
+	installVSCGO(
+		ctx.extension.id,
+		extensionInfo.version || '',
+		ctx.extensionPath,
+		extensionInfo.isPreview,
+		forceInstall
+	)
+		.then((path) => telemetryReporter.setTool(path))
+		.catch((reason) => console.error(reason));
+
 	suggestUpdates();
 	offerToInstallLatestGoVersion();
 	offerToInstallTools();
@@ -201,16 +221,35 @@ export async function activate(ctx: vscode.ExtensionContext): Promise<ExtensionA
 
 	registerCommand('go.vulncheck.toggle', toggleVulncheckCommandFactory);
 
+	telemetryReporter.add(activationLatency(Date.now() - start), 1);
+
 	return extensionAPI;
 }
 
+function activationLatency(duration: number): string {
+	// TODO: generalize and move to goTelemetry.ts
+	let bucket = '>=5s';
+
+	if (duration < 100) {
+		bucket = '<100ms';
+	} else if (duration < 500) {
+		bucket = '<500ms';
+	} else if (duration < 1000) {
+		bucket = '<1s';
+	} else if (duration < 5000) {
+		bucket = '<5s';
+	}
+	return 'activation_latency:' + bucket;
+}
+
 export function deactivate() {
 	return Promise.all([
 		goCtx.languageClient?.stop(),
 		cancelRunningTests(),
 		killRunningPprof(),
 		Promise.resolve(cleanupTempDir()),
-		Promise.resolve(disposeGoStatusBar())
+		Promise.resolve(disposeGoStatusBar()),
+		telemetryReporter.dispose()
 	]);
 }
 

src/goTelemetry.ts

@@ -9,6 +9,9 @@ import { createHash } from 'crypto';
 import { ExecuteCommandRequest } from 'vscode-languageserver-protocol';
 import { daysBetween } from './goSurvey';
 import { LanguageClient } from 'vscode-languageclient/node';
+import * as cp from 'child_process';
+import { getWorkspaceFolderPath } from './util';
+import { toolExecutionEnvironment } from './goEnv';
 
 // Name of the prompt telemetry command. This is also used to determine if the gopls instance supports telemetry.
 // Exported for testing.
@@ -18,6 +21,121 @@ export const GOPLS_MAYBE_PROMPT_FOR_TELEMETRY = 'gopls.maybe_prompt_for_telemetr
 // Exported for testing.
 export const TELEMETRY_START_TIME_KEY = 'telemetryStartTime';
 
+enum ReporterState {
+	NOT_INITIALIZED,
+	IDLE,
+	STARTING,
+	RUNNING
+}
+
+// exported for testing.
+export class TelemetryReporter implements vscode.Disposable {
+	private _state = ReporterState.NOT_INITIALIZED;
+	private _counters: { [key: string]: number } = {};
+	private _flushTimer: NodeJS.Timeout | undefined;
+	private _tool = '';
+	constructor(flushIntervalMs = 60_000, private counterFile: string = '') {
+		if (flushIntervalMs > 0) {
+			// periodically call flush.
+			this._flushTimer = setInterval(this.flush.bind(this), flushIntervalMs);
+		}
+	}
+
+	public setTool(tool: string) {
+		// allow only once.
+		if (tool === '' || this._state !== ReporterState.NOT_INITIALIZED) {
+			return;
+		}
+		this._state = ReporterState.IDLE;
+		this._tool = tool;
+	}
+
+	public add(key: string, value: number) {
+		if (value <= 0) {
+			return;
+		}
+		key = key.replace(/[\s\n]/g, '_');
+		this._counters[key] = (this._counters[key] || 0) + value;
+	}
+
+	// flush is called periodically (by the callback set up in the constructor)
+	// or when the extension is deactivated (with force=true).
+	public async flush(force = false) {
+		// If flush runs with force=true, ignore the state and skip state update.
+		if (!force && this._state !== ReporterState.IDLE) {
+			// vscgo is not installed yet or is running. flush next time.
+			return 0;
+		}
+		if (!force) {
+			this._state = ReporterState.STARTING;
+		}
+		try {
+			await this.writeGoTelemetry();
+		} catch (e) {
+			console.log(`failed to flush telemetry data: ${e}`);
+		} finally {
+			if (!force) {
+				this._state = ReporterState.IDLE;
+			}
+		}
+	}
+
+	private writeGoTelemetry() {
+		const data = Object.entries(this._counters);
+		if (data.length === 0) {
+			return;
+		}
+		this._counters = {};
+
+		let stderr = '';
+		return new Promise<number | null>((resolve, reject) => {
+			const env = toolExecutionEnvironment();
+			if (this.counterFile !== '') {
+				env['TELEMETRY_COUNTER_FILE'] = this.counterFile;
+			}
+			const p = cp.spawn(this._tool, ['inc_counters'], {
+				cwd: getWorkspaceFolderPath(),
+				env
+			});
+
+			p.stderr.on('data', (data) => {
+				stderr += data;
+			});
+
+			// 'close' fires after exit or error when the subprocess closes all stdio.
+			p.on('close', (exitCode, signal) => {
+				if (exitCode > 0) {
+					reject(`exited with code=${exitCode} signal=${signal} stderr=${stderr}`);
+				} else {
+					resolve(exitCode);
+				}
+			});
+			// Stream key/value to the vscgo process.
+			data.forEach(([key, value]) => {
+				p.stdin.write(`${key} ${value}\n`);
+			});
+			p.stdin.end();
+		});
+	}
+
+	public async dispose() {
+		if (this._flushTimer) {
+			clearInterval(this._flushTimer);
+		}
+		this._flushTimer = undefined;
+		await this.flush(true); // flush any remaining data in buffer.
+	}
+}
+
+// global telemetryReporter instance.
+export const telemetryReporter = new TelemetryReporter();
+
+// TODO(hyangah): consolidate the list of all the telemetries and bucketting functions.
+
+export function addTelemetryEvent(name: string, count: number) {
+	telemetryReporter.add(name, count);
+}
+
 // Go extension delegates most of the telemetry logic to gopls.
 // TelemetryService provides API to interact with gopls's telemetry.
 export class TelemetryService {

src/goToolsInformation.ts

@@ -103,10 +103,10 @@ export const allToolsInformation: { [key: string]: Tool } = {
 		description: 'Language Server from Google',
 		usePrereleaseInPreviewMode: true,
 		minimumGoVersion: semver.coerce('1.18'),
-		latestVersion: semver.parse('v0.14.1'),
-		latestVersionTimestamp: moment('2023-10-26', 'YYYY-MM-DD'),
-		latestPrereleaseVersion: semver.parse('v0.14.1'),
-		latestPrereleaseVersionTimestamp: moment('2023-10-26', 'YYYY-MM-DD')
+		latestVersion: semver.parse('v0.14.2'),
+		latestVersionTimestamp: moment('2023-11-14', 'YYYY-MM-DD'),
+		latestPrereleaseVersion: semver.parse('v0.14.2'),
+		latestPrereleaseVersionTimestamp: moment('2023-11-14', 'YYYY-MM-DD')
 	},
 	'dlv': {
 		name: 'dlv',
@@ -118,5 +118,14 @@ export const allToolsInformation: { [key: string]: Tool } = {
 		latestVersion: semver.parse('v1.8.3'),
 		latestVersionTimestamp: moment('2022-04-26', 'YYYY-MM-DD'),
 		minimumGoVersion: semver.coerce('1.18')
+	},
+	'vscgo': {
+		name: 'vscgo',
+		importPath: 'github.com/golang/vscode-go/vscgo',
+		modulePath: 'github.com/golang/vscode-go/vscgo',
+		replacedByGopls: false,
+		isImportant: true,
+		description: 'VS Code Go helper program',
+		minimumGoVersion: semver.coerce('1.18')
 	}
 };

test/gopls/telemetry.test.ts

@@ -6,8 +6,21 @@
 
 import * as sinon from 'sinon';
 import { describe, it } from 'mocha';
-import { GOPLS_MAYBE_PROMPT_FOR_TELEMETRY, TELEMETRY_START_TIME_KEY, TelemetryService } from '../../src/goTelemetry';
+import {
+	GOPLS_MAYBE_PROMPT_FOR_TELEMETRY,
+	TELEMETRY_START_TIME_KEY,
+	TelemetryReporter,
+	TelemetryService
+} from '../../src/goTelemetry';
 import { MockMemento } from '../mocks/MockMemento';
+import { installVSCGO } from '../../src/goInstallTools';
+import assert from 'assert';
+import path from 'path';
+import * as fs from 'fs-extra';
+import os = require('os');
+import { rmdirRecursive } from '../../src/util';
+import { extensionId } from '../../src/const';
+import { executableFileExists, fileExists } from '../../src/utils/pathUtils';
 
 describe('# prompt for telemetry', () => {
 	it(
@@ -157,3 +170,66 @@ function testTelemetryPrompt(tc: testCase, wantPrompt: boolean) {
 		}
 	};
 }
+
+describe('# telemetry reporter using vscgo', async () => {
+	// installVSCGO expects
+	//   {extensionPath}/vscgo: vscgo source code for testing.
+	//   {extensionPath}/bin: where compiled vscgo will be stored.
+	// During testing, extensionDevelopmentPath is the root of the extension.
+	// __dirname = out/test/gopls.
+	const extensionDevelopmentPath = path.resolve(__dirname, '../../..');
+	const tmpDir = fs.mkdtempSync(path.join(os.tmpdir(), 'telemetryReporter'));
+	const counterfile = path.join(tmpDir, 'counterfile.txt');
+	const sut = new TelemetryReporter(0, counterfile);
+	let vscgo: string;
+
+	suiteSetup(async () => {
+		try {
+			vscgo = await installVSCGO(
+				extensionId,
+				'',
+				extensionDevelopmentPath,
+				true /*isPreview*/,
+				true /* force install */
+			);
+		} catch (e) {
+			assert.fail(`failed to install vscgo needed for testing: ${e}`);
+		}
+	});
+	suiteTeardown(() => {
+		rmdirRecursive(tmpDir);
+		if (executableFileExists(vscgo)) {
+			fs.unlink(vscgo);
+		}
+	});
+
+	teardown(() => {
+		if (fileExists(counterfile)) {
+			fs.unlink(counterfile);
+		}
+	});
+
+	it('add succeeds before telemetryReporter.setTool runs', () => {
+		sut.add('hello', 1);
+		sut.add('world', 2);
+	});
+
+	it('flush is noop before setTool', async () => {
+		await sut.flush();
+		assert(!fileExists(counterfile), 'counterfile exists');
+	});
+
+	it('flush writes accumulated counters after setTool', async () => {
+		sut.setTool(vscgo);
+		await sut.flush();
+		const readAll = fs.readFileSync(counterfile).toString();
+		assert(readAll.includes('hello 1\n') && readAll.includes('world 2\n'), readAll);
+	});
+
+	it('dispose triggers flush', async () => {
+		sut.add('bye', 3);
+		await sut.dispose();
+		const readAll = fs.readFileSync(counterfile).toString();
+		assert(readAll.includes('bye 3\n'), readAll);
+	});
+});

tools/allTools.ts.in

@@ -116,5 +116,14 @@ export const allToolsInformation: { [key: string]: Tool } = {
 		latestVersion: semver.parse('v1.8.3'),
 		latestVersionTimestamp: moment('2022-04-26', 'YYYY-MM-DD'),
 		minimumGoVersion: semver.coerce('1.18')
+	},
+	'vscgo': {
+		name: 'vscgo',
+		importPath: 'github.com/golang/vscode-go/vscgo',
+		modulePath: 'github.com/golang/vscode-go/vscgo',
+		replacedByGopls: false,
+		isImportant: true,
+		description: 'VS Code Go helper program',
+		minimumGoVersion: semver.coerce('1.18')
 	}
 };

vscgo/main.go

@@ -153,9 +153,27 @@ func help(name string) {
 // runIncCounters increments telemetry counters read from stdin.
 func runIncCounters(_ []string) error {
 	scanner := bufio.NewScanner(os.Stdin)
+	if counterFile := os.Getenv("TELEMETRY_COUNTER_FILE"); counterFile != "" {
+		return printCounter(counterFile, scanner)
+	}
 	return runIncCountersImpl(scanner, counter.Add)
 }
 
+func printCounter(fname string, scanner *bufio.Scanner) (rerr error) {
+	f, err := os.OpenFile(fname, os.O_CREATE|os.O_WRONLY|os.O_APPEND, 0644)
+	if err != nil {
+		return err
+	}
+	defer func() {
+		if err := f.Close(); rerr == nil {
+			rerr = err
+		}
+	}()
+	return runIncCountersImpl(scanner, func(name string, count int64) {
+		fmt.Fprintln(f, name, count)
+	})
+}
+
 const (
 	incCountersBadInput = "inc_counters_bad_input"
 )