--- title: Interaction trace (slow-click, jank, and navigation latency log) --- # Interaction trace (slow-click, jank, and navigation latency log) ## What it is A dedicated log file — `interaction.log` — that captures every slow interaction (click, keypress, tap) and rendering-thread stall that happens while Omniscio is open, in one continuous self-contained timeline. It exists so a user reporting "clicks feel laggy" or "the UI freezes for a second when I switch sessions" can attach exactly **one** file to a bug report, and any agent (or outside AI like ChatGPT) reading that pasted file can immediately tell which interactions were slow and where the time was spent — without seeing the rest of the codebase. The file lives next to the regular logs: - **Windows**: `%APPDATA%/omniscio/logs/interaction.log` - **macOS**: `~/Library/Application Support/omniscio/logs/interaction.log` - **Linux**: `~/.config/omniscio/logs/interaction.log` Unlike `startup.log` (which rotates per-launch), `interaction.log` is a **continuous tape across launches** — the same file keeps growing every time you open the app, capped at **1 MB**. When it reaches the cap, it rotates to `interaction.log.1` → … → `interaction.log.5` (oldest dropped). This is intentional: a "lag that only shows up sometimes" needs a tape that spans days, not a fresh file each launch. It is **separate from `main.log`** on purpose: `main.log` is a rolling firehose of every log line during runtime; `interaction.log` is a focused timeline of just the perf-sensitive events, with a TOP 10 worst-offenders summary at the bottom so even a non-technical reader can see the pattern. ## Where to find it The file sits in your Omniscio logs folder, next to the other logs — on Windows under `%APPDATA%/omniscio/logs/interaction.log`, on macOS under `~/Library/Application Support/omniscio/logs/`, and on Linux under `~/.config/omniscio/logs/`. There is no in-app viewer; you open it, or attach it to a bug report. ## How it behaves ### How to use it ### To attach it to a bug report 1. Open **Settings → Diagnostics**. You'll see a card titled **Interaction Trace** with a single button: **Reveal Interaction Log**. 2. Click it. Omniscio flushes a fresh TOP 10 summary block, then opens your file manager with `interaction.log` highlighted. 3. Drag the file into the bug report (or paste its contents into a chat). The file is plain text, opens in any editor. The very top has a self-describing header so an LLM reading a pasted copy with no other context understands what each section means. ### What you'll see in the file ``` ═══════════════════════════════════════════════════════════════ Omniscio INTERACTION TRACE …self-describing header (purpose, Version, Electron, Mode, PID)… ═══════════════════════════════════════════════════════════════ ── Launch resumed at 2026-05-18T15:42:11.123Z (PID 12345) ── 2026-05-18T15:42:14.901Z [event] name=click duration=423ms inputDelay=32ms processing=280ms target=button.send iid=7 2026-05-18T15:42:15.044Z [loaf] duration=240ms blocking=180ms scripts=3 slowest=120ms at DOMWebSocket.onmessage 2026-05-18T15:42:18.221Z [phased-nav] activation=7 total=850ms session=sess-abc nav-to-mount 12ms mount-to-fetch 4ms fetch 380ms build-turns 18ms commit-to-paint 436ms … ──────────────────────────────────────────────── SUMMARY (flushed at 2026-05-18T16:01:33.444Z) ──────────────────────────────────────────────── TOP 10 SLOWEST INTERACTIONS 1. click 423ms (input=32ms processing=280ms) target=button.send at=2026-05-18T15:42:14.901Z 2. keypress 308ms (input=18ms processing=210ms) target=textarea#composer at=2026-05-18T15:43:02.118Z … TOP 10 LONG ANIMATION FRAMES 1. 240ms blocking=180ms scripts=3 slowest=120ms at DOMWebSocket.onmessage at=… … TOP 10 PHASED-NAV 1. activation=7 850ms session=sess-abc at=2026-05-18T15:42:18.221Z nav-to-mount 12ms mount-to-fetch 4ms fetch 380ms build-turns 18ms commit-to-paint 436ms … ``` The **TOP 10 sections** are the most useful for triage — they sort by duration so you can immediately see the worst offenders without scanning the whole tape. Phased-nav entries break down a single session cold-mount into five named phases — `nav-to-mount → mount-to-fetch → fetch → build-turns → commit-to-paint` — so you can see _where_ the time went between the user clicking a session and the first paint. ### How to read each line - `[event]` — a click / tap / keypress that took longer than **200 ms** end-to-end. `inputDelay` is wall-clock time from event hit to JS handler start; `processing` is the synchronous JS work the handler did. `target` is a short CSS-selector-ish description of the element. `iid` is the browser's interaction id (groups multiple events from one logical interaction). - `[loaf]` — a "long animation frame" (>100 ms of render-thread time). `blocking` is time the main thread couldn't yield to input. `scripts` is how many JS callbacks ran in that frame. `slowest` names the worst single callback, formatted `ms at ` — **the separator is ` at `, never `@`** (a `@` joins into an email-shaped string that the log scrubber rewrites to `[EMAIL_REDACTED]`, destroying the one field that says what blocked the frame; guarded by `loaf-attribution-avoids-email-shape.test.ts`). Burst protection coalesces multiple LoAFs in the same 1-second window into a single entry with a `coalesced=N` suffix. - `[phased-nav]` — a session/route switch broken down into named phases (currently click-to-state-set → state-set-to-mount → mount-to-first-message). These are emitted explicitly by the navigation code rather than auto-detected, so they are the ground truth for "where did the second go." ### When the window stops painting — the `[present-stall]` lines (in `renderer-diag.log`) Sometimes the window freezes although nothing above looks slow: the keystrokes show `inputDelay` and `processing` near 0, and the `[loaf]` line reads `blocking=0ms scripts=0`. That is a **presentation stall** — the app handled the input, but the finished frame did not reach the screen. A small probe watches for exactly this and writes to `renderer-diag.log`, in the same folder: - `[present-stall]` — one line per stall you could feel: after a text edit or a click, the next frame was still missing half a second later. It carries `late` (how late the frame was), `input` (`text` or `pointer`), `verdict`, then the readings taken at both ends of the stall: `gpuCpu` (the graphics process's CPU time, and its share of one core), `gpuFaults` (its page faults), `gpuWs` (its memory in use), `gpuIo` / `gpuPage` (its current disk and memory priority), `kernel` (the share of all CPU time the machine spent inside Windows itself), `dwm` (`alive` when the Windows desktop compositor drew during the stall; `quiet` is ambiguous, because it only draws when something on screen changes), `window` and `beginLag` (how much of the stall was measured), `live` (running sessions), `episode`, and `dropped` (stalls skipped by the six-a-minute cap). - The verdict: `gpu-busy` — the graphics process worked hard through the stall; `gpu-blocked` — it barely ran while the machine was in a kernel storm, so the machine starved it; `gpu-idle` — it barely ran on a calm machine, so nothing asked it to draw; `inconclusive` — a `reason=` says why (a reading failed, the window went hidden, the stall never ended). A value that could not be read is written `n/a`, never 0. - `[present-stall-count]` — at most once a minute, and only for a minute in which you typed or clicked: `composerKeys` (characters typed into a message box), `otherInputs`, and `late` (late frames). A log with count lines and no stall lines means "watched, and nothing stalled"; no count line at all means nobody was typing. The probe runs only in the main desktop window, and only while Settings → Diagnostics → "Performance & interaction tracing" is on. It reads nothing until a frame is already late, and every reading happens off the app's main thread. It sees frames whose drawing started late; a frame drawn on time but shown late is not caught. ### How it works Two parts: the renderer observer that detects slow events, and the main-process recorder that writes them to disk. ### Renderer (observer) Lives in [/src/renderer/src/lib/interaction-trace.ts](/src/renderer/src/lib/interaction-trace.ts). The `useRendererDiagnostics` hook ([/src/renderer/src/app/useRendererDiagnostics.ts](/src/renderer/src/app/useRendererDiagnostics.ts)) — called once from [/src/renderer/src/App.tsx](/src/renderer/src/App.tsx) at boot — runs an effect that calls `installInteractionObserver({ reporter })`: - Wraps two `PerformanceObserver` streams: - `event` (Event Timing API, Chrome 85+) — fires for every event whose `duration` ≥ 200 ms. - `long-animation-frame` (LoAF API, Chrome 123+) — fires for every animation frame whose duration ≥ 100 ms. - Coalesces LoAF bursts in a 1-second window (`setTimeout` flush) so a misbehaving render loop can't flood the log. - Caps every user-derived string at 200 chars before forwarding (DoS protection — a giant `aria-label` on a slow button can't blow the IPC budget). - Returns a `{ stop, reportPhasedNav }` handle. The `reportPhasedNav` shim is also exposed at module-level via [/src/renderer/src/lib/phased-nav-reporter.ts](/src/renderer/src/lib/phased-nav-reporter.ts) so navigation code can fire phased-nav events without prop-drilling. Each detected entry goes through `ipc.invoke(IPC.RENDERER_DIAG_REPORT, payload)` — the same channel the existing longtask/snapshot diagnostics use. The Zod schema is a discriminated union so every payload shape (`longtask` / `snapshot` / `interaction-event` / `long-anim-frame` / `phased-nav`, plus freeze attribution and the two presentation-stall reports) stays independently validatable. **Kill switch**: set `AMC_DISABLE_INTERACTION_TRACE=1` in the environment before launch and the observer never installs (returns a no-op handle). The reveal button still works — it'll just open whatever file is on disk. ### Main process (recorder) Lives in [/src/main/services/diagnostics/interaction-trace.ts](/src/main/services/diagnostics/interaction-trace.ts). Initialized once from [/src/main/index.ts](/src/main/index.ts) immediately after `initStartupTrace()`: - `initInteractionTrace()` — opens `interaction.log`. If the existing file is already over 1 MB, rotates it first; otherwise appends a `── Launch resumed at … ──` marker and continues writing. - `recordInteractionEvent` / `recordLongAnimFrame` / `recordPhasedNav` — three append helpers, each also maintaining a rolling in-memory **TOP 10** sorted by duration. Per-record format is one line per entry; phased-nav writes its line plus an indented breakdown per phase. - `flushInteractionSummary()` — appends a fresh `SUMMARY (flushed at …)` block with all three TOP 10 sections. Called from two sites: (a) `gracefulShutdown()` in `index.ts` so the final file always ends with an up-to-date summary, and (b) the reveal handler itself, so clicking the button always reveals a file with current data even if the user has been running for hours. All disk writes are wrapped in try/catch — a failed `appendFileSync` must never disrupt the renderer or the IPC handler. If the log directory can't be created, the recorder silently no-ops. The IPC wiring is in [/src/main/ipc/diagnostic-handlers.ts](/src/main/ipc/diagnostic-handlers.ts): - `RENDERER_DIAG_REPORT` — routes by `payload.type`: `longtask`, `freeze-attribution` and `snapshot` become lines in the non-blocking `renderer-diag.log` (buffered and flushed off the main thread; `snapshot` only in dev builds), the three perf-trace variants → the recorder (does NOT write to `main.log`, which would balloon), and the two presentation-stall variants → the presentation-stall probe. - `INTERACTION_LOG_REVEAL` — flushes summary, then `shell.showItemInFolder(getInteractionLogPath())`. ### Why a separate file (not just `main.log`) `main.log` would be wrong for three reasons: - LoAF can fire hundreds of times per second during pathological renders — interleaving that into `main.log` would crowd out actionable lines. - A user reporting "clicks have felt laggy for a few days" needs a tape that spans days, but `main.log` rotates by size — your bad-Tuesday afternoon may be gone by Thursday. - The TOP 10 summary at the bottom only makes sense if every line in the file is the same _shape_ — interleaving with unrelated log lines defeats the summary. `interaction.log` solves all three: only perf-sensitive events, 1 MB cap with 5 rotated backups, and a self-describing header + TOP 10 sections that make it interpretable in isolation. ### Limitations - **Sub-200ms events are invisible.** The Event Timing threshold is hard-coded at 200 ms (INP-style) — a click that takes 180 ms feels noticeable but won't show up here. Lower thresholds would flood the file. - **LoAF requires Chrome 123+.** Electron 39 bundles Chromium 134 so it's covered, but if a future Electron downgrade removes the API the observer silently no-ops on that stream (Event Timing still works). - **Phased-nav events are explicit, not auto-detected.** Navigation code has to call `reportPhasedNav(...)` from `phased-nav-reporter.ts`. If a nav site doesn't, it just won't appear in the trace. - **Continuous tape means cross-launch context lives in one file.** If you only care about the most recent launch, look for the latest `── Launch resumed at … ──` marker and read forward from there. ## Related - [logs-and-debugging.md](logs-and-debugging.md) — the broader logging system (`main.log`, Debug Log Viewer, crash dumps, ZIP export). - [startup-trace.md](startup-trace.md) — the sibling launch-only timeline (per-launch rotation, not continuous). - [heap-snapshot-diagnostics.md](heap-snapshot-diagnostics.md) — the on-demand heap snapshot endpoint, complementary for memory bloat.