From ff604ca9988420aefa4f66c1681e3d3374c5e03c Mon Sep 17 00:00:00 2001 From: Eleanor Boyd Date: Wed, 1 Nov 2023 09:31:16 -0700 Subject: [PATCH] Add cwd to error logs (#22387) closes https://github.com/microsoft/vscode-python/issues/22359 --- .../testController/common/resultResolver.ts | 2 +- .../testing/testController/common/server.ts | 14 +++++----- .../testing/testController/common/utils.ts | 4 +-- .../pytest/pytestDiscoveryAdapter.ts | 14 +++++++--- .../pytest/pytestExecutionAdapter.ts | 26 ++++++++++++------- .../testController/workspaceTestAdapter.ts | 2 +- .../workspaceTestAdapter.unit.test.ts | 10 ++++--- 7 files changed, 44 insertions(+), 28 deletions(-) diff --git a/src/client/testing/testController/common/resultResolver.ts b/src/client/testing/testController/common/resultResolver.ts index 22a13090e1b1..3bf7d6baf34b 100644 --- a/src/client/testing/testController/common/resultResolver.ts +++ b/src/client/testing/testController/common/resultResolver.ts @@ -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( diff --git a/src/client/testing/testController/common/server.ts b/src/client/testing/testController/common/server.ts index 4e7a617a3ffd..5969a5f75708 100644 --- a/src/client/testing/testController/common/server.ts +++ b/src/client/testing/testController/common/server.ts @@ -221,7 +221,7 @@ 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?.(); @@ -229,17 +229,17 @@ export class PythonTestServer implements ITestServer, Disposable { } 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>(); 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(); @@ -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, @@ -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({ @@ -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, diff --git a/src/client/testing/testController/common/utils.ts b/src/client/testing/testController/common/utils.ts index 48e7fd3f2dd7..23ee881a405a 100644 --- a/src/client/testing/testController/common/utils.ts +++ b/src/client/testing/testController/common/utils.ts @@ -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. @@ -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}`, ], }; } diff --git a/src/client/testing/testController/pytest/pytestDiscoveryAdapter.ts b/src/client/testing/testController/pytest/pytestDiscoveryAdapter.ts index 7599513497d7..39dc87ed12c1 100644 --- a/src/client/testing/testController/pytest/pytestDiscoveryAdapter.ts +++ b/src/client/testing/testController/pytest/pytestDiscoveryAdapter.ts @@ -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 @@ -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, @@ -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 = createTestingDeferred(); const result = execService?.execObservable(execArgs, spawnOptions); @@ -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) => { diff --git a/src/client/testing/testController/pytest/pytestExecutionAdapter.ts b/src/client/testing/testController/pytest/pytestExecutionAdapter.ts index 5812df48600c..8995a182a774 100644 --- a/src/client/testing/testController/pytest/pytestExecutionAdapter.ts +++ b/src/client/testing/testController/pytest/pytestExecutionAdapter.ts @@ -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) { @@ -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(); }); @@ -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, @@ -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(); }); @@ -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(); @@ -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}`, + ); } }); @@ -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, @@ -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); } diff --git a/src/client/testing/testController/workspaceTestAdapter.ts b/src/client/testing/testController/workspaceTestAdapter.ts index f3ea0b9f6193..35a5b7a24418 100644 --- a/src/client/testing/testController/workspaceTestAdapter.ts +++ b/src/client/testing/testController/workspaceTestAdapter.ts @@ -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); diff --git a/src/test/testing/testController/workspaceTestAdapter.unit.test.ts b/src/test/testing/testController/workspaceTestAdapter.unit.test.ts index 41cd1bbd7ef2..abee275c1bb6 100644 --- a/src/test/testing/testController/workspaceTestAdapter.unit.test.ts +++ b/src/test/testing/testController/workspaceTestAdapter.unit.test.ts @@ -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', () => { @@ -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, ); @@ -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(); + 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 () => {