diff --git a/test/automation/src/application.ts b/test/automation/src/application.ts index 4a58db4aa80..0b2bbedee05 100644 --- a/test/automation/src/application.ts +++ b/test/automation/src/application.ts @@ -7,7 +7,7 @@ import * as fs from 'fs'; import * as path from 'path'; import { Workbench } from './workbench'; import { Code, spawn, SpawnOptions } from './code'; -import { Logger } from './logger'; +import { Logger, measureAndLog } from './logger'; export const enum Quality { Dev, @@ -94,7 +94,7 @@ export class Application { async captureScreenshot(name: string): Promise { if (this.options.screenshotsPath) { - const raw = await this.code.capturePage(); + const raw = await measureAndLog(this.code.capturePage(), 'capturePage', this.options.logger); const buffer = Buffer.from(raw, 'base64'); const screenshotPath = path.join(this.options.screenshotsPath, `${name}.png`); this.logger.log('Screenshot recorded:', screenshotPath); diff --git a/test/automation/src/code.ts b/test/automation/src/code.ts index 0e30e8a1690..ac138b770de 100644 --- a/test/automation/src/code.ts +++ b/test/automation/src/code.ts @@ -9,7 +9,7 @@ import * as cp from 'child_process'; import { IDriver, IDisposable, IElement, Thenable, ILocalizedStrings, ILocaleInfo } from './driver'; import { launch as launchElectron } from './electronDriver'; import { launch as launchPlaywright } from './playwrightDriver'; -import { Logger } from './logger'; +import { Logger, measureAndLog } from './logger'; import { copyExtension } from './extensions'; const repoPath = path.join(__dirname, '../../..'); @@ -39,7 +39,7 @@ export async function spawn(options: SpawnOptions): Promise { throw new Error('Smoke test process has terminated, refusing to spawn Code'); } - await copyExtension(repoPath, options.extensionsPath, 'vscode-notebook-tests'); + await measureAndLog(copyExtension(repoPath, options.extensionsPath, 'vscode-notebook-tests'), 'copyExtension(vscode-notebook-tests)', options.logger); // Browser smoke tests if (options.web) { @@ -135,12 +135,16 @@ export class Code { async startTracing(name: string): Promise { const windowId = await this.getActiveWindowId(); - return await this.driver.startTracing(windowId, name); + if (typeof this.driver.startTracing === 'function') { // added only in 1.64 + return await this.driver.startTracing(windowId, name); + } } async stopTracing(name: string, persist: boolean): Promise { const windowId = await this.getActiveWindowId(); - return await this.driver.stopTracing(windowId, name, persist); + if (typeof this.driver.stopTracing === 'function') { // added only in 1.64 + return await this.driver.stopTracing(windowId, name, persist); + } } async waitForWindowIds(fn: (windowIds: number[]) => boolean): Promise { @@ -153,7 +157,7 @@ export class Code { } async exit(): Promise { - return new Promise((resolve, reject) => { + return measureAndLog(new Promise((resolve, reject) => { let done = false; // Start the exit flow via driver @@ -190,7 +194,7 @@ export class Code { })(); }).finally(() => { this.dispose(); - }); + }), 'Code#exit()', this.logger); } async waitForTextContent(selector: string, textContent?: string, accept?: (result: string) => boolean, retryCount?: number): Promise { diff --git a/test/automation/src/electronDriver.ts b/test/automation/src/electronDriver.ts index 51f59af2b8d..823b4f0fb42 100644 --- a/test/automation/src/electronDriver.ts +++ b/test/automation/src/electronDriver.ts @@ -13,7 +13,7 @@ import { promisify } from 'util'; import * as kill from 'tree-kill'; import { copyExtension } from './extensions'; import { URI } from 'vscode-uri'; -import { Logger } from './logger'; +import { Logger, measureAndLog } from './logger'; const repoPath = path.join(__dirname, '../../..'); @@ -22,7 +22,7 @@ export async function launch(codePath: string | undefined, userDataDir: string, const logsPath = path.join(repoPath, '.build', 'logs', remote ? 'smoke-tests-remote' : 'smoke-tests'); const outPath = codePath ? getBuildOutPath(codePath) : getDevOutPath(); - const driverIPCHandle = await createDriverHandle(); + const driverIPCHandle = await measureAndLog(createDriverHandle(), 'createDriverHandle', logger); const args = [ workspacePath, @@ -50,7 +50,7 @@ export async function launch(codePath: string | undefined, userDataDir: string, if (codePath) { // running against a build: copy the test resolver extension - await copyExtension(repoPath, extensionsPath, 'vscode-test-resolver'); + await measureAndLog(copyExtension(repoPath, extensionsPath, 'vscode-test-resolver'), 'copyExtension(vscode-test-resolver)', logger); } args.push('--enable-proposed-api=vscode.vscode-test-resolver'); const remoteDataDir = `${userDataDir}-server`; @@ -60,7 +60,7 @@ export async function launch(codePath: string | undefined, userDataDir: string, // running against a build: copy the test resolver extension into remote extensions dir const remoteExtensionsDir = path.join(remoteDataDir, 'extensions'); mkdirp.sync(remoteExtensionsDir); - await copyExtension(repoPath, remoteExtensionsDir, 'vscode-notebook-tests'); + await measureAndLog(copyExtension(repoPath, remoteExtensionsDir, 'vscode-notebook-tests'), 'copyExtension(vscode-notebook-tests)', logger); } env['TESTRESOLVER_DATA_FOLDER'] = remoteDataDir; @@ -109,7 +109,7 @@ export async function launch(codePath: string | undefined, userDataDir: string, while (true) { try { - const { client, driver } = await connectElectronDriver(outPath, driverIPCHandle); + const { client, driver } = await measureAndLog(connectElectronDriver(outPath, driverIPCHandle), 'connectElectronDriver()', logger); return { electronProcess, client, driver }; } catch (err) { @@ -118,7 +118,7 @@ export async function launch(codePath: string | undefined, userDataDir: string, logger.log(`Error connecting driver: ${err}. Giving up...`); try { - await promisify(kill)(electronProcess.pid!); + await measureAndLog(promisify(kill)(electronProcess.pid!), 'Kill Electron after failing to connect', logger); } catch (error) { logger.log(`Error tearing down electron client (pid: ${electronProcess.pid}): ${error}`); } diff --git a/test/automation/src/playwrightDriver.ts b/test/automation/src/playwrightDriver.ts index 73f7543260e..d85f2b9cfe1 100644 --- a/test/automation/src/playwrightDriver.ts +++ b/test/automation/src/playwrightDriver.ts @@ -12,8 +12,7 @@ import { IDriver, IDisposable, IWindowDriver } from './driver'; import { URI } from 'vscode-uri'; import * as kill from 'tree-kill'; import { PageFunction } from 'playwright-core/types/structs'; -import { Logger } from './logger'; -import { measureAndLog } from '.'; +import { Logger, measureAndLog } from './logger'; const width = 1200; const height = 800; @@ -223,7 +222,7 @@ export async function launch(codeServerPath = process.env.VSCODE_REMOTE_SERVER_P async function launchServer(userDataDir: string, codeServerPath: string | undefined, extensionsPath: string, verbose: boolean, logger: Logger) { const agentFolder = userDataDir; - await promisify(mkdir)(agentFolder); + await measureAndLog(promisify(mkdir)(agentFolder), `mkdir(${agentFolder})`, logger); const env = { VSCODE_AGENT_FOLDER: agentFolder, VSCODE_REMOTE_SERVER_PATH: codeServerPath, @@ -271,22 +270,22 @@ async function launchServer(userDataDir: string, codeServerPath: string | undefi return { serverProcess, - endpoint: await waitForEndpoint(serverProcess) + endpoint: await measureAndLog(waitForEndpoint(serverProcess), 'waitForEndpoint(serverProcess)', logger) }; } async function launchBrowser(options: PlaywrightOptions, endpoint: string, workspacePath: string, logger: Logger) { - const browser = await playwright[options.browser ?? 'chromium'].launch({ headless: options.headless ?? false }); - const context = await browser.newContext(); + const browser = await measureAndLog(playwright[options.browser ?? 'chromium'].launch({ headless: options.headless ?? false }), 'playwright#launch', logger); + const context = await measureAndLog(browser.newContext(), 'browser.newContext', logger); try { - await context.tracing.start({ screenshots: true, snapshots: true, sources: true }); + await measureAndLog(context.tracing.start({ screenshots: true, snapshots: true, sources: true }), 'context.tracing.start()', logger); } catch (error) { logger.log(`Failed to start playwright tracing: ${error}`); // do not fail the build when this fails } - const page = await context.newPage(); - await page.setViewportSize({ width, height }); + const page = await measureAndLog(context.newPage(), 'context.newPage()', logger); + await measureAndLog(page.setViewportSize({ width, height }), 'page.setViewportSize', logger); page.on('pageerror', async (error) => logger.log(`Playwright ERROR: page error: ${error}`)); page.on('crash', page => logger.log('Playwright ERROR: page crash')); @@ -297,7 +296,7 @@ async function launchBrowser(options: PlaywrightOptions, endpoint: string, works }); const payloadParam = `[["enableProposedApi",""],["skipWelcome","true"]]`; - await page.goto(`${endpoint}&folder=vscode-remote://localhost:9888${URI.file(workspacePath!).path}&payload=${payloadParam}`); + await measureAndLog(page.goto(`${endpoint}&folder=vscode-remote://localhost:9888${URI.file(workspacePath!).path}&payload=${payloadParam}`), 'page.goto()', logger); return { browser, context, page }; } diff --git a/test/automation/src/terminal.ts b/test/automation/src/terminal.ts index 5813f0215ed..fe2589f726a 100644 --- a/test/automation/src/terminal.ts +++ b/test/automation/src/terminal.ts @@ -3,7 +3,7 @@ * Licensed under the MIT License. See License.txt in the project root for license information. *--------------------------------------------------------------------------------------------*/ -import { QuickInput } from '.'; +import { QuickInput } from './quickinput'; import { Code } from './code'; import { QuickAccess } from './quickaccess'; diff --git a/test/smoke/src/areas/workbench/data-loss.test.ts b/test/smoke/src/areas/workbench/data-loss.test.ts index 24be2f5743e..0521bcb4859 100644 --- a/test/smoke/src/areas/workbench/data-loss.test.ts +++ b/test/smoke/src/areas/workbench/data-loss.test.ts @@ -5,13 +5,14 @@ import { Application, ApplicationOptions, Quality } from '../../../../automation/out'; import { ParsedArgs } from 'minimist'; -import { installCommonAfterHandlers, getRandomUserDataDir, startApp, timeout } from '../../utils'; +import { installCommonAfterHandlers, getRandomUserDataDir, startApp, timeout, installCommonBeforeEachHandler } from '../../utils'; export function setup(opts: ParsedArgs) { describe('Data Loss (insiders -> insiders)', () => { let app: Application | undefined = undefined; + installCommonBeforeEachHandler(); installCommonAfterHandlers(opts, () => app); it('verifies opened editors are restored', async function () { @@ -97,6 +98,7 @@ export function setup(opts: ParsedArgs) { let insidersApp: Application | undefined = undefined; let stableApp: Application | undefined = undefined; + installCommonBeforeEachHandler(); installCommonAfterHandlers(opts, () => insidersApp ?? stableApp, async () => stableApp?.stop()); it('verifies opened editors are restored', async function () { diff --git a/test/smoke/src/areas/workbench/launch.test.ts b/test/smoke/src/areas/workbench/launch.test.ts index dc17c9dc14c..d9e54876fe9 100644 --- a/test/smoke/src/areas/workbench/launch.test.ts +++ b/test/smoke/src/areas/workbench/launch.test.ts @@ -6,13 +6,14 @@ import minimist = require('minimist'); import { join } from 'path'; import { Application } from '../../../../automation'; -import { installCommonAfterHandlers, startApp } from '../../utils'; +import { installCommonAfterHandlers, installCommonBeforeEachHandler, startApp } from '../../utils'; export function setup(args: minimist.ParsedArgs) { describe('Launch', () => { let app: Application | undefined; + installCommonBeforeEachHandler(); installCommonAfterHandlers(args, () => app); it(`verifies that application launches when user data directory has non-ascii characters`, async function () { diff --git a/test/smoke/src/areas/workbench/localization.test.ts b/test/smoke/src/areas/workbench/localization.test.ts index 27ce308a902..ebc6841f473 100644 --- a/test/smoke/src/areas/workbench/localization.test.ts +++ b/test/smoke/src/areas/workbench/localization.test.ts @@ -5,7 +5,7 @@ import minimist = require('minimist'); import { Application, Quality } from '../../../../automation'; -import { installCommonAfterHandlers, startApp } from '../../utils'; +import { installCommonAfterHandlers, installCommonBeforeEachHandler, startApp } from '../../utils'; export function setup(args: minimist.ParsedArgs) { @@ -13,6 +13,7 @@ export function setup(args: minimist.ParsedArgs) { let app: Application | undefined = undefined; + installCommonBeforeEachHandler(); installCommonAfterHandlers(args, () => app); it(`starts with 'DE' locale and verifies title and viewlets text is in German`, async function () { diff --git a/test/smoke/src/main.ts b/test/smoke/src/main.ts index ce06c48fff8..20aec66e4d0 100644 --- a/test/smoke/src/main.ts +++ b/test/smoke/src/main.ts @@ -13,7 +13,7 @@ import * as rimraf from 'rimraf'; import * as mkdirp from 'mkdirp'; import * as vscodetest from 'vscode-test'; import fetch from 'node-fetch'; -import { Quality, ApplicationOptions, MultiLogger, Logger, ConsoleLogger, FileLogger } from '../../automation'; +import { Quality, ApplicationOptions, MultiLogger, Logger, ConsoleLogger, FileLogger, measureAndLog } from '../../automation'; import { timeout } from './utils'; import { setup as setupDataLossTests } from './areas/workbench/data-loss.test'; @@ -216,7 +216,6 @@ async function setupRepository(logger: Logger): Promise { } else { cp.execSync(`cp -R "${opts['test-repo']}" "${workspacePath}"`); } - } else { if (!fs.existsSync(workspacePath)) { logger.log('Cloning test project repository...'); @@ -244,13 +243,13 @@ async function ensureStableCode(logger: Logger): Promise { if (!stableCodePath) { const { major, minor } = parseVersion(version!); const majorMinorVersion = `${major}.${minor - 1}`; - const versionsReq = await fetch('https://update.code.visualstudio.com/api/releases/stable', { headers: { 'x-api-version': '2' } }); + const versionsReq = await measureAndLog(fetch('https://update.code.visualstudio.com/api/releases/stable', { headers: { 'x-api-version': '2' } }), 'versionReq', logger); if (!versionsReq.ok) { throw new Error('Could not fetch releases from update server'); } - const versions: { version: string }[] = await versionsReq.json(); + const versions: { version: string }[] = await measureAndLog(versionsReq.json(), 'versionReq.json()', logger); const prefix = `${majorMinorVersion}.`; const previousVersion = versions.find(v => v.version.startsWith(prefix)); @@ -260,10 +259,10 @@ async function ensureStableCode(logger: Logger): Promise { logger.log(`Found VS Code v${version}, downloading previous VS Code version ${previousVersion.version}...`); - const stableCodeExecutable = await vscodetest.download({ + const stableCodeExecutable = await measureAndLog(vscodetest.download({ cachePath: path.join(os.tmpdir(), 'vscode-test'), version: previousVersion.version - }); + }), 'download stable code', logger); if (process.platform === 'darwin') { // Visual Studio Code.app/Contents/MacOS/Electron @@ -287,8 +286,8 @@ async function setup(logger: Logger): Promise { logger.log('Test data:', testDataPath); logger.log('Preparing smoketest setup...'); - await ensureStableCode(logger); - await setupRepository(logger); + await measureAndLog(ensureStableCode(logger), 'ensureStableCode', logger); + await measureAndLog(setupRepository(logger), 'setupRepository', logger); logger.log('Smoketest setup done!\n'); } @@ -350,7 +349,7 @@ after(async function () { // // Refs: https://github.com/microsoft/vscode/issues/137725 let deleted = false; - await Promise.race([ + await measureAndLog(Promise.race([ new Promise((resolve, reject) => rimraf(testDataPath, { maxBusyTries: 10 }, error => { if (error) { reject(error); @@ -364,9 +363,9 @@ after(async function () { throw new Error('giving up after 30s'); } }) - ]); + ]), 'rimraf(testDataPath)', this.defaultOptions.logger); } catch (error) { - this.options.logger(`Unable to delete smoke test workspace: ${error}. This indicates some process is locking the workspace folder.`); + this.defaultOptions.logger(`Unable to delete smoke test workspace: ${error}. This indicates some process is locking the workspace folder.`); } }); diff --git a/test/smoke/src/utils.ts b/test/smoke/src/utils.ts index 76f465d5081..d4d8eabe634 100644 --- a/test/smoke/src/utils.ts +++ b/test/smoke/src/utils.ts @@ -26,23 +26,20 @@ export function installCommonTestHandlers(args: minimist.ParsedArgs, optionsTran export function installCommonBeforeHandlers(args: minimist.ParsedArgs, optionsTransform?: (opts: ApplicationOptions) => Promise) { before(async function () { - const testTitle = this.currentTest?.title; - - this.app = await startApp(args, this.defaultOptions, async opts => { - opts.testTitle = testTitle; - - if (optionsTransform) { - opts = await optionsTransform(opts); - } - - return opts; - }); + this.app = await startApp(args, this.defaultOptions, optionsTransform); }); + installCommonBeforeEachHandler(); +} + +export function installCommonBeforeEachHandler() { beforeEach(async function () { - if (this.app) { - await this.app.startTracing(this.currentTest?.title); - } + const testTitle = this.currentTest?.title; + this.defaultOptions.logger.log(''); + this.defaultOptions.logger.log(`>>> Test start: ${testTitle} <<<`); + this.defaultOptions.logger.log(''); + + await this.app?.startTracing(testTitle); }); } @@ -58,10 +55,6 @@ export async function startApp(args: minimist.ParsedArgs, options: ApplicationOp await app.start(); - if (options.testTitle) { - app.logger.log('Test start:', options.testTitle); - } - return app; } @@ -98,9 +91,7 @@ export function installCommonAfterHandlers(opts: minimist.ParsedArgs, appFn?: () }); afterEach(async function () { - if (this.app) { - await this.app.stopTracing(this.currentTest?.title, this.currentTest?.state === 'failed'); - } + await this.app?.stopTracing(this.currentTest?.title, this.currentTest?.state === 'failed'); }); }