fix(ink): reduce high-write-ratio diagnostic noise (#1699)

* fix(ink): reduce high-write-ratio diagnostic noise

* test(ink): cover high-write diagnostic suppression

* fix(ink): preserve churn warnings at suspicious widths

src/ink/ink.tsx

@@ -1114,7 +1114,9 @@ export default class Ink {
       offsetY: -elTop,
       prevScreen: undefined
     });
-    const rendered = output.get();
+    const rendered = output.get({
+      suppressHighWriteRatioDiagnostics: true
+    });
     // renderNodeToOutput wrote our offset positions to nodeCache —
     // corrupts the main render (it'd blit from wrong coords). Mark the
     // subtree dirty so the next main render repaints + re-caches

src/ink/output.test.ts

@@ -0,0 +1,258 @@
+import { afterEach, beforeEach, expect, spyOn, test } from 'bun:test'
+
+import * as debug from '../utils/debug.ts'
+import Output from './output.ts'
+import {
+  CharPool,
+  createScreen,
+  HyperlinkPool,
+  StylePool,
+  type Screen,
+} from './screen.ts'
+
+let logSpy: ReturnType<typeof spyOn>
+
+type Harness = {
+  output: Output
+  stylePool: StylePool
+  charPool: CharPool
+  hyperlinkPool: HyperlinkPool
+}
+
+function createHarness(width: number, height: number): Harness {
+  const stylePool = new StylePool()
+  const charPool = new CharPool()
+  const hyperlinkPool = new HyperlinkPool()
+  const screen = createScreen(width, height, stylePool, charPool, hyperlinkPool)
+
+  return {
+    output: new Output({ width, height, stylePool, screen }),
+    stylePool,
+    charPool,
+    hyperlinkPool,
+  }
+}
+
+function resetOutput(harness: Harness, width: number, height: number): void {
+  harness.output.reset(
+    width,
+    height,
+    createScreen(
+      width,
+      height,
+      harness.stylePool,
+      harness.charPool,
+      harness.hyperlinkPool,
+    ),
+  )
+}
+
+function createScreenForHarness(
+  harness: Harness,
+  width: number,
+  height: number,
+): Screen {
+  return createScreen(
+    width,
+    height,
+    harness.stylePool,
+    harness.charPool,
+    harness.hyperlinkPool,
+  )
+}
+
+function writeFullFrame(output: Output, width: number, height: number): void {
+  const row = 'x'.repeat(width)
+
+  for (let y = 0; y < height; y++) {
+    output.write(0, y, row)
+  }
+}
+
+beforeEach(() => {
+  logSpy = spyOn(debug, 'logForDebugging').mockImplementation(() => {})
+})
+
+afterEach(() => {
+  logSpy.mockRestore()
+})
+
+test('classifies first render high-write frames as expected full redraws', () => {
+  const harness = createHarness(80, 20)
+
+  writeFullFrame(harness.output, 80, 20)
+  harness.output.get({ highWriteRatioReason: 'first-render' })
+
+  expect(logSpy).toHaveBeenCalledTimes(1)
+  expect(logSpy.mock.calls[0]?.[0]).toContain('render.high_write_ratio')
+  expect(logSpy.mock.calls[0]?.[0]).toContain('reason=first-render')
+  expect(logSpy.mock.calls[0]?.[0]).toContain('expected=true')
+  expect(logSpy.mock.calls[0]?.[1]).toEqual({ level: 'debug' })
+})
+
+test('classifies resize high-write frames as expected full redraws', () => {
+  const harness = createHarness(100, 14)
+
+  writeFullFrame(harness.output, 100, 14)
+  harness.output.get({ highWriteRatioReason: 'resize' })
+
+  expect(logSpy).toHaveBeenCalledTimes(1)
+  expect(logSpy.mock.calls[0]?.[0]).toContain('reason=resize')
+  expect(logSpy.mock.calls[0]?.[0]).toContain('expected=true')
+  expect(logSpy.mock.calls[0]?.[1]).toEqual({ level: 'debug' })
+})
+
+test('aggregates sustained unknown high-write frames instead of logging every frame', () => {
+  const harness = createHarness(80, 20)
+
+  for (let frame = 0; frame < 5; frame++) {
+    if (frame > 0) {
+      resetOutput(harness, 80, 20)
+    }
+    writeFullFrame(harness.output, 80, 20)
+    harness.output.get()
+  }
+
+  expect(logSpy).toHaveBeenCalledTimes(1)
+  expect(logSpy.mock.calls[0]?.[0]).toContain('reason=unknown')
+  expect(logSpy.mock.calls[0]?.[0]).toContain('frames=3')
+  expect(logSpy.mock.calls[0]?.[1]).toEqual({ level: 'warn' })
+})
+
+test('suppresses high-write diagnostics and resets unknown aggregation state', () => {
+  const harness = createHarness(80, 20)
+
+  for (let frame = 0; frame < 2; frame++) {
+    if (frame > 0) {
+      resetOutput(harness, 80, 20)
+    }
+    writeFullFrame(harness.output, 80, 20)
+    harness.output.get()
+  }
+
+  for (let frame = 0; frame < 5; frame++) {
+    resetOutput(harness, 80, 20)
+    writeFullFrame(harness.output, 80, 20)
+    harness.output.get({ suppressHighWriteRatioDiagnostics: true })
+  }
+
+  expect(logSpy).not.toHaveBeenCalled()
+
+  for (let frame = 0; frame < 2; frame++) {
+    resetOutput(harness, 80, 20)
+    writeFullFrame(harness.output, 80, 20)
+    harness.output.get()
+  }
+
+  expect(logSpy).not.toHaveBeenCalled()
+
+  resetOutput(harness, 80, 20)
+  writeFullFrame(harness.output, 80, 20)
+  harness.output.get()
+
+  expect(logSpy).toHaveBeenCalledTimes(1)
+  expect(logSpy.mock.calls[0]?.[0]).toContain('reason=unknown')
+  expect(logSpy.mock.calls[0]?.[0]).toContain('frames=3')
+  expect(logSpy.mock.calls[0]?.[1]).toEqual({ level: 'warn' })
+})
+
+test('dimension changes reset sustained unknown high-write aggregation', () => {
+  const harness = createHarness(80, 20)
+
+  for (let frame = 0; frame < 2; frame++) {
+    if (frame > 0) {
+      resetOutput(harness, 80, 20)
+    }
+    writeFullFrame(harness.output, 80, 20)
+    harness.output.get()
+  }
+
+  resetOutput(harness, 81, 20)
+  writeFullFrame(harness.output, 81, 20)
+  harness.output.get()
+
+  expect(logSpy).not.toHaveBeenCalled()
+
+  for (let frame = 0; frame < 2; frame++) {
+    resetOutput(harness, 81, 20)
+    writeFullFrame(harness.output, 81, 20)
+    harness.output.get()
+  }
+
+  expect(logSpy).toHaveBeenCalledTimes(1)
+  expect(logSpy.mock.calls[0]?.[0]).toContain('frames=3')
+})
+
+test('flags suspicious terminal columns only once', () => {
+  const harness = createHarness(1201, 1)
+
+  writeFullFrame(harness.output, 1201, 1)
+  harness.output.get()
+
+  resetOutput(harness, 1201, 1)
+  writeFullFrame(harness.output, 1201, 1)
+  harness.output.get()
+
+  expect(logSpy).toHaveBeenCalledTimes(1)
+  expect(logSpy.mock.calls[0]?.[0]).toContain(
+    'reason=suspicious-terminal-columns',
+  )
+  expect(logSpy.mock.calls[0]?.[1]).toEqual({ level: 'warn' })
+})
+
+test('continues sustained unknown aggregation at suspicious terminal widths', () => {
+  const harness = createHarness(1201, 1)
+
+  for (let frame = 0; frame < 3; frame++) {
+    if (frame > 0) {
+      resetOutput(harness, 1201, 1)
+    }
+    writeFullFrame(harness.output, 1201, 1)
+    harness.output.get()
+  }
+
+  expect(logSpy).toHaveBeenCalledTimes(2)
+  expect(logSpy.mock.calls[0]?.[0]).toContain(
+    'reason=suspicious-terminal-columns',
+  )
+  expect(logSpy.mock.calls[0]?.[0]).toContain('frames=1')
+  expect(logSpy.mock.calls[0]?.[1]).toEqual({ level: 'warn' })
+  expect(logSpy.mock.calls[1]?.[0]).toContain('reason=unknown')
+  expect(logSpy.mock.calls[1]?.[0]).toContain('frames=3')
+  expect(logSpy.mock.calls[1]?.[1]).toEqual({ level: 'warn' })
+})
+
+test('suspicious terminal columns can be flagged again after returning to normal width', () => {
+  const harness = createHarness(1201, 1)
+
+  writeFullFrame(harness.output, 1201, 1)
+  harness.output.get()
+
+  resetOutput(harness, 80, 20)
+  writeFullFrame(harness.output, 80, 20)
+  harness.output.get({ highWriteRatioReason: 'resize' })
+
+  resetOutput(harness, 1201, 1)
+  writeFullFrame(harness.output, 1201, 1)
+  harness.output.get()
+
+  expect(logSpy).toHaveBeenCalledTimes(3)
+  expect(logSpy.mock.calls[0]?.[0]).toContain(
+    'reason=suspicious-terminal-columns',
+  )
+  expect(logSpy.mock.calls[1]?.[0]).toContain('reason=resize')
+  expect(logSpy.mock.calls[2]?.[0]).toContain(
+    'reason=suspicious-terminal-columns',
+  )
+})
+
+test('does not report high-write diagnostics for blit-heavy incremental frames', () => {
+  const harness = createHarness(80, 20)
+  const prevScreen = createScreenForHarness(harness, 80, 20)
+
+  harness.output.blit(prevScreen, 0, 0, 80, 20)
+  harness.output.write(0, 0, 'changed')
+  harness.output.get()
+
+  expect(logSpy).not.toHaveBeenCalled()
+})

src/ink/output.ts

@@ -59,6 +59,38 @@ type Options = {
   screen: Screen
 }
 
+export type HighWriteRatioReason =
+  | 'first-render'
+  | 'resize'
+  | 'remount'
+  | 'debug-full-redraw'
+  | 'suspicious-terminal-columns'
+  | 'unknown'
+
+export type GetOptions = {
+  highWriteRatioReason?: HighWriteRatioReason
+  suppressHighWriteRatioDiagnostics?: boolean
+}
+
+type HighWriteRatioStats = {
+  blitCells: number
+  writeCells: number
+  screenHeight: number
+  screenWidth: number
+}
+
+const HIGH_WRITE_RATIO_MIN_CELLS = 1000
+const HIGH_WRITE_RATIO_STREAK_THRESHOLD = 3
+const HIGH_WRITE_RATIO_REPEAT_INTERVAL = 20
+const SUSPICIOUS_TERMINAL_COLUMNS = 1000
+
+const EXPECTED_HIGH_WRITE_REASONS = new Set<HighWriteRatioReason>([
+  'first-render',
+  'resize',
+  'remount',
+  'debug-full-redraw',
+])
+
 export type Operation =
   | WriteOperation
   | ClipOperation
@@ -176,6 +208,9 @@ export default class Output {
   private readonly operations: Operation[] = []
 
   private charCache: Map<string, ClusteredChar[]> = new Map()
+  private highWriteRatioStreak = 0
+  private highWriteRatioStreakReason: HighWriteRatioReason = 'unknown'
+  private suspiciousColumnsLogged = false
 
   constructor(options: Options) {
     const { width, height, stylePool, screen } = options
@@ -196,12 +231,19 @@ export default class Output {
    * becomes a cache hit.
    */
   reset(width: number, height: number, screen: Screen): void {
+    const dimensionsChanged = width !== this.width || height !== this.height
     this.width = width
     this.height = height
     this.screen = screen
     this.operations.length = 0
     resetScreen(screen, width, height)
     if (this.charCache.size > 16384) this.charCache.clear()
+    if (dimensionsChanged) {
+      this.resetHighWriteRatioStreak()
+      if (width <= SUSPICIOUS_TERMINAL_COLUMNS) {
+        this.suspiciousColumnsLogged = false
+      }
+    }
   }
 
   /**
@@ -265,7 +307,7 @@ export default class Output {
     })
   }
 
-  get(): Screen {
+  get(options: GetOptions = {}): Screen {
     const screen = this.screen
     const screenWidth = this.width
     const screenHeight = this.height
@@ -519,16 +561,107 @@ export default class Output {
       }
     }
 
-    // Log blit/write ratio for debugging - high write count suggests blitting isn't working
-    const totalCells = blitCells + writeCells
-    if (totalCells > 1000 && writeCells > blitCells) {
-      logForDebugging(
-        `High write ratio: blit=${blitCells}, write=${writeCells} (${((writeCells / totalCells) * 100).toFixed(1)}% writes), screen=${screenHeight}x${screenWidth}`,
-      )
-    }
+    this.maybeLogHighWriteRatio(
+      { blitCells, writeCells, screenHeight, screenWidth },
+      options,
+    )
 
     return screen
   }
+
+  private maybeLogHighWriteRatio(
+    stats: HighWriteRatioStats,
+    options: GetOptions,
+  ): void {
+    if (options.suppressHighWriteRatioDiagnostics) {
+      this.resetHighWriteRatioStreak()
+      return
+    }
+
+    const { blitCells, writeCells, screenWidth } = stats
+    const totalCells = blitCells + writeCells
+    if (
+      totalCells <= HIGH_WRITE_RATIO_MIN_CELLS ||
+      writeCells <= blitCells
+    ) {
+      this.resetHighWriteRatioStreak()
+      return
+    }
+
+    if (screenWidth > SUSPICIOUS_TERMINAL_COLUMNS) {
+      if (!this.suspiciousColumnsLogged) {
+        this.logHighWriteRatio(stats, {
+          reason: 'suspicious-terminal-columns',
+          expected: false,
+          frames: 1,
+          level: 'warn',
+        })
+        this.suspiciousColumnsLogged = true
+      }
+    }
+
+    const reason = options.highWriteRatioReason ?? 'unknown'
+    if (EXPECTED_HIGH_WRITE_REASONS.has(reason)) {
+      this.logHighWriteRatio(stats, {
+        reason,
+        expected: true,
+        frames: 1,
+        level: 'debug',
+      })
+      this.resetHighWriteRatioStreak()
+      return
+    }
+
+    if (this.highWriteRatioStreakReason !== reason) {
+      this.highWriteRatioStreakReason = reason
+      this.highWriteRatioStreak = 0
+    }
+
+    this.highWriteRatioStreak++
+    if (
+      this.highWriteRatioStreak === HIGH_WRITE_RATIO_STREAK_THRESHOLD ||
+      (this.highWriteRatioStreak > HIGH_WRITE_RATIO_STREAK_THRESHOLD &&
+        (this.highWriteRatioStreak - HIGH_WRITE_RATIO_STREAK_THRESHOLD) %
+          HIGH_WRITE_RATIO_REPEAT_INTERVAL ===
+          0)
+    ) {
+      this.logHighWriteRatio(stats, {
+        reason,
+        expected: false,
+        frames: this.highWriteRatioStreak,
+        level: 'warn',
+      })
+    }
+  }
+
+  private resetHighWriteRatioStreak(): void {
+    this.highWriteRatioStreak = 0
+    this.highWriteRatioStreakReason = 'unknown'
+  }
+
+  private logHighWriteRatio(
+    stats: HighWriteRatioStats,
+    {
+      reason,
+      expected,
+      frames,
+      level,
+    }: {
+      reason: HighWriteRatioReason
+      expected: boolean
+      frames: number
+      level: 'debug' | 'warn'
+    },
+  ): void {
+    const { blitCells, writeCells, screenHeight, screenWidth } = stats
+    const totalCells = blitCells + writeCells
+    logForDebugging(
+      `render.high_write_ratio: reason=${reason} expected=${expected} frames=${frames} ` +
+        `blit=${blitCells} write=${writeCells} ratio=${((writeCells / totalCells) * 100).toFixed(1)}% ` +
+        `screen=${screenHeight}x${screenWidth}`,
+      { level },
+    )
+  }
 }
 
 function stylesEqual(a: AnsiCode[], b: AnsiCode[]): boolean {

src/ink/render-to-screen.ts

@@ -110,7 +110,7 @@ export function renderToScreen(
   // renderNodeToOutput queues writes into Output; .get() flushes the
   // queue into the Screen's cell arrays. Without this the screen is
   // blank (constructor-zero).
-  const rendered = output.get()
+  const rendered = output.get({ suppressHighWriteRatioDiagnostics: true })
   const t3 = performance.now()
 
   // Unmount so next call gets a fresh tree. Leaves root/container/pools.

src/ink/renderer.test.ts

@@ -0,0 +1,151 @@
+import { expect, test } from 'bun:test'
+
+import { emptyFrame, type Frame } from './frame.ts'
+import { classifyHighWriteRatioReason } from './renderer.ts'
+import {
+  CharPool,
+  createScreen,
+  HyperlinkPool,
+  StylePool,
+} from './screen.ts'
+
+const stylePool = new StylePool()
+const charPool = new CharPool()
+const hyperlinkPool = new HyperlinkPool()
+
+function createFrame({
+  screenWidth,
+  screenHeight,
+  viewportWidth = screenWidth,
+  viewportHeight = screenHeight,
+}: {
+  screenWidth: number
+  screenHeight: number
+  viewportWidth?: number
+  viewportHeight?: number
+}): Frame {
+  return {
+    screen: createScreen(
+      screenWidth,
+      screenHeight,
+      stylePool,
+      charPool,
+      hyperlinkPool,
+    ),
+    viewport: {
+      width: viewportWidth,
+      height: viewportHeight,
+    },
+    cursor: { x: 0, y: 0, visible: true },
+  }
+}
+
+test('high-write classifier identifies initial empty frame as first render', () => {
+  const frontFrame = emptyFrame(24, 80, stylePool, charPool, hyperlinkPool)
+
+  expect(
+    classifyHighWriteRatioReason(
+      {
+        frontFrame,
+        backFrame: frontFrame,
+        isTTY: true,
+        terminalWidth: 80,
+        terminalRows: 24,
+        altScreen: false,
+        prevFrameContaminated: false,
+      },
+      false,
+    ),
+  ).toBe('first-render')
+})
+
+test('high-write classifier reports debug full redraw when a contaminated empty frame forces repaint', () => {
+  const frontFrame = emptyFrame(24, 80, stylePool, charPool, hyperlinkPool)
+
+  expect(
+    classifyHighWriteRatioReason(
+      {
+        frontFrame,
+        backFrame: frontFrame,
+        isTTY: true,
+        terminalWidth: 80,
+        terminalRows: 24,
+        altScreen: false,
+        prevFrameContaminated: true,
+      },
+      false,
+    ),
+  ).toBe('debug-full-redraw')
+})
+
+test('high-write classifier does not treat steady alt-screen viewport offset as resize', () => {
+  const frontFrame = createFrame({
+    screenWidth: 120,
+    screenHeight: 24,
+    viewportWidth: 120,
+    viewportHeight: 25,
+  })
+
+  expect(
+    classifyHighWriteRatioReason(
+      {
+        frontFrame,
+        backFrame: frontFrame,
+        isTTY: true,
+        terminalWidth: 120,
+        terminalRows: 24,
+        altScreen: true,
+        prevFrameContaminated: true,
+      },
+      false,
+    ),
+  ).toBe('remount')
+})
+
+test('high-write classifier keeps real resize reason ahead of contamination', () => {
+  const frontFrame = createFrame({
+    screenWidth: 120,
+    screenHeight: 24,
+    viewportWidth: 120,
+    viewportHeight: 24,
+  })
+
+  expect(
+    classifyHighWriteRatioReason(
+      {
+        frontFrame,
+        backFrame: frontFrame,
+        isTTY: true,
+        terminalWidth: 120,
+        terminalRows: 24,
+        altScreen: true,
+        prevFrameContaminated: true,
+      },
+      false,
+    ),
+  ).toBe('resize')
+})
+
+test('high-write classifier reports absolute removals as remount redraws', () => {
+  const frontFrame = createFrame({
+    screenWidth: 80,
+    screenHeight: 24,
+    viewportWidth: 80,
+    viewportHeight: 24,
+  })
+
+  expect(
+    classifyHighWriteRatioReason(
+      {
+        frontFrame,
+        backFrame: frontFrame,
+        isTTY: true,
+        terminalWidth: 80,
+        terminalRows: 24,
+        altScreen: false,
+        prevFrameContaminated: false,
+      },
+      true,
+    ),
+  ).toBe('remount')
+})

src/ink/renderer.ts

@@ -2,7 +2,7 @@ import { logForDebugging } from 'src/utils/debug.js'
 import { type DOMElement, markDirty } from './dom.js'
 import type { Frame } from './frame.js'
 import { consumeAbsoluteRemovedFlag } from './node-cache.js'
-import Output from './output.js'
+import Output, { type HighWriteRatioReason } from './output.js'
 import renderNodeToOutput, {
   getScrollDrainNode,
   getScrollHint,
@@ -127,6 +127,10 @@ export default function createRenderer(
     // node's pixels. hasRemovedChild only shields direct siblings.
     // Normal-flow removals don't paint cross-subtree and are fine.
     const absoluteRemoved = consumeAbsoluteRemovedFlag()
+    const highWriteRatioReason = classifyHighWriteRatioReason(
+      options,
+      absoluteRemoved,
+    )
     renderNodeToOutput(node, output, {
       prevScreen:
         absoluteRemoved || options.prevFrameContaminated
@@ -134,7 +138,7 @@ export default function createRenderer(
           : prevScreen,
     })
 
-    const renderedScreen = output.get()
+    const renderedScreen = output.get({ highWriteRatioReason })
 
     // Drain continuation: render cleared scrollbox.dirty, so next frame's
     // root blit would skip the subtree. markDirty walks ancestors so the
@@ -176,3 +180,40 @@ export default function createRenderer(
     }
   }
 }
+
+export function classifyHighWriteRatioReason(
+  options: RenderOptions,
+  absoluteRemoved: boolean,
+): HighWriteRatioReason {
+  const expectedViewportHeight = options.altScreen
+    ? options.terminalRows + 1
+    : options.terminalRows
+
+  if (
+    options.frontFrame.viewport.width !== options.terminalWidth ||
+    options.frontFrame.viewport.height !== expectedViewportHeight
+  ) {
+    return 'resize'
+  }
+
+  if (
+    options.prevFrameContaminated &&
+    options.frontFrame.screen.width === 0 &&
+    options.frontFrame.screen.height === 0
+  ) {
+    return 'debug-full-redraw'
+  }
+
+  if (options.prevFrameContaminated || absoluteRemoved) {
+    return 'remount'
+  }
+
+  if (
+    options.frontFrame.screen.width === 0 &&
+    options.frontFrame.screen.height === 0
+  ) {
+    return 'first-render'
+  }
+
+  return 'unknown'
+}