diff --git a/docs/src/content/docs/docs/Advanced/CLI.md b/docs/src/content/docs/docs/Advanced/CLI.md index a0c80bbfa..6c0995516 100644 --- a/docs/src/content/docs/docs/Advanced/CLI.md +++ b/docs/src/content/docs/docs/Advanced/CLI.md @@ -136,14 +136,15 @@ the prompts opening in Obsidian. ```bash obsidian vault=dev quickadd:interactive choice="Import from Readwise" -# -> {"ok":true,"host":"127.0.0.1","port":51789,"sessionId":"…","token":"…"} +# -> {"ok":true,"host":"127.0.0.1","port":51789,"sessionId":"…","token":"…","capabilities":["abort"]} ``` The command returns connection details immediately and runs the choice in the background. Attach to the session and drive it: - `GET http://127.0.0.1:/poll?session=&token=` - long-polls for the next event: `{"kind":"prompt","requestId":…,"prompt":{…}}`, `{"kind":"done","result":…}`, `{"kind":"error","error":…}`, or a periodic `{"kind":"idle"}` keepalive (just poll again). -- `POST http://127.0.0.1:/reply?session=&token=` with body `{"requestId":…,"value":…}` to answer, or `{"requestId":…,"cancelled":true}` to cancel (which aborts the run). +- `POST http://127.0.0.1:/reply?session=&token=` with body `{"requestId":…,"value":…}` to answer, or `{"requestId":…,"cancelled":true}` to cancel (which ends the run - except on an `info` panel, see below). +- `POST http://127.0.0.1:/abort?session=&token=` - end the run. Answers `{"ok":true,"interrupted":}`, where `n` is how many pending prompts it rejected; `409` if the run had already finished (benign - poll for the terminal event); `404` for an unknown session or token, or for any method other than `POST`. Prompt `type`s and the `value` you reply with: `suggester`/`input`/`date` → string, `confirm` → boolean, `checkbox` → string array, `info` → @@ -151,15 +152,39 @@ acknowledgement, `form` → an object mapping each field's `id` to its string value (date fields use the `@date:ISO` format). The run's outcome arrives as the `done`/`error` poll event. -### Cancelling - -`{"cancelled":true}` is how you say *the user dismissed this prompt*. It aborts -the run exactly as pressing Escape on the in-app dialog does. +### Cancelling, and ending a run + +`{"cancelled":true}` is how you say *the user dismissed this prompt*. It ends the +run exactly as pressing Escape on the in-app dialog does. + +`info` is the exception, because the in-app dialog is: `GenericInfoDialog` resolves +on every close path and has no way to abort anything, so the same choice run in +Obsidian continues past the panel. Escape is the only gesture an info panel affords, +so cancelling one just closes it and the run carries on - matching the app. + +To end a run deliberately, `POST /abort`. It rejects whatever the run is blocked on +and makes its next prompt fail too, so the run unwinds and delivers its **real** +outcome - usually `{"kind":"error","error":"Input cancelled by user"}`, but `done` if +it had nothing left to interrupt and simply finished. `/abort` never fabricates a +terminal event; keep polling until one arrives. The `interrupted` count tells you +whether it stopped anything. + +:::caution[What `/abort` cannot reach] +`/abort` interrupts prompts that were routed **to you**. A run that is mid-work +between prompts keeps going, and a Template or Capture run still opens some prompts in +Obsidian itself - the "file already exists" chooser, the folder picker, the +capture-target picker - which do not travel over this bridge +([#1614](https://github.com/chhoumann/quickadd/issues/1614)). So `"interrupted":0` +means nothing was waiting on you, and the run may still succeed and commit its side +effects. +::: -Do not use it just to close an `info` panel. `info` is the one prompt that cannot -be cancelled in the app - the dialog has no reject path - so cancelling it -remotely aborts a run that would have continued. Send a plain reply instead. It -stays cancellable because it is a client's only explicit way to bail out mid-run. +:::note[Available in the next release] +`POST /abort` and the `info` behaviour above are new; `"capabilities":["abort"]` in +the handshake tells you a build has them. Before them, cancelling an `info` prompt +ended the run, and there was no explicit way to end one other than to stop polling +and wait out the ~75s disconnect watchdog. +::: ### When a reply is rejected @@ -183,7 +208,7 @@ Every other prompt type accepts whatever you send, including an empty answer: `""` and `[]` are things a user genuinely submits in the app (the Skip buttons, optional fields), so they must stay legal here too. -A `409` means nothing was waiting on that `requestId`. +A `409` from `/reply` means nothing was waiting on that `requestId`. Good to know: diff --git a/src/ai/OpenAIRequest.test.ts b/src/ai/OpenAIRequest.test.ts index c1dc13aa1..80c7b90a0 100644 --- a/src/ai/OpenAIRequest.test.ts +++ b/src/ai/OpenAIRequest.test.ts @@ -735,7 +735,17 @@ describe("OpenAIRequest", () => { const [, result] = finishAIRequestLogEntryMock.mock.calls[0]; expect(result.status).toBe("error"); expect(result.errorMessage).toBe("Network down"); - expect(logErrorMock).toHaveBeenCalledWith(networkError); + // The WRAPPER is what gets reported, not the bare provider error. Its message + // is a strict superset - it names the provider, and on a context-overflow it + // carries QuickAdd's remediation sentence - and `reportError` reports a + // failure once (#1601), so reporting the cause first would leave the user + // with the least informative half of the pair. + expect(logErrorMock).toHaveBeenCalledTimes(1); + const reported = logErrorMock.mock.calls[0][0] as Error; + expect(reported.message).toBe( + "Error while making request to OpenAI: Network down", + ); + expect(reported.cause).toBe(networkError); }); it("preserves the original error as the cause of the wrapped error", async () => { diff --git a/src/ai/OpenAIRequest.ts b/src/ai/OpenAIRequest.ts index 639a44db7..004fa7d7b 100644 --- a/src/ai/OpenAIRequest.ts +++ b/src/ai/OpenAIRequest.ts @@ -14,6 +14,7 @@ import { finishAIRequestLogEntry, } from "./AIAssistant"; import { preventCursorChange } from "./preventCursorChange"; +import { reportError } from "../utils/errorUtils"; import type { AIProvider, Model } from "./Provider"; import { getProviderKind } from "./Provider"; import type { NormalizedChatRequest } from "./tools/NormalizedTools"; @@ -515,8 +516,6 @@ export function OpenAIRequest( `[AI Request ${requestLogId}] Failed in ${durationMs}ms: ${errorMessage}` ); - log.logError(error as Error); - // Help users act on the most common failure: a prompt that overflows // the model's context window. (ChunkedPrompt retries these automatically; // the single-prompt path cannot, so we point the user at a remedy.) @@ -525,10 +524,18 @@ export function OpenAIRequest( ? " The prompt likely exceeds the model's context window — shorten it, choose a model with a larger context, or use the chunked AI prompt API." : ""; - throw new Error( + // Report the WRAPPER, not the bare provider error, and report it before + // throwing so the failure is surfaced even if a caller swallows it. The + // wrapper's message is a strict superset - it names the provider and + // carries the guidance above - and since `reportError` reports a failure + // once (#1601), reporting the cause instead would leave the user with the + // least informative half of the pair. + const failure = new Error( `Error while making request to ${modelProvider.name}: ${errorMessage}${guidance}`, { cause: error } ); + reportError(failure); + throw failure; } }; } @@ -728,10 +735,14 @@ export async function chatRequest( durationMs, errorMessage, }); - log.logError(error as Error); - throw new Error( + // Report the wrapper, not the bare cause: its message names the provider, and + // `reportError` reports a failure once (#1601), so reporting the cause first + // would suppress the more informative message at every layer above. + const failure = new Error( `Error while making request to ${modelProvider.name}: ${errorMessage}`, { cause: error }, ); + reportError(failure); + throw failure; } } diff --git a/src/choiceExecutor.ts b/src/choiceExecutor.ts index 683b001e5..3335a75ae 100644 --- a/src/choiceExecutor.ts +++ b/src/choiceExecutor.ts @@ -240,7 +240,10 @@ export class ChoiceExecutor implements IChoiceExecutor { return { status: "cancelled", cancelKind: "aborted", reason: error.message }; } reportError(error, "Error executing choice from URI"); - return { status: "error" }; + return { + status: "error", + reason: error instanceof Error ? error.message : String(error), + }; } finally { this.endExecutionContext(); } diff --git a/src/cli/registerQuickAddCliHandlers.test.ts b/src/cli/registerQuickAddCliHandlers.test.ts index 672f26148..a63a82b0f 100644 --- a/src/cli/registerQuickAddCliHandlers.test.ts +++ b/src/cli/registerQuickAddCliHandlers.test.ts @@ -11,10 +11,22 @@ const { ChoiceExecutorMock, collectChoiceRequirementsMock, getUnresolvedRequirementsMock, + interactiveServerMock, } = vi.hoisted(() => ({ ChoiceExecutorMock: vi.fn(), collectChoiceRequirementsMock: vi.fn(), getUnresolvedRequirementsMock: vi.fn(), + // Stubbed so driving quickadd:interactive does not really bind a loopback port + // (and leave watchdog timers behind) just to read the terminal event. + interactiveServerMock: { + ensureStarted: vi.fn(), + createSession: vi.fn(), + finish: vi.fn(), + }, +})); + +vi.mock("../interactive/interactivePromptServer", () => ({ + interactivePromptServer: interactiveServerMock, })); vi.mock("../choiceExecutor", () => ({ @@ -150,6 +162,15 @@ describe("registerQuickAddCliHandlers", () => { collectChoiceRequirementsMock.mockResolvedValue([]); getUnresolvedRequirementsMock.mockReturnValue([]); + + interactiveServerMock.ensureStarted.mockReset(); + interactiveServerMock.createSession.mockReset(); + interactiveServerMock.finish.mockReset(); + interactiveServerMock.ensureStarted.mockResolvedValue(51789); + interactiveServerMock.createSession.mockReturnValue({ + id: "session-1", + token: "token-1", + }); }); it("registers run/list/check/preview handlers when CLI API is available", () => { @@ -363,6 +384,109 @@ describe("registerQuickAddCliHandlers", () => { expect(executors[0].execute).not.toHaveBeenCalled(); }); + /** + * #1603. The engines report a failure with a desktop notice and return without + * recording anything, so the outcome carried no reason and the CLI substituted a + * fixed sentence - on the interactive path, to a client that is the whole reason + * nobody is looking at the desktop. + */ + it("forwards the engine's real message to an interactive client", async () => { + const { plugin, handlers } = createPlugin([templateChoice]); + registerQuickAddCliHandlers(plugin); + const interactive = handlers.find( + (handler) => handler.command === "quickadd:interactive", + ); + ChoiceExecutorMock.mockImplementationOnce(function () { + const executor: IChoiceExecutor = { + execute: vi.fn().mockResolvedValue(undefined), + executeWithOutcome: vi.fn().mockResolvedValue({ + status: "error", + reason: 'Template file not found at path "templates/x.md".', + }), + variables: new Map(), + consumeAbortSignal: vi.fn().mockReturnValue(null), + }; + executors.push(executor); + return executor; + }); + + const response = JSON.parse( + String(await interactive!.handler({ choice: "Template Choice" })), + ); + expect(response.ok).toBe(true); + // The only feature-detection signal clients are told to use: it says both that + // POST /abort exists and that cancelling an `info` prompt no longer ends the + // run (#1605). An unknown path and an unauthed session answer the same 404 + // shape, so without this a client could only detect the build by string-matching + // an error body. + expect(response.capabilities).toEqual(["abort"]); + // The run is fire-and-forget; let its microtasks settle. + await new Promise((resolve) => setTimeout(resolve, 0)); + + expect(interactiveServerMock.finish).toHaveBeenCalledWith("session-1", { + kind: "error", + error: 'Template file not found at path "templates/x.md".', + }); + }); + + it("keeps the fixed sentence for an outcome that carries no reason", async () => { + const { plugin, handlers } = createPlugin([templateChoice]); + registerQuickAddCliHandlers(plugin); + const interactive = handlers.find( + (handler) => handler.command === "quickadd:interactive", + ); + ChoiceExecutorMock.mockImplementationOnce(function () { + const executor: IChoiceExecutor = { + execute: vi.fn().mockResolvedValue(undefined), + executeWithOutcome: vi.fn().mockResolvedValue({ status: "error" }), + variables: new Map(), + consumeAbortSignal: vi.fn().mockReturnValue(null), + }; + executors.push(executor); + return executor; + }); + + await interactive!.handler({ choice: "Template Choice" }); + await new Promise((resolve) => setTimeout(resolve, 0)); + + expect(interactiveServerMock.finish).toHaveBeenCalledWith("session-1", { + kind: "error", + error: "Choice execution failed; no file was created.", + }); + }); + + it("forwards the engine's real message on the verified run-template path too", async () => { + const { plugin, handlers } = createPlugin([]); + withTemplateFile(plugin, "Templates/Daily.md"); + registerQuickAddCliHandlers(plugin); + const run = handlers.find((h) => h.command === "quickadd:run-template"); + ChoiceExecutorMock.mockImplementationOnce(function () { + const executor: IChoiceExecutor = { + execute: vi.fn().mockResolvedValue(undefined), + executeWithOutcome: vi.fn().mockResolvedValue({ + status: "error", + reason: "Could not create file 'Daily.md'.", + }), + variables: new Map(), + consumeAbortSignal: vi.fn().mockReturnValue(null), + }; + executors.push(executor); + return executor; + }); + + const payload = JSON.parse( + String( + await run!.handler({ + path: "Templates/Daily.md", + "value-value": "Daily", + }), + ), + ); + + expect(payload.ok).toBe(false); + expect(payload.error).toBe("Could not create file 'Daily.md'."); + }); + it("maps an error outcome to ok:false even when execute() would have resolved", async () => { const { plugin, handlers } = createPlugin([]); withTemplateFile(plugin, "Templates/Daily.md"); diff --git a/src/cli/registerQuickAddCliHandlers.ts b/src/cli/registerQuickAddCliHandlers.ts index e672f9c74..6b5f830a7 100644 --- a/src/cli/registerQuickAddCliHandlers.ts +++ b/src/cli/registerQuickAddCliHandlers.ts @@ -456,7 +456,12 @@ async function runResolvedChoice( return serialize({ ok: false, command, - error: "Choice execution failed; no file was created.", + // The engine's own message, so a headless caller learns the cause + // (`Template file not found at path "…"`) instead of a fixed sentence + // while the actionable text goes to a desktop notice nobody is + // watching (#1603). The fallback is for an outcome that carries + // nothing at all - every engine failure exit records a reason. + error: outcome.reason || "Choice execution failed; no file was created.", choice: describeChoice(choice), durationMs, }); @@ -791,7 +796,11 @@ async function interactiveHandler( (outcome.cancelKind === "user" ? "Execution cancelled by user" : "Execution aborted") - : "Choice execution failed; no file was created.", + : // The engine's real message. A remote client is the whole + // premise of this seam - nobody is at the desktop to read + // the notice that carries the same text (#1603). + outcome.reason || + "Choice execution failed; no file was created.", }); return; } @@ -825,6 +834,12 @@ async function interactiveHandler( port, sessionId, token, + // Feature detection for the wire. `abort` says two things at once: this + // build serves `POST /abort`, and cancelling an `info` prompt closes the + // panel instead of ending the run (#1605). Without it a client could only + // tell the two behaviours apart by string-matching a 404 body, since an + // unknown path and an unauthed session answer the same shape. + capabilities: ["abort"], }); } catch (error) { return serialize({ diff --git a/src/engine/CaptureChoiceEngine.notice.test.ts b/src/engine/CaptureChoiceEngine.notice.test.ts index bc8c65691..d3013cf60 100644 --- a/src/engine/CaptureChoiceEngine.notice.test.ts +++ b/src/engine/CaptureChoiceEngine.notice.test.ts @@ -474,7 +474,14 @@ describe("CaptureChoiceEngine append-link destination", () => { expect(app.vault.adapter.exists).not.toHaveBeenCalled(); expect(app.vault.modify).not.toHaveBeenCalled(); - expect(choiceExecutor.recordExecutionResult).not.toHaveBeenCalled(); + // This exit used to record NOTHING, so `executeWithOutcome` produced a + // reason-less error and the CLI substituted its fixed sentence - #1603's exact + // symptom, reachable without any throw. It now carries the message the desktop + // notice carries. + expect(choiceExecutor.recordExecutionResult).toHaveBeenCalledWith({ + status: "error", + reason: expect.stringContaining("Append link target file not found"), + }); expect(appendFileLinkToDestinationFileMock).not.toHaveBeenCalled(); expect(copyFileLinkToClipboardMock).not.toHaveBeenCalled(); }); diff --git a/src/engine/CaptureChoiceEngine.selection.test.ts b/src/engine/CaptureChoiceEngine.selection.test.ts index 7bbf877dc..26f1bf85f 100644 --- a/src/engine/CaptureChoiceEngine.selection.test.ts +++ b/src/engine/CaptureChoiceEngine.selection.test.ts @@ -1248,8 +1248,11 @@ describe("CaptureChoiceEngine capture target resolution", () => { await engine.run(); expect(app.fileManager.trashFile).toHaveBeenCalledWith(attachmentFile); + // The reason travels with the outcome so a CLI/interactive caller is told WHY, + // instead of the fixed "Choice execution failed; no file was created." (#1603). expect(executor.recordExecutionResult).toHaveBeenCalledWith({ status: "error", + reason: expect.stringContaining("no active Markdown editor"), }); }); diff --git a/src/engine/CaptureChoiceEngine.ts b/src/engine/CaptureChoiceEngine.ts index 9eb793b5c..94808ec69 100644 --- a/src/engine/CaptureChoiceEngine.ts +++ b/src/engine/CaptureChoiceEngine.ts @@ -51,6 +51,10 @@ import { waitForTemplaterTriggerOnCreateToComplete, } from "../utilityObsidian"; import { isCancellationError, reportError } from "../utils/errorUtils"; +import { + ChoiceOutcomeRecorder, + failureReason, +} from "./choiceOutcomeRecorder"; import type { FieldFilter } from "../utils/FieldSuggestionParser"; import { resolveCaptureTarget as resolveCaptureTargetFromString, @@ -129,6 +133,7 @@ export class CaptureChoiceEngine extends QuickAddChoiceEngine { // TEXT (without '#' markers) for the success notice; the verbatim line goes to the // formatter override. Null when not in heading mode. private resolvedInsertAfterHeading: string | null = null; + private readonly outcome: ChoiceOutcomeRecorder; constructor( app: App, @@ -140,6 +145,7 @@ export class CaptureChoiceEngine extends QuickAddChoiceEngine { super(app); this.choice = choice; this.plugin = plugin; + this.outcome = new ChoiceOutcomeRecorder(choiceExecutor); this.formatter = new CaptureChoiceFormatter(app, plugin, choiceExecutor); // Every prompt this run opens can say which choice is asking (issue #1546). this.formatter.setPromptRunContext({ @@ -336,8 +342,7 @@ export class CaptureChoiceEngine extends QuickAddChoiceEngine { return true; } - InputPromptDraftStore.getInstance().markExecutionScopeFailed(); - log.logError( + this.failRun( `Append link target file not found or is not a Markdown file: ${linkOptions.destination.path}`, ); return false; @@ -543,11 +548,9 @@ export class CaptureChoiceEngine extends QuickAddChoiceEngine { // No active Markdown editor — the capture did not land. Report a // failure instead of falling through to the success notice/callback. await this.cleanupCreatedClipboardAttachments(); - InputPromptDraftStore.getInstance().markExecutionScopeFailed(); - log.logError( + this.failRun( `Capture "${this.choice.name}": no active Markdown editor to insert into.`, ); - this.choiceExecutor.recordExecutionResult?.({ status: "error" }); return; } contentCommitted = true; @@ -570,7 +573,7 @@ export class CaptureChoiceEngine extends QuickAddChoiceEngine { // Content is committed. Record success before append-link/open-file steps // so a later post-commit failure cannot make automation callers retry and // duplicate the Capture side effect. - this.choiceExecutor.recordExecutionResult?.({ status: "success", file }); + this.outcome.success(file); // Show success notification if (this.plugin.settings.showCaptureNotification) { @@ -636,6 +639,12 @@ export class CaptureChoiceEngine extends QuickAddChoiceEngine { return; } InputPromptDraftStore.getInstance().markExecutionScopeFailed(); + // Record BEFORE reporting: the notice is for whoever is at the desktop, the + // reason is for whoever is not (a CLI or interactive-bridge caller), and both + // must say the same thing (#1603). A no-op once the capture committed, so a + // post-commit link/open failure cannot make an automation retry and write + // the capture twice. + this.outcome.failure(failureReason(err)); reportError(err, `Error running capture choice "${this.choice.name}"`); } finally { if (contentCommitted) { @@ -644,6 +653,17 @@ export class CaptureChoiceEngine extends QuickAddChoiceEngine { } } + /** + * A failure exit that is not a throw: log it for the desktop, and record the same + * message as the run's outcome so a caller who cannot see notices learns the cause + * instead of the CLI's fixed "Choice execution failed" sentence (#1603). + */ + private failRun(message: string): void { + InputPromptDraftStore.getInstance().markExecutionScopeFailed(); + log.logError(message); + this.outcome.failure(message); + } + private async cleanupCreatedClipboardAttachments(): Promise { const paths = this.formatter.consumeCreatedClipboardAttachmentPaths(); for (const path of paths) { @@ -721,7 +741,7 @@ export class CaptureChoiceEngine extends QuickAddChoiceEngine { const captureIsNoOp = nextText === existingText; // Committed; append-link/open-file steps remain post-commit (see run()). - this.choiceExecutor.recordExecutionResult?.({ status: "success", file }); + this.outcome.success(file); if (this.plugin.settings.showCaptureNotification) { if (captureIsNoOp) { diff --git a/src/engine/MacroChoiceEngine.ts b/src/engine/MacroChoiceEngine.ts index e9984ba96..4572687ac 100644 --- a/src/engine/MacroChoiceEngine.ts +++ b/src/engine/MacroChoiceEngine.ts @@ -363,8 +363,15 @@ export class MacroChoiceEngine extends QuickAddChoiceEngine { if (err instanceof MacroAbortError) { throw err; } - // Report and re-throw script errors so users can debug them - reportError(err, `Failed to run user script ${command.name}`); + // Report and re-throw script errors so users can debug them. This report is + // the one the user sees - `reportError` reports a failure once (#1601), and + // the layers above catch the same instance - so it names the CHOICE as well + // as the script. Without that, a run-on-startup macro failing has no user + // action to correlate it with and nothing on screen says which macro broke. + reportError( + err, + `Failed to run user script ${command.name} in "${this.choice.name}"`, + ); throw err; } finally { this.userScriptCommand = null; diff --git a/src/engine/TemplateChoiceEngine.notice.test.ts b/src/engine/TemplateChoiceEngine.notice.test.ts index 9f74ccdd9..af285b4be 100644 --- a/src/engine/TemplateChoiceEngine.notice.test.ts +++ b/src/engine/TemplateChoiceEngine.notice.test.ts @@ -551,6 +551,79 @@ describe("TemplateChoiceEngine cancellation notices", () => { }); }); + /** + * #1603. A genuine failure (a missing template file, a vault error) reported a + * desktop notice and recorded nothing, so `executeWithOutcome` produced a + * reason-less error and the CLI replaced it with "Choice execution failed; no file + * was created." - on the interactive path, for a client that is the whole reason + * nobody is watching the desktop. + */ + it("records the real failure message so a headless caller learns the cause", async () => { + const { engine, choiceExecutor } = createEngine("unused", { + throwDuringFileName: false, + }); + choiceExecutor.recordExecutionResult = vi.fn(); + formatFileNameMock.mockRejectedValue( + new Error('Template file not found at path "templates/x.md".'), + ); + + await engine.run(); + + expect(choiceExecutor.recordExecutionResult).toHaveBeenCalledWith({ + status: "error", + reason: 'Template file not found at path "templates/x.md".', + }); + }); + + // A failure exit that is not a throw used to record nothing at all, which is the + // same reason-less outcome reached without any exception. + it("records a reason when the file could not be created", async () => { + const { engine, choiceExecutor } = createEngine("unused", { + throwDuringFileName: false, + stubTemplateContent: true, + }); + choiceExecutor.recordExecutionResult = vi.fn(); + ( + engine as unknown as { + createFileWithTemplate: () => Promise; + } + ).createFileWithTemplate = vi.fn().mockResolvedValue(null); + + await engine.run(); + + expect(choiceExecutor.recordExecutionResult).toHaveBeenCalledWith({ + status: "error", + reason: expect.stringContaining("Could not create file"), + }); + }); + + // The most actionable of the report-and-return-null exits - it names the fix - and it + // was the last one still handing a headless caller "Could not resolve file exists + // behavior". + it("records why a template cannot be appended to a canvas file", async () => { + const { engine, choiceExecutor, app } = createEngine("unused", { + throwDuringFileName: false, + stubTemplateContent: true, + }); + choiceExecutor.recordExecutionResult = vi.fn(); + const canvas = new TFile(); + canvas.path = "Board.canvas"; + canvas.extension = "canvas"; + canvas.basename = "Board"; + (app.vault.getAbstractFileByPath as ReturnType).mockReturnValue( + canvas, + ); + (app.vault.adapter.exists as ReturnType).mockResolvedValue(true); + engine.choice.fileExistsBehavior = { kind: "apply", mode: "appendTop" }; + + await engine.run(); + + expect(choiceExecutor.recordExecutionResult).toHaveBeenCalledWith({ + status: "error", + reason: expect.stringContaining('Use the "Overwrite" file-exists option'), + }); + }); + it("keeps template execution successful when clipboard copying throws", async () => { const store = InputPromptDraftStore.getInstance(); const draftKey = store.makeKey({ diff --git a/src/engine/TemplateChoiceEngine.ts b/src/engine/TemplateChoiceEngine.ts index 29d596431..50bce3c46 100644 --- a/src/engine/TemplateChoiceEngine.ts +++ b/src/engine/TemplateChoiceEngine.ts @@ -29,6 +29,10 @@ import { openFile, } from "../utilityObsidian"; import { isCancellationError, reportError } from "../utils/errorUtils"; +import { + ChoiceOutcomeRecorder, + failureReason, +} from "./choiceOutcomeRecorder"; import { filterFolderPathsWithinRoots, sortFolderPathsByTree, @@ -55,6 +59,7 @@ type NormalizedAppendLinkOptions = ReturnType export class TemplateChoiceEngine extends TemplateEngine { public choice: ITemplateChoice; private readonly choiceExecutor: IChoiceExecutor; + private readonly outcome: ChoiceOutcomeRecorder; constructor( app: App, @@ -65,6 +70,7 @@ export class TemplateChoiceEngine extends TemplateEngine { ) { super(app, plugin, choiceExecutor); this.choiceExecutor = choiceExecutor; + this.outcome = new ChoiceOutcomeRecorder(choiceExecutor); this.choice = choice; // Every prompt this run opens can say which choice is asking (issue #1546). this.formatter.setPromptRunContext({ @@ -110,10 +116,7 @@ export class TemplateChoiceEngine extends TemplateEngine { ); if (discovery.kind === "openExisting") { await this.openDiscoveredExistingNote(discovery.file); - this.choiceExecutor.recordExecutionResult?.({ - status: "success", - file: discovery.file, - }); + this.outcome.success(discovery.file); return; } @@ -198,8 +201,7 @@ export class TemplateChoiceEngine extends TemplateEngine { existingFile.extension !== "canvas" && existingFile.extension !== "base")) ) { - InputPromptDraftStore.getInstance().markExecutionScopeFailed(); - log.logError( + this.failRun( `'${targetFilePath}' already exists but could not be resolved as a markdown, canvas, or base file.`, ); return; @@ -213,8 +215,17 @@ export class TemplateChoiceEngine extends TemplateEngine { linkOptions, )); if (!createdFile) { - InputPromptDraftStore.getInstance().markExecutionScopeFailed(); - log.logWarning(`Could not resolve file exists behavior for '${targetFilePath}'.`); + // applyFileExistsMode's write helper has already reported the real + // cause (whichever mode ran - create, overwrite or append); prefer it + // and do not log a vaguer second line for the same failure. + if (this.lastTemplateFileFailure) { + this.failRun(this.lastTemplateFileFailure, "none"); + } else { + this.failRun( + `Could not resolve file exists behavior for '${targetFilePath}'.`, + "warning", + ); + } return; } } else { @@ -223,8 +234,14 @@ export class TemplateChoiceEngine extends TemplateEngine { templatePath, ); if (!createdFile) { - InputPromptDraftStore.getInstance().markExecutionScopeFailed(); - log.logWarning(`Could not create file '${targetFilePath}'.`); + // No second log line: createFileWithTemplate already reported the real + // cause. Record that same cause as the outcome, so a caller who cannot + // see notices is told what the notice said (#1603). + this.failRun( + this.lastTemplateFileFailure ?? + `Could not create file '${targetFilePath}'.`, + "none", + ); return; } createdNew = true; @@ -233,10 +250,7 @@ export class TemplateChoiceEngine extends TemplateEngine { // File is created/resolved (the commit point). Record success before // append-link/open-file steps so a later post-commit failure cannot make // automation callers retry and duplicate the Template side effect. - this.choiceExecutor.recordExecutionResult?.({ - status: "success", - file: createdFile, - }); + this.outcome.success(createdFile); if (linkOptions.enabled && createdFile) { // The note is already committed (success recorded above). A link @@ -332,12 +346,34 @@ export class TemplateChoiceEngine extends TemplateEngine { return; } InputPromptDraftStore.getInstance().markExecutionScopeFailed(); + // Record BEFORE reporting: the notice is for whoever is at the desktop, the + // reason is for whoever is not (a CLI or interactive-bridge caller), and both + // must say the same thing (#1603). + this.outcome.failure(failureReason(err)); reportError(err, `Error running template choice "${this.choice.name}"`); } finally { restoreDiscoveryValue?.(); } } + /** + * A failure exit that is not a throw: log it for the desktop, and record the same + * message as the run's outcome so a caller who cannot see notices learns the cause + * instead of the CLI's fixed "Choice execution failed" sentence (#1603). + */ + private failRun( + message: string, + level: "error" | "warning" | "none" = "error", + ): void { + InputPromptDraftStore.getInstance().markExecutionScopeFailed(); + // "none" is for a failure a lower layer has ALREADY reported: logging again + // would put a second notice on screen for one failure, which is exactly what + // report-once removes elsewhere (#1601). + if (level === "warning") log.logWarning(message); + else if (level === "error") log.logError(message); + this.outcome.failure(message); + } + private setTemporaryValueVariable(value: string): () => void { const variables = this.choiceExecutor.variables; const hadPreviousValue = variables.has("value"); @@ -368,8 +404,7 @@ export class TemplateChoiceEngine extends TemplateEngine { return true; } - InputPromptDraftStore.getInstance().markExecutionScopeFailed(); - log.logError( + this.failRun( `Append link target file not found or is not a Markdown file: ${linkOptions.destination.path}`, ); return false; @@ -522,10 +557,14 @@ export class TemplateChoiceEngine extends TemplateEngine { // Appending raw template text to a canvas/base file would splice it // into the file's structured JSON content and corrupt it. Only the // "Overwrite" file-exists option is safe for these formats. + // + // Recorded, not just logged: this is one of the report-and-return-null exits + // whose caller owns the run's outcome, and it carries the most actionable + // sentence of any of them (it names the fix). A CLI or interactive caller + // would otherwise be told "Could not resolve file exists behavior" (#1603). + this.lastTemplateFileFailure = `Cannot append to '${existingFile.path}': appending a template to a ${existingFile.extension} file would corrupt it. Use the "Overwrite" file-exists option instead.`; InputPromptDraftStore.getInstance().markExecutionScopeFailed(); - log.logError( - `Cannot append to '${existingFile.path}': appending a template to a ${existingFile.extension} file would corrupt it. Use the "Overwrite" file-exists option instead.`, - ); + log.logError(this.lastTemplateFileFailure); return null; } diff --git a/src/engine/TemplateEngine.ts b/src/engine/TemplateEngine.ts index 50588fc0e..3ead948fc 100644 --- a/src/engine/TemplateEngine.ts +++ b/src/engine/TemplateEngine.ts @@ -574,10 +574,31 @@ export abstract class TemplateEngine extends QuickAddEngine { return assembledPath; } + /** + * Why the last template write failed. + * + * Each of the write helpers below reports the real cause ("Template file not found at + * path …") and then returns null, so its caller only knew THAT the write failed, not + * why - and the caller is what records the run's outcome. A remote client was told + * "Choice execution failed; no file was created." while the actionable sentence went + * to a desktop notice nobody was watching (#1603). + * + * Every helper that reports-and-returns-null sets this, so a new one that forgets is + * the only way back to a vague outcome. + */ + protected lastTemplateFileFailure: string | null = null; + + /** Record the cause a report-and-return-null helper is about to swallow. */ + protected noteTemplateFileFailure(err: unknown, fallback: string): void { + this.lastTemplateFileFailure = + err instanceof Error && err.message ? err.message : fallback; + } + protected async createFileWithTemplate( filePath: string, resolvedTemplatePath: string ) { + this.lastTemplateFileFailure = null; try { const templateContent: string = await this.getTemplateContent( resolvedTemplatePath @@ -633,6 +654,10 @@ export abstract class TemplateEngine extends QuickAddEngine { if (isMacroAbortError(err)) { throw err; } + this.noteTemplateFileFailure( + err, + `Could not create file with template at ${filePath}`, + ); reportError(err, `Could not create file with template at ${filePath}`); return null; } @@ -680,6 +705,7 @@ export abstract class TemplateEngine extends QuickAddEngine { file: TFile, resolvedTemplatePath: string ) { + this.lastTemplateFileFailure = null; try { const templateContent: string = await this.getTemplateContent( resolvedTemplatePath @@ -726,6 +752,7 @@ export abstract class TemplateEngine extends QuickAddEngine { if (isMacroAbortError(err)) { throw err; } + this.noteTemplateFileFailure(err, "Could not overwrite file with template"); reportError(err, "Could not overwrite file with template"); return null; } @@ -736,6 +763,7 @@ export abstract class TemplateEngine extends QuickAddEngine { resolvedTemplatePath: string, section: "top" | "bottom" ) { + this.lastTemplateFileFailure = null; try { const templateContent: string = await this.getTemplateContent( resolvedTemplatePath @@ -774,6 +802,7 @@ export abstract class TemplateEngine extends QuickAddEngine { if (isMacroAbortError(err)) { throw err; } + this.noteTemplateFileFailure(err, "Could not append to file with template"); reportError(err, "Could not append to file with template"); return null; } diff --git a/src/engine/choiceOutcomeRecorder.test.ts b/src/engine/choiceOutcomeRecorder.test.ts new file mode 100644 index 000000000..367d7300e --- /dev/null +++ b/src/engine/choiceOutcomeRecorder.test.ts @@ -0,0 +1,63 @@ +import { describe, expect, it, vi } from "vitest"; +import { ChoiceOutcomeRecorder, failureReason } from "./choiceOutcomeRecorder"; + +const executor = () => ({ recordExecutionResult: vi.fn() }); + +describe("ChoiceOutcomeRecorder (#1603)", () => { + it("carries the reason on a failure so a headless caller learns the cause", () => { + const target = executor(); + + new ChoiceOutcomeRecorder(target).failure( + 'Template file not found at path "templates/x.md".', + ); + + expect(target.recordExecutionResult).toHaveBeenCalledWith({ + status: "error", + reason: 'Template file not found at path "templates/x.md".', + }); + }); + + // Both engines record success at their COMMIT point precisely so a later + // append-link or open-file failure cannot make an automation caller retry and + // duplicate the side effect. Terminality has to belong to the recorder: Capture + // commits from two methods, and the canvas path keeps going into steps whose + // throws unwind into run()'s catch. + it("is a no-op once the run has committed", () => { + const target = executor(); + const recorder = new ChoiceOutcomeRecorder(target); + + recorder.success({ path: "Note.md" } as never); + recorder.failure("Cannot append link because no active Markdown view is available."); + + expect(target.recordExecutionResult).toHaveBeenCalledTimes(1); + expect(target.recordExecutionResult).toHaveBeenCalledWith({ + status: "success", + file: { path: "Note.md" }, + }); + }); + + it("tolerates an executor that does not record outcomes at all", () => { + expect(() => new ChoiceOutcomeRecorder({}).failure("boom")).not.toThrow(); + }); +}); + +describe("failureReason", () => { + it("uses the Error's own message, with no context prefix", () => { + expect(failureReason(new Error("Template file not found"))).toBe( + "Template file not found", + ); + }); + + it("stringifies a non-Error throw", () => { + expect(failureReason("a script threw a string")).toBe( + "a script threw a string", + ); + }); + + // An Error with an empty message would otherwise hand the client "" and read as + // "no reason given", which is the state this whole change removes. + it("never yields an empty reason", () => { + expect(failureReason(new Error(""))).toBe("Choice execution failed."); + expect(failureReason(undefined)).toBe("undefined"); + }); +}); diff --git a/src/engine/choiceOutcomeRecorder.ts b/src/engine/choiceOutcomeRecorder.ts new file mode 100644 index 000000000..bfc3d27f7 --- /dev/null +++ b/src/engine/choiceOutcomeRecorder.ts @@ -0,0 +1,60 @@ +import type { TFile } from "obsidian"; +import type { IChoiceExecutor } from "../IChoiceExecutor"; + +/** + * Records what a choice run actually did, for the callers that must report it back to + * someone who is not looking at the Obsidian window. + * + * The Template and Capture engines report a failure with `reportError` - a desktop + * notice - and then return without recording anything. `executeWithOutcome` reads that + * as `{status:"error"}` with no reason, and the CLI substitutes a fixed sentence, so a + * remote run of a Template whose template file is missing told its client + * `"Choice execution failed; no file was created."` while the actionable message + * (`Template file not found at path "templates/x.md"`) went to a notice nobody was + * looking at (#1603). The whole premise of that seam is that nobody is at the desktop. + * + * Two rules: + * + * - **Every failure exit carries its reason.** Not just the top-level catch: the engines + * have five other places that log and return, and each one used to produce the same + * reason-less outcome. Routing them all through {@link failure} is what makes the CLI's + * fixed sentence unreachable rather than merely less common. + * - **The failure recorder is a no-op once the run has committed.** Both engines record + * success at their commit point precisely so a later append-link or open-file failure + * cannot make an automation caller retry and duplicate the side effect. That has to be + * a property of the recorder, not of one method: Capture commits from two places (the + * note path and the canvas path), and the canvas path keeps going into link and + * open-file steps whose throws unwind into `run()`'s catch. + */ +export class ChoiceOutcomeRecorder { + private committed = false; + + constructor( + private readonly executor: Pick, + ) {} + + /** The run committed its side effect. Records success and closes the outcome. */ + success(file?: TFile): void { + this.committed = true; + this.executor.recordExecutionResult?.({ status: "success", file }); + } + + /** + * The run failed, with the message that explains why - the same text the desktop + * notice carries, so a remote client and a local user learn the same thing. + */ + failure(reason: string): void { + if (this.committed) return; + this.executor.recordExecutionResult?.({ status: "error", reason }); + } +} + +/** The message to report for a caught value, without any context prefix. */ +export function failureReason(error: unknown): string { + // Never yields "": an empty reason reads to a client as "no reason given", which is + // the state this whole seam exists to remove. + if (error instanceof Error) return error.message || FALLBACK_REASON; + return String(error) || FALLBACK_REASON; +} + +const FALLBACK_REASON = "Choice execution failed."; diff --git a/src/gui/GenericSuggester/genericSuggester.ts b/src/gui/GenericSuggester/genericSuggester.ts index b72662a12..79258a49f 100644 --- a/src/gui/GenericSuggester/genericSuggester.ts +++ b/src/gui/GenericSuggester/genericSuggester.ts @@ -1,7 +1,8 @@ import { FuzzySuggestModal } from "obsidian"; import type { FuzzyMatch, App } from "obsidian"; -import { log, toError } from "src/logger/logManager"; +import { log } from "src/logger/logManager"; import { + createRenderFallbackWarner, installSkipAffordance, normalizeDisplayItem, normalizeQuery, @@ -29,6 +30,9 @@ export default class GenericSuggester extends FuzzySuggestModal { private displayItems: string[]; private items: T[]; private warnedOnEmptyDisplay = false; + private warnRenderItemFailure = createRenderFallbackWarner( + "Custom renderItem threw an error; falling back to default rendering", + ); public static Suggest( @@ -137,9 +141,7 @@ export default class GenericSuggester extends FuzzySuggestModal { this.renderItem(value.item, el); } catch (error) { // Fallback to default rendering if custom render throws - const err = toError(error); - err.message = `Custom renderItem threw an error; falling back to default rendering. ${err.message}`; - log.logWarning(err); + this.warnRenderItemFailure(error); el.empty(); super.renderSuggestion(value, el); } diff --git a/src/gui/InputSuggester/inputSuggester.ts b/src/gui/InputSuggester/inputSuggester.ts index a16bd4511..f9e9f3df3 100644 --- a/src/gui/InputSuggester/inputSuggester.ts +++ b/src/gui/InputSuggester/inputSuggester.ts @@ -1,7 +1,8 @@ import { FuzzySuggestModal, setIcon } from "obsidian"; import type { FuzzyMatch, App } from "obsidian"; -import { log, toError } from "src/logger/logManager"; +import { log } from "src/logger/logManager"; import { + createRenderFallbackWarner, installSkipAffordance, normalizeDisplayItem, normalizeQuery, @@ -58,6 +59,12 @@ export default class InputSuggester extends FuzzySuggestModal { private searchItems: string[]; private items: string[]; private warnedOnEmptyDisplay = false; + private warnRenderItemFailure = createRenderFallbackWarner( + "Custom renderItem threw an error; falling back to default rendering", + ); + private warnCustomValueFailure = createRenderFallbackWarner( + "Custom create-row rendering threw an error; falling back to default rendering", + ); private allowCustomValue = true; private customValueLabel?: (value: string) => string; private valueExists?: (value: string) => boolean; @@ -230,9 +237,7 @@ export default class InputSuggester extends FuzzySuggestModal { el.empty(); this.renderItem(value.item, el); } catch (error) { - const err = toError(error); - err.message = `Custom renderItem threw an error; falling back to default rendering. ${err.message}`; - log.logWarning(err); + this.warnRenderItemFailure(error); el.empty(); super.renderSuggestion(value, el); } @@ -250,9 +255,7 @@ export default class InputSuggester extends FuzzySuggestModal { const aux = el.createDiv({ cls: "suggestion-aux" }); setIcon(aux.createSpan({ cls: "suggestion-flair" }), "file-plus"); } catch (error) { - const err = toError(error); - err.message = `Custom create-row rendering threw an error; falling back to default rendering. ${err.message}`; - log.logWarning(err); + this.warnCustomValueFailure(error); el.empty(); super.renderSuggestion( { item: value, match: { score: 0, matches: [] } }, diff --git a/src/gui/suggesters/choiceSuggester.ts b/src/gui/suggesters/choiceSuggester.ts index 135aafe60..458828fd0 100644 --- a/src/gui/suggesters/choiceSuggester.ts +++ b/src/gui/suggesters/choiceSuggester.ts @@ -13,7 +13,8 @@ import { MultiChoice } from "../../types/choices/MultiChoice"; import type IMultiChoice from "../../types/choices/IMultiChoice"; import type QuickAdd from "../../main"; import type { IChoiceExecutor } from "../../IChoiceExecutor"; -import { log } from "../../logger/logManager"; +import { createRenderFallbackWarner } from "./utils"; +import { reportUnlessCancelled } from "../../utils/errorUtils"; import { settingsStore } from "../../settingsStore"; import { childChoicesOf, @@ -203,6 +204,9 @@ export default class ChoiceSuggester extends FuzzySuggestModal { // so they are torn down when the suggester closes instead of leaking onto the // long-lived plugin instance. private readonly markdownComponent = new Component(); + private readonly warnRenderFailure = createRenderFallbackWarner( + "Could not render a choice name as Markdown; showing it as plain text", + ); public static Open( plugin: QuickAdd, @@ -380,7 +384,12 @@ export default class ChoiceSuggester extends FuzzySuggestModal { void MarkdownRenderer.render(this.app, item.item.name, nameEl, "", this.markdownComponent) .catch((error) => { nameEl.textContent = item.item.name; - log.logError(`Failed to render choice suggestion: ${error}`); + // renderSuggestion runs per row and re-runs on every keystroke, so a + // renderer that keeps failing would raise a 15-second ERROR notice per + // row per keypress. Same shape as the renderItem storm in #1604: one + // broken renderer is one defect, and the plain-text fallback above is + // what every row gets anyway. + this.warnRenderFailure(error); }); el.classList.add("quickadd-choice-suggestion"); if (item.item.id === BACK_CHOICE_ID) @@ -444,7 +453,10 @@ export default class ChoiceSuggester extends FuzzySuggestModal { void runTemplateFromFolder(this.app, this.plugin, { choiceExecutor: this.choiceExecutor, }).catch((error) => { - log.logError(`Failed to run template from folder: ${error}`); + // reportError, not a template-stringified log line: interpolating the + // error throws its stack away, and only a value passed through + // reportError participates in the report-once contract (#1601). + reportUnlessCancelled(error, "Could not run a template from that folder"); }); return; } @@ -465,7 +477,7 @@ export default class ChoiceSuggester extends FuzzySuggestModal { ) : this.choiceExecutor.execute(item); void execute.catch((error) => { - log.logError(`Failed to execute selected choice: ${error}`); + reportUnlessCancelled(error, `Could not run "${item.name}"`); }); } } diff --git a/src/gui/suggesters/utils.test.ts b/src/gui/suggesters/utils.test.ts index 146ffbe7c..87dc5108d 100644 --- a/src/gui/suggesters/utils.test.ts +++ b/src/gui/suggesters/utils.test.ts @@ -1,4 +1,5 @@ -import { describe, it, expect, beforeEach } from "vitest"; +import { describe, it, expect, beforeEach, afterEach, vi } from "vitest"; +import { log } from "../../logger/logManager"; import { insertAtCursor, replaceRange, @@ -6,6 +7,7 @@ import { renderExactHighlight, renderFuzzyHighlight, stripMdExtensionForDisplay, + createRenderFallbackWarner, } from "./utils"; // Mock HTMLInputElement for testing @@ -252,3 +254,72 @@ describe("Suggester Utils", () => { }); }); }); + +/** + * #1604. `renderSuggestion` runs once per visible row and re-runs on every keystroke, so + * a caller-supplied `renderItem` that throws fails dozens of times for ONE defect. The + * old handler assigned to `err.message` on the CALLER's Error - measured live: three + * items over three renders put nine stacked Notices on screen, each message one prefix + * longer than the last. + */ +describe("createRenderFallbackWarner (#1604)", () => { + afterEach(() => { + vi.restoreAllMocks(); + }); + + it("warns once however many rows and renders fail", () => { + const logWarning = vi.spyOn(log, "logWarning").mockImplementation(() => {}); + const warn = createRenderFallbackWarner("Custom renderItem threw an error"); + + for (let i = 0; i < 30; i++) warn(new Error("renderItem is broken")); + + expect(logWarning).toHaveBeenCalledTimes(1); + }); + + it("never mutates the Error it was handed", () => { + const logWarning = vi.spyOn(log, "logWarning").mockImplementation(() => {}); + const cached = new TypeError("renderItem is broken"); + const warn = createRenderFallbackWarner("Custom renderItem threw an error"); + + warn(cached); + + expect(cached.message).toBe("renderItem is broken"); + const reported = logWarning.mock.calls[0][0] as Error; + expect(reported).not.toBe(cached); + expect(reported.message).toBe( + "Custom renderItem threw an error: renderItem is broken", + ); + // The fresh Error keeps the original's identity so DevTools still points at the + // callback that threw, not at the fallback handler. + expect(reported.name).toBe("TypeError"); + expect(reported.stack).toBe(cached.stack); + }); + + // The compounding shape, pinned directly: the same instance through many renders. + it("does not grow the message when one cached Error is rethrown per row", () => { + const logWarning = vi.spyOn(log, "logWarning").mockImplementation(() => {}); + const cached = new Error("renderItem is broken"); + const first = createRenderFallbackWarner("ctx"); + const second = createRenderFallbackWarner("ctx"); + + first(cached); + second(cached); + + expect( + logWarning.mock.calls.map((call) => (call[0] as Error).message), + ).toEqual(["ctx: renderItem is broken", "ctx: renderItem is broken"]); + }); + + // Two independent fallbacks in one modal (renderItem vs the custom "create" row) must + // not silence each other - they have different root causes and different copy. + it("keeps separate call sites independent", () => { + const logWarning = vi.spyOn(log, "logWarning").mockImplementation(() => {}); + const renderItem = createRenderFallbackWarner("renderItem failed"); + const customRow = createRenderFallbackWarner("create-row failed"); + + renderItem(new Error("a")); + customRow(new Error("b")); + + expect(logWarning).toHaveBeenCalledTimes(2); + }); +}); diff --git a/src/gui/suggesters/utils.ts b/src/gui/suggesters/utils.ts index 7b372dc94..827d4c1e3 100644 --- a/src/gui/suggesters/utils.ts +++ b/src/gui/suggesters/utils.ts @@ -1,5 +1,7 @@ import type { Instruction, Scope } from "obsidian"; +import { log } from "src/logger/logManager"; import { createOwnedElement, createOwnedTextNode } from "src/utils/activeWindow"; +import { toError } from "src/utils/errorUtils"; type CompletionInputEvent = Event & { fromCompletion?: boolean; @@ -69,6 +71,35 @@ export function installSkipAffordance( } } +/** + * A one-shot warner for a render fallback, scoped to one modal instance. + * + * `renderSuggestion` runs once per visible row and re-runs on every keystroke, so a + * caller-supplied `renderItem` that throws fails dozens of times for ONE defect. + * `log.logWarning` raises a Notice, so reporting each failure buried the user - measured + * live: three items over three renders put NINE stacked notices on screen (#1604). One + * broken callback is one defect, and the fallback rendering it triggers is identical for + * every row, so the first failure is the whole message. + * + * The trade accepted: a `renderItem` that throws a DIFFERENT error per row surfaces only + * the first. Warning per distinct message instead would restore the storm for the shape + * most likely to produce one (a message embedding the row's value). + * + * The context is passed to {@link toError}, which builds a fresh Error rather than + * mutating the caller's - assigning to `err.message` compounded the prefix on every + * render when a callback rethrew one cached Error (#1604). + */ +export function createRenderFallbackWarner( + context: string, +): (error: unknown) => void { + let warned = false; + return (error: unknown): void => { + if (warned) return; + warned = true; + log.logWarning(toError(error, context)); + }; +} + export function normalizeQuery(value: unknown): string { return normalizeDisplayItem(value); } diff --git a/src/interactive/interactivePromptServer.test.ts b/src/interactive/interactivePromptServer.test.ts index 417befe0c..bcb86dd02 100644 --- a/src/interactive/interactivePromptServer.test.ts +++ b/src/interactive/interactivePromptServer.test.ts @@ -3,6 +3,7 @@ import { interactivePromptServer, isLoopbackClient, safeEqual, + type PromptSpec, type ReplyBody, } from "./interactivePromptServer"; import { UserCancelError } from "../errors/UserCancelError"; @@ -24,6 +25,10 @@ function replyOverWire( afterEach(() => { vi.useRealTimers(); + // Sessions live for SESSION_TTL_MS after finish(), so without this the file + // accumulates them across tests and eventually trips MAX_SESSIONS - a capacity + // failure that looks like whatever test happens to be 33rd. + interactivePromptServer.stop(); }); describe("safeEqual", () => { @@ -243,9 +248,9 @@ describe("interactivePromptServer session multiplexing", () => { }); // A confirm reply that is neither boolean nor a cancel is validated HERE, while the - // client is still holding the HTTP response, because deeper in the only options are - // to invent an answer or to fail the run with a message the Template/Capture path - // replaces with a generic sentence the client never sees. + // client is still holding the HTTP response and the prompt is still PENDING, so the + // client can correct itself. Deeper in, the only options are to invent an answer or + // to fail the whole run. it.each([[undefined], [null], ["yes"], [0], [{}]])( "rejects a non-boolean confirm reply (%o) with 400", async (value) => { @@ -283,6 +288,182 @@ describe("interactivePromptServer session multiplexing", () => { }, ); + /** + * #1605. `GenericInfoDialog` resolves on EVERY close path and has no reject path at + * all, so the same choice run in the app continues past the panel. Escape is the only + * gesture an info panel affords, so a client mapping it to a cancel used to kill a run + * the app would have finished. + */ + it("closes an info panel on a cancel instead of ending the run", async () => { + const s = interactivePromptServer.createSession(); + const prompt = interactivePromptServer.emitPrompt(s.id, { + type: "info", + header: "Heads up", + text: ["Something to read."], + }); + const rid = pendingRequestId(s.id); + + expect(replyOverWire(s.id, { requestId: rid, cancelled: true }).status).toBe(200); + + await expect(prompt).resolves.toBeUndefined(); + interactivePromptServer.finish(s.id, { kind: "done", result: {} }); + }); + + it.each<[string, PromptSpec]>([ + ["input", { type: "input", header: "Name", multiline: false }], + ["confirm", { type: "confirm", header: "Proceed?" }], + ["checkbox", { type: "checkbox", items: [] }], + ])( + "still ends the run on a cancelled %s prompt", + async (_name, spec) => { + const s = interactivePromptServer.createSession(); + const prompt = interactivePromptServer.emitPrompt(s.id, spec); + const rid = pendingRequestId(s.id); + + expect(replyOverWire(s.id, { requestId: rid, cancelled: true }).status).toBe( + 200, + ); + + await expect(prompt).rejects.toBeInstanceOf(UserCancelError); + interactivePromptServer.finish(s.id, { kind: "done", result: {} }); + }, + ); + + // The replacement for info-cancel-as-bail-out. Without it, making an info cancel + // resolve would take away a client's only explicit way out, leaving it to stop + // polling and wait out the 75-second watchdog. + it("ends the run on abort, whatever prompt it is blocked on", async () => { + const s = interactivePromptServer.createSession(); + const info = interactivePromptServer.emitPrompt(s.id, { + type: "info", + header: "Heads up", + text: ["Something to read."], + }); + + expect(interactivePromptServer.abortSession(s.id)).toBe(1); + + await expect(info).rejects.toBeInstanceOf(UserCancelError); + // And a prompt raised afterwards rejects immediately rather than parking, so a + // run that was mid-work when the abort arrived unwinds at its next prompt. + await expect( + interactivePromptServer.emitPrompt(s.id, { + type: "input", + header: "Name", + multiline: false, + }), + ).rejects.toBeInstanceOf(UserCancelError); + interactivePromptServer.finish(s.id, { kind: "done", result: {} }); + }); + + // Reported so a client can tell an effective abort from a no-op: 0 means the run was + // mid-work, or blocked on a prompt QuickAdd opened in Obsidian rather than here. + it("reports how many pending prompts it interrupted", () => { + const s = interactivePromptServer.createSession(); + + expect(interactivePromptServer.abortSession(s.id)).toBe(0); + + interactivePromptServer.finish(s.id, { kind: "done", result: {} }); + }); + + it("refuses to abort a session that already ended", () => { + const s = interactivePromptServer.createSession(); + interactivePromptServer.finish(s.id, { kind: "done", result: {} }); + + expect(interactivePromptServer.abortSession(s.id)).toBeNull(); + expect(interactivePromptServer.abortSession("no-such-session")).toBeNull(); + }); + + // The pending entry is dropped BEFORE it is rejected, exactly as finish() does, so a + // reply that was already mid-flight cannot be answered 200 for a settle that is a + // no-op on an already-rejected promise. + it("leaves no pending entry for a reply that arrives after the abort", async () => { + const s = interactivePromptServer.createSession(); + const prompt = interactivePromptServer.emitPrompt(s.id, { + type: "input", + header: "Name", + multiline: false, + }); + const rid = pendingRequestId(s.id); + + interactivePromptServer.abortSession(s.id); + + expect(replyOverWire(s.id, { requestId: rid, value: "Ada" }).status).toBe(409); + await expect(prompt).rejects.toBeInstanceOf(UserCancelError); + interactivePromptServer.finish(s.id, { kind: "done", result: {} }); + }); + + // The wire contract this PR adds and documents: everything above goes through + // abortSession() directly, so without these the POST-only routing, the status + // mapping and the response shape rest on manual verification alone. + it("serves POST /abort over the router, and only POST", async () => { + const s = interactivePromptServer.createSession(); + const qs = `session=${s.id}&token=${s.token}`; + const prompt = interactivePromptServer.emitPrompt(s.id, { + type: "info", + header: "Heads up", + text: ["Something to read."], + }); + void prompt.catch(() => {}); + + // A browser can issue a GET with no Origin; the method gate is what stops it + // from ending a run. + expect((await overWire("GET", "/abort", qs)).status).toBe(404); + + const aborted = await overWire("POST", "/abort", qs); + expect(aborted.status).toBe(200); + expect(aborted.body).toEqual({ ok: true, interrupted: 1 }); + await expect(prompt).rejects.toBeInstanceOf(UserCancelError); + + interactivePromptServer.finish(s.id, { kind: "done", result: {} }); + // Aborting a run that already ended must not report that it stopped something. + const late = await overWire("POST", "/abort", qs); + expect(late.status).toBe(409); + + expect((await overWire("POST", "/abort", `session=${s.id}&token=nope`)).status).toBe( + 404, + ); + }); + + // A prompt raised while no poll was parked sits in the queue. Left there, the next + // poll hands the client a dialog it just asked to cancel, for a requestId that no + // longer exists, in FRONT of the run's real terminal event. + it("does not hand the client a prompt it already aborted", async () => { + const s = interactivePromptServer.createSession(); + const prompt = interactivePromptServer.emitPrompt(s.id, { + type: "input", + header: "Name", + multiline: false, + }); + void prompt.catch(() => {}); + + interactivePromptServer.abortSession(s.id); + interactivePromptServer.finish(s.id, { + kind: "error", + error: "Input cancelled by user", + }); + + const { res, events } = fakeRes(); + ( + interactivePromptServer as unknown as { + handlePoll: (session: unknown, res: unknown) => void; + sessions: Map; + } + ).handlePoll( + ( + interactivePromptServer as unknown as { + sessions: Map; + } + ).sessions.get(s.id), + res, + ); + + expect(events[0]).toEqual({ + kind: "error", + error: "Input cancelled by user", + }); + await expect(prompt).rejects.toBeInstanceOf(UserCancelError); + }); + it("still 409s an unknown requestId", () => { const s = interactivePromptServer.createSession(); const outcome = replyOverWire(s.id, { requestId: "nope", value: "x" }); @@ -321,6 +502,40 @@ describe("interactivePromptServer session multiplexing", () => { }); }); +/** + * Drives a request through the real `handle()` router, so the method gate, the auth + * gate and the status mapping are the ones production uses. Everything below the + * router (session lookup, abort, reply) is shared with the direct-call tests. + */ +async function overWire( + method: string, + path: string, + query: string, +): Promise<{ status: number; body: Record }> { + const { res, events } = fakeRes(); + let status = 0; + (res as { writeHead: (code: number) => void }).writeHead = (code: number) => { + status = code; + }; + await ( + interactivePromptServer as unknown as { + handle: (req: unknown, res: unknown) => Promise; + } + ).handle( + { + method, + url: `${path}?${query}`, + headers: { host: "127.0.0.1" }, + on() {}, + // A real IncomingMessage is an async iterable; the router drains the body + // before answering, so a stand-in that is not iterable would 400 here. + async *[Symbol.asyncIterator]() {}, + }, + res, + ); + return { status, body: (events[0] ?? {}) as Record }; +} + /** Minimal ServerResponse stand-in capturing what `send()` writes. */ function fakeRes(): { res: unknown; diff --git a/src/interactive/interactivePromptServer.ts b/src/interactive/interactivePromptServer.ts index 795d504b1..ddfa6a4f3 100644 --- a/src/interactive/interactivePromptServer.ts +++ b/src/interactive/interactivePromptServer.ts @@ -150,6 +150,13 @@ interface Session { } >; finished: boolean; + /** + * The client asked to end the run (`POST /abort`). Every pending prompt has been + * rejected; this makes a prompt raised AFTERWARDS reject immediately instead of + * parking, so a run that was mid-work when the abort arrived unwinds at its next + * prompt rather than carrying on to completion. + */ + aborted: boolean; cleanupTimer: number | null; /** True once a client has polled at least once. */ attached: boolean; @@ -345,6 +352,7 @@ class InteractivePromptServer { waiterTimer: null, pending: new Map(), finished: false, + aborted: false, cleanupTimer: null, attached: false, attachTimer: null, @@ -372,6 +380,11 @@ class InteractivePromptServer { if (session.finished) { return Promise.reject(new Error("Interactive session ended")); } + // The client already asked to end this run; do not park a new prompt it will + // never answer. + if (session.aborted) { + return Promise.reject(new UserCancelError(PROMPT_CANCELLED_MESSAGE)); + } const requestId = randomId(); return new Promise((resolve, reject) => { session.pending.set(requestId, { @@ -410,6 +423,50 @@ class InteractivePromptServer { ); } + /** + * End a run at the client's request: reject everything it is blocked on, and make + * the next prompt reject too. + * + * This exists because cancelling an `info` prompt no longer aborts. Escape is the + * only gesture an info panel affords, so treating it as "end the run" made a remote + * run diverge from the identical run in the app, where `GenericInfoDialog` resolves + * on every close path and can never abort anything (#1605). Taking that away without + * replacing it would have left a client with no explicit way out at all - only + * stopping its polling and waiting out the 75-second watchdog. + * + * No final event is pushed: the run unwinds through the ordinary cancellation path + * and delivers its real outcome, which is more truthful than a fabricated one. + * + * The honest limit, documented at the wire: this interrupts prompts that were routed + * to the CLIENT. Prompts QuickAdd still opens in Obsidian on a Template/Capture run + * (the file-exists suggester, the folder chooser, the capture-target picker) do not + * go through this server and are unaffected, which is why the reply says how many + * pending prompts it actually interrupted. + * + * @returns the number of pending prompts rejected, or null if there is no live + * session to abort. + */ + abortSession(sessionId: string): number | null { + const session = this.sessions.get(sessionId); + if (!session || session.finished) return null; + session.aborted = true; + // Delete before rejecting, exactly as finish() does: a `/reply` that was already + // mid-readBody would otherwise still find a pending entry, pass validation and + // be answered 200 for a settle that is a no-op on an already-rejected promise. + const pending = [...session.pending.values()]; + session.pending.clear(); + for (const prompt of pending) { + prompt.reject(new UserCancelError(PROMPT_CANCELLED_MESSAGE)); + } + // Drop prompts the client has not collected yet. A prompt raised while no poll + // was parked sits in the queue, and the next poll would hand the client a dialog + // it just asked to cancel - for a requestId that no longer exists, in front of + // the run's real terminal event. Only prompts are dropped; a queued done/error + // is the outcome the client is waiting for. + session.queue = session.queue.filter((event) => event.kind !== "prompt"); + return pending.length; + } + /** Stop the server and drop all sessions (plugin unload). */ stop(): void { // Invalidate any in-flight ensureStarted() so its listen() callback @@ -514,9 +571,22 @@ class InteractivePromptServer { // `describeReplyProblem` turns it into a 400 at the wire, leaving the prompt // pending - because resolving it would hand the run an empty answer the user // never gave, which is worse than the spurious abort a loose truthy check caused. - if (cancelled === true) - pending.reject(new UserCancelError(PROMPT_CANCELLED_MESSAGE)); - else pending.resolve(value); + if (cancelled === true) { + // An `info` prompt is the exception, and it is the in-app behaviour that + // makes it one: `GenericInfoDialog` resolves on EVERY close path and has no + // reject path at all, so pressing Escape on it in the app continues the run. + // Escape is the only gesture an info panel affords, so a client that maps it + // to a cancel used to kill a run the same choice would have finished in the + // app (#1605). Closing an info panel is not a cancellation; a client that + // really wants out sends `POST /abort`. + // + // Decided here rather than in RemotePromptProvider.infoDialog because the + // provider cannot tell a per-prompt cancel from a session abort without a + // second error class - and swallowing both would leave /abort unable to end + // a run blocked on an info panel, the one case it exists for. + if (pending.promptType === "info") pending.resolve(value); + else pending.reject(new UserCancelError(PROMPT_CANCELLED_MESSAGE)); + } else pending.resolve(value); return true; } @@ -537,6 +607,15 @@ class InteractivePromptServer { res.end(payload); } + /** Read and discard a request body we have no use for. */ + private async drainBody(req: HttpIncomingMessage): Promise { + let size = 0; + for await (const chunk of req) { + size += (chunk as Buffer).length; + if (size > 1_000_000) throw new Error("Request body too large"); + } + } + private async readBody(req: HttpIncomingMessage): Promise { const chunks: Buffer[] = []; let size = 0; @@ -572,6 +651,29 @@ class InteractivePromptServer { this.handlePoll(session, res); return; } + if (req.method === "POST" && url.pathname === "/abort") { + // Consume the request before answering, like /reply does. /abort takes no + // body, but a client may still send one, and unread bytes left on a + // keep-alive socket are the next request's problem. Node drains an + // unconsumed request itself when the response finishes; doing it here + // makes the route independent of that internal. + await this.drainBody(req); + const interrupted = this.abortSession(session.id); + if (interrupted === null) { + // The run already ended, so nothing was aborted. Saying ok:true would + // tell the client it stopped something it did not. + this.send(res, 409, { + ok: false, + error: "The interactive session has already ended", + }); + return; + } + // `interrupted` lets a client tell an effective abort from a no-op: it is + // 0 when the run was mid-work, or blocked on a prompt QuickAdd opened in + // Obsidian rather than routing here. + this.send(res, 200, { ok: true, interrupted }); + return; + } if (req.method === "POST" && url.pathname === "/reply") { const body = (await this.readBody(req)) as ReplyBody; const outcome = this.submitWireReply(session.id, body); diff --git a/src/interactive/promptProvider.test.ts b/src/interactive/promptProvider.test.ts index a83402fc3..c5ba416d1 100644 --- a/src/interactive/promptProvider.test.ts +++ b/src/interactive/promptProvider.test.ts @@ -198,9 +198,16 @@ describe("RemotePromptProvider suggester marshaling", () => { // --------------------------------------------------------------------------- describe("RemotePromptProvider cancel propagation", () => { - // A client cancel must abort the run exactly like dismissing the Obsidian modal. - // The file's own contract ("returns exactly what its in-app counterpart returns") - // only holds if this is true for EVERY method, so every method is covered. + // An abort reaching the provider must propagate untouched, for EVERY method: the + // file's own contract ("returns exactly what its in-app counterpart returns") only + // holds if none of them swallows one. + // + // This table drives `rejectingServer`, so it pins the PROVIDER's behaviour, not the + // wire's. Which client replies produce a rejection in the first place is decided in + // `submitReply` and covered in interactivePromptServer.test.ts - including the one + // case where they differ, an `info` prompt, whose cancel resolves because the in-app + // dialog cannot abort anything either (#1605). A session abort still rejects here, + // which is why `infoDialog` must keep propagating it. const calls: Array<[string, (p: RemotePromptProvider) => Promise]> = [ ["suggester", (p) => p.suggester(["a"], ["a"])], ["suggesterMulti", (p) => p.suggesterMulti(["a"], ["a"])], @@ -214,7 +221,7 @@ describe("RemotePromptProvider cancel propagation", () => { ]; for (const [name, call] of calls) { - it(`${name} propagates a client cancel as UserCancelError`, async () => { + it(`${name} propagates an abort as UserCancelError`, async () => { const cancelled = promptCancelled(); const provider = new RemotePromptProvider("s", rejectingServer(cancelled)); await expect(call(provider)).rejects.toBe(cancelled); diff --git a/src/interactive/promptProvider.ts b/src/interactive/promptProvider.ts index d4ff9e224..f1a1926df 100644 --- a/src/interactive/promptProvider.ts +++ b/src/interactive/promptProvider.ts @@ -11,15 +11,16 @@ * A dismissal is part of that contract, not an exception to it: a client replies * `{"cancelled": true}` (see `submitReply`), the pending prompt rejects with * `UserCancelError`, and the run aborts exactly as it does when the Obsidian modal - * is dismissed - same class, same message. `promptProvider.test.ts` pins that for - * every method. + * is dismissed - same class, same message. That holds for every prompt except `info` + * (below), and `promptProvider.test.ts` pins the half that lives here: no method + * swallows an abort on its way to the script. * - * One genuine asymmetry, kept deliberately: cancelling an `info` prompt aborts the - * run, while `GenericInfoDialog` in-app has no reject path and can never abort - * anything. Removing it would take away a remote client's only way to bail out - * mid-run, so it stays and is documented at the wire (docs/.../Advanced/CLI.md) - * instead: a client that just wants to close an info panel should send a plain - * reply, not a cancel. + * `info` is the one prompt where a cancel does NOT abort, and that too is parity + * rather than an exception to it: `GenericInfoDialog` resolves on every close path and + * has no reject path at all, so the identical choice run in the app continues past the + * panel. Escape is the only gesture an info panel affords, so a client mapping it to a + * cancel used to kill a run the app would have finished (#1605). A client that really + * wants out sends `POST /abort`, which ends the run whatever it is blocked on. */ import { formatISODate } from "../utils/dateParser"; @@ -276,10 +277,11 @@ export class RemotePromptProvider implements PromptProvider { * * A live client never sees this throw: the same rule is enforced at `/reply` * (`describeReplyProblem`), where a 400 reaches the client while it is still - * holding the response and the prompt stays pending. This is the backstop for - * every other caller of the provider, and the reason it is not the primary check - * is that on the Template/Capture path a thrown message is replaced by a generic - * sentence before the client ever polls for it. + * holding the response and the prompt stays pending. Validating at the wire is what + * makes a malformed reply RECOVERABLE - the client is still awaiting the HTTP + * response and the prompt has not been settled - so it stays the primary check even + * now that a thrown message survives to the client (#1603). This is the backstop for + * every other caller of the provider. * * The other prompt types stay lenient on purpose: `""` and `[]` are answers a * user really can give in-app (the Skip affordances, optional fields), so diff --git a/src/logger/logManager.ts b/src/logger/logManager.ts index 4defe4234..ad44e6ea3 100644 --- a/src/logger/logManager.ts +++ b/src/logger/logManager.ts @@ -1,26 +1,10 @@ import type { ILogger } from "./ilogger"; -/** - * Helper function to convert any value to an Error object - * This function ensures that an Error object is always returned, preserving - * the original Error if provided or creating a new one otherwise. - * - * @param err - The error value to convert (can be any type) - * @returns A proper Error object with stack trace - * - * @example - * ```ts - * try { - * // Some operation - * } catch (err) { - * log.logError(toError(err)); - * } - * ``` - */ -export function toError(err: unknown): Error { - if (err instanceof Error) return err; - return new Error(typeof err === 'string' ? err : String(err)); -} +// There used to be a second `toError` here, a context-less twin of the one in +// `utils/errorUtils`. Its existence is why #1604 happened: the two suggesters +// imported THIS one, so the safe helper's "do NOT mutate the caller's Error" +// contract did not apply to the call sites that most needed it, and they hand-rolled +// the mutation it forbids. One helper now, in `utils/errorUtils`. export class LogManager { public static loggers: ILogger[] = []; diff --git a/src/main.ts b/src/main.ts index 2c465d772..4de4e8ced 100644 --- a/src/main.ts +++ b/src/main.ts @@ -8,7 +8,11 @@ import { log } from "./logger/logManager"; import { ConsoleErrorLogger } from "./logger/consoleErrorLogger"; import { GuiLogger } from "./logger/guiLogger"; import { LogManager } from "./logger/logManager"; -import { reportError, withErrorHandling } from "./utils/errorUtils"; +import { + reportError, + reportUnlessCancelled, + withErrorHandling, +} from "./utils/errorUtils"; import { registerUnhandledRejectionReporter } from "./utils/unhandledRejectionReporter"; import { openQuickAddSettings } from "./utils/openPluginSettings"; import { StartupMacroEngine } from "./engine/StartupMacroEngine"; @@ -421,7 +425,9 @@ export default class QuickAdd extends Plugin { try { await choiceExecutor.execute(choice); } catch (err) { - reportError(err, "Error executing choice from URI"); + // Silent for a dismissal: a URI run that opens a prompt the user escapes is + // not a failure, and this legacy path has no x-cancel target to tell. + reportUnlessCancelled(err, `Could not run "${choice.name}"`); } } @@ -569,11 +575,22 @@ export default class QuickAdd extends Plugin { name: choice.name, icon: resolveChoiceIcon(choice), callback: async () => { + // Resolved outside the try so the failure can name the choice the user + // actually ran; a bare UUID tells them nothing. Falls back to the name + // captured at registration when the lookup itself is what failed. + let current: IChoice | undefined; try { - const current = this.getChoiceById(choiceId); + current = this.getChoiceById(choiceId); await new ChoiceExecutor(this.app, this).execute(current); } catch (err) { - reportError(err, `Error executing choice ${choiceId}`); + // The outermost handler: the last chance to say which choice failed. + // It reports only what nothing below it already reported (#1601), and + // stays silent when the user simply dismissed a prompt - Escape on the + // one-page input modal used to raise a 15-second ERROR notice here. + reportUnlessCancelled( + err, + `Could not run "${current?.name ?? choice.name}"`, + ); } }, }); diff --git a/src/quickAddApi.ts b/src/quickAddApi.ts index 324533ece..ef7ec85ae 100644 --- a/src/quickAddApi.ts +++ b/src/quickAddApi.ts @@ -1038,10 +1038,10 @@ export class QuickAddApi { * inline scripts, main.ts / choiceSuggester at the top), and `reportError` raises a * 15-second Notice - so reporting here too would stack another one. * - * "Already reports" is at least once, not exactly once: on the command-palette macro - * path MacroChoiceEngine reports and rethrows into main.ts, which reports again, so a - * user script error raises TWO notices today. That is pre-existing and tracked - * separately; adding a third here would make it worse, not better. + * "Already reports" is now exactly once: `reportError` drops a value it has already + * shown the user, so the layer with the most specific context wins however many layers + * catch it (#1601). Reporting here would still be the wrong layer - it knows only that + * "a prompt failed", not which script or choice was running. */ function rethrowPromptError(error: unknown): never { if (error instanceof MacroAbortError) { diff --git a/src/types/ChoiceOutcome.ts b/src/types/ChoiceOutcome.ts index 8a7e07df7..b444c2a1a 100644 --- a/src/types/ChoiceOutcome.ts +++ b/src/types/ChoiceOutcome.ts @@ -8,15 +8,17 @@ import type { TFile } from "obsidian"; * * `success` carries the affected file when one is known (Template, Capture). * `cancelled` distinguishes a genuine user prompt-dismissal (`"user"`) from an - * involuntary script/config abort (`"aborted"`). `error` means the choice failed - * (the detailed message is kept in the internal log, never surfaced externally). + * involuntary script/config abort (`"aborted"`). `error` means the choice failed. * - * `reason` carries the abort message for a local, trusted caller (the CLI) to - * surface — e.g. "needs to ask … re-run with the ui flag". The URI x-callback - * handler deliberately ignores it, reporting only `cancelKind`, so no vault detail - * leaks to an external callback URL. + * `reason` carries the message that explains the outcome — the abort reason ("needs + * to ask … re-run with the ui flag") or the failure itself (`Template file not found + * at path "templates/x.md"`). It is for a local, trusted caller: the CLI and the + * interactive bridge, both loopback- and token-gated, surface it, because on those + * paths nobody is looking at the desktop notice that carries the same text (#1603). + * The URI x-callback handler deliberately ignores it on BOTH variants, reporting only + * a fixed code, so no vault detail leaks to an external callback URL. */ export type ChoiceOutcome = | { status: "success"; file?: TFile } - | { status: "error" } + | { status: "error"; reason?: string } | { status: "cancelled"; cancelKind: "user" | "aborted"; reason?: string }; diff --git a/src/utils/errorUtils.test.ts b/src/utils/errorUtils.test.ts index e36371c37..a88d1c2af 100644 --- a/src/utils/errorUtils.test.ts +++ b/src/utils/errorUtils.test.ts @@ -1,6 +1,12 @@ import { afterEach, describe, expect, it, vi } from "vitest"; import { log } from "../logger/logManager"; -import { reportingHandler, toError } from "./errorUtils"; +import { + reportError, + reportUnlessCancelled, + reportingHandler, + toError, +} from "./errorUtils"; +import { promptCancelled } from "../errors/UserCancelError"; describe("toError", () => { it("returns the same Error instance when no context is provided", () => { @@ -137,3 +143,130 @@ describe("reportingHandler", () => { expect(logError).not.toHaveBeenCalled(); }); }); + +/** + * #1601. One user-script failure produced TWO 15-second notices, because + * MacroChoiceEngine reports and re-throws and the command handler reports again. Both + * layers are right to report - neither can know whether anything above it will - so + * report-once lives in the function they both call. + */ +describe("reportError reports each failure once", () => { + const spyOnLogError = () => + vi.spyOn(log, "logError").mockImplementation(() => {}); + + afterEach(() => { + vi.restoreAllMocks(); + }); + + it("reports the same Error instance once, however many layers report it", () => { + const logError = spyOnLogError(); + const failure = new Error("Cannot read properties of undefined"); + + expect(reportError(failure, "Failed to run user script probe.js")).toBe(true); + expect(reportError(failure, "Error executing choice probe-1601")).toBe(false); + + expect(logError).toHaveBeenCalledTimes(1); + // The INNER layer wins: it is the one that knows which script failed. + expect((logError.mock.calls[0][0] as Error).message).toBe( + "Failed to run user script probe.js: Cannot read properties of undefined", + ); + }); + + // Keyed on identity, not text: a loop that fails on 200 notes with the same sentence + // is 200 failures, and each still deserves its own report. + it("reports two distinct failures that happen to read the same", () => { + const logError = spyOnLogError(); + + reportError(new Error("boom"), "ctx"); + reportError(new Error("boom"), "ctx"); + + expect(logError).toHaveBeenCalledTimes(2); + }); + + // Not every layer re-throws the same instance: the AI request path reports the + // provider error and throws a wrapper carrying it as `cause`. + it("suppresses a wrapper whose cause was already reported", () => { + const logError = spyOnLogError(); + const cause = new Error("429 rate limited"); + + reportError(cause); + reportError(new Error("Error while making request to OpenAI", { cause })); + + expect(logError).toHaveBeenCalledTimes(1); + }); + + // Suppression has to EXPIRE. A long-lived user-script module that re-throws one + // cached Error on every invocation would otherwise be reported the first time and + // then be silent forever - a command that does nothing, which is the failure the + // whole reporting seam exists to remove. + it("reports the same instance again on a later, independent run", () => { + const logError = spyOnLogError(); + const cached = new Error("config missing"); + + vi.useFakeTimers({ toFake: ["Date"] }); + try { + vi.setSystemTime(new Date("2026-07-27T12:00:00Z")); + expect(reportError(cached, "first run")).toBe(true); + expect(reportError(cached, "same propagation")).toBe(false); + + // A minute later the user runs the command again. + vi.setSystemTime(new Date("2026-07-27T12:01:00Z")); + expect(reportError(cached, "second run")).toBe(true); + } finally { + vi.useRealTimers(); + } + + expect(logError).toHaveBeenCalledTimes(2); + }); + + it("survives a cyclic cause chain", () => { + spyOnLogError(); + const a = new Error("a") as Error & { cause?: unknown }; + const b = new Error("b") as Error & { cause?: unknown }; + a.cause = b; + b.cause = a; + + expect(() => reportError(a)).not.toThrow(); + }); + + // A WeakSet cannot hold a primitive, and MacroChoiceEngine really is handed whatever + // a user script threw - including a bare string. Those keep the old behaviour rather + // than silently changing it. + it("cannot dedupe a non-object rejection, and says so by reporting twice", () => { + const logError = spyOnLogError(); + + reportError("a script threw a string", "inner"); + reportError("a script threw a string", "outer"); + + expect(logError).toHaveBeenCalledTimes(2); + }); +}); + +/** + * PR #1606's first rule at the outermost handlers: pressing Escape on the one-page input + * modal raised `(ERROR) Error executing choice : One-page input cancelled by user` + * - a 15-second red notice for a deliberate dismissal. + */ +describe("reportUnlessCancelled", () => { + afterEach(() => { + vi.restoreAllMocks(); + }); + + it("stays silent for a dismissal", () => { + const logError = vi.spyOn(log, "logError").mockImplementation(() => {}); + + expect(reportUnlessCancelled(promptCancelled(), "Could not run \"Daily note\"")).toBe( + false, + ); + expect(logError).not.toHaveBeenCalled(); + }); + + it("reports a genuine failure", () => { + const logError = vi.spyOn(log, "logError").mockImplementation(() => {}); + + expect( + reportUnlessCancelled(new Error("Template file not found"), "Could not run it"), + ).toBe(true); + expect(logError).toHaveBeenCalledTimes(1); + }); +}); diff --git a/src/utils/errorUtils.ts b/src/utils/errorUtils.ts index 936b12b23..e3fa0cd31 100644 --- a/src/utils/errorUtils.ts +++ b/src/utils/errorUtils.ts @@ -100,14 +100,73 @@ const LEGACY_CANCELLATION_SENTINELS: ReadonlySet = new Set([ "cancelled", // OnePageInputModal ]); +/** + * When {@link reportError} last showed the user each value. + * + * One failure travelled up through two reporting layers and produced two stacked + * 15-second notices for one bug (#1601): `MacroChoiceEngine` reports a script failure + * AND re-throws it, and the command-palette handler in `main.ts` reports it again. Both + * layers are right to report - neither can know whether anything above it will - so + * "report once" belongs in the function they both call, not in a rule each has to + * remember. + * + * Keyed on the value's IDENTITY, not its message: two independent failures with the + * same text still both report, and the same failure re-thrown through five layers + * reports once. A `WeakMap` so a reported Error is still collectable. + */ +const reportedErrors = new WeakMap(); + +/** + * How long a value stays "already reported". + * + * Suppression has to expire, or a long-lived user-script module that re-throws one + * cached `Error` on every invocation would be reported the first time and then + * silently forever after - a command that does nothing, which is the failure the whole + * reporting seam exists to remove. One propagation unwinds in microseconds, so any + * window comfortably above that collapses the stacked notices while leaving separate + * runs separate. Same value, and the same reasoning, as the unhandled-rejection + * reporter's repeat window. + */ +const REPORT_WINDOW_MS = 10_000; + +/** Bound the `cause` walk; also what stops a cyclic `cause` chain from spinning. */ +const MAX_CAUSE_DEPTH = 8; + +function isTrackable(value: unknown): value is object { + return (typeof value === "object" && value !== null) || typeof value === "function"; +} + +/** + * True if this value, or any error it was wrapped around, has already been reported. + * + * The `cause` chain matters because not every layer re-throws the same instance: the AI + * request path reports the provider error and then throws + * `new Error("Error while making request to …", { cause: error })`, so identity alone + * would let that pair through as two notices for one failed request. + */ +function alreadyReported(err: unknown, at: number): boolean { + let current: unknown = err; + for (let depth = 0; depth < MAX_CAUSE_DEPTH && isTrackable(current); depth++) { + const reportedAt = reportedErrors.get(current); + if (reportedAt !== undefined && at - reportedAt < REPORT_WINDOW_MS) return true; + current = (current as { cause?: unknown }).cause; + } + return false; +} + /** * Reports an error to the logging system with additional context * Converts any error type to a proper Error object and logs it with the appropriate level - * + * + * Reports each failure ONCE: a value already reported (directly, or as the `cause` of one) + * is dropped for {@link REPORT_WINDOW_MS}, so the innermost layer - the one with the most + * specific context - is the one the user sees. See {@link reportedErrors}. + * * @param err - The error to report * @param contextMessage - Optional context message to add * @param level - Error level (defaults to ERROR) - * + * @returns true if this call reported, false if the failure had already been reported + * * @example * ```ts * try { @@ -118,12 +177,18 @@ const LEGACY_CANCELLATION_SENTINELS: ReadonlySet = new Set([ * ``` */ export function reportError( - err: unknown, + err: unknown, contextMessage?: string, level: ErrorLevel = ErrorLevelEnum.Error -): void { +): boolean { + const at = Date.now(); + if (alreadyReported(err, at)) return false; + // Mark the value itself, not the whole chain: the rule is "do not report a failure + // whose cause the user has already seen", not "reporting a wrapper silences its parts". + if (isTrackable(err)) reportedErrors.set(err, at); + const error = toError(err, contextMessage); - + switch (level) { case ErrorLevelEnum.Error: log.logError(error); @@ -138,6 +203,27 @@ export function reportError( // Ensure exhaustiveness log.logError(error); } + return true; +} + +/** + * Reports a failure, staying silent for a dismissal. + * + * The outermost handlers - the command-palette callback, the choice picker - catch + * whatever a run threw, and a user pressing Escape reaches them exactly like a bug does. + * Reporting that as `(ERROR) Error executing choice : One-page input cancelled by + * user` for a deliberate Escape is the failure PR #1606's first rule exists to prevent, + * and it is what those handlers did before this guard. + * + * @returns true if it reported; false for a cancellation or an already-reported failure. + */ +export function reportUnlessCancelled( + err: unknown, + contextMessage?: string, + level: ErrorLevel = ErrorLevelEnum.Error, +): boolean { + if (isCancellationError(err)) return false; + return reportError(err, contextMessage, level); } /** @@ -201,8 +287,7 @@ export function reportingHandler( fn: (...args: A) => unknown, ): (...args: A) => void { const report = (err: unknown): void => { - if (isCancellationError(err)) return; - reportError(err, contextMessage); + reportUnlessCancelled(err, contextMessage); }; return (...args: A): void => { diff --git a/src/utils/unhandledRejectionReporter.test.ts b/src/utils/unhandledRejectionReporter.test.ts index 96eea7df6..077080b94 100644 --- a/src/utils/unhandledRejectionReporter.test.ts +++ b/src/utils/unhandledRejectionReporter.test.ts @@ -3,6 +3,7 @@ import { registerUnhandledRejectionReporter } from "./unhandledRejectionReporter import { ChoiceAbortError } from "../errors/ChoiceAbortError"; import { promptCancelled } from "../errors/UserCancelError"; import { log } from "../logger/logManager"; +import { reportError } from "./errorUtils"; /** * Errors get attributed to QuickAdd by the `plugin:` marker Obsidian puts in a @@ -22,6 +23,41 @@ function foreignError(message: string): Error { return error; } +/** + * A rejection CONSTRUCTED in another plugin's callback but running inside QuickAdd - + * the shape #1602 is about. Measured live: another plugin calling + * `quickadd.api.suggester(v => v.nope.trim(), items)` produces exactly this. + */ +function foreignCallbackInsideQuickAdd(message: string): Error { + const error = new TypeError(message); + error.name = "TypeError"; + error.stack = [ + `TypeError: ${message}`, + " at eval (plugin:probe-foreign:19:43)", + " at eval (plugin:quickadd:88:3004)", + " at Array.map ()", + " at r.suggester (plugin:quickadd:88:2988)", + " at Object.callback (plugin:probe-foreign:19:19)", + " at f3 (app://obsidian.md/app.js:1:2995616)", + ].join("\n"); + return error; +} + +/** + * JavaScriptCore's shape. QuickAdd is `isDesktopOnly: false`, and Obsidian mobile runs + * WKWebView: frames are `fn@url:line:col`, with no `at ` and no `Name: message` header. + * A frame filter keyed on `at ` would leave the whole reporter dead on iOS with every + * desktop-shaped test still green. + */ +function jscError(message: string, site = "doThing", plugin = "quickadd"): Error { + const error = new Error(message); + error.stack = [ + `${site}@plugin:${plugin}:88:3004`, + "forEach@[native code]", + ].join("\n"); + return error; +} + describe("unhandled rejection reporter (#1576)", () => { let listener: ((event: PromiseRejectionEvent) => void) | null = null; let logError: ReturnType; @@ -181,6 +217,96 @@ describe("unhandled rejection reporter (#1576)", () => { expect(logError).not.toHaveBeenCalled(); }); + // `Error.stack` is captured at construction with the WHOLE live call stack, so "any + // frame is ours" claimed a foreign caller's bug the moment it ran through QuickAdd - + // and preventDefault() took away the console line naming the real culprit (#1602). + it("does not claim a foreign callback's bug that merely ran inside QuickAdd", () => { + const { defaultPrevented } = fire( + foreignCallbackInsideQuickAdd("Cannot read properties of undefined"), + ); + + expect(defaultPrevented).toBe(false); + expect(logError).not.toHaveBeenCalled(); + }); + + // The mirror: OUR bug, called into by another plugin. The construction frame is ours, + // so it is still reported even though a foreign frame sits below it. + it("still claims a QuickAdd bug reached through another plugin", () => { + const error = new Error("Choice not found"); + error.stack = [ + "Error: Choice not found", + " at mS.getChoiceByName (plugin:quickadd:414:30553)", + " at Object.callback (plugin:probe-foreign:19:19)", + ].join("\n"); + + fire(error); + + expect(logError).toHaveBeenCalledTimes(1); + }); + + // An eval'd frame names the bundle as an ORIGIN, with no :line:col - which is how a + // user script's own code and a dataviewjs snippet appear. Requiring a position would + // skip straight past them to the QuickAdd frame underneath and mis-claim the bug. + it("attributes an eval'd frame to the bundle that evaluated it", () => { + const error = new TypeError("x.nope is not a function"); + error.name = "TypeError"; + error.stack = [ + "TypeError: x.nope is not a function", + " at eval (eval at (plugin:dataview), :3:47)", + " at r.suggester (plugin:quickadd:88:2988)", + ].join("\n"); + + const { defaultPrevented } = fire(error); + + expect(defaultPrevented).toBe(false); + expect(logError).not.toHaveBeenCalled(); + }); + + // A message is part of `stack` on V8, so without stripping the header an Error could + // name a plugin in its own text and dictate who gets blamed. + it("ignores a plugin name that appears only in the message", () => { + const error = new Error("could not reach plugin:some-other-plugin:1:1"); + error.stack = [ + "Error: could not reach plugin:some-other-plugin:1:1", + " at mS.fetchThing (plugin:quickadd:414:30553)", + ].join("\n"); + + fire(error); + + expect(logError).toHaveBeenCalledTimes(1); + }); + + // Obsidian mobile is JavaScriptCore. QuickAdd ships there (isDesktopOnly: false), so + // attribution must not assume V8's ` at fn (url)` frame syntax. + it("attributes a JavaScriptCore stack, which has no `at ` frames", () => { + fire(jscError("mobile bug")); + + expect(logError).toHaveBeenCalledTimes(1); + }); + + it("leaves another plugin alone on a JavaScriptCore stack too", () => { + const { defaultPrevented } = fire( + jscError("not ours", "theirThing", "some-other-plugin"), + ); + + expect(defaultPrevented).toBe(false); + expect(logError).not.toHaveBeenCalled(); + }); + + // #1601: reportError drops a failure a lower layer already showed the user. Claiming + // the event anyway would take the console's async trace away and put nothing in its + // place - strictly less evidence than before this reporter existed. + it("leaves the browser default alone when the failure was already reported", () => { + const error = pluginError("reported downstream"); + reportError(error, "an inner layer"); + logError.mockClear(); + + const { defaultPrevented } = fire(error); + + expect(logError).not.toHaveBeenCalled(); + expect(defaultPrevented).toBe(false); + }); + it("does not let one noisy failure mask a different one", () => { fire(pluginError("first", "siteA")); fire(pluginError("second", "siteB")); diff --git a/src/utils/unhandledRejectionReporter.ts b/src/utils/unhandledRejectionReporter.ts index 0537d8347..5b05909db 100644 --- a/src/utils/unhandledRejectionReporter.ts +++ b/src/utils/unhandledRejectionReporter.ts @@ -37,38 +37,78 @@ export interface UnhandledRejectionReporterHost { } /** - * Dedupe on the throw SITE, not the message. + * Obsidian evaluates a plugin's `main.js` with a `sourceURL` of `plugin:`, so a + * frame inside a plugin bundle names it: `at mS.getChoiceByName (plugin:quickadd:414:30553)` + * on desktop, `getChoiceByName@plugin:quickadd:414:30553` on iOS. * - * A message often embeds a varying value ("Could not read note "), so keying on it - * would let one broken loop over 500 notes raise 500 notices. The first `plugin:` - * frame is where the Error was constructed, so the same bug collapses to one report - * however many values it fails on, while two genuinely different bugs stay distinct. + * The id is read WITHOUT requiring a trailing `::`, because an eval'd frame + * carries the bundle as an origin with no position - `at module.exports (eval at + * exports.load (plugin:quickadd), :3:47)` is how a user script's own code + * appears, and `eval at (plugin:dataview)` is how a dataviewjs snippet does. + * Those are exactly the frames attribution must not skip past. The character class stops + * at `:` and `)`, so `plugin:quickadd-beta:1:1` still reads as `quickadd-beta` and is not + * confused with `quickadd`. + */ +const PLUGIN_FRAME = /plugin:([^\s:)]+)/; + +/** + * The frames of a stack, with the `Name: message` header removed. + * + * V8 puts the message INSIDE `stack`, so an Error whose message happens to contain + * `plugin:some-plugin:1:1` could otherwise dictate attribution. Stripping the exact + * `${name}: ${message}` prefix is engine-agnostic in a way a `/^\s*at /` filter is not: + * QuickAdd is `isDesktopOnly: false` and Obsidian mobile runs JavaScriptCore, whose + * frames are `fn@url:line:col` with no `at ` and no header line at all - so filtering on + * `at ` would silently turn this whole reporter into dead code on iOS and iPadOS. + */ +function stackFrames(error: Error): string[] { + const stack = error.stack ?? ""; + const header = `${error.name}: ${error.message}`; + const body = stack.startsWith(header) ? stack.slice(header.length) : stack; + return body.split("\n"); +} + +/** + * The topmost frame that names a plugin bundle: the one closest to where the Error was + * constructed, and therefore the one that decides whose bug this is. Null when no frame + * names a plugin at all. + * + * `Error.stack` is captured at construction with the whole live call stack, so the old + * rule - "does ANY frame name us" - claimed other people's bugs: another plugin calling + * `quickadd.api.suggester(v => v.nope.trim(), items)` builds its TypeError inside its own + * callback, with QuickAdd frames underneath, and QuickAdd would raise "A QuickAdd action + * failed" for it AND `preventDefault()` away the console line naming the real culprit + * (#1602). + * + * Measured, so the cost of the stricter rule is known rather than assumed: an Error + * constructed inside Obsidian's own async plumbing (`vault.create` into a missing folder, + * awaited from a plugin) carries NO plugin frame at all - not even the caller's - so the + * old rule was never catching that class either. It stays unclaimed, as before. What the + * old rule caught and this does not is precisely a foreign frame above ours, which is the + * false positive. A non-Error rejection (a bare string has no stack) is likewise left + * alone: with nothing to attribute it to, reporting it would be a guess. */ -function dedupeKey(error: Error, pluginId: string): string { - const frame = (error.stack ?? "") - .split("\n") - .find((line) => line.includes(`plugin:${pluginId}:`)); - return `${error.name}@${frame?.trim() ?? error.message}`; +function attributingFrame( + error: Error, +): { pluginId: string; frame: string } | null { + for (const line of stackFrames(error)) { + const match = PLUGIN_FRAME.exec(line); + if (match) return { pluginId: match[1], frame: line.trim() }; + } + return null; } /** - * True only when the rejection demonstrably came from QuickAdd's own bundle. + * Dedupe on the throw SITE, not the message. * - * Obsidian evaluates a plugin's `main.js` with a `sourceURL` of `plugin:`, so any - * Error constructed inside QuickAdd carries frames like - * `at mS.getChoiceByName (plugin:quickadd:414:30553)`. Requiring that keeps QuickAdd from - * claiming another plugin's bug, and is why a non-Error rejection (a bare string has no - * stack) is left alone: with nothing to attribute it to, reporting it would be a guess. + * A message often embeds a varying value ("Could not read note "), so keying on it + * would let one broken loop over 500 notes raise 500 notices. The attributing frame is + * where the Error was constructed, so the same bug collapses to one report however many + * values it fails on, while two genuinely different bugs stay distinct. The frame is + * passed in, not re-derived: nothing reaches this point without one. */ -function isFromPlugin(reason: unknown, pluginId: string): boolean { - return ( - reason instanceof Error && - typeof reason.stack === "string" && - // Trailing colon: the frame is `plugin:::`, so an undelimited - // match would claim `plugin:quickadd-beta` - a fork's or beta's rejections, - // whose only console line we would then suppress on their behalf. - reason.stack.includes(`plugin:${pluginId}:`) - ); +function dedupeKey(error: Error, frame: string): string { + return `${error.name}@${frame}`; } export function registerUnhandledRejectionReporter( @@ -85,7 +125,9 @@ export function registerUnhandledRejectionReporter( plugin.registerDomEvent(window, "unhandledrejection", (event) => { const reason = event.reason; - if (!isFromPlugin(reason, pluginId)) return; + const attribution = + reason instanceof Error ? attributingFrame(reason) : null; + if (attribution?.pluginId !== pluginId) return; // A dismissed prompt is not a failure. It reaches here when a handler floats a // prompt (e.g. the macro editor's script picker), and telling the user "an @@ -106,7 +148,7 @@ export function registerUnhandledRejectionReporter( } const error = reason as Error; - const key = dedupeKey(error, pluginId); + const key = dedupeKey(error, attribution.frame); const at = now(); const last = recentlySeen.get(key); // Stamp every OCCURRENCE, not every report. Stamping only on report restarts @@ -134,7 +176,13 @@ export function registerUnhandledRejectionReporter( } } - event.preventDefault(); - reportError(error, "A QuickAdd action failed"); + // Claim the event only if a notice actually went out. `reportError` now returns + // false when the same failure was already reported by a layer that also re-threw + // it (#1601); calling preventDefault first would kill the browser's async trace + // and put nothing in its place - the opposite of the guarantee the repeat-window + // branch above keeps. + if (reportError(error, "A QuickAdd action failed")) { + event.preventDefault(); + } }); } diff --git a/src/utils/userScript.ts b/src/utils/userScript.ts index 6ea693976..87aee7454 100644 --- a/src/utils/userScript.ts +++ b/src/utils/userScript.ts @@ -4,6 +4,7 @@ import { MARKDOWN_FILE_EXTENSION_REGEX } from "../constants"; import { log } from "../logger/logManager"; import type { IUserScript } from "../types/macros/IUserScript"; import { extractScriptFromMarkdown } from "./extractScriptFromMarkdown"; +import { reportError } from "./errorUtils"; type GetUserScriptOptions = { reportLoadErrors?: boolean; @@ -45,7 +46,11 @@ function reportAndThrowUserScriptLoadError( ): never { const error = new UserScriptLoadError(message); if (options.reportLoadErrors !== false) { - log.logError(error); + // reportError, not log.logError: this error is thrown straight past + // MacroChoiceEngine's own reporting catch and lands in the command-palette + // handler, which reported it a second time - two stacked 15-second notices with + // the same 300-character message for one typo'd require (#1601). + reportError(error); } throw error;