Add StartupTimings per-phase breakdown to Client::start#2066
Open
jmoseley wants to merge 1 commit into
Open
Conversation
Introduce a `StartupTimings` struct that decomposes the CLI spawn + handshake cost into per-phase millisecond fields, so hosts can attribute "time to first token" startup latency to a specific phase instead of reconstructing it from scattered debug lines. Phases captured: - program_resolve_ms: NEW timer around bundled-CLI resolution/extraction (`resolve::copilot_binary_with_extract_dir`), previously untimed and the prime suspect for cold-start cost on Windows. - process_spawn_ms: subprocess `command.spawn()`. - port_wait_ms: TCP port-announcement wait (tcp transport only). - handshake_ms: `verify_protocol_version` connect round-trip. - session_fs_ms / llm_handler_ms: post-handshake provider-registration RPCs. - total_ms: full Client::start wall-clock. Surfacing is non-breaking: timings are stored on ClientInner via a `OnceLock` and exposed through a new `Client::startup_timings()` getter, plus a single structured `debug!` event. `Client::start`'s return type is unchanged. Existing per-phase debug logs are retained. Co-authored-by: Copilot App <223556219+Copilot@users.noreply.github.com> Copilot-Session: 95834bd3-b7ac-40bc-8bf4-60102600d41a
Contributor
There was a problem hiding this comment.
Pull request overview
Adds per-phase Rust SDK startup timing instrumentation for TTFT analysis.
Changes:
- Introduces the public
StartupTimingstype. - Measures startup phases and exposes them through
Client::startup_timings(). - Emits a consolidated tracing event.
Show a summary per file
| File | Description |
|---|---|
rust/src/startup_timings.rs |
Defines timing fields and duration conversion tests. |
rust/src/lib.rs |
Captures, stores, logs, and exposes startup timings. |
Review details
- Files reviewed: 2/2 changed files
- Comments generated: 2
- Review effort level: Medium
Comment on lines
+1372
to
+1376
| program_resolve_ms = ?timings.program_resolve_ms, | ||
| process_spawn_ms = ?timings.process_spawn_ms, | ||
| port_wait_ms = ?timings.port_wait_ms, | ||
| handshake_ms = ?timings.handshake_ms, | ||
| session_fs_ms = ?timings.session_fs_ms, |
| total_ms = ?timings.total_ms, | ||
| "Client::start timings" | ||
| ); | ||
| let _ = client.inner.startup_timings.set(timings); |
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
Summary
Adds a
StartupTimingsstruct to the Rust SDK that decomposes the CLI spawn + handshake cost ofClient::startinto per-phase millisecond fields. This is Phase 1 of a cross-repo effort to reduce and instrument time to first token (TTFT): the github-app host currently only measures the totalClient::start(config).awaitduration and can't attribute cold-start latency to a specific phase.What's included
New module
rust/src/startup_timings.rswith a#[non_exhaustive]publicStartupTimingsstruct. Fields (allOption<u64>, whole milliseconds):program_resolve_msresolve::copilot_binary_with_extract_dir) — previously completely untimed, and the prime suspect for the large Windows cold-start costprocess_spawn_mscommand.spawn()port_wait_mshandshake_msverify_protocol_versionconnect round-tripsession_fs_mssessionFs.setProviderRPC (when configured)llm_handler_msllmInference.setProviderRPC (when configured)total_msClient::startwall-clockEach field is
Someonly when its phase actually runs (e.g.program_resolve_msisNonewhen the caller passes an explicit CLI path;port_wait_msisSomeonly on the TCP transport).Surfacing (non-breaking)
ClientInnervia aOnceLockand exposed through a new getterClient::startup_timings() -> Option<StartupTimings>.debug!("Client::start timings", …)event carries the full breakdown, so hosts don't have to stitch together the individual per-phase debug lines.Client::start's return type is unchanged — no breaking API change for any Rust consumer. Existing per-phase debug logs are retained.spawn_stdio/spawn_tcpsignatures now return their measuredDuration(s) to the caller; these are private helpers, so no public surface changes.Validation
cargo +nightly-2026-04-14 fmt --check— cleancargo clippy --all-features --all-targets -- -D warnings— cleancargo test --lib— 200/200 pass (incl. 2 new unit tests)cargo test --all-features --test e2e— 389/389 passScope
SDK crate only. The github-app host will consume these after a vendored SDK bump (separate follow-up) — this PR does not touch github-app.