diff --git a/package-lock.json b/package-lock.json index 3284495..034af60 100644 --- a/package-lock.json +++ b/package-lock.json @@ -14,6 +14,7 @@ "@eslint/js": "^9.34.0", "@types/fs-extra": "^11.0.4", "@types/mocha": "^10.0.10", + "@types/ms": "^2.1.0", "@types/node": "20.x", "@types/vscode": "^1.83.0", "@vscode/test-cli": "^0.0.11", @@ -23,6 +24,7 @@ "eslint": "^9.34.0", "eslint-plugin-import": "^2.32.0", "fs-extra": "^11.3.1", + "ms": "^2.1.3", "npm-run-all": "^4.1.5", "p-min-delay": "^4.1.0", "typescript": "^5.9.2", @@ -1678,6 +1680,13 @@ "dev": true, "license": "MIT" }, + "node_modules/@types/ms": { + "version": "2.1.0", + "resolved": "https://registry.npmjs.org/@types/ms/-/ms-2.1.0.tgz", + "integrity": "sha512-GsCCIZDE/p3i96vtEqx+7dBUGXrc7zeSK3wwPHIaRThS+9OhWIXRqzs4d6k1SVU8g91DrNRWxWUGhp5KXQb2VA==", + "dev": true, + "license": "MIT" + }, "node_modules/@types/node": { "version": "20.19.0", "resolved": "https://registry.npmjs.org/@types/node/-/node-20.19.0.tgz", diff --git a/package.json b/package.json index b7789f4..26e8db6 100644 --- a/package.json +++ b/package.json @@ -126,6 +126,7 @@ "@eslint/js": "^9.34.0", "@types/fs-extra": "^11.0.4", "@types/mocha": "^10.0.10", + "@types/ms": "^2.1.0", "@types/node": "20.x", "@types/vscode": "^1.83.0", "@vscode/test-cli": "^0.0.11", @@ -135,6 +136,7 @@ "eslint": "^9.34.0", "eslint-plugin-import": "^2.32.0", "fs-extra": "^11.3.1", + "ms": "^2.1.3", "npm-run-all": "^4.1.5", "p-min-delay": "^4.1.0", "typescript": "^5.9.2", diff --git a/src/extension.ts b/src/extension.ts index 330e349..f4f02c2 100644 --- a/src/extension.ts +++ b/src/extension.ts @@ -1,3 +1,4 @@ +import ms from "ms"; import { StatusBarAlignment, window } from "vscode"; import type { ExtensionContext } from "vscode"; @@ -13,6 +14,7 @@ import { createLocalStackStatusTracker } from "./utils/localstack-status.ts"; import { getOrCreateExtensionSessionId } from "./utils/manage.ts"; import { createSetupStatusTracker } from "./utils/setup-status.ts"; import { createTelemetry } from "./utils/telemetry.ts"; +import { createTimeTracker } from "./utils/time-tracker.ts"; const plugins = new PluginManager([ setup, @@ -29,36 +31,83 @@ export async function activate(context: ExtensionContext) { }); context.subscriptions.push(outputChannel); - const statusBarItem = window.createStatusBarItem(StatusBarAlignment.Left, -1); - context.subscriptions.push(statusBarItem); - statusBarItem.text = "$(loading~spin) LocalStack"; - statusBarItem.show(); + const timeTracker = createTimeTracker({ outputChannel }); - const containerStatusTracker = await createContainerStatusTracker( - "localstack-main", - outputChannel, - ); - context.subscriptions.push(containerStatusTracker); - - const localStackStatusTracker = await createLocalStackStatusTracker( - containerStatusTracker, - outputChannel, - ); - context.subscriptions.push(localStackStatusTracker); - - const setupStatusTracker = await createSetupStatusTracker(outputChannel); - - const sessionId = await getOrCreateExtensionSessionId(context); - const telemetry = createTelemetry(outputChannel, sessionId); - - await plugins.activate({ - context, - outputChannel, - statusBarItem, + const { containerStatusTracker, localStackStatusTracker, setupStatusTracker, + statusBarItem, telemetry, + } = await timeTracker.run("extension.dependencies", async () => { + const statusBarItem = window.createStatusBarItem( + StatusBarAlignment.Left, + -1, + ); + context.subscriptions.push(statusBarItem); + statusBarItem.text = "$(loading~spin) LocalStack"; + statusBarItem.show(); + + const containerStatusTracker = await createContainerStatusTracker( + "localstack-main", + outputChannel, + timeTracker, + ); + context.subscriptions.push(containerStatusTracker); + + const localStackStatusTracker = await createLocalStackStatusTracker( + containerStatusTracker, + outputChannel, + timeTracker, + ); + context.subscriptions.push(localStackStatusTracker); + + outputChannel.trace(`[setup-status]: Starting...`); + const startStatusTracker = Date.now(); + const setupStatusTracker = await createSetupStatusTracker( + outputChannel, + timeTracker, + ); + context.subscriptions.push(setupStatusTracker); + const endStatusTracker = Date.now(); + outputChannel.trace( + `[setup-status]: Completed in ${ms( + endStatusTracker - startStatusTracker, + { long: true }, + )}`, + ); + + const startTelemetry = Date.now(); + outputChannel.trace(`[telemetry]: Starting...`); + const sessionId = await getOrCreateExtensionSessionId(context); + const telemetry = createTelemetry(outputChannel, sessionId); + const endTelemetry = Date.now(); + outputChannel.trace( + `[telemetry]: Completed in ${ms(endTelemetry - startTelemetry, { + long: true, + })}`, + ); + + return { + statusBarItem, + containerStatusTracker, + localStackStatusTracker, + setupStatusTracker, + telemetry, + }; + }); + + await timeTracker.run("extension.activatePlugins", async () => { + await plugins.activate({ + context, + outputChannel, + statusBarItem, + containerStatusTracker, + localStackStatusTracker, + setupStatusTracker, + telemetry, + timeTracker, + }); }); } diff --git a/src/plugins.ts b/src/plugins.ts index ccb200d..b35d3f9 100644 --- a/src/plugins.ts +++ b/src/plugins.ts @@ -1,9 +1,11 @@ +import ms from "ms"; import type { ExtensionContext, LogOutputChannel, StatusBarItem } from "vscode"; import type { ContainerStatusTracker } from "./utils/container-status.ts"; import type { LocalStackStatusTracker } from "./utils/localstack-status.ts"; import type { SetupStatusTracker } from "./utils/setup-status.ts"; import type { Telemetry } from "./utils/telemetry.ts"; +import type { TimeTracker } from "./utils/time-tracker.ts"; export type Deactivate = () => Promise | void; @@ -15,40 +17,59 @@ export interface PluginOptions { localStackStatusTracker: LocalStackStatusTracker; setupStatusTracker: SetupStatusTracker; telemetry: Telemetry; + timeTracker: TimeTracker; } export interface Plugin { deactivate: Deactivate; } -export type PluginFactory = (options: PluginOptions) => Promise; +export type PluginDefinition = { + name: string; + factory: (options: PluginOptions) => Promise; +}; export const createPlugin = ( + name: string, // biome-ignore lint/suspicious/noConfusingVoidType: required handler: (options: PluginOptions) => Promise | void, -): PluginFactory => { - return async (options) => { - const deactivate = (await handler(options)) ?? (() => {}); - return { - deactivate, - }; +): PluginDefinition => { + return { + name, + async factory(options: PluginOptions): Promise { + const deactivate = (await handler(options)) ?? (() => {}); + return { + deactivate, + }; + }, }; }; export class PluginManager { - private plugins: PluginFactory[]; + private plugins: PluginDefinition[]; private deactivatables: Plugin[]; - constructor(plugins: PluginFactory[]) { + constructor(plugins: PluginDefinition[]) { this.plugins = plugins; this.deactivatables = []; } async activate(options: PluginOptions) { for (const activate of this.plugins) { - const deactivatable = await activate(options); + const startPlugin = Date.now(); + options.outputChannel.trace( + `[extension.plugins]: Activating plugin "${activate.name}"...`, + ); + const deactivatable = await activate.factory(options); this.deactivatables.push(deactivatable); + const endPlugin = Date.now(); + options.outputChannel.trace( + `[extension.plugins]: Activated plugin "${activate.name}" in ${ms( + endPlugin - startPlugin, + { long: true }, + )}`, + ); } } diff --git a/src/plugins/authenticate.ts b/src/plugins/authenticate.ts index 7237122..ed5329e 100644 --- a/src/plugins/authenticate.ts +++ b/src/plugins/authenticate.ts @@ -6,99 +6,131 @@ import { requestAuthentication, saveAuthToken } from "../utils/authenticate.ts"; const MIN_TIME_BETWEEN_STEPS_MS = 1_000; // 1s -export default createPlugin(({ context, outputChannel, telemetry }) => { - context.subscriptions.push( - commands.registerCommand("localstack.authenticate", async () => { - const startedAt = new Date().toISOString(); - const selection = await window.showInformationMessage( - "Choose authentication method", - "Sign in to LocalStack", - "Enter auth token", - ); - if (selection === "Sign in to LocalStack") { - window.withProgress( - { - location: ProgressLocation.Notification, - title: "Authenticate", - cancellable: true, - }, - async (progress, cancellationToken) => { - ///////////////////////////////////////////////////////////////////// - progress.report({ - message: - "Waiting for authentication response from the browser...", - }); - const { authToken } = await pMinDelay( - requestAuthentication(context, undefined), - MIN_TIME_BETWEEN_STEPS_MS, - ); - if (cancellationToken.isCancellationRequested) { +export default createPlugin( + "authenticate", + ({ context, outputChannel, telemetry }) => { + context.subscriptions.push( + commands.registerCommand("localstack.authenticate", async () => { + const startedAt = new Date().toISOString(); + const selection = await window.showInformationMessage( + "Choose authentication method", + "Sign in to LocalStack", + "Enter auth token", + ); + if (selection === "Sign in to LocalStack") { + window.withProgress( + { + location: ProgressLocation.Notification, + title: "Authenticate", + cancellable: true, + }, + async (progress, cancellationToken) => { + ///////////////////////////////////////////////////////////////////// + progress.report({ + message: + "Waiting for authentication response from the browser...", + }); + const { authToken } = await pMinDelay( + requestAuthentication(context, undefined), + MIN_TIME_BETWEEN_STEPS_MS, + ); + if (cancellationToken.isCancellationRequested) { + telemetry.track({ + name: "auth_token_configured", + payload: { + namespace: "onboarding", + origin: "manual_trigger", + position: 2, + started_at: startedAt, + ended_at: new Date().toISOString(), + status: "CANCELLED", + }, + }); + return; + } + + ///////////////////////////////////////////////////////////////////// + progress.report({ + message: "Authenticating to file...", + }); + await pMinDelay( + saveAuthToken(authToken, outputChannel), + MIN_TIME_BETWEEN_STEPS_MS, + ); + + ///////////////////////////////////////////////////////////////////// + window.showInformationMessage("Authentication successful."); telemetry.track({ name: "auth_token_configured", payload: { namespace: "onboarding", origin: "manual_trigger", position: 2, + auth_token: authToken, started_at: startedAt, ended_at: new Date().toISOString(), - status: "CANCELLED", + status: "COMPLETED", }, }); - return; - } + }, + ); + } else if (selection === "Enter auth token") { + const token = await window.showInputBox({ + prompt: "Enter your LocalStack Auth Token", + placeHolder: "Paste your auth token here", + ignoreFocusOut: true, + }); - ///////////////////////////////////////////////////////////////////// - progress.report({ - message: "Authenticating to file...", + if (!token) { + telemetry.track({ + name: "auth_token_configured", + payload: { + namespace: "onboarding", + origin: "manual_trigger", + position: 2, + started_at: startedAt, + ended_at: new Date().toISOString(), + status: "FAILED", + errors: ["No token was provided."], + }, }); - await pMinDelay( - saveAuthToken(authToken, outputChannel), - MIN_TIME_BETWEEN_STEPS_MS, - ); + return; + } + + if (!token.startsWith("ls-")) { + const error_msg = 'The auth token should start with "ls-".'; + window.showErrorMessage(error_msg); - ///////////////////////////////////////////////////////////////////// - window.showInformationMessage("Authentication successful."); telemetry.track({ name: "auth_token_configured", payload: { namespace: "onboarding", origin: "manual_trigger", position: 2, - auth_token: authToken, started_at: startedAt, ended_at: new Date().toISOString(), - status: "COMPLETED", + status: "FAILED", + errors: [error_msg], }, }); - }, - ); - } else if (selection === "Enter auth token") { - const token = await window.showInputBox({ - prompt: "Enter your LocalStack Auth Token", - placeHolder: "Paste your auth token here", - ignoreFocusOut: true, - }); + return; + } - if (!token) { + await saveAuthToken(token, outputChannel); + window.showInformationMessage("Authentication successful."); telemetry.track({ name: "auth_token_configured", payload: { namespace: "onboarding", origin: "manual_trigger", position: 2, + auth_token: token, started_at: startedAt, ended_at: new Date().toISOString(), - status: "FAILED", - errors: ["No token was provided."], + status: "COMPLETED", }, }); - return; - } - - if (!token.startsWith("ls-")) { - const error_msg = 'The auth token should start with "ls-".'; - window.showErrorMessage(error_msg); - + } else if (selection === undefined) { telemetry.track({ name: "auth_token_configured", payload: { @@ -107,40 +139,11 @@ export default createPlugin(({ context, outputChannel, telemetry }) => { position: 2, started_at: startedAt, ended_at: new Date().toISOString(), - status: "FAILED", - errors: [error_msg], + status: "CANCELLED", }, }); - return; } - - await saveAuthToken(token, outputChannel); - window.showInformationMessage("Authentication successful."); - telemetry.track({ - name: "auth_token_configured", - payload: { - namespace: "onboarding", - origin: "manual_trigger", - position: 2, - auth_token: token, - started_at: startedAt, - ended_at: new Date().toISOString(), - status: "COMPLETED", - }, - }); - } else if (selection === undefined) { - telemetry.track({ - name: "auth_token_configured", - payload: { - namespace: "onboarding", - origin: "manual_trigger", - position: 2, - started_at: startedAt, - ended_at: new Date().toISOString(), - status: "CANCELLED", - }, - }); - } - }), - ); -}); + }), + ); + }, +); diff --git a/src/plugins/configure-aws.ts b/src/plugins/configure-aws.ts index 4996819..a721f05 100644 --- a/src/plugins/configure-aws.ts +++ b/src/plugins/configure-aws.ts @@ -3,7 +3,7 @@ import { commands } from "vscode"; import { createPlugin } from "../plugins.ts"; import { configureAwsProfiles } from "../utils/configure-aws.ts"; -export default createPlugin(({ context, telemetry }) => { +export default createPlugin("configure-aws", ({ context, telemetry }) => { context.subscriptions.push( commands.registerCommand("localstack.configureAwsProfiles", async () => { await configureAwsProfiles({ diff --git a/src/plugins/logs.ts b/src/plugins/logs.ts index 7078e13..e7c1671 100644 --- a/src/plugins/logs.ts +++ b/src/plugins/logs.ts @@ -5,6 +5,7 @@ import { createPlugin } from "../plugins.ts"; import { pipeToLogOutputChannel } from "../utils/spawn.ts"; export default createPlugin( + "logs", ({ context, outputChannel, containerStatusTracker }) => { let logsProcess: ChildProcess | undefined; diff --git a/src/plugins/manage.ts b/src/plugins/manage.ts index de97cde..9eca357 100644 --- a/src/plugins/manage.ts +++ b/src/plugins/manage.ts @@ -7,28 +7,31 @@ import { stopLocalStack, } from "../utils/manage.ts"; -export default createPlugin(({ context, outputChannel, telemetry }) => { - context.subscriptions.push( - commands.registerCommand("localstack.viewLogs", () => { - outputChannel.show(true); - }), - ); +export default createPlugin( + "manage", + ({ context, outputChannel, telemetry }) => { + context.subscriptions.push( + commands.registerCommand("localstack.viewLogs", () => { + outputChannel.show(true); + }), + ); - context.subscriptions.push( - commands.registerCommand("localstack.start", () => { - void startLocalStack(outputChannel, telemetry); - }), - ); + context.subscriptions.push( + commands.registerCommand("localstack.start", () => { + void startLocalStack(outputChannel, telemetry); + }), + ); - context.subscriptions.push( - commands.registerCommand("localstack.stop", () => { - void stopLocalStack(outputChannel, telemetry); - }), - ); + context.subscriptions.push( + commands.registerCommand("localstack.stop", () => { + void stopLocalStack(outputChannel, telemetry); + }), + ); - context.subscriptions.push( - commands.registerCommand("localstack.openLicensePage", () => { - void openLicensePage(); - }), - ); -}); + context.subscriptions.push( + commands.registerCommand("localstack.openLicensePage", () => { + void openLicensePage(); + }), + ); + }, +); diff --git a/src/plugins/setup.ts b/src/plugins/setup.ts index 68c6f92..fc7921b 100644 --- a/src/plugins/setup.ts +++ b/src/plugins/setup.ts @@ -13,6 +13,7 @@ import { runInstallProcess } from "../utils/install.ts"; import { minDelay } from "../utils/promises.ts"; export default createPlugin( + "setup", ({ context, outputChannel, setupStatusTracker, telemetry }) => { context.subscriptions.push( commands.registerCommand( diff --git a/src/plugins/status-bar.ts b/src/plugins/status-bar.ts index bd2262e..16d9332 100644 --- a/src/plugins/status-bar.ts +++ b/src/plugins/status-bar.ts @@ -5,6 +5,7 @@ import { createPlugin } from "../plugins.ts"; import { checkIsProfileConfigured } from "../utils/configure-aws.ts"; export default createPlugin( + "status-bar", ({ context, statusBarItem, localStackStatusTracker, setupStatusTracker }) => { context.subscriptions.push( commands.registerCommand("localstack.showCommands", async () => { diff --git a/src/utils/container-status.ts b/src/utils/container-status.ts index 352a764..d09fff3 100644 --- a/src/utils/container-status.ts +++ b/src/utils/container-status.ts @@ -5,6 +5,7 @@ import * as z from "zod/v4-mini"; import { createEmitter } from "./emitter.ts"; import { JsonLinesStream } from "./json-lines-stream.ts"; +import type { TimeTracker } from "./time-tracker.ts"; export type ContainerStatus = "running" | "stopping" | "stopped"; @@ -19,6 +20,7 @@ export interface ContainerStatusTracker extends Disposable { export async function createContainerStatusTracker( containerName: string, outputChannel: LogOutputChannel, + timeTracker: TimeTracker, ): Promise { let status: ContainerStatus | undefined; const emitter = createEmitter(outputChannel); @@ -34,9 +36,11 @@ export async function createContainerStatusTracker( }, ); - await getContainerStatus(containerName).then((newStatus) => { - status ??= newStatus; - void emitter.emit(status); + await timeTracker.run("container-status.getContainerStatus", async () => { + await getContainerStatus(containerName).then((newStatus) => { + status ??= newStatus; + void emitter.emit(status); + }); }); return { @@ -77,7 +81,9 @@ function listenToContainerStatus( const startListening = () => { if (isDisposed) return; - outputChannel.debug("Spawning 'docker events'..."); + outputChannel.debug( + "[container-status.listenToContainerStatus] Spawning 'docker events'...", + ); try { dockerEvents = spawn("docker", [ diff --git a/src/utils/localstack-status.ts b/src/utils/localstack-status.ts index f613c7c..f9ac65b 100644 --- a/src/utils/localstack-status.ts +++ b/src/utils/localstack-status.ts @@ -5,6 +5,7 @@ import type { ContainerStatusTracker, } from "./container-status.ts"; import { createEmitter } from "./emitter.ts"; +import type { TimeTracker } from "./time-tracker.ts"; export type LocalStackStatus = "starting" | "running" | "stopping" | "stopped"; @@ -19,6 +20,7 @@ export interface LocalStackStatusTracker extends Disposable { export async function createLocalStackStatusTracker( containerStatusTracker: ContainerStatusTracker, outputChannel: LogOutputChannel, + timeTracker: TimeTracker, ): Promise { let status: LocalStackStatus | undefined; const emitter = createEmitter(outputChannel); @@ -46,7 +48,10 @@ export async function createLocalStackStatusTracker( updateStatus(); healthCheckTimeout = setTimeout(() => void startHealthCheck(), 1_000); }; - await startHealthCheck(); + + await timeTracker.run("localstack-status.healthCheck", async () => { + await startHealthCheck(); + }); return { status() { diff --git a/src/utils/setup-status.ts b/src/utils/setup-status.ts index ef7fa72..ffff689 100644 --- a/src/utils/setup-status.ts +++ b/src/utils/setup-status.ts @@ -1,7 +1,9 @@ +import ms from "ms"; import type { Disposable, LogOutputChannel } from "vscode"; import { createEmitter } from "./emitter.ts"; import { checkIsSetupRequired } from "./setup.ts"; +import type { TimeTracker } from "./time-tracker.ts"; export type SetupStatus = "ok" | "setup_required"; @@ -15,9 +17,15 @@ export interface SetupStatusTracker extends Disposable { */ export async function createSetupStatusTracker( outputChannel: LogOutputChannel, + timeTracker: TimeTracker, ): Promise { + const start = Date.now(); let status: SetupStatus | undefined; const emitter = createEmitter(outputChannel); + const end = Date.now(); + outputChannel.trace( + `[setup-status]: Initialized dependencies in ${ms(end - start, { long: true })}`, + ); let timeout: NodeJS.Timeout | undefined; const startChecking = async () => { @@ -31,7 +39,9 @@ export async function createSetupStatusTracker( timeout = setTimeout(() => void startChecking(), 1_000); }; - await startChecking(); + await timeTracker.run("setup-status.checkIsSetupRequired", async () => { + await startChecking(); + }); return { status() { diff --git a/src/utils/time-tracker.ts b/src/utils/time-tracker.ts new file mode 100644 index 0000000..c82a3bb --- /dev/null +++ b/src/utils/time-tracker.ts @@ -0,0 +1,34 @@ +import ms from "ms"; +import type { LogOutputChannel } from "vscode"; + +const timeDiff = (start: number, end: number) => + ms(end - start, { long: true }); + +export interface TimeTracker { + run(name: string, fn: () => Promise): Promise; +} + +export const createTimeTracker = (options: { + outputChannel: LogOutputChannel; +}): TimeTracker => { + return { + async run(name: string, fn: () => Promise): Promise { + options.outputChannel.trace(`[${name}]: Starting...`); + const start = Date.now(); + try { + const result = await fn(); + const end = Date.now(); + options.outputChannel.trace( + `[${name}]: Completed in ${timeDiff(start, end)}`, + ); + return result; + } catch (error) { + const end = Date.now(); + options.outputChannel.error( + `[${name}]: Failed after ${timeDiff(start, end)}`, + ); + throw error; + } + }, + }; +};