From 86297e80f2232a90166f7ea11709026b83a62e37 Mon Sep 17 00:00:00 2001 From: Bronley Plumb Date: Sat, 22 Jul 2023 08:22:09 -0400 Subject: [PATCH] Fix timing issues with semantic tokens --- src/BuildStatusTracker.spec.ts | 298 --------------------------------- src/BuildStatusTracker.ts | 207 ----------------------- src/BusyStatusTracker.spec.ts | 152 +++++++++++++++++ src/BusyStatusTracker.ts | 89 ++++++++++ src/LanguageServer.spec.ts | 4 +- src/LanguageServer.ts | 178 ++++++++++++-------- src/Logger.ts | 2 +- src/Throttler.ts | 47 ++++++ src/index.ts | 3 +- 9 files changed, 403 insertions(+), 577 deletions(-) delete mode 100644 src/BuildStatusTracker.spec.ts delete mode 100644 src/BuildStatusTracker.ts create mode 100644 src/BusyStatusTracker.spec.ts create mode 100644 src/BusyStatusTracker.ts diff --git a/src/BuildStatusTracker.spec.ts b/src/BuildStatusTracker.spec.ts deleted file mode 100644 index d6fc9c6e6..000000000 --- a/src/BuildStatusTracker.spec.ts +++ /dev/null @@ -1,298 +0,0 @@ -import type { Connection } from 'vscode-languageserver'; -import type { BuildStatusEvent } from './BuildStatusTracker'; -import { BuildStatus, BuildStatusTracker } from './BuildStatusTracker'; -import { createSandbox } from 'sinon'; -import type { Project } from './LanguageServer'; -import { tempDir } from './testHelpers.spec'; -import { standardizePath as s } from './util'; -import { expect } from 'chai'; -import { Deferred } from './deferred'; -const sinon = createSandbox(); - -describe('BuildStatusTracker', () => { - let tracker: BuildStatusTracker; - let connection = { - sendNotification: () => { } - } as any as Connection; - - const project1 = { - projectNumber: 1, - projectPath: s`${tempDir}/project1` - } as Project; - - const project2 = { - projectNumber: 2, - projectPath: s`${tempDir}/project2` - } as Project; - - const timeoutDurations: number[] = []; - - beforeEach(() => { - tracker = new BuildStatusTracker(connection); - sinon.stub(tracker as any, 'getDuration').callsFake(() => { - return timeoutDurations.shift() ?? 30_000; - }); - }); - - it('supports tracking events without project info', () => { - tracker.run(undefined, () => { }); - expect(tracker['buildEvent']()).to.eql({ - projectInfo: [{ - projectNumber: undefined, - projectPath: undefined, - statistics: { - average: 30_000, - count: 1, - max: 30_000, - min: 30_000 - } - }], - status: BuildStatus.success - } as BuildStatusEvent); - }); - - it('tracks a single run', () => { - tracker.run(project1, () => { - //noop - }); - expect(tracker['buildEvent']()).to.eql({ - projectInfo: [{ - ...project1, - statistics: { - average: 30_000, - count: 1, - max: 30_000, - min: 30_000 - } - }], - status: BuildStatus.success - } as BuildStatusEvent); - }); - - it('tracks a single async flow', async () => { - const deferred = new Deferred(); - const finishedPromise = tracker.run(project1, () => { - return deferred.promise; - }); - //no data tracked yet - expect(tracker['buildEvent']()).to.eql({ - projectInfo: [{ - ...project1, - statistics: { - min: Number.MAX_SAFE_INTEGER, - max: 0, - average: 0, - count: 0 - } - }], - status: BuildStatus.building - } as BuildStatusEvent); - - deferred.resolve(); - await finishedPromise; - - expect(tracker['buildEvent']()).to.eql({ - projectInfo: [{ - ...project1, - statistics: { - min: 30_000, - max: 30_000, - average: 30_000, - count: 1 - } - }], - status: 'success' - } as BuildStatusEvent); - }); - - it('independently tracks multiple runs for same program', () => { - timeoutDurations.push(10_000, 20_000); - tracker.run(project1, () => { - //noop - }); - tracker.run(project1, () => { - //noop - }); - expect(tracker['buildEvent']()).to.eql({ - projectInfo: [{ - ...project1, - statistics: { - min: 10_000, - max: 20_000, - average: 15_000, - count: 2 - } - }], - status: 'success' - } as BuildStatusEvent); - }); - - it('returns "building" when one of the runs is still pending', async () => { - const deferred = new Deferred(); - tracker.run(project1, () => { - //noop - }); - const finishedPromise = tracker.run(project1, () => { - return deferred.promise; - }); - expect(tracker['buildEvent']()).to.eql({ - projectInfo: [{ - ...project1, - statistics: { - min: 30_000, - max: 30_000, - average: 30_000, - count: 1 - } - }], - status: BuildStatus.building - } as BuildStatusEvent); - - deferred.resolve(); - await finishedPromise; - - expect(tracker['buildEvent']()).to.eql({ - projectInfo: [{ - ...project1, - statistics: { - min: 30_000, - max: 30_000, - average: 30_000, - count: 2 - } - }], - status: BuildStatus.success - } as BuildStatusEvent); - }); - - it('handles error during synchronous flow', () => { - try { - tracker.run(project1, () => { - throw new Error('Crash'); - }); - } catch { } - - expect(tracker['buildEvent']()).to.eql({ - projectInfo: [{ - ...project1, - statistics: { - average: 30_000, - count: 1, - max: 30_000, - min: 30_000 - } - }], - status: BuildStatus.criticalError - } as BuildStatusEvent); - }); - - it('handles error during async flow', async () => { - try { - await tracker.run(project1, () => { - return Promise.reject(new Error('Crash')); - }); - } catch { } - - expect(tracker['buildEvent']()).to.eql({ - projectInfo: [{ - ...project1, - statistics: { - min: 30_000, - max: 30_000, - average: 30_000, - count: 1 - } - }], - status: BuildStatus.criticalError - } as BuildStatusEvent); - }); - - it('only finalizes on the first call to finalize', () => { - try { - tracker.run(project1, (finalize) => { - finalize(); - finalize(); - }); - } catch { } - - expect(tracker['buildEvent']()).to.eql({ - projectInfo: [{ - ...project1, - statistics: { - min: 30_000, - max: 30_000, - average: 30_000, - count: 1 - } - }], - status: BuildStatus.success - } as BuildStatusEvent); - }); - - it('supports multiple simultaneous projects', async () => { - //run the projects out of order - const deferred2 = new Deferred(); - const run1Promise = tracker.run(project2, () => { - return deferred2.promise; - }); - - const deferred1 = new Deferred(); - const run2Promise = tracker.run(project1, () => { - return deferred1.promise; - }); - - expect(tracker['buildEvent']()).to.eql({ - //the projects are sorted before being emitted - projectInfo: [{ - ...project1, - statistics: { - min: Number.MAX_SAFE_INTEGER, - max: 0, - average: 0, - count: 0 - } - }, { - ...project2, - statistics: { - min: Number.MAX_SAFE_INTEGER, - max: 0, - average: 0, - count: 0 - } - }], - status: BuildStatus.building - } as BuildStatusEvent); - - deferred1.resolve(); - deferred2.resolve(); - await Promise.all([run1Promise, run2Promise]); - - expect(tracker['buildEvent']()).to.eql({ - //the projects are sorted before being emitted - projectInfo: [{ - ...project1, - statistics: { - min: 30_000, - max: 30_000, - average: 30_000, - count: 1 - } - }, { - ...project2, - statistics: { - min: 30_000, - max: 30_000, - average: 30_000, - count: 1 - } - }], - status: BuildStatus.success - } as BuildStatusEvent); - }); - - it('getDuration returns a duration', () => { - expect( - new BuildStatusTracker(connection)['getDuration'](Date.now() - 500) - ).to.be.gte(500); - }); -}); diff --git a/src/BuildStatusTracker.ts b/src/BuildStatusTracker.ts deleted file mode 100644 index d2be5588b..000000000 --- a/src/BuildStatusTracker.ts +++ /dev/null @@ -1,207 +0,0 @@ -import type { Connection } from 'vscode-languageserver/node'; -import type { Project } from './LanguageServer'; - -/** - * Tracks the building/success/error status of various projects in the language server. - * Reports the overall status (is nothing building, is something building, did something fail) to the language client - */ -export class BuildStatusTracker { - constructor( - private connection: Connection - ) { } - - private projectContainers = new Map; - }>(); - - private globalProject = { - projectNumber: undefined, - projectPath: undefined - } as Project; - - public run>(project: Project, callback: (finalize?: FinalizeBuildStatusRun) => R): R { - const finalizeRun = this.createRun(project); - let result: R | PromiseLike; - //call the callback function - try { - result = callback(finalizeRun); - //if the result is a promise, don't finalize until it completes - if (typeof (result as any)?.then === 'function') { - return Promise.resolve(result).then(() => { - finalizeRun(); - }).catch((e) => { - finalizeRun(BuildStatus.criticalError); - }).then(() => result) as any; - } else { - finalizeRun(); - return result; - } - } catch (e) { - finalizeRun(BuildStatus.criticalError); - throw e; - } - } - - /** - * Create a new run, and return the "finished" callback function" - */ - private createRun(project: Project) { - project ??= this.globalProject; - - //create the project container if missing - if (!this.projectContainers.has(project)) { - this.projectContainers.set(project, { - min: Number.MAX_SAFE_INTEGER, - max: 0, - average: 0, - count: 0, - mostRecentStatus: BuildStatus.success, - activeRuns: new Set() - }); - } - const projectContainer = this.projectContainers.get(project); - - //create the current run - const currentRunData: BuildStatusRun = { - status: BuildStatus.building, - startTime: Date.now() - }; - projectContainer.activeRuns.add(currentRunData); - - //return a function that should be called when the job has completed - return (status = BuildStatus.success) => { - this.finalizeRun(project, currentRunData, status); - }; - } - - /** - * Roll up the new build time average and send the event - */ - private finalizeRun(project: Project, statusRun: BuildStatusRun, status: BuildStatus) { - const container = this.projectContainers.get(project); - //skip processing if we can't find that builder or we can't find this active run - if (!container || !container.activeRuns.has(statusRun)) { - return; - } - - const buildTime = this.getDuration(statusRun.startTime); - - //if this is the first completed status, just use the current build time - if (container.count === 0) { - container.min = buildTime; - container.max = buildTime; - container.average = buildTime; - } else { - container.min = Math.min(container.min, buildTime); - container.max = Math.max(container.max, buildTime); - //calculate a new average - container.average = ((container.average * container.count) + buildTime) / (container.count + 1); - } - container.count++; - container.mostRecentStatus = status; - - container.activeRuns.delete(statusRun); - - this.sendEvent( - this.buildEvent() - ); - } - - private getDuration(time: number) { - return Date.now() - time; - } - - /** - * Build the event object for this status event that will be sent to the client - */ - private buildEvent() { - const event: BuildStatusEvent = { - status: BuildStatus.success, - projectInfo: [] - }; - const projects = [...this.projectContainers].map(x => x[0]).sort((a, b) => a.projectNumber - b.projectNumber); - for (const project of projects) { - const container = this.projectContainers.get(project); - event.projectInfo.push({ - projectNumber: project.projectNumber, - projectPath: project.projectPath, - statistics: { - min: container.min, - max: container.max, - count: container.count, - average: container.average - } - }); - - //if there's a critical error, set the state to that - if (container.mostRecentStatus === BuildStatus.criticalError || event.status === BuildStatus.criticalError) { - event.status = BuildStatus.criticalError; - - //if there are in-flight runs, set the state to "building" - } else if (container.activeRuns.size > 0) { - event.status = BuildStatus.building; - } - } - return event; - } - - /** - * Rolls up all the current data into a single status event - */ - private sendEvent(event: BuildStatusEvent) { - this.connection.sendNotification('build-status', event); - } - -} - -interface BuildStatusRun { - status: BuildStatus; - startTime: number; -} - -export type FinalizeBuildStatusRun = (status?: BuildStatus) => void; - -export enum BuildStatus { - building = 'building', - success = 'success', - criticalError = 'criticalError' -} - -export interface BuildStatusEvent { - status: BuildStatus; - projectInfo: Array; -} -export interface ProjectInfo { - projectNumber?: number; - projectPath?: string; - status: BuildStatus; - statistics: { - min: number; - max: number; - average: number; - count: number; - }; -} diff --git a/src/BusyStatusTracker.spec.ts b/src/BusyStatusTracker.spec.ts new file mode 100644 index 000000000..5872e799b --- /dev/null +++ b/src/BusyStatusTracker.spec.ts @@ -0,0 +1,152 @@ +import { expect } from 'chai'; +import { Deferred } from './deferred'; +import { BusyStatus, BusyStatusTracker } from './BusyStatusTracker'; + +describe('BusyStatusTracker', () => { + let tracker: BusyStatusTracker; + + let latestStatus: BusyStatus; + + beforeEach(() => { + latestStatus = BusyStatus.idle; + tracker = new BusyStatusTracker(); + tracker.on('change', (value) => { + latestStatus = value; + }); + }); + + afterEach(() => { + tracker?.destroy(); + }); + + it('tracks a single run', () => { + expect(latestStatus).to.eql(BusyStatus.idle); + tracker.run(() => { + expect(tracker.status).to.eql(BusyStatus.busy); + }); + expect(latestStatus).to.eql(BusyStatus.idle); + }); + + it('tracks a single async flow', async () => { + const deferred = new Deferred(); + const finishedPromise = tracker.run(() => { + return deferred.promise; + }); + expect(latestStatus).to.eql(BusyStatus.busy); + + deferred.resolve(); + await finishedPromise; + + expect(latestStatus).to.eql(BusyStatus.idle); + }); + + it('independently tracks multiple runs for same program', () => { + tracker.run(() => { + expect(latestStatus).to.eql(BusyStatus.busy); + }); + tracker.run(() => { + expect(latestStatus).to.eql(BusyStatus.busy); + }); + expect(latestStatus).to.eql(BusyStatus.idle); + }); + + it('tracks as `busy` one of the runs is still pending', async () => { + const deferred = new Deferred(); + tracker.run(() => { + expect(latestStatus).to.eql(BusyStatus.busy); + }); + const finishedPromise = tracker.run(() => { + expect(latestStatus).to.eql(BusyStatus.busy); + return deferred.promise; + }); + expect(latestStatus).to.eql(BusyStatus.busy); + + deferred.resolve(); + await finishedPromise; + + expect(latestStatus).to.eql(BusyStatus.idle); + }); + + it('handles error during synchronous flow', () => { + try { + tracker.run(() => { + throw new Error('Crash'); + }); + } catch { } + expect(latestStatus).to.eql(BusyStatus.idle); + }); + + it('handles error during async flow', async () => { + try { + await tracker.run(() => { + return Promise.reject(new Error('Crash')); + }); + } catch { } + expect(latestStatus).to.eql(BusyStatus.idle); + }); + + it('only finalizes on the first call to finalize', () => { + try { + tracker.run((finalize) => { + expect(latestStatus).to.eql(BusyStatus.busy); + finalize(); + expect(latestStatus).to.eql(BusyStatus.idle); + finalize(); + expect(latestStatus).to.eql(BusyStatus.idle); + }); + } catch { } + expect(latestStatus).to.eql(BusyStatus.idle); + }); + + it('supports multiple simultaneous projects', async () => { + //run the projects out of order + const deferred2 = new Deferred(); + const run1Promise = tracker.run(() => { + expect(latestStatus).to.eql(BusyStatus.busy); + return deferred2.promise; + }); + + const deferred1 = new Deferred(); + const run2Promise = tracker.run(() => { + expect(latestStatus).to.eql(BusyStatus.busy); + return deferred1.promise; + }); + + expect(latestStatus).to.eql(BusyStatus.busy); + + + deferred1.resolve(); + await run2Promise; + expect(latestStatus).to.eql(BusyStatus.busy); + + deferred2.resolve(); + await run1Promise; + expect(latestStatus).to.eql(BusyStatus.idle); + }); + + it('supports unsubscribing from events', () => { + const changes = []; //contains every busy/idle status change + const disconnect = tracker.on('change', (status) => changes.push(status)); + + expect(changes.length).to.eql(0); + + tracker.run(() => { }); + expect(changes.length).to.eql(2); + + tracker.run(() => { }); + expect(changes.length).to.eql(4); + + disconnect(); + + tracker.run(() => { }); + expect(changes.length).to.eql(4); + }); + + it('getStatus returns proper value', () => { + expect(tracker.status).to.eql(BusyStatus.idle); + tracker.run(() => { + expect(tracker.status).to.eql(BusyStatus.busy); + }); + expect(tracker.status).to.eql(BusyStatus.idle); + }); +}); diff --git a/src/BusyStatusTracker.ts b/src/BusyStatusTracker.ts new file mode 100644 index 000000000..bce4ca5bd --- /dev/null +++ b/src/BusyStatusTracker.ts @@ -0,0 +1,89 @@ +import { EventEmitter } from 'eventemitter3'; + +/** + * Tracks the busy/idle status of various sync or async tasks + * Reports the overall status to the client + */ +export class BusyStatusTracker { + /** + * @readonly + */ + public activeRuns = new Set<{ + label?: string; + startTime?: Date; + }>(); + + /** + * Start a new piece of work + */ + public run>(callback: (finalize?: FinalizeBuildStatusRun) => R, label?: string): R { + const run = { + label: label, + startTime: new Date() + }; + this.activeRuns.add(run); + + if (this.activeRuns.size === 1) { + this.emit('change', BusyStatus.busy); + } + + let isFinalized = false; + const finalizeRun = () => { + if (isFinalized === false) { + isFinalized = true; + this.activeRuns.delete(run); + if (this.activeRuns.size <= 0) { + this.emit('change', BusyStatus.idle); + } + } + }; + + let result: R | PromiseLike; + //call the callback function + try { + result = callback(finalizeRun); + //if the result is a promise, don't finalize until it completes + if (typeof (result as any)?.then === 'function') { + return Promise.resolve(result).finally(finalizeRun).then(() => result) as any; + } else { + finalizeRun(); + return result; + } + } catch (e) { + finalizeRun(); + throw e; + } + } + + private emitter = new EventEmitter(); + + public on(eventName: 'change', handler: (status: BusyStatus) => void) { + this.emitter.on(eventName, handler); + return () => { + this.emitter.off(eventName, handler); + }; + } + + private emit(eventName: 'change', value: BusyStatus) { + this.emitter.emit(eventName, value); + } + + public destroy() { + this.emitter.removeAllListeners(); + } + + /** + * The current status of the busy tracker. + * @readonly + */ + public get status() { + return this.activeRuns.size === 0 ? BusyStatus.idle : BusyStatus.busy; + } +} + +export type FinalizeBuildStatusRun = (status?: BusyStatus) => void; + +export enum BusyStatus { + busy = 'busy', + idle = 'idle' +} diff --git a/src/LanguageServer.spec.ts b/src/LanguageServer.spec.ts index f15f19bd4..6b69a899a 100644 --- a/src/LanguageServer.spec.ts +++ b/src/LanguageServer.spec.ts @@ -17,7 +17,7 @@ import { isBrsFile, isLiteralString } from './astUtils/reflection'; import { createVisitor, WalkMode } from './astUtils/visitors'; import { tempDir, rootDir } from './testHelpers.spec'; import { URI } from 'vscode-uri'; -import { BuildStatusTracker } from './BuildStatusTracker'; +import { BusyStatusTracker } from './BusyStatusTracker'; const sinon = createSandbox(); @@ -77,7 +77,7 @@ describe('LanguageServer', () => { beforeEach(() => { sinon.restore(); server = new LanguageServer(); - server['buildStatusTracker'] = new BuildStatusTracker(connection as any); + server['busyStatusTracker'] = new BusyStatusTracker(); workspaceFolders = [workspacePath]; vfs = {}; diff --git a/src/LanguageServer.ts b/src/LanguageServer.ts index e5bcc01ca..3035709a2 100644 --- a/src/LanguageServer.ts +++ b/src/LanguageServer.ts @@ -46,7 +46,8 @@ import { KeyedThrottler } from './KeyedThrottler'; import { DiagnosticCollection } from './DiagnosticCollection'; import { isBrsFile } from './astUtils/reflection'; import { encodeSemanticTokens, semanticTokensLegend } from './SemanticTokenUtils'; -import { BuildStatusTracker } from './BuildStatusTracker'; +import type { BusyStatus } from './BusyStatusTracker'; +import { BusyStatusTracker } from './BusyStatusTracker'; export class LanguageServer { private connection = undefined as Connection; @@ -97,7 +98,7 @@ export class LanguageServer { return this.validateThrottler.run(this.boundValidateAll); } - private buildStatusTracker: BuildStatusTracker; + public busyStatusTracker = new BusyStatusTracker(); //run the server public run() { @@ -105,7 +106,10 @@ export class LanguageServer { // Also include all preview / proposed LSP features. this.connection = this.createConnection(); - this.buildStatusTracker = new BuildStatusTracker(this.connection); + // Send the current status of the busyStatusTracker anytime it changes + this.busyStatusTracker.on('change', (status) => { + this.sendBusyStatus(status); + }); //listen to all of the output log events and pipe them into the debug channel in the extension this.loggerSubscription = Logger.subscribe((text) => { @@ -182,6 +186,18 @@ export class LanguageServer { this.connection.listen(); } + private busyStatusIndex = -1; + private sendBusyStatus(status: BusyStatus) { + this.busyStatusIndex = ++this.busyStatusIndex <= 0 ? 0 : this.busyStatusIndex; + + this.connection.sendNotification(NotificationName.busyStatus, { + status: status, + timestamp: Date.now(), + index: this.busyStatusIndex, + activeRuns: [...this.busyStatusTracker.activeRuns] + }); + } + /** * Called when the client starts initialization */ @@ -268,6 +284,7 @@ export class LanguageServer { * Scan the workspace for all `bsconfig.json` files. If at least one is found, then only folders who have bsconfig.json are returned. * If none are found, then the workspaceFolder itself is treated as a project */ + @TrackBusyStatus private async getProjectPaths(workspaceFolder: string) { const excludes = (await this.getWorkspaceExcludeGlobs(workspaceFolder)).map(x => s`!${x}`); const files = await rokuDeploy.getFilePaths([ @@ -314,49 +331,46 @@ export class LanguageServer { * Handle situations where bsconfig.json files were added or removed (to elevate/lower workspaceFolder projects accordingly) * Leave existing projects alone if they are not affected by these changes */ + @TrackBusyStatus private async syncProjects() { - await this.buildStatusTracker.run(this as any, async () => { - - const workspacePaths = await this.getWorkspacePaths(); - let projectPaths = (await Promise.all( - workspacePaths.map(async workspacePath => { - const projectPaths = await this.getProjectPaths(workspacePath); - return projectPaths.map(projectPath => ({ - projectPath: projectPath, - workspacePath: workspacePath - })); - }) - )).flat(1); + const workspacePaths = await this.getWorkspacePaths(); + let projectPaths = (await Promise.all( + workspacePaths.map(async workspacePath => { + const projectPaths = await this.getProjectPaths(workspacePath); + return projectPaths.map(projectPath => ({ + projectPath: projectPath, + workspacePath: workspacePath + })); + }) + )).flat(1); - //delete projects not represented in the list - for (const project of this.getProjects()) { - if (!projectPaths.find(x => x.projectPath === project.projectPath)) { - this.removeProject(project); - } + //delete projects not represented in the list + for (const project of this.getProjects()) { + if (!projectPaths.find(x => x.projectPath === project.projectPath)) { + this.removeProject(project); } + } - //exclude paths to projects we already have - projectPaths = projectPaths.filter(x => { - //only keep this project path if there's not a project with that path - return !this.projects.find(project => project.projectPath === x.projectPath); - }); - - //dedupe by project path - projectPaths = [ - ...projectPaths.reduce( - (acc, x) => acc.set(x.projectPath, x), - new Map() - ).values() - ]; + //exclude paths to projects we already have + projectPaths = projectPaths.filter(x => { + //only keep this project path if there's not a project with that path + return !this.projects.find(project => project.projectPath === x.projectPath); + }); - //create missing projects - await Promise.all( - projectPaths.map(x => this.createProject(x.projectPath, x.workspacePath)) - ); - //flush diagnostics - await this.sendDiagnostics(); + //dedupe by project path + projectPaths = [ + ...projectPaths.reduce( + (acc, x) => acc.set(x.projectPath, x), + new Map() + ).values() + ]; - }); + //create missing projects + await Promise.all( + projectPaths.map(x => this.createProject(x.projectPath, x.workspacePath)) + ); + //flush diagnostics + await this.sendDiagnostics(); } /** @@ -373,6 +387,7 @@ export class LanguageServer { * Called when the client has finished initializing */ @AddStackToErrorMessage + @TrackBusyStatus private async onInitialized() { let projectCreatedDeferred = new Deferred(); this.initialProjectsCreated = projectCreatedDeferred.promise; @@ -502,6 +517,7 @@ export class LanguageServer { * @param workspacePath path to the workspace in which all project should reside or are referenced by * @param projectNumber an optional project number to assign to the project. Used when reloading projects that should keep the same number */ + @TrackBusyStatus private async createProject(projectPath: string, workspacePath = projectPath, projectNumber?: number) { workspacePath ??= projectPath; let project = this.projects.find((x) => x.projectPath === projectPath); @@ -558,16 +574,14 @@ export class LanguageServer { this.projects.push(newProject); try { - await this.buildStatusTracker.run(project, async () => { - await builder.run({ - cwd: cwd, - project: configFilePath, - watch: false, - createPackage: false, - deploy: false, - copyToStaging: false, - showDiagnosticsInConsole: false - }); + await builder.run({ + cwd: cwd, + project: configFilePath, + watch: false, + createPackage: false, + deploy: false, + copyToStaging: false, + showDiagnosticsInConsole: false }); newProject.isFirstRunComplete = true; newProject.isFirstRunSuccessful = true; @@ -670,6 +684,7 @@ export class LanguageServer { * Provide a list of completion items based on the current cursor position */ @AddStackToErrorMessage + @TrackBusyStatus private async onCompletion(params: TextDocumentPositionParams) { //ensure programs are initialized await this.waitAllProjectFirstRuns(); @@ -706,6 +721,7 @@ export class LanguageServer { } @AddStackToErrorMessage + @TrackBusyStatus private async onCodeAction(params: CodeActionParams) { //ensure programs are initialized await this.waitAllProjectFirstRuns(); @@ -851,6 +867,7 @@ export class LanguageServer { * file types are watched (.brs,.bs,.xml,manifest, and any json/text/image files) */ @AddStackToErrorMessage + @TrackBusyStatus private async onDidChangeWatchedFiles(params: DidChangeWatchedFilesParams) { //ensure programs are initialized await this.waitAllProjectFirstRuns(); @@ -938,7 +955,7 @@ export class LanguageServer { projects.map((project) => this.handleFileChanges(project, changes)) ); } - this.connection.sendNotification('build-status', 'success'); + } /** @@ -1072,6 +1089,7 @@ export class LanguageServer { } @AddStackToErrorMessage + @TrackBusyStatus private async validateTextDocument(event: TextDocumentChangeEvent): Promise { const { document } = event; //ensure programs are initialized @@ -1084,8 +1102,6 @@ export class LanguageServer { //throttle file processing. first call is run immediately, and then the last call is processed. await this.keyedThrottler.run(filePath, () => { - this.connection.sendNotification('build-status', 'building'); - let documentText = document.getText(); for (const project of this.getProjects()) { //only add or replace existing files. All of the files in the project should @@ -1107,6 +1123,7 @@ export class LanguageServer { } } + @TrackBusyStatus private async validateAll() { try { //synchronize parsing for open files that were included/excluded from projects @@ -1117,23 +1134,18 @@ export class LanguageServer { //validate all programs await Promise.all( projects.map((project) => { - return this.buildStatusTracker.run(project, () => { - - project.builder.program.validate(); - return project; - - }); + project.builder.program.validate(); + return project; }) ); } catch (e: any) { this.connection.console.error(e); this.sendCriticalFailure(`Critical error validating project: ${e.message}${e.stack ?? ''}`); } - - this.connection.sendNotification('build-status', 'success'); } @AddStackToErrorMessage + @TrackBusyStatus public async onWorkspaceSymbol(params: WorkspaceSymbolParams) { await this.waitAllProjectFirstRuns(); @@ -1154,6 +1166,7 @@ export class LanguageServer { } @AddStackToErrorMessage + @TrackBusyStatus public async onDocumentSymbol(params: DocumentSymbolParams) { await this.waitAllProjectFirstRuns(); @@ -1169,6 +1182,7 @@ export class LanguageServer { } @AddStackToErrorMessage + @TrackBusyStatus private async onDefinition(params: TextDocumentPositionParams) { await this.waitAllProjectFirstRuns(); @@ -1184,6 +1198,7 @@ export class LanguageServer { } @AddStackToErrorMessage + @TrackBusyStatus private async onSignatureHelp(params: SignatureHelpParams) { await this.waitAllProjectFirstRuns(); @@ -1218,6 +1233,7 @@ export class LanguageServer { } @AddStackToErrorMessage + @TrackBusyStatus private async onReferences(params: ReferenceParams) { await this.waitAllProjectFirstRuns(); @@ -1233,16 +1249,23 @@ export class LanguageServer { return results.filter((r) => r); } + private onValidateSettled() { + return Promise.all([ + //wait for the validator to start running (or timeout if it never did) + this.validateThrottler.onRunOnce(100), + //wait for the validator to stop running (or resolve immediately if it's already idle) + this.validateThrottler.onIdleOnce(true) + ]); + } + @AddStackToErrorMessage + @TrackBusyStatus private async onFullSemanticTokens(params: SemanticTokensParams) { await this.waitAllProjectFirstRuns(); - await Promise.all([ - //wait for the file to settle (in case there are multiple file changes in quick succession) - this.keyedThrottler.onIdleOnce(util.uriToPath(params.textDocument.uri), true), - // wait for the validation to finish before providing semantic tokens. program.validate() populates and then caches AstNode.parent properties. - // If we don't wait, then fetching semantic tokens can cause some invalid cache - this.validateThrottler.onIdleOnce(false) - ]); + //wait for the file to settle (in case there are multiple file changes in quick succession) + await this.keyedThrottler.onIdleOnce(util.uriToPath(params.textDocument.uri), true); + //wait for the validation cycle to settle + await this.onValidateSettled(); const srcPath = util.uriToPath(params.textDocument.uri); for (const project of this.projects) { @@ -1281,6 +1304,7 @@ export class LanguageServer { } @AddStackToErrorMessage + @TrackBusyStatus public async onExecuteCommand(params: ExecuteCommandParams) { await this.waitAllProjectFirstRuns(); if (params.command === CustomCommands.TranspileFile) { @@ -1333,6 +1357,10 @@ export enum CustomCommands { TranspileFile = 'TranspileFile' } +export enum NotificationName { + busyStatus = 'busyStatus' +} + /** * Wraps a method. If there's an error (either sync or via a promise), * this appends the error's stack trace at the end of the error message so that the connection will @@ -1363,3 +1391,17 @@ function AddStackToErrorMessage(target: any, propertyKey: string, descriptor: Pr } }; } + +/** + * An annotation used to wrap the method in a busyStatus tracking call + */ +function TrackBusyStatus(target: any, propertyKey: string, descriptor: PropertyDescriptor) { + let originalMethod = descriptor.value; + + //wrapping the original method + descriptor.value = function value(this: LanguageServer, ...args: any[]) { + return this.busyStatusTracker.run(() => { + return originalMethod.apply(this, args); + }, originalMethod.name); + }; +} diff --git a/src/Logger.ts b/src/Logger.ts index 315392970..cac73702d 100644 --- a/src/Logger.ts +++ b/src/Logger.ts @@ -37,7 +37,7 @@ export class Logger { } private _logLevel = LogLevel.log; - private getTimestamp() { + public getTimestamp() { return '[' + chalk.grey(moment().format(`hh:mm:ss:SSSS A`)) + ']'; } diff --git a/src/Throttler.ts b/src/Throttler.ts index 65b492b6f..b7a769e23 100644 --- a/src/Throttler.ts +++ b/src/Throttler.ts @@ -16,6 +16,50 @@ export class Throttler { return !this.runningJobPromise; } + public on(eventName: 'idle' | 'run', callback: () => any) { + this.emitter.on(eventName, callback); + return () => { + this.emitter.off(eventName, callback); + }; + } + + /** + * Resolve a promise the next time the event fires + * @param eventName the name of the event to subscribe to + * @param timeout if the event doesn't fire within the specified time, the promise will auto-resolve itself + */ + public once(eventName: 'idle' | 'run', timeout?: number) { + const promises: Promise[] = []; + + //register a timeout if specified + if (timeout > 0) { + promises.push(util.sleep(timeout)); + } + + //wait for the event + promises.push( + new Promise((resolve) => { + const disconnect = this.on(eventName, () => { + disconnect(); + resolve(); + }); + }) + ); + + return Promise.race(promises); + } + + /** + * Wait for the next 'run' event. Or resolve immediately if already running. + * @param timeout after this timeout, the promise resolves even if the 'run' event never fired + */ + public async onRunOnce(timeout = 0) { + if (!this.isIdle) { + return; + } + return this.once('run', timeout); + } + /** * Get a promise that resolves the next time the throttler becomes idle */ @@ -61,6 +105,9 @@ export class Throttler { * Private method to run a job after a delay. */ private async runInternal(job) { + if (!this.pendingJob) { + this.emitter.emit('run'); + } this.runningJobPromise = util.sleep(this.delay).then(() => { //run the job return job(); diff --git a/src/index.ts b/src/index.ts index adb95d67f..f6dbf87f5 100644 --- a/src/index.ts +++ b/src/index.ts @@ -25,4 +25,5 @@ export * from './astUtils/reflection'; export * from './astUtils/creators'; export * from './astUtils/xml'; export * from './astUtils/AstEditor'; -export * from './BuildStatusTracker'; +export * from './BusyStatusTracker'; +export * from './Logger';