Add Tests to measure activation times of extension

.gitignore

@@ -19,3 +19,4 @@ analysis/**
 bin/**
 obj/**
 .pytest_cache
+tmp/**

.travis.yml

@@ -27,6 +27,9 @@ matrix:
         - os: linux
           python: "3.6-dev"
           env: MULTIROOT_WORKSPACE_TEST=true
+        - os: linux
+          python: "3.6-dev"
+          env: PERFORMANCE_TEST=true
     allow_failures:
         - os: linux
           python: "2.7"
@@ -111,6 +114,11 @@ script:
   - if [ $TRAVIS_UPLOAD_COVERAGE == "true" ]; then
         bash <(curl -s https://codecov.io/bash);
     fi
+  - if [[ "$TRAVIS_BRANCH" == "master" && "$TRAVIS_PULL_REQUEST" == "false" && "$PERFORMANCE_TEST" == "true" ]]; then
+        yarn run clean;
+        yarn run vscode:prepublish;
+        yarn run testPerformance --silent;
+    fi
   - if [ "$TRAVIS_PYTHON_VERSION" != "2.7" ]; then
         python3 -m pip install --upgrade -r news/requirements.txt;
         python3 news/announce.py --dry_run;

.vscodeignore

@@ -45,5 +45,6 @@ requirements.txt
 scripts/**
 src/**
 test/**
+tmp/**
 typings/**
 vsc-extension-quickstart.md

news/3 Code Health/932.md

@@ -0,0 +1 @@
+Create tests to measure activation times for the extension.

package.json

@@ -1853,6 +1853,7 @@
         "testSingleWorkspace": "node ./out/test/standardTest.js",
         "testMultiWorkspace": "node ./out/test/multiRootTest.js",
         "testAnalysisEngine": "node ./out/test/analysisEngineTest.js",
+        "testPerformance": "node ./out/test/performanceTest.js",
         "precommit": "node gulpfile.js",
         "lint-staged": "node gulpfile.js",
         "lint": "tslint src/**/*.ts -t verbose",
@@ -1903,6 +1904,7 @@
         "@types/chai-arrays": "^1.0.2",
         "@types/chai-as-promised": "^7.1.0",
         "@types/del": "^3.0.0",
+        "@types/download": "^6.2.2",
         "@types/dotenv": "^4.0.3",
         "@types/event-stream": "^3.3.33",
         "@types/fs-extra": "^5.0.1",
@@ -1914,6 +1916,7 @@
         "@types/md5": "^2.1.32",
         "@types/mocha": "^2.2.48",
         "@types/node": "^9.4.7",
+        "@types/request": "^2.47.0",
         "@types/semver": "^5.5.0",
         "@types/shortid": "^0.0.29",
         "@types/sinon": "^4.3.0",
@@ -1931,6 +1934,7 @@
         "debounce": "^1.1.0",
         "decache": "^4.4.0",
         "del": "^3.0.0",
+        "download": "^7.0.0",
         "event-stream": "^3.3.4",
         "flat": "^4.0.0",
         "gulp": "^3.9.1",

src/test/index.ts

@@ -3,7 +3,6 @@ if ((Reflect as any).metadata === undefined) {
     // tslint:disable-next-line:no-require-imports no-var-requires
     require('reflect-metadata');
 }
-import { MochaSetupOptions } from 'vscode/lib/testrunner';
 import { IS_CI_SERVER, IS_CI_SERVER_TEST_DEBUGGER, IS_MULTI_ROOT_TEST } from './constants';
 import * as testRunner from './testRunner';
 
@@ -15,15 +14,18 @@ process.env.IS_MULTI_ROOT_TEST = IS_MULTI_ROOT_TEST.toString();
 // So the solution is to run them separately and first on CI.
 const grep = IS_CI_SERVER && IS_CI_SERVER_TEST_DEBUGGER ? 'Debug' : undefined;
 
+const testFilesSuffix = process.env.TEST_FILES_SUFFIX;
+
 // You can directly control Mocha options by uncommenting the following lines.
 // See https://github.com/mochajs/mocha/wiki/Using-mocha-programmatically#set-options for more info.
 // Hack, as retries is not supported as setting in tsd.
-const options: MochaSetupOptions & { retries: number } = {
+const options: testRunner.SetupOptions & { retries: number } = {
     ui: 'tdd',
     useColors: true,
     timeout: 25000,
     retries: 3,
-    grep
+    grep,
+    testFilesSuffix
 };
 testRunner.configure(options, { coverageConfig: '../coverconfig.json' });
 module.exports = testRunner;

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

@@ -0,0 +1,72 @@
+// Copyright (c) Microsoft Corporation. All rights reserved.
+// Licensed under the MIT License.
+
+'use strict';
+
+// tslint:disable:no-invalid-this no-console
+
+import { expect } from 'chai';
+import * as fs from 'fs-extra';
+import { EOL } from 'os';
+import * as path from 'path';
+import { commands, extensions } from 'vscode';
+import { StopWatch } from '../../client/common/stopWatch';
+
+const AllowedIncreaseInActivationDelayInMS = 500;
+
+suite('Activation Times', () => {
+    if (process.env.ACTIVATION_TIMES_LOG_FILE_PATH) {
+        const logFile = process.env.ACTIVATION_TIMES_LOG_FILE_PATH;
+        const sampleCounter = fs.existsSync(logFile) ? fs.readFileSync(logFile, { encoding: 'utf8' }).toString().split(/\r?\n/g).length : 1;
+        if (sampleCounter > 10) {
+            return;
+        }
+        test(`Capture Extension Activation Times (Version: ${process.env.ACTIVATION_TIMES_EXT_VERSION}, sample: ${sampleCounter})`, async () => {
+            const pythonExtension = extensions.getExtension('ms-python.python');
+            if (pythonExtension) {
+                throw new Error('Python Extension not found');
+            }
+            const stopWatch = new StopWatch();
+            await pythonExtension!.activate();
+            const elapsedTime = stopWatch.elapsedTime;
+            if (elapsedTime > 10) {
+                await fs.ensureDir(path.dirname(logFile));
+                await fs.appendFile(logFile, `${elapsedTime}${EOL}`, { encoding: 'utf8' });
+                console.log(`Loaded in ${elapsedTime}ms`);
+            }
+            commands.executeCommand('workbench.action.reloadWindow');
+        });
+    }
+
+    if (process.env.ACTIVATION_TIMES_DEV_LOG_FILE_PATHS &&
+        process.env.ACTIVATION_TIMES_RELEASE_LOG_FILE_PATHS &&
+        process.env.ACTIVATION_TIMES_DEV_ANALYSIS_LOG_FILE_PATHS) {
+
+        test('Test activation times of Dev vs Release Extension', async () => {
+            function getActivationTimes(files: string[]) {
+                const activationTimes: number[] = [];
+                for (const file of files) {
+                    fs.readFileSync(file, { encoding: 'utf8' }).toString()
+                        .split(/\r?\n/g)
+                        .map(line => line.trim())
+                        .filter(line => line.length > 0)
+                        .map(line => parseInt(line, 10))
+                        .forEach(item => activationTimes.push(item));
+                }
+                return activationTimes;
+            }
+            const devActivationTimes = getActivationTimes(JSON.parse(process.env.ACTIVATION_TIMES_DEV_LOG_FILE_PATHS!));
+            const releaseActivationTimes = getActivationTimes(JSON.parse(process.env.ACTIVATION_TIMES_RELEASE_LOG_FILE_PATHS!));
+            const analysisEngineActivationTimes = getActivationTimes(JSON.parse(process.env.ACTIVATION_TIMES_DEV_ANALYSIS_LOG_FILE_PATHS!));
+            const devActivationAvgTime = devActivationTimes.reduce((sum, item) => sum + item, 0) / devActivationTimes.length;
+            const releaseActivationAvgTime = releaseActivationTimes.reduce((sum, item) => sum + item, 0) / releaseActivationTimes.length;
+            const analysisEngineActivationAvgTime = analysisEngineActivationTimes.reduce((sum, item) => sum + item, 0) / analysisEngineActivationTimes.length;
+
+            console.log(`Dev version Loaded in ${devActivationAvgTime}ms`);
+            console.log(`Release version Loaded in ${releaseActivationAvgTime}ms`);
+            console.log(`Analysis Engine Loaded in ${analysisEngineActivationAvgTime}ms`);
+
+            expect(devActivationAvgTime - releaseActivationAvgTime).to.be.lessThan(AllowedIncreaseInActivationDelayInMS, 'Activation times have increased above allowed threshold.');
+        });
+    }
+});

src/test/performance/settings.json

@@ -0,0 +1 @@
+{ "python.jediEnabled": true }

src/test/performanceTest.ts

@@ -0,0 +1,177 @@
+// Copyright (c) Microsoft Corporation. All rights reserved.
+// Licensed under the MIT License.
+
+'use strict';
+
+/*
+Comparing performance metrics is not easy (the metrics can and always get skewed).
+One approach is to run the tests multile times and gather multiple sample data.
+For Extension activation times, we load both extensions x times, and re-load the window y times in each x load.
+I.e. capture averages by giving the extensions sufficient time to warm up.
+This block of code merely launches the tests by using either the dev or release version of the extension,
+and spawning the tests (mimic user starting tests from command line), this way we can run tests multiple times.
+*/
+
+// tslint:disable:no-console no-require-imports no-var-requires
+
+import { spawn } from 'child_process';
+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';
+
+const NamedRegexp = require('named-js-regexp');
+const StreamZip = require('node-stream-zip');
+const del = require('del');
+
+const tmpFolder = path.join(EXTENSION_ROOT_DIR, 'tmp');
+const publishedExtensionPath = path.join(tmpFolder, 'ext', 'testReleaseExtensionsFolder');
+const logFilesPath = path.join(tmpFolder, 'test', 'logs');
+
+enum Version {
+    Dev, Release
+}
+
+class TestRunner {
+    public async start() {
+        await del([path.join(tmpFolder, '**')]);
+        await this.extractLatestExtension(publishedExtensionPath);
+
+        const timesToLoadEachVersion = 3;
+        const devLogFiles: string[] = [];
+        const releaseLogFiles: string[] = [];
+        const newAnalysisEngineLogFiles: string[] = [];
+
+        for (let i = 0; i < timesToLoadEachVersion; i += 1) {
+            await this.enableNewAnalysisEngine(false);
+
+            const devLogFile = path.join(logFilesPath, `dev_loadtimes${i}.txt`);
+            await this.capturePerfTimes(Version.Dev, devLogFile);
+            devLogFiles.push(devLogFile);
+
+            const releaseLogFile = path.join(logFilesPath, `release_loadtimes${i}.txt`);
+            await this.capturePerfTimes(Version.Release, releaseLogFile);
+            releaseLogFiles.push(releaseLogFile);
+
+            // New Analysis engine.
+            await this.enableNewAnalysisEngine(true);
+            const newAnalysisEngineLogFile = path.join(logFilesPath, `newAnalysisEngine_loadtimes${i}.txt`);
+            await this.capturePerfTimes(Version.Release, newAnalysisEngineLogFile);
+            newAnalysisEngineLogFiles.push(newAnalysisEngineLogFile);
+        }
+
+        await this.runPerfTest(devLogFiles, releaseLogFiles, newAnalysisEngineLogFiles);
+    }
+    private async enableNewAnalysisEngine(enable: boolean) {
+        const settings = `{ "python.jediEnabled": ${!enable} }`;
+        await fs.writeFile(path.join(EXTENSION_ROOT_DIR, 'src', 'test', 'performance', 'settings.json'), settings);
+    }
+
+    private async  capturePerfTimes(version: Version, logFile: string) {
+        const releaseVersion = await this.getReleaseVersion();
+        const devVersion = await this.getDevVersion();
+        await fs.ensureDir(path.dirname(logFile));
+        const env: { [key: string]: {} } = {
+            ACTIVATION_TIMES_LOG_FILE_PATH: logFile,
+            ACTIVATION_TIMES_EXT_VERSION: version === Version.Release ? releaseVersion : devVersion,
+            CODE_EXTENSIONS_PATH: version === Version.Release ? publishedExtensionPath : EXTENSION_ROOT_DIR
+        };
+
+        await this.launchTest(env);
+    }
+    private async  runPerfTest(devLogFiles: string[], releaseLogFiles: string[], newAnalysisEngineLogFiles: string[]) {
+        const env: { [key: string]: {} } = {
+            ACTIVATION_TIMES_DEV_LOG_FILE_PATHS: JSON.stringify(devLogFiles),
+            ACTIVATION_TIMES_RELEASE_LOG_FILE_PATHS: JSON.stringify(releaseLogFiles),
+            ACTIVATION_TIMES_DEV_ANALYSIS_LOG_FILE_PATHS: JSON.stringify(newAnalysisEngineLogFiles)
+        };
+
+        await this.launchTest(env);
+    }
+
+    private async  launchTest(customEnvVars: { [key: string]: {} }) {
+        await new Promise((resolve, reject) => {
+            const env: { [key: string]: {} } = {
+                TEST_FILES_SUFFIX: 'perf.test',
+                CODE_TESTS_WORKSPACE: path.join(EXTENSION_ROOT_DIR, 'src', 'test', 'performance'),
+                ...process.env,
+                ...customEnvVars
+            };
+
+            const proc = spawn('node', [path.join(__dirname, 'standardTest.js')], { cwd: EXTENSION_ROOT_DIR, env });
+            proc.stdout.pipe(process.stdout);
+            proc.stderr.pipe(process.stderr);
+            proc.on('error', reject);
+            proc.on('close', code => {
+                if (code === 0) {
+                    resolve();
+                } else {
+                    reject(`Failed with code ${code}.`);
+                }
+            });
+        });
+    }
+
+    private async extractLatestExtension(targetDir: string): Promise<void> {
+        const extensionFile = await this.downloadExtension();
+        await this.unzip(extensionFile, targetDir);
+    }
+
+    private async  getReleaseVersion(): Promise<string> {
+        const url = 'https://marketplace.visualstudio.com/items?itemName=ms-python.python';
+        const content = await new Promise<string>((resolve, reject) => {
+            request(url, (error, response, body) => {
+                if (error) {
+                    return reject(error);
+                }
+                if (response.statusCode === 200) {
+                    return resolve(body);
+                }
+                reject(`Status code of ${response.statusCode} received.`);
+            });
+        });
+        const re = NamedRegexp('"version"\S?:\S?"(:<version>\\d{4}\\.\\d{1,2}\\.\\d{1,2})"', 'g');
+        const matches = re.exec(content);
+        return matches.groups().version;
+    }
+
+    private async  getDevVersion(): Promise<string> {
+        // tslint:disable-next-line:non-literal-require
+        return require(path.join(EXTENSION_ROOT_DIR, 'package.json')).version;
+    }
+
+    private async  unzip(zipFile: string, targetFolder: string): Promise<void> {
+        await fs.ensureDir(targetFolder);
+        return new Promise<void>((resolve, reject) => {
+            const zip = new StreamZip({
+                file: zipFile,
+                storeEntries: true
+            });
+            zip.on('ready', async () => {
+                zip.extract('extension', targetFolder, err => {
+                    if (err) {
+                        reject(err);
+                    } else {
+                        resolve();
+                    }
+                    zip.close();
+                });
+            });
+        });
+    }
+
+    private async downloadExtension(): Promise<string> {
+        const version = await this.getReleaseVersion();
+        const url = `https://marketplace.visualstudio.com/_apis/public/gallery/publishers/ms-python/vsextensions/python/${version}/vspackage`;
+        const destination = path.join(__dirname, `extension${version}.zip`);
+        if (await fs.pathExists(destination)) {
+            return destination;
+        }
+
+        await download(url, path.dirname(destination), { filename: path.basename(destination) });
+        return destination;
+    }
+}
+
+new TestRunner().start().catch(ex => console.error('Error in running Performance Tests', ex));

src/test/standardTest.ts

@@ -2,7 +2,7 @@
 
 import * as path from 'path';
 
-process.env.CODE_TESTS_WORKSPACE = path.join(__dirname, '..', '..', 'src', 'test');
+process.env.CODE_TESTS_WORKSPACE = process.env.CODE_TESTS_WORKSPACE ? process.env.CODE_TESTS_WORKSPACE : path.join(__dirname, '..', '..', 'src', 'test');
 process.env.IS_CI_SERVER_TEST_DEBUGGER = '';
 
 function start() {