Skip to content

Commit

Permalink
Add await for stdout (microsoft#22049)
Browse files Browse the repository at this point in the history 
Add await so all output is read before ending the run instance.
  • Loading branch information
@eleanorjboyd
eleanorjboyd committed Oct 2, 2023
1 parent 0d8a32d commit e01b7df
Show file tree
Hide file tree
Showing 9 changed files with 126 additions and 54 deletions.
29 changes: 23 additions & 6 deletions src/client/testing/testController/common/server.ts
View file
Original file line number Diff line number Diff line change
Expand Up @@ -5,6 +5,7 @@ import * as net from 'net';
import * as crypto from 'crypto';
import { Disposable, Event, EventEmitter, TestRun } from 'vscode';
import * as path from 'path';
import { ChildProcess } from 'child_process';
import {
ExecutionFactoryCreateWithEnvironmentOptions,
ExecutionResult,
Expand Down Expand Up @@ -86,7 +87,7 @@ export class PythonTestServer implements ITestServer, Disposable {
// what payload is so small it doesn't include the whole UUID think got this
if (extractedJsonPayload.uuid !== undefined && extractedJsonPayload.cleanedJsonData !== undefined) {
// if a full json was found in the buffer, fire the data received event then keep cycling with the remaining raw data.
traceInfo(`Firing data received event, ${extractedJsonPayload.cleanedJsonData}`);
traceLog(`Firing data received event, ${extractedJsonPayload.cleanedJsonData}`);
this._fireDataReceived(extractedJsonPayload.uuid, extractedJsonPayload.cleanedJsonData);
}
buffer = Buffer.from(extractedJsonPayload.remainingRawData);
Expand Down Expand Up @@ -223,13 +224,23 @@ export class PythonTestServer implements ITestServer, Disposable {
// This means it is running discovery
traceLog(`Discovering unittest tests with arguments: ${args}\r\n`);
}
const deferred = createDeferred<ExecutionResult<string>>();
const result = execService.execObservable(args, spawnOptions);
const deferredTillExecClose = createDeferred<ExecutionResult<string>>();

let resultProc: ChildProcess | undefined;

runInstance?.token.onCancellationRequested(() => {
traceInfo('Test run cancelled, killing unittest subprocess.');
result?.proc?.kill();
// if the resultProc exists just call kill on it which will handle resolving the ExecClose deferred, otherwise resolve the deferred here.
if (resultProc) {
resultProc?.kill();
} else {
deferredTillExecClose?.resolve();
}
});

const result = execService?.execObservable(args, spawnOptions);
resultProc = result?.proc;

// Take all output from the subprocess and add it to the test output channel. This will be the pytest output.
// Displays output to user and ensure the subprocess doesn't run into buffer overflow.
result?.proc?.stdout?.on('data', (data) => {
Expand All @@ -238,6 +249,12 @@ export class PythonTestServer implements ITestServer, Disposable {
result?.proc?.stderr?.on('data', (data) => {
spawnOptions?.outputChannel?.append(data.toString());
});
result?.proc?.on('exit', (code, signal) => {
if (code !== 0) {
traceError(`Subprocess exited unsuccessfully with exit code ${code} and signal ${signal}`);
}
});

result?.proc?.on('exit', (code, signal) => {
// if the child has testIds then this is a run request
if (code !== 0 && testIds && testIds?.length !== 0) {
Expand Down Expand Up @@ -269,9 +286,9 @@ export class PythonTestServer implements ITestServer, Disposable {
data: JSON.stringify(createEOTPayload(true)),
});
}
deferred.resolve({ stdout: '', stderr: '' });
deferredTillExecClose.resolve({ stdout: '', stderr: '' });
});
await deferred.promise;
await deferredTillExecClose.promise;
}
} catch (ex) {
traceError(`Error while server attempting to run unittest command: ${ex}`);
Expand Down
2 changes: 1 addition & 1 deletion src/client/testing/testController/common/utils.ts
View file
Original file line number Diff line number Diff line change
Expand Up @@ -43,7 +43,7 @@ export const JSONRPC_UUID_HEADER = 'Request-uuid';
export const JSONRPC_CONTENT_LENGTH_HEADER = 'Content-Length';
export const JSONRPC_CONTENT_TYPE_HEADER = 'Content-Type';

export function createEOTDeferred(): Deferred<void> {
export function createTestingDeferred(): Deferred<void> {
return createDeferred<void>();
}

Expand Down
1 change: 0 additions & 1 deletion src/client/testing/testController/controller.ts
View file
Original file line number Diff line number Diff line change
Expand Up @@ -462,7 +462,6 @@ export class PythonTestController implements ITestController, IExtensionSingleAc
);
}
}

if (!settings.testing.pytestEnabled && !settings.testing.unittestEnabled) {
unconfiguredWorkspaces.push(workspace);
}
Expand Down
21 changes: 13 additions & 8 deletions src/client/testing/testController/pytest/pytestDiscoveryAdapter.ts
View file
Original file line number Diff line number Diff line change
Expand Up @@ -4,7 +4,6 @@ import * as path from 'path';
import { Uri } from 'vscode';
import {
ExecutionFactoryCreateWithEnvironmentOptions,
ExecutionResult,
IPythonExecutionFactory,
SpawnOptions,
} from '../../../common/process/types';
Expand All @@ -19,7 +18,7 @@ import {
ITestResultResolver,
ITestServer,
} from '../common/types';
import { createDiscoveryErrorPayload, createEOTPayload } from '../common/utils';
import { createDiscoveryErrorPayload, createEOTPayload, createTestingDeferred } from '../common/utils';

/**
* Wrapper class for unittest test discovery. This is where we call `runTestCommand`. #this seems incorrectly copied
Expand Down Expand Up @@ -47,6 +46,7 @@ export class PytestTestDiscoveryAdapter implements ITestDiscoveryAdapter {
await this.runPytestDiscovery(uri, uuid, executionFactory);
} finally {
await deferredTillEOT.promise;
traceVerbose('deferredTill EOT resolved');
disposeDataReceiver(this.testServer);
}
// this is only a placeholder to handle function overloading until rewrite is finished
Expand All @@ -55,7 +55,6 @@ export class PytestTestDiscoveryAdapter implements ITestDiscoveryAdapter {
}

async runPytestDiscovery(uri: Uri, uuid: string, executionFactory?: IPythonExecutionFactory): Promise<void> {
const deferred = createDeferred<DiscoveredTestPayload>();
const relativePathToPytest = 'pythonFiles';
const fullPluginPath = path.join(EXTENSION_ROOT_DIR, relativePathToPytest);
const settings = this.configSettings.getSettings(uri);
Expand Down Expand Up @@ -83,9 +82,10 @@ export class PytestTestDiscoveryAdapter implements ITestDiscoveryAdapter {
};
const execService = await executionFactory?.createActivatedEnvironment(creationOptions);
// delete UUID following entire discovery finishing.
const deferredExec = createDeferred<ExecutionResult<string>>();
const execArgs = ['-m', 'pytest', '-p', 'vscode_pytest', '--collect-only'].concat(pytestArgs);
traceVerbose(`Running pytest discovery with command: ${execArgs.join(' ')}`);

const deferredTillExecClose: Deferred<void> = createTestingDeferred();
const result = execService?.execObservable(execArgs, spawnOptions);

// Take all output from the subprocess and add it to the test output channel. This will be the pytest output.
Expand All @@ -97,6 +97,11 @@ export class PytestTestDiscoveryAdapter implements ITestDiscoveryAdapter {
spawnOptions.outputChannel?.append(data.toString());
});
result?.proc?.on('exit', (code, signal) => {
if (code !== 0) {
traceError(`Subprocess exited unsuccessfully with exit code ${code} and signal ${signal}.`);
}
});
result?.proc?.on('close', (code, signal) => {
if (code !== 0) {
traceError(
`Subprocess exited unsuccessfully with exit code ${code} and signal ${signal}. Creating and sending error discovery payload`,
Expand All @@ -112,10 +117,10 @@ export class PytestTestDiscoveryAdapter implements ITestDiscoveryAdapter {
data: JSON.stringify(createEOTPayload(true)),
});
}
deferredExec.resolve({ stdout: '', stderr: '' });
deferred.resolve();
// deferredTillEOT is resolved when all data sent on stdout and stderr is received, close event is only called when this occurs
// due to the sync reading of the output.
deferredTillExecClose?.resolve();
});

await deferredExec.promise;
await deferredTillExecClose.promise;
}
}
55 changes: 39 additions & 16 deletions src/client/testing/testController/pytest/pytestExecutionAdapter.ts
View file
Original file line number Diff line number Diff line change
Expand Up @@ -3,9 +3,10 @@

import { TestRun, Uri } from 'vscode';
import * as path from 'path';
import { ChildProcess } from 'child_process';
import { IConfigurationService, ITestOutputChannel } from '../../../common/types';
import { Deferred, createDeferred } from '../../../common/utils/async';
import { traceError, traceInfo } from '../../../logging';
import { Deferred } from '../../../common/utils/async';
import { traceError, traceInfo, traceVerbose } from '../../../logging';
import {
DataReceivedEvent,
ExecutionTestPayload,
Expand All @@ -15,7 +16,6 @@ import {
} from '../common/types';
import {
ExecutionFactoryCreateWithEnvironmentOptions,
ExecutionResult,
IPythonExecutionFactory,
SpawnOptions,
} from '../../../common/process/types';
Expand All @@ -42,7 +42,9 @@ export class PytestTestExecutionAdapter implements ITestExecutionAdapter {
debugLauncher?: ITestDebugLauncher,
): Promise<ExecutionTestPayload> {
const uuid = this.testServer.createUUID(uri.fsPath);
const deferredTillEOT: Deferred<void> = utils.createEOTDeferred();
// deferredTillEOT is resolved when all data sent over payload is received
const deferredTillEOT: Deferred<void> = utils.createTestingDeferred();

const dataReceivedDisposable = this.testServer.onRunDataReceived((e: DataReceivedEvent) => {
if (runInstance) {
const eParsed = JSON.parse(e.data);
Expand All @@ -60,8 +62,9 @@ export class PytestTestExecutionAdapter implements ITestExecutionAdapter {
traceInfo("Test run cancelled, resolving 'till EOT' deferred.");
deferredTillEOT.resolve();
});

try {
this.runTestsNew(
await this.runTestsNew(
uri,
testIds,
uuid,
Expand All @@ -73,6 +76,7 @@ export class PytestTestExecutionAdapter implements ITestExecutionAdapter {
);
} finally {
await deferredTillEOT.promise;
traceVerbose('deferredTill EOT resolved');
disposeDataReceiver(this.testServer);
}

Expand Down Expand Up @@ -123,7 +127,6 @@ export class PytestTestExecutionAdapter implements ITestExecutionAdapter {
};
// need to check what will happen in the exec service is NOT defined and is null
const execService = await executionFactory?.createActivatedEnvironment(creationOptions);

try {
// Remove positional test folders and files, we will add as needed per node
const testArgs = removePositionalFoldersAndFiles(pytestArgs);
Expand Down Expand Up @@ -159,19 +162,28 @@ export class PytestTestExecutionAdapter implements ITestExecutionAdapter {
deferredTillEOT?.resolve();
});
} else {
// deferredTillExecClose is resolved when all stdout and stderr is read
const deferredTillExecClose: Deferred<void> = utils.createTestingDeferred();
// combine path to run script with run args
const scriptPath = path.join(fullPluginPath, 'vscode_pytest', 'run_pytest_script.py');
const runArgs = [scriptPath, ...testArgs];
traceInfo(`Running pytest with arguments: ${runArgs.join(' ')}\r\n`);

const deferredExec = createDeferred<ExecutionResult<string>>();
const result = execService?.execObservable(runArgs, spawnOptions);
let resultProc: ChildProcess | undefined;

runInstance?.token.onCancellationRequested(() => {
traceInfo('Test run cancelled, killing pytest subprocess.');
result?.proc?.kill();
// if the resultProc exists just call kill on it which will handle resolving the ExecClose deferred, otherwise resolve the deferred here.
if (resultProc) {
resultProc?.kill();
} else {
deferredTillExecClose?.resolve();
}
});

const result = execService?.execObservable(runArgs, spawnOptions);
resultProc = result?.proc;

// Take all output from the subprocess and add it to the test output channel. This will be the pytest output.
// Displays output to user and ensure the subprocess doesn't run into buffer overflow.
result?.proc?.stdout?.on('data', (data) => {
Expand All @@ -180,15 +192,20 @@ export class PytestTestExecutionAdapter implements ITestExecutionAdapter {
result?.proc?.stderr?.on('data', (data) => {
this.outputChannel?.append(data.toString());
});

result?.proc?.on('exit', (code, signal) => {
traceInfo('Test run finished, subprocess exited.');
if (code !== 0 && testIds) {
traceError(`Subprocess exited unsuccessfully with exit code ${code} and signal ${signal}.`);
}
});

result?.proc?.on('close', (code, signal) => {
traceVerbose('Test run finished, subprocess closed.');
// if the child has testIds then this is a run request
// if the child process exited with a non-zero exit code, then we need to send the error payload.
if (code !== 0 && testIds) {
traceError(
`Subprocess exited unsuccessfully with exit code ${code} and signal ${signal}. Creating and sending error execution payload`,
`Subprocess closed unsuccessfully with exit code ${code} and signal ${signal}. Creating and sending error execution payload`,
);
// if the child process exited with a non-zero exit code, then we need to send the error payload.
this.testServer.triggerRunDataReceivedEvent({
uuid,
data: JSON.stringify(utils.createExecutionErrorPayload(code, signal, testIds, cwd)),
Expand All @@ -199,16 +216,22 @@ export class PytestTestExecutionAdapter implements ITestExecutionAdapter {
data: JSON.stringify(utils.createEOTPayload(true)),
});
}
deferredExec.resolve({ stdout: '', stderr: '' });
// deferredTillEOT is resolved when all data sent on stdout and stderr is received, close event is only called when this occurs
// due to the sync reading of the output.
deferredTillExecClose?.resolve();
});
await deferredExec.promise;
await deferredTillExecClose?.promise;
}
} catch (ex) {
traceError(`Error while running tests: ${testIds}\r\n${ex}\r\n\r\n`);
return Promise.reject(ex);
}

const executionPayload: ExecutionTestPayload = { cwd, status: 'success', error: '' };
const executionPayload: ExecutionTestPayload = {
cwd,
status: 'success',
error: '',
};
return executionPayload;
}
}
6 changes: 3 additions & 3 deletions src/test/mocks/mockChildProcess.ts
View file
Original file line number Diff line number Diff line change
Expand Up @@ -133,9 +133,9 @@ export class MockChildProcess extends EventEmitter {

emit(event: string | symbol, ...args: unknown[]): boolean {
if (this.eventMap.has(event.toString())) {
this.eventMap.get(event.toString()).forEach((listener: (arg0: unknown) => void) => {
const argsArray = Array.isArray(args) ? args : [args];
listener(argsArray);
this.eventMap.get(event.toString()).forEach((listener: (...arg0: unknown[]) => void) => {
const argsArray: unknown[] = Array.isArray(args) ? args : [args];
listener(...argsArray);
});
}
return true;
Expand Down
11 changes: 5 additions & 6 deletions src/test/testing/common/testingPayloadsEot.test.ts
View file
Original file line number Diff line number Diff line change
Expand Up @@ -66,6 +66,7 @@ suite('EOT tests', () => {
let testController: TestController;
let stubExecutionFactory: typeMoq.IMock<IPythonExecutionFactory>;
let client: net.Socket;
let mockProc: MockChildProcess;
const sandbox = sinon.createSandbox();
// const unittestProvider: TestProvider = UNITTEST_PROVIDER;
// const pytestProvider: TestProvider = PYTEST_PROVIDER;
Expand All @@ -86,7 +87,7 @@ suite('EOT tests', () => {
traceLog('Socket connection error:', error);
});

const mockProc = new MockChildProcess('', ['']);
mockProc = new MockChildProcess('', ['']);
const output2 = new Observable<Output<string>>(() => {
/* no op */
});
Expand Down Expand Up @@ -156,15 +157,17 @@ suite('EOT tests', () => {
}
})(client, payloadArray[i]);
}
mockProc.emit('close', 0, null);
client.end();
});

resultResolver = new PythonResultResolver(testController, PYTEST_PROVIDER, workspaceUri);
resultResolver._resolveExecution = async (payload, _token?) => {
// the payloads that get to the _resolveExecution are all data and should be successful.
actualCollectedResult = actualCollectedResult + JSON.stringify(payload.result);
assert.strictEqual(payload.status, 'success', "Expected status to be 'success'");
assert.ok(payload.result, 'Expected results to be present');
actualCollectedResult = actualCollectedResult + JSON.stringify(payload.result);

return Promise.resolve();
};
// set workspace to test workspace folder
Expand Down Expand Up @@ -200,10 +203,6 @@ suite('EOT tests', () => {
actualCollectedResult,
"Expected collected result to match 'data'",
);
// nervous about this not testing race conditions correctly
// client.end();
// verify that the _resolveExecution was called once per test
// assert.strictEqual(callCount, 1, 'Expected _resolveExecution to be called once');
});
});
});
Expand Down
2 changes: 1 addition & 1 deletion src/test/testing/testController/pytest/pytestExecutionAdapter.unit.test.ts
View file
Original file line number Diff line number Diff line change
Expand Up @@ -268,7 +268,7 @@ suite('pytest test execution adapter', () => {
traceInfo('stubs launch debugger');
deferredEOT.resolve();
});
const utilsCreateEOTStub: sinon.SinonStub = sinon.stub(util, 'createEOTDeferred');
const utilsCreateEOTStub: sinon.SinonStub = sinon.stub(util, 'createTestingDeferred');
utilsCreateEOTStub.callsFake(() => deferredEOT);
const testRun = typeMoq.Mock.ofType<TestRun>();
testRun
Expand Down
Loading

0 comments on commit e01b7df

Please sign in to comment.