diff --git a/src/client/testing/testController/common/server.ts b/src/client/testing/testController/common/server.ts index a00623aa33c7..62c14d451fc2 100644 --- a/src/client/testing/testController/common/server.ts +++ b/src/client/testing/testController/common/server.ts @@ -9,7 +9,7 @@ import { IPythonExecutionFactory, SpawnOptions, } from '../../../common/process/types'; -import { traceLog } from '../../../logging'; +import { traceError, traceInfo, traceLog, traceVerbose } from '../../../logging'; import { DataReceivedEvent, ITestServer, TestCommandOptions } from './types'; import { ITestDebugLauncher, LaunchOptions } from '../../common/types'; import { UNITTEST_PROVIDER } from '../../common/constants'; @@ -36,12 +36,12 @@ export class PythonTestServer implements ITestServer, Disposable { const uuid = rpcHeaders.headers.get(JSONRPC_UUID_HEADER); const totalContentLength = rpcHeaders.headers.get('Content-Length'); if (!uuid) { - traceLog('On data received: Error occurred because payload UUID is undefined'); + traceError('On data received: Error occurred because payload UUID is undefined'); this._onDataReceived.fire({ uuid: '', data: '' }); return; } if (!this.uuids.includes(uuid)) { - traceLog('On data received: Error occurred because the payload UUID is not recognized'); + traceError('On data received: Error occurred because the payload UUID is not recognized'); this._onDataReceived.fire({ uuid: '', data: '' }); return; } @@ -50,6 +50,7 @@ export class PythonTestServer implements ITestServer, Disposable { const extractedData = rpcContent.extractedJSON; if (extractedData.length === Number(totalContentLength)) { // do not send until we have the full content + traceVerbose(`Received data from test server: ${extractedData}`); this._onDataReceived.fire({ uuid, data: extractedData }); this.uuids = this.uuids.filter((u) => u !== uuid); buffer = Buffer.alloc(0); @@ -58,7 +59,7 @@ export class PythonTestServer implements ITestServer, Disposable { } } } catch (ex) { - traceLog(`Error processing test server request: ${ex} observe`); + traceError(`Error processing test server request: ${ex} observe`); this._onDataReceived.fire({ uuid: '', data: '' }); } }); @@ -114,6 +115,8 @@ export class PythonTestServer implements ITestServer, Disposable { outputChannel: options.outChannel, }; + const isRun = !options.testIds; + // Create the Python environment in which to execute the command. const creationOptions: ExecutionFactoryCreateWithEnvironmentOptions = { allowEnvironmentFetchExceptions: false, @@ -154,9 +157,16 @@ export class PythonTestServer implements ITestServer, Disposable { token: options.token, testProvider: UNITTEST_PROVIDER, }; - + traceInfo(`Running DEBUG unittest with arguments: ${args}\r\n`); await this.debugLauncher!.launchDebugger(launchOptions); } else { + if (isRun) { + // This means it is running the test + traceInfo(`Running unittests with arguments: ${args}\r\n`); + } else { + // This means it is running discovery + traceLog(`Discovering unittest tests with arguments: ${args}\r\n`); + } await execService.exec(args, spawnOptions); } } catch (ex) { diff --git a/src/client/testing/testController/controller.ts b/src/client/testing/testController/controller.ts index 6c6b9f409e5f..0d3487855380 100644 --- a/src/client/testing/testController/controller.ts +++ b/src/client/testing/testController/controller.ts @@ -24,7 +24,7 @@ import { IConfigurationService, IDisposableRegistry, ITestOutputChannel, Resourc import { DelayedTrigger, IDelayedTrigger } from '../../common/utils/delayTrigger'; import { noop } from '../../common/utils/misc'; import { IInterpreterService } from '../../interpreter/contracts'; -import { traceError, traceVerbose } from '../../logging'; +import { traceError, traceInfo, traceVerbose } from '../../logging'; import { IEventNamePropertyMapping, sendTelemetryEvent } from '../../telemetry'; import { EventName } from '../../telemetry/constants'; import { PYTEST_PROVIDER, UNITTEST_PROVIDER } from '../common/constants'; @@ -243,14 +243,14 @@ export class PythonTestController implements ITestController, IExtensionSingleAc this.refreshingStartedEvent.fire(); if (uri) { const settings = this.configSettings.getSettings(uri); - traceVerbose(`Testing: Refreshing test data for ${uri.fsPath}`); + const workspace = this.workspaceService.getWorkspaceFolder(uri); + traceInfo(`Discover tests for workspace name: ${workspace?.name} - uri: ${uri.fsPath}`); + // Ensure we send test telemetry if it gets disabled again + this.sendTestDisabledTelemetry = true; + // ** experiment to roll out NEW test discovery mechanism if (settings.testing.pytestEnabled) { - // Ensure we send test telemetry if it gets disabled again - this.sendTestDisabledTelemetry = true; - // ** experiment to roll out NEW test discovery mechanism if (pythonTestAdapterRewriteEnabled(this.serviceContainer)) { - const workspace = this.workspaceService.getWorkspaceFolder(uri); - traceVerbose(`Discover tests for workspace name: ${workspace?.name} - uri: ${uri.fsPath}`); + traceInfo(`Running discovery for pytest using the new test adapter.`); const testAdapter = this.testAdapters.get(uri) || (this.testAdapters.values().next().value as WorkspaceTestAdapter); testAdapter.discoverTests( @@ -263,12 +263,8 @@ export class PythonTestController implements ITestController, IExtensionSingleAc await this.pytest.refreshTestData(this.testController, uri, this.refreshCancellation.token); } } else if (settings.testing.unittestEnabled) { - // ** Ensure we send test telemetry if it gets disabled again - this.sendTestDisabledTelemetry = true; - // ** experiment to roll out NEW test discovery mechanism if (pythonTestAdapterRewriteEnabled(this.serviceContainer)) { - const workspace = this.workspaceService.getWorkspaceFolder(uri); - traceVerbose(`Discover tests for workspace name: ${workspace?.name} - uri: ${uri.fsPath}`); + traceInfo(`Running discovery for unittest using the new test adapter.`); const testAdapter = this.testAdapters.get(uri) || (this.testAdapters.values().next().value as WorkspaceTestAdapter); testAdapter.discoverTests( @@ -288,7 +284,6 @@ export class PythonTestController implements ITestController, IExtensionSingleAc // If we are here we may have to remove an existing node from the tree // This handles the case where user removes test settings. Which should remove the // tests for that particular case from the tree view - const workspace = this.workspaceService.getWorkspaceFolder(uri); if (workspace) { const toDelete: string[] = []; this.testController.items.forEach((i: TestItem) => { diff --git a/src/client/testing/testController/pytest/pytestDiscoveryAdapter.ts b/src/client/testing/testController/pytest/pytestDiscoveryAdapter.ts index 792826f4c3a5..aeb920407cd2 100644 --- a/src/client/testing/testController/pytest/pytestDiscoveryAdapter.ts +++ b/src/client/testing/testController/pytest/pytestDiscoveryAdapter.ts @@ -10,7 +10,7 @@ import { import { IConfigurationService, ITestOutputChannel } from '../../../common/types'; import { createDeferred, Deferred } from '../../../common/utils/async'; import { EXTENSION_ROOT_DIR } from '../../../constants'; -import { traceVerbose } from '../../../logging'; +import { traceError, traceLog, traceVerbose } from '../../../logging'; import { DataReceivedEvent, DiscoveredTestPayload, ITestDiscoveryAdapter, ITestServer } from '../common/types'; /** @@ -80,11 +80,12 @@ export class PytestTestDiscoveryAdapter implements ITestDiscoveryAdapter { resource: uri, }; const execService = await executionFactory.createActivatedEnvironment(creationOptions); - execService - .exec(['-m', 'pytest', '-p', 'vscode_pytest', '--collect-only'].concat(pytestArgs), spawnOptions) - .catch((ex) => { - deferred.reject(ex as Error); - }); + const discoveryArgs = ['-m', 'pytest', '-p', 'vscode_pytest', '--collect-only'].concat(pytestArgs); + traceLog(`Discovering pytest tests with arguments: ${discoveryArgs.join(' ')}`); + execService.exec(discoveryArgs, spawnOptions).catch((ex) => { + traceError(`Error occurred while discovering tests: ${ex}`); + deferred.reject(ex as Error); + }); return deferred.promise; } } diff --git a/src/client/testing/testController/pytest/pytestExecutionAdapter.ts b/src/client/testing/testController/pytest/pytestExecutionAdapter.ts index 39b7f8c787b9..413d18497613 100644 --- a/src/client/testing/testController/pytest/pytestExecutionAdapter.ts +++ b/src/client/testing/testController/pytest/pytestExecutionAdapter.ts @@ -6,7 +6,7 @@ import * as path from 'path'; import * as net from 'net'; import { IConfigurationService, ITestOutputChannel } from '../../../common/types'; import { createDeferred, Deferred } from '../../../common/utils/async'; -import { traceError, traceLog, traceVerbose } from '../../../logging'; +import { traceError, traceInfo, traceLog, traceVerbose } from '../../../logging'; import { DataReceivedEvent, ExecutionTestPayload, ITestExecutionAdapter, ITestServer } from '../common/types'; import { ExecutionFactoryCreateWithEnvironmentOptions, @@ -21,7 +21,7 @@ import { EXTENSION_ROOT_DIR } from '../../../common/constants'; // eslint-disable-next-line @typescript-eslint/no-explicit-any // (global as any).EXTENSION_ROOT_DIR = EXTENSION_ROOT_DIR; /** - * Wrapper Class for pytest test execution. This is where we call `runTestCommand`? + * Wrapper Class for pytest test execution.. */ export class PytestTestExecutionAdapter implements ITestExecutionAdapter { @@ -52,7 +52,6 @@ export class PytestTestExecutionAdapter implements ITestExecutionAdapter { executionFactory?: IPythonExecutionFactory, debugLauncher?: ITestDebugLauncher, ): Promise { - traceVerbose(uri, testIds, debugBool); if (executionFactory !== undefined) { // ** new version of run tests. return this.runTestsNew(uri, testIds, debugBool, executionFactory, debugLauncher); @@ -120,41 +119,43 @@ export class PytestTestExecutionAdapter implements ITestExecutionAdapter { const testData = JSON.stringify(testIds); const headers = [`Content-Length: ${Buffer.byteLength(testData)}`, 'Content-Type: application/json']; const payload = `${headers.join('\r\n')}\r\n\r\n${testData}`; + traceLog(`Running pytest execution for the following test ids: ${testIds}`); let pytestRunTestIdsPort: string | undefined; const startServer = (): Promise => new Promise((resolve, reject) => { const server = net.createServer((socket: net.Socket) => { socket.on('end', () => { - traceLog('Client disconnected'); + traceVerbose('Client disconnected for pytest test ids server'); }); }); server.listen(0, () => { const { port } = server.address() as net.AddressInfo; - traceLog(`Server listening on port ${port}`); + traceVerbose(`Server listening on port ${port} for pytest test ids server`); resolve(port); }); server.on('error', (error: Error) => { + traceError('Error starting server for pytest test ids server:', error); reject(error); }); server.on('connection', (socket: net.Socket) => { socket.write(payload); - traceLog('payload sent', payload); + traceVerbose('payload sent for pytest execution', payload); }); }); // Start the server and wait until it is listening await startServer() .then((assignedPort) => { - traceLog(`Server started and listening on port ${assignedPort}`); + traceVerbose(`Server started for pytest test ids server and listening on port ${assignedPort}`); pytestRunTestIdsPort = assignedPort.toString(); if (spawnOptions.extraVariables) spawnOptions.extraVariables.RUN_TEST_IDS_PORT = pytestRunTestIdsPort; }) .catch((error) => { - traceError('Error starting server:', error); + traceError('Error starting server for pytest test ids server:', error); }); if (debugBool) { @@ -169,12 +170,13 @@ export class PytestTestExecutionAdapter implements ITestExecutionAdapter { pytestUUID, pytestRunTestIdsPort, }; - traceVerbose(`Running debug test with arguments: ${testArgs.join(' ')}\r\n`); + traceInfo(`Running DEBUG pytest with arguments: ${testArgs.join(' ')}\r\n`); await debugLauncher!.launchDebugger(launchOptions); } else { // 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 pytests with arguments: ${runArgs.join(' ')}\r\n`); await execService?.exec(runArgs, spawnOptions).catch((ex) => { traceError(`Error while running tests: ${testIds}\r\n${ex}\r\n\r\n`); @@ -182,7 +184,7 @@ export class PytestTestExecutionAdapter implements ITestExecutionAdapter { }); } } catch (ex) { - traceVerbose(`Error while running tests: ${testIds}\r\n${ex}\r\n\r\n`); + traceError(`Error while running tests: ${testIds}\r\n${ex}\r\n\r\n`); return Promise.reject(ex); } diff --git a/src/client/testing/testController/unittest/testDiscoveryAdapter.ts b/src/client/testing/testController/unittest/testDiscoveryAdapter.ts index 3f8ecb5797d3..9c565af78c08 100644 --- a/src/client/testing/testController/unittest/testDiscoveryAdapter.ts +++ b/src/client/testing/testController/unittest/testDiscoveryAdapter.ts @@ -14,6 +14,7 @@ import { TestCommandOptions, TestDiscoveryCommand, } from '../common/types'; +import { traceInfo } from '../../../logging'; /** * Wrapper class for unittest test discovery. This is where we call `runTestCommand`. @@ -61,6 +62,7 @@ export class UnittestTestDiscoveryAdapter implements ITestDiscoveryAdapter { // Send the test command to the server. // The server will fire an onDataReceived event once it gets a response. + traceInfo(`Sending discover unittest script to server.`); this.testServer.sendCommand(options); return deferred.promise; diff --git a/src/client/testing/testController/workspaceTestAdapter.ts b/src/client/testing/testController/workspaceTestAdapter.ts index 0edac06c2b5a..5cba6c193d3c 100644 --- a/src/client/testing/testController/workspaceTestAdapter.ts +++ b/src/client/testing/testController/workspaceTestAdapter.ts @@ -101,6 +101,7 @@ export class WorkspaceTestAdapter { const testCaseIds = Array.from(testCaseIdsSet); // ** execution factory only defined for new rewrite way if (executionFactory !== undefined) { + traceVerbose('executionFactory defined'); rawTestExecData = await this.executionAdapter.runTests( this.workspaceUri, testCaseIds, @@ -108,7 +109,6 @@ export class WorkspaceTestAdapter { executionFactory, debugLauncher, ); - traceVerbose('executionFactory defined'); } else { rawTestExecData = await this.executionAdapter.runTests(this.workspaceUri, testCaseIds, debugBool); } @@ -300,6 +300,7 @@ export class WorkspaceTestAdapter { try { // ** execution factory only defined for new rewrite way if (executionFactory !== undefined) { + traceVerbose('executionFactory defined'); rawTestData = await this.discoveryAdapter.discoverTests(this.workspaceUri, executionFactory); } else { rawTestData = await this.discoveryAdapter.discoverTests(this.workspaceUri);