Skip to content

Commit

Permalink
Add cwd to error logs (microsoft#22387)
Browse files Browse the repository at this point in the history
  • Loading branch information
eleanorjboyd authored Nov 1, 2023
1 parent 78052bd commit ff604ca
Show file tree
Hide file tree
Showing 7 changed files with 44 additions and 28 deletions.
2 changes: 1 addition & 1 deletion src/client/testing/testController/common/resultResolver.ts
Original file line number Diff line number Diff line change
Expand Up @@ -74,7 +74,7 @@ export class PythonResultResolver implements ITestResultResolver {
const testingErrorConst =
this.testProvider === 'pytest' ? Testing.errorPytestDiscovery : Testing.errorUnittestDiscovery;
const { error } = rawTestData;
traceError(testingErrorConst, '\r\n', error?.join('\r\n\r\n') ?? '');
traceError(testingErrorConst, 'for workspace: ', workspacePath, '\r\n', error?.join('\r\n\r\n') ?? '');

let errorNode = this.testController.items.get(`DiscoveryError:${workspacePath}`);
const message = util.format(
Expand Down
14 changes: 7 additions & 7 deletions src/client/testing/testController/common/server.ts
Original file line number Diff line number Diff line change
Expand Up @@ -221,25 +221,25 @@ export class PythonTestServer implements ITestServer, Disposable {
pytestUUID: uuid.toString(),
pytestPort: this.getPort().toString(),
};
traceInfo(`Running DEBUG unittest with arguments: ${args}\r\n`);
traceInfo(`Running DEBUG unittest for workspace ${options.cwd} with arguments: ${args}\r\n`);

await this.debugLauncher!.launchDebugger(launchOptions, () => {
callback?.();
});
} else {
if (isRun) {
// This means it is running the test
traceInfo(`Running unittests with arguments: ${args}\r\n`);
traceInfo(`Running unittests for workspace ${options.cwd} with arguments: ${args}\r\n`);
} else {
// This means it is running discovery
traceLog(`Discovering unittest tests with arguments: ${args}\r\n`);
traceLog(`Discovering unittest tests for workspace ${options.cwd} with arguments: ${args}\r\n`);
}
const deferredTillExecClose = createDeferred<ExecutionResult<string>>();

let resultProc: ChildProcess | undefined;

runInstance?.token.onCancellationRequested(() => {
traceInfo('Test run cancelled, killing unittest subprocess.');
traceInfo(`Test run cancelled, killing unittest subprocess for workspace ${options.cwd}.`);
// 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();
Expand Down Expand Up @@ -285,7 +285,7 @@ export class PythonTestServer implements ITestServer, Disposable {
if (code !== 0) {
// This occurs when we are running discovery
traceError(
`Subprocess exited unsuccessfully with exit code ${code} and signal ${signal}. Creating and sending error discovery payload`,
`Subprocess exited unsuccessfully with exit code ${code} and signal ${signal} on workspace ${options.cwd}. Creating and sending error discovery payload \n`,
);
this._onDiscoveryDataReceived.fire({
uuid,
Expand All @@ -301,7 +301,7 @@ export class PythonTestServer implements ITestServer, Disposable {
// This occurs when we are running the test and there is an error which occurs.

traceError(
`Subprocess exited unsuccessfully with exit code ${code} and signal ${signal}. Creating and sending error execution payload`,
`Subprocess exited unsuccessfully with exit code ${code} and signal ${signal} for workspace ${options.cwd}. Creating and sending error execution payload \n`,
);
// if the child process exited with a non-zero exit code, then we need to send the error payload.
this._onRunDataReceived.fire({
Expand All @@ -319,7 +319,7 @@ export class PythonTestServer implements ITestServer, Disposable {
await deferredTillExecClose.promise;
}
} catch (ex) {
traceError(`Error while server attempting to run unittest command: ${ex}`);
traceError(`Error while server attempting to run unittest command for workspace ${options.cwd}: ${ex}`);
this.uuids = this.uuids.filter((u) => u !== uuid);
this._onDataReceived.fire({
uuid,
Expand Down
4 changes: 2 additions & 2 deletions src/client/testing/testController/common/utils.ts
Original file line number Diff line number Diff line change
Expand Up @@ -297,7 +297,7 @@ export function createExecutionErrorPayload(
const etp: ExecutionTestPayload = {
cwd,
status: 'error',
error: 'Test run failed, the python test process was terminated before it could exit on its own.',
error: `Test run failed, the python test process was terminated before it could exit on its own for workspace ${cwd}`,
result: {},
};
// add error result for each attempted test.
Expand All @@ -321,7 +321,7 @@ export function createDiscoveryErrorPayload(
cwd,
status: 'error',
error: [
` \n The python test process was terminated before it could exit on its own, the process errored with: Code: ${code}, Signal: ${signal}`,
` \n The python test process was terminated before it could exit on its own, the process errored with: Code: ${code}, Signal: ${signal} for workspace ${cwd}`,
],
};
}
Expand Down
14 changes: 10 additions & 4 deletions src/client/testing/testController/pytest/pytestDiscoveryAdapter.ts
Original file line number Diff line number Diff line change
Expand Up @@ -54,7 +54,7 @@ export class PytestTestDiscoveryAdapter implements ITestDiscoveryAdapter {
await this.runPytestDiscovery(uri, uuid, executionFactory);
} finally {
await deferredTillEOT.promise;
traceVerbose('deferredTill EOT resolved');
traceVerbose(`deferredTill EOT resolved for ${uri.fsPath}`);
disposeDataReceiver(this.testServer);
}
// this is only a placeholder to handle function overloading until rewrite is finished
Expand All @@ -79,7 +79,11 @@ export class PytestTestDiscoveryAdapter implements ITestDiscoveryAdapter {
mutableEnv.PYTHONPATH = pythonPathCommand;
mutableEnv.TEST_UUID = uuid.toString();
mutableEnv.TEST_PORT = this.testServer.getPort().toString();
traceInfo(`All environment variables set for pytest discovery: ${JSON.stringify(mutableEnv)}`);
traceInfo(
`All environment variables set for pytest discovery for workspace ${uri.fsPath}: ${JSON.stringify(
mutableEnv,
)} \n`,
);
const spawnOptions: SpawnOptions = {
cwd,
throwOnStdErr: true,
Expand All @@ -95,7 +99,7 @@ export class PytestTestDiscoveryAdapter implements ITestDiscoveryAdapter {
const execService = await executionFactory?.createActivatedEnvironment(creationOptions);
// delete UUID following entire discovery finishing.
const execArgs = ['-m', 'pytest', '-p', 'vscode_pytest', '--collect-only'].concat(pytestArgs);
traceVerbose(`Running pytest discovery with command: ${execArgs.join(' ')}`);
traceVerbose(`Running pytest discovery with command: ${execArgs.join(' ')} for workspace ${uri.fsPath}.`);

const deferredTillExecClose: Deferred<void> = createTestingDeferred();
const result = execService?.execObservable(execArgs, spawnOptions);
Expand All @@ -117,7 +121,9 @@ export class PytestTestDiscoveryAdapter implements ITestDiscoveryAdapter {
result?.proc?.on('exit', (code, signal) => {
this.outputChannel?.append(MESSAGE_ON_TESTING_OUTPUT_MOVE);
if (code !== 0) {
traceError(`Subprocess exited unsuccessfully with exit code ${code} and signal ${signal}.`);
traceError(
`Subprocess exited unsuccessfully with exit code ${code} and signal ${signal} on workspace ${uri.fsPath}.`,
);
}
});
result?.proc?.on('close', (code, signal) => {
Expand Down
26 changes: 17 additions & 9 deletions src/client/testing/testController/pytest/pytestExecutionAdapter.ts
Original file line number Diff line number Diff line change
Expand Up @@ -53,7 +53,7 @@ export class PytestTestExecutionAdapter implements ITestExecutionAdapter {
const eParsed = JSON.parse(e.data);
this.resultResolver?.resolveExecution(eParsed, runInstance, deferredTillEOT);
} else {
traceError('No run instance found, cannot resolve execution.');
traceError(`No run instance found, cannot resolve execution, for workspace ${uri.fsPath}.`);
}
});
const disposeDataReceiver = function (testServer: ITestServer) {
Expand All @@ -62,7 +62,7 @@ export class PytestTestExecutionAdapter implements ITestExecutionAdapter {
dataReceivedDisposable.dispose();
};
runInstance?.token.onCancellationRequested(() => {
traceInfo("Test run cancelled, resolving 'till EOT' deferred.");
traceInfo(`Test run cancelled, resolving 'till EOT' deferred for ${uri.fsPath}.`);
deferredTillEOT.resolve();
});

Expand Down Expand Up @@ -143,7 +143,11 @@ export class PytestTestExecutionAdapter implements ITestExecutionAdapter {
// add port with run test ids to env vars
const pytestRunTestIdsPort = await utils.startTestIdServer(testIds);
mutableEnv.RUN_TEST_IDS_PORT = pytestRunTestIdsPort.toString();
traceInfo(`All environment variables set for pytest execution: ${JSON.stringify(mutableEnv)}`);
traceInfo(
`All environment variables set for pytest execution in ${uri.fsPath} workspace: \n ${JSON.stringify(
mutableEnv,
)}`,
);

const spawnOptions: SpawnOptions = {
cwd,
Expand All @@ -165,7 +169,9 @@ export class PytestTestExecutionAdapter implements ITestExecutionAdapter {
pytestUUID,
runTestIdsPort: pytestRunTestIdsPort.toString(),
};
traceInfo(`Running DEBUG pytest with arguments: ${testArgs.join(' ')}\r\n`);
traceInfo(
`Running DEBUG pytest with arguments: ${testArgs.join(' ')} for workspace ${uri.fsPath} \r\n`,
);
await debugLauncher!.launchDebugger(launchOptions, () => {
deferredTillEOT?.resolve();
});
Expand All @@ -175,12 +181,12 @@ export class PytestTestExecutionAdapter implements ITestExecutionAdapter {
// 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`);
traceInfo(`Running pytest with arguments: ${runArgs.join(' ')} for workspace ${uri.fsPath} \r\n`);

let resultProc: ChildProcess | undefined;

runInstance?.token.onCancellationRequested(() => {
traceInfo('Test run cancelled, killing pytest subprocess.');
traceInfo(`Test run cancelled, killing pytest subprocess for workspace ${uri.fsPath}`);
// 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();
Expand Down Expand Up @@ -208,7 +214,9 @@ export class PytestTestExecutionAdapter implements ITestExecutionAdapter {
result?.proc?.on('exit', (code, signal) => {
this.outputChannel?.append(utils.MESSAGE_ON_TESTING_OUTPUT_MOVE);
if (code !== 0 && testIds) {
traceError(`Subprocess exited unsuccessfully with exit code ${code} and signal ${signal}.`);
traceError(
`Subprocess exited unsuccessfully with exit code ${code} and signal ${signal} on workspace ${uri.fsPath}`,
);
}
});

Expand All @@ -218,7 +226,7 @@ export class PytestTestExecutionAdapter implements ITestExecutionAdapter {
// 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 closed unsuccessfully with exit code ${code} and signal ${signal}. Creating and sending error execution payload`,
`Subprocess closed unsuccessfully with exit code ${code} and signal ${signal} for workspace ${uri.fsPath}. Creating and sending error execution payload \n`,
);
this.testServer.triggerRunDataReceivedEvent({
uuid,
Expand All @@ -237,7 +245,7 @@ export class PytestTestExecutionAdapter implements ITestExecutionAdapter {
await deferredTillExecClose?.promise;
}
} catch (ex) {
traceError(`Error while running tests: ${testIds}\r\n${ex}\r\n\r\n`);
traceError(`Error while running tests for workspace ${uri}: ${testIds}\r\n${ex}\r\n\r\n`);
return Promise.reject(ex);
}

Expand Down
2 changes: 1 addition & 1 deletion src/client/testing/testController/workspaceTestAdapter.ts
Original file line number Diff line number Diff line change
Expand Up @@ -143,7 +143,7 @@ export class WorkspaceTestAdapter {
cancel = token?.isCancellationRequested ? Testing.cancelPytestDiscovery : Testing.errorPytestDiscovery;
}

traceError(`${cancel}\r\n`, ex);
traceError(`${cancel} for workspace: ${this.workspaceUri} \r\n`, ex);

// Report also on the test view.
const message = util.format(`${cancel} ${Testing.seePythonOutput}\r\n`, ex);
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -16,6 +16,7 @@ import { ITestResultResolver, ITestServer } from '../../../client/testing/testCo
import * as testItemUtilities from '../../../client/testing/testController/common/testItemUtilities';
import * as util from '../../../client/testing/testController/common/utils';
import * as ResultResolver from '../../../client/testing/testController/common/resultResolver';
import { IPythonExecutionFactory } from '../../../client/common/process/types';

suite('Workspace test adapter', () => {
suite('Test discovery', () => {
Expand Down Expand Up @@ -137,12 +138,12 @@ suite('Workspace test adapter', () => {
stubConfigSettings,
outputChannel.object,
);

const uriFoo = Uri.parse('foo');
const workspaceTestAdapter = new WorkspaceTestAdapter(
'unittest',
testDiscoveryAdapter,
testExecutionAdapter,
Uri.parse('foo'),
uriFoo,
stubResultResolver,
);

Expand All @@ -164,10 +165,11 @@ suite('Workspace test adapter', () => {
const buildErrorNodeOptionsStub = sinon.stub(util, 'buildErrorNodeOptions').returns(errorTestItemOptions);
const testProvider = 'unittest';

await workspaceTestAdapter.discoverTests(testController);
const execFactory = typemoq.Mock.ofType<IPythonExecutionFactory>();
await workspaceTestAdapter.discoverTests(testController, undefined, execFactory.object);

sinon.assert.calledWithMatch(createErrorTestItemStub, sinon.match.any, sinon.match.any);
sinon.assert.calledWithMatch(buildErrorNodeOptionsStub, Uri.parse('foo'), sinon.match.any, testProvider);
sinon.assert.calledWithMatch(buildErrorNodeOptionsStub, uriFoo, sinon.match.any, testProvider);
});

test("When discovering tests, the workspace test adapter should call the test discovery adapter's discoverTest method", async () => {
Expand Down

0 comments on commit ff604ca

Please sign in to comment.