From 63321c1d84efb25d976837e02ac49636c92dc21d Mon Sep 17 00:00:00 2001 From: Julius Marminge Date: Sat, 20 Jun 2026 10:56:30 -0700 Subject: [PATCH] Structure keybindings failure diagnostics Co-authored-by: codex --- apps/server/src/keybindings.test.ts | 130 ++++++++++---- apps/server/src/keybindings.ts | 188 +++++++++++++++------ apps/server/src/serverRuntimeStartup.ts | 15 +- packages/client-runtime/src/rpc/session.ts | 2 +- packages/contracts/src/keybindings.ts | 15 +- 5 files changed, 255 insertions(+), 95 deletions(-) diff --git a/apps/server/src/keybindings.test.ts b/apps/server/src/keybindings.test.ts index ba95422735c..9884552a05f 100644 --- a/apps/server/src/keybindings.test.ts +++ b/apps/server/src/keybindings.test.ts @@ -1,17 +1,16 @@ import { KeybindingCommand, KeybindingRule, KeybindingsConfig } from "@t3tools/contracts"; import * as NodeServices from "@effect/platform-node/NodeServices"; import { assert, it } from "@effect/vitest"; -import { assertFailure } from "@effect/vitest/utils"; import * as Cause from "effect/Cause"; import * as Effect from "effect/Effect"; import * as FileSystem from "effect/FileSystem"; import * as Layer from "effect/Layer"; import * as Logger from "effect/Logger"; import * as Path from "effect/Path"; +import * as Result from "effect/Result"; import * as Schema from "effect/Schema"; import * as ServerConfig from "./config.ts"; import * as Keybindings from "./keybindings.ts"; -import { KeybindingsConfigError } from "@t3tools/contracts"; const KeybindingsConfigJson = Schema.fromJsonString(KeybindingsConfig); const encodeKeybindingsConfigJson = Schema.encodeEffect(KeybindingsConfigJson); @@ -34,12 +33,6 @@ const makeKeybindingsLayer = () => { ); }; -const toDetailResult = (effect: Effect.Effect) => - effect.pipe( - Effect.mapError((error) => error.detail), - Effect.result, - ); - const writeKeybindingsConfig = (configPath: string, rules: readonly KeybindingRule[]) => Effect.gen(function* () { const fileSystem = yield* FileSystem.FileSystem; @@ -223,15 +216,21 @@ it.layer(NodeServices.layer)("keybindings", (it) => { assert.deepEqual(configState.issues, [ { kind: "keybindings.malformed-config", - message: configState.issues[0]?.message ?? "", + message: "Expected the keybindings configuration to be a JSON array.", }, ]); assert.equal(yield* fs.readFileString(keybindingsConfigPath), "{ not-json"); }).pipe(Effect.provide(makeKeybindingsLayer())), ); - it.effect("ignores invalid entries in runtime and reports them as issues", () => - Effect.gen(function* () { + it.effect("ignores invalid entries in runtime and reports them as issues", () => { + const logs: ReadonlyArray[] = []; + const logger = Logger.make(({ message }) => { + logs.push(Array.isArray(message) ? message : [message]); + }); + const secret = "private-shortcut-payload"; + + return Effect.gen(function* () { const fs = yield* FileSystem.FileSystem; const { keybindingsConfigPath } = yield* ServerConfig.ServerConfig; yield* fs.writeFileString( @@ -240,7 +239,7 @@ it.layer(NodeServices.layer)("keybindings", (it) => { JSON.stringify([ { key: "mod+j", command: "terminal.toggle" }, { key: "mod+shift+d+o", command: "terminal.new" }, - { key: "mod+x", command: "invalid.command" }, + { key: "mod+x", command: secret }, ]), ); @@ -250,23 +249,55 @@ it.layer(NodeServices.layer)("keybindings", (it) => { }); assert.isTrue(configState.keybindings.some((entry) => entry.command === "terminal.toggle")); - assert.isFalse( - configState.keybindings.some((entry) => String(entry.command) === "invalid.command"), - ); + assert.isFalse(configState.keybindings.some((entry) => String(entry.command) === secret)); assert.deepEqual(configState.issues, [ { kind: "keybindings.invalid-entry", index: 1, - message: configState.issues[0]?.message ?? "", + message: "The keybinding entry contains an invalid shortcut or when expression.", }, { kind: "keybindings.invalid-entry", index: 2, - message: configState.issues[1]?.message ?? "", + message: "Expected a keybinding entry with key, command, and optional when fields.", }, ]); - }).pipe(Effect.provide(makeKeybindingsLayer())), - ); + const invalidEntryLog = logs.find((log) => { + const attributes = log[1]; + return ( + String(log[0]).includes("ignoring invalid keybinding entry") && + typeof attributes === "object" && + attributes !== null && + Reflect.get(attributes, "entryIndex") === 2 + ); + }); + if (!invalidEntryLog) { + return assert.fail("Expected invalid keybinding warning"); + } + const attributes = invalidEntryLog[1]; + if (typeof attributes !== "object" || attributes === null) { + return assert.fail("Expected structured invalid keybinding attributes"); + } + assert.equal(Reflect.get(attributes, "validationStage"), "entry-schema"); + assert.equal(Reflect.get(attributes, "validationInputKind"), "object"); + assert.equal(Reflect.get(attributes, "validationInputSize"), 2); + assert.equal(Reflect.get(attributes, "validationHasKeyField"), true); + assert.equal(Reflect.get(attributes, "validationHasCommandField"), true); + assert.equal(Reflect.get(attributes, "validationHasWhenField"), false); + assert.equal(Reflect.get(attributes, "causeReasonCount"), 1); + assert.isFalse("entry" in attributes); + assert.isFalse("cause" in attributes); + assert.isFalse(String(invalidEntryLog[0]).includes(secret)); + assert.isFalse(Object.values(attributes).some((value) => String(value).includes(secret))); + }).pipe( + Effect.provide( + Layer.mergeAll( + makeKeybindingsLayer(), + Logger.layer([logger], { mergeWithExisting: false }), + ), + ), + ); + }); it.effect( "upserts missing default keybindings on startup without overriding existing command rules", @@ -301,9 +332,9 @@ it.layer(NodeServices.layer)("keybindings", (it) => { ); it.effect("skips conflicting default keybindings on startup and logs a detailed warning", () => { - const messages: string[] = []; + const logs: ReadonlyArray[] = []; const logger = Logger.make(({ message }) => { - messages.push(String(message)); + logs.push(Array.isArray(message) ? message : [message]); }); return Effect.gen(function* () { @@ -321,11 +352,21 @@ it.layer(NodeServices.layer)("keybindings", (it) => { assert.isFalse(persisted.some((entry) => entry.command === "terminal.toggle")); assert.isTrue(persisted.some((entry) => entry.command === "script.custom-action.run")); - assert.isTrue( - messages.some((message) => - message.includes("skipping default keybinding due to shortcut conflict"), - ), + const warning = logs.find((log) => + String(log[0]).includes("skipping default keybinding due to shortcut conflict"), ); + if (!warning) { + return assert.fail("Expected shortcut conflict warning"); + } + const attributes = warning[1]; + if (typeof attributes !== "object" || attributes === null) { + return assert.fail("Expected structured shortcut conflict attributes"); + } + assert.equal(Reflect.get(attributes, "defaultCommand"), "terminal.toggle"); + assert.equal(Reflect.get(attributes, "conflictingCommand"), "script.custom-action.run"); + assert.equal(Reflect.get(attributes, "hasWhenContext"), false); + assert.isFalse("key" in attributes); + assert.isFalse("when" in attributes); }).pipe( Effect.provide( Layer.mergeAll( @@ -443,15 +484,24 @@ it.layer(NodeServices.layer)("keybindings", (it) => { key: "mod+shift+r", command: "script.run-tests.run", }); - }).pipe(toDetailResult); - assertFailure(result, "expected JSON array"); + }).pipe(Effect.result); + if (Result.isSuccess(result)) { + return assert.fail("Expected malformed config update to fail"); + } + assert.equal(result.failure._tag, "KeybindingsConfigError"); + assert.equal(result.failure.operation, "decode"); + assert.isTrue(Schema.isSchemaError(result.failure.cause)); + assert.equal( + result.failure.message, + `Keybindings config operation 'decode' failed at ${keybindingsConfigPath}.`, + ); const persistedRaw = yield* fs.readFileString(keybindingsConfigPath); assert.equal(persistedRaw, "{ not-json"); }).pipe(Effect.provide(makeKeybindingsLayer())), ); - it.effect("reports non-array config parse errors without duplicate prefix", () => + it.effect("returns stable structured decode errors across retries", () => Effect.gen(function* () { const fs = yield* FileSystem.FileSystem; const { keybindingsConfigPath } = yield* ServerConfig.ServerConfig; @@ -466,8 +516,12 @@ it.layer(NodeServices.layer)("keybindings", (it) => { key: "mod+shift+r", command: "script.run-tests.run", }); - }).pipe(toDetailResult); - assertFailure(firstResult, "expected JSON array"); + }).pipe(Effect.result); + if (Result.isSuccess(firstResult)) { + return assert.fail("Expected first malformed config update to fail"); + } + assert.equal(firstResult.failure.operation, "decode"); + assert.isTrue(Schema.isSchemaError(firstResult.failure.cause)); const secondResult = yield* Effect.gen(function* () { const keybindings = yield* Keybindings.Keybindings; @@ -475,8 +529,13 @@ it.layer(NodeServices.layer)("keybindings", (it) => { key: "mod+shift+r", command: "script.run-tests.run", }); - }).pipe(toDetailResult); - assertFailure(secondResult, "expected JSON array"); + }).pipe(Effect.result); + if (Result.isSuccess(secondResult)) { + return assert.fail("Expected second malformed config update to fail"); + } + assert.equal(secondResult.failure.operation, "decode"); + assert.isTrue(Schema.isSchemaError(secondResult.failure.cause)); + assert.equal(secondResult.failure.message, firstResult.failure.message); }).pipe(Effect.provide(makeKeybindingsLayer())), ); @@ -496,8 +555,11 @@ it.layer(NodeServices.layer)("keybindings", (it) => { key: "mod+shift+r", command: "script.run-tests.run", }); - }).pipe(toDetailResult); - assertFailure(result, "failed to write keybindings config"); + }).pipe(Effect.result); + if (Result.isSuccess(result)) { + return assert.fail("Expected update in a read-only directory to fail"); + } + assert.equal(result.failure.operation, "write"); yield* fs.chmod(dirname(keybindingsConfigPath), 0o700); diff --git a/apps/server/src/keybindings.ts b/apps/server/src/keybindings.ts index 5ddae4943f8..baca9a6d71d 100644 --- a/apps/server/src/keybindings.ts +++ b/apps/server/src/keybindings.ts @@ -44,6 +44,7 @@ import * as Semaphore from "effect/Semaphore"; import * as ServerConfig from "./config.ts"; import { writeFileStringAtomically } from "./atomicWrite.ts"; import { fromJsonStringPretty, fromLenientJson } from "@t3tools/shared/schemaJson"; +import { causeErrorTag } from "@t3tools/shared/observability"; import { DEFAULT_KEYBINDINGS, DEFAULT_RESOLVED_KEYBINDINGS, @@ -186,23 +187,53 @@ export interface KeybindingsChangeEvent { readonly issues: readonly ServerConfigIssue[]; } -function trimIssueMessage(message: string): string { - const trimmed = message.trim(); - return trimmed.length > 0 ? trimmed : "Invalid keybindings configuration."; -} +const MALFORMED_KEYBINDINGS_CONFIG_MESSAGE = + "Expected the keybindings configuration to be a JSON array."; +const INVALID_KEYBINDING_ENTRY_MESSAGE = + "Expected a keybinding entry with key, command, and optional when fields."; +const INVALID_KEYBINDING_RULE_MESSAGE = + "The keybinding entry contains an invalid shortcut or when expression."; -function malformedConfigIssue(detail: string): ServerConfigIssue { +function keybindingsCauseLogAttributes(cause: Cause.Cause) { return { - kind: "keybindings.malformed-config", - message: trimIssueMessage(detail), + errorTag: causeErrorTag(cause), + causeReasonCount: cause.reasons.length, + causeFailureCount: cause.reasons.filter(Cause.isFailReason).length, + causeDefectCount: cause.reasons.filter(Cause.isDieReason).length, + causeInterruptionCount: cause.reasons.filter(Cause.isInterruptReason).length, }; } -function invalidEntryIssue(index: number, detail: string): ServerConfigIssue { +function keybindingsValidationInputLogAttributes(value: unknown) { + if (typeof value === "string") { + return { validationInputKind: "string", validationInputSize: value.length }; + } + if (Array.isArray(value)) { + return { validationInputKind: "array", validationInputSize: value.length }; + } + if (typeof value === "object" && value !== null) { + return { + validationInputKind: "object", + validationInputSize: Object.keys(value).length, + validationHasKeyField: Object.hasOwn(value, "key"), + validationHasCommandField: Object.hasOwn(value, "command"), + validationHasWhenField: Object.hasOwn(value, "when"), + }; + } + return { validationInputKind: value === null ? "null" : typeof value }; +} + +function keybindingsValidationLogAttributes(input: { + readonly stage: "document" | "entry-schema" | "resolved-rule"; + readonly value: unknown; + readonly cause: Cause.Cause; + readonly index?: number; +}) { return { - kind: "keybindings.invalid-entry", - index, - message: trimIssueMessage(detail), + validationStage: input.stage, + ...(input.index === undefined ? {} : { entryIndex: input.index }), + ...keybindingsValidationInputLogAttributes(input.value), + ...keybindingsCauseLogAttributes(input.cause), }; } @@ -306,7 +337,7 @@ const make = Effect.gen(function* () { (cause) => new KeybindingsConfigError({ configPath: keybindingsConfigPath, - detail: "failed to access keybindings config", + operation: "access", cause, }), ), @@ -317,7 +348,7 @@ const make = Effect.gen(function* () { (cause) => new KeybindingsConfigError({ configPath: keybindingsConfigPath, - detail: "failed to read keybindings config", + operation: "read", cause, }), ), @@ -337,20 +368,24 @@ const make = Effect.gen(function* () { (cause) => new KeybindingsConfigError({ configPath: keybindingsConfigPath, - detail: "expected JSON array", + operation: "decode", cause, }), ), ); - return yield* Effect.forEach(rawConfig, (entry) => + return yield* Effect.forEach(rawConfig, (entry, index) => Effect.gen(function* () { const decodedRule = decodeKeybindingRuleExit(entry); if (decodedRule._tag === "Failure") { yield* Effect.logWarning("ignoring invalid keybinding entry", { path: keybindingsConfigPath, - entry, - error: Cause.pretty(decodedRule.cause), + ...keybindingsValidationLogAttributes({ + stage: "entry-schema", + value: entry, + cause: decodedRule.cause, + index, + }), }); return null; } @@ -358,8 +393,12 @@ const make = Effect.gen(function* () { if (resolved._tag === "Failure") { yield* Effect.logWarning("ignoring invalid keybinding entry", { path: keybindingsConfigPath, - entry, - error: Cause.pretty(resolved.cause), + ...keybindingsValidationLogAttributes({ + stage: "resolved-rule", + value: entry, + cause: resolved.cause, + index, + }), }); return null; } @@ -382,10 +421,22 @@ const make = Effect.gen(function* () { const rawConfig = yield* readRawConfig; const decodedEntries = decodeRawKeybindingsEntriesExit(rawConfig); if (decodedEntries._tag === "Failure") { - const detail = `expected JSON array (${Cause.pretty(decodedEntries.cause)})`; + yield* Effect.logWarning("ignoring malformed keybindings config", { + path: keybindingsConfigPath, + ...keybindingsValidationLogAttributes({ + stage: "document", + value: rawConfig, + cause: decodedEntries.cause, + }), + }); return { keybindings: [], - issues: [malformedConfigIssue(detail)], + issues: [ + { + kind: "keybindings.malformed-config", + message: MALFORMED_KEYBINDINGS_CONFIG_MESSAGE, + }, + ], }; } @@ -394,26 +445,38 @@ const make = Effect.gen(function* () { for (const [index, entry] of decodedEntries.value.entries()) { const decodedRule = decodeKeybindingRuleExit(entry); if (decodedRule._tag === "Failure") { - const detail = Cause.pretty(decodedRule.cause); - issues.push(invalidEntryIssue(index, detail)); + issues.push({ + kind: "keybindings.invalid-entry", + index, + message: INVALID_KEYBINDING_ENTRY_MESSAGE, + }); yield* Effect.logWarning("ignoring invalid keybinding entry", { path: keybindingsConfigPath, - index, - entry, - error: detail, + ...keybindingsValidationLogAttributes({ + stage: "entry-schema", + value: entry, + cause: decodedRule.cause, + index, + }), }); continue; } const resolvedRule = decodeResolvedKeybindingFromConfigExit(decodedRule.value); if (resolvedRule._tag === "Failure") { - const detail = Cause.pretty(resolvedRule.cause); - issues.push(invalidEntryIssue(index, detail)); + issues.push({ + kind: "keybindings.invalid-entry", + index, + message: INVALID_KEYBINDING_RULE_MESSAGE, + }); yield* Effect.logWarning("ignoring invalid keybinding entry", { path: keybindingsConfigPath, - index, - entry, - error: detail, + ...keybindingsValidationLogAttributes({ + stage: "resolved-rule", + value: entry, + cause: resolvedRule.cause, + index, + }), }); continue; } @@ -425,6 +488,14 @@ const make = Effect.gen(function* () { const writeConfigAtomically = (rules: readonly KeybindingRule[]) => { return encodeKeybindingsConfigPrettyJson(rules).pipe( + Effect.mapError( + (cause) => + new KeybindingsConfigError({ + configPath: keybindingsConfigPath, + operation: "encode", + cause, + }), + ), Effect.map((encoded) => `${encoded}\n`), Effect.flatMap((encoded) => writeFileStringAtomically({ @@ -433,16 +504,16 @@ const make = Effect.gen(function* () { }).pipe( Effect.provideService(FileSystem.FileSystem, fs), Effect.provideService(Path.Path, path), + Effect.mapError( + (cause) => + new KeybindingsConfigError({ + configPath: keybindingsConfigPath, + operation: "write", + cause, + }), + ), ), ), - Effect.mapError( - (cause) => - new KeybindingsConfigError({ - configPath: keybindingsConfigPath, - detail: "failed to write keybindings config", - cause, - }), - ), ); }; @@ -487,7 +558,13 @@ const make = Effect.gen(function* () { "skipping startup keybindings default sync because config has issues", { path: keybindingsConfigPath, - issues: runtimeConfig.issues, + issueCount: runtimeConfig.issues.length, + malformedConfigIssueCount: runtimeConfig.issues.filter( + (issue) => issue.kind === "keybindings.malformed-config", + ).length, + invalidEntryIssueCount: runtimeConfig.issues.filter( + (issue) => issue.kind === "keybindings.invalid-entry", + ).length, }, ); yield* Cache.invalidate(resolvedConfigCache, resolvedConfigCacheKey); @@ -499,8 +576,7 @@ const make = Effect.gen(function* () { const shortcutConflictWarnings: Array<{ defaultCommand: KeybindingRule["command"]; conflictingCommand: KeybindingRule["command"]; - key: string; - when: string | null; + hasWhenContext: boolean; }> = []; for (const defaultRule of DEFAULT_KEYBINDINGS) { if (existingCommands.has(defaultRule.command)) { @@ -513,8 +589,7 @@ const make = Effect.gen(function* () { shortcutConflictWarnings.push({ defaultCommand: defaultRule.command, conflictingCommand: conflictingEntry.command, - key: defaultRule.key, - when: defaultRule.when ?? null, + hasWhenContext: defaultRule.when !== undefined, }); continue; } @@ -525,8 +600,7 @@ const make = Effect.gen(function* () { path: keybindingsConfigPath, defaultCommand: conflict.defaultCommand, conflictingCommand: conflict.conflictingCommand, - key: conflict.key, - when: conflict.when, + hasWhenContext: conflict.hasWhenContext, reason: "shortcut context already used by existing rule", }); } @@ -574,13 +648,22 @@ const make = Effect.gen(function* () { (cause) => new KeybindingsConfigError({ configPath: keybindingsConfigPath, - detail: "failed to prepare keybindings config directory", + operation: "prepare-directory", cause, }), ), ); - const revalidateAndEmitSafely = revalidateAndEmit.pipe(Effect.ignoreCause({ log: true })); + const revalidateAndEmitSafely = revalidateAndEmit.pipe( + Effect.catchCause((cause) => + Cause.hasInterruptsOnly(cause) + ? Effect.void + : Effect.logWarning("keybindings config revalidation failed", { + path: keybindingsConfigPath, + ...keybindingsCauseLogAttributes(cause), + }), + ), + ); // Debounce watch events so the file is fully written before we read it. // Editors emit multiple events per save (truncate, write, rename) and @@ -597,7 +680,14 @@ const make = Effect.gen(function* () { ); yield* Stream.runForEach(debouncedKeybindingsEvents, () => revalidateAndEmitSafely).pipe( - Effect.ignoreCause({ log: true }), + Effect.catchCause((cause) => + Cause.hasInterruptsOnly(cause) + ? Effect.void + : Effect.logWarning("keybindings config watcher failed", { + path: keybindingsConfigPath, + ...keybindingsCauseLogAttributes(cause), + }), + ), Effect.forkIn(watcherScope), Effect.asVoid, ); diff --git a/apps/server/src/serverRuntimeStartup.ts b/apps/server/src/serverRuntimeStartup.ts index cbdf58c4d67..846c91e6f78 100644 --- a/apps/server/src/serverRuntimeStartup.ts +++ b/apps/server/src/serverRuntimeStartup.ts @@ -309,13 +309,14 @@ export const make = Effect.gen(function* () { yield* runStartupPhase( "keybindings.start", keybindings.start.pipe( - Effect.catch((error) => - Effect.logWarning("failed to start keybindings runtime", { - path: error.configPath, - detail: error.detail, - cause: error.cause, - }), - ), + Effect.catchTags({ + KeybindingsConfigError: (error) => + Effect.logWarning("failed to start keybindings runtime", { + path: error.configPath, + operation: error.operation, + errorTag: error._tag, + }), + }), Effect.forkScoped, ), ); diff --git a/packages/client-runtime/src/rpc/session.ts b/packages/client-runtime/src/rpc/session.ts index 52483ec5bd3..c651ac697d3 100644 --- a/packages/client-runtime/src/rpc/session.ts +++ b/packages/client-runtime/src/rpc/session.ts @@ -51,7 +51,7 @@ function mapInitialConfigError(error: InitialConfigError): ConnectionAttemptErro detail: error.message, cause: error, }); - case "KeybindingsConfigParseError": + case "KeybindingsConfigError": case "ServerSettingsError": return new ConnectionTransientErrorClass({ reason: "remote-unavailable", diff --git a/packages/contracts/src/keybindings.ts b/packages/contracts/src/keybindings.ts index 4a5ffd0c3dd..c0e6eea7f0f 100644 --- a/packages/contracts/src/keybindings.ts +++ b/packages/contracts/src/keybindings.ts @@ -157,14 +157,21 @@ export const ResolvedKeybindingsConfig = Schema.Array(ResolvedKeybindingRule).ch export type ResolvedKeybindingsConfig = typeof ResolvedKeybindingsConfig.Type; export class KeybindingsConfigError extends Schema.TaggedErrorClass()( - "KeybindingsConfigParseError", + "KeybindingsConfigError", { configPath: Schema.String, - detail: Schema.String, - cause: Schema.optional(Schema.Defect()), + operation: Schema.Literals([ + "access", + "read", + "decode", + "encode", + "write", + "prepare-directory", + ]), + cause: Schema.Defect(), }, ) { override get message(): string { - return `Unable to parse keybindings config at ${this.configPath}: ${this.detail}`; + return `Keybindings config operation '${this.operation}' failed at ${this.configPath}.`; } }