starred/orca
1
0
Fork 0
mirror of https://github.com/stablyai/orca.git synced 2026-10-19 16:03:26 +00:00
Code Issues Packages Projects Releases Wiki Activity

test(terminal): attribute typing stalls under load

Browse Source
This commit is contained in:
Neil
2026-07-29 07:36:22 -07:00
parent 5687a2c227
commit e9cbe41152
2 changed files with 234 additions and 62 deletions
Download Patch File Download Diff File Expand all files Collapse all files
tests/e2e/artificial-opencode-terminal-load.spec.ts
+28 -62
View File
@@ -16,27 +16,17 @@ import {
waitForActivePanePtyId,
waitForActiveTerminalManager
} from './helpers/terminal'
import { ensureActiveWorktreePaneLoad, focusPane } from './artificial-opencode-pane-interactions'
import {
ensureActiveWorktreePaneLoad,
focusActiveTerminalInput,
focusPane,
waitForMarkerLatency,
waitForTerminalOutputForPtyId
} from './artificial-opencode-pane-interactions'
measureTerminalTypingDuringLoad,
type TypingMeasurement
} from './artificial-opencode-typing-measurement'
import { runHiddenRealPtyPressureScenario } from './artificial-opencode-hidden-pressure-scenario'
import type { HiddenPressureOutputMode } from './artificial-opencode-hidden-pressure-script'
import { runMainPressureScenario } from './artificial-opencode-main-pressure-scenario'
import { runRendererBackpressureRevisitScenario } from './artificial-opencode-revisit-pressure-scenario'
import { startSyntheticOpenCodeInjection } from './artificial-opencode-synthetic-injection'
type TypingMeasurement = {
latencies: number[]
medianLatencyMs: number
worstLatencyMs: number
maxTimerDriftMs: number
frameCount: number
}
type SyntheticOpenCodeWindow = Window & {
__terminalPtyDataInjection?: {
inject: (paneKey: string, data: string) => boolean
@@ -108,7 +98,6 @@ type MainPtyPressureDebugSnapshot = {
pendingDroppedChars: number
}
const KEY_LATENCY_SAMPLES = 'abcdefghijklmnop'
const DEFAULT_SAME_WORKSPACE_PANES = 5
const DEFAULT_CROSS_WORKSPACE_PANES_PER_WORKTREE = 3
const DEFAULT_PRESSURE_BACKGROUND_PANES = 17
@@ -117,7 +106,6 @@ const DEFAULT_HIDDEN_PRESSURE_PANES = 17
const HIDDEN_PRESSURE_START_DELAY_MS = 1200
const DEFAULT_FRAME_COUNT = 180
const DEFAULT_FRAME_INTERVAL_MS = 6
const TIMER_SAMPLE_MS = 16
const MAIN_RENDERER_PRESSURE_TARGET_CHARS = 2 * 1024 * 1024
// Why: these are regression budgets, not observed baselines. Repeated local
// 100-pane OpenCode-scale runs are below 50ms worst-key latency; keep enough
@@ -233,57 +221,13 @@ function writeInteractivePromptScript(scriptPath: string, runId: string): void {
writeFileSync(scriptPath, interactivePromptScript(runId))
}
function median(values: number[]): number {
const sorted = [...values].sort((a, b) => a - b)
return sorted[Math.floor(sorted.length / 2)] ?? 0
}
async function measureTypingDuringLoad(
page: Page,
scriptPath: string,
ptyId: string,
runId: string
): Promise<TypingMeasurement> {
await sendToTerminal(page, ptyId, `node ${JSON.stringify(scriptPath)}\r`)
await waitForTerminalOutputForPtyId(page, ptyId, `OPENCODE_TYPING_READY_${runId}`, 10_000)
await focusActiveTerminalInput(page)
const eventLoop = await page.evaluateHandle((sampleMs) => {
let maxTimerDriftMs = 0
let lastTick = performance.now()
const timer = window.setInterval(() => {
const now = performance.now()
maxTimerDriftMs = Math.max(maxTimerDriftMs, now - lastTick - sampleMs)
lastTick = now
}, sampleMs)
return {
stop: () => {
window.clearInterval(timer)
return maxTimerDriftMs
}
}
}, TIMER_SAMPLE_MS)
const latencies: number[] = []
for (const [index, char] of [...KEY_LATENCY_SAMPLES].entries()) {
const marker = `OPENCODE_TYPING_KEY_${runId}_${index + 1}`
const start = performance.now()
await page.keyboard.type(char)
// Why: wait up to the under-load budget so a slow echo is measured and
// asserted per-scenario, not thrown as a confusing "did not contain".
await waitForMarkerLatency(page, marker, MAX_WORST_KEY_LATENCY_UNDER_LOAD_MS)
latencies.push(performance.now() - start)
}
const maxTimerDriftMs = await eventLoop.evaluate((watcher) => watcher.stop())
await eventLoop.dispose()
return {
latencies,
medianLatencyMs: median(latencies),
worstLatencyMs: Math.max(...latencies),
maxTimerDriftMs,
frameCount: FRAME_COUNT
}
return measureTerminalTypingDuringLoad(page, scriptPath, ptyId, runId, FRAME_COUNT)
}
async function resetTerminalPtyOutputDebug(page: Page): Promise<void> {
@@ -388,7 +332,29 @@ function annotateTypingMeasurement(
1
)}ms worst=${measurement.worstLatencyMs.toFixed(
1
)}ms maxTimerDrift=${measurement.maxTimerDriftMs.toFixed(1)}ms samples=${measurement.latencies
)}ms maxTimerDrift=${measurement.maxTimerDriftMs.toFixed(
1
)}ms controllerDrift=${measurement.controllerMaxTimerDriftMs.toFixed(
1
)}ms rendererLongTask=${measurement.rendererMaxLongTaskMs.toFixed(
1
)}ms rendererLongTaskSupported=${
measurement.rendererLongTaskSupported
} rendererKeydowns=${measurement.rendererKeydownCount} typingElapsed=${measurement.elapsedMs.toFixed(
1
)}ms dispatchSamples=${measurement.dispatchLatencies
.map((value) => value.toFixed(1))
.join(',')} echoSamples=${measurement.echoLatencies
.map((value) => value.toFixed(1))
.join(',')} hostCpuBusy=${
measurement.hostCpuBusyPercent == null
? 'na'
: `${measurement.hostCpuBusyPercent.toFixed(1)}%`
} hostCpuPressureWait=${
measurement.hostCpuPressureWaitMs == null
? 'na'
: `${measurement.hostCpuPressureWaitMs.toFixed(1)}ms`
} samples=${measurement.latencies
.map((value) => value.toFixed(1))
.join(',')}${mode2031Summary}${schedulerSummary}${mainPressureSummary}${ackGateSummary}`
})
tests/e2e/artificial-opencode-typing-measurement.ts
+206
View File
@@ -0,0 +1,206 @@
import type { Page } from '@stablyai/playwright-test'
import { readFileSync } from 'node:fs'
import { performance } from 'node:perf_hooks'
import {
focusActiveTerminalInput,
waitForMarkerLatency,
waitForTerminalOutputForPtyId
} from './artificial-opencode-pane-interactions'
import { sendToTerminal } from './helpers/terminal'
export type TypingMeasurement = {
latencies: number[]
dispatchLatencies: number[]
echoLatencies: number[]
medianLatencyMs: number
worstLatencyMs: number
maxTimerDriftMs: number
controllerMaxTimerDriftMs: number
rendererMaxLongTaskMs: number
rendererLongTaskSupported: boolean
rendererKeydownCount: number
hostCpuBusyPercent: number | null
hostCpuPressureWaitMs: number | null
elapsedMs: number
frameCount: number
}
type HostCpuSnapshot = {
idleTicks: number
pressureWaitMicros: number | null
totalTicks: number
}
const KEY_LATENCY_SAMPLES = 'abcdefghijklmnop'
const MAX_KEY_ECHO_LATENCY_MS = 3_000
const TIMER_SAMPLE_MS = 16
function median(values: number[]): number {
const sorted = [...values].sort((a, b) => a - b)
return sorted[Math.floor(sorted.length / 2)] ?? 0
}
function readHostCpuSnapshot(): HostCpuSnapshot | null {
if (process.platform !== 'linux') {
return null
}
try {
const cpuFields = readFileSync('/proc/stat', 'utf8')
.split('\n')[0]
?.trim()
.split(/\s+/)
.slice(1)
.map(Number)
if (!cpuFields || cpuFields.length < 4 || cpuFields.some((value) => !Number.isFinite(value))) {
return null
}
const pressureMatch = readFileSync('/proc/pressure/cpu', 'utf8').match(
/^some\s+.*\btotal=(\d+)$/m
)
return {
idleTicks: cpuFields[3] + (cpuFields[4] ?? 0),
pressureWaitMicros: pressureMatch ? Number(pressureMatch[1]) : null,
totalTicks: cpuFields.reduce((total, value) => total + value, 0)
}
} catch {
return null
}
}
function hostCpuDelta(
start: HostCpuSnapshot | null,
end: HostCpuSnapshot | null
): {
busyPercent: number | null
pressureWaitMs: number | null
} {
if (!start || !end) {
return { busyPercent: null, pressureWaitMs: null }
}
const totalTicks = end.totalTicks - start.totalTicks
const idleTicks = end.idleTicks - start.idleTicks
const pressureWaitMicros =
start.pressureWaitMicros == null || end.pressureWaitMicros == null
? null
: end.pressureWaitMicros - start.pressureWaitMicros
return {
busyPercent: totalTicks > 0 ? ((totalTicks - idleTicks) / totalTicks) * 100 : null,
pressureWaitMs: pressureWaitMicros == null ? null : pressureWaitMicros / 1_000
}
}
function startControllerTimerDrift(): () => number {
let maxTimerDriftMs = 0
let lastTick = performance.now()
const timer = setInterval(() => {
const now = performance.now()
maxTimerDriftMs = Math.max(maxTimerDriftMs, now - lastTick - TIMER_SAMPLE_MS)
lastTick = now
}, TIMER_SAMPLE_MS)
return () => {
clearInterval(timer)
return maxTimerDriftMs
}
}
export async function measureTerminalTypingDuringLoad(
page: Page,
scriptPath: string,
ptyId: string,
runId: string,
frameCount: number
): Promise<TypingMeasurement> {
await sendToTerminal(page, ptyId, `node ${JSON.stringify(scriptPath)}\r`)
await waitForTerminalOutputForPtyId(page, ptyId, `OPENCODE_TYPING_READY_${runId}`, 10_000)
await focusActiveTerminalInput(page)
const rendererWatcher = await page.evaluateHandle((sampleMs) => {
let maxTimerDriftMs = 0
let maxLongTaskMs = 0
let keydownCount = 0
let lastTick = window.performance.now()
const timer = window.setInterval(() => {
const now = window.performance.now()
maxTimerDriftMs = Math.max(maxTimerDriftMs, now - lastTick - sampleMs)
lastTick = now
}, sampleMs)
const onKeydown = (): void => {
keydownCount += 1
}
window.addEventListener('keydown', onKeydown, true)
const longTaskSupported = PerformanceObserver.supportedEntryTypes.includes('longtask')
const observer = longTaskSupported
? new PerformanceObserver((list) => {
for (const entry of list.getEntries()) {
maxLongTaskMs = Math.max(maxLongTaskMs, entry.duration)
}
})
: null
observer?.observe({ type: 'longtask' })
return {
stop: () => {
window.clearInterval(timer)
window.removeEventListener('keydown', onKeydown, true)
for (const entry of observer?.takeRecords() ?? []) {
maxLongTaskMs = Math.max(maxLongTaskMs, entry.duration)
}
observer?.disconnect()
return { keydownCount, longTaskSupported, maxLongTaskMs, maxTimerDriftMs }
}
}
}, TIMER_SAMPLE_MS)
const stopControllerTimer = startControllerTimerDrift()
const hostCpuStart = readHostCpuSnapshot()
const measurementStart = performance.now()
const latencies: number[] = []
const dispatchLatencies: number[] = []
const echoLatencies: number[] = []
let controllerMaxTimerDriftMs = 0
let elapsedMs = 0
let hostCpuEnd: HostCpuSnapshot | null = null
let rendererTiming = {
keydownCount: 0,
longTaskSupported: false,
maxLongTaskMs: 0,
maxTimerDriftMs: 0
}
try {
for (const [index, char] of KEY_LATENCY_SAMPLES.split('').entries()) {
const marker = `OPENCODE_TYPING_KEY_${runId}_${index + 1}`
const start = performance.now()
await page.keyboard.type(char)
const dispatched = performance.now()
await waitForMarkerLatency(page, marker, MAX_KEY_ECHO_LATENCY_MS)
const completed = performance.now()
dispatchLatencies.push(dispatched - start)
echoLatencies.push(completed - dispatched)
latencies.push(completed - start)
}
} finally {
try {
rendererTiming = await rendererWatcher.evaluate((watcher) => watcher.stop())
} finally {
controllerMaxTimerDriftMs = stopControllerTimer()
hostCpuEnd = readHostCpuSnapshot()
elapsedMs = performance.now() - measurementStart
await rendererWatcher.dispose()
}
}
const hostCpu = hostCpuDelta(hostCpuStart, hostCpuEnd)
return {
latencies,
dispatchLatencies,
echoLatencies,
medianLatencyMs: median(latencies),
worstLatencyMs: Math.max(...latencies),
maxTimerDriftMs: rendererTiming.maxTimerDriftMs,
controllerMaxTimerDriftMs,
rendererMaxLongTaskMs: rendererTiming.maxLongTaskMs,
rendererLongTaskSupported: rendererTiming.longTaskSupported,
rendererKeydownCount: rendererTiming.keydownCount,
hostCpuBusyPercent: hostCpu.busyPercent,
hostCpuPressureWaitMs: hostCpu.pressureWaitMs,
elapsedMs,
frameCount
}
}