diff --git a/README.md b/README.md index 5aacbd34f..7d9eade5c 100644 --- a/README.md +++ b/README.md @@ -6,7 +6,6 @@ [![Node.js](https://img.shields.io/badge/dynamic/json?url=https%3A%2F%2Fraw.githubusercontent.com%2Faws-cloudformation%2Fcloudformation-vscode%2Frefs%2Fheads%2Fmain%2Fpackage.json&query=%24.engines.node&label=Node.js&color=339933&logo=node.js&logoColor=white)](https://github.com/aws-cloudformation/cloudformation-vscode/blob/main/package.json) [![Latest Release](https://img.shields.io/github/v/release/aws-cloudformation/cloudformation-vscode?include_prereleases&sort=semver)](https://github.com/aws-cloudformation/cloudformation-vscode/releases) -[![Downloads](https://img.shields.io/github/downloads/aws-cloudformation/cloudformation-vscode/total.svg)](https://github.com/aws-cloudformation/cloudformation-vscode/releases) ## Overview @@ -90,13 +89,14 @@ template validation, and importing resource state, are not available in this ext | `aws.cloudformation.diagnostics.cfnGuard.enabledRulePacks` | `["cis-aws-benchmark-level-1"]` | Managed rule packs to validate against | | `aws.cloudformation.diagnostics.cfnGuard.rulesFile` | `""` | Path to a custom cfn-guard rules file; empty uses the enabled rule packs | | `aws.cloudformation.trace.server` | `"off"` | Trace communication with the language server (`messages`, `verbose`) | -| `aws.cloudformation.telemetry.enabled` | `false` | Share anonymous usage telemetry with AWS | +| `aws.iac.telemetry.enabled` | `false` | Share anonymous usage telemetry with AWS | | `aws.cloudformation.telemetry.logLevel` | `"info"` | Log level of the extension output channel; applies after a window reload | ## Telemetry Telemetry is off by default. On first activation the extension asks whether to share anonymous usage data with AWS; -you can change the choice at any time with `aws.cloudformation.telemetry.enabled`. See the language server's +you can change the choice at any time with `aws.iac.telemetry.enabled`. The setting is specific to this extension; +it does not read or change the telemetry preference of any other extension. See the language server's [telemetry documentation](https://github.com/aws-cloudformation/cloudformation-languageserver/tree/main/src/telemetry) for what is collected. diff --git a/package.json b/package.json index 098d9323a..2706e09a6 100644 --- a/package.json +++ b/package.json @@ -128,10 +128,10 @@ "default": "off", "description": "Traces the communication between VS Code and the language server" }, - "aws.cloudformation.telemetry.enabled": { + "aws.iac.telemetry.enabled": { "type": "boolean", "default": false, - "description": "Configure anonymous telemetry collection (cannot disable unless it is a production release)" + "description": "Share anonymous usage telemetry from the AWS CloudFormation extension with AWS" }, "aws.cloudformation.telemetry.logLevel": { "type": "string", diff --git a/src/telemetry/TelemetryOptIn.ts b/src/telemetry/TelemetryOptIn.ts index 83896bcbb..249976200 100644 --- a/src/telemetry/TelemetryOptIn.ts +++ b/src/telemetry/TelemetryOptIn.ts @@ -15,7 +15,7 @@ const stateKeys = { unpersistedResponse: `${ExtensionConfigKey}.telemetry.unpersistedResponse`, } as const; -const telemetrySettingKey = 'aws.cloudformation.telemetry'; +const telemetrySettingKey = 'aws.iac.telemetry'; const thirtyDaysMs = 30 * 24 * 60 * 60 * 1000; const promptTimeoutMs = 2500; const telemetryDocsUrl = 'https://github.com/aws-cloudformation/cloudformation-languageserver/tree/main/src/telemetry'; @@ -105,7 +105,7 @@ async function promptTelemetryOptIn(context: ExtensionContext): Promise const { globalState } = context; const response = await window.showInformationMessage( - 'Help us improve the AWS CloudFormation Language Server by sharing anonymous telemetry data with AWS. You can change this preference at any time in aws.cloudformation Settings.', + 'Help us improve the AWS CloudFormation Language Server by sharing anonymous telemetry data with AWS. You can change this preference at any time with the aws.iac.telemetry.enabled setting.', TelemetryChoice.Allow, TelemetryChoice.Later, TelemetryChoice.Never, diff --git a/src/utils/Logger.ts b/src/utils/Logger.ts index 7e08bc55d..f588168c2 100644 --- a/src/utils/Logger.ts +++ b/src/utils/Logger.ts @@ -1,5 +1,5 @@ -import { OutputChannel, workspace } from 'vscode'; -import { toString } from './Utils'; +import { LogOutputChannel, workspace } from 'vscode'; +import { extractErrorMessage, toString } from './Utils'; type LogLevel = 'debug' | 'info' | 'warn' | 'error'; @@ -10,15 +10,6 @@ const levelPriority: Record = { error: 3, }; -function formatTime(): string { - return new Date().toLocaleTimeString('en-US', { - hour: '2-digit', - minute: '2-digit', - second: '2-digit', - hour12: true, - }); -} - export class Logger { private readonly configuredLevel = workspace .getConfiguration('aws.cloudformation.telemetry') @@ -26,7 +17,7 @@ export class Logger { constructor( private readonly name: string, - private readonly channel: OutputChannel, + private readonly channel: LogOutputChannel, ) {} private shouldLog(level: LogLevel): boolean { @@ -38,15 +29,16 @@ export class Logger { return; } - let line = `[${formatTime()}] ${capitalize(level)}: [${this.name}]`; + // The channel stamps time and level itself; only the component name is added here. + let line = `[${this.name}]`; if (message) { - line += `${line} ${message}`; + line += ` ${message}`; } if (data) { - line += ` ${toString(data)}`; + line += ` ${data instanceof Error ? (data.stack ?? extractErrorMessage(data)) : toString(data)}`; } - this.channel.appendLine(line); + this.channel[level](line); } debug(data: unknown, message?: string): void { @@ -67,10 +59,10 @@ export class Logger { } export class LoggerFactory { - private static channel: OutputChannel; + private static channel: LogOutputChannel; private static readonly loggers = new Map(); - static initialize(channel: OutputChannel) { + static initialize(channel: LogOutputChannel) { this.channel = channel; } @@ -89,14 +81,7 @@ export class LoggerFactory { /** @internal For testing only */ static reset(): void { - this.channel = undefined as unknown as OutputChannel; + this.channel = undefined as unknown as LogOutputChannel; this.loggers.clear(); } } - -function capitalize(str: string) { - return str - .split(' ') - .map((word) => word.charAt(0).toUpperCase() + word.slice(1)) - .join(' '); -} diff --git a/tst/__mocks__/vscode.ts b/tst/__mocks__/vscode.ts index 70ba837b4..adef4e654 100644 --- a/tst/__mocks__/vscode.ts +++ b/tst/__mocks__/vscode.ts @@ -20,6 +20,11 @@ const vscode = { }), createOutputChannel: vi.fn().mockReturnValue({ appendLine: vi.fn(), + trace: vi.fn(), + debug: vi.fn(), + info: vi.fn(), + warn: vi.fn(), + error: vi.fn(), dispose: vi.fn(), }), showQuickPick: vi.fn(), diff --git a/tst/auth/awsCredentials.test.ts b/tst/auth/awsCredentials.test.ts index 04496642e..e3be4e76e 100644 --- a/tst/auth/awsCredentials.test.ts +++ b/tst/auth/awsCredentials.test.ts @@ -21,7 +21,7 @@ describe('AwsCredentialsService', () => { vi.clearAllMocks(); LoggerFactory.reset(); - LoggerFactory.initialize(window.createOutputChannel('test')); + LoggerFactory.initialize(window.createOutputChannel('test', { log: true })); mockStatusBarItem = { show: vi.fn(), diff --git a/tst/lsp-server/CfnDevLspServerProvider.test.ts b/tst/lsp-server/CfnDevLspServerProvider.test.ts index a9d059695..6f9ca762f 100644 --- a/tst/lsp-server/CfnDevLspServerProvider.test.ts +++ b/tst/lsp-server/CfnDevLspServerProvider.test.ts @@ -15,7 +15,7 @@ describe('CfnDevLspServerProvider', () => { beforeEach(() => { LoggerFactory.reset(); - LoggerFactory.initialize(window.createOutputChannel('test')); + LoggerFactory.initialize(window.createOutputChannel('test', { log: true })); testDir = nodeFs.mkdtempSync(join(tmpdir(), 'cfn-dev-test-')); }); diff --git a/tst/lsp-server/CfnRemoteLspServerProvider.test.ts b/tst/lsp-server/CfnRemoteLspServerProvider.test.ts index 457a3a026..9a26baeaa 100644 --- a/tst/lsp-server/CfnRemoteLspServerProvider.test.ts +++ b/tst/lsp-server/CfnRemoteLspServerProvider.test.ts @@ -24,7 +24,7 @@ describe('CfnRemoteLspServerProvider', () => { beforeEach(() => { LoggerFactory.reset(); - LoggerFactory.initialize(window.createOutputChannel('test')); + LoggerFactory.initialize(window.createOutputChannel('test', { log: true })); testDir = nodeFs.mkdtempSync(join(tmpdir(), 'cfn-remote-provider-test-')); }); @@ -125,7 +125,7 @@ describe('Installer → Provider → Launcher integration: failed managed path i beforeEach(() => { LoggerFactory.reset(); - LoggerFactory.initialize(window.createOutputChannel('test')); + LoggerFactory.initialize(window.createOutputChannel('test', { log: true })); testDir = nodeFs.mkdtempSync(join(tmpdir(), 'cfn-integration-test-')); }); diff --git a/tst/lsp-server/LspLauncher.test.ts b/tst/lsp-server/LspLauncher.test.ts index c7f986637..fe0cbfcf3 100644 --- a/tst/lsp-server/LspLauncher.test.ts +++ b/tst/lsp-server/LspLauncher.test.ts @@ -47,7 +47,7 @@ describe('LspLauncher', () => { beforeEach(() => { LoggerFactory.reset(); - LoggerFactory.initialize(window.createOutputChannel('test')); + LoggerFactory.initialize(window.createOutputChannel('test', { log: true })); let resolveCount = 0; resolver = { diff --git a/tst/lsp-server/LspServerLifecycle.test.ts b/tst/lsp-server/LspServerLifecycle.test.ts index 77127ef51..0fb1cd349 100644 --- a/tst/lsp-server/LspServerLifecycle.test.ts +++ b/tst/lsp-server/LspServerLifecycle.test.ts @@ -30,7 +30,7 @@ describe('LspServerLifecycleController', () => { beforeEach(() => { LoggerFactory.reset(); - LoggerFactory.initialize(window.createOutputChannel('test')); + LoggerFactory.initialize(window.createOutputChannel('test', { log: true })); let resolveCount = 0; resolveServer = vi.fn(() => Promise.resolve(`server-${++resolveCount}`)); diff --git a/tst/lsp-server/installer/BaseLspInstaller.test.ts b/tst/lsp-server/installer/BaseLspInstaller.test.ts index 558c2f97c..beed9f134 100644 --- a/tst/lsp-server/installer/BaseLspInstaller.test.ts +++ b/tst/lsp-server/installer/BaseLspInstaller.test.ts @@ -267,7 +267,7 @@ describe('BaseLspInstaller', () => { beforeEach(() => { LoggerFactory.reset(); - LoggerFactory.initialize(window.createOutputChannel('test')); + LoggerFactory.initialize(window.createOutputChannel('test', { log: true })); memFs = new MemoryFs(); fetcher = new MockFetcher(); installer = createInstaller(baseDir, memFs, fetcher); diff --git a/tst/lsp-server/installer/CfnLspInstaller.test.ts b/tst/lsp-server/installer/CfnLspInstaller.test.ts index c42666b7a..ceb908d9e 100644 --- a/tst/lsp-server/installer/CfnLspInstaller.test.ts +++ b/tst/lsp-server/installer/CfnLspInstaller.test.ts @@ -28,7 +28,7 @@ describe('CfnLspInstaller', () => { beforeEach(() => { LoggerFactory.reset(); - LoggerFactory.initialize(window.createOutputChannel('test')); + LoggerFactory.initialize(window.createOutputChannel('test', { log: true })); testDir = nodeFs.mkdtempSync(join(tmpdir(), 'cfn-installer-test-')); installer = new CfnLspInstaller(testDir, 'prod', undefined, undefined, async () => {}); }); diff --git a/tst/lsp-server/installer/platform.test.ts b/tst/lsp-server/installer/platform.test.ts index 7d1907059..c3dbb3402 100644 --- a/tst/lsp-server/installer/platform.test.ts +++ b/tst/lsp-server/installer/platform.test.ts @@ -13,7 +13,7 @@ vi.mock('vscode'); describe('platform detection', () => { beforeEach(() => { LoggerFactory.reset(); - LoggerFactory.initialize(window.createOutputChannel('test')); + LoggerFactory.initialize(window.createOutputChannel('test', { log: true })); }); describe('detectPlatformTarget (default, no injection)', () => { diff --git a/tst/lsp-server/installer/zipExtraction.test.ts b/tst/lsp-server/installer/zipExtraction.test.ts index 5b58f9a22..95d44592f 100644 --- a/tst/lsp-server/installer/zipExtraction.test.ts +++ b/tst/lsp-server/installer/zipExtraction.test.ts @@ -120,7 +120,7 @@ describe('BaseLspInstaller - zip extraction', () => { beforeEach(() => { LoggerFactory.reset(); - LoggerFactory.initialize(window.createOutputChannel('test')); + LoggerFactory.initialize(window.createOutputChannel('test', { log: true })); testDir = nodeFs.mkdtempSync(join(tmpdir(), 'zip-test-')); }); diff --git a/tst/telemetry/ClientId.test.ts b/tst/telemetry/ClientId.test.ts index 745812cc6..3fbbbf9dc 100644 --- a/tst/telemetry/ClientId.test.ts +++ b/tst/telemetry/ClientId.test.ts @@ -14,7 +14,7 @@ describe('ClientId / telemetry', () => { beforeEach(() => { LoggerFactory.reset(); - LoggerFactory.initialize(window.createOutputChannel('test')); + LoggerFactory.initialize(window.createOutputChannel('test', { log: true })); const data: Record = {}; mockState = { data, diff --git a/tst/telemetry/TelemetryOptIn.test.ts b/tst/telemetry/TelemetryOptIn.test.ts new file mode 100644 index 000000000..e0c776ff9 --- /dev/null +++ b/tst/telemetry/TelemetryOptIn.test.ts @@ -0,0 +1,68 @@ +import { beforeEach, describe, expect, it, vi } from 'vitest'; +import { window, workspace } from 'vscode'; +import { handleTelemetryOptIn } from '../../src/telemetry/TelemetryOptIn'; +import { LoggerFactory } from '../../src/utils/Logger'; + +vi.mock('vscode'); + +const settingKey = 'aws.iac.telemetry'; + +function createContext(state: Record) { + return { + globalState: { + get: (key: string) => state[key], + update: (key: string, value: unknown) => { + state[key] = value; + return Promise.resolve(); + }, + }, + } as any; +} + +describe('handleTelemetryOptIn', () => { + let settings: Record>; + + beforeEach(() => { + LoggerFactory.reset(); + LoggerFactory.initialize(window.createOutputChannel('test', { log: true })); + + settings = {}; + vi.mocked(workspace.getConfiguration).mockImplementation((section?: string) => { + const values = (settings[section ?? ''] ??= {}); + return { + get: vi.fn((key: string, defaultValue?: unknown) => values[key] ?? defaultValue), + update: vi.fn((key: string, value: unknown) => { + values[key] = value; + return Promise.resolve(); + }), + has: vi.fn(), + inspect: vi.fn(), + }; + }); + }); + + it('reads a previously recorded choice from aws.iac.telemetry.enabled', async () => { + settings[settingKey] = { enabled: true }; + const context = createContext({ 'aws.cloudformation.telemetry.hasResponded': true }); + + await expect(handleTelemetryOptIn(context)).resolves.toBe(true); + }); + + it('ignores aws.cloudformation.telemetry.enabled contributed by other extensions', async () => { + settings['aws.cloudformation.telemetry'] = { enabled: true }; + const context = createContext({ 'aws.cloudformation.telemetry.hasResponded': true }); + + await expect(handleTelemetryOptIn(context)).resolves.toBe(false); + }); + + it('persists the prompt answer under aws.iac.telemetry.enabled only', async () => { + vi.mocked(window.showInformationMessage).mockResolvedValue('Yes, Allow' as any); + const state: Record = {}; + + await expect(handleTelemetryOptIn(createContext(state))).resolves.toBe(true); + + expect(settings[settingKey]).toEqual({ enabled: true }); + expect(settings['aws.cloudformation.telemetry']?.enabled).toBeUndefined(); + expect(state['aws.cloudformation.telemetry.hasResponded']).toBe(true); + }); +}); diff --git a/tst/utils/Logger.test.ts b/tst/utils/Logger.test.ts new file mode 100644 index 000000000..1eb0f0fff --- /dev/null +++ b/tst/utils/Logger.test.ts @@ -0,0 +1,107 @@ +import { beforeEach, describe, expect, it, vi } from 'vitest'; +import { workspace } from 'vscode'; +import { Logger, LoggerFactory } from '../../src/utils/Logger'; + +vi.mock('vscode'); + +function createChannel() { + return { + appendLine: vi.fn(), + trace: vi.fn(), + debug: vi.fn(), + info: vi.fn(), + warn: vi.fn(), + error: vi.fn(), + dispose: vi.fn(), + }; +} + +function configureLevel(level: string | undefined) { + vi.mocked(workspace.getConfiguration).mockReturnValue({ + get: vi.fn().mockImplementation((_key: string, defaultValue: unknown) => level ?? defaultValue), + update: vi.fn(), + has: vi.fn(), + inspect: vi.fn(), + }); +} + +describe('Logger', () => { + let channel: ReturnType; + + beforeEach(() => { + channel = createChannel(); + configureLevel(undefined); + }); + + it('writes through the channel method matching the level instead of appendLine', () => { + const log = new Logger('Extension', channel as any); + + log.info('Activating v1.0.0'); + log.warn('slow start'); + log.error('boom'); + + expect(channel.info).toHaveBeenCalledWith('[Extension] Activating v1.0.0'); + expect(channel.warn).toHaveBeenCalledWith('[Extension] slow start'); + expect(channel.error).toHaveBeenCalledWith('[Extension] boom'); + expect(channel.appendLine).not.toHaveBeenCalled(); + }); + + it('does not add its own timestamp or level prefix', () => { + const log = new Logger('Extension', channel as any); + + log.info('Activating v1.0.0'); + + const [line] = channel.info.mock.calls[0]; + expect(line).toBe('[Extension] Activating v1.0.0'); + expect(line).not.toMatch(/\d{2}:\d{2}:\d{2}/); + expect(line).not.toMatch(/Info:/); + }); + + it('emits the prefix once when both a message and data are given', () => { + const log = new Logger('BaseLspInstaller', channel as any); + const err = new Error('ENOENT'); + + log.error(err, 'Download failed'); + + const [line] = channel.error.mock.calls[0]; + expect(line.startsWith('[BaseLspInstaller] Download failed ')).toBe(true); + expect(line.match(/\[BaseLspInstaller\]/g)).toHaveLength(1); + expect(line).toContain('ENOENT'); + }); + + it('honors the configured log level', () => { + configureLevel('warn'); + const log = new Logger('Extension', channel as any); + + log.debug('d'); + log.info('i'); + log.warn('w'); + log.error('e'); + + expect(channel.debug).not.toHaveBeenCalled(); + expect(channel.info).not.toHaveBeenCalled(); + expect(channel.warn).toHaveBeenCalledWith('[Extension] w'); + expect(channel.error).toHaveBeenCalledWith('[Extension] e'); + }); + + it('emits debug through the channel debug method when configured', () => { + configureLevel('debug'); + const log = new Logger('Extension', channel as any); + + log.debug('details'); + + expect(channel.debug).toHaveBeenCalledWith('[Extension] details'); + }); + + it('LoggerFactory returns one logger per name bound to the initialized channel', () => { + LoggerFactory.reset(); + LoggerFactory.initialize(channel as any); + + const a = LoggerFactory.getLogger('A'); + const b = LoggerFactory.getLogger('A'); + a.info('hello'); + + expect(a).toBe(b); + expect(channel.info).toHaveBeenCalledWith('[A] hello'); + }); +});