Skip to content
Open
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
11 changes: 11 additions & 0 deletions config.example.yaml
Original file line number Diff line number Diff line change
Expand Up @@ -133,6 +133,17 @@ cache:
trusted-upload-keys: []
# - my-cache-1:abcdef0123456789...=
storage:
# Maximum time the NAR read path waits on a storage presence probe before
# treating presence as undetermined (default: 5s). Keep it well below your
# reverse-proxy read timeout. The local backend's probe is an os.Stat, which
# bottoms out in an uncancellable fstatat(2): on a hard NFS mount a single one
# has been measured blocking ~57s, long enough for the proxy to abort the
# response mid-body and hand the client a 200 with a truncated body. 5s sits an
# order of magnitude above a healthy probe (8-300ms) and an order of magnitude
# below a 60s proxy timeout, so it fires only on genuine pathology.
# A timed-out probe is treated as undetermined, never as a cache miss, so it
# never becomes a spurious 404. Set to 0 to disable the bound (rollback).
stat-timeout: 5s
# The local data path used for configuration and cache storage
# Use this OR S3 storage (cache.storage.s3.bucket) - not both
local: "/var/lib/ncps"
Expand Down
44 changes: 44 additions & 0 deletions nix/e2e-tests/src/client.py
Original file line number Diff line number Diff line change
Expand Up @@ -14,13 +14,26 @@
import os
import subprocess
import sys
import time
import urllib.error
import urllib.request
from dataclasses import dataclass
from typing import Dict, Optional, Tuple

from harness_config import REPO_ROOT, VAR_NCPS


@dataclass
class TimedResponse:
"""An HTTP response with its time-to-first-byte recorded."""

status: int
headers: Dict[str, str]
body: bytes
ttfb_seconds: float
total_seconds: float


class Client:
"""Talks to a single ncps replica at ``base_url``."""

Expand All @@ -34,6 +47,37 @@ def get(self, path: str, timeout: int = 300) -> Tuple[int, Dict[str, str], bytes
with urllib.request.urlopen(url, timeout=timeout) as r:
return r.status, dict(r.headers), r.read()

def get_timed(self, path: str, timeout: int = 300) -> "TimedResponse":
"""GET ``path``, measuring time-to-first-byte separately from completion.

TTFB is the interval from issuing the request to the first *body* byte
arriving. That is the number a reverse proxy's read timeout actually
governs, and it is the one that mattered in production: every NAR in the
failing runs was byte-perfect but took ~57s to its first byte, so the
ingress aborted the response mid-body and the client saw a truncated 200.
Asserting only on bytes cannot see that; asserting on total duration
conflates a slow start with a large payload.
"""
url = self.base_url + "/" + path.lstrip("/")
started = time.monotonic()
with urllib.request.urlopen(url, timeout=timeout) as r:
first = r.read(1)
ttfb = time.monotonic() - started
chunks = [first]
while True:
block = r.read(1 << 20)
if not block:
break
chunks.append(block)
body = b"".join(chunks)
return TimedResponse(
status=r.status,
headers=dict(r.headers),
body=body,
ttfb_seconds=ttfb,
total_seconds=time.monotonic() - started,
)

def head(self, path: str, timeout: int = 30) -> Tuple[int, Dict[str, str]]:
url = self.base_url + "/" + path.lstrip("/")
req = urllib.request.Request(url, method="HEAD")
Expand Down
39 changes: 38 additions & 1 deletion nix/e2e-tests/src/phases/serve.py
Original file line number Diff line number Diff line change
Expand Up @@ -8,12 +8,32 @@

from __future__ import annotations

import os

from client import canonical_nar_sha256, hash_of_store_path, realise_package
from harness_config import check, section
from harness_config import check, log, section

# Small package — short closure, fast to fetch through ncps.
SERVE_PKG = "nixpkgs#hello"

# Budget for time-to-first-byte on a warm NAR read, in seconds.
#
# A NAR that is already in the store must begin streaming promptly. In production
# this exact path — serving a NAR already present in storage — stalled ~57s in a
# single uncancellable stat on an NFS mount, and the ingress (60s read timeout)
# aborted the response mid-body, handing the client a 200 with a truncated body.
# Every byte was correct; only the latency was wrong, so byte-comparison alone
# scored it a PASS.
#
# The budget is deliberately far below any reverse-proxy read timeout and far
# above a healthy read (8-300ms observed), so it flags pathology without being
# fragile on a loaded CI runner.
TTFB_BUDGET_SECONDS = float(os.environ.get("NCPS_E2E_TTFB_BUDGET_SECONDS", "15"))

# The client timeout must exceed the budget, so a stall is reported as a measured
# budget violation rather than an opaque client timeout with no number attached.
TTFB_CLIENT_TIMEOUT = int(TTFB_BUDGET_SECONDS * 6)


def run(deployment, scenario) -> None:
section(f"SERVE — {scenario.name}")
Expand All @@ -38,5 +58,22 @@ def run(deployment, scenario) -> None:
)
digests.append(digest)

# Re-fetch the now-warm NAR and measure time-to-first-byte. This is the
# production failure shape: the NAR is present and correct, but the first
# byte arrives too late to survive a reverse proxy.
timed = c.get_timed("/" + fields["URL"].lstrip("/"), timeout=TTFB_CLIENT_TIMEOUT)
log(
f"replica {i}: warm NAR ttfb={timed.ttfb_seconds:.3f}s "
f"total={timed.total_seconds:.3f}s bytes={len(timed.body)} "
f"(budget {TTFB_BUDGET_SECONDS:.1f}s)"
)
check(timed.status == 200, f"replica {i}: warm NAR re-read returned 200")
check(
timed.ttfb_seconds < TTFB_BUDGET_SECONDS,
f"replica {i}: warm NAR time-to-first-byte {timed.ttfb_seconds:.3f}s "
f"is within the {TTFB_BUDGET_SECONDS:.1f}s budget "
f"(a byte-correct but slow response is a FAILURE, not a pass)",
)

if len(digests) > 1:
check(len(set(digests)) == 1, "all replicas served byte-identical NARs")
125 changes: 125 additions & 0 deletions nix/e2e-tests/tests/test_client_ttfb.py
Original file line number Diff line number Diff line change
@@ -0,0 +1,125 @@
"""Unit tests for the harness client's time-to-first-byte measurement.

TTFB is the assertion that would have caught the production stall: every NAR in
the failing runs was byte-perfect, but the first byte arrived ~57s late, so the
ingress aborted the response mid-body and the client saw a truncated 200. A
harness that only compares bytes — and waits up to 900s to do it — scores that
as a PASS. These tests pin the measurement itself against a stub server whose
first byte is deliberately late.
"""

from __future__ import annotations

import threading
import time
from http.server import BaseHTTPRequestHandler, HTTPServer

import pytest

from client import Client


def _make_server(delay_before_first_byte: float, body: bytes):
"""An HTTP server that stalls `delay` seconds before the first body byte.

Headers (and the 200) are sent immediately, then the body is withheld. That
is exactly the production shape: the status line commits, and the stall
happens afterwards, so anything measuring only the status or the final bytes
sees nothing wrong.
"""

class Handler(BaseHTTPRequestHandler):
protocol_version = "HTTP/1.1"

def do_GET(self): # noqa: N802 — BaseHTTPRequestHandler's required name
self.send_response(200)
self.send_header("Content-Type", "application/octet-stream")
self.send_header("Content-Length", str(len(body)))
self.end_headers()
self.wfile.flush()

time.sleep(delay_before_first_byte)

self.wfile.write(body)
self.wfile.flush()

def log_message(self, *_args):
pass # keep test output quiet

server = HTTPServer(("127.0.0.1", 0), Handler)
Comment thread
kalbasit marked this conversation as resolved.
Dismissed
thread = threading.Thread(target=server.serve_forever, daemon=True)
thread.start()

return server, f"http://127.0.0.1:{server.server_port}"
Comment thread
kalbasit marked this conversation as resolved.
Dismissed


def test_ttfb_measures_the_stall_not_the_payload():
body = b"x" * 4096
server, base = _make_server(1.0, body)

try:
resp = Client(base).get_timed("/slow", timeout=30)
finally:
server.shutdown()

assert resp.status == 200
assert resp.body == body, "the body must still be delivered intact"
assert resp.ttfb_seconds >= 1.0, "TTFB must include the pre-body stall"
assert resp.total_seconds >= resp.ttfb_seconds


def test_fast_response_has_small_ttfb():
body = b"y" * 4096
server, base = _make_server(0.0, body)

try:
resp = Client(base).get_timed("/fast", timeout=30)
finally:
server.shutdown()

assert resp.status == 200
assert resp.body == body
assert resp.ttfb_seconds < 1.0, "a healthy response must not be flagged as slow"


def test_byte_correct_but_slow_is_distinguishable_from_fast():
"""The regression guard: identical bytes, different TTFB.

Both responses are byte-identical, so a bytes-only assertion cannot tell them
apart. TTFB can, and must.
"""
body = b"z" * 4096

slow_server, slow_base = _make_server(1.0, body)
fast_server, fast_base = _make_server(0.0, body)

try:
slow = Client(slow_base).get_timed("/slow", timeout=30)
fast = Client(fast_base).get_timed("/fast", timeout=30)
finally:
slow_server.shutdown()
fast_server.shutdown()

assert slow.body == fast.body, "precondition: the payloads are identical"
assert slow.ttfb_seconds > fast.ttfb_seconds + 0.5, (
"a byte-correct but slow response must be distinguishable from a fast one; "
"this is the distinction the production stall hid from every existing scenario"
)


@pytest.mark.parametrize("budget", [0.25])
def test_budget_violation_is_detectable(budget):
"""A declared budget must be able to fail a byte-correct response."""
body = b"w" * 1024
server, base = _make_server(1.0, body)

try:
resp = Client(base).get_timed("/slow", timeout=30)
finally:
server.shutdown()

assert resp.status == 200
assert resp.body == body
assert resp.ttfb_seconds > budget, (
"the stub stalls 1s against a 0.25s budget, so this must register as a violation"
)
2 changes: 1 addition & 1 deletion nix/packages/ncps/default.nix
Original file line number Diff line number Diff line change
Expand Up @@ -15,7 +15,7 @@
in
if tag != "" then tag else rev;

vendorHash = "sha256-S+hZRSEpD4oxXtgoGy3J6yMX80kvf0RwK+zIRuy/kbA=";
vendorHash = "sha256-z3a7XTR5jcVsIdbvK0bOYFx7JTrRwXOEoEeUrfZf9w4=";

ncpsSrc = lib.fileset.toSource {
fileset = lib.fileset.unions [
Expand Down
Original file line number Diff line number Diff line change
@@ -0,0 +1,2 @@
schema: spec-driven
created: 2026-08-25
Loading