firewall: bound, retry and report the GitHub ranges fetch #60

Merged

branderson merged 7 commits from firewall-fetch-timeout into main 2026-08-03 03:51:31 -07:00

Conversation 0 Commits 7 Files Changed 5

+580 -42

branderson commented 2026-08-03 01:06:48 -07:00

Owner

Copy Link

Copy Source

Fixes #59.

What the fault actually was

The transport test in runtime.bats detached its container and asked
docker logs for the output afterwards. The stdout half arrived complete; the
stderr half never arrived at all.

That single fact accounts for the whole sequence. The test asserts on
entrypoint.sh's FATAL: SANDBOX_ANTHROPIC_TRANSPORT is set to 'Loopback'
message — written to stderr — so the assertion failed while the container was
behaving perfectly. And every diagnostic added along the way to explain the
failure also wrote to stderr, so each fix appeared to do nothing and pointed at
a different phantom.

Measurement, not inspection, is what finally showed it: the captured output was
2100 bytes and then 2189 bytes, each exactly the length of the visible text.
Nothing was truncated. Something was simply absent.

The test now runs its container in the foreground, so docker run attaches
to the container's streams directly — nothing buffered, flushed or dropped in
between — and one command yields both the output and the exit status, with no
docker wait, no settling and no read-after-exit race. Less machinery than what
it replaces.

The bugs found on the way

These are real and independently worth having, but none of them was the cause.

1. Two pipelines assigned directly under set -euo pipefail.

gh_ranges=$(curl -s ${gh_auth[@]+"${gh_auth[@]}"} https://api.github.com/meta)
ips=$(dig +noall +answer A "$domain" | awk '$4 == "A" {print $5}')

In that form a failure kills the script on the assignment, before the
diagnostics written for it can run:

$ bash -c 'set -euo pipefail
  echo "Looking up..."; out=$(curl -s --connect-timeout 1 https://198.51.100.1/meta)
  if [ -z "$out" ]; then echo "ERROR: Empty response"; exit 1; fi
  echo "reached the diagnostics"'
Looking up...
$ echo $?    # 7 - the ERROR branch is unreachable

Both now capture the status and report it. The fetch also had no deadline at
all — curl has no default overall timeout — and neither was retried, though
both failure modes are transient. Three bounded attempts each, and the fetch's
retry wraps the response check too, since a burst of container starts trips
GitHub's secondary rate limit, which answers with a JSON body rather than a
transport error.

2. The extra-domains loop contradicted its own comment. Failures there are
documented as non-fatal, and that held for a domain resolving to nothing but not
for one whose lookup errored — pipefail took the whole script down instead of
warning and skipping.

3. Nothing in the startup path could report where it aborted. -E and an
ERR trap now go in init-firewall.sh, dns-proxy.sh and entrypoint.sh,
naming the script, line and failing command. -E is load-bearing: without
errtrace the handler does not fire inside functions or subshells, which is where
the fetch and both loops live. log-shipper.sh is excluded deliberately.

4. runtime.bats could run against an image that isn't the checkout.
$IMAGE is one mutable tag on a shared daemon, and CI sets SKIP_BUILD=1
because it builds in an earlier step — and the runner has no daemon of its own,
so that tag is shared with anything built by hand on the host. setup_file now
compares md5s of the three startup scripts against the image and refuses to run
if they differ. A guard, not a fix: it stops thirty-seven tests reporting on code
that is not under test.

5. The test discarded its own evidence — captured the log into a variable,
asserted with [[ ]], and removed the container on the line before. bats prints
the expression, not the variable. Failures now print the exit code, the byte
count and the container's state.

wait_ready goes 60s → 120s, since a fetch that loses two attempts before
succeeding now spends ~26s of the budget.

Testing

Seventeen new bats tests. The behavioural ones drive the real functions —
extracted from init-firewall.sh, which cannot be sourced because it flushes
iptables at the top level — against stubbed curl and dig on PATH. No
container, no network:

• the fetch: returns the body; reports a failing curl instead of dying on the
  assignment; retries a rate-limit body and surfaces its message; recovers on a
  later attempt; names an empty response as empty
• resolution: returns the A records; reports a failing dig with its own message;
  distinguishes a CNAME-only answer from a failed lookup; recovers on a later
  attempt
• the ERR trap: extracted from the real file and fired, asserting it reports the
  failing line and command — which catches quoting the trap body so $LINENO
  and $BASH_COMMAND expand at definition time and it reports its own line
  forever
• the image guard: driven against a stubbed docker, naming the one file that
  differs and staying silent when all three agree

Plus greps guarding the shapes, and the existing container-start/--network
count updated to include foreground starts.

Checked in both directions, not just the passing one: the behavioural tests fail
when the retry loops are cut to one attempt, and every grep fails when the old
construct is restored or the trap renamed.

Full fast suite and the full runtime suite both pass.

Fixes #59. ## What the fault actually was The transport test in `runtime.bats` detached its container and asked `docker logs` for the output afterwards. The stdout half arrived complete; the stderr half never arrived at all. That single fact accounts for the whole sequence. The test asserts on `entrypoint.sh`'s `FATAL: SANDBOX_ANTHROPIC_TRANSPORT is set to 'Loopback'` message — written to stderr — so the assertion failed while the container was behaving perfectly. And every diagnostic added along the way to explain the failure also wrote to stderr, so each fix appeared to do nothing and pointed at a different phantom. Measurement, not inspection, is what finally showed it: the captured output was 2100 bytes and then 2189 bytes, each **exactly** the length of the visible text. Nothing was truncated. Something was simply absent. The test now runs its container in the **foreground**, so `docker run` attaches to the container's streams directly — nothing buffered, flushed or dropped in between — and one command yields both the output and the exit status, with no `docker wait`, no settling and no read-after-exit race. Less machinery than what it replaces. ## The bugs found on the way These are real and independently worth having, but none of them was the cause. **1. Two pipelines assigned directly under `set -euo pipefail`.** ```sh gh_ranges=$(curl -s ${gh_auth[@]+"${gh_auth[@]}"} https://api.github.com/meta) ips=$(dig +noall +answer A "$domain" | awk '$4 == "A" {print $5}') ``` In that form a failure kills the script *on the assignment*, before the diagnostics written for it can run: ``` $ bash -c 'set -euo pipefail echo "Looking up..."; out=$(curl -s --connect-timeout 1 https://198.51.100.1/meta) if [ -z "$out" ]; then echo "ERROR: Empty response"; exit 1; fi echo "reached the diagnostics"' Looking up... $ echo $? # 7 - the ERROR branch is unreachable ``` Both now capture the status and report it. The fetch also had **no deadline at all** — `curl` has no default overall timeout — and neither was retried, though both failure modes are transient. Three bounded attempts each, and the fetch's retry wraps the *response check* too, since a burst of container starts trips GitHub's secondary rate limit, which answers with a JSON body rather than a transport error. **2. The extra-domains loop contradicted its own comment.** Failures there are documented as non-fatal, and that held for a domain resolving to nothing but not for one whose lookup *errored* — pipefail took the whole script down instead of warning and skipping. **3. Nothing in the startup path could report where it aborted.** `-E` and an `ERR` trap now go in `init-firewall.sh`, `dns-proxy.sh` and `entrypoint.sh`, naming the script, line and failing command. `-E` is load-bearing: without errtrace the handler does not fire inside functions or subshells, which is where the fetch and both loops live. `log-shipper.sh` is excluded deliberately. **4. `runtime.bats` could run against an image that isn't the checkout.** `$IMAGE` is one mutable tag on a shared daemon, and CI sets `SKIP_BUILD=1` because it builds in an earlier step — and the runner has no daemon of its own, so that tag is shared with anything built by hand on the host. `setup_file` now compares md5s of the three startup scripts against the image and refuses to run if they differ. A guard, not a fix: it stops thirty-seven tests reporting on code that is not under test. **5. The test discarded its own evidence** — captured the log into a variable, asserted with `[[ ]]`, and removed the container on the line before. bats prints the expression, not the variable. Failures now print the exit code, the byte count and the container's state. `wait_ready` goes 60s → 120s, since a fetch that loses two attempts before succeeding now spends ~26s of the budget. ## Testing Seventeen new bats tests. The behavioural ones drive the **real** functions — extracted from `init-firewall.sh`, which cannot be sourced because it flushes iptables at the top level — against stubbed `curl` and `dig` on `PATH`. No container, no network: - the fetch: returns the body; reports a failing curl instead of dying on the assignment; retries a rate-limit body and surfaces its message; recovers on a later attempt; names an empty response as empty - resolution: returns the A records; reports a failing dig with its own message; distinguishes a CNAME-only answer from a failed lookup; recovers on a later attempt - the ERR trap: extracted from the real file and fired, asserting it reports the failing line and command — which catches quoting the trap body so `$LINENO` and `$BASH_COMMAND` expand at definition time and it reports its own line forever - the image guard: driven against a stubbed docker, naming the one file that differs and staying silent when all three agree Plus greps guarding the shapes, and the existing container-start/`--network` count updated to include foreground starts. Checked in both directions, not just the passing one: the behavioural tests fail when the retry loops are cut to one attempt, and every grep fails when the old construct is restored or the trap renamed. Full fast suite and the full runtime suite both pass.

branderson added 1 commit 2026-08-03 01:06:49 -07:00

firewall: bound, retry and report the GitHub ranges fetch ... 1a722fc076

init-firewall.sh runs under `set -euo pipefail`, and pulled GitHub's
published ranges with a bare `gh_ranges=$(curl -s ...)`. Three separate
problems compounded into one:

`curl` has no default overall timeout, so with neither --max-time nor
--connect-timeout the call had no deadline at all - it waited as long as
the kernel kept retrying the SYN, and the container's startup waited with
it.

When it did fail, `set -e` took the script down ON THE ASSIGNMENT. The
"ERROR: Empty response fetching GitHub's IP ranges" branch below it is
unreachable in that case - it can only fire when curl exits 0 with an
empty body - so the careful diagnostics written for a failed fetch never
ran for the most likely failure. The container exited having printed
nothing after "Looking up GitHub's IP ranges...", which reads as the
sandbox being broken rather than as GitHub being unreachable.

And nothing was retried, though both failure modes here are transient: a
network blip cost the whole launch, and a burst of container starts can
trip GitHub's secondary rate limit, which answers with a JSON body rather
than a transport error. The retry therefore wraps the response check as
well as the transfer - curl's own --retry would not cover the second case.

Three attempts, each bounded at 10s with a 5s connect timeout, delays of
2s and 4s: ~36s worst case, against an unbounded wait before. Each
attempt says why it failed, and curl keeps -S so its own reason ("Operation
timed out after ...") reaches the log too.

The two firewall self-checks further down get --max-time as well. They sit
inside `if`, so set -e cannot take the script down there, but
--connect-timeout alone does not bound a transfer that connects and then
stalls.

Also makes the failure legible from the test side. runtime.bats's
transport test captured the container log into a variable, asserted against
it with `[[ ]]`, and removed the container on the line before - so when a
container exited 1 somewhere earlier in the entrypoint it presented
identically to the check under test being broken, and the one artefact that
would have named the cause was discarded. It now prints the exit code and
the log on every one of those assertions.

wait_ready goes from 60s to 120s: a run that loses two fetch attempts before
succeeding now spends ~26s of the budget on that call, which on a runner
that has just spent three minutes unpacking an image was enough to turn a
recovery into a spurious failure. A longer budget only delays reporting a
stuck startup; nothing there passes on a timeout.

Tested: five new bats tests drive the real fetch function against a stubbed
curl - success, a failing transfer reported rather than swallowed, a rate-
limit body retried and surfaced, recovery on a later attempt, and an empty
response named as empty. Two greps guard the shape against regression: every
runtime fetch carries --max-time, and the ranges fetch is not a bare
assignment again. All five behavioural tests fail if the retry loop is
removed, and both greps fail if the old invocation is restored - checked
both ways. Full fast suite passes.

Refs #59

branderson added 1 commit 2026-08-03 01:17:41 -07:00

container: make a startup abort say where it happened ... 94c63aed60

Follow-up to the fetch fix in this branch, from the same root cause showing
up in a second place. The runtime suite's transport test, with the log dump
this branch adds, produced:

    Reinstating captured Docker DNS rules
    Looking up GitHub's IP ranges...
    Loading GitHub's ranges into the ipset...
      + 4.208.26.197/32
      ... (GitHub ranges) ...
    Looking up registry.npmjs.org...
    Looking up platform.claude.com...
    Looking up gitlab.com...
    Looking up pypi.org...
    Looking up files.pythonhosted.org...
      + 151.101.192.223 (files.pythonhosted.org)

and then nothing, exit 1. Five of eight fixed domains resolved, and the
script died in the loop without a word - the same silent `set -e` abort as
the GitHub fetch, in a different place.

So rather than patch the second instance, put a floor under all of them:
-E and an ERR trap in each of the three scripts that run during container
startup, naming the script, the line and the failing command. The explicit
`exit 1` paths say more than a trap can and stay exactly as they are; this
only covers what previously said nothing at all.

Each trap names its own script, because the three run back to back into one
log and "aborted at line 128" is useless without knowing whose line 128.
-E rather than plain -e because without errtrace the handler does not fire
inside functions or subshells, which is where the fetch and both resolution
loops live. A failure inside a command substitution therefore reports twice,
once from the subshell and once from the statement - worth the noise, since
for `x=$(a | b)` the first line is the only thing that says whether it was
`a` or `b` that failed.

log-shipper.sh is deliberately left alone: it does not use -e at all, on
purpose, so one bad line does not kill the tailer.

Tested: a grep test holds all three scripts to setting -E and installing a
trap that names them, and a behavioural one extracts the real trap line from
init-firewall.sh and fires it, asserting it reports the failing line number
and command. That second test is what catches the mistake this is most
prone to - single-quoting the trap body wrongly, so $LINENO and $BASH_COMMAND
expand at definition time and it reports its own line forever. Both fail
when the trap is renamed or -E dropped, checked. Full fast suite passes.

Refs #59

branderson added 1 commit 2026-08-03 01:34:19 -07:00

firewall: bound, retry and report the domain lookups too ... d13b1a42b8

The runtime suite aborted a container in the fixed-domain loop twice, at a
different point each time - once after files.pythonhosted.org's addresses,
once immediately after its "Looking up" line with none. A cause that moves
between runs is not a bad domain; it is the lookup itself failing, and

    ips=$(dig +noall +answer A "$domain" | awk '$4 == "A" {print $5}')

under `set -o pipefail` dies on the ASSIGNMENT when dig exits non-zero -
before the "returned nothing" check below it can say anything. Identical in
shape to the GitHub fetch earlier in this branch, and identically invisible.

So the same treatment. resolve_domain retries three times, reports each
attempt with dig's own exit status and output, and distinguishes the two
failures that an empty A list conflates: a lookup that errored, and an
answer that arrived carrying no A records - a CNAME-only response, or one
dnsmasq's stop-dns-rebind refused. Each attempt is bounded with +time=3
+tries=1, because dig's defaults are 5s x 3 tries, so a single unanswered
lookup could spend 45s of a startup budget across three attempts.

Retrying is right on its own terms here, not just as a workaround: these are
the first queries through a dnsmasq that dns-proxy.sh started moments
earlier.

The extra-domains loop below used the same construct, and there it also
contradicted its own comment. Failures there are documented as non-fatal -
"a host may be transiently unresolvable, and that shouldn't prevent the
firewall from coming up" - and that held for a domain that resolved to
nothing, but not for one whose lookup errored: pipefail took the whole
script down rather than warning and skipping. It now goes through
resolve_domain, which makes the comment true.

Tested: six more bats tests drive resolve_domain against a stubbed dig -
records returned, a failing dig reported instead of swallowed (with dig's
own message preserved), a CNAME-only answer distinguished from a failed
lookup, recovery on a later attempt, each attempt bounded, and the
extra-domains loop no longer assigning a dig pipeline directly. The last of
those fails when the bare construct is restored, checked. Full fast suite
passes.

Refs #59

branderson added 1 commit 2026-08-03 01:46:04 -07:00

test: read a container's log after the driver has caught up ... 82da66c29e

`docker wait` returns the moment the container exits, but the json-file log
driver writes asynchronously, so reading the log right then can return one
that stops mid-stream.

This is what the transport test has actually been failing on, and it took
three fixes to the wrong thing to see it. The log ended partway through
init-firewall.sh's domain loop, at a slightly different domain each run,
which read as an abort in that loop. It survived bounding the lookups,
retrying them, and reporting each attempt - and the giveaway was in the last
run: the log ended with no message from an ERR trap that cannot be bypassed,
and no output from a retry that prints on every path before it returns.
Nothing had aborted. The read was short.

settled_logs takes reads until two consecutive ones match, which is the
driver having caught up. It is deliberately content-neutral: waiting for an
expected string would make the wait pass or fail on the very thing the caller
is about to assert. wait_ready's own dump goes through it too - a truncated
log is just as misleading when the container is stuck as when it has exited.

The failure dump now also prints the log's length, because a short read and a
container that died mid-startup are indistinguishable without it. That is the
line that would have ended this three rounds earlier.

Tested: settled_logs driven against a stubbed docker whose first two reads
return a growing prefix and whose third returns the whole thing - it takes
four reads and returns the complete log, where a single read returns the
first line. Full fast suite passes.

Refs #59

branderson added 1 commit 2026-08-03 01:56:28 -07:00

test: capture the container's final state, not just its log ... cbd2c1beaa

Four runs of the transport test have now ended with a log that stops
partway through init-firewall.sh and a container that exited 1, and the
last of them came from an image whose init-firewall.sh cannot fail
silently: it carries an ERR trap that nothing reaching that point can
bypass, and a resolver that prints on every path before it returns -
success, dig failure and no-A-records alike. Verified the code is in the
image, too: the COPY layer was rebuilt (DONE, not CACHED) in the three
builds that included it.

A script cannot both be there and say neither of those things. So the
question is no longer where in the script it aborted - it is whether the
script aborted at all, or whether something is ending the container from
outside. The log cannot tell those apart; `docker inspect` can.

So capture it before the container is removed: exit code, OOMKilled, the
daemon's own Error field, and the start/finish timestamps. Plus a
timestamped tail, which separates a container that stopped dead from one
that stalled first.

No behaviour change, and no new assertion - this only widens what a
failure prints.

Refs #59

branderson added 1 commit 2026-08-03 02:06:21 -07:00

test: refuse to run against an image that isn't this checkout ... ad1c793b64

$IMAGE is a single mutable tag on a shared daemon, and CI sets
SKIP_BUILD=1 because it builds the image in an earlier step - so nothing
in runtime.bats ties the image it tests to the code in the working tree.
When those disagree, every assertion in the file is made against code that
is not under test, and the failure looks exactly like a bug in the code
you are reading.

That is what the transport test has been doing. Its container log is
2100 bytes and ends mid-way through init-firewall.sh's domain loop -
measured, not eyeballed: the visible text is exactly 2100 bytes, so the
log is whole and nothing followed it. But the commit under test carries an
ERR trap that nothing reaching that point can bypass, and a resolver that
prints on every path before it returns. Neither said anything. A script
cannot be running there and produce that log, and the same image tag run
by hand on the host gets all the way to the transport check and prints
the FATAL message the test is looking for.

So compare the image against the checkout before trusting either: one
container start, md5 of the three startup scripts, and a refusal that says
which ones differ and how to rebuild. Content, not any claim about how the
image was produced.

This is a guard rather than a fix - it does not make a stale image fresh,
it stops thirty-seven tests from reporting on the wrong code. Six CI
rounds went into a fault that this would have named on the first.

Tested: driven against a stubbed docker whose image reports a different
digest for init-firewall.sh - refuses and names that file, with the other
two matching so the message is specific rather than a blanket mismatch;
and silent when all three agree. Full fast suite passes.

Refs #59

branderson added 1 commit 2026-08-03 02:18:23 -07:00

test: read the container's own streams instead of the daemon's log ... 8558efb097

The transport test detached its container and asked `docker logs` for the
output afterwards. Across six CI rounds that arrangement insisted the
container was aborting partway through init-firewall.sh. It was not.

The tell was in what those logs never contained. Every line any of them
ever carried came from an `echo` to stdout; not one line written to stderr
appeared in any of them. Not init-firewall.sh's ERR trap, which nothing
reaching that point can bypass. Not resolve_domain's per-attempt reports,
which print on every path before it returns. And not the FATAL message
this test asserts on, which entrypoint.sh writes to stderr too - so the
assertion was failing on the same missing half as the diagnostics that
were supposed to explain why.

The output was also measured rather than eyeballed, twice: 2100 bytes and
2189 bytes, both exactly the length of the visible text. Nothing was
truncated. The stdout half arrived complete and the stderr half never
arrived at all.

So stop going through the log driver. A foreground `docker run` attaches
to the container's streams directly - nothing is buffered, flushed or
dropped in between - and one command yields both the output and the exit
status, with no wait, no settling, and no read-after-exit race. It is less
machinery than what it replaces, not more.

settled_logs stays for wait_ready, which has no foreground option: it is
watching a container that is meant to keep running.

The static test counting container starts against --network flags is
updated to match: it counted `docker run -d` lines, and now counts
foreground starts too, exempting runs that replace the entrypoint with a
plain shell - those never reach dns-proxy.sh, so a resolver cannot be
missing from them.

Refs #59

branderson merged commit 7783c13bc1 into main 2026-08-03 03:51:31 -07:00

branderson referenced this issue from a commit 2026-08-03 03:51:31 -07:00

Merge pull request 'firewall: bound, retry and report the GitHub ranges fetch' (#60) from firewall-fetch-timeout into main

branderson referenced this pull request 2026-08-03 03:52:40 -07:00

init-firewall.sh's GitHub ranges fetch has no timeout, so a stalled call hangs every container start #59

branderson referenced this issue from a commit 2026-08-03 05:27:46 -07:00

Merge main into config-provider-axes

branderson referenced this issue from a commit 2026-08-03 06:08:00 -07:00

Merge config-provider-axes into provider-axes

Sign in to join this conversation.

Reviewers

No Reviewers

Labels

Clear labels

Compat/Breaking

Breaking change that won't be backward compatible

Kind/Bug

Something is not working

Kind/Documentation

Documentation changes

Kind/Enhancement

Improve existing functionality

Kind/Feature

New functionality

Kind/Security

This is security issue

Kind/Testing

Issue or pull request related to testing

Priority

Critical

1

The priority is critical

Priority

High

2

The priority is high

Priority

Low

4

The priority is low

Priority

Medium

3

The priority is medium

Reviewed

Confirmed

1

Issue has been confirmed

Reviewed

Duplicate

2

This issue or pull request already exists

Reviewed

Invalid

3

Invalid issue

Reviewed

Won't Fix

3

This issue won't be fixed

Status

Abandoned

3

Somebody has started to work on this but abandoned work

Status

Blocked

1

Something is blocking this issue or pull request

Status

Need More Info

2

Feedback is required to reproduce issue or to continue work

No labels

Milestone

No items

No Milestone

Projects

Clear projects

No projects

Assignees

Clear assignees

branderson dejima-agent

No Assignees

1 Participants

Notifications

Subscribe

Due Date

No due date set.

Dependencies

No dependencies set.

Reference: dejima/dejima#60