From f75a50de029501632dc9de8bddd429aac851e566 Mon Sep 17 00:00:00 2001 From: Zhiming Ma Date: Tue, 26 Sep 2023 18:01:38 +0800 Subject: [PATCH] Refactor completion request statistics (#474) * refactor(agent): improve completion provider stats. * refactor(agent): refactor issues notification and config update. --- clients/tabby-agent/package.json | 1 + clients/tabby-agent/src/Agent.ts | 36 +- .../src/CompletionProviderStats.ts | 175 ++++++++++ clients/tabby-agent/src/ResponseStats.ts | 110 ------- clients/tabby-agent/src/TabbyAgent.ts | 310 +++++++++++------- clients/tabby-agent/src/index.ts | 2 +- clients/vscode/package.json | 4 +- clients/vscode/src/TabbyStatusBarItem.ts | 63 ++-- clients/vscode/src/agent.ts | 9 +- clients/vscode/src/extension.ts | 5 +- clients/vscode/src/notifications.ts | 8 +- yarn.lock | 15 +- 12 files changed, 456 insertions(+), 282 deletions(-) create mode 100644 clients/tabby-agent/src/CompletionProviderStats.ts delete mode 100644 clients/tabby-agent/src/ResponseStats.ts diff --git a/clients/tabby-agent/package.json b/clients/tabby-agent/package.json index 8579c72..b96846e 100644 --- a/clients/tabby-agent/package.json +++ b/clients/tabby-agent/package.json @@ -44,6 +44,7 @@ "openapi-fetch": "^0.7.6", "pino": "^8.14.1", "rotating-file-stream": "^3.1.0", + "stats-logscale": "^1.0.7", "toml": "^3.0.0", "uuid": "^9.0.0" } diff --git a/clients/tabby-agent/src/Agent.ts b/clients/tabby-agent/src/Agent.ts index 8f39621..6d5d9fa 100644 --- a/clients/tabby-agent/src/Agent.ts +++ b/clients/tabby-agent/src/Agent.ts @@ -45,11 +45,8 @@ export type AgentIssue = SlowCompletionResponseTimeIssue | HighCompletionTimeout * and no `Authorization` request header is provided in the agent config, * and the user has not completed the auth flow or the auth token is expired. * See also `requestAuthUrl` and `waitForAuthToken`. - * @property {string} issuesExist - When the agent gets a valid response from the server, but still - * has some non-blocking issues, e.g. the average completion response time is too slow, - * or the timeout rate is too high. */ -export type AgentStatus = "notInitialized" | "ready" | "disconnected" | "unauthorized" | "issuesExist"; +export type AgentStatus = "notInitialized" | "ready" | "disconnected" | "unauthorized"; export interface AgentFunction { /** @@ -58,6 +55,11 @@ export interface AgentFunction { */ initialize(options?: AgentInitOptions): Promise; + /** + * Finalize agent. Client should call this method before exiting. + */ + finalize(): Promise; + /** * The agent configuration has the following levels, will be deep merged in the order: * 1. Default config @@ -87,9 +89,16 @@ export interface AgentFunction { getStatus(): AgentStatus; /** - * @returns the current issues if AgentStatus is `issuesExist`, otherwise returns empty array + * @returns the current issues if any exists */ - getIssues(): AgentIssue[]; + getIssues(detail?: boolean): AgentIssue["name"][]; + + /** + * Get the detail of an issue by index or name. + * @param options if `index` is provided, `name` will be ignored + * @returns the issue detail if exists, otherwise null + */ + getIssueDetail(options: { index?: number; name?: AgentIssue["name"] }): AgentIssue | null; /** * @returns server info returned from latest server health check, returns null if not available @@ -146,13 +155,18 @@ export type AuthRequiredEvent = { event: "authRequired"; server: AgentConfig["server"]; }; -export type NewIssueEvent = { - event: "newIssue"; - issue: AgentIssue; +export type IssuesUpdatedEvent = { + event: "issuesUpdated"; + issues: AgentIssue["name"][]; }; -export type AgentEvent = StatusChangedEvent | ConfigUpdatedEvent | AuthRequiredEvent | NewIssueEvent; -export const agentEventNames: AgentEvent["event"][] = ["statusChanged", "configUpdated", "authRequired", "newIssue"]; +export type AgentEvent = StatusChangedEvent | ConfigUpdatedEvent | AuthRequiredEvent | IssuesUpdatedEvent; +export const agentEventNames: AgentEvent["event"][] = [ + "statusChanged", + "configUpdated", + "authRequired", + "issuesUpdated", +]; export interface AgentEventEmitter { on(eventName: T["event"], callback: (event: T) => void): this; diff --git a/clients/tabby-agent/src/CompletionProviderStats.ts b/clients/tabby-agent/src/CompletionProviderStats.ts new file mode 100644 index 0000000..1df415a --- /dev/null +++ b/clients/tabby-agent/src/CompletionProviderStats.ts @@ -0,0 +1,175 @@ +import { Univariate } from "stats-logscale"; +import { rootLogger } from "./logger"; + +export type CompletionProviderStatsEntry = { + triggerMode: "auto" | "manual"; + cacheHit: boolean; + aborted: boolean; + requestSent: boolean; + requestLatency: number; // ms, NaN if timeout + requestCanceled: boolean; + requestTimeout: boolean; +}; + +class Average { + private sum = 0; + private quantity = 0; + + add(value: number): void { + this.sum += value; + this.quantity += 1; + } + + mean(): number { + return this.sum / this.quantity; + } + + count(): number { + return this.quantity; + } +} + +class Windowed { + private readonly maxSize: number; + private readonly values: number[] = []; + + constructor(maxSize: number) { + this.maxSize = maxSize; + } + + add(value: number): void { + this.values.push(value); + if (this.values.length > this.maxSize) { + this.values.shift(); + } + } + + getValues(): number[] { + return this.values; + } +} + +type WindowedStats = { + values: number[]; + stats: { total: number; timeouts: number; responses: number; averageResponseTime: number }; +}; + +export class CompletionProviderStats { + private readonly logger = rootLogger.child({ component: "CompletionProviderStats" }); + + private autoCompletionCount = 0; + private manualCompletionCount = 0; + private cacheHitCount = 0; + private cacheMissCount = 0; + + private completionRequestLatencyStats = new Univariate(); + private completionRequestCanceledStats = new Average(); + private completionRequestTimeoutCount = 0; + + private recentCompletionRequestLatencies = new Windowed(10); + + add(value: CompletionProviderStatsEntry): void { + const { triggerMode, cacheHit, aborted, requestSent, requestLatency, requestCanceled, requestTimeout } = value; + if (!aborted) { + if (triggerMode === "auto") { + this.autoCompletionCount += 1; + } else { + this.manualCompletionCount += 1; + } + if (cacheHit) { + this.cacheHitCount += 1; + } else { + this.cacheMissCount += 1; + } + } + if (requestSent) { + if (requestCanceled) { + this.completionRequestCanceledStats.add(requestLatency); + } else if (requestTimeout) { + this.completionRequestTimeoutCount += 1; + } else { + this.completionRequestLatencyStats.add(requestLatency); + } + if (!requestCanceled) { + this.recentCompletionRequestLatencies.add(requestLatency); + } + } + } + + reset() { + this.autoCompletionCount = 0; + this.manualCompletionCount = 0; + this.cacheHitCount = 0; + this.cacheMissCount = 0; + this.completionRequestLatencyStats = new Univariate(); + this.completionRequestCanceledStats = new Average(); + this.completionRequestTimeoutCount = 0; + } + + resetWindowed() { + this.recentCompletionRequestLatencies = new Windowed(10); + } + + // stats for anonymous usage report + stats() { + return { + completion: { + count_auto: this.autoCompletionCount, + count_manual: this.manualCompletionCount, + cache_hit: this.cacheHitCount, + cache_miss: this.cacheMissCount, + }, + completion_request: { + count: this.completionRequestLatencyStats.count(), + latency_avg: this.completionRequestLatencyStats.mean(), + latency_p50: this.completionRequestLatencyStats.percentile(50), + latency_p95: this.completionRequestLatencyStats.percentile(95), + latency_p99: this.completionRequestLatencyStats.percentile(99), + }, + completion_request_canceled: { + count: this.completionRequestCanceledStats.count(), + latency_avg: this.completionRequestCanceledStats.mean(), + }, + completion_request_timeout: { + count: this.completionRequestTimeoutCount, + }, + }; + } + + // stats for "highTimeoutRate" | "slowResponseTime" warning + windowed(): WindowedStats { + const latencies = this.recentCompletionRequestLatencies.getValues(); + const timeouts = latencies.filter((latency) => Number.isNaN(latency)); + const responses = latencies.filter((latency) => !Number.isNaN(latency)); + const averageResponseTime = responses.reduce((acc, latency) => acc + latency, 0) / responses.length; + return { + values: latencies, + stats: { + total: latencies.length, + timeouts: timeouts.length, + responses: responses.length, + averageResponseTime, + }, + }; + } + + static check(windowed: WindowedStats): "healthy" | "highTimeoutRate" | "slowResponseTime" | null { + const { + values: latencies, + stats: { total, timeouts, responses, averageResponseTime }, + } = windowed; + // if the recent 3 requests all have latency less than 3s + if (latencies.slice(-3).every((latency) => latency < 3000)) { + return "healthy"; + } + // if the recent requests timeout percentage is more than 50%, at least 3 timeouts + if (timeouts / total > 0.5 && timeouts >= 3) { + return "highTimeoutRate"; + } + // if average response time is more than 4s, at least 3 requests + if (responses >= 3 && averageResponseTime > 4000) { + return "slowResponseTime"; + } + return null; + } +} diff --git a/clients/tabby-agent/src/ResponseStats.ts b/clients/tabby-agent/src/ResponseStats.ts deleted file mode 100644 index 9a9b05d..0000000 --- a/clients/tabby-agent/src/ResponseStats.ts +++ /dev/null @@ -1,110 +0,0 @@ -import { EventEmitter } from "events"; -import { rootLogger } from "./logger"; -import { isTimeoutError } from "./utils"; - -export type ResponseStatsEntry = { - name: string; - status: number; - responseTime: number; - error?: any; -}; - -export type ResponseStatsStrategy = { - maxSize: number; - stats: Record number>; - checks: { - name: string; - check: (entries: ResponseStatsEntry[], stats: Record) => boolean; - }[]; -}; - -export const completionResponseTimeStatsStrategy = { - maxSize: 50, - stats: { - total: (entries: ResponseStatsEntry[]) => entries.length, - responses: (entries: ResponseStatsEntry[]) => entries.filter((entry) => entry.status === 200).length, - timeouts: (entries: ResponseStatsEntry[]) => entries.filter((entry) => isTimeoutError(entry.error)).length, - averageResponseTime: (entries: ResponseStatsEntry[]) => - entries.filter((entry) => entry.status === 200).reduce((acc, entry) => acc + entry.responseTime, 0) / - entries.length, - }, - checks: [ - // check in order and emit the first event that matches - // if all the last 5 entries have status 200 and response time less than 3s - { - name: "healthy", - check: (entries: ResponseStatsEntry[], stats) => { - const recentEntries = entries.slice(-5); - return recentEntries.every((entry) => entry.status === 200 && entry.responseTime < 3000); - }, - }, - // if TimeoutError percentage is more than 50%, at least 3 requests - { - name: "highTimeoutRate", - check: (entries: ResponseStatsEntry[], stats) => { - if (stats.total < 3) { - return false; - } - return stats.timeouts / stats.total > 0.5; - }, - }, - // if average response time is more than 4s, at least 5 requests - { - name: "slowResponseTime", - check: (entries: ResponseStatsEntry[], stats) => { - if (stats.responses < 5) { - return false; - } - return stats.averageResponseTime > 4000; - }, - }, - ], -}; - -export class ResponseStats extends EventEmitter { - private readonly logger = rootLogger.child({ component: "ResponseStats" }); - private strategy: ResponseStatsStrategy = { - maxSize: 0, - stats: {}, - checks: [], - }; - - private entries: ResponseStatsEntry[] = []; - - constructor(strategy: ResponseStatsStrategy) { - super(); - this.strategy = strategy; - } - - push(entry: ResponseStatsEntry): void { - this.entries.push(entry); - if (this.entries.length > this.strategy.maxSize) { - this.entries.shift(); - } - const stats = this.stats(); - for (const check of this.strategy.checks) { - if (check.check(this.entries, stats)) { - this.logger.debug({ check: check.name, stats }, "Check condition met"); - this.emit(check.name, stats); - } - } - } - - stats(): Record { - const result: Record = {}; - for (const [name, stats] of Object.entries(this.strategy.stats)) { - result[name] = stats(this.entries); - } - return result; - } - - check(): string | null { - const stats = this.stats(); - for (const check of this.strategy.checks) { - if (check.check(this.entries, stats)) { - return check.name; - } - } - return null; - } -} diff --git a/clients/tabby-agent/src/TabbyAgent.ts b/clients/tabby-agent/src/TabbyAgent.ts index 2562afd..ea121e0 100644 --- a/clients/tabby-agent/src/TabbyAgent.ts +++ b/clients/tabby-agent/src/TabbyAgent.ts @@ -26,7 +26,7 @@ import { DataStore } from "./dataStore"; import { postprocess, preCacheProcess } from "./postprocess"; import { rootLogger, allLoggers } from "./logger"; import { AnonymousUsageLogger } from "./AnonymousUsageLogger"; -import { ResponseStats, completionResponseTimeStatsStrategy } from "./ResponseStats"; +import { CompletionProviderStats, CompletionProviderStatsEntry } from "./CompletionProviderStats"; /** * Different from AgentInitOptions or AgentConfig, this may contain non-serializable objects, @@ -51,9 +51,11 @@ export class TabbyAgent extends EventEmitter implements Agent { private completionCache: CompletionCache = new CompletionCache(); private completionDebounce: CompletionDebounce = new CompletionDebounce(); private nonParallelProvideCompletionAbortController: AbortController | null = null; - private completionResponseStats: ResponseStats = new ResponseStats(completionResponseTimeStatsStrategy); + private completionProviderStats: CompletionProviderStats = new CompletionProviderStats(); static readonly tryConnectInterval = 1000 * 30; // 30s private tryingConnectTimer: ReturnType | null = null; + static readonly submitStatsInterval = 1000 * 60 * 60 * 24; // 24h + private submitStatsTimer: ReturnType | null = null; private constructor() { super(); @@ -65,22 +67,10 @@ export class TabbyAgent extends EventEmitter implements Agent { } }, TabbyAgent.tryConnectInterval); - this.completionResponseStats.on("healthy", () => { - this.popIssue("slowCompletionResponseTime"); - this.popIssue("highCompletionTimeoutRate"); - }); - this.completionResponseStats.on("highTimeoutRate", () => { - if (this.status === "ready" || this.status === "issuesExist") { - this.popIssue("slowCompletionResponseTime"); - this.pushIssue("highCompletionTimeoutRate"); - } - }); - this.completionResponseStats.on("slowResponseTime", () => { - if (this.status === "ready" || this.status === "issuesExist") { - this.popIssue("highCompletionTimeoutRate"); - this.pushIssue("slowCompletionResponseTime"); - } - }); + this.submitStatsTimer = setInterval(async () => { + await this.submitStats(); + this.logger.debug("Stats submitted"); + }, TabbyAgent.submitStatsInterval); } static async create(options?: TabbyAgentOptions): Promise { @@ -91,6 +81,9 @@ export class TabbyAgent extends EventEmitter implements Agent { } private async applyConfig() { + const oldConfig = this.config; + const oldStatus = this.status; + this.config = deepmerge(defaultAgentConfig, this.userConfig, this.clientConfig); allLoggers.forEach((logger) => (logger.level = this.config.logs.level)); this.anonymousUsageLogger.disabled = this.config.anonymousUsageTracking.disable; @@ -104,6 +97,24 @@ export class TabbyAgent extends EventEmitter implements Agent { this.auth = null; } await this.setupApi(); + + // If server config changed, clear server related state + if (!deepEqual(oldConfig.server, this.config.server)) { + this.serverHealthState = null; + this.completionProviderStats.resetWindowed(); + this.popIssue("slowCompletionResponseTime"); + this.popIssue("highCompletionTimeoutRate"); + + // If server config changed and status remain `unauthorized`, we want to emit `authRequired` again. + // but `changeStatus` will not emit `authRequired` if status is not changed, so we emit it manually here. + if (oldStatus === "unauthorized" && this.status === "unauthorized") { + this.emitAuthRequired(); + } + } + + const event: AgentEvent = { event: "configUpdated", config: this.config }; + this.logger.debug({ event }, "Config updated"); + super.emit("configUpdated", event); } private async setupApi() { @@ -129,17 +140,17 @@ export class TabbyAgent extends EventEmitter implements Agent { } } - private issueWithDetails(issue: AgentIssue["name"]): AgentIssue { - switch (issue) { + private issueFromName(issueName: AgentIssue["name"]): AgentIssue { + switch (issueName) { case "highCompletionTimeoutRate": return { name: "highCompletionTimeoutRate", - completionResponseStats: this.completionResponseStats.stats(), + completionResponseStats: this.completionProviderStats.windowed().stats, }; case "slowCompletionResponseTime": return { name: "slowCompletionResponseTime", - completionResponseStats: this.completionResponseStats.stats(), + completionResponseStats: this.completionProviderStats.windowed().stats, }; } } @@ -147,17 +158,17 @@ export class TabbyAgent extends EventEmitter implements Agent { private pushIssue(issue: AgentIssue["name"]) { if (this.issues.indexOf(issue) === -1) { this.issues.push(issue); - this.changeStatus("issuesExist"); - const event: AgentEvent = { event: "newIssue", issue: this.issueWithDetails(issue) }; - this.logger.debug({ event }, "New issue"); - super.emit("newIssue", event); + this.logger.debug({ issue }, "Issues Pushed"); + this.emitIssueUpdated(); } } private popIssue(issue: AgentIssue["name"]) { - this.issues = this.issues.filter((i) => i !== issue); - if (this.issues.length === 0 && this.status === "issuesExist") { - this.changeStatus("ready"); + const index = this.issues.indexOf(issue); + if (index >= 0) { + this.issues.splice(index, 1); + this.logger.debug({ issue }, "Issues Popped"); + this.emitIssueUpdated(); } } @@ -166,6 +177,17 @@ export class TabbyAgent extends EventEmitter implements Agent { super.emit("authRequired", event); } + private emitIssueUpdated() { + const event: AgentEvent = { event: "issuesUpdated", issues: this.issues }; + super.emit("issuesUpdated", event); + } + + private async submitStats() { + const stats = this.completionProviderStats.stats(); + await this.anonymousUsageLogger.event("AgentStats", { stats, config: this.config.completion }); + this.completionProviderStats.reset(); + } + private async post[0]>( path: T, requestOptions: Parameters>[1], @@ -181,9 +203,7 @@ export class TabbyAgent extends EventEmitter implements Agent { throw new HttpError(response.response); } this.logger.debug({ requestId, path, response: response.data }, "API response"); - if (this.status !== "issuesExist") { - this.changeStatus("ready"); - } + this.changeStatus("ready"); return response.data; } catch (error) { if (isTimeoutError(error)) { @@ -266,6 +286,21 @@ export class TabbyAgent extends EventEmitter implements Agent { return this.status !== "notInitialized"; } + public async finalize(): Promise { + await this.submitStats(); + + if (this.tryingConnectTimer) { + clearInterval(this.tryingConnectTimer); + this.tryingConnectTimer = null; + } + if (this.submitStatsTimer) { + clearInterval(this.submitStatsTimer); + this.submitStatsTimer = null; + } + this.logger.debug("Finalized"); + return true; + } + public async updateConfig(key: string, value: any): Promise { const current = getProperty(this.clientConfig, key); if (!deepEqual(current, value)) { @@ -274,20 +309,7 @@ export class TabbyAgent extends EventEmitter implements Agent { } else { setProperty(this.clientConfig, key, value); } - const prevStatus = this.status; await this.applyConfig(); - // If server config changed, clear server health state - if (key.startsWith("server")) { - this.serverHealthState = null; - } - // If status unchanged, `authRequired` will not be emitted when `applyConfig`, - // so we need to emit it manually. - if (key.startsWith("server") && prevStatus === "unauthorized" && this.status === "unauthorized") { - this.emitAuthRequired(); - } - const event: AgentEvent = { event: "configUpdated", config: this.config }; - this.logger.debug({ event }, "Config updated"); - super.emit("configUpdated", event); } return true; } @@ -304,8 +326,18 @@ export class TabbyAgent extends EventEmitter implements Agent { return this.status; } - public getIssues(): AgentIssue[] { - return this.issues.map((issue) => this.issueWithDetails(issue)); + public getIssues(): AgentIssue["name"][] { + return this.issues; + } + + public getIssueDetail(options: { index?: number; name?: AgentIssue["name"] }): AgentIssue | null { + if (options.index !== undefined) { + return this.issueFromName(this.issues[options.index]); + } else if (options.name !== undefined && this.issues.indexOf(options.name) !== -1) { + return this.issueFromName(options.name); + } else { + return null; + } } public getServerHealthState(): ServerHealthState | null { @@ -345,83 +377,139 @@ export class TabbyAgent extends EventEmitter implements Agent { this.nonParallelProvideCompletionAbortController = new AbortController(); const signal = abortSignalFromAnyOf([this.nonParallelProvideCompletionAbortController.signal, options?.signal]); let completionResponse: CompletionResponse | null = null; - if (this.completionCache.has(request)) { - // Hit cache - this.logger.debug({ request }, "Completion cache hit"); - await this.completionDebounce.debounce( - { - request, - config: this.config.completion.debounce, - responseTime: 0, - }, - { signal }, - ); - completionResponse = this.completionCache.get(request); - } else { - // No cache - const segments = this.createSegments(request); - if (isBlank(segments.prefix)) { - // Empty prompt - this.logger.debug("Segment prefix is blank, returning empty completion response"); - completionResponse = { - id: "agent-" + uuid(), - choices: [], - }; - } else { - // Request server + + let stats: CompletionProviderStatsEntry | null = { + triggerMode: request.manually ? "manual" : "auto", + cacheHit: false, + aborted: false, + requestSent: false, + requestLatency: 0, + requestCanceled: false, + requestTimeout: false, + }; + let requestStartedAt: number | null = null; + + try { + if (this.completionCache.has(request)) { + // Cache hit + stats.cacheHit = true; + this.logger.debug({ request }, "Completion cache hit"); + // Debounce before returning cached response await this.completionDebounce.debounce( { request, config: this.config.completion.debounce, - responseTime: this.completionResponseStats.stats()["averageResponseTime"], + responseTime: 0, }, - options, + { signal }, ); - - const requestStartedAt = performance.now(); - const apiPath = "/v1/completions"; - try { - completionResponse = await this.post( - apiPath, + completionResponse = this.completionCache.get(request); + } else { + // Cache miss + stats.cacheHit = false; + const segments = this.createSegments(request); + if (isBlank(segments.prefix)) { + // Empty prompt + stats = null; // no need to record stats for empty prompt + this.logger.debug("Segment prefix is blank, returning empty completion response"); + completionResponse = { + id: "agent-" + uuid(), + choices: [], + }; + } else { + // Debounce before sending request + await this.completionDebounce.debounce( { - body: { - language: request.language, - segments, - user: this.auth?.user, - }, - }, - { - signal, - timeout: request.manually ? this.config.completion.timeout.manually : this.config.completion.timeout.auto, + request, + config: this.config.completion.debounce, + responseTime: this.completionProviderStats.stats()["averageResponseTime"], }, + options, ); - this.completionResponseStats.push({ - name: apiPath, - status: 200, - responseTime: performance.now() - requestStartedAt, - }); - } catch (error) { - // record timed out request in stats, do not record canceled request - if (isTimeoutError(error)) { - this.completionResponseStats.push({ - name: apiPath, - status: error.status, - responseTime: performance.now() - requestStartedAt, - error, - }); + + // Send http request + stats.requestSent = true; + requestStartedAt = performance.now(); + try { + completionResponse = await this.post( + "/v1/completions", + { + body: { + language: request.language, + segments, + user: this.auth?.user, + }, + }, + { + signal, + timeout: request.manually + ? this.config.completion.timeout.manually + : this.config.completion.timeout.auto, + }, + ); + stats.requestLatency = performance.now() - requestStartedAt; + } catch (error) { + if (isCanceledError(error)) { + stats.requestCanceled = true; + stats.requestLatency = performance.now() - requestStartedAt; + } + if (isTimeoutError(error)) { + stats.requestTimeout = true; + stats.requestLatency = NaN; + } + // rethrow error + throw error; + } + // Postprocess (pre-cache) + completionResponse = await preCacheProcess(request, completionResponse); + if (options?.signal?.aborted) { + throw options.signal.reason; + } + // Build cache + this.completionCache.set(request, completionResponse); + } + } + // Postprocess (post-cache) + completionResponse = await postprocess(request, completionResponse); + if (options?.signal?.aborted) { + throw options.signal.reason; + } + } catch (error) { + if (isCanceledError(error) || isTimeoutError(error)) { + if (stats) { + stats.aborted = true; + } + } else { + // unexpected error + stats = null; + } + // rethrow error + throw error; + } finally { + if (stats) { + this.completionProviderStats.add(stats); + + if (stats.requestSent && !stats.requestCanceled) { + const windowedStats = this.completionProviderStats.windowed(); + const checkResult = CompletionProviderStats.check(windowedStats); + switch (checkResult) { + case "healthy": + this.popIssue("slowCompletionResponseTime"); + this.popIssue("highCompletionTimeoutRate"); + break; + case "highTimeoutRate": + this.popIssue("slowCompletionResponseTime"); + this.pushIssue("highCompletionTimeoutRate"); + break; + case "slowResponseTime": + this.popIssue("highCompletionTimeoutRate"); + this.pushIssue("slowCompletionResponseTime"); + break; } } - completionResponse = await preCacheProcess(request, completionResponse); - if (options?.signal?.aborted) { - throw options.signal.reason; - } - this.completionCache.set(request, completionResponse); } } - completionResponse = await postprocess(request, completionResponse); - if (options?.signal?.aborted) { - throw options.signal.reason; - } + return completionResponse; } diff --git a/clients/tabby-agent/src/index.ts b/clients/tabby-agent/src/index.ts index 79022f6..c714a98 100644 --- a/clients/tabby-agent/src/index.ts +++ b/clients/tabby-agent/src/index.ts @@ -9,7 +9,7 @@ export { StatusChangedEvent, ConfigUpdatedEvent, AuthRequiredEvent, - NewIssueEvent, + IssuesUpdatedEvent, SlowCompletionResponseTimeIssue, HighCompletionTimeoutRateIssue, AgentInitOptions, diff --git a/clients/vscode/package.json b/clients/vscode/package.json index 8b4d8a6..126649c 100644 --- a/clients/vscode/package.json +++ b/clients/vscode/package.json @@ -199,8 +199,8 @@ "devDependencies": { "@types/glob": "^7.2.0", "@types/mocha": "^10.0.1", - "@types/node": "16.x", - "@types/vscode": "^1.70.0", + "@types/node": "18.x", + "@types/vscode": "^1.82.0", "@typescript-eslint/eslint-plugin": "^5.31.0", "@typescript-eslint/parser": "^5.31.0", "@vscode/test-electron": "^2.1.5", diff --git a/clients/vscode/src/TabbyStatusBarItem.ts b/clients/vscode/src/TabbyStatusBarItem.ts index a137103..5e74b8c 100644 --- a/clients/vscode/src/TabbyStatusBarItem.ts +++ b/clients/vscode/src/TabbyStatusBarItem.ts @@ -20,8 +20,13 @@ const backgroundColorWarning = new ThemeColor("statusBarItem.warningBackground") export class TabbyStatusBarItem { private item = window.createStatusBarItem(StatusBarAlignment.Right); private completionProvider: TabbyCompletionProvider; + private completionResponseWarningShown = false; - private transitionsForCompletionProviderStatus = [ + private subStatusForReady = [ + { + target: "issuesExist", + cond: () => agent().getIssues().length > 0, + }, { target: "automatic", cond: () => this.completionProvider.getTriggerMode() === "automatic", @@ -46,82 +51,70 @@ export class TabbyStatusBarItem { states: { initializing: { on: { - ready: this.transitionsForCompletionProviderStatus, + ready: this.subStatusForReady, disconnected: "disconnected", unauthorized: "unauthorized", - issuesExist: "issuesExist", }, entry: () => this.toInitializing(), }, automatic: { on: { - completionStatusChanged: this.transitionsForCompletionProviderStatus, - ready: this.transitionsForCompletionProviderStatus, + ready: this.subStatusForReady, disconnected: "disconnected", unauthorized: "unauthorized", - issuesExist: "issuesExist", }, entry: () => this.toAutomatic(), }, manual: { on: { - completionStatusChanged: this.transitionsForCompletionProviderStatus, - ready: this.transitionsForCompletionProviderStatus, + ready: this.subStatusForReady, disconnected: "disconnected", unauthorized: "unauthorized", - issuesExist: "issuesExist", }, entry: () => this.toManual(), }, loading: { on: { - completionStatusChanged: this.transitionsForCompletionProviderStatus, - ready: this.transitionsForCompletionProviderStatus, + ready: this.subStatusForReady, disconnected: "disconnected", unauthorized: "unauthorized", - issuesExist: "issuesExist", }, entry: () => this.toLoading(), }, disabled: { on: { - completionStatusChanged: this.transitionsForCompletionProviderStatus, - ready: this.transitionsForCompletionProviderStatus, + ready: this.subStatusForReady, disconnected: "disconnected", unauthorized: "unauthorized", - issuesExist: "issuesExist", }, entry: () => this.toDisabled(), }, disconnected: { on: { - ready: this.transitionsForCompletionProviderStatus, + ready: this.subStatusForReady, unauthorized: "unauthorized", - issuesExist: "issuesExist", }, entry: () => this.toDisconnected(), }, unauthorized: { on: { - ready: this.transitionsForCompletionProviderStatus, + ready: this.subStatusForReady, disconnected: "disconnected", - issuesExist: "issuesExist", authStart: "unauthorizedAndAuthInProgress", }, entry: () => this.toUnauthorized(), }, unauthorizedAndAuthInProgress: { on: { - ready: this.transitionsForCompletionProviderStatus, + ready: this.subStatusForReady, disconnected: "disconnected", - issuesExist: "issuesExist", authEnd: "unauthorized", // if auth succeeds, we will get `ready` before `authEnd` event }, entry: () => this.toUnauthorizedAndAuthInProgress(), }, issuesExist: { on: { - ready: this.transitionsForCompletionProviderStatus, + ready: this.subStatusForReady, disconnected: "disconnected", unauthorized: "unauthorized", }, @@ -136,14 +129,13 @@ export class TabbyStatusBarItem { this.completionProvider = completionProvider; this.fsmService.start(); this.fsmService.send(agent().getStatus()); - this.fsmService.send("completionStatusChanged"); this.item.show(); this.completionProvider.on("triggerModeUpdated", () => { - this.fsmService.send("completionStatusChanged"); + this.fsmService.send(agent().getStatus()); }); this.completionProvider.on("loadingStatusUpdated", () => { - this.fsmService.send("completionStatusChanged"); + this.fsmService.send(agent().getStatus()); }); agent().on("statusChanged", (event) => { console.debug("Tabby agent statusChanged", { event }); @@ -162,12 +154,16 @@ export class TabbyStatusBarItem { }); }); - agent().on("newIssue", (event) => { - console.debug("Tabby agent newIssue", { event }); - if (event.issue.name === "slowCompletionResponseTime") { - notifications.showInformationWhenSlowCompletionResponseTime(); - } else if (event.issue.name === "highCompletionTimeoutRate") { - notifications.showInformationWhenHighCompletionTimeoutRate(); + agent().on("issuesUpdated", (event) => { + console.debug("Tabby agent issuesUpdated", { event }); + this.fsmService.send(agent().getStatus()); + if (event.issues.length > 0 && !this.completionResponseWarningShown) { + this.completionResponseWarningShown = true; + if (event.issues[0] === "slowCompletionResponseTime") { + notifications.showInformationWhenSlowCompletionResponseTime(); + } else if (event.issues[0] === "highCompletionTimeoutRate") { + notifications.showInformationWhenHighCompletionTimeoutRate(); + } } }); } @@ -285,7 +281,8 @@ export class TabbyStatusBarItem { this.item.color = colorWarning; this.item.backgroundColor = backgroundColorWarning; this.item.text = `${iconIssueExist} ${label}`; - switch (agent().getIssues()[0]?.name) { + const issue = agent().getIssueDetail({ index: 0 }); + switch (issue?.name) { case "slowCompletionResponseTime": this.item.tooltip = "Completion requests appear to take too much time."; break; @@ -301,7 +298,7 @@ export class TabbyStatusBarItem { command: "tabby.applyCallback", arguments: [ () => { - switch (agent().getIssues()[0]?.name) { + switch (issue?.name) { case "slowCompletionResponseTime": notifications.showInformationWhenSlowCompletionResponseTime(); break; diff --git a/clients/vscode/src/agent.ts b/clients/vscode/src/agent.ts index 41f6131..12f0d21 100644 --- a/clients/vscode/src/agent.ts +++ b/clients/vscode/src/agent.ts @@ -17,7 +17,7 @@ function getWorkspaceConfiguration(): PartialAgentConfig { return config; } -var instance: TabbyAgent; +var instance: TabbyAgent | undefined = undefined; export function agent(): TabbyAgent { if (!instance) { @@ -72,3 +72,10 @@ export async function createAgentInstance(context: ExtensionContext): Promise { + if (instance) { + await instance.finalize(); + instance = undefined; + } +} diff --git a/clients/vscode/src/extension.ts b/clients/vscode/src/extension.ts index a2504df..8804628 100644 --- a/clients/vscode/src/extension.ts +++ b/clients/vscode/src/extension.ts @@ -1,7 +1,7 @@ // The module 'vscode' contains the VS Code extensibility API // Import the module and reference it with the alias vscode in your code below import { ExtensionContext, languages } from "vscode"; -import { createAgentInstance } from "./agent"; +import { createAgentInstance, disposeAgentInstance } from "./agent"; import { tabbyCommands } from "./commands"; import { TabbyCompletionProvider } from "./TabbyCompletionProvider"; import { TabbyStatusBarItem } from "./TabbyStatusBarItem"; @@ -21,6 +21,7 @@ export async function activate(context: ExtensionContext) { } // this method is called when your extension is deactivated -export function deactivate() { +export async function deactivate() { console.debug("Deactivating Tabby extension", new Date()); + await disposeAgentInstance(); } diff --git a/clients/vscode/src/notifications.ts b/clients/vscode/src/notifications.ts index 1f66a39..7a9f201 100644 --- a/clients/vscode/src/notifications.ts +++ b/clients/vscode/src/notifications.ts @@ -159,9 +159,7 @@ function getHelpMessageForCompletionResponseTimeIssue() { function showInformationWhenSlowCompletionResponseTime(modal: boolean = false) { if (modal) { - const stats = agent() - .getIssues() - .find((issue) => issue.name === "slowCompletionResponseTime")?.completionResponseStats; + const stats = agent().getIssueDetail({ name: "slowCompletionResponseTime" })?.completionResponseStats; let statsMessage = ""; if (stats && stats["responses"] && stats["averageResponseTime"]) { statsMessage = `The average response time of recent ${stats["responses"]} completion requests is ${Number( @@ -202,9 +200,7 @@ function showInformationWhenSlowCompletionResponseTime(modal: boolean = false) { function showInformationWhenHighCompletionTimeoutRate(modal: boolean = false) { if (modal) { - const stats = agent() - .getIssues() - .find((issue) => issue.name === "highCompletionTimeoutRate")?.completionResponseStats; + const stats = agent().getIssueDetail({ name: "highCompletionTimeoutRate" })?.completionResponseStats; let statsMessage = ""; if (stats && stats["total"] && stats["timeouts"]) { statsMessage = `${stats["timeouts"]} of ${stats["total"]} completion requests timed out.\n\n`; diff --git a/yarn.lock b/yarn.lock index 30d5a00..7aefc94 100644 --- a/yarn.lock +++ b/yarn.lock @@ -375,10 +375,10 @@ resolved "https://registry.yarnpkg.com/@types/node/-/node-20.6.0.tgz#9d7daa855d33d4efec8aea88cd66db1c2f0ebe16" integrity sha512-najjVq5KN2vsH2U/xyh2opaSEz6cZMR2SetLIlxlj08nOcmPOemJmUK2o4kUzfLqfrWE0PIrNeE16XhYDd3nqg== -"@types/node@16.x": - version "16.18.50" - resolved "https://registry.yarnpkg.com/@types/node/-/node-16.18.50.tgz#93003cf0251a2ecd26dad6dc757168d648519805" - integrity sha512-OiDU5xRgYTJ203v4cprTs0RwOCd5c5Zjv+K5P8KSqfiCsB1W3LcamTUMcnQarpq5kOYbhHfSOgIEJvdPyb5xyw== +"@types/node@18.x": + version "18.18.0" + resolved "https://registry.yarnpkg.com/@types/node/-/node-18.18.0.tgz#bd19d5133a6e5e2d0152ec079ac27c120e7f1763" + integrity sha512-3xA4X31gHT1F1l38ATDIL9GpRLdwVhnEFC8Uikv5ZLlXATwrCYyPq7ZWHxzxc3J/30SUiwiYT+bQe0/XvKlWbw== "@types/node@^18.12.0": version "18.17.15" @@ -395,7 +395,7 @@ resolved "https://registry.yarnpkg.com/@types/semver/-/semver-7.5.2.tgz#31f6eec1ed7ec23f4f05608d3a2d381df041f564" integrity sha512-7aqorHYgdNO4DM36stTiGO3DvKoex9TQRwsJU6vMaFGyqpBA1MNZkz+PG3gaNUPpTAOYhT1WR7M1JyA3fbS9Cw== -"@types/vscode@^1.70.0": +"@types/vscode@^1.82.0": version "1.82.0" resolved "https://registry.yarnpkg.com/@types/vscode/-/vscode-1.82.0.tgz#89b0b21179dcf5e8cee1664a9a05c5f6c60d38d0" integrity sha512-VSHV+VnpF8DEm8LNrn8OJ8VuUNcBzN3tMvKrNpbhhfuVjFm82+6v44AbDhLvVFgCzn6vs94EJNTp7w8S6+Q1Rw== @@ -3684,6 +3684,11 @@ split2@^4.0.0: resolved "https://registry.yarnpkg.com/split2/-/split2-4.2.0.tgz#c9c5920904d148bab0b9f67145f245a86aadbfa4" integrity sha512-UcjcJOWknrNkF6PLX83qcHM6KHgVKNkV62Y8a5uYDVv9ydGQVwAHMKqHdJje1VTWpljG0WYpCDhrCdAOYH4TWg== +stats-logscale@^1.0.7: + version "1.0.7" + resolved "https://registry.yarnpkg.com/stats-logscale/-/stats-logscale-1.0.7.tgz#cfc32d42cc480575336f265d864cb819c6618eb5" + integrity sha512-Vwgch6DGsyBR7avsqyDlpgod8PjD0zY58UoAZHWAr7fMFrxTgBKkdlErk1mZk4hm85VLaRvoeEu6hS4ODseOnw== + statuses@2.0.1: version "2.0.1" resolved "https://registry.yarnpkg.com/statuses/-/statuses-2.0.1.tgz#55cb000ccf1d48728bd23c685a063998cf1a1b63"