Skip to content

Commit 998a0a5

Browse files
eleanorjboydeleanorjboyd
authored
Add await for stdout (#22049)
Add await so all output is read before ending the run instance.
1 parent 337b862 commit 998a0a5

File tree

9 files changed

+126
-54
lines changed

9 files changed

+126
-54
lines changed

‎src/client/testing/testController/common/server.ts‎

Lines changed: 23 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -5,6 +5,7 @@ import * as net from 'net';
55
import * as crypto from 'crypto';
66
import { Disposable, Event, EventEmitter, TestRun } from 'vscode';
77
import * as path from 'path';
8+
import { ChildProcess } from 'child_process';
89
import {
910
ExecutionFactoryCreateWithEnvironmentOptions,
1011
ExecutionResult,
@@ -86,7 +87,7 @@ export class PythonTestServer implements ITestServer, Disposable {
8687
// what payload is so small it doesn't include the whole UUID think got this
8788
if (extractedJsonPayload.uuid !== undefined && extractedJsonPayload.cleanedJsonData !== undefined) {
8889
// if a full json was found in the buffer, fire the data received event then keep cycling with the remaining raw data.
89-
traceInfo(`Firing data received event, ${extractedJsonPayload.cleanedJsonData}`);
90+
traceLog(`Firing data received event, ${extractedJsonPayload.cleanedJsonData}`);
9091
this._fireDataReceived(extractedJsonPayload.uuid, extractedJsonPayload.cleanedJsonData);
9192
}
9293
buffer = Buffer.from(extractedJsonPayload.remainingRawData);
@@ -223,13 +224,23 @@ export class PythonTestServer implements ITestServer, Disposable {
223224
// This means it is running discovery
224225
traceLog(`Discovering unittest tests with arguments: ${args}\r\n`);
225226
}
226-
const deferred = createDeferred<ExecutionResult<string>>();
227-
const result = execService.execObservable(args, spawnOptions);
227+
const deferredTillExecClose = createDeferred<ExecutionResult<string>>();
228+
229+
let resultProc: ChildProcess | undefined;
230+
228231
runInstance?.token.onCancellationRequested(() => {
229232
traceInfo('Test run cancelled, killing unittest subprocess.');
230-
result?.proc?.kill();
233+
// if the resultProc exists just call kill on it which will handle resolving the ExecClose deferred, otherwise resolve the deferred here.
234+
if (resultProc) {
235+
resultProc?.kill();
236+
} else {
237+
deferredTillExecClose?.resolve();
238+
}
231239
});
232240

241+
const result = execService?.execObservable(args, spawnOptions);
242+
resultProc = result?.proc;
243+
233244
// Take all output from the subprocess and add it to the test output channel. This will be the pytest output.
234245
// Displays output to user and ensure the subprocess doesn't run into buffer overflow.
235246
result?.proc?.stdout?.on('data', (data) => {
@@ -238,6 +249,12 @@ export class PythonTestServer implements ITestServer, Disposable {
238249
result?.proc?.stderr?.on('data', (data) => {
239250
spawnOptions?.outputChannel?.append(data.toString());
240251
});
252+
result?.proc?.on('exit', (code, signal) => {
253+
if (code !== 0) {
254+
traceError(`Subprocess exited unsuccessfully with exit code ${code} and signal ${signal}`);
255+
}
256+
});
257+
241258
result?.proc?.on('exit', (code, signal) => {
242259
// if the child has testIds then this is a run request
243260
if (code !== 0 && testIds && testIds?.length !== 0) {
@@ -269,9 +286,9 @@ export class PythonTestServer implements ITestServer, Disposable {
269286
data: JSON.stringify(createEOTPayload(true)),
270287
});
271288
}
272-
deferred.resolve({ stdout: '', stderr: '' });
289+
deferredTillExecClose.resolve({ stdout: '', stderr: '' });
273290
});
274-
await deferred.promise;
291+
await deferredTillExecClose.promise;
275292
}
276293
} catch (ex) {
277294
traceError(`Error while server attempting to run unittest command: ${ex}`);

‎src/client/testing/testController/common/utils.ts‎

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -43,7 +43,7 @@ export const JSONRPC_UUID_HEADER = 'Request-uuid';
4343
export const JSONRPC_CONTENT_LENGTH_HEADER = 'Content-Length';
4444
export const JSONRPC_CONTENT_TYPE_HEADER = 'Content-Type';
4545

46-
export function createEOTDeferred(): Deferred<void> {
46+
export function createTestingDeferred(): Deferred<void> {
4747
return createDeferred<void>();
4848
}
4949

‎src/client/testing/testController/controller.ts‎

Lines changed: 0 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -462,7 +462,6 @@ export class PythonTestController implements ITestController, IExtensionSingleAc
462462
);
463463
}
464464
}
465-
466465
if (!settings.testing.pytestEnabled && !settings.testing.unittestEnabled) {
467466
unconfiguredWorkspaces.push(workspace);
468467
}

‎src/client/testing/testController/pytest/pytestDiscoveryAdapter.ts‎

Lines changed: 13 additions & 8 deletions
Original file line numberDiff line numberDiff line change
@@ -4,7 +4,6 @@ import * as path from 'path';
44
import { Uri } from 'vscode';
55
import {
66
ExecutionFactoryCreateWithEnvironmentOptions,
7-
ExecutionResult,
87
IPythonExecutionFactory,
98
SpawnOptions,
109
} from '../../../common/process/types';
@@ -19,7 +18,7 @@ import {
1918
ITestResultResolver,
2019
ITestServer,
2120
} from '../common/types';
22-
import { createDiscoveryErrorPayload, createEOTPayload } from '../common/utils';
21+
import { createDiscoveryErrorPayload, createEOTPayload, createTestingDeferred } from '../common/utils';
2322

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

5757
async runPytestDiscovery(uri: Uri, uuid: string, executionFactory?: IPythonExecutionFactory): Promise<void> {
58-
const deferred = createDeferred<DiscoveredTestPayload>();
5958
const relativePathToPytest = 'pythonFiles';
6059
const fullPluginPath = path.join(EXTENSION_ROOT_DIR, relativePathToPytest);
6160
const settings = this.configSettings.getSettings(uri);
@@ -83,9 +82,10 @@ export class PytestTestDiscoveryAdapter implements ITestDiscoveryAdapter {
8382
};
8483
const execService = await executionFactory?.createActivatedEnvironment(creationOptions);
8584
// delete UUID following entire discovery finishing.
86-
const deferredExec = createDeferred<ExecutionResult<string>>();
8785
const execArgs = ['-m', 'pytest', '-p', 'vscode_pytest', '--collect-only'].concat(pytestArgs);
8886
traceVerbose(`Running pytest discovery with command: ${execArgs.join(' ')}`);
87+
88+
const deferredTillExecClose: Deferred<void> = createTestingDeferred();
8989
const result = execService?.execObservable(execArgs, spawnOptions);
9090

9191
// Take all output from the subprocess and add it to the test output channel. This will be the pytest output.
@@ -97,6 +97,11 @@ export class PytestTestDiscoveryAdapter implements ITestDiscoveryAdapter {
9797
spawnOptions.outputChannel?.append(data.toString());
9898
});
9999
result?.proc?.on('exit', (code, signal) => {
100+
if (code !== 0) {
101+
traceError(`Subprocess exited unsuccessfully with exit code ${code} and signal ${signal}.`);
102+
}
103+
});
104+
result?.proc?.on('close', (code, signal) => {
100105
if (code !== 0) {
101106
traceError(
102107
`Subprocess exited unsuccessfully with exit code ${code} and signal ${signal}. Creating and sending error discovery payload`,
@@ -112,10 +117,10 @@ export class PytestTestDiscoveryAdapter implements ITestDiscoveryAdapter {
112117
data: JSON.stringify(createEOTPayload(true)),
113118
});
114119
}
115-
deferredExec.resolve({ stdout: '', stderr: '' });
116-
deferred.resolve();
120+
// deferredTillEOT is resolved when all data sent on stdout and stderr is received, close event is only called when this occurs
121+
// due to the sync reading of the output.
122+
deferredTillExecClose?.resolve();
117123
});
118-
119-
await deferredExec.promise;
124+
await deferredTillExecClose.promise;
120125
}
121126
}

‎src/client/testing/testController/pytest/pytestExecutionAdapter.ts‎

Lines changed: 39 additions & 16 deletions
Original file line numberDiff line numberDiff line change
@@ -3,9 +3,10 @@
33

44
import { TestRun, Uri } from 'vscode';
55
import * as path from 'path';
6+
import { ChildProcess } from 'child_process';
67
import { IConfigurationService, ITestOutputChannel } from '../../../common/types';
7-
import { Deferred, createDeferred } from '../../../common/utils/async';
8-
import { traceError, traceInfo } from '../../../logging';
8+
import { Deferred } from '../../../common/utils/async';
9+
import { traceError, traceInfo, traceVerbose } from '../../../logging';
910
import {
1011
DataReceivedEvent,
1112
ExecutionTestPayload,
@@ -15,7 +16,6 @@ import {
1516
} from '../common/types';
1617
import {
1718
ExecutionFactoryCreateWithEnvironmentOptions,
18-
ExecutionResult,
1919
IPythonExecutionFactory,
2020
SpawnOptions,
2121
} from '../../../common/process/types';
@@ -42,7 +42,9 @@ export class PytestTestExecutionAdapter implements ITestExecutionAdapter {
4242
debugLauncher?: ITestDebugLauncher,
4343
): Promise<ExecutionTestPayload> {
4444
const uuid = this.testServer.createUUID(uri.fsPath);
45-
const deferredTillEOT: Deferred<void> = utils.createEOTDeferred();
45+
// deferredTillEOT is resolved when all data sent over payload is received
46+
const deferredTillEOT: Deferred<void> = utils.createTestingDeferred();
47+
4648
const dataReceivedDisposable = this.testServer.onRunDataReceived((e: DataReceivedEvent) => {
4749
if (runInstance) {
4850
const eParsed = JSON.parse(e.data);
@@ -60,8 +62,9 @@ export class PytestTestExecutionAdapter implements ITestExecutionAdapter {
6062
traceInfo("Test run cancelled, resolving 'till EOT' deferred.");
6163
deferredTillEOT.resolve();
6264
});
65+
6366
try {
64-
this.runTestsNew(
67+
await this.runTestsNew(
6568
uri,
6669
testIds,
6770
uuid,
@@ -73,6 +76,7 @@ export class PytestTestExecutionAdapter implements ITestExecutionAdapter {
7376
);
7477
} finally {
7578
await deferredTillEOT.promise;
79+
traceVerbose('deferredTill EOT resolved');
7680
disposeDataReceiver(this.testServer);
7781
}
7882

@@ -123,7 +127,6 @@ export class PytestTestExecutionAdapter implements ITestExecutionAdapter {
123127
};
124128
// need to check what will happen in the exec service is NOT defined and is null
125129
const execService = await executionFactory?.createActivatedEnvironment(creationOptions);
126-
127130
try {
128131
// Remove positional test folders and files, we will add as needed per node
129132
const testArgs = removePositionalFoldersAndFiles(pytestArgs);
@@ -159,19 +162,28 @@ export class PytestTestExecutionAdapter implements ITestExecutionAdapter {
159162
deferredTillEOT?.resolve();
160163
});
161164
} else {
165+
// deferredTillExecClose is resolved when all stdout and stderr is read
166+
const deferredTillExecClose: Deferred<void> = utils.createTestingDeferred();
162167
// combine path to run script with run args
163168
const scriptPath = path.join(fullPluginPath, 'vscode_pytest', 'run_pytest_script.py');
164169
const runArgs = [scriptPath, ...testArgs];
165170
traceInfo(`Running pytest with arguments: ${runArgs.join(' ')}\r\n`);
166171

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

170174
runInstance?.token.onCancellationRequested(() => {
171175
traceInfo('Test run cancelled, killing pytest subprocess.');
172-
result?.proc?.kill();
176+
// if the resultProc exists just call kill on it which will handle resolving the ExecClose deferred, otherwise resolve the deferred here.
177+
if (resultProc) {
178+
resultProc?.kill();
179+
} else {
180+
deferredTillExecClose?.resolve();
181+
}
173182
});
174183

184+
const result = execService?.execObservable(runArgs, spawnOptions);
185+
resultProc = result?.proc;
186+
175187
// Take all output from the subprocess and add it to the test output channel. This will be the pytest output.
176188
// Displays output to user and ensure the subprocess doesn't run into buffer overflow.
177189
result?.proc?.stdout?.on('data', (data) => {
@@ -180,15 +192,20 @@ export class PytestTestExecutionAdapter implements ITestExecutionAdapter {
180192
result?.proc?.stderr?.on('data', (data) => {
181193
this.outputChannel?.append(data.toString());
182194
});
183-
184195
result?.proc?.on('exit', (code, signal) => {
185-
traceInfo('Test run finished, subprocess exited.');
196+
if (code !== 0 && testIds) {
197+
traceError(`Subprocess exited unsuccessfully with exit code ${code} and signal ${signal}.`);
198+
}
199+
});
200+
201+
result?.proc?.on('close', (code, signal) => {
202+
traceVerbose('Test run finished, subprocess closed.');
186203
// if the child has testIds then this is a run request
204+
// if the child process exited with a non-zero exit code, then we need to send the error payload.
187205
if (code !== 0 && testIds) {
188206
traceError(
189-
`Subprocess exited unsuccessfully with exit code ${code} and signal ${signal}. Creating and sending error execution payload`,
207+
`Subprocess closed unsuccessfully with exit code ${code} and signal ${signal}. Creating and sending error execution payload`,
190208
);
191-
// if the child process exited with a non-zero exit code, then we need to send the error payload.
192209
this.testServer.triggerRunDataReceivedEvent({
193210
uuid,
194211
data: JSON.stringify(utils.createExecutionErrorPayload(code, signal, testIds, cwd)),
@@ -199,16 +216,22 @@ export class PytestTestExecutionAdapter implements ITestExecutionAdapter {
199216
data: JSON.stringify(utils.createEOTPayload(true)),
200217
});
201218
}
202-
deferredExec.resolve({ stdout: '', stderr: '' });
219+
// deferredTillEOT is resolved when all data sent on stdout and stderr is received, close event is only called when this occurs
220+
// due to the sync reading of the output.
221+
deferredTillExecClose?.resolve();
203222
});
204-
await deferredExec.promise;
223+
await deferredTillExecClose?.promise;
205224
}
206225
} catch (ex) {
207226
traceError(`Error while running tests: ${testIds}\r\n${ex}\r\n\r\n`);
208227
return Promise.reject(ex);
209228
}
210229

211-
const executionPayload: ExecutionTestPayload = { cwd, status: 'success', error: '' };
230+
const executionPayload: ExecutionTestPayload = {
231+
cwd,
232+
status: 'success',
233+
error: '',
234+
};
212235
return executionPayload;
213236
}
214237
}

‎src/test/mocks/mockChildProcess.ts‎

Lines changed: 3 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -133,9 +133,9 @@ export class MockChildProcess extends EventEmitter {
133133

134134
emit(event: string | symbol, ...args: unknown[]): boolean {
135135
if (this.eventMap.has(event.toString())) {
136-
this.eventMap.get(event.toString()).forEach((listener: (arg0: unknown) => void) => {
137-
const argsArray = Array.isArray(args) ? args : [args];
138-
listener(argsArray);
136+
this.eventMap.get(event.toString()).forEach((listener: (...arg0: unknown[]) => void) => {
137+
const argsArray: unknown[] = Array.isArray(args) ? args : [args];
138+
listener(...argsArray);
139139
});
140140
}
141141
return true;

‎src/test/testing/common/testingPayloadsEot.test.ts‎

Lines changed: 5 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -66,6 +66,7 @@ suite('EOT tests', () => {
6666
let testController: TestController;
6767
let stubExecutionFactory: typeMoq.IMock<IPythonExecutionFactory>;
6868
let client: net.Socket;
69+
let mockProc: MockChildProcess;
6970
const sandbox = sinon.createSandbox();
7071
// const unittestProvider: TestProvider = UNITTEST_PROVIDER;
7172
// const pytestProvider: TestProvider = PYTEST_PROVIDER;
@@ -86,7 +87,7 @@ suite('EOT tests', () => {
8687
traceLog('Socket connection error:', error);
8788
});
8889

89-
const mockProc = new MockChildProcess('', ['']);
90+
mockProc = new MockChildProcess('', ['']);
9091
const output2 = new Observable<Output<string>>(() => {
9192
/* no op */
9293
});
@@ -156,15 +157,17 @@ suite('EOT tests', () => {
156157
}
157158
})(client, payloadArray[i]);
158159
}
160+
mockProc.emit('close', 0, null);
159161
client.end();
160162
});
161163

162164
resultResolver = new PythonResultResolver(testController, PYTEST_PROVIDER, workspaceUri);
163165
resultResolver._resolveExecution = async (payload, _token?) => {
164166
// the payloads that get to the _resolveExecution are all data and should be successful.
167+
actualCollectedResult = actualCollectedResult + JSON.stringify(payload.result);
165168
assert.strictEqual(payload.status, 'success', "Expected status to be 'success'");
166169
assert.ok(payload.result, 'Expected results to be present');
167-
actualCollectedResult = actualCollectedResult + JSON.stringify(payload.result);
170+
168171
return Promise.resolve();
169172
};
170173
// set workspace to test workspace folder
@@ -200,10 +203,6 @@ suite('EOT tests', () => {
200203
actualCollectedResult,
201204
"Expected collected result to match 'data'",
202205
);
203-
// nervous about this not testing race conditions correctly
204-
// client.end();
205-
// verify that the _resolveExecution was called once per test
206-
// assert.strictEqual(callCount, 1, 'Expected _resolveExecution to be called once');
207206
});
208207
});
209208
});

‎src/test/testing/testController/pytest/pytestExecutionAdapter.unit.test.ts‎

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -268,7 +268,7 @@ suite('pytest test execution adapter', () => {
268268
traceInfo('stubs launch debugger');
269269
deferredEOT.resolve();
270270
});
271-
const utilsCreateEOTStub: sinon.SinonStub = sinon.stub(util, 'createEOTDeferred');
271+
const utilsCreateEOTStub: sinon.SinonStub = sinon.stub(util, 'createTestingDeferred');
272272
utilsCreateEOTStub.callsFake(() => deferredEOT);
273273
const testRun = typeMoq.Mock.ofType<TestRun>();
274274
testRun

0 commit comments

Comments
 (0)