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

Fixes #2461 (alternate fix to PR #2593)

Author: d3r3kk

.gitignore

@@ -12,7 +12,7 @@ npm-debug.log
 !yarn.lock
 coverage/
 .vscode-test/**
-.venv
+.venv*/
 pythonFiles/experimental/ptvsd/**
 debug_coverage*/**
 languageServer/**

news/1 Enhancements/2461.md

@@ -0,0 +1 @@
+Add telemetry to download, extract, and analyze, phases of the Python Language Server

news/2 Fixes/2297.md

@@ -0,0 +1 @@
+Stop duplicate initializations of Python Language Server progress reporter.

src/client/activation/downloader.ts

@@ -7,8 +7,14 @@ 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,
+    PYTHON_LANGUAGE_SERVER_EXTRACTED
+} from '../telemetry/constants';
 import { PlatformData, PlatformName } from './platformData';
 import { IDownloadFileService } from './types';
 
@@ -28,6 +34,7 @@ export const DownloadLinks = {
 };
 
 export class LanguageServerDownloader {
+
     constructor(
         private readonly output: IOutputChannel,
         private readonly fs: IFileSystem,
@@ -43,19 +50,40 @@ 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... ');
+        } catch (err) {
+            this.output.appendLine('download failed.');
+            this.output.appendLine(err);
+            success = false;
+            throw new Error(err);
+        } finally {
+            sendTelemetryEvent(
+                PYTHON_LANGUAGE_SERVER_DOWNLOADED,
+                timer.elapsedTime,
+                { success }
+            );
+        }
+
+        timer.reset();
+        try {
             await this.unpackArchive(context.extensionPath, localTempFilePath);
         } catch (err) {
-            this.output.appendLine('failed.');
+            this.output.appendLine('extraction failed.');
             this.output.appendLine(err);
+            success = false;
             throw new Error(err);
         } finally {
-            if (localTempFilePath.length > 0) {
-                await this.fs.deleteFile(localTempFilePath);
-            }
+            sendTelemetryEvent(
+                PYTHON_LANGUAGE_SERVER_EXTRACTED,
+                timer.elapsedTime,
+                { success }
+            );
+            await this.fs.deleteFile(localTempFilePath);
         }
     }
 

src/client/activation/languageServer.ts

@@ -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 {
@@ -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';
@@ -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);
 
@@ -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());

src/client/activation/progress.ts

@@ -4,11 +4,21 @@
 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';
+
+// Draw the line at Language Server analysis 'timing out'
+// and becoming a failure-case at 1 minute:
+const ANALYSIS_TIMEOUT_MS: number = 60000;
 
 export class ProgressReporting {
   private statusBarMessage: Disposable | undefined;
   private progress: Progress<{ message?: string; increment?: number }> | undefined;
   private progressDeferred: Deferred<void> | undefined;
+  private progressTimer?: StopWatch;
+  // tslint:disable-next-line:no-unused-variable
+  private progressTimeout?: NodeJS.Timer;
 
   constructor(private readonly languageClient: LanguageClient) {
     this.languageClient.onNotification('python/setStatusBarMessage', (m: string) => {
@@ -19,7 +29,17 @@ export class ProgressReporting {
     });
 
     this.languageClient.onNotification('python/beginProgress', async _ => {
+      if (this.progressDeferred) {
+        return;
+      }
+
       this.progressDeferred = createDeferred<void>();
+      this.progressTimer = new StopWatch();
+      this.progressTimeout = setTimeout(
+        this.handleTimeout.bind(this),
+        ANALYSIS_TIMEOUT_MS
+      );
+
       window.withProgress({
         location: ProgressLocation.Window,
         title: ''
@@ -40,7 +60,26 @@ export class ProgressReporting {
       if (this.progressDeferred) {
         this.progressDeferred.resolve();
         this.progressDeferred = undefined;
+        this.progress = undefined;
+        this.completeAnalysisTracking(true);
       }
     });
   }
+
+  private completeAnalysisTracking(success: boolean): void {
+    if (this.progressTimer) {
+      sendTelemetryEvent(
+        PYTHON_LANGUAGE_SERVER_ANALYSISTIME,
+        this.progressTimer.elapsedTime,
+        { success }
+      );
+    }
+    this.progressTimer = undefined;
+    this.progressTimeout = undefined;
+  }
+
+  // tslint:disable-next-line:no-any
+  private handleTimeout(_args: any[]): void {
+    this.completeAnalysisTracking(false);
+  }
 }

src/client/common/constants.ts

@@ -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';

src/client/telemetry/constants.ts

@@ -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';

src/client/telemetry/index.ts

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

src/client/telemetry/telemetry.ts

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

src/client/telemetry/types.ts

@@ -15,6 +15,10 @@ export type FormatTelemetry = {
     formatSelection: boolean;
 };
 
+export type LanguageServerTelemetry = {
+    success: boolean;
+};
+
 export type LinterTrigger = 'auto' | 'save';
 
 export type LintingTelemetry = {
@@ -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;

src/test/aaFirstTest/aaFirstTest.test.ts

@@ -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:
@@ -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');
     });
 });

src/test/initialize.ts

@@ -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';
@@ -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;
     }

src/test/performance/load.perf.test.ts

@@ -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;
@@ -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');
             }

src/test/performanceTest.ts

@@ -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');
@@ -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) {