Skip to content

Add telemetry for download, extract, and analyze. #2597

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Merged
merged 11 commits into from
Sep 18, 2018
Merged
Show file tree
Hide file tree
Changes from 9 commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
2 changes: 1 addition & 1 deletion .gitignore
Original file line number Diff line number Diff line change
Expand Up @@ -12,7 +12,7 @@ npm-debug.log
!yarn.lock
coverage/
.vscode-test/**
.venv
.venv*/
pythonFiles/experimental/ptvsd/**
debug_coverage*/**
languageServer/**
Expand Down
1 change: 1 addition & 0 deletions news/1 Enhancements/2461.md
Original file line number Diff line number Diff line change
@@ -0,0 +1 @@
Add telemetry to download, extract, and analyze, phases of the Python Language Server
1 change: 1 addition & 0 deletions news/2 Fixes/2297.md
Original file line number Diff line number Diff line change
@@ -0,0 +1 @@
Stop duplicate initializations of Python Language Server progress reporter.
30 changes: 26 additions & 4 deletions src/client/activation/downloader.ts
Original file line number Diff line number Diff line change
Expand Up @@ -7,8 +7,13 @@ import * as path from 'path';
import * as requestProgress from 'request-progress';
import { ProgressLocation, window } from 'vscode';
import { createDeferred } from '../../utils/async';
import { StopWatch } from '../../utils/stopWatch';
import { IFileSystem } from '../common/platform/types';
import { IExtensionContext, IOutputChannel } from '../common/types';
import { sendTelemetryEvent } from '../telemetry';
import {
PYTHON_LANGUAGE_SERVER_DOWNLOADED
} from '../telemetry/constants';
import { PlatformData, PlatformName } from './platformData';
import { IDownloadFileService } from './types';

Expand All @@ -28,6 +33,7 @@ export const DownloadLinks = {
};

export class LanguageServerDownloader {

constructor(
private readonly output: IOutputChannel,
private readonly fs: IFileSystem,
Expand All @@ -43,19 +49,35 @@ export class LanguageServerDownloader {

public async downloadLanguageServer(context: IExtensionContext): Promise<void> {
const downloadUri = this.getDownloadUri();

const timer: StopWatch = new StopWatch();
let success: boolean = true;
let localTempFilePath = '';

try {
localTempFilePath = await this.downloadFile(downloadUri, 'Downloading Microsoft Python Language Server... ');
// success telemetry for download
success = true;
} catch (err) {

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Why did we go with this approach instead of the decorator?

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

As you can see there's some duplication of code..

Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Because the decorator emits telemetry, and adds timing info. It does not allow for state changes in property values without increasing complexity of the decorator function. I couldn't come up with an appropriate reason for the added complexity.

this.output.appendLine('failed.');
this.output.appendLine(err);
success = false;
throw new Error(err);
} finally {
sendTelemetryEvent(PYTHON_LANGUAGE_SERVER_DOWNLOADED, timer.elapsedTime, { success: success === true });
}

timer.reset();
try {
await this.unpackArchive(context.extensionPath, localTempFilePath);
success = true;
} catch (err) {
this.output.appendLine('failed.');
this.output.appendLine(err);
success = true;
throw new Error(err);
} finally {
if (localTempFilePath.length > 0) {
await this.fs.deleteFile(localTempFilePath);
}
sendTelemetryEvent('DEREK2', timer.elapsedTime, { success: success === true });

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

DEREK2 ?

Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Apologies - this is a WIP at the moment...

await this.fs.deleteFile(localTempFilePath);
}
}

Expand Down
5 changes: 2 additions & 3 deletions src/client/activation/languageServer.ts
Original file line number Diff line number Diff line change
@@ -1,6 +1,8 @@
// Copyright (c) Microsoft Corporation. All rights reserved.
// Licensed under the MIT License.

'use strict';

import { inject, injectable } from 'inversify';
import * as path from 'path';
import {
Expand Down Expand Up @@ -29,7 +31,6 @@ import { IEnvironmentVariablesProvider } from '../common/variables/types';
import { IServiceContainer } from '../ioc/types';
import { LanguageServerSymbolProvider } from '../providers/symbolProvider';
import {
PYTHON_LANGUAGE_SERVER_DOWNLOADED,
PYTHON_LANGUAGE_SERVER_ENABLED,
PYTHON_LANGUAGE_SERVER_ERROR
} from '../telemetry/constants';
Expand Down Expand Up @@ -143,7 +144,6 @@ export class LanguageServerExtensionActivator implements IExtensionActivator {

private async startLanguageServer(clientOptions: LanguageClientOptions): Promise<boolean> {
// Determine if we are running MSIL/Universal via dotnet or self-contained app.

const reporter = getTelemetryReporter();
reporter.sendTelemetryEvent(PYTHON_LANGUAGE_SERVER_ENABLED);

Expand All @@ -164,7 +164,6 @@ export class LanguageServerExtensionActivator implements IExtensionActivator {
new RequestWithProxy(this.workspace.getConfiguration('http').get('proxy', '')),
languageServerFolder);
await downloader.downloadLanguageServer(this.context);
reporter.sendTelemetryEvent(PYTHON_LANGUAGE_SERVER_DOWNLOADED);
}

const serverModule = path.join(this.context.extensionPath, languageServerFolder, this.platformData.getEngineExecutableName());
Expand Down
39 changes: 39 additions & 0 deletions src/client/activation/progress.ts
Original file line number Diff line number Diff line change
Expand Up @@ -4,11 +4,18 @@
import { Progress, ProgressLocation, window } from 'vscode';
import { Disposable, LanguageClient } from 'vscode-languageclient';
import { createDeferred, Deferred } from '../../utils/async';
import { StopWatch } from '../../utils/stopWatch';
import { sendTelemetryEvent } from '../telemetry';
import { PYTHON_LANGUAGE_SERVER_ANALYSISTIME } from '../telemetry/constants';
import { LanguageServerTelemetry } from '../telemetry/types';

export class ProgressReporting {
private statusBarMessage: Disposable | undefined;
private progress: Progress<{ message?: string; increment?: number }> | undefined;
private progressDeferred: Deferred<void> | undefined;
private progressTimer: StopWatch | undefined;
private progressTimeout: NodeJS.Timer | undefined;
private ANALYSIS_TIMEOUT_MS: number = 60000;

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This needs to be a constant, not a member.

Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Agreed. I will make the change. Thanks for calling this out!


constructor(private readonly languageClient: LanguageClient) {
this.languageClient.onNotification('python/setStatusBarMessage', (m: string) => {
Expand All @@ -19,7 +26,14 @@ export class ProgressReporting {
});

this.languageClient.onNotification('python/beginProgress', async _ => {
if (this.progressDeferred) { // if we restarted, no worries as reporting will still funnel to the same place.
Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This is the fix for #2297 and related...

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

For #2297 (while most of the problem is not here, restart is rare) you need to track 'stateChange' on the language client. When it gets to 'stopped' LS has terminated.

Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Cool! Thanks for the tip. I'll move this code to another PR that we can review separately and cover all the appropriate cases.

Copy link
Author

@d3r3kk d3r3kk Sep 17, 2018

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@MikhailArkhipov please see #2606

return;
}

this.progressDeferred = createDeferred<void>();
this.progressTimer = new StopWatch();
this.progressTimeout = setTimeout(this.handleTimeout, this.ANALYSIS_TIMEOUT_MS);

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Change to setTimeout(this.handleTimeout.bind(this), .....
You need to preserve callback scope.

Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Cool - that callback scope still isn't always clear to me, thanks for catching this.

window.withProgress({
location: ProgressLocation.Window,
title: ''
Expand All @@ -40,7 +54,32 @@ export class ProgressReporting {
if (this.progressDeferred) {
this.progressDeferred.resolve();
this.progressDeferred = undefined;
this.completeAnalysisTracking(true);
this.progress = undefined;
}
});
}

private completeAnalysisTracking(isSuccess: boolean): void {
if (this.progressTimer) {
const lsAnalysisTelemetry: LanguageServerTelemetry = {
success: isSuccess
};
sendTelemetryEvent(
PYTHON_LANGUAGE_SERVER_ANALYSISTIME,
this.progressTimer.elapsedTime,
lsAnalysisTelemetry
);
this.progressTimer = undefined;
}

if (this.progressTimeout) {
this.progressTimeout = undefined;
}
}

// tslint:disable-next-line:no-any
private handleTimeout(_args: any[]): void {
this.completeAnalysisTracking(false);
}
}
2 changes: 2 additions & 0 deletions src/client/common/constants.ts
Original file line number Diff line number Diff line change
Expand Up @@ -6,6 +6,8 @@ export const PYTHON = [
{ scheme: 'untitled', language: PYTHON_LANGUAGE }
];

export const PVSC_EXTENSION_ID = 'ms-python.python';

export namespace Commands {
export const Set_Interpreter = 'python.setInterpreter';
export const Set_ShebangInterpreter = 'python.setShebangInterpreter';
Expand Down
3 changes: 3 additions & 0 deletions src/client/telemetry/constants.ts
Original file line number Diff line number Diff line change
Expand Up @@ -32,9 +32,12 @@ export const UNITTEST_STOP = 'UNITTEST.STOP';
export const UNITTEST_RUN = 'UNITTEST.RUN';
export const UNITTEST_DISCOVER = 'UNITTEST.DISCOVER';
export const UNITTEST_VIEW_OUTPUT = 'UNITTEST.VIEW_OUTPUT';
export const PYTHON_LANGUAGE_SERVER_ANALYSISTIME = 'PYTHON_LANGUAGE_SERVER.ANALYSIS_TIME';
export const PYTHON_LANGUAGE_SERVER_ENABLED = 'PYTHON_LANGUAGE_SERVER.ENABLED';
export const PYTHON_LANGUAGE_SERVER_EXTRACTED = 'PYTHON_LANGUAGE_SERVER.EXTRACTED';
export const PYTHON_LANGUAGE_SERVER_DOWNLOADED = 'PYTHON_LANGUAGE_SERVER.DOWNLOADED';
export const PYTHON_LANGUAGE_SERVER_ERROR = 'PYTHON_LANGUAGE_SERVER.ERROR';
export const PYTHON_LANGUAGE_SERVER_STARTUP = 'PYTHON_LANGUAGE_SERVER.STARTUP';
export const PYTHON_LANGUAGE_SERVER_PLATFORM_NOT_SUPPORTED = 'PYTHON_LANGUAGE_SERVER.PLATFORM_NOT_SUPPORTED';

export const TERMINAL_CREATE = 'TERMINAL.CREATE';
7 changes: 6 additions & 1 deletion src/client/telemetry/index.ts
Original file line number Diff line number Diff line change
Expand Up @@ -26,7 +26,11 @@ export function sendTelemetryEvent(eventName: string, durationMs?: number, prope
}

// tslint:disable-next-line:no-any function-name
export function captureTelemetry(eventName: string, properties?: TelemetryProperties, captureDuration: boolean = true) {
export function captureTelemetry(
eventName: string,
properties?: TelemetryProperties,
captureDuration: boolean = true
) {
// tslint:disable-next-line:no-function-expression no-any
return function (target: Object, propertyKey: string, descriptor: TypedPropertyDescriptor<any>) {
const originalMethod = descriptor.value;
Expand All @@ -53,6 +57,7 @@ export function captureTelemetry(eventName: string, properties?: TelemetryProper
})
// tslint:disable-next-line:promise-function-async
.catch(ex => {
// tslint:disable-next-line:no-any
sendTelemetryEvent(eventName, stopWatch.elapsedTime, properties);
return Promise.reject(ex);
});
Expand Down
3 changes: 2 additions & 1 deletion src/client/telemetry/telemetry.ts
Original file line number Diff line number Diff line change
Expand Up @@ -8,14 +8,15 @@
import { extensions } from 'vscode';
// tslint:disable-next-line:import-name
import TelemetryReporter from 'vscode-extension-telemetry';
import { PVSC_EXTENSION_ID } from '../common/constants';

// tslint:disable-next-line:no-any
let telemetryReporter: TelemetryReporter;
export function getTelemetryReporter() {
if (telemetryReporter) {
return telemetryReporter;
}
const extensionId = 'ms-python.python';
const extensionId = PVSC_EXTENSION_ID;
// tslint:disable-next-line:no-non-null-assertion
const extension = extensions.getExtension(extensionId)!;
// tslint:disable-next-line:no-unsafe-any
Expand Down
17 changes: 16 additions & 1 deletion src/client/telemetry/types.ts
Original file line number Diff line number Diff line change
Expand Up @@ -15,6 +15,10 @@ export type FormatTelemetry = {
formatSelection: boolean;
};

export type LanguageServerTelemetry = {
success: boolean;
};

export type LinterTrigger = 'auto' | 'save';

export type LintingTelemetry = {
Expand Down Expand Up @@ -81,4 +85,15 @@ export type TerminalTelemetry = {
pythonVersion?: string;
interpreterType?: InterpreterType;
};
export type TelemetryProperties = FormatTelemetry | LintingTelemetry | EditorLoadTelemetry | PythonInterpreterTelemetry | CodeExecutionTelemetry | TestRunTelemetry | TestDiscoverytTelemetry | FeedbackTelemetry | TerminalTelemetry | DebuggerTelemetryV2 | SettingsTelemetry;
export type TelemetryProperties = FormatTelemetry
| LanguageServerTelemetry
| LintingTelemetry
| EditorLoadTelemetry
| PythonInterpreterTelemetry
| CodeExecutionTelemetry
| TestRunTelemetry
| TestDiscoverytTelemetry
| FeedbackTelemetry
| TerminalTelemetry
| DebuggerTelemetryV2
| SettingsTelemetry;
3 changes: 2 additions & 1 deletion src/test/aaFirstTest/aaFirstTest.test.ts
Original file line number Diff line number Diff line change
Expand Up @@ -3,6 +3,7 @@

import { expect } from 'chai';
import { extensions } from 'vscode';
import { PVSC_EXTENSION_ID } from '../../client/common/constants';
import { initialize } from '../initialize';

// NOTE:
Expand All @@ -17,6 +18,6 @@ suite('Activate Extension', () => {
await initialize();
});
test('Python extension has activated', async () => {
expect(extensions.getExtension('ms-python.python')!.isActive).to.equal(true, 'Extension has not been activated');
expect(extensions.getExtension(PVSC_EXTENSION_ID)!.isActive).to.equal(true, 'Extension has not been activated');
});
});
3 changes: 2 additions & 1 deletion src/test/initialize.ts
Original file line number Diff line number Diff line change
Expand Up @@ -4,6 +4,7 @@ import * as path from 'path';
import * as vscode from 'vscode';
import { IExtensionApi } from '../client/api';
import { PythonSettings } from '../client/common/configSettings';
import { PVSC_EXTENSION_ID } from '../client/common/constants';
import { clearPythonPathInWorkspaceFolder, PYTHON_PATH, resetGlobalPythonPathSetting, setPythonPathInWorkspaceRoot } from './common';

export * from './constants';
Expand Down Expand Up @@ -32,7 +33,7 @@ export async function initialize(): Promise<any> {
PythonSettings.dispose();
}
export async function activateExtension() {
const extension = vscode.extensions.getExtension<IExtensionApi>('ms-python.python')!;
const extension = vscode.extensions.getExtension<IExtensionApi>(PVSC_EXTENSION_ID)!;
if (extension.isActive) {
return;
}
Expand Down
3 changes: 2 additions & 1 deletion src/test/performance/load.perf.test.ts
Original file line number Diff line number Diff line change
Expand Up @@ -10,6 +10,7 @@ import * as fs from 'fs-extra';
import { EOL } from 'os';
import * as path from 'path';
import { commands, extensions } from 'vscode';
import { PVSC_EXTENSION_ID } from '../../client/common/constants';
import { StopWatch } from '../../utils/stopWatch';

const AllowedIncreaseInActivationDelayInMS = 500;
Expand All @@ -22,7 +23,7 @@ suite('Activation Times', () => {
return;
}
test(`Capture Extension Activation Times (Version: ${process.env.ACTIVATION_TIMES_EXT_VERSION}, sample: ${sampleCounter})`, async () => {
const pythonExtension = extensions.getExtension('ms-python.python');
const pythonExtension = extensions.getExtension(PVSC_EXTENSION_ID);
if (!pythonExtension) {
throw new Error('Python Extension not found');
}
Expand Down
4 changes: 2 additions & 2 deletions src/test/performanceTest.ts
Original file line number Diff line number Diff line change
Expand Up @@ -19,7 +19,7 @@ import * as download from 'download';
import * as fs from 'fs-extra';
import * as path from 'path';
import * as request from 'request';
import { EXTENSION_ROOT_DIR } from '../client/common/constants';
import { EXTENSION_ROOT_DIR, PVSC_EXTENSION_ID } from '../client/common/constants';

const NamedRegexp = require('named-js-regexp');
const StreamZip = require('node-stream-zip');
Expand Down Expand Up @@ -123,7 +123,7 @@ class TestRunner {
}

private async getReleaseVersion(): Promise<string> {
const url = 'https://marketplace.visualstudio.com/items?itemName=ms-python.python';
const url = `https://marketplace.visualstudio.com/items?itemName=${PVSC_EXTENSION_ID}`;
const content = await new Promise<string>((resolve, reject) => {
request(url, (error, response, body) => {
if (error) {
Expand Down