Skip to content

Measure startup time - #1181

Open
hugo-ccabral wants to merge 1 commit into
mainfrom
ft/measure-startup-time
Open

Measure startup time#1181
hugo-ccabral wants to merge 1 commit into
mainfrom
ft/measure-startup-time

Conversation

@hugo-ccabral

@hugo-ccabral hugo-ccabral commented May 1, 2026

Copy link
Copy Markdown
Contributor

Summary by cubic

Adds phase-based startup timing and a true readiness signal. New /_ready waits until the worker serves its first request and returns startup phase timings.

  • New Features

    • Phase tracker with [phase] logs and phaseSummary(); exposed via /_ready JSON (ready, version, phases, uptime).
    • Instrumented phases: daemon_boot, git_setup, cache_download, manifest_gen, blocks_metadata, worker_ready.
    • /_ready waits for first worker-ready event; supports ?timeout=<ms> (30s default, 120s max). CORS enabled; non-ready returns 503.
  • Migration

    • Use /_ready for readiness checks; keep /_healthcheck or /deco/_liveness for liveness.
    • Optionally set a custom timeout when polling from CI or admin tools.

Written for commit 89d90f6. Summary will update on new commits. Review in cubic

Summary by CodeRabbit

New Features

  • Added a readiness endpoint (GET /_ready) that returns daemon version, worker readiness state, and initialization phase timings in JSON format
  • Endpoint returns HTTP 200 when daemon is ready and HTTP 503 on timeout; timeout duration is configurable via query parameter

@coderabbitai

coderabbitai Bot commented May 1, 2026

Copy link
Copy Markdown
📝 Walkthrough

Walkthrough

This PR introduces phase-based instrumentation for daemon startup, tracking key initialization steps with timing and outcomes. A new readiness endpoint (GET /_ready) exposes JSON containing worker readiness state, daemon version, and phase metrics. Worker readiness primitives enable querying whether the worker has reached ready state for the first time.

Changes

Cohort / File(s) Summary
Phase Instrumentation Framework
daemon/phases.ts
New module providing phaseStart() and phaseEnd() functions to record initialization phase timings and outcomes in memory. Includes phaseSummary() API that returns boot start time, uptime, and per-phase status (duration, outcome, or pending state) without requiring log parsing.
Daemon Initialization & Readiness Endpoint
daemon/main.ts
Instruments daemon boot, git setup, cache download, manifest generation, and blocks metadata generation with phase tracking calls. Introduces GET /_ready HTTP endpoint that returns JSON with worker readiness state, daemon version, and phase timings; honors optional timeout query parameter and returns 200 when ready or 503 on timeout.
Worker Readiness Tracking
daemon/worker.ts
Adds isWorkerEverReady() boolean accessor and waitForFirstReady() promise primitive to track whether worker has reached ready state. Calls phaseEnd("worker_ready") on first ready transition and attaches error handler to prevent unhandled rejections.

Sequence Diagram

sequenceDiagram
    participant Client
    participant Daemon as Daemon (/_ready)
    participant Phases as Phase Tracker
    participant Worker

    Note over Daemon: Daemon Startup
    Daemon->>Phases: phaseStart("daemon_boot")
    Daemon->>Phases: phaseEnd("daemon_boot", "ok")
    
    Daemon->>Phases: phaseStart("git_setup")
    Daemon->>Phases: phaseEnd("git_setup", "ok")
    
    Daemon->>Phases: phaseStart("cache_download")
    Daemon->>Phases: phaseEnd("cache_download", "skipped")
    
    Daemon->>Phases: phaseStart("manifest_generation")
    Daemon->>Phases: phaseEnd("manifest_generation", "ok")
    
    Note over Worker: Worker Initialization
    Worker->>Phases: phaseStart("worker_ready")
    Worker->>Worker: dispatchWorkerState("ready")
    Worker->>Phases: phaseEnd("worker_ready", "ok")
    
    Note over Client: User Readiness Check
    Client->>Daemon: GET /_ready?timeout=5000
    Daemon->>Worker: isWorkerEverReady()
    Daemon->>Phases: phaseSummary()
    Daemon->>Client: 200 {ready: true, version: "X.Y.Z", phases: {...}}
Loading

Estimated code review effort

🎯 3 (Moderate) | ⏱️ ~20 minutes

Poem

🐰 A daemon awakens with phases so bright,
Each step marked and timed through the startup night,
The worker stands ready, its signal rings clear,
And travellers ask "Are you there?" without fear,
With /\_ready endpoint, the answer's sincere! ✨

🚥 Pre-merge checks | ✅ 5
✅ Passed checks (5 passed)
Check name Status Explanation
Description Check ✅ Passed Check skipped - CodeRabbit’s high-level summary is enabled.
Title check ✅ Passed The title 'Measure startup time' directly and concisely reflects the main change: adding phase instrumentation to track daemon startup timing with a readiness endpoint.
Docstring Coverage ✅ Passed No functions found in the changed files to evaluate docstring coverage. Skipping docstring coverage check.
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.

✨ Finishing Touches
📝 Generate docstrings
  • Create stacked PR
  • Commit on current branch
🧪 Generate unit tests (beta)
  • Create PR with unit tests
  • Commit unit tests in branch ft/measure-startup-time

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
Review rate limit: 7/8 reviews remaining, refill in 7 minutes and 30 seconds.

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

@github-actions

github-actions Bot commented May 1, 2026

Copy link
Copy Markdown
Contributor

Tagging Options

Should a new tag be published when this PR is merged?

  • 👍 for Patch 1.197.1 update
  • 🎉 for Minor 1.198.0 update
  • 🚀 for Major 2.0.0 update

@coderabbitai coderabbitai Bot left a comment

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Actionable comments posted: 3

🤖 Prompt for all review comments with AI agents
Verify each finding against the current code and only fix it if needed.

Inline comments:
In `@daemon/main.ts`:
- Around line 314-320: The cache download errors are being swallowed and
phaseEnd("cache_download") is still called as if successful; update the
SANDBOX_MODE block around downloadCache(siteName) so the catch captures the
error, logs it, and calls phaseEnd with a non-ok outcome (e.g.,
phaseEnd("cache_download", "failure") or the appropriate failure payload your
phaseEnd accepts) instead of the default success; reference SANDBOX_MODE,
downloadCache, phaseStart, and phaseEnd to locate and change the code.

In `@daemon/worker.ts`:
- Around line 43-47: The ready phase is being ended without ever being started,
so change the block that handles state === "ready" && !everReady to call
phaseStart("worker_ready") before calling phaseEnd("worker_ready") (i.e., invoke
phaseStart("worker_ready") then phaseEnd("worker_ready") and only then set
everReady = true and call firstReady.resolve()); this ensures the ready phase
records a real duration instead of bootstrapping a zero-length record; reference
the variables/state names state, everReady, phaseStart, phaseEnd, and
firstReady.resolve in the worker.ts block.
- Around line 25-29: resetWorkerState() currently only recreates the worker
proxy (wp) but leaves the readiness latch variables firstReady and everReady
unchanged, causing /_ready to short-circuit after undeploy/redeploy; update
resetWorkerState() to reinitialize firstReady to a new
Promise.withResolvers<void>() and set everReady = false, and immediately attach
firstReady.promise.catch(() => {}) to prevent unhandled rejections so the
readiness logic (firstReady, everReady, and any code that resolves firstReady)
reflects the new worker lifecycle.
🪄 Autofix (Beta)

Fix all unresolved CodeRabbit comments on this PR:

  • Push a commit to this branch (recommended)
  • Create a new PR with the fixes

ℹ️ Review info
⚙️ Run configuration

Configuration used: defaults

Review profile: CHILL

Plan: Pro

Run ID: 4eb4d6ed-786b-4d29-a19b-9d44d0fd334b

📥 Commits

Reviewing files that changed from the base of the PR and between 2666148 and 89d90f6.

📒 Files selected for processing (3)
  • daemon/main.ts
  • daemon/phases.ts
  • daemon/worker.ts

Comment thread daemon/main.ts
Comment on lines 314 to +320
if (SANDBOX_MODE) {
start = performance.now();
phaseStart("cache_download");
await downloadCache(siteName).catch((err) => {
console.warn(`[cache] Failed to download build cache: ${err.message}`);
});
phaseEnd("cache_download");

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

⚠️ Potential issue | 🟡 Minor | ⚡ Quick win

Mark failed cache downloads explicitly.

The cache download error is swallowed, but the phase is still ended with the default ok outcome. That makes the startup metrics report success even when the cache was unavailable.

Suggested fix
-      await downloadCache(siteName).catch((err) => {
-        console.warn(`[cache] Failed to download build cache: ${err.message}`);
-      });
-      phaseEnd("cache_download");
+      const cacheOutcome = await downloadCache(siteName)
+        .then(() => "ok" as const)
+        .catch((err) => {
+          console.warn(
+            `[cache] Failed to download build cache: ${err.message}`,
+          );
+          return "fail" as const;
+        });
+      phaseEnd("cache_download", cacheOutcome);
🤖 Prompt for AI Agents
Verify each finding against the current code and only fix it if needed.

In `@daemon/main.ts` around lines 314 - 320, The cache download errors are being
swallowed and phaseEnd("cache_download") is still called as if successful;
update the SANDBOX_MODE block around downloadCache(siteName) so the catch
captures the error, logs it, and calls phaseEnd with a non-ok outcome (e.g.,
phaseEnd("cache_download", "failure") or the appropriate failure payload your
phaseEnd accepts) instead of the default success; reference SANDBOX_MODE,
downloadCache, phaseStart, and phaseEnd to locate and change the code.

Comment thread daemon/worker.ts
Comment on lines +25 to +29
const firstReady = Promise.withResolvers<void>();
// Prevent unhandled rejection if the daemon shuts down before the worker
// ever becomes ready — callers handle the race against their own timeouts.
firstReady.promise.catch(() => {});
let everReady = false;

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

⚠️ Potential issue | 🟠 Major | ⚡ Quick win

Reset the readiness state on undeploy.

resetWorkerState() only recreates wp; firstReady and everReady stay latched across deploys. After a sandbox undeploy/redeploy, / _ready will short-circuit to 200 before the new worker has actually become ready.

Suggested fix
-const firstReady = Promise.withResolvers<void>();
+let firstReady = Promise.withResolvers<void>();
 ...
 export const resetWorkerState = () => {
   workerInitFailed = false;
   wp = makeWp();
+  firstReady = Promise.withResolvers<void>();
+  firstReady.promise.catch(() => {});
+  everReady = false;
 };

Also applies to: 72-75

🤖 Prompt for AI Agents
Verify each finding against the current code and only fix it if needed.

In `@daemon/worker.ts` around lines 25 - 29, resetWorkerState() currently only
recreates the worker proxy (wp) but leaves the readiness latch variables
firstReady and everReady unchanged, causing /_ready to short-circuit after
undeploy/redeploy; update resetWorkerState() to reinitialize firstReady to a new
Promise.withResolvers<void>() and set everReady = false, and immediately attach
firstReady.promise.catch(() => {}) to prevent unhandled rejections so the
readiness logic (firstReady, everReady, and any code that resolves firstReady)
reflects the new worker lifecycle.

Comment thread daemon/worker.ts
Comment on lines +43 to +47
if (state === "ready" && !everReady) {
everReady = true;
phaseEnd("worker_ready");
firstReady.resolve();
}

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

⚠️ Potential issue | 🟠 Major | ⚡ Quick win

Start worker_ready before ending it.

phaseEnd("worker_ready") currently runs without a matching phaseStart(), and phaseEnd() bootstraps missing records with durationMs: 0. That makes the new readiness payload report a zero-length ready phase instead of time-to-ready.

🤖 Prompt for AI Agents
Verify each finding against the current code and only fix it if needed.

In `@daemon/worker.ts` around lines 43 - 47, The ready phase is being ended
without ever being started, so change the block that handles state === "ready"
&& !everReady to call phaseStart("worker_ready") before calling
phaseEnd("worker_ready") (i.e., invoke phaseStart("worker_ready") then
phaseEnd("worker_ready") and only then set everReady = true and call
firstReady.resolve()); this ensures the ready phase records a real duration
instead of bootstrapping a zero-length record; reference the variables/state
names state, everReady, phaseStart, phaseEnd, and firstReady.resolve in the
worker.ts block.

@cubic-dev-ai cubic-dev-ai Bot left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

3 issues found across 3 files

Prompt for AI agents (unresolved issues)

Check if these issues are valid — if so, understand the root cause of each and fix them. If appropriate, use sub-agents to investigate and fix each issue separately.


<file name="daemon/main.ts">

<violation number="1" location="daemon/main.ts:320">
P2: The cache download error is caught and swallowed, but `phaseEnd("cache_download")` still runs with the default `"ok"` outcome. This causes startup metrics to report a successful cache download even when it failed. Capture the outcome from the `.catch()` and pass it to `phaseEnd`.</violation>

<violation number="2" location="daemon/main.ts:605">
P2: `/_ready` can report a false positive after sandbox redeploys because it short-circuits on a global `everReady` flag that is never reset by `resetWorkerState()`.</violation>
</file>

<file name="daemon/worker.ts">

<violation number="1" location="daemon/worker.ts:45">
P2: `phaseEnd("worker_ready")` is called here without a corresponding `phaseStart("worker_ready")` anywhere. The `phaseEnd` implementation bootstraps a missing record with `durationMs: 0`, so the readiness phase will always report zero duration instead of actual time-to-ready. Add a `phaseStart("worker_ready")` call at the point the worker is created/started.</violation>
</file>

Reply with feedback, questions, or to request a fix. Tag @cubic-dev-ai to re-run a review.

Comment thread daemon/main.ts
{ status: ready ? 200 : 503, headers },
);

if (isWorkerEverReady()) return respond(true);

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

P2: /_ready can report a false positive after sandbox redeploys because it short-circuits on a global everReady flag that is never reset by resetWorkerState().

Prompt for AI agents
Check if this issue is valid — if so, understand the root cause and fix it. At daemon/main.ts, line 605:

<comment>`/_ready` can report a false positive after sandbox redeploys because it short-circuits on a global `everReady` flag that is never reset by `resetWorkerState()`.</comment>

<file context>
@@ -550,6 +564,54 @@ app.get("/_healthcheck", (c) => {
+      { status: ready ? 200 : 503, headers },
+    );
+
+  if (isWorkerEverReady()) return respond(true);
+
+  const ready = await Promise.race([
</file context>

Comment thread daemon/main.ts
await downloadCache(siteName).catch((err) => {
console.warn(`[cache] Failed to download build cache: ${err.message}`);
});
phaseEnd("cache_download");

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

P2: The cache download error is caught and swallowed, but phaseEnd("cache_download") still runs with the default "ok" outcome. This causes startup metrics to report a successful cache download even when it failed. Capture the outcome from the .catch() and pass it to phaseEnd.

Prompt for AI agents
Check if this issue is valid — if so, understand the root cause and fix it. At daemon/main.ts, line 320:

<comment>The cache download error is caught and swallowed, but `phaseEnd("cache_download")` still runs with the default `"ok"` outcome. This causes startup metrics to report a successful cache download even when it failed. Capture the outcome from the `.catch()` and pass it to `phaseEnd`.</comment>

<file context>
@@ -305,9 +313,11 @@ const createDeps = (
       await downloadCache(siteName).catch((err) => {
         console.warn(`[cache] Failed to download build cache: ${err.message}`);
       });
+      phaseEnd("cache_download");
       logs.push({
         level: "info",
</file context>

Comment thread daemon/worker.ts
broadcast({ type: "worker-status", detail: workerState });
if (state === "ready" && !everReady) {
everReady = true;
phaseEnd("worker_ready");

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

P2: phaseEnd("worker_ready") is called here without a corresponding phaseStart("worker_ready") anywhere. The phaseEnd implementation bootstraps a missing record with durationMs: 0, so the readiness phase will always report zero duration instead of actual time-to-ready. Add a phaseStart("worker_ready") call at the point the worker is created/started.

Prompt for AI agents
Check if this issue is valid — if so, understand the root cause and fix it. At daemon/worker.ts, line 45:

<comment>`phaseEnd("worker_ready")` is called here without a corresponding `phaseStart("worker_ready")` anywhere. The `phaseEnd` implementation bootstraps a missing record with `durationMs: 0`, so the readiness phase will always report zero duration instead of actual time-to-ready. Add a `phaseStart("worker_ready")` call at the point the worker is created/started.</comment>

<file context>
@@ -21,9 +22,29 @@ export type WorkerStatus = { state: "updating" | "ready" };
   broadcast({ type: "worker-status", detail: workerState });
+  if (state === "ready" && !everReady) {
+    everReady = true;
+    phaseEnd("worker_ready");
+    firstReady.resolve();
+  }
</file context>

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant