diff --git a/src/deployment/default/logging.ts b/src/deployment/default/logging.ts index 8c7853e89..115d78ffe 100644 --- a/src/deployment/default/logging.ts +++ b/src/deployment/default/logging.ts @@ -14,8 +14,12 @@ export class ConsoleLogging implements Logging { event(event: Event): void { console.log(event); } - error(message: string, e: unknown): void { - console.error(message, e); + error(message: string, e: unknown, context?: Record): void { + if (context) { + console.error(message, e, context); + } else { + console.error(message, e); + } } log(e: any): void { console.log(e); diff --git a/src/editor/codemirror/CodeMirror.tsx b/src/editor/codemirror/CodeMirror.tsx index b3c6c2e3c..abdf89bdb 100644 --- a/src/editor/codemirror/CodeMirror.tsx +++ b/src/editor/codemirror/CodeMirror.tsx @@ -40,6 +40,7 @@ import { languageServer } from "./language-server/view"; import { lintGutter } from "./lint/lint"; import { codeStructure } from "./structure-highlighting"; import themeExtensions from "./themeExtensions"; +import { ViewErrorReporting } from "./view-error-reporting"; import { useDevice } from "../../device/device-hooks"; interface CodeMirrorProps { @@ -120,10 +121,12 @@ const CodeMirror = ({ logPastedLineCount(logging, update); } }); + const errorReporting = new ViewErrorReporting(logging); const state = EditorState.create({ doc: defaultValue, extensions: [ notify, + errorReporting.extension(), editorConfig, // Extension requires external state. dndSupport({ sessionSettings, setSessionSettings }), @@ -164,6 +167,7 @@ const CodeMirror = ({ const view = new EditorView({ state, parent: elementRef.current!, + dispatchTransactions: errorReporting.dispatchTransactions, }); viewRef.current = view; diff --git a/src/editor/codemirror/view-error-reporting.test.ts b/src/editor/codemirror/view-error-reporting.test.ts new file mode 100644 index 000000000..057ebeeef --- /dev/null +++ b/src/editor/codemirror/view-error-reporting.test.ts @@ -0,0 +1,134 @@ +/** + * (c) 2026, Micro:bit Educational Foundation and contributors + * + * SPDX-License-Identifier: MIT + */ +import { EditorState } from "@codemirror/state"; +import { Decoration, EditorView, ViewPlugin } from "@codemirror/view"; +import { afterEach, beforeEach, describe, expect, it } from "vitest"; +import { MockLogging } from "../../logging/mock"; +import { ViewErrorReporting } from "./view-error-reporting"; + +let failRedraw: Error | undefined; +let failPlugin: Error | undefined; + +// Evaluated inside EditorView.update after the state has been applied, so +// throwing here leaves the view out of step, like the tile bugs do. +const explosiveDecorations = EditorView.decorations.of(() => { + if (failRedraw) { + throw failRedraw; + } + return Decoration.none; +}); + +// Plugin update errors are caught by CodeMirror and sent to the exception sink. +const explosivePlugin = ViewPlugin.define(() => ({ + update() { + if (failPlugin) { + throw failPlugin; + } + }, +})); + +describe("ViewErrorReporting", () => { + let logging: MockLogging; + let view: EditorView; + + beforeEach(() => { + failRedraw = undefined; + failPlugin = undefined; + logging = new MockLogging(); + const reporting = new ViewErrorReporting(logging); + view = new EditorView({ + state: EditorState.create({ + doc: "abc", + extensions: [ + reporting.extension(), + explosiveDecorations, + explosivePlugin, + ], + }), + parent: document.body, + dispatchTransactions: reporting.dispatchTransactions, + }); + }); + + afterEach(() => { + view.destroy(); + }); + + it("reports an update failure with context instead of rethrowing", () => { + failRedraw = new Error("Right side of assignment cannot be destructured"); + + expect(() => + view.dispatch({ + changes: { from: 0, insert: "x" }, + userEvent: "input.type", + }) + ).not.toThrow(); + + expect(view.state.doc.toString()).toEqual("xabc"); + expect(logging.errors).toHaveLength(1); + const { message, e, context } = logging.errors[0]; + expect(message).toEqual("CodeMirror update failed"); + expect(e).toBe(failRedraw); + expect(context).toMatchObject({ + phase: "update", + stateAdvanced: true, + startDocLength: 3, + docLength: 4, + userEvents: "input.type", + changes: "0-0+1", + effects: 0, + }); + expect(context).toHaveProperty("tileLength"); + expect(context).toHaveProperty("composing", false); + }); + + it("reports exceptions CodeMirror catches itself", () => { + failPlugin = new Error("plugin crashed"); + + view.dispatch({ selection: { anchor: 1 } }); + + expect(logging.errors).toHaveLength(1); + expect(logging.errors[0]).toMatchObject({ + message: "CodeMirror logged exception", + e: failPlugin, + }); + expect(logging.errors[0].context).toMatchObject({ + phase: "logged", + docLength: 3, + selectionHead: 1, + }); + }); + + it("includes recent input events without typed characters", () => { + view.contentDOM.dispatchEvent( + new Event("compositionstart", { bubbles: true }) + ); + view.contentDOM.dispatchEvent( + new KeyboardEvent("keydown", { key: "a", bubbles: true }) + ); + view.contentDOM.dispatchEvent( + new KeyboardEvent("keydown", { key: "Backspace", bubbles: true }) + ); + view.contentDOM.dispatchEvent( + new KeyboardEvent("keydown", { key: "\u{1F600}", bubbles: true }) + ); + view.contentDOM.dispatchEvent( + new KeyboardEvent("keydown", { key: "A", bubbles: true }) + ); + failPlugin = new Error("plugin crashed"); + view.dispatch({ selection: { anchor: 1 } }); + + const recentInput = logging.errors[0].context?.recentInput as string; + expect(recentInput).toMatch(/compositionstart-\d+ms/); + expect(recentInput).toMatch(/keydown:char-\d+ms/); + expect(recentInput).toMatch(/keydown:Backspace-\d+ms/); + expect(recentInput).not.toContain("keydown:a"); + expect(recentInput).not.toContain("\u{1F600}"); + expect(recentInput).not.toContain("keydown:A"); + expect(recentInput.match(/keydown:char/g)).toHaveLength(3); + expect(logging.errors[0].context).not.toHaveProperty("language"); + }); +}); diff --git a/src/editor/codemirror/view-error-reporting.ts b/src/editor/codemirror/view-error-reporting.ts new file mode 100644 index 000000000..5b0be43be --- /dev/null +++ b/src/editor/codemirror/view-error-reporting.ts @@ -0,0 +1,155 @@ +/** + * (c) 2026, Micro:bit Educational Foundation and contributors + * + * SPDX-License-Identifier: MIT + */ +import { Extension, Transaction } from "@codemirror/state"; +import { EditorView, ViewPlugin } from "@codemirror/view"; +import { Logging } from "../../logging/logging"; + +const recentInputSize = 20; + +/** + * Reports failures inside CodeMirror's view with the context needed to + * chase them upstream (see #1317). + * + * EditorView.update applies the new state before it redraws and does not + * roll back if the redraw throws, so one exception leaves the view out of + * step with the document and every later keystroke, click and measure + * throws too. Sentry then sees hundreds of follow-ups that all look alike. + * Reporting here attaches what distinguishes the first failure: the + * transaction, document versus tile-tree length, composition state and the + * preceding input events. + * + * One instance per editor. Put `extension()` in the state and pass + * `dispatchTransactions` to the EditorView constructor. + */ +export class ViewErrorReporting { + private view: EditorView | null = null; + private recentInput: Array<{ kind: string; time: number }> = []; + + constructor(private logging: Logging) {} + + extension(): Extension { + return [ + ViewPlugin.define((view) => { + this.view = view; + return { + destroy: () => { + if (this.view === view) { + this.view = null; + } + }, + }; + }), + // Exceptions CodeMirror catches itself (plugin crashes, measure reads) + // would otherwise go straight to window.onerror without context. + EditorView.exceptionSink.of((e) => { + this.logging.error( + "CodeMirror logged exception", + e, + this.view + ? this.context(this.view, { phase: "logged" }) + : { phase: "logged" } + ); + }), + EditorView.domEventObservers({ + compositionstart: () => this.noteInput("compositionstart"), + compositionend: () => this.noteInput("compositionend"), + beforeinput: (e) => this.noteInput("beforeinput:" + e.inputType), + // Named keys only (Backspace, ArrowLeft, Dead, Process...): at least + // two characters, so a shifted capital never matches, and no astral + // character either. Everything else is reported as "char" so no + // typed text leaves the browser. + keydown: (e) => + this.noteInput( + "keydown:" + (/^[A-Z][A-Za-z0-9]+$/.test(e.key) ? e.key : "char") + ), + mousedown: () => this.noteInput("mousedown"), + }), + ]; + } + + /** + * Exceptions are reported once, with context, rather than rethrown to + * the caller of dispatch (which would report them again via onerror). + */ + dispatchTransactions = ( + trs: readonly Transaction[], + view: EditorView + ): void => { + try { + view.update(trs); + } catch (e) { + const startState = trs.length > 0 ? trs[0].startState : undefined; + this.logging.error( + "CodeMirror update failed", + e, + this.context(view, { + phase: "update", + // The state is applied before the redraw; if it moved on, the + // view is now inconsistent with the document. + stateAdvanced: startState !== undefined && view.state !== startState, + startDocLength: startState?.doc.length, + userEvents: trs + .map((tr) => tr.annotation(Transaction.userEvent) ?? "-") + .join(","), + changes: describeChanges(trs), + effects: trs.reduce((n, tr) => n + tr.effects.length, 0), + }) + ); + } + }; + + private noteInput(kind: string) { + this.recentInput.push({ kind, time: Date.now() }); + if (this.recentInput.length > recentInputSize) { + this.recentInput.shift(); + } + } + + private context( + view: EditorView, + extra: Record + ): Record { + const now = Date.now(); + const state = view.state; + const selection = state.selection.main; + // docView is internal to CodeMirror. Its tile length versus the + // document length is the most direct evidence of an out-of-step view, + // so read it defensively. + const internal = view as unknown as { + docView?: { tile?: { length?: number } }; + }; + return { + docLength: state.doc.length, + docLines: state.doc.lines, + tileLength: internal.docView?.tile?.length, + viewportFrom: view.viewport.from, + viewportTo: view.viewport.to, + selectionAnchor: selection.anchor, + selectionHead: selection.head, + composing: view.composing, + compositionStarted: view.compositionStarted, + recentInput: this.recentInput + .map((r) => `${r.kind}-${now - r.time}ms`) + .join(" "), + ...extra, + }; + } +} + +/** + * Positions and lengths only; document text must not be reported. + */ +const describeChanges = (trs: readonly Transaction[]): string => { + const parts: string[] = []; + for (const tr of trs) { + tr.changes.iterChanges((fromA, toA, _fromB, _toB, inserted) => { + if (parts.length < 10) { + parts.push(`${fromA}-${toA}+${inserted.length}`); + } + }); + } + return parts.join(" "); +}; diff --git a/src/logging/logger.ts b/src/logging/logger.ts index 353fa692d..ef12c5f4c 100644 --- a/src/logging/logger.ts +++ b/src/logging/logger.ts @@ -42,8 +42,8 @@ export class Logger implements Logging { this.sink.setUserProperty(name, value); } - error(message: string, e: unknown): void { - reportError(this.sentryDsn, message, e); + error(message: string, e: unknown, context?: Record): void { + reportError(this.sentryDsn, message, e, context); } log(v: unknown): void { diff --git a/src/logging/logging.ts b/src/logging/logging.ts index c208c29ca..3970cab50 100644 --- a/src/logging/logging.ts +++ b/src/logging/logging.ts @@ -12,7 +12,11 @@ export interface Event { export interface Logging { event(event: Event): void; - error(message: string, e: unknown): void; + /** + * Report an error. `context` is attached to the Sentry event as extra + * data; keep it to primitives and never include document text. + */ + error(message: string, e: unknown, context?: Record): void; log(e: any): void; /** * Set a GA4 user property — auto-attaches to every subsequent event diff --git a/src/logging/mock.ts b/src/logging/mock.ts index 2bae8d35f..4352b8581 100644 --- a/src/logging/mock.ts +++ b/src/logging/mock.ts @@ -7,15 +7,19 @@ import { Event, Logging } from "./logging"; export class MockLogging implements Logging { events: Event[] = []; - errors: Array<{ message: string; e: unknown }> = []; + errors: Array<{ + message: string; + e: unknown; + context?: Record; + }> = []; logs: any[] = []; userProperties: Record = {}; event(event: Event): void { this.events.push(event); } - error(message: string, e: unknown): void { - this.errors.push({ message, e }); + error(message: string, e: unknown, context?: Record): void { + this.errors.push({ message, e, context }); } log(e: any): void { this.logs.push(e); diff --git a/src/logging/sentry.ts b/src/logging/sentry.ts index 615a0091a..7eac0a08a 100644 --- a/src/logging/sentry.ts +++ b/src/logging/sentry.ts @@ -44,9 +44,14 @@ export const initSentry = (env: Record): string | undefined => { export const reportError = ( dsn: string | undefined, message: string, - e: unknown + e: unknown, + context?: Record ): void => { - console.error(message, e); + if (context) { + console.error(message, e, context); + } else { + console.error(message, e); + } if (!dsn) { return; } @@ -56,7 +61,7 @@ export const reportError = ( type: "error-message", level: "error", }); - sentryCaptureException(e); + sentryCaptureException(e, context ? { extra: context } : undefined); } catch (err) { console.error(err); }