feat: add request timing markers

[Nomadcxx]

PR B for the perf work.\n\nAdds CURSOR_ACP_TIMING=1 request timing logs with ordered phase timelines, fixes repeated marker accounting, and records streaming phases for request parse, prompt/backend resolution, child creation, first stdout byte, first SSE write, and request completion.\n\nVerification:\n- bun test tests/unit/perf.test.ts\n- bun test tests/integration/opencode-loop.integration.test.ts\n- npm run build\n- npm test

[coderabbitai]

📝 Walkthrough

Walkthrough

src/utils/perf.ts gains exported PerfPhase and PerfSummary interfaces and a reworked summarize() that returns a structured summary with phaseTotals and timeline, logging at info or debug based on CURSOR_ACP_TIMING. Both Bun and Node proxy handlers in src/plugin.ts are instrumented with RequestPerf lifecycle marks and refactored to route all SSE writes through enqueueSse/writeSse helpers that capture first-write timing. New unit and integration tests validate the summary shape and log file output.

Changes

Request Performance Instrumentation

Layer / File(s)	Summary
PerfPhase/PerfSummary types and summarize() rework src/utils/perf.ts	Exports PerfPhase and PerfSummary interfaces, adds isTimingLogEnabled() helper reading CURSOR_ACP_TIMING, and rewrites summarize() to return PerfSummary | undefined with phaseTotals, timeline, and conditional info/debug logging.
Bun handler RequestPerf marks and enqueueSse helper src/plugin.ts (lines 1153–1647)	Initializes RequestPerf in the Bun chat handler, adds lifecycle marks (body-read, body-parsed, backend-resolved, prompt-built, child-create-start, child-created, first-stdout-byte), introduces enqueueSse helper tracking first-SSE state, and routes all SSE chunk writes through it across tool-loop callbacks, termination paths, and stream finalization.
Node handler RequestPerf marks and writeSse helper src/plugin.ts (lines 1732–2183)	Mirrors the Bun changes for the Node handler: same lifecycle marks plus child-dispatched, introduces writeSse helper, and routes all SSE chunk writes through it across spawn-error, tool-loop, drain loop, error termination, and finalization paths.
Unit and integration tests tests/unit/perf.test.ts, tests/integration/opencode-loop.integration.test.ts	Adds a unit test asserting summarize() preserves repeated marker phases in the timeline; adds an integration test that polls plugin.log via waitForFileText() for expected phase strings, with beforeAll/afterAll wiring for CURSOR_ACP_TIMING, CURSOR_ACP_LOG_DIR, CURSOR_ACP_LOG_CONSOLE, and logger state resets.

Estimated code review effort

🎯 3 (Moderate) | ⏱️ ~25 minutes

Possibly related PRs

• Nomadcxx/opencode-cursor#94: Modifies src/plugin.ts to add RequestPerf timing marks in the Node proxy handler around prompt-building, backend resolution, and child spawn — directly overlapping with this PR's expanded lifecycle instrumentation in the same code paths.

🚥 Pre-merge checks | ✅ 4 | ❌ 1

❌ Failed checks (1 warning)

Check name	Status	Explanation	Resolution
Docstring Coverage	⚠️ Warning	Docstring coverage is 0.00% which is insufficient. The required threshold is 80.00%.	Write docstrings for the functions missing them to satisfy the coverage threshold.

✅ Passed checks (4 passed)

Check name	Status	Explanation
Title check	✅ Passed	The pull request title 'feat: add request timing markers' accurately summarizes the main change—adding request performance instrumentation via timing markers throughout the request lifecycle.
Description check	✅ Passed	The pull request description is directly related to the changeset, explaining the addition of CURSOR_ACP_TIMING request timing logs, fixes for repeated marker accounting, and recording of streaming phases.
Linked Issues check	✅ Passed	Check skipped because no linked issues were found for this pull request.
Out of Scope Changes check	✅ Passed	Check skipped because no linked issues were found for this pull request.

_{✏️ Tip: You can configure your own custom pre-merge checks in the settings.}

---

Thanks for using CodeRabbit! It's free for OSS, and your support helps us grow. If you like it, consider giving us a shout-out.

❤️ Share

• X
• Mastodon
• Reddit
• LinkedIn

_{Comment @coderabbitai help to get the list of available commands and usage tips.}

[coderabbitai]

🧹 Nitpick comments (1)

tests/integration/opencode-loop.integration.test.ts (1)

267-278: ⚡ Quick win

Consider increasing the timeout for more reliable CI execution.

The current polling timeout is 500ms (20 iterations × 25ms). This may be insufficient in slow CI environments or under heavy load, potentially causing flaky test failures. Additionally, when the timeout expires, returning an empty string provides no diagnostic information about whether the file never appeared or simply didn't contain the required text.

💡 Suggested improvements

-async function waitForFileText(path: string, requiredText?: string): Promise<string> {
-  for (let i = 0; i < 20; i++) {
+async function waitForFileText(path: string, requiredText?: string, timeoutMs = 2000): Promise<string> {
+  const iterations = Math.ceil(timeoutMs / 50);
+  for (let i = 0; i < iterations; i++) {
     if (existsSync(path)) {
       const text = readFileSync(path, "utf8");
       if (text.length > 0 && (requiredText === undefined || text.includes(requiredText))) {
         return text;
       }
     }
-    await new Promise((resolve) => setTimeout(resolve, 25));
+    await new Promise((resolve) => setTimeout(resolve, 50));
   }
   return existsSync(path) ? readFileSync(path, "utf8") : "";
 }

🤖 Prompt for AI Agents

Verify each finding against current code. Fix only still-valid issues, skip the
rest with a brief reason, keep changes minimal, and validate.

In `@tests/integration/opencode-loop.integration.test.ts` around lines 267 - 278,
The waitForFileText function has an insufficient timeout of 500ms total (20
iterations × 25ms), which can cause flaky tests in CI environments. Increase the
timeout by either increasing the number of iterations (the loop counter 20) or
the sleep duration (25ms), or both. Additionally, when the function times out
and is about to return at the end, instead of returning an empty string, throw
an error or return a meaningful diagnostic message that indicates whether the
file never appeared or if it appeared but didn't contain the required text. This
will provide better visibility into test failures.

🤖 Prompt for all review comments with AI agents

Verify each finding against current code. Fix only still-valid issues, skip the
rest with a brief reason, keep changes minimal, and validate.

Nitpick comments:
In `@tests/integration/opencode-loop.integration.test.ts`:
- Around line 267-278: The waitForFileText function has an insufficient timeout
of 500ms total (20 iterations × 25ms), which can cause flaky tests in CI
environments. Increase the timeout by either increasing the number of iterations
(the loop counter 20) or the sleep duration (25ms), or both. Additionally, when
the function times out and is about to return at the end, instead of returning
an empty string, throw an error or return a meaningful diagnostic message that
indicates whether the file never appeared or if it appeared but didn't contain
the required text. This will provide better visibility into test failures.

---

ℹ️ Review info

⚙️ Run configuration

Configuration used: Path: .coderabbit.yaml

Review profile: CHILL

Plan: Pro

Run ID: f493fee9-a533-4d99-8926-e47098187551

📥 Commits

Reviewing files that changed from the base of the PR and between fce9e62 and 3cc0047.

📒 Files selected for processing (4)

• src/plugin.ts
• src/utils/perf.ts
• tests/integration/opencode-loop.integration.test.ts
• tests/unit/perf.test.ts