Files
spinifex/scripts/images/rds-postgres/rds-agent.initd
T
Ben Duncan 18853cef31 fix: close the four defects keeping the e2e nightly red (#1007)
* fix: stop the e2e analyser inventing failures and let a detach outlast its seal

go-junit-report emits <error message="No test result found"> for a === RUN with
no matching result line, and attaches the test's own captured log as the body.
The analyser counted those as failures, so the baremetal cell reported 25
failures against a junit file recording 1, with log output reading as
assertions. Separate the marker from a real error in both the parse and the
roll-up, count the unresolved cases and say so in the summary.

The gateway gave a detach 30s while the daemon budgets 180s for the ebs.unmount
seal and 180s more for the QMP unplug chain, so any detach whose seal replayed a
WAL was reported as ServerInternal while it went on to succeed.

Also switch four nightly job gates from always() to !cancelled(): always()
overrides cancellation, so a cancelled run kept starting jobs.

* fix: serialise the e2e workflows on one group and retry a dropped libvirt

e2e.yml had no concurrency block at all, so every push to dev could provision
alongside every other push and alongside the nightly. All four workflows that
build on these hypervisors now share e2e-hypervisors, queued rather than
cancelled. A per-environment group is not expressible: GitHub picks the group
before it picks a runner, and the environment is a property of the runner.

tofu apply also failed outright on a transient libvirt connect, which fails a
45-minute job in 90 seconds and reports it as a test failure. retry_run retries
only when that attempt's own output names a connection failure, so a real
failure still fails once.

Also collect the unfiltered journal from the matrix cells and the node journal
from cell-21: the unit filter drops the kernel and OOM lines that explain why
one node behaved unlike its siblings, and a passing run's journal is what makes
a failing one readable.

* fix: build the baremetal junit from the unfiltered suite log

run-baremetal-e2e.sh streams the full suite output to suite-output.log and a
grep-filtered summary to its stdout, which the workflow tees into
test-baremetal.log. That filter anchors --- PASS at column 0 and Go indents
every subtest result by four spaces, so the junit was generated from a log with
no subtest results in it: go-junit-report saw each === RUN with no outcome and
emitted <error message="No test result found">.

17 of cell-28's 39 testcases and 93 of cell-20's 120 were that. Regenerating
cell-28 from suite-output.log gives 39 tests, 0 failures, 0 errors.

* fix: converge released EIPs instead of trusting a fire-and-forget teardown

A disassociate leaves the ENI running, so the orphan sweep's owning-port test
never fires for it. The teardown then rests entirely on vpc.delete-nat, which is
core NATS and is lost whenever vpcd is restarting — and the intent KV watch is
UpdatesOnly, so the same window hides the write that would have driven a repair
pass. The dnat_and_snat row and its host /32 route to a released public address
survived until something else happened to touch them, which for a live ENI was
nothing at all.

Give the sweep the second test it was missing: AddEIP is the only writer of
dnat_and_snat, so the floating IPs intent asks for are the complete set of
addresses that may hold one, and a row for any other address is stale however
alive its port. Ports and external IPs travel together in LiveEIPs, both unioned
from the start-of-pass snapshot and the fresh re-read, so a mid-pass launch is
still spared. The host unbind now runs even when the row had already gone, which
is the state a crash between the OVN delete and the unbind leaves.

Run that sweep on the startup pass too. Startup is the pass that follows the
blind window, so skipping it deferred repair of exactly the changes that were
missed. The port-group and ENI-port sweeps stay gated there for the in-flight
create they were written for; the EIP sweep re-reads intent immediately before
deciding and abandons the whole sweep if that read fails, which is the same
protection by a stronger route.

* fix: keep a release verify off the hypervisors an e2e run is using

release.yml is the fifth workflow that provisions on the ci-single pool and had
no concurrency block at all, so a tag push could land a tofu apply on the same
libvirt host a nightly cell was mid-provision on. The group goes on the verify
job rather than the workflow: the build jobs touch no hypervisor and should not
queue behind a nightly.

* fix: stop cell-27 handing a 50-minute suite a 50-minute job

The rds suite is budgeted 50m in suite-sets.sh and cell-27 took the matrix
default of 50 minutes for the whole job, so provisioning, install, the suite and
teardown had to fit inside the suite's allowance alone. It never could: the last
measured run spent 6 minutes reaching the suite and was killed 44 minutes into
it, mid-TestAutomatedBackups. A job timeout reports "The operation was canceled"
and nothing else, which is why this cell has no verdict in any nightly rather
than a failure anyone could read.

cell-27 gets 75 minutes, and the select job now refuses to start a run whose job
budget does not clear its suite budget plus a setup allowance. The inner timeout
firing first is the property that matters: go test says where it stopped and
what failed, and the job timeout says nothing at all. cell-29 already had the
same fix applied by hand; nothing stopped the next suite from repeating it.

* fix: converge host EIP plumbing against intent, not against the NAT row

The released-EIP sweep landed and did not fire. Its premise was that a stranded
dnat_and_snat row is what a stranded host route can be found by, and on the path
that actually strands one there is no row left. AddEIP scrubs the predecessor
row sharing the private IP before installing the new one, so when reconcile
re-added the instance's auto-assigned address it silently deleted the released
EIP's row — and applyEIPs runs ahead of the sweep, which then walked a table
with nothing stale in it while the /32 route and its proxy-ARP stayed up.

Give the sweep the host's own inventory. ListEIPIngress reads the EIPs back from
the FORWARD accepts EnsureEIPIngress stamps with its own comment, so a binding is
found by what installed it rather than by a row some other path is free to
delete. Anything plumbed that intent no longer asks for is torn down, which also
covers a crash between the OVN delete and the unbind. A failed inventory fails
the pass: an empty list and an unreadable one are indistinguishable, and reading
the second as the first is a sweep that reports success having done nothing.

Close the window inside the pass too. The predecessor scrub now reads the row it
is about to drop and releases that address's host state, so the strand does not
exist between applyEIPs and the sweep rather than merely being repaired a step
later.

* fix: retry the release verify's libvirt calls like every other job does

The verify job drives the same libvirt provider on the same hypervisors as the
e2e cells, where a dropped connection under concurrent load is the steady state
and is retried. Here it was a hard failure that reads as a broken release. It
was skipped earlier only because the job checks out mulga and not spinifex, so
the shared helpers were not on disk — a sparse checkout of .github/scripts costs
nothing and makes apply and destroy behave like their e2e counterparts.

* fix: do not report a rebooting DB instance available on the pre-reboot agent's health

RegisterDBInstance stamped a fresh LastSeen while leaving Agent.EngineHealth at
the value the previous agent process reported. After a reboot the new agent
registers before it has probed anything, so the record read as a healthy engine
with a beat newer than the transition, and the reconciler moved the instance to
available while PostgreSQL was still starting up. A client that connects the
moment the status turns green then gets "the database system is starting up".

A register now discards the previous process's verdict and records when this
agent process started. The restart reconciler requires that registration to be
newer than the transition, which also closes the window where a beat lands
between the engine being stopped and the VM going down.

* test: record the credential kubectl sent when an EKS call comes back Unauthorized

The IRSA pod subtest's first kubectl is the gateway-CA configmap, which lands
before the pod dumps are registered, so a 401 there left no evidence at all. A
verbose read-only probe reports whether an Authorization header was sent, which
separates a token the apiserver rejected from one the exec plugin never made.

* fix: report a starting engine promptly, and budget CI jobs from the suite

The agent waited a full heartbeat interval before its first beat, so a restart
could not be observed as finished for up to 30 seconds after the engine was
already serving. Beat at startup instead, and report every 5 seconds until the
engine has answered once — the control plane is actively waiting on that beat,
and the steady-state cadence it hands back is for a database already serving.

The rds suite is the one most sensitive to what else the hypervisor is doing:
its DB VMs serialise behind a 4 GiB semaphore, so its wall clock is set by how
long it waits for the budget. The same pass ran 45m beside four nightly cells
and overran 50m beside nine, panicking with two tests still running. Raise its
budget to 60m.

That budget was then larger than the jobs meant to contain it. A job cancelled
on timeout reports only "The operation was canceled" and takes the artifacts
with it, so the inner `go test` timeout must always fire first — and it could
not for rds on e2e.yml, nor for storagefault or diskperf, which have asked for
90m and 180m inside a 60m job since they were added. Both workflows now resolve
their job budget from suite-sets.sh rather than carrying a literal: e2e.yml
from the largest requested suite, e2e-suites.yml per matrix leg, so a leg is
bounded by its own suite and not by the longest one beside it. The default push
set resolves to exactly the timeouts both workflows had before.

* fix: check a permutation cell's job budget against the suites it runs

The guard only saw cells that name a suite, so the nine that run a topology's
nightly subset were never checked against it — the same class of mistake the
guard exists to catch, in the majority of the cells. Bound each by the longest
suite in its subset: max() and not sum(), because whichever suite hangs must
panic on its own timeout first, and a sum would demand a budget the set has
never come close to using. Every cell clears it today.

* fix: report why a PostgreSQL engine would not start, and stop failing a stop that landed

Three defects, all found by the first rds pass that ever ran deep enough to
reach them.

A wait that saw an instance reach `failed` called t.Fatalf from inside the
polling condition, and testify runs that condition on its own goroutine. The
Goexit killed the tick and left the collector empty, which reads as the
condition being satisfied — so the wait returned successfully on an instance it
had just declared broken, logged "reached status available" about one that was
failed, and let the test carry on against it. Six conditions across four suites
call Fatal or require the same way. EventuallyErr now runs its condition on the
test's goroutine, which makes all six behave as written.

A DB VM stop has two drivers: the API call and the reconciler resuming one whose
caller it assumes has died. When they overlap the loser is told the VM is not in
a state to be stopped — which is the state the stop was heading for — and the
customer's StopDBInstance returned InvalidDBInstanceState for a stop that had
just completed. Both paths now treat a refused command the way they already
treat an unanswered one: it says nothing about the VM, so the fleet view
settles it.

PostgreSQL had no equivalent of the engine log tail MariaDB has carried since it
was added, so a postmaster that refuses a setting produced "engine did not
respond on /run/postgresql:5432" and nothing else — on a guest with no SSH,
whose console records only that pg_ctl could not start the server. The probe now
quotes the tail of the log the image already directs the postmaster to, and the
reboot and modify paths carry the agent's reason into the failure the way the
create path always has. The reason reaches the customer through StatusInfos.

The rds suite's budget goes to 90m and cell-27's job to 100m. Its wall clock is
what the DB-VM queue costs rather than what the tests do — single tests logged
11m, 22m and 26m waiting for budget — and the pass above still had three of
seventeen tests running at 60m.

* fix: keep a DB VM recoverable when its agent cannot start, and flush the volume before a snapshot

An rds-agent that failed to construct exited, so a transient IMDS credential
resolution took the guest down for good: rds-datadir and rds-init cascade on the
missing handoff, the engine never starts, and the control plane sees only silence
until it declares the instance failed ten minutes later. Construction is retried
like every other boot step instead.

OpenRC skips start_post when the start itself fails, which is the one case with
no diagnostic at all — the console carried nothing but "died". The log mirror
moves out of the handoff wait so a failed start uses it too.

A snapshot quiesced the engine and nothing else. The engine repairs its own files
from the WAL, but postgresql.conf sits beside them and it does not: a restore
came up on a torn tail and the postmaster stopped on a syntax error at the
unterminated include hook. The quiesce now flushes the whole data mount, and the
hook is renamed into place rather than appended, so a boot that finds a half
written one replaces it instead of appending after its open quote.

* fix: flush the config cloud-init wrote before a reset can take it

A DB instance rebooted seconds after it went available came back with no
RDS_GATEWAY_URL, so rds-agent could not reach the control plane and the engine
never started. cloud-init writes agent.env once, per-instance, and never again;
a reboot is a QMP system_reset with no guest shutdown, so the file was still
dirty page cache when the machine reset under it and the next boot read nothing.
The handoff wait now syncs, which is the point at which the agent has proved it
read that file.

* fix: stop dropping an EIP teardown published while vpcd is restarting

DisassociateAddress publishes vpc.delete-nat fire-and-forget. On run
34046316024 vpcd disconnected from NATS at 03:51:26.73 and its replacement
subscribed at 03:51:27.09; the publish landed at 03:51:26.92, in the gap, and
went nowhere. ReleaseAddress then returned the address to the pool two minutes
later with its /32 host route still delivering to the guest that had held it.

vpc.delete-nat now uses request-reply like vpc.add-nat, and retries only on
no-responders — which returns immediately, so the cost is paid solely when
nothing is listening. A teardown that still fails is logged as an error naming
the address rather than lost silently. Neither is fatal to the caller: the
reconciler's orphan sweep remains the backstop.

vpc.add-nat on the EIP path stays fire-and-forget. The shared helper blocks it
on the flows barrier for up to 45s, and associating an address should not
inherit that.

Two reconcile passes in that run had the address absent from intent and did not
sweep its host route, and the journal cannot say why: the sweep logged only when
it acted, so a route it kept was indistinguishable from one it never saw. It now
logs the bindings it found, kept and wanted.

* ci: render one run-level table for the e2e nightly

Reading a nightly meant opening nineteen jobs, and the Actions UI does not
separate a cell that failed from one cancelled out from under it — a
distinction every investigation of this suite has needed, and one the run
34046316024 analysis had to reach for the jobs API to get.

A final job, needs: every cell and if: always(), renders cell, topology,
result, duration, runner and per-cell test counts into the step summary, with
run-level totals, the three slowest cells and the failing test names.

Result, duration and runner come from the jobs API so a cell that died before
writing junit still gets a row. Counts come from a new junit-only artifact per
cell rather than the full cell artifact, so the roll-up does not pull nineteen
journals it has no use for.

Verified against run 34046316024: 14 success, 2 cancelled, 1 failure, with the
two cancellations shown as cancelled rather than folded into failure.

* fix: assert EC2's actual EIP semantics, and probe EKS auth on an authenticated path

natuplink asserted that an instance's auto-assigned public IP is still plumbed
after an EIP associated to the same instance is torn down. EC2 does the
opposite: associating an EIP releases the auto-assigned address back into the
pool, and it cannot be reused. Our datapath already does that — run 34059879666
shows 192.168.0.72's ingress removed at 07:09:44.000, 36ms before .73's was
installed — so the test was asserting behaviour neither AWS nor we have.

It now asserts the release at the point it happens, and that no public delivery
remains after the teardown. This surfaced only once the teardown itself started
working: the run's other assertions passed, including .73's removal, which was
the failure before.

Our records still disagree with our datapath — the ENI keeps the released
address, which is why termination tears the old one down twice and never the
current one. That is the remaining half of mulga-7zc9w and is not fixed here;
it needs an IPAM release on the associate path.

Separately, AuthDiagnostics read /version, which is anonymously readable, so its
200 was consistent with both branches it claimed to distinguish. It now runs
auth whoami, reads kube-system, and invokes the credential plugin directly,
reporting exit code, stderr and whether a token was produced — never the token,
since CI logs outlive it.

* test: capture per-guest state when a spread guest never answers SSH

TestMultinodeSpread's only failure dump is dumpPlacementNATDiag, which collects
OVN, OVS, ARP and route state aimed at the NAT and EIP half of the test. The
failure it actually hits is a guest that never accepted SSH — run 34040324968,
the guest on node3 at 10.100.2.5 — and for that it recorded no console, no port
binding and no tap state. There was no way to tell from the artifact whether the
guest booted at all.

Now dumps, per guest: the console, the NB logical switch port, the SB port
binding, the OVS interface backing its tap, and br-int's port list. Probed on
every node rather than the expected one, because a port bound on the wrong
chassis is exactly what a hosting-node-only dump cannot show.

Covers all three guests, not just the failing one, so a working guest is
available as the control.

* ci: sample hypervisor load either side of every cell

Eight runner names map onto three hypervisors, so cells that never share a
runner still share a host: when cell 10's SSH wait expired on run 34040324968,
cells 22, 17, 18 and 28 were concurrently live, two of them multi-node. Nothing
in the artifacts measured host load, which left co-tenancy as an explanation
that could be neither confirmed nor ruled out.

Records loadavg, MemAvailable, SwapFree, the cpu line carrying steal, and the
QEMU process count before and after each cell, into the cell artifact.

* ci: note that main's missing concurrency block is why the nightly runs ungrouped

Three refs carry three different groupings: main has no concurrency block at
all, dev uses e2e-nightly, this branch uses e2e-hypervisors. Scheduled runs load
the workflow from the default branch, so every cron nightly runs ungrouped and
cannot queue against anything — which is how a dispatch of 34050630627 ran
alongside the scheduled 34046316024 and cost it cells 24 and 27.

e2e-hypervisors is the right group and deliberately broader than dev's, since
e2e.yml, e2e-suites.yml and e2e-ddil.yml draw on the same runner pools. Nothing
on a feature branch can fix this; the block has to reach main.
2026-09-06 16:53:32 -05:00

98 lines
3.7 KiB
Plaintext

#!/sbin/openrc-run
# rds-agent — Spinifex RDS in-guest agent. Reaches the control plane over
# TLS+SigV4 (never NATS), signing with IMDS instance-role credentials. Static
# config comes from /etc/spinifex-rds/agent.env, which carries no secrets.
description="Spinifex RDS instance agent"
command="/usr/local/bin/rds-agent"
command_background="yes"
pidfile="/run/rds-agent.pid"
output_log="/var/log/rds-agent.log"
error_log="/var/log/rds-agent.log"
start_stop_daemon_args="--wait 2000"
AGENT_ENV="/etc/spinifex-rds/agent.env"
# The agent retries indefinitely, so this only bounds how long the boot waits
# before letting rds-init fail visibly rather than hanging forever.
handoff_timeout="${RDS_HANDOFF_TIMEOUT:-120}"
# How much of the agent log to mirror to the console when the handoff times out.
# Enough to carry a few backed-off retries with their errors, not the whole boot.
handoff_tail="${RDS_HANDOFF_TAIL:-20}"
depend() {
need net
after localmount
before rds-datadir rds-init postgresql
}
start_pre() {
# An absent file is tolerated, so the agent still starts and logs why it
# cannot reach the gateway.
if [ -f "${AGENT_ENV}" ]; then
# shellcheck disable=SC1090
. "${AGENT_ENV}"
export RDS_GATEWAY_URL RDS_GATEWAY_CA RDS_REGION RDS_DB_INSTANCE_IDENTIFIER \
RDS_ENGINE RDS_ENGINE_VERSION RDS_HANDOFF_DIR RDS_ENGINE_PORT \
RDS_POLL_WAIT RDS_DATA_MOUNT
fi
}
# The agent's log is inside a guest nothing can reach, so anything that is not
# mirrored here is lost. Used by both the failed start and the handoff timeout.
mirror_agent_log() {
if [ -s "${output_log}" ]; then
einfo "last ${handoff_tail} lines of ${output_log}:"
tail -n "${handoff_tail}" "${output_log}" 2>/dev/null | while IFS= read -r _line; do
einfo " [rds-agent] ${_line}"
done
else
einfo "${output_log} is empty — the agent produced no output at all"
fi
}
# OpenRC skips start_post when the start itself fails, which is the one case
# with no diagnostic at all: the console reports only that the process died.
start() {
default_start && return 0
eerror "rds-agent exited during start"
mirror_agent_log
return 1
}
start_post() {
# Resolve this after start_pre loads agent.env so custom handoff directories
# are shared by the agent, this wait, and rds-init.
HANDOFF_ENV="${RDS_HANDOFF_DIR:-/run/spinifex-rds}/bootstrap.env"
# `before rds-init` only orders the starts; rds-init needs the fetched config
# itself. The agent writes bootstrap.env last and renames it into place, so
# its appearance means the whole handoff is there.
ebegin "Waiting for the RDS bootstrap handoff"
_waited=0
while [ ! -f "${HANDOFF_ENV}" ]; do
if [ "${_waited}" -ge "${handoff_timeout}" ]; then
eend 1 "no bootstrap handoff after ${handoff_timeout}s"
# An unreachable gateway is the usual cause, and the host-side console
# capture is the only way that dial error survives — without it the
# failure reads as silence.
mirror_agent_log
# The agent keeps retrying, so it is left running: rds-init fails on
# the missing handoff and the engine stays down, which is what the
# control plane observes.
return 0
fi
sleep 1
_waited=$((_waited + 1))
done
# A handoff means the agent read agent.env, which cloud-init wrote seconds
# ago and only into page cache. A reboot is a QMP reset with no guest
# shutdown, so anything not yet written back is gone and the next boot has
# no gateway URL to reach the control plane with.
sync
eend 0
}