diff --git a/.vscode-test.js b/.vscode-test.js index 2a1072d22..e5c232519 100644 --- a/.vscode-test.js +++ b/.vscode-test.js @@ -44,6 +44,7 @@ const launchArgs = [ "--disable-gpu", "--disable-gpu-sandbox", "--disable-chromium-sandbox", + "--disable-extension=vscode.git", "--no-xshm", ]; if (dataDir) { diff --git a/scripts/soundness.sh b/scripts/soundness.sh index 1540fd1f6..839713563 100755 --- a/scripts/soundness.sh +++ b/scripts/soundness.sh @@ -103,8 +103,9 @@ EOF \( \! -path './assets/*' -a \ \( \! -path './coverage/*' -a \ \( \! -path './.husky/*' -a \ + \( \! -path './src/typings/*' -a \ \( "${matching_files[@]}" \) \ - \) \) \) \) \) \) \) + \) \) \) \) \) \) \) \) \) } | while read -r line; do if [[ "$(replace_acceptable_years < "$line" | head -n "$expected_lines" | shasum)" != "$expected_sha" ]]; then printf "\033[0;31mmissing headers in file '%s'!\033[0m\n" "$line" diff --git a/src/BackgroundCompilation.ts b/src/BackgroundCompilation.ts index 8de59e168..68e132949 100644 --- a/src/BackgroundCompilation.ts +++ b/src/BackgroundCompilation.ts @@ -26,6 +26,7 @@ export class BackgroundCompilation implements vscode.Disposable { private workspaceFileWatcher?: vscode.FileSystemWatcher; private configurationEventDisposable?: vscode.Disposable; private disposables: vscode.Disposable[] = []; + private _disposed = false; constructor(private folderContext: FolderContext) { // We only want to configure the file watcher if background compilation is enabled. @@ -59,7 +60,9 @@ export class BackgroundCompilation implements vscode.Disposable { this.workspaceFileWatcher.onDidChange( debounce( () => { - void this.runTask(); + if (!this._disposed) { + void this.runTask(); + } }, 100 /* 10 times per second */, { trailing: true } @@ -73,6 +76,7 @@ export class BackgroundCompilation implements vscode.Disposable { } dispose() { + this._disposed = true; this.configurationEventDisposable?.dispose(); this.disposables.forEach(disposable => disposable.dispose()); } diff --git a/src/FolderContext.ts b/src/FolderContext.ts index d5190a70c..003de394e 100644 --- a/src/FolderContext.ts +++ b/src/FolderContext.ts @@ -70,6 +70,7 @@ export class FolderContext implements vscode.Disposable { this.packageWatcher.dispose(); this.testExplorer?.dispose(); this.backgroundCompilation.dispose(); + this.taskQueue.dispose(); } /** diff --git a/src/PackageWatcher.ts b/src/PackageWatcher.ts index 96d18364a..25e5618d5 100644 --- a/src/PackageWatcher.ts +++ b/src/PackageWatcher.ts @@ -108,6 +108,8 @@ export class PackageWatcher { watcher.onDidDelete(async () => await this.handleWorkspaceStateChange()); if (await fileExists(uri.fsPath)) { + // TODO: Remove this + this.logger.info("Loading initial workspace-state.json"); await this.handleWorkspaceStateChange(); } @@ -193,6 +195,10 @@ export class PackageWatcher { */ private async handleWorkspaceStateChange() { await this.folderContext.reloadWorkspaceState(); + // TODO: Remove this + this.logger.info( + `Package watcher state updated workspace-state.json: ${JSON.stringify(this.folderContext.swiftPackage.workspaceState, null, 2)}` + ); await this.folderContext.fireEvent(FolderOperation.workspaceStateUpdated); } } diff --git a/src/SwiftPackage.ts b/src/SwiftPackage.ts index d4b6c318a..ab64b2724 100644 --- a/src/SwiftPackage.ts +++ b/src/SwiftPackage.ts @@ -204,7 +204,8 @@ export class SwiftPackage { readonly folder: vscode.Uri, private contentsPromise: Promise, public resolved: PackageResolved | undefined, - private workspaceState: WorkspaceState | undefined + // TODO: Make private again + public workspaceState: WorkspaceState | undefined ) {} /** diff --git a/src/WorkspaceContext.ts b/src/WorkspaceContext.ts index 77e5ccebc..68403a4f0 100644 --- a/src/WorkspaceContext.ts +++ b/src/WorkspaceContext.ts @@ -34,6 +34,7 @@ import { SwiftTaskProvider } from "./tasks/SwiftTaskProvider"; import { TaskManager } from "./tasks/TaskManager"; import { BuildFlags } from "./toolchain/BuildFlags"; import { SwiftToolchain } from "./toolchain/toolchain"; +import { ProjectPanelProvider } from "./ui/ProjectPanelProvider"; import { StatusItem } from "./ui/StatusItem"; import { SwiftBuildStatus } from "./ui/SwiftBuildStatus"; import { isExcluded, isPathInsidePath } from "./utilities/filesystem"; @@ -60,6 +61,7 @@ export class WorkspaceContext implements vscode.Disposable { public commentCompletionProvider: CommentCompletionProviders; public documentation: DocumentationManager; public testRunManager: TestRunManager; + public projectPanel: ProjectPanelProvider; private lastFocusUri: vscode.Uri | undefined; private initialisationFinished = false; @@ -102,6 +104,7 @@ export class WorkspaceContext implements vscode.Disposable { this.documentation = new DocumentationManager(extensionContext, this); this.currentDocument = null; this.commentCompletionProvider = new CommentCompletionProviders(); + this.projectPanel = new ProjectPanelProvider(this); const onChangeConfig = vscode.workspace.onDidChangeConfiguration(async event => { // Clear build path cache when build-related configurations change @@ -225,6 +228,7 @@ export class WorkspaceContext implements vscode.Disposable { this.logger, this.statusItem, this.buildStatus, + this.projectPanel, ]; this.lastFocusUri = vscode.window.activeTextEditor?.document.uri; @@ -463,7 +467,7 @@ export class WorkspaceContext implements vscode.Disposable { // find context with root folder const index = this.folders.findIndex(context => context.folder.fsPath === folder.fsPath); if (index !== -1) { - this.logger.warn(`Adding package folder ${folder} twice`); + this.logger.warn(`Adding package folder ${folder} twice: ${Error().stack}`); return this.folders[index]; } const folderContext = await FolderContext.create(folder, workspaceFolder, this); diff --git a/src/commands/dependencies/useLocal.ts b/src/commands/dependencies/useLocal.ts index f69543f97..8db43bb81 100644 --- a/src/commands/dependencies/useLocal.ts +++ b/src/commands/dependencies/useLocal.ts @@ -67,12 +67,21 @@ export async function useLocalDependency( currentFolder.toolchain ); + ctx.logger.debug( + `Placing dependency "${identifier}" in "editing" state with task: ${task.definition}` + ); + const success = await executeTaskWithUI( task, `Use local version of ${identifier}`, currentFolder, true ); + + ctx.logger.debug( + `Finished placing dependency "${identifier}" in "editing" state, success: ${success}` + ); + if (success) { await ctx.fireEvent(currentFolder, FolderOperation.resolvedUpdated); } diff --git a/src/debugger/buildConfig.ts b/src/debugger/buildConfig.ts index 35e9fee45..062431c31 100644 --- a/src/debugger/buildConfig.ts +++ b/src/debugger/buildConfig.ts @@ -441,6 +441,7 @@ export class TestingConfigurationFactory { if (xcTestPath === undefined) { return null; } + const toolchain = this.ctx.toolchain; return { ...baseConfig, program: path.join(xcTestPath, "xctest"), @@ -450,6 +451,16 @@ export class TestingConfigurationFactory { env: { ...this.testEnv, ...this.sanitizerRuntimeEnvironment, + ...(toolchain.swiftVersion.isGreaterThanOrEqual( + new Version(6, 2, 0) + ) + ? { + // Starting in 6.2 we need to provide libTesting.dylib for xctests + DYLD_FRAMEWORK_PATH: + toolchain.swiftTestingFrameworkPath(), + DYLD_LIBRARY_PATH: toolchain.swiftTestingLibraryPath(), + } + : {}), SWIFT_TESTING_ENABLED: "0", }, }; diff --git a/src/debugger/debugAdapterFactory.ts b/src/debugger/debugAdapterFactory.ts index 7fdc0d0af..67390fa08 100644 --- a/src/debugger/debugAdapterFactory.ts +++ b/src/debugger/debugAdapterFactory.ts @@ -148,9 +148,9 @@ export class LLDBDebugConfigurationProvider implements vscode.DebugConfiguration return undefined; } } - if (!(await this.promptForCodeLldbSettings(toolchain))) { - return undefined; - } + + await this.promptForCodeLldbSettingsIfRequired(toolchain); + // Rename lldb-dap's "terminateCommands" to "preTerminateCommands" for CodeLLDB if ("terminateCommands" in launchConfig) { launchConfig["preTerminateCommands"] = launchConfig["terminateCommands"]; @@ -203,7 +203,7 @@ export class LLDBDebugConfigurationProvider implements vscode.DebugConfiguration } } - async promptForCodeLldbSettings(toolchain: SwiftToolchain): Promise { + async promptForCodeLldbSettingsIfRequired(toolchain: SwiftToolchain) { const libLldbPathResult = await getLLDBLibPath(toolchain); if (!libLldbPathResult.success) { const errorMessage = `Error: ${getErrorDescription(libLldbPathResult.failure)}`; @@ -211,7 +211,7 @@ export class LLDBDebugConfigurationProvider implements vscode.DebugConfiguration `Failed to setup CodeLLDB for debugging of Swift code. Debugging may produce unexpected results. ${errorMessage}` ); this.logger.error(`Failed to setup CodeLLDB: ${errorMessage}`); - return true; + return; } const libLldbPath = libLldbPathResult.success; const lldbConfig = vscode.workspace.getConfiguration("lldb"); @@ -219,7 +219,7 @@ export class LLDBDebugConfigurationProvider implements vscode.DebugConfiguration lldbConfig.get("library") === libLldbPath && lldbConfig.get("launch.expressions") === "native" ) { - return true; + return; } let userSelection: "Global" | "Workspace" | "Run Anyway" | undefined = undefined; switch (configuration.debugger.setupCodeLLDB) { @@ -272,7 +272,6 @@ export class LLDBDebugConfigurationProvider implements vscode.DebugConfiguration ); break; } - return true; } private convertEnvironmentVariables(map: { [key: string]: string }): string[] { diff --git a/src/extension.ts b/src/extension.ts index 9ee3c1437..9cf991052 100644 --- a/src/extension.ts +++ b/src/extension.ts @@ -33,7 +33,6 @@ import { SelectedXcodeWatcher } from "./toolchain/SelectedXcodeWatcher"; import { checkForSwiftlyInstallation } from "./toolchain/swiftly"; import { SwiftToolchain } from "./toolchain/toolchain"; import { LanguageStatusItems } from "./ui/LanguageStatusItems"; -import { ProjectPanelProvider } from "./ui/ProjectPanelProvider"; import { getReadOnlyDocumentProvider } from "./ui/ReadOnlyDocumentProvider"; import { showToolchainError } from "./ui/ToolchainSelection"; import { checkAndWarnAboutWindowsSymlinks } from "./ui/win32"; @@ -144,14 +143,13 @@ export async function activate(context: vscode.ExtensionContext): Promise { ); // project panel provider - const projectPanelProvider = new ProjectPanelProvider(workspaceContext); const dependenciesView = vscode.window.createTreeView("projectPanel", { - treeDataProvider: projectPanelProvider, + treeDataProvider: workspaceContext.projectPanel, showCollapseAll: true, }); - projectPanelProvider.observeFolders(dependenciesView); + workspaceContext.projectPanel.observeFolders(dependenciesView); - context.subscriptions.push(dependenciesView, projectPanelProvider); + context.subscriptions.push(dependenciesView); // observer that will resolve package and build launch configurations context.subscriptions.push(workspaceContext.onDidChangeFolders(handleFolderEvent(logger))); diff --git a/src/sourcekit-lsp/LanguageClientManager.ts b/src/sourcekit-lsp/LanguageClientManager.ts index 9d987aecd..13ec7d139 100644 --- a/src/sourcekit-lsp/LanguageClientManager.ts +++ b/src/sourcekit-lsp/LanguageClientManager.ts @@ -517,11 +517,13 @@ export class LanguageClientManager implements vscode.Disposable { this.logMessage(client, params as SourceKitLogMessageParams); }); - // start client - this.clientReadyPromise = client - .start() - .then(() => runningPromise) - .then(() => { + // Create and save the client ready promise + this.clientReadyPromise = (async () => { + try { + // start client + await client.start(); + await runningPromise; + // Now that we've started up correctly, start the error handler to auto-restart // if sourcekit-lsp crashes during normal operation. errorHandler.enable(); @@ -546,15 +548,19 @@ export class LanguageClientManager implements vscode.Disposable { this.subscriptions.push(this.didChangeActiveDocument); } } catch { - // do nothing + // do nothing, the experimental capability is not supported + } + } catch (reason) { + this.folderContext.workspaceContext.logger.error( + `Error starting SourceKit-LSP: ${reason}` + ); + if (this.languageClient?.state === State.Running) { + await this.languageClient?.stop(); } - }) - .catch(reason => { - this.folderContext.workspaceContext.logger.error(reason); - void this.languageClient?.stop(); this.languageClient = undefined; throw reason; - }); + } + })(); this.languageClient = client; this.cancellationToken = new vscode.CancellationTokenSource(); diff --git a/src/tasks/TaskQueue.ts b/src/tasks/TaskQueue.ts index 0d04ac8e1..ccfc86272 100644 --- a/src/tasks/TaskQueue.ts +++ b/src/tasks/TaskQueue.ts @@ -163,7 +163,7 @@ class QueuedOperation { * * Queue swift task operations to be executed serially */ -export class TaskQueue { +export class TaskQueue implements vscode.Disposable { queue: QueuedOperation[]; activeOperation?: QueuedOperation; workspaceContext: WorkspaceContext; @@ -176,6 +176,11 @@ export class TaskQueue { this.disabled = false; } + dispose() { + this.queue = []; + this.activeOperation = undefined; + } + /** * Add operation to queue * @param operation Operation to queue diff --git a/src/toolchain/toolchain.ts b/src/toolchain/toolchain.ts index aa4f0e88c..5ead0bc01 100644 --- a/src/toolchain/toolchain.ts +++ b/src/toolchain/toolchain.ts @@ -127,7 +127,8 @@ export class SwiftToolchain { ); const toolchainPath = await this.getToolchainPath(swiftFolderPath, folder, logger); const targetInfo = await this.getSwiftTargetInfo( - this._getToolchainExecutable(toolchainPath, "swift") + this._getToolchainExecutable(toolchainPath, "swift"), + logger ); const swiftVersion = this.getSwiftVersion(targetInfo); const [runtimePath, defaultSDK] = await Promise.all([ @@ -872,24 +873,35 @@ export class SwiftToolchain { } /** @returns swift target info */ - private static async getSwiftTargetInfo(swiftExecutable: string): Promise { + private static async getSwiftTargetInfo( + swiftExecutable: string, + logger?: SwiftLogger + ): Promise { try { try { const { stdout } = await execSwift(["-print-target-info"], { swiftExecutable }); const targetInfo = JSON.parse(stdout.trimEnd()) as SwiftTargetInfo; + if (!targetInfo.target) { + logger?.warn( + `No target found in toolchain, targetInfo was: ${JSON.stringify(targetInfo)}` + ); + } + if (targetInfo.compilerVersion) { return targetInfo; } - } catch { + } catch (error) { // hit error while running `swift -print-target-info`. We are possibly running // a version of swift 5.3 or older + logger?.warn(`Error while running 'swift -print-target-info': ${error}`); } const { stdout } = await execSwift(["--version"], { swiftExecutable }); return { compilerVersion: stdout.split(lineBreakRegex, 1)[0], paths: { runtimeLibraryPaths: [""] }, }; - } catch { + } catch (error) { + logger?.warn(`Error while running 'swift --version': ${error}`); throw Error( "Failed to get swift version from either '-print-target-info' or '--version'." ); diff --git a/src/ui/ProjectPanelProvider.ts b/src/ui/ProjectPanelProvider.ts index 512c53bd8..7e6615697 100644 --- a/src/ui/ProjectPanelProvider.ts +++ b/src/ui/ProjectPanelProvider.ts @@ -164,15 +164,13 @@ export class PackageNode { } async getChildren(): Promise { - const [childDeps, files] = await Promise.all([ - this.childDependencies(this.dependency), - getChildren( - this.dependency.path, - excludedFilesForProjectPanelExplorer(), - this.id, - this.fs - ), - ]); + const childDeps = this.childDependencies(this.dependency); + const files = await getChildren( + this.dependency.path, + excludedFilesForProjectPanelExplorer(), + this.id, + this.fs + ); const childNodes = childDeps.map( dep => new PackageNode(dep, this.childDependencies, this.id) ); @@ -493,6 +491,8 @@ export class ProjectPanelProvider implements vscode.TreeDataProvider { dispose() { this.workspaceObserver?.dispose(); + this.disposables.forEach(d => d.dispose()); + this.disposables.length = 0; } observeTasks(ctx: WorkspaceContext) { @@ -502,11 +502,17 @@ export class ProjectPanelProvider implements vscode.TreeDataProvider { vscode.tasks.onDidStartTask(e => { const taskId = e.execution.task.detail ?? e.execution.task.name; this.activeTasks.add(taskId); + this.workspaceContext.logger.info( + `Project panel updating after task ${taskId} has started` + ); this.didChangeTreeDataEmitter.fire(); }), vscode.tasks.onDidEndTask(e => { const taskId = e.execution.task.detail ?? e.execution.task.name; this.activeTasks.delete(taskId); + this.workspaceContext.logger.info( + `Project panel updating after task ${taskId} has ended` + ); this.didChangeTreeDataEmitter.fire(); }), ctx.onDidStartBuild(e => { @@ -515,6 +521,7 @@ export class ProjectPanelProvider implements vscode.TreeDataProvider { } else { this.activeTasks.add(e.targetName); } + this.workspaceContext.logger.info("Project panel updating after build has started"); this.didChangeTreeDataEmitter.fire(); }), ctx.onDidFinishBuild(e => { @@ -523,18 +530,25 @@ export class ProjectPanelProvider implements vscode.TreeDataProvider { } else { this.activeTasks.delete(e.targetName); } + this.workspaceContext.logger.info( + "Project panel updating after build has finished" + ); this.didChangeTreeDataEmitter.fire(); }), ctx.onDidStartTests(e => { for (const target of e.targets) { this.activeTasks.add(testTaskName(target)); } + this.workspaceContext.logger.info("Project panel updating on test run start"); this.didChangeTreeDataEmitter.fire(); }), ctx.onDidFinishTests(e => { for (const target of e.targets) { this.activeTasks.delete(testTaskName(target)); } + this.workspaceContext.logger.info( + "Project panel updating after test run has finished" + ); this.didChangeTreeDataEmitter.fire(); }) ); @@ -545,6 +559,9 @@ export class ProjectPanelProvider implements vscode.TreeDataProvider { e.affectsConfiguration("files.exclude") || e.affectsConfiguration("swift.excludePathsFromPackageDependencies") ) { + this.workspaceContext.logger.info( + "Project panel updating due to configuration changes" + ); this.didChangeTreeDataEmitter.fire(); } }) @@ -561,10 +578,16 @@ export class ProjectPanelProvider implements vscode.TreeDataProvider { } this.watchBuildPluginOutputs(folder); treeView.title = `Swift Project (${folder.name})`; + this.workspaceContext.logger.info( + `Project panel updating, focused folder ${folder.name}` + ); this.didChangeTreeDataEmitter.fire(); break; case FolderOperation.unfocus: treeView.title = `Swift Project`; + this.workspaceContext.logger.info( + `Project panel updating, unfocused folder` + ); this.didChangeTreeDataEmitter.fire(); break; case FolderOperation.workspaceStateUpdated: @@ -572,9 +595,15 @@ export class ProjectPanelProvider implements vscode.TreeDataProvider { case FolderOperation.packageViewUpdated: case FolderOperation.pluginsUpdated: if (!folder) { + this.workspaceContext.logger.info( + `Project panel cannot update, "${operation}" event was provided with no folder.` + ); return; } if (folder === this.workspaceContext.currentFolder) { + this.workspaceContext.logger.info( + `Project panel updating, "${operation}" for folder ${folder.name}` + ); this.didChangeTreeDataEmitter.fire(); } } @@ -685,8 +714,14 @@ export class ProjectPanelProvider implements vscode.TreeDataProvider { if (!folderContext) { return []; } + this.workspaceContext.logger.info("Project panel refreshing dependencies"); const pkg = folderContext.swiftPackage; const rootDeps = await pkg.rootDependencies; + + rootDeps.forEach(dep => { + this.workspaceContext.logger.info(`\tAdding dependency: ${dep.identity}`); + }); + if (this.workspaceContext.contextKeys.flatDependenciesList) { const existenceMap = new Map(); const gatherChildren = (dependencies: ResolvedDependency[]): ResolvedDependency[] => { @@ -825,6 +860,7 @@ class TaskPoller implements vscode.Disposable { dispose() { if (this.timeout) { clearTimeout(this.timeout); + this.timeout = undefined; } } } diff --git a/test/integration-tests/FolderContext.test.ts b/test/integration-tests/FolderContext.test.ts index d5b537485..30c3638ce 100644 --- a/test/integration-tests/FolderContext.test.ts +++ b/test/integration-tests/FolderContext.test.ts @@ -26,6 +26,7 @@ import { activateExtensionForSuite, getRootWorkspaceFolder } from "./utilities/t suite("FolderContext Error Handling Test Suite", () => { let workspaceContext: WorkspaceContext; + let folderContext: FolderContext | undefined; let swiftToolchainCreateStub: MockedFunction; const showToolchainError = mockGlobalValue(toolchain, "showToolchainError"); @@ -38,6 +39,7 @@ suite("FolderContext Error Handling Test Suite", () => { }); afterEach(() => { + folderContext?.dispose(); restore(); }); @@ -52,11 +54,7 @@ suite("FolderContext Error Handling Test Suite", () => { const workspaceFolder = getRootWorkspaceFolder(); const testFolder = testAssetUri("package2"); - const folderContext = await FolderContext.create( - testFolder, - workspaceFolder, - workspaceContext - ); + folderContext = await FolderContext.create(testFolder, workspaceFolder, workspaceContext); assert.ok(folderContext, "FolderContext should be created despite toolchain failure"); assert.strictEqual( @@ -99,11 +97,7 @@ suite("FolderContext Error Handling Test Suite", () => { const showToolchainErrorStub = stub().resolves(true); showToolchainError.setValue(showToolchainErrorStub); - const folderContext = await FolderContext.create( - testFolder, - workspaceFolder, - workspaceContext - ); + folderContext = await FolderContext.create(testFolder, workspaceFolder, workspaceContext); // Assert: FolderContext should be created successfully assert.ok(folderContext, "FolderContext should be created after retry"); @@ -146,11 +140,7 @@ suite("FolderContext Error Handling Test Suite", () => { const showToolchainErrorStub = stub().resolves(true); showToolchainError.setValue(showToolchainErrorStub); - const folderContext = await FolderContext.create( - testFolder, - workspaceFolder, - workspaceContext - ); + folderContext = await FolderContext.create(testFolder, workspaceFolder, workspaceContext); assert.ok( folderContext, diff --git a/test/integration-tests/commands/build.test.ts b/test/integration-tests/commands/build.test.ts index ba78c312e..877cedca5 100644 --- a/test/integration-tests/commands/build.test.ts +++ b/test/integration-tests/commands/build.test.ts @@ -62,7 +62,15 @@ tag("large").suite("Build Commands", function () { expect(result).to.be.true; }); - test("Swift: Debug Build", async () => { + test("Swift: Debug Build", async function () { + // This is failing in CI only in Linux 5.10 by crashing VS Code with the error + // `CodeWindow: renderer process gone (reason: crashed, code: 133)` + if ( + folderContext.swiftVersion.isGreaterThanOrEqual(new Version(5, 10, 0)) && + folderContext.swiftVersion.isLessThan(new Version(6, 0, 0)) + ) { + this.skip(); + } // Promise used to indicate we hit the break point. // NB: "stopped" is the exact command when debuggee has stopped due to break point, // but "stackTrace" is the deterministic sync point we will use to make sure we can execute continue diff --git a/test/integration-tests/commands/dependency.test.ts b/test/integration-tests/commands/dependency.test.ts index 2379c282b..40aaf683d 100644 --- a/test/integration-tests/commands/dependency.test.ts +++ b/test/integration-tests/commands/dependency.test.ts @@ -12,6 +12,8 @@ // //===----------------------------------------------------------------------===// import { expect } from "chai"; +import * as fs from "fs/promises"; +import * as path from "path"; import * as vscode from "vscode"; import { FolderContext } from "@src/FolderContext"; @@ -22,9 +24,13 @@ import { PackageNode, ProjectPanelProvider } from "@src/ui/ProjectPanelProvider" import { testAssetUri } from "../../fixtures"; import { tag } from "../../tags"; import { waitForNoRunningTasks } from "../../utilities/tasks"; -import { activateExtensionForSuite, findWorkspaceFolder } from "../utilities/testutilities"; +import { + activateExtensionForSuite, + findWorkspaceFolder, + folderInRootWorkspace, +} from "../utilities/testutilities"; -tag("large").suite("Dependency Commmands Test Suite", function () { +tag("large").suite("Dependency Commands Test Suite", function () { let depsContext: FolderContext; let workspaceContext: WorkspaceContext; @@ -65,10 +71,17 @@ tag("large").suite("Dependency Commmands Test Suite", function () { async function getDependency() { const headers = await treeProvider.getChildren(); const header = headers.find(n => n.name === "Dependencies") as PackageNode; + workspaceContext.logger.info( + `getDependency: Current headers: ${headers.map(n => n.name)}` + ); if (!header) { return; } + const children = await header.getChildren(); + workspaceContext.logger.info( + `getDependencyInState: Current children for "Dependencies" entry: ${children.map(n => n.name).join(", ")}` + ); return children.find( n => n.name.toLocaleLowerCase() === "swift-markdown" ) as PackageNode; @@ -79,20 +92,56 @@ tag("large").suite("Dependency Commmands Test Suite", function () { // and RESET_PACKAGE commands because the file watcher on // workspace-state.json needs to trigger. async function getDependencyInState(state: "remote" | "editing") { + let depType: string | undefined; for (let i = 0; i < 10; i++) { const dep = await getDependency(); if (dep?.type === state) { return dep; } + depType = dep?.type; await new Promise(resolve => setTimeout(resolve, 1000)); } - throw Error(`Could not find dependency with state "${state}"`); + + const headers = await treeProvider.getChildren(); + const headerNames = headers.map(n => n.name); + const depChildren = await ( + headers.find(n => n.name === "Dependencies") as PackageNode + )?.getChildren(); + const childrenNames = depChildren?.map(n => n.name) ?? []; + + const dependenciesFolderContext = await folderInRootWorkspace( + "dependencies", + workspaceContext + ); + const resolvedPath = path.join( + dependenciesFolderContext.folder.fsPath, + "Package.resolved" + ); + const packageResolvedContents = await fs.readFile(resolvedPath, "utf8"); + + throw Error( + `Could not find dependency with state "${state}", instead it was "${depType}". Current headers: ${headerNames.map(h => `"${h}"`).join(", ")}, Current children for "Dependencies" entry: ${childrenNames.map(c => `"${c}"`).join(", ")}\nContents of Package.resolved:\n${packageResolvedContents}` + ); } async function useLocalDependencyTest() { + workspaceContext.logger.info( + "useLocalDependencyTest: Fetching the dependency in the 'remote' state" + ); + // spm edit with user supplied local version of dependency const item = await getDependencyInState("remote"); const localDep = testAssetUri("swift-markdown"); + + workspaceContext.logger.info( + "useLocalDependencyTest: Resolving latest dependencies before editing" + ); + + // Perform a resolve first to make sure that dependencies are up to date + await vscode.commands.executeCommand(Commands.RESOLVE_DEPENDENCIES); + + workspaceContext.logger.info(`Configuring ${localDep.fsPath} to the "editing" state`); + const result = await vscode.commands.executeCommand( Commands.USE_LOCAL_DEPENDENCY, item, @@ -101,15 +150,25 @@ tag("large").suite("Dependency Commmands Test Suite", function () { ); expect(result).to.be.true; + workspaceContext.logger.info( + "useLocalDependencyTest: Set use local dependency to remote, now verifying" + ); + const dep = await getDependencyInState("editing"); expect(dep).to.not.be.undefined; // Make sure using local expect(dep?.type).to.equal("editing"); + + workspaceContext.logger.info( + "useLocalDependencyTest: Use local dependency was verified to be in 'editing' state" + ); } test("Swift: Reset Package Dependencies", async function () { await useLocalDependencyTest(); + workspaceContext.logger.info("Resetting package dependency to remote version"); + // spm reset const result = await vscode.commands.executeCommand( Commands.RESET_PACKAGE, @@ -123,9 +182,11 @@ tag("large").suite("Dependency Commmands Test Suite", function () { expect(dep?.type).to.equal("remote"); }); - test("Swift: Revert To Original Version", async function () { + test("Swift: Unedit To Original Version", async function () { await useLocalDependencyTest(); + workspaceContext.logger.info("Unediting package dependency to original version"); + const result = await vscode.commands.executeCommand( Commands.UNEDIT_DEPENDENCY, await getDependencyInState("editing"), diff --git a/test/integration-tests/language/LanguageClientIntegration.test.ts b/test/integration-tests/language/LanguageClientIntegration.test.ts index 05754e56c..5e8e0ded4 100644 --- a/test/integration-tests/language/LanguageClientIntegration.test.ts +++ b/test/integration-tests/language/LanguageClientIntegration.test.ts @@ -30,6 +30,7 @@ async function buildProject(ctx: WorkspaceContext, name: string) { await waitForNoRunningTasks(); const folderContext = await folderInRootWorkspace(name, ctx); const task = await createBuildAllTask(folderContext); + task.definition.dontTriggerTestDiscovery = true; const { exitCode, output } = await executeTaskAndWaitForResult(task); expect(exitCode, `${output}`).to.equal(0); return folderContext; diff --git a/test/integration-tests/tasks/SwiftPluginTaskProvider.test.ts b/test/integration-tests/tasks/SwiftPluginTaskProvider.test.ts index fba67001b..9371e6eb7 100644 --- a/test/integration-tests/tasks/SwiftPluginTaskProvider.test.ts +++ b/test/integration-tests/tasks/SwiftPluginTaskProvider.test.ts @@ -42,9 +42,17 @@ tag("medium").suite("SwiftPluginTaskProvider Test Suite", function () { activateExtensionForSuite({ async setup(ctx) { workspaceContext = ctx; + ctx.logger.info("Locating command-plugin folder in root workspace"); folderContext = await folderInRootWorkspace("command-plugin", workspaceContext); + ctx.logger.info( + "Located command-plugin folder in root workspace at " + folderContext.folder.fsPath + ); const logger = await ctx.loggerFactory.temp("SwiftPluginTaskProvider.tests"); + ctx.logger.info("Loading swift plugins"); await folderContext.loadSwiftPlugins(logger); + ctx.logger.info( + "Finished loading swift plugins, captured logs should be empty: " + logger.logs + ); if (logger.logs.length > 0) { expect.fail( `Expected no output channel logs: ${JSON.stringify(logger.logs, undefined, 2)}` diff --git a/test/integration-tests/testexplorer/TestExplorerIntegration.test.ts b/test/integration-tests/testexplorer/TestExplorerIntegration.test.ts index 5930c78b1..76b7d1de3 100644 --- a/test/integration-tests/testexplorer/TestExplorerIntegration.test.ts +++ b/test/integration-tests/testexplorer/TestExplorerIntegration.test.ts @@ -25,6 +25,7 @@ import { MessageRenderer, TestSymbol, } from "@src/TestExplorer/TestParsers/SwiftTestingOutputParser"; +import { TestRunProxy } from "@src/TestExplorer/TestRunner"; import { flattenTestItemCollection, reduceTestItemChildren } from "@src/TestExplorer/TestUtils"; import { WorkspaceContext } from "@src/WorkspaceContext"; import { Commands } from "@src/commands"; @@ -39,6 +40,7 @@ import { activateExtensionForSuite, folderInRootWorkspace, updateSettings, + withLogging, } from "../utilities/testutilities"; import { assertContains, @@ -48,7 +50,7 @@ import { buildStateFromController, eventPromise, gatherTests, - runTest, + runTest as runTestWithLogging, waitForTestExplorerReady, } from "./utilities"; @@ -56,23 +58,39 @@ tag("large").suite("Test Explorer Suite", function () { let workspaceContext: WorkspaceContext; let folderContext: FolderContext; let testExplorer: TestExplorer; + let runTest: ( + testExplorer: TestExplorer, + runProfile: TestKind, + ...tests: string[] + ) => Promise; activateExtensionForSuite({ async setup(ctx) { workspaceContext = ctx; - folderContext = await folderInRootWorkspace("defaultPackage", workspaceContext); + runTest = runTestWithLogging.bind(null, workspaceContext.logger); + const logger = withLogging(ctx.logger); + folderContext = await logger("Locating defaultPackage folder in root workspace", () => + folderInRootWorkspace("defaultPackage", workspaceContext) + ); if (!folderContext) { throw new Error("Unable to find test explorer"); } - testExplorer = await folderContext.resolvedTestExplorer; + testExplorer = await logger( + "Waiting for test explorer to resolve", + () => folderContext.resolvedTestExplorer + ); - await executeTaskAndWaitForResult(await createBuildAllTask(folderContext)); + await logger("Executing build all task", async () => + executeTaskAndWaitForResult(await createBuildAllTask(folderContext)) + ); // Set up the listener before bringing the text explorer in to focus, // which starts searching the workspace for tests. - await waitForTestExplorerReady(testExplorer); + await logger("Waiting for test explorer to be ready", () => + waitForTestExplorerReady(testExplorer) + ); }, requiresLSP: true, requiresDebugger: true, diff --git a/test/integration-tests/testexplorer/utilities.ts b/test/integration-tests/testexplorer/utilities.ts index bde6e8503..cfed0d214 100644 --- a/test/integration-tests/testexplorer/utilities.ts +++ b/test/integration-tests/testexplorer/utilities.ts @@ -19,6 +19,7 @@ import { TestKind } from "@src/TestExplorer/TestKind"; import { TestRunProxy } from "@src/TestExplorer/TestRunner"; import { reduceTestItemChildren } from "@src/TestExplorer/TestUtils"; import { WorkspaceContext } from "@src/WorkspaceContext"; +import { SwiftLogger } from "@src/logging/SwiftLogger"; import { testAssetUri } from "../../fixtures"; import { @@ -295,10 +296,12 @@ export function gatherTests( * @returns A test run proxy whose `runState` can be inspected for test results. */ export async function runTest( + logger: SwiftLogger, testExplorer: TestExplorer, runProfile: TestKind, ...tests: string[] ): Promise { + logger.info(`runTest: ${runProfile} tests: ${tests}`); const targetProfile = testExplorer.testRunProfiles.find( profile => profile.label === runProfile ); @@ -308,13 +311,22 @@ export async function runTest( const testItems = gatherTests(testExplorer.controller, ...tests); const request = new vscode.TestRunRequest(testItems); + logger.info(`runTest: configuring test run with ${testItems}`); + // The first promise is the return value, the second promise builds and runs // the tests, populating the TestRunProxy with results and blocking the return // of that TestRunProxy until the test run is complete. return ( await Promise.all([ - eventPromise(testExplorer.onCreateTestRun), - targetProfile.runHandler(request, new vscode.CancellationTokenSource().token), + eventPromise(testExplorer.onCreateTestRun).then(run => { + logger.info(`runTest: created test run with items ${run.testItems}`); + return run; + }), + targetProfile + .runHandler(request, new vscode.CancellationTokenSource().token) + ?.then(() => { + logger.info(`runTest: completed running tests`); + }), ]) )[0]; } diff --git a/test/integration-tests/ui/ProjectPanelProvider.test.ts b/test/integration-tests/ui/ProjectPanelProvider.test.ts index e2aa64c2a..247a1d3b1 100644 --- a/test/integration-tests/ui/ProjectPanelProvider.test.ts +++ b/test/integration-tests/ui/ProjectPanelProvider.test.ts @@ -16,6 +16,7 @@ import { afterEach, beforeEach } from "mocha"; import * as path from "path"; import * as vscode from "vscode"; +import { FolderContext } from "@src/FolderContext"; import { WorkspaceContext } from "@src/WorkspaceContext"; import { Commands } from "@src/commands"; import { createBuildAllTask } from "@src/tasks/SwiftTaskProvider"; @@ -44,6 +45,7 @@ tag("medium").suite("ProjectPanelProvider Test Suite", function () { activateExtensionForSuite({ async setup(ctx) { workspaceContext = ctx; + const folderContext = await folderInRootWorkspace("targets", workspaceContext); await vscode.workspace.openTextDocument( path.join(folderContext.folder.fsPath, "Package.swift") @@ -55,7 +57,9 @@ tag("medium").suite("ProjectPanelProvider Test Suite", function () { `Expected no output channel logs: ${JSON.stringify(logger.logs, undefined, 2)}` ); } - treeProvider = new ProjectPanelProvider(workspaceContext); + + treeProvider = ctx.projectPanel; + await workspaceContext.focusFolder(folderContext); const buildAllTask = await createBuildAllTask(folderContext); buildAllTask.definition.dontTriggerTestDiscovery = true; @@ -63,7 +67,6 @@ tag("medium").suite("ProjectPanelProvider Test Suite", function () { }, async teardown() { workspaceContext.contextKeys.flatDependenciesList = false; - treeProvider.dispose(); }, testAssets: ["targets"], }); @@ -404,13 +407,31 @@ tag("medium").suite("ProjectPanelProvider Test Suite", function () { expect(items.find(n => n.name === "defaultpackage")).to.not.be.undefined; }); - test("Shows an error node when there is a problem compiling Package.swift", async () => { - workspaceContext.folders[0].hasResolveErrors = true; - workspaceContext.currentFolder = workspaceContext.folders[0]; - const treeProvider = new ProjectPanelProvider(workspaceContext); - const children = await treeProvider.getChildren(); - const errorNode = children.find(n => n.name === "Error Parsing Package.swift"); - expect(errorNode).to.not.be.undefined; + suite("Error handling", () => { + let savedCurrentFolder: FolderContext | null | undefined; + let errorTreeProvider: ProjectPanelProvider | undefined; + + beforeEach(async () => { + workspaceContext.folders[0].hasResolveErrors = true; + savedCurrentFolder = workspaceContext.currentFolder; + workspaceContext.currentFolder = workspaceContext.folders[0]; + }); + + afterEach(() => { + errorTreeProvider?.dispose(); + errorTreeProvider = undefined; + workspaceContext.folders[0].hasResolveErrors = false; + workspaceContext.currentFolder = savedCurrentFolder; + }); + + test("Shows an error node when there is a problem compiling Package.swift", async () => { + workspaceContext.folders[0].hasResolveErrors = true; + workspaceContext.currentFolder = workspaceContext.folders[0]; + errorTreeProvider = new ProjectPanelProvider(workspaceContext); + const children = await errorTreeProvider.getChildren(); + const errorNode = children.find(n => n.name === "Error Parsing Package.swift"); + expect(errorNode).to.not.be.undefined; + }); }); suite("Excluded files", () => { diff --git a/test/integration-tests/utilities/testutilities.ts b/test/integration-tests/utilities/testutilities.ts index 03771cbba..03fc819cf 100644 --- a/test/integration-tests/utilities/testutilities.ts +++ b/test/integration-tests/utilities/testutilities.ts @@ -20,6 +20,7 @@ import * as vscode from "vscode"; import { FolderContext } from "@src/FolderContext"; import { FolderOperation, WorkspaceContext } from "@src/WorkspaceContext"; import configuration from "@src/configuration"; +import { getLLDBLibPath } from "@src/debugger/lldb"; import { Api } from "@src/extension"; import { SwiftLogger } from "@src/logging/SwiftLogger"; import { buildAllTaskName, resetBuildAllTaskCache } from "@src/tasks/SwiftTaskProvider"; @@ -37,10 +38,68 @@ export function getRootWorkspaceFolder(): vscode.WorkspaceFolder { return result; } -function printLogs(logger: SwiftLogger, message: string) { +interface Loggable { + get logs(): string[]; +} + +function printLogs(logger: Loggable, message: string) { console.error(`${message}, captured logs are:`); logger.logs.map(log => console.log(log)); - console.log("======== END OF LOGS ========\n\n"); + console.log("======== END OF LOGS ========\n"); +} + +// Until the logger on the WorkspaceContext is available we capture logs here. +// Once it becomes available (via setLogger) we forward logs to that logger to maintain ordering. +class ExtensionActivationLogger implements Loggable { + private logger: SwiftLogger | undefined; + private _logs: string[] = []; + + get logs(): string[] { + return [...this._logs, ...(this.logger?.logs ?? [])]; + } + + setLogger(logger: SwiftLogger) { + this.logger = logger; + } + + private formatTimestamp(): string { + const now = new Date(); + return now.toLocaleString("en-US", { + hour: "2-digit", + minute: "2-digit", + second: "2-digit", + hour12: false, + }); + } + + info(message: string) { + const timestamp = this.formatTimestamp(); + const timestampedMessage = `[${timestamp}] ${message}`; + + if (this.logger) { + this.logger.info(timestampedMessage); + } else { + this._logs.push(timestampedMessage); + } + } + + reset() { + this._logs = []; + this.logger = undefined; + } +} + +// Mocha doesn't give us a hook to run code when a before block times out. +// This utility method can be used to dump logs right before the before block times out. +// Ensure you pass in a timeout that is slightly less than mocha's `before` timeout. +function configureLogDumpOnTimeout(timeout: number, logger: ExtensionActivationLogger) { + return setTimeout( + () => { + logger.info(`Activating extension timed out!`); + printLogs(logger, "Activating extension exceeded the timeout"); + }, + Math.max(0, timeout - 300) + ); } const extensionBootstrapper = (() => { @@ -48,6 +107,8 @@ const extensionBootstrapper = (() => { let activatedAPI: Api | undefined = undefined; let lastTestName: string | undefined = undefined; const testTitle = (currentTest: Mocha.Test) => currentTest.titlePath().join(" → "); + let activationLogger: ExtensionActivationLogger; + let asyncLogWrapper: (prefix: string, asyncWork: () => Thenable) => Promise; function testRunnerSetup( before: Mocha.HookFunction, @@ -66,23 +127,41 @@ const extensionBootstrapper = (() => { let workspaceContext: WorkspaceContext | undefined; let autoTeardown: void | (() => Promise); let restoreSettings: (() => Promise) | undefined; + activationLogger = new ExtensionActivationLogger(); + asyncLogWrapper = withLogging(activationLogger); + const SETUP_TIMEOUT_MS = 300_000; + const TEARDOWN_TIMEOUT_MS = 60_000; + before("Activate Swift Extension", async function () { // Allow enough time for the extension to activate - this.timeout(180_000); + this.timeout(SETUP_TIMEOUT_MS); + + // Mocha doesn't give us a hook to run code when a before block times out, so + // we set a timeout to just before mocha's so we have time to print the logs. + const timer = configureLogDumpOnTimeout(SETUP_TIMEOUT_MS, activationLogger); + + activationLogger.info(`Begin activating extension`); // Make sure that CodeLLDB is installed for debugging related tests if (!vscode.extensions.getExtension("vadimcn.vscode-lldb")) { - await vscode.commands.executeCommand( - "workbench.extensions.installExtension", - "vadimcn.vscode-lldb" + await asyncLogWrapper( + "vadimcn.vscode-lldb is not installed, installing CodeLLDB extension for the debugging tests.", + () => + vscode.commands.executeCommand( + "workbench.extensions.installExtension", + "vadimcn.vscode-lldb" + ) ); } // Always activate the extension. If no test assets are provided, // default to adding `defaultPackage` to the workspace. workspaceContext = await extensionBootstrapper.activateExtension( - this.currentTest, + this.currentTest ?? this.test, testAssets ?? ["defaultPackage"] ); + activationLogger.setLogger(workspaceContext.logger); + activationLogger.info(`Extension activated successfully.`); + // Need the `disableSandbox` configuration which is only in 6.1 // https://github.com/swiftlang/sourcekit-lsp/commit/7e2d12a7a0d184cc820ae6af5ddbb8aa18b1501c if ( @@ -90,43 +169,60 @@ const extensionBootstrapper = (() => { workspaceContext.globalToolchain.swiftVersion.isLessThan(new Version(6, 1, 0)) && requiresLSP ) { + activationLogger.info(`Skipping test, LSP is required but not available.`); this.skip(); } if (requiresDebugger && configuration.debugger.disable) { + activationLogger.info( + `Skipping test, Debugger is required but disabled in the configuration.` + ); this.skip(); } // CodeLLDB does not work with libllbd in Swift toolchains prior to 5.10 if (workspaceContext.globalToolchainSwiftVersion.isLessThan(new Version(5, 10, 0))) { - restoreSettings = await updateSettings({ - "swift.debugger.setupCodeLLDB": "never", - }); + await asyncLogWrapper('Setting swift.debugger.setupCodeLLDB: "never"', () => + updateSettings({ + "swift.debugger.setupCodeLLDB": "never", + }) + ); } else if (requiresDebugger) { - await workspaceContext.launchProvider.promptForCodeLldbSettings( - workspaceContext.globalToolchain + const lldbLibPath = await asyncLogWrapper("Getting LLDB library path", async () => + getLLDBLibPath(workspaceContext!.globalToolchain) + ); + activationLogger.info( + `LLDB library path is: ${lldbLibPath.success ?? "not found"}` ); } // Make sure no running tasks before setting up - await waitForNoRunningTasks({ timeout: 10000 }); + await asyncLogWrapper("Waiting for no running tasks before starting test/suite", () => + waitForNoRunningTasks({ timeout: 10000 }) + ); + // Clear build all cache before starting suite resetBuildAllTaskCache(); if (!setup) { + activationLogger.info("Activation complete!"); + clearTimeout(timer); return; } try { // If the setup returns a promise it is used to undo whatever setup it did. // Typically this is the promise returned from `updateSettings`, which will // undo any settings changed during setup. - autoTeardown = await setup.call(this, workspaceContext); + autoTeardown = await asyncLogWrapper( + "Calling user defined setup method to configure test/suite specifics", + () => setup.call(this, workspaceContext!) + ); } catch (error: any) { // Mocha will throw an error to break out of a test if `.skip` is used. if (error.message?.indexOf("sync skip;") === -1) { - console.error(`Error during test/suite setup, captured logs are:`); - workspaceContext.logger.logs.map(log => console.error(log)); - console.log("======== END OF LOGS ========\n\n"); + printLogs(activationLogger, "Error during test/suite setup"); } throw error; + } finally { + clearTimeout(timer); } }); @@ -139,7 +235,7 @@ const extensionBootstrapper = (() => { mocha.afterEach(async function () { if (this.currentTest && activatedAPI && this.currentTest.isFailed()) { - printLogs(activatedAPI.logger, `Test failed: ${testTitle(this.currentTest)}`); + printLogs(activationLogger, `Test failed: ${testTitle(this.currentTest)}`); } if (vscode.debug.activeDebugSession) { await vscode.debug.stopDebugging(vscode.debug.activeDebugSession); @@ -148,20 +244,29 @@ const extensionBootstrapper = (() => { after("Deactivate Swift Extension", async function () { // Allow enough time for the extension to deactivate - this.timeout(60_000); + this.timeout(TEARDOWN_TIMEOUT_MS); + + const timer = configureLogDumpOnTimeout(TEARDOWN_TIMEOUT_MS, activationLogger); + + activationLogger.info("Deactivating extension..."); let userTeardownError: unknown | undefined; try { // First run the users supplied teardown, then await the autoTeardown if it exists. if (teardown) { - await teardown.call(this); + await asyncLogWrapper("Running user teardown function...", () => + teardown.call(this) + ); } if (autoTeardown) { - await autoTeardown(); + await asyncLogWrapper( + "Running auto teardown function (function returned from setup)...", + () => autoTeardown!() + ); } } catch (error) { if (workspaceContext) { - printLogs(workspaceContext.logger, "Error during test/suite teardown"); + printLogs(activationLogger, "Error during test/suite teardown"); } // We always want to restore settings and deactivate the extension even if the // user supplied teardown fails. That way we have the best chance at not causing @@ -172,9 +277,15 @@ const extensionBootstrapper = (() => { } if (restoreSettings) { - await restoreSettings(); + await asyncLogWrapper("Running restore settings function...", () => + restoreSettings!() + ); } + activationLogger.info("Deactivation complete, calling deactivateExtension()"); await extensionBootstrapper.deactivateExtension(); + activationLogger.reset(); + + clearTimeout(timer); // Re-throw the user supplied teardown error if (userTeardownError) { @@ -189,12 +300,13 @@ const extensionBootstrapper = (() => { // test run, so after it is called once we switch over to calling activate on // the returned API object which behaves like the extension is being launched for // the first time _as long as everything is disposed of properly in `deactivate()`_. - activateExtension: async function (currentTest?: Mocha.Test, testAssets?: string[]) { + activateExtension: async function (currentTest?: Mocha.Runnable, testAssets?: string[]) { if (activatedAPI) { throw new Error( `Extension is already activated. Last test that activated the extension: ${lastTestName}` ); } + const extensionId = "swiftlang.swift-vscode"; const ext = vscode.extensions.getExtension(extensionId); if (!ext) { @@ -207,28 +319,41 @@ const extensionBootstrapper = (() => { // `vscode.extensions.getExtension("swiftlang.swift-vscode")` once. // Subsequent activations must be done through the returned API object. if (!activator) { + activationLogger.info( + "Performing the one and only extension activation for this test run." + ); for (const depId of [Extension.CODELLDB, Extension.LLDBDAP]) { const dep = vscode.extensions.getExtension(depId); if (!dep) { throw new Error(`Unable to find extension "${depId}"`); } - await dep.activate(); + await asyncLogWrapper(`Activating dependency extension "${depId}".`, () => + dep.activate() + ); } - activatedAPI = await ext.activate(); + + activatedAPI = await asyncLogWrapper( + "Activating Swift extension (true activation)...", + () => ext.activate() + ); + // Save the test name so if the test doesn't clean up by deactivating properly the next // test that tries to activate can throw an error with the name of the test that needs to clean up. lastTestName = currentTest?.titlePath().join(" → "); activator = activatedAPI.activate; workspaceContext = activatedAPI.workspaceContext; } else { - activatedAPI = await activator(); + activatedAPI = await asyncLogWrapper( + "Activating Swift extension by re-calling the extension's activation method...", + () => activator!() + ); lastTestName = currentTest?.titlePath().join(" → "); workspaceContext = activatedAPI.workspaceContext; } if (!workspaceContext) { printLogs( - activatedAPI.logger, + activationLogger, "Error during test/suite setup, workspace context could not be created" ); throw new Error("Extension did not activate. Workspace context is not available."); @@ -237,9 +362,13 @@ const extensionBootstrapper = (() => { // Add assets required for the suite/test to the workspace. const expectedAssets = testAssets ?? ["defaultPackage"]; if (!vscode.workspace.workspaceFile) { + activationLogger.info(`No workspace file found, adding assets directly.`); for (const asset of expectedAssets) { - await folderInRootWorkspace(asset, workspaceContext); + await asyncLogWrapper(`Adding ${asset} to workspace...`, () => + folderInRootWorkspace(asset, workspaceContext) + ); } + activationLogger.info(`All assets added to workspace.`); } else if (expectedAssets.length > 0) { await new Promise(res => { const found: string[] = []; @@ -247,6 +376,7 @@ const extensionBootstrapper = (() => { if (found.includes(f.name) || !expectedAssets.includes(f.name)) { continue; } + activationLogger.info(`Added ${f.name} to workspace`); found.push(f.name); } if (expectedAssets.length === found.length) { @@ -261,6 +391,7 @@ const extensionBootstrapper = (() => { ) { return; } + activationLogger.info(`Added ${e.folder!.name} to workspace`); found.push(e.folder!.name); if (expectedAssets.length === found.length) { res(); @@ -268,6 +399,7 @@ const extensionBootstrapper = (() => { } }); }); + activationLogger.info(`All assets added to workspace.`); } return workspaceContext; @@ -279,13 +411,23 @@ const extensionBootstrapper = (() => { // Wait for up to 10 seconds for all tasks to complete before deactivating. // Long running tasks should be avoided in tests, but this is a safety net. - await waitForNoRunningTasks({ timeout: 10000 }); + await asyncLogWrapper(`Deactivating extension, waiting for no running tasks.`, () => + waitForNoRunningTasks({ timeout: 10000 }) + ); // Close all editors before deactivating the extension. - await closeAllEditors(); - - await activatedAPI.workspaceContext?.removeWorkspaceFolder(getRootWorkspaceFolder()); + await asyncLogWrapper(`Closing all editors.`, () => closeAllEditors()); + + await asyncLogWrapper( + `Removing root workspace folder.`, + () => + activatedAPI!.workspaceContext?.removeWorkspaceFolder( + getRootWorkspaceFolder() + ) ?? Promise.resolve() + ); + activationLogger.info(`Running extension deactivation function.`); await activatedAPI.deactivate(); + activationLogger.reset(); activatedAPI = undefined; lastTestName = undefined; }, @@ -544,3 +686,24 @@ export function isConfigurationSuperset(configValue: unknown, expected: unknown) // If types don't match (one is array, one is object), return false return false; } + +/** + * Creates a logging wrapper function that wraps async operations with prefixed start/end logging messages. + * Logs when the operation starts, completes successfully, or fails with an error. + * + * @param logger The logger object that must have an `info` method for logging messages + * @returns A wrapper function that takes a prefix and async work function, returning a promise that resolves to the result of the async work + */ +export function withLogging(logger: { info: (message: string) => void }) { + return async function (prefix: string, asyncWork: () => Thenable): Promise { + logger.info(`${prefix} - starting`); + try { + const result = await asyncWork(); + logger.info(`${prefix} - completed`); + return result; + } catch (error) { + logger.info(`${prefix} - failed: ${error}`); + throw error; + } + }; +} diff --git a/test/utilities/tasks.ts b/test/utilities/tasks.ts index 7ec6bab07..7b0832200 100644 --- a/test/utilities/tasks.ts +++ b/test/utilities/tasks.ts @@ -40,17 +40,18 @@ export async function executeTaskAndWaitForResult( ): Promise<{ exitCode?: number; output: string }> { const task = "task" in fixture ? fixture.task : fixture; const exitPromise = waitForEndTaskProcess(task); - return await vscode.tasks.executeTask(task).then(async execution => { - let output = ""; - const runningTask = execution.task as SwiftTask; - const disposables = [runningTask.execution.onDidWrite(e => (output += e))]; - const exitCode = await exitPromise; - disposables.forEach(d => d.dispose()); - return { - output, - exitCode, - }; - }); + + const execution = await vscode.tasks.executeTask(task); + + let output = ""; + const runningTask = execution.task as SwiftTask; + const disposables = [runningTask.execution.onDidWrite(e => (output += e))]; + const exitCode = await exitPromise; + disposables.forEach(d => d.dispose()); + return { + output, + exitCode, + }; } /**