Skip to content

Commit a444777

Browse files
bpaserobpasero
authored
smoke - fix log and retry exitApplication (microsoft#160244)
1 parent cb6e870 commit a444777

File tree

8 files changed

+71
-56
lines changed

8 files changed

+71
-56
lines changed

‎automation/src/application.ts

Lines changed: 5 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -69,7 +69,7 @@ export class Application {
6969
}
7070

7171
async restart(options?: { workspaceOrFolder?: string; extraArgs?: string[] }): Promise<void> {
72-
await measureAndLog((async () => {
72+
await measureAndLog(() => (async () => {
7373
await this.stop();
7474
await this._start(options?.workspaceOrFolder, options?.extraArgs);
7575
})(), 'Application#restart()', this.logger);
@@ -82,7 +82,7 @@ export class Application {
8282
const code = await this.startApplication(extraArgs);
8383

8484
// ...and make sure the window is ready to interact
85-
await measureAndLog(this.checkWindowReady(code), 'Application#checkWindowReady()', this.logger);
85+
await measureAndLog(() => this.checkWindowReady(code), 'Application#checkWindowReady()', this.logger);
8686
}
8787

8888
async stop(): Promise<void> {
@@ -117,12 +117,12 @@ export class Application {
117117
private async checkWindowReady(code: Code): Promise<void> {
118118

119119
// We need a rendered workbench
120-
await measureAndLog(code.didFinishLoad(), 'Application#checkWindowReady: wait for navigation to be committed', this.logger);
121-
await measureAndLog(code.waitForElement('.monaco-workbench'), 'Application#checkWindowReady: wait for .monaco-workbench element', this.logger);
120+
await measureAndLog(() => code.didFinishLoad(), 'Application#checkWindowReady: wait for navigation to be committed', this.logger);
121+
await measureAndLog(() => code.waitForElement('.monaco-workbench'), 'Application#checkWindowReady: wait for .monaco-workbench element', this.logger);
122122

123123
// Remote but not web: wait for a remote connection state change
124124
if (this.remote) {
125-
await measureAndLog(code.waitForTextContent('.monaco-workbench .statusbar-item[id="status.host"]', undefined, statusHostLabel => {
125+
await measureAndLog(() => code.waitForTextContent('.monaco-workbench .statusbar-item[id="status.host"]', undefined, statusHostLabel => {
126126
this.logger.log(`checkWindowReady: remote indicator text is ${statusHostLabel}`);
127127

128128
// The absence of "Opening Remote" is not a strict

‎automation/src/code.ts

Lines changed: 37 additions & 22 deletions
Original file line numberDiff line numberDiff line change
@@ -76,19 +76,19 @@ export async function launch(options: LaunchOptions): Promise<Code> {
7676
throw new Error('Smoke test process has terminated, refusing to spawn Code');
7777
}
7878

79-
await measureAndLog(copyExtension(rootPath, options.extensionsPath, 'vscode-notebook-tests'), 'copyExtension(vscode-notebook-tests)', options.logger);
79+
await measureAndLog(() => copyExtension(rootPath, options.extensionsPath, 'vscode-notebook-tests'), 'copyExtension(vscode-notebook-tests)', options.logger);
8080

8181
// Browser smoke tests
8282
if (options.web) {
83-
const { serverProcess, driver } = await measureAndLog(launchPlaywrightBrowser(options), 'launch playwright (browser)', options.logger);
83+
const { serverProcess, driver } = await measureAndLog(() => launchPlaywrightBrowser(options), 'launch playwright (browser)', options.logger);
8484
registerInstance(serverProcess, options.logger, 'server');
8585

8686
return new Code(driver, options.logger, serverProcess);
8787
}
8888

8989
// Electron smoke tests (playwright)
9090
else {
91-
const { electronProcess, driver } = await measureAndLog(launchPlaywrightElectron(options), 'launch playwright (electron)', options.logger);
91+
const { electronProcess, driver } = await measureAndLog(() => launchPlaywrightElectron(options), 'launch playwright (electron)', options.logger);
9292
registerInstance(electronProcess, options.logger, 'electron');
9393

9494
return new Code(driver, options.logger, electronProcess);
@@ -140,7 +140,7 @@ export class Code {
140140
}
141141

142142
async exit(): Promise<void> {
143-
return measureAndLog(new Promise<void>(resolve => {
143+
return measureAndLog(() => new Promise<void>(resolve => {
144144
const pid = this.mainProcess.pid!;
145145

146146
let done = false;
@@ -154,18 +154,39 @@ export class Code {
154154
while (!done) {
155155
retries++;
156156

157-
if (retries === 40) {
158-
this.logger.log('Smoke test exit call did not terminate process after 20s, forcefully exiting the application...');
159-
160-
// no need to await since we're polling for the process to die anyways
161-
treekill(pid, err => {
162-
try {
163-
process.kill(pid, 0); // throws an exception if the process doesn't exist anymore
164-
this.logger.log('Failed to kill Electron process tree:', err?.message);
165-
} catch (error) {
166-
// Expected when process is gone
167-
}
168-
});
157+
switch (retries) {
158+
159+
// after 5 / 10 seconds: try to exit gracefully again
160+
case 10:
161+
case 20: {
162+
this.logger.log('Smoke test exit call did not terminate process after 5-10s, gracefully trying to exit the application again...');
163+
this.driver.exitApplication();
164+
break;
165+
}
166+
167+
// after 20 seconds: forcefully kill
168+
case 40: {
169+
this.logger.log('Smoke test exit call did not terminate process after 20s, forcefully exiting the application...');
170+
171+
// no need to await since we're polling for the process to die anyways
172+
treekill(pid, err => {
173+
try {
174+
process.kill(pid, 0); // throws an exception if the process doesn't exist anymore
175+
this.logger.log('Failed to kill Electron process tree:', err?.message);
176+
} catch (error) {
177+
// Expected when process is gone
178+
}
179+
});
180+
181+
break;
182+
}
183+
184+
// after 30 seconds: give up
185+
case 60: {
186+
done = true;
187+
this.logger.log('Smoke test exit call did not terminate process after 30s, giving up');
188+
resolve();
189+
}
169190
}
170191

171192
try {
@@ -175,12 +196,6 @@ export class Code {
175196
done = true;
176197
resolve();
177198
}
178-
179-
if (retries === 60) {
180-
done = true;
181-
this.logger.log('Smoke test exit call did not terminate process after 30s, giving up');
182-
resolve();
183-
}
184199
}
185200
})();
186201
}), 'Code#exit()', this.logger);

‎automation/src/electron.ts

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -55,7 +55,7 @@ export async function resolveElectronConfiguration(options: LaunchOptions): Prom
5555

5656
if (codePath) {
5757
// running against a build: copy the test resolver extension
58-
await measureAndLog(copyExtension(root, extensionsPath, 'vscode-test-resolver'), 'copyExtension(vscode-test-resolver)', logger);
58+
await measureAndLog(() => copyExtension(root, extensionsPath, 'vscode-test-resolver'), 'copyExtension(vscode-test-resolver)', logger);
5959
}
6060
args.push('--enable-proposed-api=vscode.vscode-test-resolver');
6161
const remoteDataDir = `${userDataDir}-server`;
@@ -65,7 +65,7 @@ export async function resolveElectronConfiguration(options: LaunchOptions): Prom
6565
// running against a build: copy the test resolver extension into remote extensions dir
6666
const remoteExtensionsDir = join(remoteDataDir, 'extensions');
6767
mkdirp.sync(remoteExtensionsDir);
68-
await measureAndLog(copyExtension(root, remoteExtensionsDir, 'vscode-notebook-tests'), 'copyExtension(vscode-notebook-tests)', logger);
68+
await measureAndLog(() => copyExtension(root, remoteExtensionsDir, 'vscode-notebook-tests'), 'copyExtension(vscode-notebook-tests)', logger);
6969
}
7070

7171
env['TESTRESOLVER_DATA_FOLDER'] = remoteDataDir;

‎automation/src/logger.ts

Lines changed: 3 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -41,15 +41,15 @@ export class MultiLogger implements Logger {
4141
}
4242
}
4343

44-
export async function measureAndLog<T>(promise: Promise<T>, name: string, logger: Logger): Promise<T> {
44+
export async function measureAndLog<T>(promiseFactory: () => Promise<T>, name: string, logger: Logger): Promise<T> {
4545
const now = Date.now();
4646

47-
logger.log(`Starting operation '${name}...`);
47+
logger.log(`Starting operation '${name}'...`);
4848

4949
let res: T | undefined = undefined;
5050
let e: unknown;
5151
try {
52-
res = await promise;
52+
res = await promiseFactory();
5353
} catch (error) {
5454
e = error;
5555
}

‎automation/src/playwrightBrowser.ts

Lines changed: 8 additions & 8 deletions
Original file line numberDiff line numberDiff line change
@@ -34,7 +34,7 @@ async function launchServer(options: LaunchOptions) {
3434
const { userDataDir, codePath, extensionsPath, logger, logsPath } = options;
3535
const codeServerPath = codePath ?? process.env.VSCODE_REMOTE_SERVER_PATH;
3636
const agentFolder = userDataDir;
37-
await measureAndLog(mkdirp(agentFolder), `mkdirp(${agentFolder})`, logger);
37+
await measureAndLog(() => mkdirp(agentFolder), `mkdirp(${agentFolder})`, logger);
3838

3939
const env = {
4040
VSCODE_REMOTE_SERVER_PATH: codeServerPath,
@@ -81,28 +81,28 @@ async function launchServer(options: LaunchOptions) {
8181

8282
return {
8383
serverProcess,
84-
endpoint: await measureAndLog(waitForEndpoint(serverProcess, logger), 'waitForEndpoint(serverProcess)', logger)
84+
endpoint: await measureAndLog(() => waitForEndpoint(serverProcess, logger), 'waitForEndpoint(serverProcess)', logger)
8585
};
8686
}
8787

8888
async function launchBrowser(options: LaunchOptions, endpoint: string) {
8989
const { logger, workspacePath, tracing, headless } = options;
9090

91-
const browser = await measureAndLog(playwright[options.browser ?? 'chromium'].launch({ headless: headless ?? false }), 'playwright#launch', logger);
91+
const browser = await measureAndLog(() => playwright[options.browser ?? 'chromium'].launch({ headless: headless ?? false }), 'playwright#launch', logger);
9292
browser.on('disconnected', () => logger.log(`Playwright: browser disconnected`));
9393

94-
const context = await measureAndLog(browser.newContext(), 'browser.newContext', logger);
94+
const context = await measureAndLog(() => browser.newContext(), 'browser.newContext', logger);
9595

9696
if (tracing) {
9797
try {
98-
await measureAndLog(context.tracing.start({ screenshots: true, /* remaining options are off for perf reasons */ }), 'context.tracing.start()', logger);
98+
await measureAndLog(() => context.tracing.start({ screenshots: true, /* remaining options are off for perf reasons */ }), 'context.tracing.start()', logger);
9999
} catch (error) {
100100
logger.log(`Playwright (Browser): Failed to start playwright tracing (${error})`); // do not fail the build when this fails
101101
}
102102
}
103103

104-
const page = await measureAndLog(context.newPage(), 'context.newPage()', logger);
105-
await measureAndLog(page.setViewportSize({ width: 1200, height: 800 }), 'page.setViewportSize', logger);
104+
const page = await measureAndLog(() => context.newPage(), 'context.newPage()', logger);
105+
await measureAndLog(() => page.setViewportSize({ width: 1200, height: 800 }), 'page.setViewportSize', logger);
106106

107107
if (options.verbose) {
108108
context.on('page', () => logger.log(`Playwright (Browser): context.on('page')`));
@@ -133,7 +133,7 @@ async function launchBrowser(options: LaunchOptions, endpoint: string) {
133133
`["logLevel","${options.verbose ? 'trace' : 'info'}"]`
134134
].join(',')}]`;
135135

136-
await measureAndLog(page.goto(`${endpoint}&${workspacePath.endsWith('.code-workspace') ? 'workspace' : 'folder'}=${URI.file(workspacePath!).path}&payload=${payloadParam}`), 'page.goto()', logger);
136+
await measureAndLog(() => page.goto(`${endpoint}&${workspacePath.endsWith('.code-workspace') ? 'workspace' : 'folder'}=${URI.file(workspacePath!).path}&payload=${payloadParam}`), 'page.goto()', logger);
137137

138138
return { browser, context, page };
139139
}

‎automation/src/playwrightDriver.ts

Lines changed: 7 additions & 7 deletions
Original file line numberDiff line numberDiff line change
@@ -46,7 +46,7 @@ export class PlaywrightDriver {
4646
}
4747

4848
try {
49-
await measureAndLog(this.context.tracing.startChunk({ title: name }), `startTracing for ${name}`, this.options.logger);
49+
await measureAndLog(() => this.context.tracing.startChunk({ title: name }), `startTracing for ${name}`, this.options.logger);
5050
} catch (error) {
5151
// Ignore
5252
}
@@ -63,7 +63,7 @@ export class PlaywrightDriver {
6363
persistPath = join(this.options.logsPath, `playwright-trace-${PlaywrightDriver.traceCounter++}-${name.replace(/\s+/g, '-')}.zip`);
6464
}
6565

66-
await measureAndLog(this.context.tracing.stopChunk({ path: persistPath }), `stopTracing for ${name}`, this.options.logger);
66+
await measureAndLog(() => this.context.tracing.stopChunk({ path: persistPath }), `stopTracing for ${name}`, this.options.logger);
6767

6868
// To ensure we have a screenshot at the end where
6969
// it failed, also trigger one explicitly. Tracing
@@ -95,7 +95,7 @@ export class PlaywrightDriver {
9595
try {
9696
const persistPath = join(this.options.logsPath, `playwright-screenshot-${PlaywrightDriver.screenShotCounter++}-${name.replace(/\s+/g, '-')}.png`);
9797

98-
await measureAndLog(this.page.screenshot({ path: persistPath, type: 'png' }), 'takeScreenshot', this.options.logger);
98+
await measureAndLog(() => this.page.screenshot({ path: persistPath, type: 'png' }), 'takeScreenshot', this.options.logger);
9999
} catch (error) {
100100
// Ignore
101101
}
@@ -110,7 +110,7 @@ export class PlaywrightDriver {
110110
// Stop tracing
111111
try {
112112
if (this.options.tracing) {
113-
await measureAndLog(this.context.tracing.stop(), 'stop tracing', this.options.logger);
113+
await measureAndLog(() => this.context.tracing.stop(), 'stop tracing', this.options.logger);
114114
}
115115
} catch (error) {
116116
// Ignore
@@ -119,7 +119,7 @@ export class PlaywrightDriver {
119119
// Web: exit via `close` method
120120
if (this.options.web) {
121121
try {
122-
await measureAndLog(this.application.close(), 'playwright.close()', this.options.logger);
122+
await measureAndLog(() => this.application.close(), 'playwright.close()', this.options.logger);
123123
} catch (error) {
124124
this.options.logger.log(`Error closing appliction (${error})`);
125125
}
@@ -128,15 +128,15 @@ export class PlaywrightDriver {
128128
// Desktop: exit via `driver.exitApplication`
129129
else {
130130
try {
131-
await measureAndLog(this.evaluateWithDriver(([driver]) => driver.exitApplication()), 'driver.exitApplication()', this.options.logger);
131+
await measureAndLog(() => this.evaluateWithDriver(([driver]) => driver.exitApplication()), 'driver.exitApplication()', this.options.logger);
132132
} catch (error) {
133133
this.options.logger.log(`Error exiting appliction (${error})`);
134134
}
135135
}
136136

137137
// Server: via `teardown`
138138
if (this.serverProcess) {
139-
await measureAndLog(teardown(this.serverProcess, this.options.logger), 'teardown server process', this.options.logger);
139+
await measureAndLog(() => teardown(this.serverProcess!, this.options.logger), 'teardown server process', this.options.logger);
140140
}
141141
}
142142

‎automation/src/playwrightElectron.ts

Lines changed: 3 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -29,19 +29,19 @@ export async function launch(options: LaunchOptions): Promise<{ electronProcess:
2929
async function launchElectron(configuration: IElectronConfiguration, options: LaunchOptions) {
3030
const { logger, tracing } = options;
3131

32-
const electron = await measureAndLog(playwright._electron.launch({
32+
const electron = await measureAndLog(() => playwright._electron.launch({
3333
executablePath: configuration.electronPath,
3434
args: configuration.args,
3535
env: configuration.env as { [key: string]: string }
3636
}), 'playwright-electron#launch', logger);
3737

38-
const window = await measureAndLog(electron.firstWindow(), 'playwright-electron#firstWindow', logger);
38+
const window = await measureAndLog(() => electron.firstWindow(), 'playwright-electron#firstWindow', logger);
3939

4040
const context = window.context();
4141

4242
if (tracing) {
4343
try {
44-
await measureAndLog(context.tracing.start({ screenshots: true, /* remaining options are off for perf reasons */ }), 'context.tracing.start()', logger);
44+
await measureAndLog(() => context.tracing.start({ screenshots: true, /* remaining options are off for perf reasons */ }), 'context.tracing.start()', logger);
4545
} catch (error) {
4646
logger.log(`Playwright (Electron): Failed to start playwright tracing (${error})`); // do not fail the build when this fails
4747
}

‎smoke/src/main.ts

Lines changed: 6 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -265,13 +265,13 @@ async function ensureStableCode(): Promise<void> {
265265
if (!stableCodePath) {
266266
const { major, minor } = parseVersion(version!);
267267
const majorMinorVersion = `${major}.${minor - 1}`;
268-
const versionsReq = await retry(() => measureAndLog(fetch('https://update.code.visualstudio.com/api/releases/stable', { headers: { 'x-api-version': '2' } }), 'versionReq', logger), 1000, 20);
268+
const versionsReq = await retry(() => measureAndLog(() => fetch('https://update.code.visualstudio.com/api/releases/stable', { headers: { 'x-api-version': '2' } }), 'versionReq', logger), 1000, 20);
269269

270270
if (!versionsReq.ok) {
271271
throw new Error('Could not fetch releases from update server');
272272
}
273273

274-
const versions: { version: string }[] = await measureAndLog(versionsReq.json(), 'versionReq.json()', logger);
274+
const versions: { version: string }[] = await measureAndLog(() => versionsReq.json(), 'versionReq.json()', logger);
275275
const prefix = `${majorMinorVersion}.`;
276276
const previousVersion = versions.find(v => v.version.startsWith(prefix));
277277

@@ -284,7 +284,7 @@ async function ensureStableCode(): Promise<void> {
284284
let lastProgressMessage: string | undefined = undefined;
285285
let lastProgressReportedAt = 0;
286286
const stableCodeDestination = path.join(testDataPath, 's');
287-
const stableCodeExecutable = await retry(() => measureAndLog(vscodetest.download({
287+
const stableCodeExecutable = await retry(() => measureAndLog(() => vscodetest.download({
288288
cachePath: stableCodeDestination,
289289
version: previousVersion.version,
290290
extractSync: true,
@@ -339,9 +339,9 @@ async function setup(): Promise<void> {
339339

340340
if (!opts.web && !opts.remote && opts.build) {
341341
// only enabled when running with --build and not in web or remote
342-
await measureAndLog(ensureStableCode(), 'ensureStableCode', logger);
342+
await measureAndLog(() => ensureStableCode(), 'ensureStableCode', logger);
343343
}
344-
await measureAndLog(setupRepository(), 'setupRepository', logger);
344+
await measureAndLog(() => setupRepository(), 'setupRepository', logger);
345345

346346
logger.log('Smoketest setup done!\n');
347347
}
@@ -375,7 +375,7 @@ before(async function () {
375375
after(async function () {
376376
try {
377377
let deleted = false;
378-
await measureAndLog(Promise.race([
378+
await measureAndLog(() => Promise.race([
379379
new Promise<void>((resolve, reject) => rimraf(testDataPath, { maxBusyTries: 10 }, error => {
380380
if (error) {
381381
reject(error);

0 commit comments

Comments
 (0)