Compare commits

..

7 Commits

Author SHA1 Message Date
dependabot[bot] f5e09923c1 chore: bump the npm_and_yarn group across 1 directory with 2 updates (#1510)
Bumps the npm_and_yarn group with 2 updates in the /spinifex/runtime/roles/spinifexui/frontend directory: [brace-expansion](https://github.com/juliangruber/brace-expansion) and [source-map-js](https://github.com/7rulnik/source-map-js).


Updates `brace-expansion` from 5.0.9 to 5.0.12
- [Release notes](https://github.com/juliangruber/brace-expansion/releases)
- [Commits](https://github.com/juliangruber/brace-expansion/compare/v5.0.9...v5.0.12)

Updates `source-map-js` from 1.2.1 to 1.2.2
- [Release notes](https://github.com/7rulnik/source-map-js/releases)
- [Changelog](https://github.com/7rulnik/source-map-js/blob/main/CHANGELOG.md)
- [Commits](https://github.com/7rulnik/source-map-js/compare/v1.2.1...v1.2.2)

---
updated-dependencies:
- dependency-name: brace-expansion
  dependency-version: 5.0.12
  dependency-type: indirect
  dependency-group: npm_and_yarn
- dependency-name: source-map-js
  dependency-version: 1.2.2
  dependency-type: indirect
  dependency-group: npm_and_yarn
...

Signed-off-by: dependabot[bot] <support@github.com>
Co-authored-by: dependabot[bot] <49699333+dependabot[bot]@users.noreply.github.com>
2026-11-04 10:13:53 +11:00
Ben Duncan fc8bf59fad chore: merge main into dev to carry the Codex review caller 2026-11-04 05:02:30 +10:00
Ben Duncan f805e947e9 ci: call the shared Codex PR review on PRs into dev 2026-11-04 04:58:32 +10:00
Ben Duncan 173ac7a936 test(e2e): attach and detach a volume on a stopped instance, as AWS allows (#1508) 2026-11-03 10:14:02 -06:00
Josh Siviour 1c39e29367 fix: stop on guest poweroff and keep stopped instances' volumes attached (#1507)
* test: pin guest poweroff handling and stopped-instance volume state

* test: gofmt the poweroff and stopped-volume tests

* test: pin start after detach, one-poll poweroff, reattach of released volumes and the delete refusal

* test: separate the embedded mounter from the recorder fields

* fix: end a guest poweroff as a stop and keep stopped instances' data volumes attached

A clean QEMU exit after the heartbeat saw the guest power off now stops the
instance instead of waiting for crash detection. Unmount no longer releases
data volumes. DetachVolume on a stopped instance edits the record, then
releases the volume. Starting an instance stopped on an older build drops data
volumes that are attached elsewhere or deleted and fails on a missing boot
volume.

* fix: keep the stopped-instance detach inside the instance service file and format start reconcile

* docs: describe guest poweroff, stopped-instance volumes and detach on a stopped instance

* fix: allow detaching the root volume of a stopped instance and refuse a start with no root volume as AWS does

* feat: attach volumes to a stopped instance and fix root-detach start fixtures

* docs: describe attach and root detach on a stopped instance

* test: Unmount seals only and leaves every attached volume in-use

Changed with the person's explicit approval, relayed by dev-design on 11-03.
EBS root and data volumes persist across stop on AWS, so stop and crash
unmount no longer release any attached volume.

* docs: note that the EFI variable store cannot be detached from a stopped instance

* test: unmount contract tests expect no volume state write on stop

* test: order imports in stopped-volume daemon tests

* refactor: drop the unused volume state updater from the volume mounter
2026-11-03 23:51:39 +10:00
Josh Siviour 19e3141c28 fix: cap instance console files and retire them when the instance ends (#1506)
* test: console log trim, removal by instance state and append-mode chardevs

* fix: cap and reap instance console logs, always append

* test: expect append mode on microvm file chardevs

* fix: retire console logs on terminate instead of reading instance state

* docs: describe console log location, caps and retirement on terminate

* test: drop removed append argument from startQEMU calls

* docs: state that GetConsoleOutput returns NotFound once an instance has been torn down

* docs: drop the unverified AWS retention claim for console output

* feat: remove idle console logs that no QEMU on the node holds open

* fix: keep idle console logs when a QEMU pidfile names a pid the scan cannot see
2026-11-03 23:51:13 +10:00
Josh Siviour ad8e4ea2d7 feat: forward filtered k3s-agent logs from EKS workers to the console (#1505)
* test: eks node log forwarder filter, redaction, caps and role wiring

* feat(eks-node): forward k3s agent warnings and errors to the serial console

A redacting, rate-capped forwarder tails the agent log and writes warning,
error and node-status lines to the console so they reach the sink. Secrets are
redacted before the 512-byte cut.
2026-11-03 23:51:00 +10:00
49 changed files with 2738 additions and 262 deletions
+21
View File
@@ -0,0 +1,21 @@
# Codex review gate: calls bluebottle's reusable workflows from main, so a PR cannot change its own review.
name: codex-review
on:
pull_request_target:
branches: [dev]
types: [opened, synchronize, reopened, ready_for_review, edited]
issue_comment:
types: [created]
permissions: {}
jobs:
review:
if: github.event_name == 'pull_request_target'
uses: mulgadc/bluebottle/.github/workflows/codex-pr-review.yml@main
secrets: inherit
waive:
if: github.event_name == 'issue_comment' && github.event.issue.pull_request
uses: mulgadc/bluebottle/.github/workflows/codex-waive.yml@main
secrets: inherit
@@ -23,6 +23,7 @@ resources:
- [Overview](#overview)
- [Launch](#launch)
- [Manage](#manage)
- [Stopping and Data Volumes](#stopping-and-data-volumes)
- [Modify Instance Attributes](#modify-instance-attributes)
- [Instance Metadata Options](#instance-metadata-options)
- [Spot Instances](#spot-instances)
@@ -73,6 +74,31 @@ aws ec2 terminate-instances --instance-ids $INSTANCE_ID
aws ec2 reboot-instances --instance-ids $INSTANCE_ID
```
## Stopping and Data Volumes
A guest that powers itself off (`poweroff`, `shutdown -h`) goes `stopping` then `stopped`, the same as `stop-instances`.
It is not restarted automatically.
`InstanceInitiatedShutdownBehavior=terminate` is not honoured yet: a guest shutdown always stops the instance.
Data volumes stay `in-use` and attached to a stopped instance, and `start-instances` mounts them again.
While the instance is stopped, `attach-volume` of one of its data volumes to another instance returns `VolumeInUse`, and `delete-volume` is refused.
`detach-volume` works on a stopped instance, with or without `--instance-id`.
The volume becomes `available` and the next start does not attach it.
The root volume of a stopped instance can be detached too, as on AWS.
The internal EFI variable store is not a customer volume: it never appears in `describe-volumes` or `BlockDeviceMappings`, and detaching it is refused with `OperationNotPermitted`.
The instance then cannot start: `start-instances` returns `InvalidParameterValue` with "Instance does not have a volume attached at root (/dev/sda1)".
`attach-volume` works on a stopped instance too.
The volume must be `available` and in the instance's availability zone, otherwise the call returns `VolumeInUse` or `InvalidVolume.ZoneMismatch`.
The attachment is recorded on the stopped instance and the volume becomes `in-use` straight away.
Attaching at the root device name (for example `/dev/sda1`) makes the volume the root again, and the next `start-instances` boots from it.
An instance stopped by an earlier build had its data volumes released to `available` while its record still listed them.
On start, a listed data volume that was deleted or is now attached to another instance is dropped with a warning in the daemon log, and the start continues.
A listed volume that is still `available` and unattached is attached again.
A missing root volume fails the start with the same `InvalidParameterValue` answer.
## Modify Instance Attributes
Change instance type, user data, or termination protection. Instance type and user data require the instance to be **stopped** first.
@@ -135,6 +161,30 @@ aws ec2 get-console-output --instance-id $INSTANCE_ID \
--query 'Output' --output text | base64 -d
```
Like AWS, the call returns the most recent 64 KiB of the console.
While an instance is shutting down after a terminate request, the call reads the renamed file described below.
Once the instance has left the node's running set, which includes a stopped or terminated instance, the node no longer answers and the call returns `InvalidInstanceID.NotFound`.
AWS still lists a terminated instance for a while after termination, so a caller may expect this call to work then; it does not here, a known gap.
Whether the API should answer for a stopped instance is not settled here; only the file on the host is kept.
### Where console logs live and how big they get
The serial console of each instance is written on its host to `/run/spinifex/console-<instance-id>.log`.
`/run` is memory-backed, so these files are cleared when the host reboots, including any left by older releases.
The daemon keeps them bounded.
A file over 4 MiB is cut back in place to its newest 1 MiB, and the guest keeps writing while it happens.
The console is opened in append mode, so a reboot or auto-restart of the guest adds to the same file instead of starting over.
A live `console-<instance-id>.log` is deleted only when it has not changed for an hour and no QEMU process on the host has it open, so a stopped instance keeps its console for an hour and a quiet running guest keeps it indefinitely.
If the daemon cannot read the open files of every QEMU process on the host, it deletes nothing on that pass and logs a warning.
This also clears the file of an instance that was stopped and then terminated, or that was recovered on another node, within about an hour of its last write.
When an instance is terminated, including a failed first launch and the system instances behind load balancers, queues and EKS control planes, its file is renamed to `console-<instance-id>.log.terminated`.
The daemon removes a `.terminated` file an hour after its last write.
Known limits:
- The log shipper follows only `console-*.log`, so it stops following a file when it is renamed on terminate, and the last few seconds of output that it had not yet read can be lost.
- The instance password retrieval reads only the live file name, so it does not find a console renamed after terminate.
## Instance Types
List instance types available on the current host. The catalog is generated from the host CPU (Intel, AMD, or ARM) and includes burstable (t-family), general purpose (m-family), compute optimised (c-family), and memory optimised (r-family) types.
+3
View File
@@ -159,6 +159,7 @@ case "${ROLE}" in
svc_start mulga-eks-state-report
svc_start mulga-eks-addon-sync
svc_start mulga-eks-node-gc
svc_optional mulga-eks-log-forward
svc_optional eks-pod-identity-webhook
;;
server-join)
@@ -178,12 +179,14 @@ case "${ROLE}" in
svc_start konnectivity-server
svc_start mulga-eks-state-report
svc_start mulga-eks-node-gc
svc_optional mulga-eks-log-forward
svc_optional eks-pod-identity-webhook
;;
agent)
log "configuring agent role"
svc_enable k3s-agent
svc_start k3s-agent
svc_optional mulga-eks-log-forward
;;
*)
die "SPINIFEX_K3S_ROLE missing or invalid: '${ROLE}'"
@@ -146,6 +146,15 @@ for INIT in openrc systemd; do
)"
check "server(${INIT}): enables node-gc" "yes" "$(present "${CALLS}" "$(enable_cmd "${INIT}" mulga-eks-node-gc)")"
check "server(${INIT}): starts node-gc" "yes" "$(present "${CALLS}" "$(start_cmd "${INIT}" mulga-eks-node-gc)")"
check "server(${INIT}): enables log-forward" "yes" "$(present "${CALLS}" "$(enable_cmd "${INIT}" mulga-eks-log-forward)")"
check "server(${INIT}): starts log-forward" "yes" "$(present "${CALLS}" "$(start_cmd "${INIT}" mulga-eks-log-forward)")"
check "server(${INIT}): starts log-forward before the webhook" "yes" "$(
awk -v f="$(start_cmd "${INIT}" mulga-eks-log-forward)" -v w="$(start_cmd "${INIT}" eks-pod-identity-webhook)" '
index($0, f) == 1 { fn = NR }
index($0, w) == 1 { wn = NR }
END { print (fn > 0 && wn > fn) ? "yes" : "no" }
' "${CALLS}"
)"
check "server(${INIT}): no k3s-agent" "no" "$(present "${CALLS}" "$(enable_cmd "${INIT}" k3s-agent)")"
check "server(${INIT}): self-disables" "yes" "$(present "${CALLS}" "$(disable_cmd "${INIT}" eks-node-role)")"
check "server(${INIT}): pod-identity-webhook is the last call" "$(start_cmd "${INIT}" eks-pod-identity-webhook)" "$(grep -v "$(disable_cmd "${INIT}" eks-node-role)" "${CALLS}" | tail -n 1)"
@@ -196,6 +205,15 @@ for INIT in openrc systemd; do
# published the cluster-identical artifacts, and a join re-publish would
# only race the bootstrap bus. This is deliberate, not an oversight.
check "server-join(${INIT}): pod-identity-webhook is the last call" "$(start_cmd "${INIT}" eks-pod-identity-webhook)" "$(grep -v "$(disable_cmd "${INIT}" eks-node-role)" "${CALLS}" | tail -n 1)"
check "server-join(${INIT}): enables log-forward" "yes" "$(present "${CALLS}" "$(enable_cmd "${INIT}" mulga-eks-log-forward)")"
check "server-join(${INIT}): starts log-forward" "yes" "$(present "${CALLS}" "$(start_cmd "${INIT}" mulga-eks-log-forward)")"
check "server-join(${INIT}): starts log-forward before the webhook" "yes" "$(
awk -v f="$(start_cmd "${INIT}" mulga-eks-log-forward)" -v w="$(start_cmd "${INIT}" eks-pod-identity-webhook)" '
index($0, f) == 1 { fn = NR }
index($0, w) == 1 { wn = NR }
END { print (fn > 0 && wn > fn) ? "yes" : "no" }
' "${CALLS}"
)"
check "server-join(${INIT}): no k3s-first-boot" "yes" "$(absent_all "${CALLS}" "k3s-first-boot")"
check "server-join(${INIT}): no k3s-agent" "yes" "$(absent_all "${CALLS}" "$(enable_cmd "${INIT}" k3s-agent)")"
check "server-join(${INIT}): self-disables" "yes" "$(present "${CALLS}" "$(disable_cmd "${INIT}" eks-node-role)")"
@@ -207,8 +225,39 @@ for INIT in openrc systemd; do
check "agent(${INIT}): exit 0" 0 "${rc}"
check "agent(${INIT}): role file" "agent" "$(cat "${ROLE_FILE}")"
check "agent(${INIT}): enables k3s-agent" "yes" "$(present "${CALLS}" "$(enable_cmd "${INIT}" k3s-agent)")"
check "agent(${INIT}): enables log-forward" "yes" "$(present "${CALLS}" "$(enable_cmd "${INIT}" mulga-eks-log-forward)")"
check "agent(${INIT}): starts log-forward" "yes" "$(present "${CALLS}" "$(start_cmd "${INIT}" mulga-eks-log-forward)")"
check "agent(${INIT}): log-forward is enabled after k3s-agent" "yes" "$(
awk -v k="$(enable_cmd "${INIT}" k3s-agent)" -v f="$(enable_cmd "${INIT}" mulga-eks-log-forward)" '
index($0, k) == 1 { kn = NR }
index($0, f) == 1 { fn = NR }
END { print (kn > 0 && fn > kn) ? "yes" : "no" }
' "${CALLS}"
)"
check "agent(${INIT}): no server services" "yes" "$(absent_all "${CALLS}" "eks-token-webhook" "eks-pod-identity-webhook" "k3s-first-boot" "mulga-eks-node-gc" "$(enable_cmd "${INIT}" k3s)")"
# A broken log forwarder must never stop a node joining.
for FAILING in enable start; do
run_case "${INIT}" agent_logfwd_${FAILING}_fail
printf 'SPINIFEX_K3S_ROLE=agent\n' > "${EKS_NODE_ENVFILE}"
if [ "${FAILING}" = enable ]; then
STUB_FAIL="$(enable_cmd "${INIT}" mulga-eks-log-forward)"
export STUB_FAIL
STUB_FAIL="${STUB_FAIL#rc-update add }"; STUB_FAIL="${STUB_FAIL#systemctl enable }"
else
STUB_FAIL="$(start_cmd "${INIT}" mulga-eks-log-forward)"
export STUB_FAIL
STUB_FAIL="${STUB_FAIL#rc-service }"; STUB_FAIL="${STUB_FAIL#systemctl start --no-block }"
fi
invoke
unset STUB_FAIL
check "agent(${INIT}): log-forward ${FAILING} failure still exits 0" 0 "${rc}"
check "agent(${INIT}): log-forward ${FAILING} failure still enables k3s-agent" "yes" "$(present "${CALLS}" "$(enable_cmd "${INIT}" k3s-agent)")"
check "agent(${INIT}): log-forward ${FAILING} failure still starts k3s-agent" "yes" "$(present "${CALLS}" "$(start_cmd "${INIT}" k3s-agent)")"
check "agent(${INIT}): log-forward ${FAILING} failure still self-disables" "yes" "$(present "${CALLS}" "$(disable_cmd "${INIT}" eks-node-role)")"
done
# --- agent (inferred from agent.env, no explicit role) ---
run_case "${INIT}" agent_inferred
printf 'K3S_URL=https://nlb:443\nK3S_TOKEN=abc\n' > "${EKS_NODE_AGENT_ENVFILE}"
+2
View File
@@ -45,6 +45,8 @@ scripts/images/eks-node/mulga-eks-addon-sync.initd:/etc/init.d/mulga-eks-addon-s
scripts/images/eks-node/mulga-eks-addon-sync.sh:/usr/local/sbin/mulga-eks-addon-sync \
scripts/images/eks-node/mulga-eks-node-gc.initd:/etc/init.d/mulga-eks-node-gc \
scripts/images/eks-node/mulga-eks-node-gc.sh:/usr/local/sbin/mulga-eks-node-gc \
scripts/images/eks-node/mulga-eks-log-forward.initd:/etc/init.d/mulga-eks-log-forward \
scripts/images/eks-node/mulga-eks-log-forward.sh:/usr/local/sbin/mulga-eks-log-forward \
scripts/images/eks-node/konnectivity-server.initd:/etc/init.d/konnectivity-server \
scripts/images/eks-node/konnectivity-server-prestart.sh:/usr/local/sbin/konnectivity-server-prestart \
scripts/images/eks-node/konnectivity/konnectivity-agent.yaml:/usr/share/spinifex-eks/konnectivity/konnectivity-agent.yaml \
+30
View File
@@ -0,0 +1,30 @@
#!/sbin/openrc-run
# mulga-eks-log-forward — copies k3s warnings and errors to the serial console
# so they reach the Elasticsearch sink. Best effort: nothing depends on it and
# a failure here never affects the node.
description="Forward k3s warnings and errors to the serial console"
command="/bin/sh"
command_background="yes"
supervisor="supervise-daemon"
respawn_delay=5
pidfile="/run/mulga-eks-log-forward.pid"
output_log="/dev/null"
error_log="/dev/null"
depend() {
after k3s k3s-agent
}
start_pre() {
role=$(cat /etc/spinifex-eks/role 2>/dev/null || true)
if [ "${role}" = "agent" ]; then
log=/var/log/k3s-agent.log
FORWARD_PREFIX="[k3s-agent]"
else
log=/var/log/k3s.log
FORWARD_PREFIX="[k3s]"
fi
export FORWARD_PREFIX
command_args="-c 'tail -n +1 -F ${log} 2>/dev/null | /usr/local/sbin/mulga-eks-log-forward'"
}
+90
View File
@@ -0,0 +1,90 @@
#!/bin/sh
# mulga-eks-log-forward — copy the warnings and errors of a k3s log to the
# serial console, where the host picks them up for the Elasticsearch sink.
#
# Reads the tailed log on stdin. Lines that matter are redacted first, then
# cut to FORWARD_MAX_BYTES, then rate limited: at most FORWARD_RATE_PER_MIN a
# minute reach the console and the rest are reported as one "N lines dropped"
# line. Every console write has a timeout, so a stuck console loses lines
# instead of stalling the tail or k3s.
#
# Env: FORWARD_CONSOLE (default /dev/console), FORWARD_PREFIX, FORWARD_MAX_BYTES
# (512), FORWARD_RATE_PER_MIN (60), FORWARD_WRITE_TIMEOUT seconds (2) and
# FORWARD_CLOCK_CMD (default: seconds of uptime, read without forking).
CONSOLE=${FORWARD_CONSOLE:-/dev/console}
PREFIX=${FORWARD_PREFIX:-[k3s]}
MAX_BYTES=${FORWARD_MAX_BYTES:-512}
RATE=${FORWARD_RATE_PER_MIN:-60}
WRITE_TIMEOUT=${FORWARD_WRITE_TIMEOUT:-2}
CLOCK_CMD=${FORWARD_CLOCK_CMD:-}
now() {
if [ -n "${CLOCK_CMD}" ]; then
sh -c "${CLOCK_CMD}"
else
read -r up _ < /proc/uptime && echo "${up%%.*}"
fi
}
# emit TEXT: one console line, abandoned after WRITE_TIMEOUT. Returns non-zero
# when the console did not take it.
emit() {
timeout "${WRITE_TIMEOUT}" sh -c 'printf "%s\n" "$1" >> "$2"' sh "$1" "${CONSOLE}" 2>/dev/null
}
# Filter, redact and truncate in one awk pass so lines that do not matter cost
# no fork. Redaction runs before the cut so a secret straddling the limit
# cannot leave a readable prefix behind.
select_lines() {
LC_ALL=C awk -v max="${MAX_BYTES}" '
{
line = $0
gsub(/\r/, "", line)
keep = 0
if (line ~ /level=(warning|error)/) keep = 1
else if (line ~ /^[WE][0-9][0-9][0-9][0-9] /) keep = 1
else if (line ~ /NodeNotReady|PLEG|[Ll]ease|[Nn]ode status/) keep = 1
if (!keep) next
gsub(/[Bb]earer +[A-Za-z0-9._~+\/=-]+/, "Bearer [REDACTED]", line)
gsub(/K10[0-9a-f]+(::[A-Za-z0-9-]+:[^ "\047]+)?/, "[REDACTED]", line)
gsub(/eyJ[A-Za-z0-9_.-]+/, "[REDACTED]", line)
gsub(/(AKIA|ASIA)[A-Z0-9]+/, "[REDACTED]", line)
gsub(/X-Amz-Signature=[^& "\047]*/, "X-Amz-Signature=[REDACTED]", line)
gsub(/X-Amz-Credential=[^& "\047]*/, "X-Amz-Credential=[REDACTED]", line)
gsub(/X-Amz-Security-Token=[^& "\047]*/, "X-Amz-Security-Token=[REDACTED]", line)
gsub(/[^[:print:]\t]/, " ", line)
print substr(line, 1, max)
}'
}
win_start=0
sent=0
dropped=0
flush_dropped() {
[ "${dropped}" -gt 0 ] || return 0
emit "${PREFIX} ${dropped} lines dropped"
dropped=0
}
select_lines | {
while IFS= read -r line; do
t=$(now) || t=0
if [ "${win_start}" -eq 0 ] || [ $((t - win_start)) -ge 60 ]; then
flush_dropped
win_start=${t}
sent=0
[ "${win_start}" -eq 0 ] && win_start=1
fi
if [ "${sent}" -ge "${RATE}" ]; then
dropped=$((dropped + 1))
continue
fi
sent=$((sent + 1))
emit "${PREFIX} ${line}" || dropped=$((dropped + 1))
done
flush_dropped
}
exit 0
@@ -0,0 +1,190 @@
#!/bin/sh
# Self-contained POSIX test for mulga-eks-log-forward.sh: the line filter,
# redaction, truncation, rate cap and blocked-console behaviour. The script
# reads the tailed log on stdin and writes to FORWARD_CONSOLE, which the test
# points at a temp file (or a reader-less FIFO), so no root or tty is needed.
#
# Run: sh scripts/images/eks-node/mulga-eks-log-forward_test.sh
set -eu
SCRIPT_DIR=$(cd "$(dirname "$0")" && pwd)
SCRIPT="${SCRIPT_DIR}/mulga-eks-log-forward.sh"
WORK=$(mktemp -d)
trap 'rm -rf "${WORK}"' EXIT
PASS=0
FAIL=0
check() { # check <desc> <expected> <actual>
if [ "$2" = "$3" ]; then
PASS=$((PASS + 1))
else
FAIL=$((FAIL + 1))
echo "FAIL: $1"
echo " expected: [$2]"
echo " actual: [$3]"
fi
}
# forward <name>: feeds stdin to the script with a per-case console file and a
# fixed clock, leaving the forwarded text in ${OUT}.
forward() {
CASE="${WORK}/$1"
mkdir -p "${CASE}"
OUT="${CASE}/console"
: > "${OUT}"
FORWARD_CONSOLE="${OUT}" FORWARD_PREFIX="[k3s-agent]" \
FORWARD_CLOCK_CMD="echo 1000" sh "${SCRIPT}" 2>/dev/null || true
}
forwarded() { grep -c . "${OUT}" || true; }
# --- filter: lines that must pass ---
forward filter_pass <<'EOF'
time="2026-11-03T03:00:00Z" level=warning msg="slow response from apiserver"
time="2026-11-03T03:00:01Z" level=error msg="failed to renew"
W1103 03:00:02.123456 1234 reflector.go:561] watch of *v1.Pod ended
E1103 03:00:03.123456 1234 kubelet.go:2400] node not found
I1103 03:00:04.123456 1234 kubelet_node_status.go:73] Node status update failed
I1103 03:00:05.123456 1234 controller.go:193] Failed to update lease
I1103 03:00:06.123456 1234 kubelet.go:2200] PLEG is not healthy
time="2026-11-03T03:00:07Z" level=info msg="Event: NodeNotReady kubelet"
EOF
check "filter: all eight interesting lines pass" "8" "$(forwarded)"
check "filter: lines carry the prefix" "8" "$(grep -c '^\[k3s-agent\] ' "${OUT}" || true)"
# --- filter: lines that must be dropped ---
forward filter_drop <<'EOF'
time="2026-11-03T03:00:00Z" level=info msg="Starting k3s agent"
time="2026-11-03T03:00:01Z" level=debug msg="tick"
I1103 03:00:02.123456 1234 server.go:100] Version: v1.32.5
I1103 03:00:03.123456 1234 kubelet.go:1000] SyncLoop (UPDATE, "api")
EOF
check "filter: info and debug lines are dropped" "0" "$(forwarded)"
# --- redaction: one case per secret shape ---
redact() { # redact <name> <line> <secret-that-must-not-appear>
forward "redact_$1" <<EOF
time="2026-11-03T03:00:00Z" level=error msg="$2"
EOF
check "redact(${1}): line still forwarded" "1" "$(forwarded)"
if grep -qF "$3" "${OUT}"; then
check "redact(${1}): secret removed" "absent" "present"
else
check "redact(${1}): secret removed" "absent" "absent"
fi
check "redact(${1}): marker present" "1" "$(grep -c 'REDACTED' "${OUT}" || true)"
}
redact bearer "request failed Authorization: Bearer abc123SECRETvalue456" "abc123SECRETvalue456"
redact k3s_token "join failed token K1009f3c2d4e5a6b7c8d9e0f1a2b3c4d5e6f7a8b9c0d1e2f3a4b5c6d7e8f9a0b1c2::server:s3cr3tPassw0rd" "s3cr3tPassw0rd"
redact jwt "bad token eyJhbGciOiJIUzI1NiJ9.eyJzdWIiOiIxMjM0NTY3ODkwIn0.c2lnbmF0dXJlLXNlY3JldA" "eyJhbGciOiJIUzI1NiJ9"
redact akia "credentials AKIAIOSFODNN7EXAMPLE rejected" "AKIAIOSFODNN7EXAMPLE"
redact asia "credentials ASIAIOSFODNN7EXAMPLE rejected" "ASIAIOSFODNN7EXAMPLE"
redact amz_signature "GET /obj?X-Amz-Signature=0123456789abcdef0123456789abcdef&X-Amz-Expires=60 failed" "0123456789abcdef0123456789abcdef"
redact amz_credential "GET /obj?X-Amz-Credential=ZZZsecretscope%2F20261103%2Fap%2Fs3%2Faws4_request failed" "ZZZsecretscope"
# --- truncation: text over 512 bytes is cut ---
LONG=$(awk 'BEGIN { for (i = 0; i < 2000; i++) printf "a"; }')
forward truncate <<EOF
time="2026-11-03T03:00:00Z" level=error msg="${LONG}"
EOF
check "truncate: still forwarded" "1" "$(forwarded)"
BODY=$(sed 's/^\[k3s-agent\] //' "${OUT}" | head -n 1)
check "truncate: body is exactly 512 bytes" "512" "$(printf '%s' "${BODY}" | wc -c | tr -d ' ')"
check "truncate: keeps the start of the line" "time=\"2026-11-03T03:00:00Z\"" "$(printf '%s' "${BODY}" | cut -c1-27)"
# --- redaction runs before the cut: a secret over the limit leaves no prefix ---
# The pad puts the 512-byte cut right after the bare marker (AKIA, eyJ, K10).
# A cut fragment that long matches no redaction pattern, so redacting after the
# cut would leave it in the output.
HEAD='time="2026-11-03T03:00:00Z" level=error msg="'
straddle() { # straddle <name> <secret> <bytes of the secret kept by the cut>
PAD=$(awk -v n=$((512 - ${#HEAD} - 1 - $3)) 'BEGIN { for (i = 0; i < n; i++) printf "x"; }')
forward "straddle_$1" <<EOF
${HEAD}${PAD} $2 tail"
EOF
check "straddle(${1}): line forwarded" "1" "$(forwarded)"
check "straddle(${1}): cut keeps the marker length" "$3" "$(sed 's/^\[k3s-agent\] //' "${OUT}" | head -n 1 | awk -v p="${PAD} " '{ print length($0) - index($0, p) - length(p) + 1 }')"
if grep -qF "$(printf '%s' "$2" | cut -c1-"$3")" "${OUT}"; then
check "straddle(${1}): no fragment survives the cut" "absent" "present"
else
check "straddle(${1}): no fragment survives the cut" "absent" "absent"
fi
}
straddle jwt "eyJhbGciOiJIUzI1NiJ9.eyJzdWIiOiIxMjM0In0.c2ln" 3
straddle akia "AKIAIOSFODNN7EXAMPLE" 4
straddle k3s_token "K1009f3c2d4e5a6b7c8d9e0f1a2b3c4d5e6f7a8b9c0d1e2f3a4b5c6d7e8f9a0b1c2::server:s3cr3tPassw0rd" 3
# --- rate cap: 60 a minute, then one summary of what was dropped ---
gen() { # gen <count>
awk -v n="$1" 'BEGIN { for (i = 0; i < n; i++) printf "time=\"t\" level=error msg=\"loop %d\"\n", i }'
}
gen 100 > "${WORK}/burst"
forward rate_cap < "${WORK}/burst"
check "rate cap: 60 lines forwarded plus one summary" "61" "$(forwarded)"
check "rate cap: one dropped summary" "1" "$(grep -c '40 lines dropped' "${OUT}" || true)"
check "rate cap: first line kept" "1" "$(grep -c 'loop 0"' "${OUT}" || true)"
check "rate cap: line past the cap is not forwarded" "0" "$(grep -c 'loop 60"' "${OUT}" || true)"
# --- rate cap: a new minute starts a new window and reports the old drops ---
# The clock command advances 60 s every 70 calls, so lines 0-69 share a window
# (10 dropped) and lines 70-74 land in the next one.
CASE="${WORK}/rate_window"
mkdir -p "${CASE}"
OUT="${CASE}/console"
: > "${OUT}"
echo 0 > "${CASE}/calls"
cat > "${CASE}/clock" <<EOF
#!/bin/sh
n=\$(cat "${CASE}/calls")
echo \$((n + 1)) > "${CASE}/calls"
echo \$((1000 + n / 70 * 60))
EOF
chmod +x "${CASE}/clock"
gen 75 | FORWARD_CONSOLE="${OUT}" FORWARD_PREFIX="[k3s-agent]" FORWARD_CLOCK_CMD="${CASE}/clock" sh "${SCRIPT}" 2>/dev/null || true
check "window: 60 + 5 forwarded plus one summary" "66" "$(forwarded)"
check "window: summary names the 10 dropped" "1" "$(grep -c '10 lines dropped' "${OUT}" || true)"
check "window: new window forwards its lines" "1" "$(grep -c 'loop 74"' "${OUT}" || true)"
# --- blocked console: lines are dropped, the forwarder neither stalls nor fails ---
CASE="${WORK}/blocked"
mkdir -p "${CASE}"
mkfifo "${CASE}/console"
gen 3 > "${CASE}/in"
(
FORWARD_CONSOLE="${CASE}/console" FORWARD_PREFIX="[k3s-agent]" FORWARD_CLOCK_CMD="echo 1000" \
FORWARD_WRITE_TIMEOUT=1 sh "${SCRIPT}" < "${CASE}/in"
) &
PID=$!
i=0
while kill -0 "${PID}" 2>/dev/null && [ "${i}" -lt 20 ]; do
sleep 1
i=$((i + 1))
done
if kill -0 "${PID}" 2>/dev/null; then
kill "${PID}" 2>/dev/null || true
check "blocked console: forwarder finished" "finished" "stalled"
else
check "blocked console: forwarder finished" "finished" "finished"
fi
rc=0
wait "${PID}" || rc=$?
check "blocked console: exit 0" "0" "${rc}"
# --- the service is wired in, and nothing depends on it ---
INITD="${SCRIPT_DIR}/mulga-eks-log-forward.initd"
check "initd ships" "yes" "$([ -f "${INITD}" ] && echo yes || echo no)"
check "manifest installs the initd" "1" "$(grep -c 'mulga-eks-log-forward.initd:/etc/init.d/mulga-eks-log-forward' "${SCRIPT_DIR}/manifest.conf" || true)"
check "manifest installs the script" "1" "$(grep -c 'mulga-eks-log-forward.sh:/usr/local/sbin/mulga-eks-log-forward' "${SCRIPT_DIR}/manifest.conf" || true)"
DEPS=0
for f in "${SCRIPT_DIR}"/*.initd; do
[ "${f}" = "${INITD}" ] && continue
if grep -E '^[[:space:]]*(need|use|want)[[:space:]].*mulga-eks-log-forward' "${f}" >/dev/null 2>&1; then
DEPS=$((DEPS + 1))
fi
done
check "nothing depends on the forwarder" "0" "${DEPS}"
if [ -f "${INITD}" ]; then
check "initd does not need anything it could block boot on" "0" "$(grep -cE '^[[:space:]]*need[[:space:]]' "${INITD}" || true)"
fi
echo "mulga-eks-log-forward_test: ${PASS} passed, ${FAIL} failed"
[ "${FAIL}" -eq 0 ]
+2 -2
View File
@@ -45,10 +45,10 @@ ln -sf /usr/local/bin/k3s /usr/local/bin/ctr
chmod 0755 /etc/init.d/eks-node-role /etc/init.d/k3s /etc/init.d/k3s-agent \
/etc/init.d/eks-token-webhook /etc/init.d/k3s-first-boot /etc/init.d/mulga-eks-state-report \
/etc/init.d/mulga-eks-addon-sync /etc/init.d/mulga-eks-node-gc /etc/init.d/konnectivity-server \
/etc/init.d/eks-pod-identity-webhook
/etc/init.d/eks-pod-identity-webhook /etc/init.d/mulga-eks-log-forward
chmod 0755 /usr/local/sbin/eks-node-role /usr/local/sbin/k3s-first-boot \
/usr/local/sbin/mulga-eks-state-report /usr/local/sbin/mulga-eks-addon-sync \
/usr/local/sbin/mulga-eks-node-gc
/usr/local/sbin/mulga-eks-node-gc /usr/local/sbin/mulga-eks-log-forward
# start_pre helpers shared with the systemd wrappers that will eventually
# replace these runscripts.
chmod 0755 /usr/local/sbin/k3s-prestart /usr/local/sbin/k3s-agent-prestart \
@@ -49,6 +49,12 @@ func AttachVolume(ctx context.Context, input *ec2.AttachVolumeInput, natsConn *n
device = *input.Device
}
// The shared record decides: a stopped instance has no QMP to plug into, so
// its record is edited and the volume claimed there instead.
if isStoppedInstance(ctx, instanceID, natsConn, accountID) {
return attachToStopped(ctx, natsConn, accountID, input)
}
command := ec2v1.EC2InstanceCommand{
ID: instanceID,
Attributes: ec2v1.EC2CommandAttributes{
@@ -97,6 +103,24 @@ func AttachVolume(ctx context.Context, input *ec2.AttachVolumeInput, natsConn *n
return output, nil
}
// attachToStoppedSubject is answered by any node and edits the stopped
// instance record in the shared bucket.
const attachToStoppedSubject = "ec2.AttachVolumeToStopped"
// attachToStopped asks the instance service to add the volume to the stopped
// instance's record; the volume is claimed in-use by the same call.
func attachToStopped(ctx context.Context, natsConn *nats.Conn, accountID string, input *ec2.AttachVolumeInput) (ec2.VolumeAttachment, error) {
attachment, err := natsmsg.NATSRequest[ec2.VolumeAttachment](ctx, natsConn, attachToStoppedSubject, input, 30*time.Second, accountID)
if err != nil {
slog.ErrorContext(ctx, "AttachVolume: stopped-instance attach failed", "volumeId", aws.StringValue(input.VolumeId), "instanceId", aws.StringValue(input.InstanceId), "err", err)
return ec2.VolumeAttachment{}, err
}
if attachment == nil {
return ec2.VolumeAttachment{}, nil
}
return *attachment, nil
}
// isStoppedInstance checks the shared KV (via ec2.DescribeStoppedInstances) to
// determine whether instanceID exists as a stopped instance.
func isStoppedInstance(ctx context.Context, instanceID string, natsConn *nats.Conn, accountID string) bool {
@@ -0,0 +1,55 @@
package volume
import (
"context"
"testing"
"github.com/aws/aws-sdk-go/aws"
"github.com/aws/aws-sdk-go/service/ec2"
"github.com/mulgadc/spinifex/internal/testkit"
"github.com/nats-io/nats.go"
"github.com/stretchr/testify/assert"
"github.com/stretchr/testify/require"
)
// The record decides the path: a stopped instance has no QMP to plug into, so
// the attach goes to the instance service and ec2.cmd.<id> is never used.
func TestAttachVolume_StoppedInstanceUsesTheRecordPath(t *testing.T) {
_, nc := testutil.StartTestNATS(t)
log := &subjectLog{}
stoppedRecord := &ec2.DescribeInstancesOutput{Reservations: []*ec2.Reservation{{
Instances: []*ec2.Instance{{InstanceId: aws.String("i-stopped")}},
}}}
handlers := map[string]func(*nats.Msg){
"ec2.DescribeStoppedInstances": func(m *nats.Msg) { respondJSON(t, m, stoppedRecord) },
attachToStoppedSubject: func(m *nats.Msg) {
log.add(attachToStoppedSubject)
respondJSON(t, m, &ec2.VolumeAttachment{
VolumeId: aws.String("vol-data"), InstanceId: aws.String("i-stopped"),
Device: aws.String("/dev/sdf"), State: aws.String("attached"),
})
},
"ec2.cmd.i-stopped": func(m *nats.Msg) {
log.add("ec2.cmd.i-stopped")
_ = m.Respond(nil)
},
}
for subject, h := range handlers {
sub, err := nc.Subscribe(subject, h)
require.NoError(t, err)
t.Cleanup(func() { _ = sub.Unsubscribe() })
}
require.NoError(t, nc.Flush())
out, err := AttachVolume(context.Background(), &ec2.AttachVolumeInput{
VolumeId: aws.String("vol-data"),
InstanceId: aws.String("i-stopped"),
Device: aws.String("/dev/sdf"),
}, nc, "000000000001")
require.NoError(t, err)
assert.Equal(t, "attached", aws.StringValue(out.State))
assert.Equal(t, []string{attachToStoppedSubject}, log.get(),
"only the record path runs for a stopped instance")
}
@@ -74,6 +74,12 @@ func DetachVolume(ctx context.Context, input *ec2.DetachVolumeInput, natsConn *n
force := input.Force != nil && *input.Force
// The shared record decides: a stopped instance has no QMP to unplug from,
// so its record is edited first and the volume released after.
if isStoppedInstance(ctx, instanceID, natsConn, accountID) {
return detachFromStopped(ctx, natsConn, accountID, volumeID, instanceID, device)
}
command := ec2v1.EC2InstanceCommand{
ID: instanceID,
Attributes: ec2v1.EC2CommandAttributes{
@@ -131,6 +137,10 @@ func DetachVolume(ctx context.Context, input *ec2.DetachVolumeInput, natsConn *n
// running the instance and so cannot help when that host is the problem.
const forceDetachSubject = "ec2.ForceDetachVolume"
// detachFromStoppedSubject is answered by any node and edits the stopped
// instance record in the shared bucket.
const detachFromStoppedSubject = "ec2.DetachVolumeFromStopped"
// forceDetach releases a volume whose instance has no responder.
//
// A volume outlives the instance it was attached to whenever teardown failed
@@ -153,3 +163,27 @@ func forceDetach(ctx context.Context, natsConn *nats.Conn, accountID, volumeID,
}
return *attachment, nil
}
// detachFromStopped removes the volume from the stopped instance's record and
// then releases the volume, in that order, so a failed release leaves the
// record clean and the volume still held rather than the reverse.
func detachFromStopped(ctx context.Context, natsConn *nats.Conn, accountID, volumeID, instanceID, device string) (ec2.VolumeAttachment, error) {
in := &ec2.DetachVolumeInput{VolumeId: &volumeID, InstanceId: &instanceID}
if device != "" {
in.Device = &device
}
if _, err := natsmsg.NATSRequest[ec2.VolumeAttachment](ctx, natsConn, detachFromStoppedSubject, in, 30*time.Second, accountID); err != nil {
slog.ErrorContext(ctx, "DetachVolume: stopped-instance record edit failed", "volumeId", volumeID, "instanceId", instanceID, "err", err)
return ec2.VolumeAttachment{}, err
}
attachment, err := natsmsg.NATSRequest[ec2.VolumeAttachment](ctx, natsConn, forceDetachSubject,
&ec2.DetachVolumeInput{VolumeId: &volumeID, Force: aws.Bool(true)}, 30*time.Second, accountID)
if err != nil {
slog.ErrorContext(ctx, "DetachVolume: release after record edit failed", "volumeId", volumeID, "instanceId", instanceID, "err", err)
return ec2.VolumeAttachment{}, err
}
if attachment == nil {
return ec2.VolumeAttachment{}, nil
}
return *attachment, nil
}
@@ -0,0 +1,115 @@
package volume
import (
"context"
"encoding/json"
"sync"
"testing"
"github.com/aws/aws-sdk-go/aws"
"github.com/aws/aws-sdk-go/service/ec2"
"github.com/mulgadc/spinifex/internal/testkit"
"github.com/nats-io/nats.go"
"github.com/stretchr/testify/assert"
"github.com/stretchr/testify/require"
)
type subjectLog struct {
mu sync.Mutex
seen []string
}
func (l *subjectLog) add(s string) {
l.mu.Lock()
defer l.mu.Unlock()
l.seen = append(l.seen, s)
}
func (l *subjectLog) get() []string {
l.mu.Lock()
defer l.mu.Unlock()
return append([]string(nil), l.seen...)
}
func respondJSON(t *testing.T, msg *nats.Msg, v any) {
t.Helper()
data, err := json.Marshal(v)
require.NoError(t, err)
require.NoError(t, msg.Respond(data))
}
// The record decides the path. A stopped instance has no QMP to unplug from, so
// its record is edited and the volume released, and ec2.cmd.<id> is never used.
func TestDetachVolume_StoppedInstanceEditsTheRecordThenReleasesTheVolume(t *testing.T) {
_, nc := testutil.StartTestNATS(t)
log := &subjectLog{}
stoppedRecord := &ec2.DescribeInstancesOutput{Reservations: []*ec2.Reservation{{
Instances: []*ec2.Instance{{InstanceId: aws.String("i-stopped")}},
}}}
handlers := map[string]func(*nats.Msg){
"ec2.DescribeStoppedInstances": func(m *nats.Msg) { respondJSON(t, m, stoppedRecord) },
detachFromStoppedSubject: func(m *nats.Msg) {
log.add(detachFromStoppedSubject)
respondJSON(t, m, &ec2.VolumeAttachment{
VolumeId: aws.String("vol-data"), InstanceId: aws.String("i-stopped"), Device: aws.String("/dev/sdf"),
})
},
forceDetachSubject: func(m *nats.Msg) {
log.add(forceDetachSubject)
respondJSON(t, m, &ec2.VolumeAttachment{
VolumeId: aws.String("vol-data"), InstanceId: aws.String("i-stopped"), State: aws.String("detached"),
})
},
"ec2.cmd.i-stopped": func(m *nats.Msg) {
log.add("ec2.cmd.i-stopped")
_ = m.Respond(nil)
},
}
for subject, h := range handlers {
sub, err := nc.Subscribe(subject, h)
require.NoError(t, err)
t.Cleanup(func() { _ = sub.Unsubscribe() })
}
require.NoError(t, nc.Flush())
out, err := DetachVolume(context.Background(), &ec2.DetachVolumeInput{
VolumeId: aws.String("vol-data"),
InstanceId: aws.String("i-stopped"),
}, nc, "000000000001")
require.NoError(t, err)
assert.Equal(t, "detached", aws.StringValue(out.State))
assert.Equal(t, []string{detachFromStoppedSubject, forceDetachSubject}, log.get(),
"record first, then the volume; the host path is never used for a stopped instance")
}
// NoResponders alone must not be read as "stopped": a dead or partitioned node
// gives the same answer, and editing the record then would race a live QEMU.
func TestDetachVolume_NoRespondersAloneDoesNotMeanStopped(t *testing.T) {
_, nc := testutil.StartTestNATS(t)
log := &subjectLog{}
for _, subject := range []string{detachFromStoppedSubject, forceDetachSubject} {
sub, err := nc.Subscribe(subject, func(m *nats.Msg) {
log.add(subject)
_ = m.Respond(nil)
})
require.NoError(t, err)
t.Cleanup(func() { _ = sub.Unsubscribe() })
}
sub, err := nc.Subscribe("ec2.DescribeStoppedInstances", func(m *nats.Msg) {
respondJSON(t, m, &ec2.DescribeInstancesOutput{})
})
require.NoError(t, err)
t.Cleanup(func() { _ = sub.Unsubscribe() })
require.NoError(t, nc.Flush())
_, err = DetachVolume(context.Background(), &ec2.DetachVolumeInput{
VolumeId: aws.String("vol-data"),
InstanceId: aws.String("i-silent-node"),
}, nc, "000000000001")
require.Error(t, err)
assert.Empty(t, log.get(), "no record edit and no control-plane release without a stopped record")
}
@@ -2700,6 +2700,12 @@ func (s *InstanceServiceImpl) launchClaimedInstance(ctx context.Context, instanc
// failure of this launch.
instance.FirstLaunch = false
if err := s.reconcileStartVolumes(ctx, instance); err != nil {
slog.ErrorContext(ctx, "launchClaimedInstance: volumes cannot be reconciled", "instanceId", instance.ID, "err", err)
undo()
return err
}
instanceType, ok := s.resourceMgr.InstanceTypes()[instance.InstanceType]
if !ok {
slog.ErrorContext(ctx, "launchClaimedInstance: instance type not available on this node",
@@ -3674,3 +3680,153 @@ func (s *InstanceServiceImpl) DescribeInstanceStatus(ctx context.Context, input
slog.InfoContext(ctx, "DescribeInstanceStatus completed", "count", len(statuses))
return &ec2.DescribeInstanceStatusOutput{InstanceStatuses: statuses}, nil
}
// DetachVolumeFromStopped removes a data volume from a stopped instance's
// record, so a later start no longer attaches it. It does not touch the
// volume's own state; the caller releases that once the record is clean. The
// device the volume held comes back on the attachment.
func (s *InstanceServiceImpl) DetachVolumeFromStopped(ctx context.Context, input *ec2.DetachVolumeInput, accountID string) (*ec2.VolumeAttachment, error) {
if input == nil || aws.StringValue(input.InstanceId) == "" || aws.StringValue(input.VolumeId) == "" {
return nil, errors.New(awserrors.ErrorMissingParameter)
}
if s.stoppedStore == nil {
slog.ErrorContext(ctx, "DetachVolumeFromStopped: stopped store not available")
return nil, errors.New(awserrors.ErrorServerInternal)
}
instanceID, volumeID := *input.InstanceId, *input.VolumeId
stored, err := s.stoppedStore.LoadStoppedInstance(instanceID)
if err != nil {
slog.ErrorContext(ctx, "DetachVolumeFromStopped: failed to load stopped instance", "instanceId", instanceID, "err", err)
return nil, errors.New(awserrors.ErrorServerInternal)
}
if stored == nil || !IsInstanceVisible(accountID, stored.AccountID) {
return nil, errors.New(awserrors.ErrorInvalidInstanceIDNotFound)
}
req, ok := findVolumeRequest(stored, volumeID)
if !ok {
return nil, errors.New(awserrors.ErrorIncorrectState)
}
if req.EFI {
return nil, errors.New(awserrors.ErrorOperationNotPermitted)
}
var removed bool
_, err = s.stoppedStore.UpdateStoppedInstance(instanceID, func(v *vm.VM) {
removed = removeVolumeFromRecord(v, volumeID)
})
if err != nil {
if errors.Is(err, kvstore.ErrNotFound) {
slog.WarnContext(ctx, "DetachVolumeFromStopped: instance claimed concurrently", "instanceId", instanceID)
return nil, errors.New(awserrors.ErrorIncorrectInstanceState)
}
slog.ErrorContext(ctx, "DetachVolumeFromStopped: failed to update stopped instance", "instanceId", instanceID, "err", err)
return nil, errors.New(awserrors.ErrorServerInternal)
}
if !removed {
return nil, errors.New(awserrors.ErrorIncorrectState)
}
return &ec2.VolumeAttachment{
VolumeId: aws.String(volumeID),
InstanceId: aws.String(instanceID),
Device: aws.String(req.DeviceName),
State: aws.String(ec2.VolumeAttachmentStateDetaching),
}, nil
}
// AttachVolumeToStopped adds an available volume to a stopped instance's
// record, so the next start mounts it. The volume is claimed in-use first and
// released again if the record edit fails, so a failure never leaves the record
// naming a volume another instance could take.
func (s *InstanceServiceImpl) AttachVolumeToStopped(ctx context.Context, input *ec2.AttachVolumeInput, accountID string) (*ec2.VolumeAttachment, error) {
if input == nil || aws.StringValue(input.InstanceId) == "" || aws.StringValue(input.VolumeId) == "" {
return nil, errors.New(awserrors.ErrorMissingParameter)
}
if s.stoppedStore == nil || s.metadata == nil {
slog.ErrorContext(ctx, "AttachVolumeToStopped: stores not available")
return nil, errors.New(awserrors.ErrorServerInternal)
}
instanceID, volumeID := *input.InstanceId, *input.VolumeId
stored, err := s.stoppedStore.LoadStoppedInstance(instanceID)
if err != nil {
slog.ErrorContext(ctx, "AttachVolumeToStopped: failed to load stopped instance", "instanceId", instanceID, "err", err)
return nil, errors.New(awserrors.ErrorServerInternal)
}
if stored == nil || !IsInstanceVisible(accountID, stored.AccountID) {
return nil, errors.New(awserrors.ErrorInvalidInstanceIDNotFound)
}
meta, err := s.metadata.GetVolume(ctx, accountID, volumeID)
if err != nil {
if objectstore.IsNoSuchKeyError(err) {
return nil, errors.New(awserrors.ErrorInvalidVolumeNotFound)
}
slog.ErrorContext(ctx, "AttachVolumeToStopped: failed to read volume", "volumeId", volumeID, "err", err)
return nil, errors.New(awserrors.ErrorServerInternal)
}
if meta.TenantID != accountID {
return nil, errors.New(awserrors.ErrorInvalidVolumeNotFound)
}
if meta.State != "available" {
return nil, errors.New(awserrors.ErrorVolumeInUse)
}
if meta.AvailabilityZone != "" && s.config != nil && s.config.AZ != "" && meta.AvailabilityZone != s.config.AZ {
return nil, errors.New(awserrors.ErrorInvalidVolumeZoneMismatch)
}
device, boot, err := stoppedAttachDevice(stored, aws.StringValue(input.Device))
if err != nil {
return nil, err
}
meta.State = "in-use"
meta.AttachedInstance = instanceID
meta.DeviceName = device
meta.AttachedAt = time.Now()
if err := s.metadata.PutVolume(ctx, meta); err != nil {
slog.ErrorContext(ctx, "AttachVolumeToStopped: failed to claim volume", "volumeId", volumeID, "err", err)
return nil, errors.New(awserrors.ErrorServerInternal)
}
var conflict error
_, err = s.stoppedStore.UpdateStoppedInstance(instanceID, func(v *vm.VM) {
// The device was chosen against a snapshot, so it is checked again
// against the record the edit is applied to.
if _, _, cerr := stoppedAttachDevice(v, device); cerr != nil {
conflict = cerr
return
}
addVolumeToRecord(v, volumeID, device, boot)
})
if err == nil && conflict != nil {
err = conflict
}
if err != nil {
meta.State = "available"
meta.AttachedInstance = ""
meta.DeviceName = ""
meta.AttachedAt = time.Time{}
if rerr := s.metadata.PutVolume(ctx, meta); rerr != nil {
slog.ErrorContext(ctx, "AttachVolumeToStopped: failed to release volume after a failed record edit", "volumeId", volumeID, "err", rerr)
}
if conflict != nil {
return nil, conflict
}
if errors.Is(err, kvstore.ErrNotFound) {
slog.WarnContext(ctx, "AttachVolumeToStopped: instance claimed concurrently", "instanceId", instanceID)
return nil, errors.New(awserrors.ErrorIncorrectInstanceState)
}
slog.ErrorContext(ctx, "AttachVolumeToStopped: failed to update stopped instance", "instanceId", instanceID, "err", err)
return nil, errors.New(awserrors.ErrorServerInternal)
}
return &ec2.VolumeAttachment{
VolumeId: aws.String(volumeID),
InstanceId: aws.String(instanceID),
Device: aws.String(device),
State: aws.String(ec2.VolumeAttachmentStateAttaching),
}, nil
}
@@ -0,0 +1,54 @@
//test:in-package — it swaps the manager's volume mounter, an unexported dependency.
package instance
import (
"context"
"errors"
"sync"
"testing"
viperblocklegacyv1 "github.com/mulgadc/spinifex/contracts/viperblockd/legacy/v1"
"github.com/mulgadc/spinifex/spinifex/runtime/compute/vm"
"github.com/stretchr/testify/assert"
"github.com/stretchr/testify/require"
)
// mountRecorder notes which volumes a launch asked to mount and then fails the
// launch, which is the earliest point that shows what the start would attach.
type mountRecorder struct {
refusingMounter
mu sync.Mutex
mounted []string
}
func (r *mountRecorder) Mount(_ context.Context, v *vm.VM) error {
r.mu.Lock()
defer r.mu.Unlock()
for _, req := range v.EBSRequests.Requests {
r.mounted = append(r.mounted, req.Name)
}
return errors.New("stop after recording")
}
func (r *mountRecorder) MountOne(context.Context, string, *viperblocklegacyv1.EBSRequest) error {
return nil
}
// A volume detached while the instance was stopped must not come back when the
// instance is started: the start path reads the same record the detach edited.
func TestStartStoppedInstance_DoesNotReattachAVolumeDetachedWhileStopped(t *testing.T) {
id := "i-detach-then-start"
stopped := stoppedWithVolumes("acc", id)
stopped.InstanceType = "t3.micro"
f := newStartFixture(t, stopped)
rec := &mountRecorder{}
f.svc.vmMgr.SetDeps(vm.Deps{VolumeMounter: rec})
_, err := f.svc.DetachVolumeFromStopped(context.Background(), stoppedDetachInput(id, "vol-data"), "acc")
require.NoError(t, err)
require.Error(t, f.start(t, id), "the recorder fails the launch after the mount")
assert.Equal(t, []string{"vol-root", "vol-other"}, rec.mounted,
"the detached volume is not part of the start")
}
@@ -0,0 +1,86 @@
package instance
import (
"context"
"fmt"
"log/slog"
"slices"
"github.com/aws/aws-sdk-go/aws"
"github.com/aws/aws-sdk-go/service/ec2"
viperblocklegacyv1 "github.com/mulgadc/spinifex/contracts/viperblockd/legacy/v1"
ebsmetadata "github.com/mulgadc/spinifex/spinifex/domains/ec2/ebs/metadata"
"github.com/mulgadc/spinifex/spinifex/foundation/aws/errors"
"github.com/mulgadc/spinifex/spinifex/providers/objectstore"
"github.com/mulgadc/spinifex/spinifex/runtime/compute/vm"
)
// reconcileStartVolumes drops the data volumes a claimed instance can no longer
// have, and fails the start when its boot volume is gone.
func (s *InstanceServiceImpl) reconcileStartVolumes(ctx context.Context, instance *vm.VM) error {
if s.metadata == nil {
return nil
}
instance.EBSRequests.Mu.Lock()
requests := slices.Clone(instance.EBSRequests.Requests)
instance.EBSRequests.Mu.Unlock()
if !slices.ContainsFunc(requests, func(r viperblocklegacyv1.EBSRequest) bool { return r.Boot }) {
return noRootVolumeError(instance)
}
var drop []string
for _, req := range requests {
meta, err := s.metadata.GetVolume(ctx, instance.AccountID, req.Name)
missing := err != nil && objectstore.IsNoSuchKeyError(err)
if err != nil && !missing {
return fmt.Errorf("read volume %s: %w", req.Name, err)
}
if req.Boot {
if missing {
slog.ErrorContext(ctx, "start: root volume no longer exists", "instanceId", instance.ID, "volumeId", req.Name)
return noRootVolumeError(instance)
}
continue
}
if req.EFI {
continue
}
if missing {
slog.WarnContext(ctx, "start: dropping deleted data volume", "instanceId", instance.ID, "volumeId", req.Name)
drop = append(drop, req.Name)
continue
}
if meta.AttachedInstance != "" && meta.AttachedInstance != instance.ID {
slog.WarnContext(ctx, "start: dropping data volume attached to another instance",
"instanceId", instance.ID, "volumeId", req.Name, "attachedTo", meta.AttachedInstance)
drop = append(drop, req.Name)
}
}
if len(drop) == 0 {
return nil
}
instance.EBSRequests.Mu.Lock()
instance.EBSRequests.Requests = slices.DeleteFunc(instance.EBSRequests.Requests, func(r viperblocklegacyv1.EBSRequest) bool {
return slices.Contains(drop, r.Name)
})
instance.EBSRequests.Mu.Unlock()
if instance.Instance != nil {
instance.Instance.BlockDeviceMappings = slices.DeleteFunc(instance.Instance.BlockDeviceMappings, func(m *ec2.InstanceBlockDeviceMapping) bool {
return m != nil && m.Ebs != nil && slices.Contains(drop, aws.StringValue(m.Ebs.VolumeId))
})
}
return nil
}
// noRootVolumeError is what AWS answers when an instance is started with
// nothing attached at its root device name.
func noRootVolumeError(instance *vm.VM) error {
device := ebsmetadata.RootDeviceName
if instance.Instance != nil && aws.StringValue(instance.Instance.RootDeviceName) != "" {
device = aws.StringValue(instance.Instance.RootDeviceName)
}
return awserrors.Errorf(awserrors.ErrorInvalidParameterValue, "Instance does not have a volume attached at root (%s)", device)
}
@@ -0,0 +1,125 @@
package instance
import (
"context"
"testing"
"github.com/aws/aws-sdk-go/aws"
"github.com/aws/aws-sdk-go/service/ec2"
viperblocklegacyv1 "github.com/mulgadc/spinifex/contracts/viperblockd/legacy/v1"
"github.com/mulgadc/spinifex/spinifex/domains/ec2/ebs/metadata"
"github.com/mulgadc/spinifex/spinifex/foundation/aws/errors"
"github.com/mulgadc/spinifex/spinifex/providers/objectstore"
"github.com/mulgadc/spinifex/spinifex/runtime/compute/vm"
"github.com/stretchr/testify/assert"
"github.com/stretchr/testify/require"
)
const startVolumesAccount = "000000000011"
func startVolumesService(t *testing.T, volumes ...ebsmetadata.Volume) *InstanceServiceImpl {
t.Helper()
store := objectstore.NewMemoryObjectStore()
meta := ebsmetadata.NewStore(store, testRootBucket)
for _, v := range volumes {
v.TenantID = startVolumesAccount
require.NoError(t, meta.PutVolume(context.Background(), v))
}
return &InstanceServiceImpl{metadata: meta}
}
func startingInstance(id string, names ...string) *vm.VM {
v := &vm.VM{ID: id, AccountID: startVolumesAccount, Status: vm.StateStopped, Instance: &ec2.Instance{InstanceId: aws.String(id)}}
for i, n := range names {
boot := i == 0
device := "/dev/sd" + string(rune('f'+i))
if boot {
device = "/dev/sda1"
}
v.EBSRequests.Requests = append(v.EBSRequests.Requests, viperblocklegacyv1.EBSRequest{Name: n, Boot: boot, DeviceName: device})
v.Instance.BlockDeviceMappings = append(v.Instance.BlockDeviceMappings, &ec2.InstanceBlockDeviceMapping{
DeviceName: aws.String(device), Ebs: &ec2.EbsInstanceBlockDevice{VolumeId: aws.String(n)},
})
}
return v
}
func requestedNames(v *vm.VM) []string {
var out []string
for _, r := range v.EBSRequests.Requests {
out = append(out, r.Name)
}
return out
}
func mappedNames(v *vm.VM) []string {
var out []string
for _, m := range v.Instance.BlockDeviceMappings {
out = append(out, aws.StringValue(m.Ebs.VolumeId))
}
return out
}
// An instance stopped on an older build had its data volumes released, and they
// may since have been attached elsewhere or deleted; starting must not take a
// volume that is no longer its own.
func TestReconcileStartVolumes_DropsVolumesThatAreNoLongerTheInstances(t *testing.T) {
svc := startVolumesService(t,
ebsmetadata.Volume{VolumeID: "vol-root", State: "in-use", AttachedInstance: "i-old"},
ebsmetadata.Volume{VolumeID: "vol-elsewhere", State: "in-use", AttachedInstance: "i-someone-else"},
ebsmetadata.Volume{VolumeID: "vol-free", State: "available"},
ebsmetadata.Volume{VolumeID: "vol-mine", State: "in-use", AttachedInstance: "i-old"},
)
inst := startingInstance("i-old", "vol-root", "vol-elsewhere", "vol-gone", "vol-free", "vol-mine")
require.NoError(t, svc.reconcileStartVolumes(context.Background(), inst))
want := []string{"vol-root", "vol-free", "vol-mine"}
assert.Equal(t, want, requestedNames(inst),
"attached-elsewhere and deleted volumes are dropped; free and own ones stay")
assert.Equal(t, want, mappedNames(inst), "the API view stops listing them too")
}
func TestReconcileStartVolumes_MissingBootVolumeFailsTheStart(t *testing.T) {
svc := startVolumesService(t, ebsmetadata.Volume{VolumeID: "vol-data", State: "available"})
inst := startingInstance("i-old", "vol-root", "vol-data")
inst.Instance.RootDeviceName = aws.String("/dev/sda1")
err := svc.reconcileStartVolumes(context.Background(), inst)
require.Error(t, err)
assert.True(t, awserrors.IsErrorCode(err, awserrors.ErrorInvalidParameterValue), "got %v", err)
assert.Contains(t, err.Error(), "Instance does not have a volume attached at root (/dev/sda1)")
}
// A root volume detached while the instance was stopped leaves no boot request
// in the record; AWS refuses the start with the same answer.
func TestReconcileStartVolumes_NoRootVolumeAttachedFailsTheStart(t *testing.T) {
svc := startVolumesService(t, ebsmetadata.Volume{VolumeID: "vol-data", State: "in-use", AttachedInstance: "i-old"})
inst := startingInstance("i-old", "vol-root", "vol-data")
require.True(t, removeVolumeFromRecord(inst, "vol-root"))
inst.Instance.RootDeviceName = aws.String("/dev/sda1")
err := svc.reconcileStartVolumes(context.Background(), inst)
require.Error(t, err)
assert.True(t, awserrors.IsErrorCode(err, awserrors.ErrorInvalidParameterValue), "got %v", err)
assert.Contains(t, err.Error(), "Instance does not have a volume attached at root (/dev/sda1)")
assert.Equal(t, []string{"vol-data"}, requestedNames(inst), "a refused start changes nothing")
}
// An instance stopped on an older build had its data volumes released to
// available with no attachment; those are still the instance's own and a
// start must bring them back.
func TestReconcileStartVolumes_ReattachesStillAvailableUnattachedVolume(t *testing.T) {
svc := startVolumesService(t,
ebsmetadata.Volume{VolumeID: "vol-root", State: "in-use", AttachedInstance: "i-old"},
ebsmetadata.Volume{VolumeID: "vol-released", State: "available"},
)
inst := startingInstance("i-old", "vol-root", "vol-released")
require.NoError(t, svc.reconcileStartVolumes(context.Background(), inst))
assert.Equal(t, []string{"vol-root", "vol-released"}, requestedNames(inst))
assert.Equal(t, []string{"vol-root", "vol-released"}, mappedNames(inst))
}
@@ -0,0 +1,180 @@
//test:in-package — it swaps the manager's volume mounter, an unexported dependency.
package instance
import (
"context"
"testing"
"github.com/aws/aws-sdk-go/aws"
"github.com/aws/aws-sdk-go/service/ec2"
"github.com/mulgadc/spinifex/spinifex/bootstrap/config"
ebsmetadata "github.com/mulgadc/spinifex/spinifex/domains/ec2/ebs/metadata"
"github.com/mulgadc/spinifex/spinifex/foundation/aws/errors"
"github.com/mulgadc/spinifex/spinifex/runtime/compute/vm"
vmmock "github.com/mulgadc/spinifex/spinifex/runtime/compute/vm/mock"
"github.com/stretchr/testify/assert"
"github.com/stretchr/testify/require"
)
const stoppedAttachAZ = "ap-southeast-2a"
type stoppedAttachFixture struct {
svc *InstanceServiceImpl
stored *vm.VM
id string
}
func newStoppedAttachFixture(t *testing.T, volumes ...ebsmetadata.Volume) *stoppedAttachFixture {
t.Helper()
id := "i-stopped-attach"
svc := startVolumesService(t, volumes...)
stored := startingInstance(id, "vol-root", "vol-data")
svc.config = &config.Config{AZ: stoppedAttachAZ}
svc.vmMgr = mgrWith(map[string]*vm.VM{})
svc.stoppedStore = &vmmock.StateStore{Stopped: map[string]*vm.VM{id: stored}}
return &stoppedAttachFixture{svc: svc, stored: stored, id: id}
}
func (f *stoppedAttachFixture) attach(volumeID, device string) (*ec2.VolumeAttachment, error) {
in := &ec2.AttachVolumeInput{InstanceId: aws.String(f.id), VolumeId: aws.String(volumeID)}
if device != "" {
in.Device = aws.String(device)
}
return f.svc.AttachVolumeToStopped(context.Background(), in, startVolumesAccount)
}
func (f *stoppedAttachFixture) volume(t *testing.T, id string) ebsmetadata.Volume {
t.Helper()
v, err := f.svc.metadata.GetVolume(context.Background(), startVolumesAccount, id)
require.NoError(t, err)
return v
}
func availableVolume(id string) ebsmetadata.Volume {
return ebsmetadata.Volume{VolumeID: id, State: "available", AvailabilityZone: stoppedAttachAZ}
}
// AWS lets a volume be attached to a stopped instance; the record then names it
// so the next start mounts it, and the volume is held in-use meanwhile.
func TestAttachVolumeToStopped_AddsTheVolumeAndClaimsIt(t *testing.T) {
f := newStoppedAttachFixture(t, availableVolume("vol-new"))
out, err := f.attach("vol-new", "")
require.NoError(t, err)
assert.Equal(t, "/dev/sdf", aws.StringValue(out.Device), "the first free data device")
assert.Equal(t, []string{"vol-root", "vol-data", "vol-new"}, requestedNames(f.stored))
assert.Equal(t, []string{"vol-root", "vol-data", "vol-new"}, mappedNames(f.stored))
assert.Equal(t, vm.StateStopped, f.stored.Status)
got := f.volume(t, "vol-new")
assert.Equal(t, "in-use", got.State)
assert.Equal(t, f.id, got.AttachedInstance)
assert.Equal(t, "/dev/sdf", got.DeviceName)
for _, r := range f.stored.EBSRequests.Requests {
if r.Name == "vol-new" {
assert.False(t, r.Boot, "a data device is not the root")
}
}
}
func TestAttachVolumeToStopped_Refusals(t *testing.T) {
tests := []struct {
name string
volumes []ebsmetadata.Volume
volume string
device string
want string
}{
{"volume in use elsewhere", []ebsmetadata.Volume{{VolumeID: "vol-busy", State: "in-use", AttachedInstance: "i-other", AvailabilityZone: stoppedAttachAZ}}, "vol-busy", "", awserrors.ErrorVolumeInUse},
{"wrong availability zone", []ebsmetadata.Volume{{VolumeID: "vol-far", State: "available", AvailabilityZone: "ap-southeast-2b"}}, "vol-far", "", awserrors.ErrorInvalidVolumeZoneMismatch},
{"no such volume", nil, "vol-missing", "", awserrors.ErrorInvalidVolumeNotFound},
{"device already taken", []ebsmetadata.Volume{availableVolume("vol-new")}, "vol-new", "/dev/sdg", awserrors.ErrorInvalidParameterValue},
{"root device already has a volume", []ebsmetadata.Volume{availableVolume("vol-new")}, "vol-new", "/dev/sda1", awserrors.ErrorInvalidParameterValue},
}
for _, tt := range tests {
t.Run(tt.name, func(t *testing.T) {
f := newStoppedAttachFixture(t, tt.volumes...)
_, err := f.attach(tt.volume, tt.device)
require.Error(t, err)
assert.True(t, awserrors.IsErrorCode(err, tt.want), "got %v, want %s", err, tt.want)
assert.Equal(t, []string{"vol-root", "vol-data"}, requestedNames(f.stored), "a refused attach changes nothing")
for _, v := range tt.volumes {
got := f.volume(t, v.VolumeID)
assert.Equal(t, v.State, got.State, "a refused attach leaves the volume as it was")
assert.Equal(t, v.AttachedInstance, got.AttachedInstance)
}
})
}
}
func TestAttachVolumeToStopped_OtherAccountsInstanceIsNotFound(t *testing.T) {
f := newStoppedAttachFixture(t, availableVolume("vol-new"))
_, err := f.svc.AttachVolumeToStopped(context.Background(),
&ec2.AttachVolumeInput{InstanceId: aws.String(f.id), VolumeId: aws.String("vol-new")}, "000000000099")
require.Error(t, err)
assert.True(t, awserrors.IsErrorCode(err, awserrors.ErrorInvalidInstanceIDNotFound))
assert.Equal(t, []string{"vol-root", "vol-data"}, requestedNames(f.stored))
}
// A record edit that cannot be applied must give the volume back, otherwise it
// stays in-use against an instance that does not name it.
func TestAttachVolumeToStopped_FailedRecordEditReleasesTheVolume(t *testing.T) {
f := newStoppedAttachFixture(t, availableVolume("vol-new"))
f.svc.stoppedStore = &vmmock.StateStore{Stopped: map[string]*vm.VM{f.id: f.stored}, UpdateStoppedErr: assert.AnError}
_, err := f.attach("vol-new", "")
require.Error(t, err)
assert.True(t, awserrors.IsErrorCode(err, awserrors.ErrorServerInternal))
got := f.volume(t, "vol-new")
assert.Equal(t, "available", got.State)
assert.Empty(t, got.AttachedInstance)
}
// Detaching the root volume of a stopped instance makes it unstartable; the way
// back is attaching a volume at the root device name, which makes it the boot
// volume again so the start finds a root.
func TestAttachVolumeToStopped_RootDeviceNameRestoresTheRootAndTheStartWorks(t *testing.T) {
id := "i-root-roundtrip"
stopped := stoppedWithVolumes(startVolumesAccount, id)
stopped.InstanceType = "t3.micro"
stopped.Instance.RootDeviceName = aws.String("/dev/sda1")
f := newStartFixture(t, stopped)
rec := &mountRecorder{}
f.svc.vmMgr.SetDeps(vm.Deps{VolumeMounter: rec})
f.svc.config = &config.Config{AZ: stoppedAttachAZ}
meta := startVolumesService(t,
ebsmetadata.Volume{VolumeID: "vol-root", State: "in-use", AttachedInstance: id, AvailabilityZone: stoppedAttachAZ},
ebsmetadata.Volume{VolumeID: "vol-data", State: "in-use", AttachedInstance: id, AvailabilityZone: stoppedAttachAZ},
ebsmetadata.Volume{VolumeID: "vol-other", State: "in-use", AttachedInstance: id, AvailabilityZone: stoppedAttachAZ},
)
f.svc.metadata = meta.metadata
stopped.AccountID = startVolumesAccount
_, err := f.svc.DetachVolumeFromStopped(context.Background(), stoppedDetachInput(id, "vol-root"), startVolumesAccount)
require.NoError(t, err)
vol, err := f.svc.metadata.GetVolume(context.Background(), startVolumesAccount, "vol-root")
require.NoError(t, err)
vol.State, vol.AttachedInstance = "available", ""
require.NoError(t, f.svc.metadata.PutVolume(context.Background(), vol))
out, err := f.svc.AttachVolumeToStopped(context.Background(),
&ec2.AttachVolumeInput{InstanceId: aws.String(id), VolumeId: aws.String("vol-root"), Device: aws.String("/dev/sda1")}, startVolumesAccount)
require.NoError(t, err)
assert.Equal(t, "/dev/sda1", aws.StringValue(out.Device))
var boot bool
for _, r := range stopped.EBSRequests.Requests {
if r.Name == "vol-root" {
boot = r.Boot
}
}
assert.True(t, boot, "the root device name makes it the boot volume")
_, err = f.svc.StartStoppedInstance(context.Background(), &StartStoppedInstanceInput{InstanceID: id}, startVolumesAccount)
require.Error(t, err, "the recorder fails the launch after the mount")
assert.Contains(t, rec.mounted, "vol-root", "the start now mounts the restored root")
}
@@ -0,0 +1,112 @@
package instance
import (
"errors"
"fmt"
"slices"
"time"
"github.com/aws/aws-sdk-go/aws"
"github.com/aws/aws-sdk-go/service/ec2"
viperblocklegacyv1 "github.com/mulgadc/spinifex/contracts/viperblockd/legacy/v1"
ebsmetadata "github.com/mulgadc/spinifex/spinifex/domains/ec2/ebs/metadata"
"github.com/mulgadc/spinifex/spinifex/foundation/aws/errors"
"github.com/mulgadc/spinifex/spinifex/runtime/compute/vm"
)
func findVolumeRequest(v *vm.VM, volumeID string) (viperblocklegacyv1.EBSRequest, bool) {
v.EBSRequests.Mu.Lock()
defer v.EBSRequests.Mu.Unlock()
i := slices.IndexFunc(v.EBSRequests.Requests, func(r viperblocklegacyv1.EBSRequest) bool { return r.Name == volumeID })
if i < 0 {
return viperblocklegacyv1.EBSRequest{}, false
}
return v.EBSRequests.Requests[i], true
}
// removeVolumeFromRecord drops the volume from the mount list and the API view
// of the record, and reports whether it was a data volume that was there.
func removeVolumeFromRecord(v *vm.VM, volumeID string) bool {
v.EBSRequests.Mu.Lock()
defer v.EBSRequests.Mu.Unlock()
i := slices.IndexFunc(v.EBSRequests.Requests, func(r viperblocklegacyv1.EBSRequest) bool { return r.Name == volumeID })
if i < 0 || v.EBSRequests.Requests[i].EFI {
return false
}
v.EBSRequests.Requests = slices.Delete(v.EBSRequests.Requests, i, i+1)
if v.Instance != nil {
v.Instance.BlockDeviceMappings = slices.DeleteFunc(v.Instance.BlockDeviceMappings, func(m *ec2.InstanceBlockDeviceMapping) bool {
return m != nil && m.Ebs != nil && aws.StringValue(m.Ebs.VolumeId) == volumeID
})
}
return true
}
// stoppedAttachDevice picks the device a volume takes on a stopped instance and
// reports whether it is the root. An empty request takes the next free
// /dev/sd[f-p]; a named device must be free, and the root device name is free
// only while no boot volume is attached.
func stoppedAttachDevice(v *vm.VM, requested string) (string, bool, error) {
root := ebsmetadata.RootDeviceName
if v.Instance != nil && aws.StringValue(v.Instance.RootDeviceName) != "" {
root = aws.StringValue(v.Instance.RootDeviceName)
}
v.EBSRequests.Mu.Lock()
defer v.EBSRequests.Mu.Unlock()
used := make(map[string]bool, len(v.EBSRequests.Requests))
hasBoot := false
for _, r := range v.EBSRequests.Requests {
if r.DeviceName != "" {
used[r.DeviceName] = true
}
hasBoot = hasBoot || r.Boot
}
if v.Instance != nil {
for _, m := range v.Instance.BlockDeviceMappings {
if m != nil && m.DeviceName != nil {
used[*m.DeviceName] = true
}
}
}
if requested == "" {
for c := 'f'; c <= 'p'; c++ {
if dev := fmt.Sprintf("/dev/sd%c", c); !used[dev] {
return dev, false, nil
}
}
return "", false, errors.New(awserrors.ErrorAttachmentLimitExceeded)
}
if used[requested] {
return "", false, errors.New(awserrors.ErrorInvalidParameterValue)
}
boot := requested == root
if boot && hasBoot {
return "", false, errors.New(awserrors.ErrorInvalidParameterValue)
}
return requested, boot, nil
}
// addVolumeToRecord adds the volume to the mount list and the API view of the
// record. The root device name makes it the boot volume.
func addVolumeToRecord(v *vm.VM, volumeID, device string, boot bool) {
v.EBSRequests.Mu.Lock()
defer v.EBSRequests.Mu.Unlock()
v.EBSRequests.Requests = append(v.EBSRequests.Requests, viperblocklegacyv1.EBSRequest{
Name: volumeID,
DeviceName: device,
Boot: boot,
})
if v.Instance == nil {
return
}
mapping := &ec2.InstanceBlockDeviceMapping{}
mapping.SetDeviceName(device)
mapping.Ebs = &ec2.EbsInstanceBlockDevice{}
mapping.Ebs.SetVolumeId(volumeID)
mapping.Ebs.SetAttachTime(time.Now())
mapping.Ebs.SetDeleteOnTermination(false)
mapping.Ebs.SetStatus("attached")
v.Instance.BlockDeviceMappings = append(v.Instance.BlockDeviceMappings, mapping)
}
@@ -0,0 +1,139 @@
package instance
import (
"context"
"testing"
"github.com/aws/aws-sdk-go/aws"
"github.com/aws/aws-sdk-go/service/ec2"
viperblocklegacyv1 "github.com/mulgadc/spinifex/contracts/viperblockd/legacy/v1"
"github.com/mulgadc/spinifex/spinifex/foundation/aws/errors"
awsidentifiers "github.com/mulgadc/spinifex/spinifex/foundation/aws/identifiers"
"github.com/mulgadc/spinifex/spinifex/runtime/compute/vm"
vmmock "github.com/mulgadc/spinifex/spinifex/runtime/compute/vm/mock"
"github.com/stretchr/testify/assert"
"github.com/stretchr/testify/require"
)
func stoppedWithVolumes(owner, id string) *vm.VM {
v := &vm.VM{
ID: id, AccountID: owner, Status: vm.StateStopped,
Instance: &ec2.Instance{
InstanceId: aws.String(id),
BlockDeviceMappings: []*ec2.InstanceBlockDeviceMapping{
{DeviceName: aws.String("/dev/sda1"), Ebs: &ec2.EbsInstanceBlockDevice{VolumeId: aws.String("vol-root")}},
{DeviceName: aws.String("/dev/sdf"), Ebs: &ec2.EbsInstanceBlockDevice{VolumeId: aws.String("vol-data")}},
{DeviceName: aws.String("/dev/sdg"), Ebs: &ec2.EbsInstanceBlockDevice{VolumeId: aws.String("vol-other")}},
},
},
}
v.EBSRequests.Requests = []viperblocklegacyv1.EBSRequest{
{Name: "vol-root", Boot: true, DeviceName: "/dev/sda1"},
{Name: "vol-data", DeviceName: "/dev/sdf"},
{Name: "vol-other", DeviceName: "/dev/sdg"},
}
return v
}
func stoppedDetachInput(instanceID, volumeID string) *ec2.DetachVolumeInput {
return &ec2.DetachVolumeInput{InstanceId: aws.String(instanceID), VolumeId: aws.String(volumeID)}
}
func volumeNames(v *vm.VM) []string {
var out []string
for _, r := range v.EBSRequests.Requests {
out = append(out, r.Name)
}
return out
}
// AWS lets a stopped instance's data volume be detached; the record must stop
// claiming it so a later start does not re-attach it.
func TestDetachVolumeFromStopped_RemovesOnlyThatVolume(t *testing.T) {
owner := awsidentifiers.GlobalAccountID
id := "i-stopped-detach"
stored := stoppedWithVolumes(owner, id)
store := &vmmock.StateStore{Stopped: map[string]*vm.VM{id: stored}}
svc := &InstanceServiceImpl{vmMgr: mgrWith(map[string]*vm.VM{}), stoppedStore: store}
out, err := svc.DetachVolumeFromStopped(context.Background(), stoppedDetachInput(id, "vol-data"), owner)
require.NoError(t, err)
assert.Equal(t, "/dev/sdf", aws.StringValue(out.Device))
assert.Equal(t, id, aws.StringValue(out.InstanceId))
assert.Equal(t, []string{"vol-root", "vol-other"}, volumeNames(stored))
var mapped []string
for _, m := range stored.Instance.BlockDeviceMappings {
mapped = append(mapped, aws.StringValue(m.Ebs.VolumeId))
}
assert.Equal(t, []string{"vol-root", "vol-other"}, mapped)
assert.Equal(t, vm.StateStopped, stored.Status, "the instance stays stopped")
}
func TestDetachVolumeFromStopped_Refusals(t *testing.T) {
owner := awsidentifiers.GlobalAccountID
tests := []struct {
name string
caller string
volume string
stopped bool
want string
}{
{"volume not on the instance", owner, "vol-elsewhere", true, awserrors.ErrorIncorrectState},
{"another account", "000000000099", "vol-data", true, awserrors.ErrorInvalidInstanceIDNotFound},
{"no such stopped instance", owner, "vol-data", false, awserrors.ErrorInvalidInstanceIDNotFound},
}
for _, tt := range tests {
t.Run(tt.name, func(t *testing.T) {
id := "i-stopped-refuse"
stored := stoppedWithVolumes(owner, id)
store := &vmmock.StateStore{Stopped: map[string]*vm.VM{}}
if tt.stopped {
store.Stopped[id] = stored
}
svc := &InstanceServiceImpl{vmMgr: mgrWith(map[string]*vm.VM{}), stoppedStore: store}
_, err := svc.DetachVolumeFromStopped(context.Background(), stoppedDetachInput(id, tt.volume), tt.caller)
require.Error(t, err)
assert.True(t, awserrors.IsErrorCode(err, tt.want), "got %v, want %s", err, tt.want)
assert.Equal(t, []string{"vol-root", "vol-data", "vol-other"}, volumeNames(stored),
"a refused detach changes nothing")
})
}
}
// AWS lets the root volume of a stopped instance be detached; the instance then
// cannot start until a volume is attached at its root device name again.
func TestDetachVolumeFromStopped_DetachesTheRootVolume(t *testing.T) {
owner := awsidentifiers.GlobalAccountID
id := "i-stopped-root"
stored := stoppedWithVolumes(owner, id)
store := &vmmock.StateStore{Stopped: map[string]*vm.VM{id: stored}}
svc := &InstanceServiceImpl{vmMgr: mgrWith(map[string]*vm.VM{}), stoppedStore: store}
out, err := svc.DetachVolumeFromStopped(context.Background(), stoppedDetachInput(id, "vol-root"), owner)
require.NoError(t, err)
assert.Equal(t, "/dev/sda1", aws.StringValue(out.Device))
assert.Equal(t, []string{"vol-data", "vol-other"}, volumeNames(stored))
assert.Equal(t, vm.StateStopped, stored.Status)
}
// The EFI variable store is Spinifex-internal and never shown to the customer,
// so it cannot be detached even by its name.
func TestDetachVolumeFromStopped_RefusesTheInternalEFIStore(t *testing.T) {
owner := awsidentifiers.GlobalAccountID
id := "i-stopped-efi"
stored := stoppedWithVolumes(owner, id)
stored.EBSRequests.Requests = append(stored.EBSRequests.Requests,
viperblocklegacyv1.EBSRequest{Name: "vol-efi", EFI: true})
store := &vmmock.StateStore{Stopped: map[string]*vm.VM{id: stored}}
svc := &InstanceServiceImpl{vmMgr: mgrWith(map[string]*vm.VM{}), stoppedStore: store}
_, err := svc.DetachVolumeFromStopped(context.Background(), stoppedDetachInput(id, "vol-efi"), owner)
require.Error(t, err)
assert.True(t, awserrors.IsErrorCode(err, awserrors.ErrorOperationNotPermitted), "got %v", err)
assert.Equal(t, []string{"vol-root", "vol-data", "vol-other", "vol-efi"}, volumeNames(stored))
}
@@ -1725,6 +1725,28 @@ func TestDeleteVolume_VolumeAttachedButAvailable(t *testing.T) {
assert.Equal(t, awserrors.ErrorVolumeInUse, err.Error())
}
// A stopped instance keeps its volumes in use, so deleting one is refused
// until it is detached; AWS answers the same.
func TestDeleteVolume_VolumeHeldByStoppedInstanceIsRefused(t *testing.T) {
kv := setupTestVolumeKV(t)
store := objectstore.NewMemoryObjectStore()
svc := newTestVolumeServiceWithStore("ap-southeast-2a", store)
svc.snapshotKV = kv
createVolumeInStoreWithMeta(t, svc, store, "vol-held", ebsmetadata.Volume{
VolumeID: "vol-held",
CapacityGiB: 10,
State: "in-use",
AttachedInstance: "i-stopped",
})
_, err := svc.DeleteVolume(context.Background(), &ec2.DeleteVolumeInput{
VolumeId: aws.String("vol-held"),
}, testVolAccountID)
require.Error(t, err)
assert.Equal(t, awserrors.ErrorVolumeInUse, err.Error())
}
func TestDeleteVolume_EmptyStateUnattachedDeletable(t *testing.T) {
kv := setupTestVolumeKV(t)
store := objectstore.NewMemoryObjectStore()
@@ -0,0 +1,228 @@
package vm
import (
"context"
"fmt"
"io"
"log/slog"
"os"
"path/filepath"
"strconv"
"strings"
"syscall"
"time"
hostprocess "github.com/mulgadc/spinifex/spinifex/runtime/host/process"
)
const (
// consoleTrimAbove is the size past which a console log is cut back.
consoleTrimAbove = 4 << 20
// consoleKeepBytes is how much of the newest output survives a cut.
consoleKeepBytes = 1 << 20
// consoleRemoveAfter is how long a retired console file lingers so a late
// GetConsoleOutput still sees it.
consoleRemoveAfter = time.Hour
// consoleIdleAfter is how long a live console file must sit unchanged, with
// no QEMU on this node holding it open, before it is removed.
consoleIdleAfter = time.Hour
)
// consoleTerminatedSuffix marks the console file of an instance that is gone
// for good. The log shipper only follows console-*.log, so a renamed file is
// no longer shipped, and the reaper removes it once it is old enough.
const consoleTerminatedSuffix = ".terminated"
// RetiredConsolePath is where the console file at path moves when its instance
// is terminated.
func RetiredConsolePath(path string) string { return path + consoleTerminatedSuffix }
// retireConsoleLog renames an ended instance's console file so the reaper can
// age it out. The file is final by now: QEMU is down or being force-finalized.
func retireConsoleLog(path string) {
if path == "" {
return
}
if err := os.Rename(path, RetiredConsolePath(path)); err != nil && !os.IsNotExist(err) {
slog.Warn("vm: retire console log failed", "path", path, "err", err)
}
}
// ConsoleLogReaper caps the serial console files under dir and removes the
// retired ones. A live console-<id>.log goes only after an idle hour with no
// QEMU on this node holding it open, decided from /proc alone and never from
// instance state.
type ConsoleLogReaper struct {
dir string
procRoot string
now func() time.Time
}
var _ Reaper = (*ConsoleLogReaper)(nil)
// NewConsoleLogReaper builds a reaper over the console files in dir.
func NewConsoleLogReaper(dir string) *ConsoleLogReaper {
return &ConsoleLogReaper{dir: dir, procRoot: qemuProcRoot, now: time.Now}
}
func (r *ConsoleLogReaper) Class() string { return "console-log" }
func (r *ConsoleLogReaper) Scope() ReaperScope { return ScopeNodeLocal }
// NewLocalConsoleLogReaper builds the reaper over this node's runtime directory.
func (m *Manager) NewLocalConsoleLogReaper() *ConsoleLogReaper {
return NewConsoleLogReaper(hostprocess.RuntimeDir())
}
// Sweep removes idle live console files nothing holds open, cuts oversized ones
// back to their newest consoleKeepBytes, and removes retired ones that have sat
// for over an hour.
func (r *ConsoleLogReaper) Sweep(context.Context) (int, error) {
reaped := 0
live, err := filepath.Glob(filepath.Join(r.dir, "console-*.log"))
if err != nil {
return 0, err
}
now := r.now()
warned := false
for _, p := range live {
info, err := os.Stat(p)
if err != nil || !info.Mode().IsRegular() {
continue
}
if now.Sub(info.ModTime()) > consoleIdleAfter && r.removeIfUnheld(p, &warned) {
reaped++
continue
}
if info.Size() <= consoleTrimAbove {
continue
}
if err := trimConsoleLog(p); err != nil {
slog.Warn("vm/gc: trim console log failed", "path", p, "err", err)
continue
}
reaped++
}
retired, err := filepath.Glob(filepath.Join(r.dir, "console-*.log"+consoleTerminatedSuffix))
if err != nil {
return reaped, err
}
for _, p := range retired {
info, err := os.Stat(p)
if err != nil || !info.Mode().IsRegular() || now.Sub(info.ModTime()) <= consoleRemoveAfter {
continue
}
if err := os.Remove(p); err != nil && !os.IsNotExist(err) {
slog.Warn("vm/gc: remove retired console log failed", "path", p, "err", err)
continue
}
reaped++
}
return reaped, nil
}
// removeIfUnheld removes path when no QEMU process on this node has it open. If
// the process table cannot be read in full it removes nothing, since a guest
// that is merely quiet must keep its log.
func (r *ConsoleLogReaper) removeIfUnheld(path string, warned *bool) bool {
held, err := qemuOpenFiles(r.procRoot, r.dir)
if err != nil {
if !*warned {
slog.Warn("vm/gc: idle console logs kept, cannot tell whether QEMU holds them", "err", err)
*warned = true
}
return false
}
if resolved, err := filepath.EvalSymlinks(path); err == nil {
path = resolved
}
if held[path] {
return false
}
if err := os.Remove(path); err != nil {
if !os.IsNotExist(err) {
slog.Warn("vm/gc: remove idle console log failed", "path", path, "err", err)
}
return false
}
return true
}
// qemuOpenFiles returns the files every QEMU process under procRoot has open.
// Any unreadable descriptor table is an error, never a partial answer. The scan
// is complete only while the daemon keeps CAP_SYS_ADMIN under ProtectProc=invisible,
// so an instance pidfile naming a live pid the scan missed is an error too.
func qemuOpenFiles(procRoot, runtimeDir string) (map[string]bool, error) {
pids, err := scanLiveQEMUPIDs(procRoot)
if err != nil {
return nil, err
}
if err := checkPidFilesVisible(runtimeDir, pids); err != nil {
return nil, err
}
held := make(map[string]bool)
for _, pid := range pids {
fdDir := filepath.Join(procRoot, strconv.Itoa(pid), "fd")
fds, err := os.ReadDir(fdDir)
if err != nil {
if os.IsNotExist(err) {
continue
}
return nil, err
}
for _, fd := range fds {
target, err := os.Readlink(filepath.Join(fdDir, fd.Name()))
if err != nil {
if os.IsNotExist(err) {
continue
}
return nil, err
}
held[target] = true
}
}
return held, nil
}
// checkPidFilesVisible fails when an instance pidfile names a process that is
// alive but absent from seen. Signal 0 answers even when /proc hides the pid.
func checkPidFilesVisible(runtimeDir string, seen []int) error {
visible := make(map[int]bool, len(seen))
for _, pid := range seen {
visible[pid] = true
}
for pid, id := range pidFileOwners(runtimeDir) {
if !strings.HasPrefix(id, "i-") || visible[pid] {
continue
}
if err := syscall.Kill(pid, 0); err == nil || err == syscall.EPERM {
return fmt.Errorf("pidfile for %s names live pid %d that the process scan cannot see", id, pid)
}
}
return nil
}
// trimConsoleLog rewrites the file in place as its newest consoleKeepBytes. The
// guest's writer keeps its descriptor (O_APPEND), so output written while the
// copy runs may be lost but the writer is never blocked.
func trimConsoleLog(path string) error {
f, err := os.OpenFile(path, os.O_RDWR, 0)
if err != nil {
return err
}
defer f.Close()
info, err := f.Stat()
if err != nil {
return err
}
if info.Size() <= consoleTrimAbove {
return nil
}
tail := make([]byte, consoleKeepBytes)
if _, err := f.ReadAt(tail, info.Size()-consoleKeepBytes); err != nil && err != io.EOF {
return err
}
if _, err := f.WriteAt(tail, 0); err != nil {
return err
}
return f.Truncate(consoleKeepBytes)
}
@@ -0,0 +1,298 @@
package vm
import (
"bytes"
"context"
"fmt"
"io"
"os"
"os/exec"
"path/filepath"
"strconv"
"testing"
"time"
"github.com/stretchr/testify/assert"
"github.com/stretchr/testify/require"
)
// consoleBody returns n bytes of 16-byte numbered lines, so any slice of it
// identifies which part of the original it came from.
func consoleBody(n int) []byte {
var b bytes.Buffer
for i := 0; b.Len() < n; i++ {
fmt.Fprintf(&b, "l%014d\n", i)
}
return b.Bytes()[:n]
}
func newConsoleReaper(t *testing.T, now time.Time) (*ConsoleLogReaper, string) {
t.Helper()
dir := t.TempDir()
r := NewConsoleLogReaper(dir)
r.procRoot = t.TempDir()
r.now = func() time.Time { return now }
return r, dir
}
func writeConsole(t *testing.T, dir, id string, body []byte, mtime time.Time) string {
t.Helper()
p := filepath.Join(dir, "console-"+id+".log")
require.NoError(t, os.WriteFile(p, body, 0o644))
require.NoError(t, os.Chtimes(p, mtime, mtime))
return p
}
func TestConsoleLogReaper_TrimsToNewestMiB(t *testing.T) {
now := time.Now()
r, dir := newConsoleReaper(t, now)
body := consoleBody(5 << 20)
p := writeConsole(t, dir, "i-big", body, now)
reaped, err := r.Sweep(context.Background())
require.NoError(t, err)
assert.Equal(t, 1, reaped)
got, err := os.ReadFile(p)
require.NoError(t, err)
gotSize := len(got)
require.Equal(t, consoleKeepBytes, gotSize, "a trim keeps exactly the newest MiB")
assert.True(t, bytes.Equal(body[len(body)-consoleKeepBytes:], got), "the newest MiB must survive, in order")
}
func TestConsoleLogReaper_LeavesFilesAtOrBelowTheLimit(t *testing.T) {
now := time.Now()
r, dir := newConsoleReaper(t, now)
small := consoleBody(3 << 20)
limit := consoleBody(consoleTrimAbove)
ps := writeConsole(t, dir, "i-small", small, now)
pl := writeConsole(t, dir, "i-limit", limit, now)
reaped, err := r.Sweep(context.Background())
require.NoError(t, err)
assert.Zero(t, reaped)
for p, want := range map[string][]byte{ps: small, pl: limit} {
got, err := os.ReadFile(p)
require.NoError(t, err)
assert.True(t, bytes.Equal(want, got), "%s must not change", filepath.Base(p))
}
}
// QEMU writes through a descriptor it keeps open, so the trim must leave the
// file usable for that writer: no hole of NULs, and later output at the end.
func TestConsoleLogReaper_AppendWriterKeepsWritingAfterTrim(t *testing.T) {
now := time.Now()
r, dir := newConsoleReaper(t, now)
p := filepath.Join(dir, "console-i-live.log")
w, err := os.OpenFile(p, os.O_WRONLY|os.O_CREATE|os.O_APPEND, 0o644)
require.NoError(t, err)
defer w.Close()
_, err = w.Write(consoleBody(5 << 20))
require.NoError(t, err)
_, err = r.Sweep(context.Background())
require.NoError(t, err)
marker := []byte("after-trim-marker\n")
_, err = w.Write(marker)
require.NoError(t, err)
got, err := os.ReadFile(p)
require.NoError(t, err)
assert.Zero(t, bytes.Count(got, []byte{0}), "no NUL hole from a stale write offset")
assert.True(t, bytes.HasSuffix(got, marker), "the writer's next line lands at the end")
assert.LessOrEqual(t, len(got), consoleKeepBytes+len(marker))
}
func TestConsoleLogReaper_RemovesOnlyAgedRetiredFiles(t *testing.T) {
now := time.Now()
r, dir := newConsoleReaper(t, now)
old := now.Add(-consoleRemoveAfter - time.Minute)
recent := now.Add(-consoleRemoveAfter + time.Minute)
retiredOld := writeConsole(t, dir, "i-gone-old", []byte("x\n"), old)
retiredNew := writeConsole(t, dir, "i-gone-new", []byte("x\n"), recent)
require.NoError(t, os.Rename(retiredOld, RetiredConsolePath(retiredOld)))
require.NoError(t, os.Rename(retiredNew, RetiredConsolePath(retiredNew)))
require.NoError(t, os.Chtimes(RetiredConsolePath(retiredOld), old, old))
require.NoError(t, os.Chtimes(RetiredConsolePath(retiredNew), recent, recent))
// A live file that is not yet idle for an hour is kept.
stopped := writeConsole(t, dir, "i-stopped", []byte("boot\n"), recent)
other := filepath.Join(dir, "serial-i-x.sock.log.terminated")
require.NoError(t, os.WriteFile(other, []byte("x"), 0o644))
require.NoError(t, os.Chtimes(other, old, old))
reaped, err := r.Sweep(context.Background())
require.NoError(t, err)
assert.Equal(t, 1, reaped, "only the retired file older than an hour")
_, err = os.Stat(RetiredConsolePath(retiredOld))
assert.ErrorIs(t, err, os.ErrNotExist, "retired over an hour ago: removed")
_, err = os.Stat(RetiredConsolePath(retiredNew))
assert.NoError(t, err, "retired recently: kept for a late GetConsoleOutput")
_, err = os.Stat(stopped)
assert.NoError(t, err, "a live file idle for under an hour is kept")
_, err = os.Stat(other)
assert.NoError(t, err, "files that are not console logs are never touched")
}
func TestRetireConsoleLog(t *testing.T) {
dir := t.TempDir()
p := writeConsole(t, dir, "i-end", []byte("last words\n"), time.Now())
retireConsoleLog(p)
_, err := os.Stat(p)
assert.ErrorIs(t, err, os.ErrNotExist, "the live name no longer matches the shipper's glob")
got, err := os.ReadFile(RetiredConsolePath(p))
require.NoError(t, err)
assert.Equal(t, "last words\n", string(got))
assert.NotPanics(t, func() { retireConsoleLog(p) }, "a repeat finalize is a no-op")
assert.NotPanics(t, func() { retireConsoleLog("") }, "an instance that never got a console path is a no-op")
}
func TestConsoleLogReaper_TrimsOnlyLiveFiles(t *testing.T) {
now := time.Now()
r, dir := newConsoleReaper(t, now)
big := writeConsole(t, dir, "i-big", consoleBody(5<<20), now)
retired := writeConsole(t, dir, "i-gone", consoleBody(5<<20), now)
require.NoError(t, os.Rename(retired, RetiredConsolePath(retired)))
reaped, err := r.Sweep(context.Background())
require.NoError(t, err)
assert.Equal(t, 1, reaped)
info, err := os.Stat(big)
require.NoError(t, err)
assert.Equal(t, int64(consoleKeepBytes), info.Size())
info, err = os.Stat(RetiredConsolePath(retired))
require.NoError(t, err)
assert.Equal(t, int64(5<<20), info.Size(), "a retired file is final and is only aged out")
}
func TestExecute_ConsoleAlwaysAppends(t *testing.T) {
for _, tc := range []struct {
name string
cfg Config
want string
}{
{"socket first boot", Config{SerialSocket: "/s", ConsoleLogPath: "/c"}, "logfile=/c,logappend=on"},
{"microvm first boot", Config{MachineType: "microvm", ConsoleLogPath: "/c"}, "file,id=console0,path=/c,append=on"},
} {
t.Run(tc.name, func(t *testing.T) {
cfg := minimalConfig()
cfg.MachineType, cfg.SerialSocket = tc.cfg.MachineType, tc.cfg.SerialSocket
cfg.ConsoleLogPath = tc.cfg.ConsoleLogPath
cmd, err := cfg.Execute()
require.NoError(t, err)
var chardev string
for i, a := range cmd.Args {
if a == "-chardev" && i+1 < len(cmd.Args) {
chardev = cmd.Args[i+1]
}
}
assert.Contains(t, chardev, tc.want, "a truncating open would let an in-place trim leave a NUL hole")
})
}
}
// fakeQEMUProc fabricates procRoot/<pid> with a QEMU comm and the given open files.
func fakeQEMUProc(t *testing.T, procRoot string, pid int, open ...string) {
t.Helper()
pdir := filepath.Join(procRoot, strconv.Itoa(pid))
require.NoError(t, os.MkdirAll(filepath.Join(pdir, "fd"), 0o755))
require.NoError(t, os.WriteFile(filepath.Join(pdir, "comm"), []byte("qemu-system-x86\n"), 0o644))
for i, f := range open {
require.NoError(t, os.Symlink(f, filepath.Join(pdir, "fd", strconv.Itoa(i+3))))
}
}
func TestConsoleLogReaper_RemovesIdleLiveFileNothingHolds(t *testing.T) {
now := time.Now()
r, dir := newConsoleReaper(t, now)
idle := writeConsole(t, dir, "i-stopped-then-terminated", []byte("boot\n"), now.Add(-consoleIdleAfter-time.Minute))
fresh := writeConsole(t, dir, "i-fresh", []byte("boot\n"), now.Add(-consoleIdleAfter+time.Minute))
fakeQEMUProc(t, r.procRoot, 4242)
reaped, err := r.Sweep(context.Background())
require.NoError(t, err)
assert.Equal(t, 1, reaped)
_, err = os.Stat(idle)
assert.ErrorIs(t, err, os.ErrNotExist, "idle over an hour and unopened: removed")
_, err = os.Stat(fresh)
assert.NoError(t, err, "written within the hour: kept")
}
func TestConsoleLogReaper_KeepsIdleFileHeldByRealProcess(t *testing.T) {
now := time.Now()
r, dir := newConsoleReaper(t, now)
held := writeConsole(t, dir, "i-quiet-guest", []byte("boot\n"), now.Add(-48*time.Hour))
// A real child holds the file open, as QEMU holds its chardev log.
cmd := exec.Command("sh", "-c", "exec 3<"+held+"; echo ready; read _")
stdin, err := cmd.StdinPipe()
require.NoError(t, err)
out, err := cmd.StdoutPipe()
require.NoError(t, err)
require.NoError(t, cmd.Start())
t.Cleanup(func() { _ = stdin.Close(); _ = cmd.Wait() })
line := make([]byte, 6)
_, err = io.ReadFull(out, line)
require.NoError(t, err)
// Present the child to the reaper as a QEMU process using its real fd table.
r.procRoot = t.TempDir()
pdir := filepath.Join(r.procRoot, strconv.Itoa(cmd.Process.Pid))
require.NoError(t, os.MkdirAll(pdir, 0o755))
require.NoError(t, os.WriteFile(filepath.Join(pdir, "comm"), []byte("qemu-system-x86\n"), 0o644))
require.NoError(t, os.Symlink(fmt.Sprintf("/proc/%d/fd", cmd.Process.Pid), filepath.Join(pdir, "fd")))
reaped, err := r.Sweep(context.Background())
require.NoError(t, err)
assert.Zero(t, reaped)
_, err = os.Stat(held)
assert.NoError(t, err, "a quiet running guest keeps its log")
}
func TestConsoleLogReaper_KeepsIdleFileWhenProcessTableUnreadable(t *testing.T) {
now := time.Now()
r, dir := newConsoleReaper(t, now)
idle := writeConsole(t, dir, "i-unprovable", []byte("boot\n"), now.Add(-48*time.Hour))
pdir := filepath.Join(r.procRoot, "4242")
require.NoError(t, os.MkdirAll(pdir, 0o755))
require.NoError(t, os.WriteFile(filepath.Join(pdir, "comm"), []byte("qemu-system-x86\n"), 0o644))
// A QEMU whose fd table cannot be read: a dangling fd entry that is a file, not a directory.
require.NoError(t, os.WriteFile(filepath.Join(pdir, "fd"), nil, 0o644))
reaped, err := r.Sweep(context.Background())
require.NoError(t, err)
assert.Zero(t, reaped)
_, err = os.Stat(idle)
assert.NoError(t, err, "cannot prove it is unused: kept")
}
func TestConsoleLogReaper_KeepsIdleFileWhenPidFileNamesLivePidTheScanMissed(t *testing.T) {
now := time.Now()
r, dir := newConsoleReaper(t, now)
idle := writeConsole(t, dir, "i-quiet", []byte("boot\n"), now.Add(-48*time.Hour))
// This test process is alive but is no QEMU, so the fabricated scan never lists it.
require.NoError(t, os.WriteFile(filepath.Join(dir, "i-quiet.pid"), []byte(strconv.Itoa(os.Getpid())), 0o644))
reaped, err := r.Sweep(context.Background())
require.NoError(t, err)
assert.Zero(t, reaped)
_, err = os.Stat(idle)
assert.NoError(t, err, "a live pid the scan cannot see means the scan is incomplete: nothing removed")
}
func TestConsoleLogReaper_IgnoresPidFileOfDeadProcess(t *testing.T) {
now := time.Now()
r, dir := newConsoleReaper(t, now)
idle := writeConsole(t, dir, "i-gone", []byte("boot\n"), now.Add(-48*time.Hour))
cmd := exec.Command("true")
require.NoError(t, cmd.Run())
require.NoError(t, os.WriteFile(filepath.Join(dir, "i-gone.pid"), []byte(strconv.Itoa(cmd.Process.Pid)), 0o644))
reaped, err := r.Sweep(context.Background())
require.NoError(t, err)
assert.Equal(t, 1, reaped)
_, err = os.Stat(idle)
assert.ErrorIs(t, err, os.ErrNotExist, "a pidfile for a dead process does not block removal")
}
@@ -0,0 +1,85 @@
package vm
import (
"context"
"os"
"path/filepath"
"testing"
"github.com/aws/aws-sdk-go/service/ec2"
"github.com/stretchr/testify/assert"
"github.com/stretchr/testify/require"
)
func consoleFixture(t *testing.T, id string) (*VM, string) {
t.Helper()
path := filepath.Join(t.TempDir(), "console-"+id+".log")
require.NoError(t, os.WriteFile(path, []byte("last output\n"), 0o644))
return &VM{
ID: id,
Status: StateRunning,
InstanceType: "t3.micro",
Instance: &ec2.Instance{},
Config: Config{ConsoleLogPath: path},
}, path
}
func requireRetired(t *testing.T, path string) {
t.Helper()
_, err := os.Stat(path)
require.ErrorIs(t, err, os.ErrNotExist, "the shipper's console-*.log glob must no longer match")
got, err := os.ReadFile(RetiredConsolePath(path))
require.NoError(t, err)
assert.Equal(t, "last output\n", string(got), "the content survives the rename")
}
func requireLive(t *testing.T, path string) {
t.Helper()
_, err := os.Stat(path)
require.NoError(t, err)
_, err = os.Stat(RetiredConsolePath(path))
require.ErrorIs(t, err, os.ErrNotExist)
}
func TestTerminate_RetiresConsoleLog(t *testing.T) {
m, _, _, _, _ := shutdownTestManager(t)
instance, path := consoleFixture(t, "i-term-console")
m.Insert(instance)
require.NoError(t, m.Terminate(instance.ID))
requireRetired(t, path)
}
func TestMarkFailed_RetiresConsoleLog(t *testing.T) {
m, _, _, _, _ := shutdownTestManager(t)
instance, path := consoleFixture(t, "i-failed-console")
instance.FirstLaunch = true
instance.Status = StatePending
m.Insert(instance)
m.MarkFailed(context.Background(), instance, "launch failed")
m.goroutineWg.Wait()
requireRetired(t, path)
}
func TestStop_KeepsConsoleLog(t *testing.T) {
m, _, _, _, _ := shutdownTestManager(t)
instance, path := consoleFixture(t, "i-stop-console")
m.Insert(instance)
require.NoError(t, m.Stop(instance.ID))
requireLive(t, path)
}
func TestStopAll_DrainKeepsConsoleLog(t *testing.T) {
m, _, _, _, _ := shutdownTestManager(t)
instance, path := consoleFixture(t, "i-drain-console")
m.Insert(instance)
require.NoError(t, m.StopAll())
requireLive(t, path)
}
@@ -0,0 +1,27 @@
package vm
import "log/slog"
// HandleQEMUExit decides what a finished QEMU process means once startup was
// confirmed. A wait error is a crash. A clean exit after the heartbeat saw the
// guest power itself off is a customer stop, kept in the stopped bucket so
// StartInstances can bring it back. Any other clean exit is left to the
// heartbeat's crash detection.
func (m *Manager) HandleQEMUExit(instance *VM, waitErr error) {
if waitErr != nil {
if m.deps.CrashHandler != nil {
m.deps.CrashHandler(instance, waitErr)
}
return
}
if !instance.guestPoweroff.Load() {
slog.Info("VM process exited cleanly", "instance", instance.ID)
return
}
slog.Info("Guest powered itself off, stopping instance", "instance", instance.ID)
m.UpdateState(instance.ID, func(v *VM) { v.DesiredState = DesiredStopped })
if err := m.Stop(instance.ID); err != nil {
slog.Error("Stop after guest poweroff failed", "instance", instance.ID, "err", err)
}
}
@@ -0,0 +1,155 @@
package vm
import (
"errors"
"sync"
"testing"
"time"
"github.com/aws/aws-sdk-go/service/ec2"
"github.com/mulgadc/spinifex/spinifex/runtime/compute/qmp"
"github.com/stretchr/testify/assert"
"github.com/stretchr/testify/require"
)
func guestPoweroffManager(t *testing.T) (*Manager, *fakeStateStore, *recordedTransitions, *[]string) {
t.Helper()
m, store, _, _, rt := shutdownTestManager(t)
var (
mu sync.Mutex
down []string
)
m.SetDeps(Deps{
NodeID: "test-node",
StateStore: store,
VolumeMounter: &fakeVolumeMounter{},
InstanceCleaner: &recordingInstanceCleaner{},
TransitionState: rt.apply,
ShutdownSignal: func() bool { return false },
CrashHandler: m.HandleCrash,
Hooks: ManagerHooks{
OnInstanceDown: func(id string) {
mu.Lock()
down = append(down, id)
mu.Unlock()
},
},
})
return m, store, rt, &down
}
func TestQMPHeartbeatPoll_MarksGuestPoweroff(t *testing.T) {
for name, tc := range map[string]struct {
status string
running bool
want bool
}{
"guest shut down": {qmpStatusShutdown, false, true},
"guest running": {"running", true, false},
} {
t.Run(name, func(t *testing.T) {
qmpClient, cancel := newMockQMPClient(t, func(cmd qmp.QMPCommand) map[string]any {
if cmd.Execute == "query-status" {
return qmpStatusResponse(tc.status, tc.running)
}
return nil
})
defer cancel()
m := NewManager()
instance := &VM{ID: "i-1", Status: StateRunning, QMPClient: qmpClient}
m.Insert(instance)
require.True(t, m.qmpHeartbeatPoll(instance))
assert.Equal(t, tc.want, instance.guestPoweroff.Load())
})
}
}
// A guest that powered itself off is a stop: stopping then stopped, released
// to the stopped bucket so StartInstances can bring it back, and never a crash.
func TestHandleQEMUExit_GuestPoweroffStopsInstance(t *testing.T) {
m, store, rt, down := guestPoweroffManager(t)
scheduled := countScheduledRestarts(t)
instance := &VM{
ID: "i-poweroff",
Status: StateRunning,
InstanceType: "t3.micro",
Instance: &ec2.Instance{},
}
instance.guestPoweroff.Store(true)
m.Insert(instance)
started := time.Now()
m.HandleQEMUExit(instance, nil)
assert.Less(t, time.Since(started), qmpHeartbeatInterval,
"the stop must not wait for the next heartbeat")
assert.Equal(t, []InstanceState{StateStopping, StateStopped}, rt.targets(instance.ID),
"a guest poweroff goes stopping then stopped and never through error")
assert.Zero(t, scheduled.Load(), "a guest poweroff must not be restarted")
assert.Equal(t, []string{instance.ID}, *down)
stored, err := store.LoadStoppedInstance(instance.ID)
require.NoError(t, err)
require.NotNil(t, stored, "the instance must be startable from the stopped bucket")
assert.Equal(t, StateStopped, stored.Status)
}
// Without the guest-poweroff mark a clean exit is not ours to call a stop.
func TestHandleQEMUExit_CleanExitWithoutMarkIsLeftToCrashRecovery(t *testing.T) {
m, _, rt, _ := guestPoweroffManager(t)
instance := &VM{ID: "i-clean", Status: StateRunning, InstanceType: "t3.micro", Instance: &ec2.Instance{}}
m.Insert(instance)
m.HandleQEMUExit(instance, nil)
assert.Empty(t, rt.targets(instance.ID), "no stop without the mark")
assert.Equal(t, StateRunning, m.Status(instance))
}
// A wait error is a crash even when the mark is set: the mark only vouches for
// the quit we sent, not for a process that died some other way.
func TestHandleQEMUExit_WaitErrorIsACrashEvenWithMark(t *testing.T) {
m, _, rt, _ := guestPoweroffManager(t)
countScheduledRestarts(t)
instance := &VM{ID: "i-killed", Status: StateRunning, InstanceType: "t3.micro", Instance: &ec2.Instance{}}
instance.guestPoweroff.Store(true)
m.Insert(instance)
m.HandleQEMUExit(instance, errors.New("signal: killed"))
assert.Contains(t, rt.targets(instance.ID), StateError)
assert.NotContains(t, rt.targets(instance.ID), StateStopped)
}
// One heartbeat poll is enough to see the poweroff and end QEMU, and the exit
// then stops the instance. It never goes through the failure count that
// precedes crash recovery, which takes three polls to reach. The interval is a
// constant, so "within one interval" is a single poll with no waiting.
func TestGuestPoweroff_ReachesStoppedFromOnePollWithoutCrashCounting(t *testing.T) {
m, _, rt, _ := guestPoweroffManager(t)
scheduled := countScheduledRestarts(t)
qmpClient, cancel := newMockQMPClient(t, func(cmd qmp.QMPCommand) map[string]any {
if cmd.Execute == "query-status" {
return qmpStatusResponse(qmpStatusShutdown, false)
}
return nil
})
defer cancel()
instance := &VM{
ID: "i-one-poll", Status: StateRunning, InstanceType: "t3.micro",
Instance: &ec2.Instance{}, QMPClient: qmpClient,
}
m.Insert(instance)
require.True(t, m.qmpHeartbeatPoll(instance), "the poll keeps running until QEMU exits")
m.HandleQEMUExit(instance, nil)
assert.Equal(t, []InstanceState{StateStopping, StateStopped}, rt.targets(instance.ID))
assert.Zero(t, instance.Health.QMPConsecutiveFailures, "a powered-off guest is not a failed heartbeat")
assert.Zero(t, scheduled.Load(), "no crash restart")
}
+6 -12
View File
@@ -176,7 +176,7 @@ func (m *Manager) launch(ctx context.Context, instance *VM) (err error) {
}
_, qemuSpan := otel.Tracer(vmTracerName).Start(ctx, "vm.launch.start_qemu")
qemuErr := m.startQEMU(instance, false)
qemuErr := m.startQEMU(instance)
endSpanWithError(qemuSpan, qemuErr)
if qemuErr != nil {
slog.ErrorContext(ctx, "Failed to launch instance", "err", qemuErr)
@@ -282,9 +282,9 @@ func qemuStderrLevel(line string) slog.Level {
}
// startQEMU launches the QEMU process for instance and waits for startup to
// confirm. appendConsole keeps the console log of the process it replaces, so a
// reboot does not erase what the guest printed before it.
func (m *Manager) startQEMU(instance *VM, appendConsole bool) error {
// confirm. The console log is opened in append mode, so a replacement process
// keeps what the guest printed before it.
func (m *Manager) startQEMU(instance *VM) error {
pidFile, err := hostprocess.GeneratePidFile(instance.ID)
if err != nil {
slog.Error("Failed to generate PID file", "err", err)
@@ -504,7 +504,6 @@ func (m *Manager) startQEMU(instance *VM, appendConsole bool) error {
}
launchCfg = &composed
}
launchCfg.ConsoleLogAppend = appendConsole
// An NBD export is waited on until it accepts connections; a block export
// is local to the host and only has to exist. An invalid request has no
@@ -607,13 +606,7 @@ func (m *Manager) startQEMU(instance *VM, appendConsole bool) error {
slog.Info("Replaced VM process exited", "instance", instance.ID, "pid", cmd.Process.Pid, "err", waitErr)
return
}
if waitErr != nil {
if m.deps.CrashHandler != nil {
m.deps.CrashHandler(instance, waitErr)
}
} else {
slog.Info("VM process exited cleanly", "instance", instance.ID)
}
m.HandleQEMUExit(instance, waitErr)
}()
pid := <-processChan
@@ -968,6 +961,7 @@ func (m *Manager) qmpHeartbeatPoll(instance *VM) bool {
if err == nil && qmpStatus.Status == qmpStatusShutdown &&
m.Status(instance) == StateRunning {
slog.InfoContext(ctx, "Guest powered itself off, ending QEMU", "instance", instance.ID)
instance.guestPoweroff.Store(true)
if _, quitErr := sendQMPCommand(ctx, instance.QMPClient,
qmp.QMPCommand{Execute: "quit"}, instance.ID); quitErr != nil {
slog.WarnContext(ctx, "QMP quit failed after guest shutdown",
+15 -15
View File
@@ -1042,7 +1042,7 @@ func TestStartQEMU_DirectBoot_PrimaryTapError(t *testing.T) {
ENIMac: "02:aa:bb:cc:dd:01",
}
err := m.startQEMU(instance, false)
err := m.startQEMU(instance)
require.Error(t, err)
assert.Contains(t, err.Error(), "setup tap device")
@@ -1070,7 +1070,7 @@ func TestStartQEMU_DirectBoot_BridgeEnsureError(t *testing.T) {
ENIMac: "02:aa:bb:cc:dd:04",
}
err := m.startQEMU(instance, false)
err := m.startQEMU(instance)
require.Error(t, err)
assert.Contains(t, err.Error(), "ensure IMDS bridge")
@@ -1105,7 +1105,7 @@ func TestStartQEMU_DirectBoot_ExtraENITapError(t *testing.T) {
},
}
err := m.startQEMU(instance, false)
err := m.startQEMU(instance)
require.Error(t, err)
assert.Contains(t, err.Error(), "extra ENI")
@@ -1126,7 +1126,7 @@ func TestStartQEMU_DirectBoot_MgmtTapError(t *testing.T) {
MgmtMAC: "02:aa:bb:cc:dd:ff",
}
err := m.startQEMU(instance, false)
err := m.startQEMU(instance)
require.Error(t, err)
assert.Contains(t, err.Error(), "mgmt tap")
@@ -1152,7 +1152,7 @@ func TestStartQEMU_DiskBoot_MgmtTapCreated(t *testing.T) {
}
instance.EBSRequests.Requests = []EBSRequest{{Name: "vol-root", NBDURI: "nbd:unix:/tmp/root.sock", Boot: true}}
err := m.startQEMU(instance, false)
err := m.startQEMU(instance)
require.Error(t, err)
assert.Contains(t, err.Error(), "mgmt tap")
@@ -1174,7 +1174,7 @@ func TestStartQEMU_DirectBoot_InstanceTypeNotFound(t *testing.T) {
DirectBoot: true,
}
err := m.startQEMU(instance, false)
err := m.startQEMU(instance)
require.Error(t, err)
assert.Contains(t, err.Error(), "x9.enormous")
@@ -1190,7 +1190,7 @@ func TestStartQEMU_BlockDeviceMissing(t *testing.T) {
instance := directBootInstance("i-blk-missing",
EBSRequest{Name: "vol-blk", BlockDevice: missing, BlockSizeBytes: 1 << 20})
err := m.startQEMU(instance, false)
err := m.startQEMU(instance)
require.Error(t, err)
assert.Contains(t, err.Error(), "block device not present for vol-blk")
@@ -2089,12 +2089,12 @@ func TestStartQEMU_DirectBoot_LaunchesMountedDataVolumeWithoutSavingIt(t *testin
second := nbdListener(t)
instance := directBootInstance("i-db-vol", EBSRequest{Name: "vol-data-a", NBDURI: first})
require.NoError(t, m.startQEMU(instance, false))
require.NoError(t, m.startQEMU(instance))
// A later launch from the same saved base, after the volume was remounted
// on a different endpoint.
instance.EBSRequests.Requests[0].NBDURI = second
require.NoError(t, m.startQEMU(instance, false))
require.NoError(t, m.startQEMU(instance))
got := launches()
require.Len(t, got, 2)
@@ -2136,7 +2136,7 @@ func TestStartQEMU_DirectBoot_LaunchesTheEndpointItProbed(t *testing.T) {
instance.EBSRequests.Mu.Unlock()
return orig(uri, timeout)
}
require.NoError(t, m.startQEMU(instance, false))
require.NoError(t, m.startQEMU(instance))
assert.Equal(t, []string{probedEP}, probed)
got := launches()
@@ -2151,7 +2151,7 @@ func TestStartQEMU_DirectBoot_NoVolumesLaunchesTheBase(t *testing.T) {
launches := withFakeQEMU(t)
instance := directBootInstance("i-db-novol")
require.NoError(t, m.startQEMU(instance, false))
require.NoError(t, m.startQEMU(instance))
got := launches()
require.Len(t, got, 1)
@@ -2176,7 +2176,7 @@ func TestStartQEMU_DirectBoot_InvalidDataRequestIsNotLaunched(t *testing.T) {
launches := withFakeQEMU(t)
instance := directBootInstance("i-db-bad", tt.req)
err := m.startQEMU(instance, false)
err := m.startQEMU(instance)
require.Error(t, err)
assert.Contains(t, err.Error(), tt.wantErr)
@@ -2197,7 +2197,7 @@ func TestStartQEMU_DiskBoot_DataVolumeStaysOnThePCIPath(t *testing.T) {
{Name: "vol-data-a", NBDURI: ep},
}
require.NoError(t, os.WriteFile(strings.TrimPrefix(instance.EBSRequests.Requests[0].NBDURI, "nbd:unix:"), nil, 0o600))
require.NoError(t, m.startQEMU(instance, false))
require.NoError(t, m.startQEMU(instance))
got := launches()
require.Len(t, got, 1)
@@ -2252,7 +2252,7 @@ func TestStartQEMU_DiskBoot_BootVolumeIsABlockdevNode(t *testing.T) {
req := tt.req(t)
instance := &VM{ID: "i-boot-blockdev", InstanceType: "t3.nano"}
instance.EBSRequests.Requests = []EBSRequest{req}
require.NoError(t, m.startQEMU(instance, false))
require.NoError(t, m.startQEMU(instance))
got := launches()
require.Len(t, got, 1)
@@ -2283,7 +2283,7 @@ func TestStartQEMU_DiskBoot_NoBootVolumeIsNotLaunched(t *testing.T) {
instance := &VM{ID: "i-no-boot", InstanceType: "t3.nano"}
instance.EBSRequests.Requests = tt.requests
err := m.startQEMU(instance, false)
err := m.startQEMU(instance)
require.Error(t, err)
assert.Contains(t, err.Error(), "no boot volume among the instance's EBS requests")
+1 -1
View File
@@ -52,7 +52,7 @@ const (
// startRelaunchedQEMU starts the replacement process. A var so tests can stand
// in for QEMU.
var startRelaunchedQEMU = func(m *Manager, instance *VM) error {
return m.startQEMU(instance, true)
return m.startQEMU(instance)
}
// errRelaunchFailed marks a reboot that ended the old QEMU and could not start
+7 -13
View File
@@ -465,21 +465,18 @@ func TestThreadStatFields(t *testing.T) {
assert.Empty(t, threadStatFields("garbage"))
}
func TestExecute_ConsoleLogAppendOnlyWhenAsked(t *testing.T) {
func TestExecute_ConsoleLogAppendOnEveryBoot(t *testing.T) {
for _, tc := range []struct {
name string
cfg Config
want string
absent string
name string
cfg Config
want string
}{
{"socket fresh", Config{SerialSocket: "/s", ConsoleLogPath: "/c"}, "logfile=/c", "logappend"},
{"socket reboot", Config{SerialSocket: "/s", ConsoleLogPath: "/c", ConsoleLogAppend: true}, "logfile=/c,logappend=on", ""},
{"file reboot", Config{MachineType: "microvm", ConsoleLogPath: "/c", ConsoleLogAppend: true}, "file,id=console0,path=/c,append=on", ""},
{"socket", Config{SerialSocket: "/s", ConsoleLogPath: "/c"}, "logfile=/c,logappend=on"},
{"file", Config{MachineType: "microvm", ConsoleLogPath: "/c"}, "file,id=console0,path=/c,append=on"},
} {
t.Run(tc.name, func(t *testing.T) {
cfg := minimalConfig()
cfg.MachineType, cfg.SerialSocket = tc.cfg.MachineType, tc.cfg.SerialSocket
cfg.ConsoleLogPath, cfg.ConsoleLogAppend = tc.cfg.ConsoleLogPath, tc.cfg.ConsoleLogAppend
cfg.MachineType, cfg.SerialSocket, cfg.ConsoleLogPath = tc.cfg.MachineType, tc.cfg.SerialSocket, tc.cfg.ConsoleLogPath
cmd, err := cfg.Execute()
require.NoError(t, err)
var chardev string
@@ -489,9 +486,6 @@ func TestExecute_ConsoleLogAppendOnlyWhenAsked(t *testing.T) {
}
}
assert.Contains(t, chardev, tc.want)
if tc.absent != "" {
assert.NotContains(t, chardev, tc.absent)
}
})
}
}
+2
View File
@@ -389,6 +389,8 @@ func (m *Manager) finalizeTerminated(instance *VM) error {
instance.TerminatedAt = time.Now()
}
retireConsoleLog(instance.Config.ConsoleLogPath)
if m.deps.StateStore != nil {
if err := m.deps.StateStore.WriteTerminatedInstance(instance.ID, instance); err != nil {
slog.Error("Failed to write terminated instance to KV, keeping in local state for retry",
+11 -19
View File
@@ -137,6 +137,10 @@ type VM struct {
// claiming the flag serialises reboots of one instance.
rebooting atomic.Bool `json:"-"`
// guestPoweroff is set once the heartbeat has seen the guest power itself off
// and asked QEMU to quit, so the exit that follows is a stop, not a crash.
guestPoweroff atomic.Bool `json:"-"`
// relaunchMu is held while a reboot swaps this guest's QEMU process, so a
// stop or terminate never unmounts volumes under a process being started.
relaunchMu sync.Mutex `json:"-"`
@@ -432,13 +436,10 @@ type Config struct {
NoGraphic bool `json:"no_graphic"`
MachineType string `json:"machine_type"`
ConsoleLogPath string `json:"console_log_path,omitempty"`
// ConsoleLogAppend keeps the existing console log rather than truncating
// it, for a reboot that replaces the process.
ConsoleLogAppend bool `json:"-"`
SerialSocket string `json:"serial_socket,omitempty"`
CPUType string `json:"cpu_type"`
CPUCount int `json:"cpu_count"`
Memory int `json:"memory"`
SerialSocket string `json:"serial_socket,omitempty"`
CPUType string `json:"cpu_type"`
CPUCount int `json:"cpu_count"`
Memory int `json:"memory"`
Drives []Drive `json:"drives"`
IOThreads []IOThread `json:"io_threads,omitempty"`
@@ -552,11 +553,11 @@ func (cfg *Config) Execute() (*exec.Cmd, error) {
// -serial chardev:console0 wires it to the existing device (not a new one).
// Do NOT use -device isa-serial here — that adds a second device (ttyS1)
// while the kernel talks to ttyS0.
args = append(args, "-chardev", fmt.Sprintf("file,id=console0,path=%s%s", cfg.ConsoleLogPath, appendOpt(",append", cfg.ConsoleLogAppend)))
args = append(args, "-chardev", fmt.Sprintf("file,id=console0,path=%s,append=on", cfg.ConsoleLogPath))
args = append(args, "-serial", "chardev:console0")
} else if cfg.SerialSocket != "" && cfg.ConsoleLogPath != "" {
chardevOpts := fmt.Sprintf("socket,id=console0,path=%s,server=on,wait=off,logfile=%s%s",
cfg.SerialSocket, cfg.ConsoleLogPath, appendOpt(",logappend", cfg.ConsoleLogAppend))
chardevOpts := fmt.Sprintf("socket,id=console0,path=%s,server=on,wait=off,logfile=%s,logappend=on",
cfg.SerialSocket, cfg.ConsoleLogPath)
args = append(args, "-chardev", chardevOpts)
args = append(args, "-serial", "chardev:console0")
}
@@ -693,12 +694,3 @@ func (cfg *Config) Execute() (*exec.Cmd, error) {
return cmd, nil
}
// appendOpt renders a chardev append option, or nothing when off, so a
// fresh launch keeps the command line it always had.
func appendOpt(key string, on bool) string {
if !on {
return ""
}
return key + "=on"
}
+2 -2
View File
@@ -463,7 +463,7 @@ func TestExecute_MicrovmFileChardev(t *testing.T) {
args := cmd.Args[1:]
chardev := argValue(args, "-chardev")
assert.Equal(t, "file,id=console0,path=/var/log/console.log", chardev)
assert.Equal(t, "file,id=console0,path=/var/log/console.log,append=on", chardev)
// -serial chardev:console0 attaches to the isa-serial=on device (ttyS0).
assert.Equal(t, "chardev:console0", argValue(args, "-serial"))
// No explicit isa-serial device addition (would create ttyS1, not ttyS0).
@@ -699,6 +699,6 @@ func TestExecute_MicrovmWithPCIEFileChardev(t *testing.T) {
require.NoError(t, err)
args := cmd.Args[1:]
assert.Equal(t, "file,id=console0,path=/var/log/console.log", argValue(args, "-chardev"))
assert.Equal(t, "file,id=console0,path=/var/log/console.log,append=on", argValue(args, "-chardev"))
assert.Equal(t, "chardev:console0", argValue(args, "-serial"))
}
+3
View File
@@ -940,6 +940,8 @@ func (d *Daemon) subscribeAll() error {
// Cluster-wide on purpose: the QMP detach is instance-scoped, so a
// volume held by an unreachable host has no other way out.
{"ec2.ForceDetachVolume", handleNATSRequest(d.node, d.volumeService.ForceDetachVolume), "spinifex-workers"},
{"ec2.DetachVolumeFromStopped", handleNATSRequest(d.node, d.instanceService.DetachVolumeFromStopped), "spinifex-workers"},
{"ec2.AttachVolumeToStopped", handleNATSRequest(d.node, d.instanceService.AttachVolumeToStopped), "spinifex-workers"},
{"ec2.DescribeVolumeStatus", handleNATSRequest(d.node, d.volumeService.DescribeVolumeStatus), "spinifex-workers"},
{"ec2.DescribeVolumesModifications", handleNATSRequest(d.node, d.volumeService.DescribeVolumesModifications), "spinifex-workers"},
{"ec2.CreateSnapshot", handleNATSRequest(d.node, d.snapshotService.CreateSnapshot), "spinifex-workers"},
@@ -2573,6 +2575,7 @@ func (d *Daemon) startCluster() error {
d.vmMgr.NewTerminatedTeardownReaper(),
d.vmMgr.NewOrphanQEMUReaper(),
d.vmMgr.NewStuckTerminateReaper(),
d.vmMgr.NewLocalConsoleLogReaper(),
}
if eniRec := d.newENIReconciler(); eniRec != nil {
reapers = append(reapers, eniRec)
@@ -8,6 +8,7 @@ import (
"github.com/aws/aws-sdk-go/service/ec2"
"github.com/mulgadc/spinifex/spinifex/foundation/aws/errors"
"github.com/mulgadc/spinifex/spinifex/runtime/compute/vm"
"github.com/nats-io/nats.go"
)
@@ -49,6 +50,11 @@ func (d *Daemon) handleEC2GetConsoleOutput(msg *nats.Msg) {
if logPath != "" {
info, err := os.Stat(logPath)
if err != nil && os.IsNotExist(err) {
// A terminated instance's file is renamed, not removed, until it ages out.
logPath = vm.RetiredConsolePath(logPath)
info, err = os.Stat(logPath)
}
if err == nil {
modTime = info.ModTime()
@@ -38,9 +38,13 @@ func daemonWithFakeStateStore(t *testing.T, store *vmmock.StateStore) *Daemon {
t.Helper()
d := createTestDaemon(t, sharedNATSURL)
d.stateStore = store
objects := objectstore.NewMemoryObjectStore()
for _, stopped := range store.Stopped {
seedBootVolume(t, objects, d.config.Predastore.Bucket, stopped.AccountID, stopped.ID)
}
d.instanceService = ec2instance.NewInstanceServiceImpl(
d.config, d.resourceMgr.instanceTypes, d.natsConn,
objectstore.NewMemoryObjectStore(), d.vmMgr, d.resourceMgr, store,
objects, d.vmMgr, d.resourceMgr, store,
)
return d
}
@@ -71,7 +75,7 @@ func decodeError(t *testing.T, data []byte) map[string]any {
// stoppedVMFixture builds a minimally-valid stopped VM for handler tests.
func stoppedVMFixture(id, accountID string) *vm.VM {
return &vm.VM{
return withBootVolume(&vm.VM{
ID: id,
Status: vm.StateStopped,
InstanceType: "t3.micro",
@@ -84,7 +88,7 @@ func stoppedVMFixture(id, accountID string) *vm.VM {
InstanceId: aws.String(id),
InstanceType: aws.String("t3.micro"),
},
}
})
}
// --- handleEC2StartStoppedInstance ---
@@ -1438,6 +1438,85 @@ func TestHandleEC2GetConsoleOutput(t *testing.T) {
assert.Contains(t, string(decoded), "Boot complete.")
}
func TestHandleEC2GetConsoleOutput_ReadsRetiredFileWhenLiveNameIsGone(t *testing.T) {
daemon := createFullTestDaemon(t, sharedNATSURL)
instanceID := "i-console-retired-001"
logPath := t.TempDir() + "/console-" + instanceID + ".log"
var body bytes.Buffer
for i := 0; body.Len() < 200<<10; i++ {
fmt.Fprintf(&body, "l%014d\n", i)
}
require.NoError(t, os.WriteFile(vm.RetiredConsolePath(logPath), body.Bytes(), 0o644))
daemon.vmMgr.Insert(&vm.VM{
ID: instanceID,
Status: vm.StateShuttingDown,
AccountID: testAccountID,
Config: vm.Config{ConsoleLogPath: logPath},
})
topic := fmt.Sprintf("ec2.%s.GetConsoleOutput", instanceID)
sub, err := daemon.natsConn.Subscribe(topic, daemon.handleEC2GetConsoleOutput)
require.NoError(t, err)
defer sub.Unsubscribe()
reqData, _ := json.Marshal(&ec2.GetConsoleOutputInput{InstanceId: aws.String(instanceID)})
reply, err := natsRequest(daemon.natsConn, topic, reqData, 5*time.Second)
require.NoError(t, err)
var output ec2.GetConsoleOutputOutput
require.NoError(t, json.Unmarshal(reply.Data, &output))
decoded, err := base64.StdEncoding.DecodeString(*output.Output)
require.NoError(t, err)
want := body.Bytes()[body.Len()-64*1024:]
decodedSize := len(decoded)
assert.Equal(t, 64*1024, decodedSize)
assert.True(t, bytes.Equal(want, decoded), "the newest 64 KiB of the retired file")
}
func TestHandleEC2GetConsoleOutput_AfterTrimReturnsNewest64KiB(t *testing.T) {
daemon := createFullTestDaemon(t, sharedNATSURL)
instanceID := "i-console-trim-001"
dir := t.TempDir()
logPath := dir + "/console-" + instanceID + ".log"
var body bytes.Buffer
for i := 0; body.Len() < 5<<20; i++ {
fmt.Fprintf(&body, "l%014d\n", i)
}
require.NoError(t, os.WriteFile(logPath, body.Bytes(), 0o644))
daemon.vmMgr.Insert(&vm.VM{
ID: instanceID,
Status: vm.StateRunning,
AccountID: testAccountID,
Config: vm.Config{ConsoleLogPath: logPath},
})
reaper := vm.NewConsoleLogReaper(dir)
_, err := reaper.Sweep(context.Background())
require.NoError(t, err)
info, err := os.Stat(logPath)
require.NoError(t, err)
require.Equal(t, int64(1<<20), info.Size(), "the console must have been trimmed before it is read")
topic := fmt.Sprintf("ec2.%s.GetConsoleOutput", instanceID)
sub, err := daemon.natsConn.Subscribe(topic, daemon.handleEC2GetConsoleOutput)
require.NoError(t, err)
defer sub.Unsubscribe()
reqData, _ := json.Marshal(&ec2.GetConsoleOutputInput{InstanceId: aws.String(instanceID)})
reply, err := natsRequest(daemon.natsConn, topic, reqData, 5*time.Second)
require.NoError(t, err)
var output ec2.GetConsoleOutputOutput
require.NoError(t, json.Unmarshal(reply.Data, &output))
decoded, err := base64.StdEncoding.DecodeString(*output.Output)
require.NoError(t, err)
want := body.Bytes()[body.Len()-64*1024:]
decodedSize := len(decoded)
assert.Equal(t, 64*1024, decodedSize)
assert.True(t, bytes.Equal(want, decoded), "the response is the newest 64 KiB of the original console")
}
func TestHandleEC2GetConsoleOutput_EmptyLog(t *testing.T) {
natsURL := sharedNATSURL
daemon := createFullTestDaemon(t, natsURL)
@@ -2763,7 +2842,7 @@ func TestHandleEC2DescribeInstanceTypes_NoFilter(t *testing.T) {
func TestHandleEC2StartStoppedInstance_InstanceTypeNotAvailable(t *testing.T) {
daemon := createFullTestDaemonWithJetStream(t, sharedJSNATSURL)
stoppedVM := &vm.VM{
stoppedVM := withBootVolume(&vm.VM{
ID: "i-start-badtype-001",
Status: vm.StateStopped,
InstanceType: "z99.nonexistent",
@@ -2772,7 +2851,13 @@ func TestHandleEC2StartStoppedInstance_InstanceTypeNotAvailable(t *testing.T) {
InstanceId: aws.String("i-start-badtype-001"),
InstanceType: aws.String("z99.nonexistent"),
},
}
})
objects := objectstore.NewMemoryObjectStore()
seedBootVolume(t, objects, daemon.config.Predastore.Bucket, testAccountID, stoppedVM.ID)
daemon.instanceService = ec2instance.NewInstanceServiceImpl(
daemon.config, daemon.resourceMgr.instanceTypes, daemon.natsConn,
objects, daemon.vmMgr, daemon.resourceMgr, daemon.jsManager,
)
err := daemon.jsManager.WriteStoppedInstance(stoppedVM.ID, stoppedVM)
require.NoError(t, err)
t.Cleanup(func() { _ = daemon.jsManager.DeleteStoppedInstance(stoppedVM.ID) })
+19 -70
View File
@@ -141,7 +141,7 @@ func createTestDaemon(t *testing.T, natsURL string) *Daemon {
// publish/unpublish over NATS using the test's connection.
daemon.vmMgr.SetDeps(vm.Deps{
NodeID: daemon.node,
VolumeMounter: newNATSMounter(daemon.natsConn, daemon.node, daemon.volumeService),
VolumeMounter: newNATSMounter(daemon.natsConn, daemon.node),
VolumeStateUpdater: daemon.volumeService,
DetachDelay: daemon.detachDelay,
DeviceDeletedTimeout: daemon.deviceDeletedTimeout,
@@ -3322,7 +3322,7 @@ func TestVolumeMounterAdapter_UnmountOne_UnmountError(t *testing.T) {
fake.setUnpublish(func(string) ebsprovider.UnpublishVolumeResponse {
return unpublishRefusal(ebsprovider.ErrorCodeInternal, "seal volume: device busy")
})
adapter := newNATSMounter(daemon.natsConn, daemon.node, nil)
adapter := newNATSMounter(daemon.natsConn, daemon.node)
err := adapter.UnmountOne(t.Context(), "", viperblocklegacyv1.EBSRequest{Name: "vol-rollback-err"})
require.Error(t, err, "an unpublish refusal must propagate so DetachVolume can keep the volume attached")
@@ -3337,55 +3337,19 @@ func TestVolumeMounterAdapter_UnmountOne_RequestFailure(t *testing.T) {
require.NoError(t, err)
nc.Close()
adapter := newNATSMounter(nc, "node-1", nil)
adapter := newNATSMounter(nc, "node-1")
require.ErrorIs(t, adapter.UnmountOne(t.Context(), "", viperblocklegacyv1.EBSRequest{Name: "vol-timeout"}), nats.ErrConnectionClosed,
"a failed unpublish request must propagate as an error")
}
// recordingVolState records UpdateVolumeState calls so the bulk-unmount test can
// assert which volumes transitioned to available.
// accounts is recorded separately because the account is a key segment of the
// document, not a label: an unmount that writes under anything but the
// instance's own account leaves the volume stuck in-use, and the adapter only
// logs the error.
type recordingVolState struct {
mu sync.Mutex
calls []string
accounts []string
}
func (r *recordingVolState) UpdateVolumeState(accountID, volumeID, state, instanceID, attachmentDevice string) error {
r.mu.Lock()
defer r.mu.Unlock()
r.calls = append(r.calls, volumeID+":"+state)
r.accounts = append(r.accounts, accountID)
return nil
}
func (r *recordingVolState) snapshot() []string {
r.mu.Lock()
defer r.mu.Unlock()
return append([]string(nil), r.calls...)
}
func (r *recordingVolState) accountsSnapshot() []string {
r.mu.Lock()
defer r.mu.Unlock()
return append([]string(nil), r.accounts...)
}
var _ vm.VolumeStateUpdater = (*recordingVolState)(nil)
// TestVolumeMounterAdapter_Unmount_SealFailureSkipsAvailable verifies the
// teardown-path durability gate: a per-volume seal failure during the bulk
// Unmount (stop/terminate) must NOT transition that volume to available — a
// reattach on a WAL-less node would find no checkpoint (bad superblock) — while
// other volumes still seal and the loop completes. The failure is returned, not
// swallowed: the caller decides whether losing that seal is survivable.
func TestVolumeMounterAdapter_Unmount_SealFailureSkipsAvailable(t *testing.T) {
// TestVolumeMounterAdapter_Unmount_SealFailureIsReported
// verifies that a per-volume seal failure during the bulk Unmount (stop/crash)
// is returned, naming the volume, while the other volumes still seal and the
// loop completes. Unmount only seals: it never writes volume state, so every
// volume stays attached to the stopped instance.
func TestVolumeMounterAdapter_Unmount_SealFailureIsReported(t *testing.T) {
daemon := createTestDaemon(t, sharedNATSURL)
volState := &recordingVolState{}
adapter := newNATSMounter(daemon.natsConn, daemon.node, volState)
adapter := newNATSMounter(daemon.natsConn, daemon.node)
fake := serveFakeNodeProvider(t, daemon.natsConn, daemon.node)
fake.setUnpublish(func(volumeID string) ebsprovider.UnpublishVolumeResponse {
if volumeID == "vol-fail" {
@@ -3403,22 +3367,15 @@ func TestVolumeMounterAdapter_Unmount_SealFailureSkipsAvailable(t *testing.T) {
err := adapter.Unmount(t.Context(), inst)
require.Error(t, err, "bulk Unmount must report a per-volume seal failure")
assert.Contains(t, err.Error(), "vol-fail", "the error must name the volume that did not seal")
calls := volState.snapshot()
assert.NotContains(t, calls, "vol-fail:available",
"a failed seal must not transition the volume to available")
assert.Contains(t, calls, "vol-ok:available",
"a successful seal must still transition the volume to available")
}
// TestVolumeMounterAdapter_Unmount_NotFoundFlipsToAvailable verifies that an
// unpublish answered not_found, which means the provider holds no export of
// the volume, still flips a non-boot data volume to available, while the
// boot/EFI gate stays intact.
func TestVolumeMounterAdapter_Unmount_NotFoundFlipsToAvailable(t *testing.T) {
// TestVolumeMounterAdapter_Unmount_NotFoundIsASealedOutcome
// verifies that an unpublish answered not_found, which means the provider holds
// no export of the volume, is not an error and, like every Unmount outcome,
// writes no volume state.
func TestVolumeMounterAdapter_Unmount_NotFoundIsASealedOutcome(t *testing.T) {
daemon := createTestDaemon(t, sharedNATSURL)
volState := &recordingVolState{}
adapter := newNATSMounter(daemon.natsConn, daemon.node, volState)
adapter := newNATSMounter(daemon.natsConn, daemon.node)
fake := serveFakeNodeProvider(t, daemon.natsConn, daemon.node)
fake.setUnpublish(func(volumeID string) ebsprovider.UnpublishVolumeResponse {
return unpublishRefusal(ebsprovider.ErrorCodeNotFound, fmt.Sprintf("Volume %s not found", volumeID))
@@ -3437,14 +3394,6 @@ func TestVolumeMounterAdapter_Unmount_NotFoundFlipsToAvailable(t *testing.T) {
require.NoError(t, adapter.Unmount(t.Context(), inst))
require.NoError(t, adapter.UnmountOne(t.Context(), "000000000042", viperblocklegacyv1.EBSRequest{Name: "vol-data-retry"}),
"a hot detach of a volume the provider no longer holds is already done")
calls := volState.snapshot()
assert.Contains(t, calls, "vol-data-retry:available",
"a not_found unpublish must still flip a non-boot data volume to available")
assert.NotContains(t, calls, "vol-boot-retry:available",
"a boot volume must stay attached even when the unpublish reports not_found")
assert.Equal(t, []string{"000000000042"}, volState.accountsSnapshot(),
"the state write must be keyed on the instance's own account, not its ID")
}
// TestVolumeMounterAdapter_Mount_PartialFailureRollback verifies that when
@@ -3461,7 +3410,7 @@ func TestVolumeMounterAdapter_Mount_PartialFailureRollback(t *testing.T) {
}
return publishedNBD("nbd://mounted-" + volumeID)
})
adapter := newNATSMounter(nc, node, nil)
adapter := newNATSMounter(nc, node)
err := adapter.Mount(t.Context(), mounterTestVM("vol-1", "vol-2", "vol-3"))
require.Error(t, err, "Mount should propagate the vol-2 failure")
@@ -3474,7 +3423,7 @@ func TestVolumeMounterAdapter_Mount_PartialFailureRollback(t *testing.T) {
// the failing volume is torn down along with the one already published.
func TestVolumeMounterAdapter_Mount_UndecodableReplyRollsBackBoth(t *testing.T) {
daemon := createTestDaemon(t, sharedNATSURL)
adapter := newNATSMounter(daemon.natsConn, daemon.node, nil)
adapter := newNATSMounter(daemon.natsConn, daemon.node)
publishSubject, err := ebsprovider.PublishSubject(daemon.node)
require.NoError(t, err)
@@ -3523,7 +3472,7 @@ func TestVolumeMounterAdapter_Mount_UndecodableReplyRollsBackBoth(t *testing.T)
// attached without surfacing the leak to the caller.
func TestVolumeMounterAdapter_Mount_RollbackFailurePropagates(t *testing.T) {
daemon := createTestDaemon(t, sharedNATSURL)
adapter := newNATSMounter(daemon.natsConn, daemon.node, nil)
adapter := newNATSMounter(daemon.natsConn, daemon.node)
fake := serveFakeNodeProvider(t, daemon.natsConn, daemon.node)
fake.setPublish(func(volumeID string) ebsprovider.PublishVolumeResponse {
if volumeID == "vol-2" {
@@ -15,9 +15,11 @@ import (
"github.com/aws/aws-sdk-go/aws"
"github.com/aws/aws-sdk-go/service/ec2"
"github.com/mulgadc/spinifex/spinifex/bootstrap/config"
ebsmetadata "github.com/mulgadc/spinifex/spinifex/domains/ec2/ebs/metadata"
ec2instance "github.com/mulgadc/spinifex/spinifex/domains/ec2/instance"
"github.com/mulgadc/spinifex/spinifex/foundation/state/clustersize"
"github.com/mulgadc/spinifex/spinifex/foundation/state/kvstore"
"github.com/mulgadc/spinifex/spinifex/providers/objectstore"
"github.com/mulgadc/spinifex/spinifex/runtime/compute/cache"
"github.com/mulgadc/spinifex/spinifex/runtime/compute/vm"
"github.com/nats-io/nats.go"
@@ -30,6 +32,7 @@ import (
type recoveryStore struct {
m *JetStreamManager
liveness *instancecache.Liveness
objects *objectstore.MemoryObjectStore
}
func newRecoveryStore(t *testing.T) *recoveryStore {
@@ -55,7 +58,7 @@ func newRecoveryStore(t *testing.T) *recoveryStore {
_ = m.js.DeleteKeyValue(context.Background(), name)
_ = m.js.DeleteKeyValue(context.Background(), name+"-hb")
})
return &recoveryStore{m: m, liveness: instancecache.NewLiveness(m.js, beats)}
return &recoveryStore{m: m, liveness: instancecache.NewLiveness(m.js, beats), objects: objectstore.NewMemoryObjectStore()}
}
// beat writes node's heartbeat stamped at.
@@ -70,6 +73,8 @@ func (s *recoveryStore) put(t *testing.T, id, node, instanceType string) {
record := runningOn(id, node)
record.Spec.InstanceType = instanceType
record.Status.Instance = &ec2.Instance{InstanceId: aws.String(id)}
record.Status.EBSRequests = []vm.EBSRequest{{Name: bootVolumeID(id), Boot: true, DeviceName: ebsmetadata.RootDeviceName}}
seedBootVolume(t, s.objects, "test-bucket", record.Metadata.AccountID, id)
require.NoError(t, s.m.records.Set(context.Background(), instanceRecordKey(id), record))
}
@@ -92,6 +97,7 @@ func recoveryDaemon(t *testing.T, s *recoveryStore) (*Daemon, *instanceRecovery)
d := createTestDaemon(t, sharedNATSURL)
d.jsManager = s.m
d.instanceService = ec2instance.NewInstanceServiceImpl(d.config, d.resourceMgr.instanceTypes, d.natsConn, s.objects, d.vmMgr, d.resourceMgr, nil)
d.predastoreHealth.at = time.Now()
d.predastoreHealth.result = predastoreHealthOK
@@ -251,7 +257,7 @@ func TestRecoveryAttemptSucceeds(t *testing.T) {
// starting QEMU, which is the one part of a recovery this cannot do.
d.vmMgr.SetDeps(vm.Deps{
NodeID: d.node,
VolumeMounter: newNATSMounter(d.natsConn, d.node, d.volumeService),
VolumeMounter: newNATSMounter(d.natsConn, d.node),
VolumeStateUpdater: d.volumeService,
Hooks: vm.ManagerHooks{BeforeInstanceRelaunch: func(v *vm.VM) error {
d.vmMgr.Inspect(v, func(v *vm.VM) { v.Status = vm.StateShuttingDown })
@@ -0,0 +1,42 @@
package daemon
import (
"testing"
"github.com/aws/aws-sdk-go/aws"
"github.com/aws/aws-sdk-go/service/ec2"
viperblocklegacyv1 "github.com/mulgadc/spinifex/contracts/viperblockd/legacy/v1"
ebsmetadata "github.com/mulgadc/spinifex/spinifex/domains/ec2/ebs/metadata"
"github.com/mulgadc/spinifex/spinifex/providers/objectstore"
"github.com/mulgadc/spinifex/spinifex/runtime/compute/vm"
"github.com/stretchr/testify/require"
)
// bootVolumeID is the root volume a fixture instance is given.
func bootVolumeID(instanceID string) string { return "vol-root-" + instanceID }
// withBootVolume gives an instance fixture the root volume every real instance
// has: a boot request at the root device and the matching API mapping.
func withBootVolume(v *vm.VM) *vm.VM {
id := bootVolumeID(v.ID)
v.EBSRequests.Requests = append(v.EBSRequests.Requests, viperblocklegacyv1.EBSRequest{Name: id, Boot: true, DeviceName: ebsmetadata.RootDeviceName})
if v.Instance != nil {
v.Instance.BlockDeviceMappings = append(v.Instance.BlockDeviceMappings, &ec2.InstanceBlockDeviceMapping{
DeviceName: aws.String(ebsmetadata.RootDeviceName),
Ebs: &ec2.EbsInstanceBlockDevice{VolumeId: aws.String(id)},
})
}
return v
}
// seedBootVolume registers the root volume document of an instance fixture, so
// a start finds the volume its record names.
func seedBootVolume(t *testing.T, store objectstore.ObjectStore, bucket, accountID, instanceID string) {
t.Helper()
require.NoError(t, ebsmetadata.NewStore(store, bucket).PutVolume(t.Context(), ebsmetadata.Volume{
VolumeID: bootVolumeID(instanceID),
TenantID: accountID,
State: "in-use",
AttachedInstance: instanceID,
}))
}
+6 -20
View File
@@ -95,10 +95,9 @@ func (a *stateStoreAdapter) DeleteTerminatedInstance(id string) error {
// volumeMounterAdapter satisfies vm.VolumeMounter over the EBS contract's
// PublishVolume and UnpublishVolume, sent at the cluster's one contract
// version to this node's provider. Unmount also marks volumes available.
// version to this node's provider.
type volumeMounterAdapter struct {
node string
volState vm.VolumeStateUpdater
provider mounterProvider
// abandonTimeout bounds each no-seal unpublish Abandon sends.
abandonTimeout time.Duration
@@ -114,10 +113,9 @@ var _ mounterProvider = (*ebsprovider.NATSProvider)(nil)
var _ vm.VolumeMounter = (*volumeMounterAdapter)(nil)
func newVolumeMounterAdapter(provider mounterProvider, node string, volState vm.VolumeStateUpdater) *volumeMounterAdapter {
func newVolumeMounterAdapter(provider mounterProvider, node string) *volumeMounterAdapter {
return &volumeMounterAdapter{
node: node,
volState: volState,
provider: provider,
abandonTimeout: abandonTimeout,
}
@@ -296,27 +294,15 @@ func (a *volumeMounterAdapter) Unmount(ctx context.Context, instance *vm.VM) err
var sealErrs []error
for _, ebsRequest := range instance.EBSRequests.Requests {
// Every volume is attempted and the seal failures aggregated. An unsealed
// volume must NOT go available: a reattach on a node without the local
// WAL would find no checkpoint (bad superblock).
// Every volume is attempted and the seal failures aggregated. A stop or
// crash leaves every volume in-use and attached, so no state is written.
if err := a.unpublish(ctx, instance.AccountID, ebsRequest); err != nil {
slog.Error("Volume seal failed, leaving volume non-available",
slog.Error("Volume seal failed",
"instance", instance.ID, "volume", ebsRequest.Name, "err", err)
sealErrs = append(sealErrs, fmt.Errorf("seal %s: %w", ebsRequest.Name, err))
continue
}
slog.Info("Unmounted volume", "instance", instance.ID, "volume", ebsRequest.Name)
// Boot/root volumes must stay attached across stop/crash unmount: EFI is
// the wrong proxy for "boot" (BIOS-boot roots are Boot && !EFI), so gate on
// Boot too. Only DetachVolume and terminate release a boot volume; flipping
// it available here while the instance restarts splits the state record.
if !ebsRequest.EFI && !ebsRequest.Boot && a.volState != nil {
if err := a.volState.UpdateVolumeState(instance.AccountID, ebsRequest.Name, "available", "", ""); err != nil {
slog.Error("Failed to update volume state to available after unmount",
"volumeId", ebsRequest.Name, "err", err)
}
}
}
return errors.Join(sealErrs...)
@@ -677,7 +663,7 @@ func (d *Daemon) buildVMManagerDeps() vm.Deps {
return vm.Deps{
NodeID: d.node,
StateStore: d.stateStore,
VolumeMounter: newVolumeMounterAdapter(d.ebsProvider, d.node, d.volumeService),
VolumeMounter: newVolumeMounterAdapter(d.ebsProvider, d.node),
NetworkPlumber: d.networkPlumber,
InstanceTypes: newInstanceTypeResolverAdapter(d.resourceMgr),
Resources: newResourceControllerAdapter(d.resourceMgr),
@@ -31,8 +31,8 @@ func newMounterTestNode() string {
}
// newNATSMounter returns a mounter driving node's provider over nc.
func newNATSMounter(nc *nats.Conn, node string, volState vm.VolumeStateUpdater) *volumeMounterAdapter {
return newVolumeMounterAdapter(ebsprovider.NewNATSProvider(nc, ebsProviderRequestTimeout), node, volState)
func newNATSMounter(nc *nats.Conn, node string) *volumeMounterAdapter {
return newVolumeMounterAdapter(ebsprovider.NewNATSProvider(nc, ebsProviderRequestTimeout), node)
}
func connectMounterTest(t *testing.T) *nats.Conn {
@@ -247,8 +247,7 @@ func TestVolumeMounterAdapter_EveryRequestAtVersion3OverTheContract(t *testing.T
for _, subject := range []string{"ebs." + node + ".*", "ebs.mount", "ebs.unmount", "ebs.abandon"} {
legacySpies = append(legacySpies, spyOn(t, nc, subject))
}
volState := &recordingVolState{}
adapter := newNATSMounter(nc, node, volState)
adapter := newNATSMounter(nc, node)
instance := mounterTestVM("vol-a", "vol-b")
require.NoError(t, adapter.Mount(t.Context(), instance))
@@ -267,7 +266,6 @@ func TestVolumeMounterAdapter_EveryRequestAtVersion3OverTheContract(t *testing.T
for _, id := range []string{"vol-a", "vol-b"} {
assert.Equal(t, ebsprovider.VolumeStateAvailable, volumeState(t, provider, id), "unmount must unpublish %s", id)
}
assert.ElementsMatch(t, []string{"vol-a:available", "vol-b:available"}, volState.snapshot())
moved := mounterTestVM("vol-moved")
require.NoError(t, adapter.Mount(t.Context(), moved))
@@ -293,7 +291,7 @@ func TestVolumeMounterAdapter_RetryLaterRefusalBacksOffAndRecovers(t *testing.T)
node := newMounterTestNode()
fake := serveFakeNodeProvider(t, nc, node)
fake.setPublish(publishRefusal(code))
adapter := newNATSMounter(nc, node, nil)
adapter := newNATSMounter(nc, node)
instance := mounterTestVM("vol-relaunch")
err := adapter.Mount(t.Context(), instance)
@@ -321,7 +319,7 @@ func TestVolumeMounterAdapter_PermanentRefusalIsNotRetryable(t *testing.T) {
node := newMounterTestNode()
fake := serveFakeNodeProvider(t, nc, node)
fake.setPublish(publishRefusal(code))
adapter := newNATSMounter(nc, node, nil)
adapter := newNATSMounter(nc, node)
err := adapter.Mount(t.Context(), mounterTestVM("vol-refused"))
require.Error(t, err)
@@ -340,9 +338,9 @@ func TestVolumeMounterAdapter_HeldElsewhereReachesTheMountCaller(t *testing.T) {
serveMemoryProvider(t, nc, provider, owner)
serveMemoryProvider(t, nc, provider, other)
require.NoError(t, newNATSMounter(nc, owner, nil).Mount(t.Context(), mounterTestVM("vol-held")))
require.NoError(t, newNATSMounter(nc, owner).Mount(t.Context(), mounterTestVM("vol-held")))
err := newNATSMounter(nc, other, nil).Mount(t.Context(), mounterTestVM("vol-held"))
err := newNATSMounter(nc, other).Mount(t.Context(), mounterTestVM("vol-held"))
require.ErrorIs(t, err, ebsprovider.ErrVolumeHeldElsewhere)
var providerErr *ebsprovider.ProviderError
require.ErrorAs(t, err, &providerErr)
@@ -369,12 +367,10 @@ func TestVolumeMounterAdapter_UnpublishOutlastingRequestTimeoutCompletes(t *test
return publishedNBD("nbd://" + volumeID)
})
volState := &recordingVolState{}
adapter := newNATSMounter(nc, node, volState)
adapter := newNATSMounter(nc, node)
adapter.provider = ebsprovider.NewNATSProvider(nc, requestTimeout)
require.NoError(t, adapter.Unmount(t.Context(), mounterTestVM("vol-slow-seal")))
assert.Equal(t, []string{"vol-slow-seal:available"}, volState.snapshot())
require.NoError(t, adapter.UnmountOne(t.Context(), testAccountID, viperblocklegacyv1.EBSRequest{Name: "vol-slow-seal"}))
err := adapter.MountOne(t.Context(), testAccountID, &viperblocklegacyv1.EBSRequest{Name: "vol-slow-seal"})
@@ -388,7 +384,7 @@ func TestVolumeMounterAdapter_MountRollsBackOnFailure(t *testing.T) {
node := newMounterTestNode()
provider := newMemoryProvider(t, "vol-present")
serveMemoryProvider(t, nc, provider, node)
adapter := newNATSMounter(nc, node, nil)
adapter := newNATSMounter(nc, node)
err := adapter.Mount(t.Context(), mounterTestVM("vol-present", "vol-missing"))
require.ErrorIs(t, err, vm.ErrMountRetryable)
@@ -417,7 +413,7 @@ func TestVolumeMounterAdapter_BlockExportReplacesNBDURI(t *testing.T) {
adapter := newVolumeMounterAdapter(&stubMounterProvider{export: ebsprovider.VolumeExport{
Kind: ebsprovider.ExportKindBlock,
Block: &ebsprovider.BlockExport{DevicePath: "/dev/sdx", SizeBytes: 1 << 30},
}}, "node-stub", nil)
}}, "node-stub")
req := &viperblocklegacyv1.EBSRequest{Name: "vol-block", NBDURI: "nbd://stale"}
require.NoError(t, adapter.MountOne(t.Context(), testAccountID, req))
@@ -473,7 +469,7 @@ func TestVolumeMounterAdapter_AmbiguousPublishIsTornDown(t *testing.T) {
node := newMounterTestNode()
fake := serveFakeNodeProvider(t, nc, node)
fake.setPublish(func(string) ebsprovider.PublishVolumeResponse { return tt.reply() })
adapter := newNATSMounter(nc, node, nil)
adapter := newNATSMounter(nc, node)
if tt.timeout > 0 {
adapter.provider = ebsprovider.NewNATSProvider(nc, tt.timeout)
}
@@ -507,7 +503,7 @@ func TestVolumeMounterAdapter_MountRollbackOutlivesCancelledCaller(t *testing.T)
}
return publishedNBD("nbd://" + volumeID)
})
adapter := newNATSMounter(nc, node, nil)
adapter := newNATSMounter(nc, node)
ctx, cancel := context.WithCancel(t.Context())
defer cancel()
@@ -537,7 +533,7 @@ func TestVolumeMounterAdapter_MountOneCancelledAfterSendIsAmbiguous(t *testing.T
<-release
return publishedNBD("nbd://" + volumeID)
})
adapter := newNATSMounter(nc, node, nil)
adapter := newNATSMounter(nc, node)
ctx, cancel := context.WithCancel(t.Context())
defer cancel()
@@ -562,7 +558,7 @@ func TestVolumeMounterAdapter_PublishAfterCallerGoneSendsNothing(t *testing.T) {
nc := connectMounterTest(t)
node := newMounterTestNode()
fake := serveFakeNodeProvider(t, nc, node)
adapter := newNATSMounter(nc, node, nil)
adapter := newNATSMounter(nc, node)
cancelled, cancel := context.WithCancel(t.Context())
cancel()
@@ -583,7 +579,7 @@ func TestVolumeMounterAdapter_ContractRequestsCarryTheAccount(t *testing.T) {
node := newMounterTestNode()
serveFakeNodeProvider(t, nc, node)
calls := spyOn(t, nc, "ebs.provider.v1."+node+".*")
adapter := newNATSMounter(nc, node, nil)
adapter := newNATSMounter(nc, node)
instance := mounterTestVM("vol-a")
require.NoError(t, adapter.Mount(t.Context(), instance))
@@ -611,7 +607,7 @@ func TestVolumeMounterAdapter_RequestSpanCarriesTheAccountUnderTheCaller(t *test
nc := connectMounterTest(t)
node := newMounterTestNode()
serveFakeNodeProvider(t, nc, node)
adapter := newNATSMounter(nc, node, nil)
adapter := newNATSMounter(nc, node)
ctx, caller := otel.Tracer("test").Start(t.Context(), "caller")
require.NoError(t, adapter.MountOne(ctx, testAccountID, &viperblocklegacyv1.EBSRequest{Name: "vol-acct"}))
@@ -638,8 +634,7 @@ func TestVolumeMounterAdapter_UnpublishOutlivesCallerContext(t *testing.T) {
sealed.Add(1)
return ebsprovider.UnpublishVolumeResponse{}
})
volState := &recordingVolState{}
adapter := newNATSMounter(nc, node, volState)
adapter := newNATSMounter(nc, node)
short, cancelShort := context.WithTimeout(t.Context(), sealTime/4)
defer cancelShort()
@@ -649,7 +644,6 @@ func TestVolumeMounterAdapter_UnpublishOutlivesCallerContext(t *testing.T) {
cancel()
require.NoError(t, adapter.Unmount(cancelled, mounterTestVM("vol-stop")))
assert.Equal(t, int32(2), sealed.Load())
assert.Equal(t, []string{"vol-stop:available"}, volState.snapshot())
}
// Abandon drops each export unsealed, at the version that carries NoSeal, and
@@ -671,7 +665,7 @@ func TestVolumeMounterAdapter_AbandonUnpublishesWithoutSealing(t *testing.T) {
return ebsprovider.UnpublishVolumeResponse{}
})
logs := captureSlogForTest(t)
adapter := newNATSMounter(nc, node, nil)
adapter := newNATSMounter(nc, node)
err := adapter.Abandon(t.Context(), mounterTestVM("vol-torn", "vol-absent", "vol-unknown", "vol-refused"), "superseded")
require.ErrorIs(t, err, ebsprovider.ErrUnavailable)
@@ -695,7 +689,7 @@ func TestVolumeMounterAdapter_AbandonUnpublishesWithoutSealing(t *testing.T) {
// An abandon that finds no provider has not let go, so the caller is told.
func TestVolumeMounterAdapter_AbandonNoResponderFails(t *testing.T) {
nc := connectMounterTest(t)
adapter := newNATSMounter(nc, newMounterTestNode(), nil)
adapter := newNATSMounter(nc, newMounterTestNode())
err := adapter.Abandon(t.Context(), mounterTestVM("vol-1", "vol-2"), "superseded")
require.ErrorIs(t, err, nats.ErrNoResponders)
@@ -710,7 +704,7 @@ func TestVolumeMounterAdapter_AbandonGivesUpWithinItsBound(t *testing.T) {
nc := connectMounterTest(t)
node := newMounterTestNode()
spyOn(t, nc, "ebs.provider.v1."+node+".*")
adapter := newNATSMounter(nc, node, nil)
adapter := newNATSMounter(nc, node)
adapter.abandonTimeout = bound
done := make(chan error, 1)
@@ -730,7 +724,7 @@ func TestVolumeMounterAdapter_AbandonSpanRecordsTheReason(t *testing.T) {
nc := connectMounterTest(t)
node := newMounterTestNode()
serveFakeNodeProvider(t, nc, node)
adapter := newNATSMounter(nc, node, nil)
adapter := newNATSMounter(nc, node)
require.NoError(t, adapter.Abandon(t.Context(), mounterTestVM("vol-moved"), "superseded"))
@@ -185,7 +185,7 @@ func TestBuildVMManagerDeps_BackingStoreReady(t *testing.T) {
// A connection that is down refuses the publish before sending it, so restore
// backs off and retries, and there is no export to tear down.
func TestVolumeMounterAdapter_Mount_DisconnectedIsRetryable(t *testing.T) {
adapter := newNATSMounter(closedAdapterTestConn(t), "node-closed", nil)
adapter := newNATSMounter(closedAdapterTestConn(t), "node-closed")
instance := &vm.VM{ID: "i-mount-closed"}
instance.EBSRequests.Requests = []viperblocklegacyv1.EBSRequest{{Name: "vol-closed"}}
@@ -196,23 +196,11 @@ func TestVolumeMounterAdapter_Mount_DisconnectedIsRetryable(t *testing.T) {
require.ErrorIs(t, adapter.MountOne(t.Context(), testAccountID, &viperblocklegacyv1.EBSRequest{Name: "vol-hot"}), vm.ErrMountRetryable)
}
// recordingVolumeState records UpdateVolumeState calls and returns err.
type recordingVolumeState struct {
err error
updated []string
}
func (r *recordingVolumeState) UpdateVolumeState(_, volumeID, state, _, _ string) error {
r.updated = append(r.updated, volumeID+"="+state)
return r.err
}
func TestVolumeMounterAdapter_Unmount_Errors(t *testing.T) {
nc := connectAdapterTestNATS(t, sharedNATSURL)
t.Run("no responder fails the seal and leaves the volume", func(t *testing.T) {
volState := &recordingVolumeState{}
adapter := newNATSMounter(nc, uniqueAdapterID("node-unmount"), volState)
t.Run("no responder fails the seal for every volume", func(t *testing.T) {
adapter := newNATSMounter(nc, uniqueAdapterID("node-unmount"))
instance := &vm.VM{ID: "i-unmount-none"}
instance.EBSRequests.Requests = []viperblocklegacyv1.EBSRequest{{Name: "vol-a"}, {Name: "vol-b"}}
@@ -220,19 +208,16 @@ func TestVolumeMounterAdapter_Unmount_Errors(t *testing.T) {
require.ErrorIs(t, err, nats.ErrNoResponders)
assert.Contains(t, err.Error(), "vol-a")
assert.Contains(t, err.Error(), "vol-b", "every volume is attempted")
assert.Empty(t, volState.updated, "an unsealed volume must not go available")
})
t.Run("state update failure does not fail the unmount", func(t *testing.T) {
t.Run("a sealed unmount succeeds", func(t *testing.T) {
node := uniqueAdapterID("node-unmount")
serveFakeNodeProvider(t, nc, node)
volState := &recordingVolumeState{err: errInjected}
adapter := newNATSMounter(nc, node, volState)
adapter := newNATSMounter(nc, node)
instance := &vm.VM{ID: "i-unmount-state"}
instance.EBSRequests.Requests = []viperblocklegacyv1.EBSRequest{{Name: "vol-a"}}
require.NoError(t, adapter.Unmount(t.Context(), instance))
assert.Equal(t, []string{"vol-a=available"}, volState.updated)
})
}
@@ -10,21 +10,19 @@ import (
)
// TestUnmountNeverReleasesBootVolume locks the stop/crash attachment-persistence
// contract: Unmount seals the block map but must NOT mark a boot/root volume
// "available". Unmount is driven by stop (runtime/compute/vm/shutdown.go) and crash recovery
// (runtime/compute/vm/crash_recovery.go), where the instance keeps its attachment and restarts —
// only DetachVolume and terminate release a boot volume. Releasing it here while
// contract: Unmount seals the block map but never marks any attached volume
// "available", boot or data. Unmount is driven by stop (runtime/compute/vm/shutdown.go)
// and crash recovery (runtime/compute/vm/crash_recovery.go), where the instance keeps
// its attachments and restarts; as on AWS, EBS root and data volumes persist across
// stop. Only DetachVolume and terminate release a volume. Releasing one here while
// the instance still owns it splits the volume-state record (describe-instances
// "attached" vs describe-volumes "available"). EFI is not a
// sufficient proxy for "boot": BIOS-boot roots are Boot && !EFI, so the gate must
// also exclude Boot. Only non-boot data volumes may be released by Unmount.
// "attached" vs describe-volumes "available").
func TestUnmountNeverReleasesBootVolume(t *testing.T) {
daemon := createTestDaemon(t, sharedNATSURL)
volState := &recordingVolState{}
adapter := newNATSMounter(daemon.natsConn, daemon.node, volState)
adapter := newNATSMounter(daemon.natsConn, daemon.node)
// Stand in for the provider: every unpublish succeeds (sealed).
serveFakeNodeProvider(t, daemon.natsConn, daemon.node)
fake := serveFakeNodeProvider(t, daemon.natsConn, daemon.node)
inst := &vm.VM{
ID: "i-unmount-boot",
@@ -38,11 +36,7 @@ func TestUnmountNeverReleasesBootVolume(t *testing.T) {
}
require.NoError(t, adapter.Unmount(t.Context(), inst))
calls := volState.snapshot()
assert.NotContains(t, calls, "vol-bios-root:available",
"a BIOS-boot root volume (Boot && !EFI) must stay attached across stop/crash unmount, not be released to available")
assert.NotContains(t, calls, "vol-efi-root:available",
"an EFI-boot root volume must stay attached across stop/crash unmount")
assert.Contains(t, calls, "vol-data:available",
"a non-boot data volume is released to available by Unmount")
// Boot, EFI and data volumes alike are sealed and left attached: stop and
// crash unmount never release any attached volume.
assert.ElementsMatch(t, []string{"vol-bios-root", "vol-efi-root", "vol-data"}, fake.unpublished())
}
@@ -0,0 +1,97 @@
package daemon
import (
"encoding/json"
"fmt"
"testing"
"time"
"github.com/aws/aws-sdk-go/service/ec2"
"github.com/mulgadc/spinifex/contracts/ec2/v1"
viperblocklegacyv1 "github.com/mulgadc/spinifex/contracts/viperblockd/legacy/v1"
"github.com/mulgadc/spinifex/spinifex/domains/ec2/ebs/metadata"
"github.com/mulgadc/spinifex/spinifex/runtime/compute/qmp"
"github.com/mulgadc/spinifex/spinifex/runtime/compute/vm"
"github.com/stretchr/testify/assert"
"github.com/stretchr/testify/require"
)
// A stopped or crashed instance still owns its data volumes, so Unmount seals
// them and releases the node-local mount without touching their state.
func TestUnmount_LeavesDataVolumesAttached(t *testing.T) {
daemon := createTestDaemon(t, sharedNATSURL)
adapter := newNATSMounter(daemon.natsConn, daemon.node)
fake := serveFakeNodeProvider(t, daemon.natsConn, daemon.node)
inst := &vm.VM{
ID: "i-stop-keep",
AccountID: "000000000042",
EBSRequests: vm.EBSRequests{
Requests: []viperblocklegacyv1.EBSRequest{
{Name: "vol-root", Boot: true},
{Name: "vol-efi", Boot: true, EFI: true},
{Name: "vol-data-a", DeviceName: "/dev/sdf"},
{Name: "vol-data-b", DeviceName: "/dev/sdg"},
},
},
}
require.NoError(t, adapter.Unmount(t.Context(), inst))
assert.ElementsMatch(t, []string{"vol-root", "vol-efi", "vol-data-a", "vol-data-b"}, fake.unpublished(),
"every volume is still sealed on stop")
}
// The point of keeping the attachment: after the stopped instance's unmount,
// another instance cannot take the volume, which is what AWS does.
func TestStoppedInstanceVolume_CannotBeAttachedElsewhere(t *testing.T) {
daemon, store := createFullTestDaemonWithStore(t, sharedNATSURL)
const (
stoppedID = "i-stopped-holder"
otherID = "i-wants-the-volume"
volumeID = "vol-held-by-stopped"
)
seedVolumeConfig(t, daemon, store, ebsmetadata.Volume{
VolumeID: volumeID,
CapacityGiB: 10,
State: "in-use",
TenantID: testAccountID,
AttachedInstance: stoppedID,
DeviceName: "/dev/sdf",
})
serveFakeNodeProvider(t, daemon.natsConn, daemon.node)
adapter := newNATSMounter(daemon.natsConn, daemon.node)
stopped := &vm.VM{
ID: stoppedID,
AccountID: testAccountID,
EBSRequests: vm.EBSRequests{
Requests: []viperblocklegacyv1.EBSRequest{{Name: volumeID, DeviceName: "/dev/sdf"}},
},
}
require.NoError(t, adapter.Unmount(t.Context(), stopped))
other := &vm.VM{
ID: otherID,
Status: vm.StateRunning,
AccountID: testAccountID,
InstanceType: getTestInstanceType(t),
Instance: &ec2.Instance{},
QMPClient: &qmp.QMPClient{},
}
daemon.vmMgr.Insert(other)
sub, err := daemon.natsConn.Subscribe(fmt.Sprintf("ec2.cmd.%s", otherID), daemon.handleEC2Events)
require.NoError(t, err)
defer sub.Unsubscribe()
cmdData, err := json.Marshal(ec2v1.EC2InstanceCommand{
ID: otherID,
Attributes: ec2v1.EC2CommandAttributes{AttachVolume: true},
AttachVolumeData: &ec2v1.AttachVolumeData{VolumeID: volumeID},
})
require.NoError(t, err)
resp, err := natsRequest(daemon.natsConn, fmt.Sprintf("ec2.cmd.%s", otherID), cmdData, 5*time.Second)
require.NoError(t, err)
assert.Contains(t, string(resp.Data), "VolumeInUse")
}
+1 -1
View File
@@ -563,7 +563,7 @@ func TestInstanceCleanerAdapter_ReleaseAttachedENIs_ListInstanceENIsErrorTolerat
func TestVolumeMounterAdapter_Mount_NoResponderIsRetryable(t *testing.T) {
daemon := createTestDaemon(t, sharedNATSURL)
adapter := newNATSMounter(daemon.natsConn, daemon.node, nil)
adapter := newNATSMounter(daemon.natsConn, daemon.node)
// No subscriber on the mount subject: viperblockd is still starting, so
// the request returns nats.ErrNoResponders, which must be retryable.
+6 -12
View File
@@ -2302,8 +2302,8 @@ packages:
bowser@2.14.1:
resolution: {integrity: sha512-tzPjzCxygAKWFOJP011oxFHs57HzIhOEracIgAePE4pqB3LikALKnSzUyU4MGs9/iCEUuHlAJTjTc5M+u7YEGg==}
brace-expansion@5.0.9:
resolution: {integrity: sha512-ScQ4IuvIEF1TMlP7Zt+vjJ//9zlPb2SDcxWxM3bk8s6t6GGdJ7KO1dCcTidOPJKePW30LE/2cT7wCyPho9/Wxg==}
brace-expansion@5.0.12:
resolution: {integrity: sha512-YovQ3rzhaLMIrDjNDMkNS01tea93qhEhG5xy8f6+R0l+dw3Ki+5sCoIoI942iuLZTHWogWktgwVDhU09iNEimQ==}
engines: {node: 20 || >=22}
braces@3.0.3:
@@ -3453,10 +3453,6 @@ packages:
resolution: {integrity: sha512-SO/3iYL5S3W57LLEniscOGPZgOqZUPCx6d3dB+52B80yJ0XstzsC/eV8gnA4tM3MHDrKz+OCFSLNjswdSC+/bA==}
engines: {node: '>=22'}
source-map-js@1.2.1:
resolution: {integrity: sha512-UXWMKhLOwVKb728IUtQPXxfYU+usdybtUrK/8uGE8CQMvrhOpwvzDBwj0QhSL7MQc7vIsISBG8VQ8+IDQxpfQA==}
engines: {node: '>=0.10.0'}
source-map-js@1.2.2:
resolution: {integrity: sha512-KGj/8Y43x35aZVDtt+J4mK1hoLGHULMYfSkODJNQjNDC3oW1PqPoxMwo0pLUsWM/UEGzON/NxeHywEfNXNP3Vw==}
engines: {node: '>=0.10.0'}
@@ -4986,7 +4982,7 @@ snapshots:
jiti: 2.7.0
lightningcss: 1.32.0
magic-string: 0.30.21
source-map-js: 1.2.1
source-map-js: 1.2.2
tailwindcss: 4.3.3
'@tailwindcss/oxide-android-arm64@4.3.3':
@@ -5566,7 +5562,7 @@ snapshots:
bowser@2.14.1: {}
brace-expansion@5.0.9:
brace-expansion@5.0.12:
dependencies:
balanced-match: 4.0.4
@@ -6189,7 +6185,7 @@ snapshots:
dependencies:
'@babel/parser': 7.29.8
'@babel/types': 7.29.8
source-map-js: 1.2.1
source-map-js: 1.2.2
markdown-table@3.0.4: {}
@@ -6550,7 +6546,7 @@ snapshots:
minimatch@10.2.6:
dependencies:
brace-expansion: 5.0.9
brace-expansion: 5.0.12
mlly@1.8.2:
dependencies:
@@ -6946,8 +6942,6 @@ snapshots:
ansi-styles: 6.2.3
is-fullwidth-code-point: 5.1.0
source-map-js@1.2.1: {}
source-map-js@1.2.2: {}
space-separated-tokens@2.0.2: {}
+41 -22
View File
@@ -16,9 +16,8 @@ var sshHealth harness.SSHHealth
// runStopStart stops fix.Instance and waits for it to reach the
// "stopped" state, then asserts that rebooting a stopped instance is
// rejected with IncorrectInstanceState. Leaves the instance stopped so
// Phase 7a / 7b can act against the stopped state. Maps to run-e2e.sh
// ~1027–1053.
// rejected with IncorrectInstanceState, then starts it again. Maps to
// run-e2e.sh ~1027–1053.
func runStopStart(t *testing.T, fix *Fixture) {
harness.Phase(t, "Single — Instance State Transitions (Stop)")
@@ -54,22 +53,21 @@ func runStopStart(t *testing.T, fix *Fixture) {
harness.WaitForInstanceState(t, fix.AWS, instanceID, "running")
}
// runAttachToStoppedError creates a fresh 10 GiB volume and attempts
// to attach it to the (currently stopped) primary instance. The attach
// must fail with IncorrectInstanceState. The test volume is deleted
// in-line on success and via t.Cleanup on early failure. Maps to
// run-e2e.sh ~1054–1068.
func runAttachToStoppedError(t *testing.T, fix *Fixture) {
harness.Phase(t, "Single — Attach Volume to Stopped Instance (Error Path)")
// runAttachToStopped attaches a fresh 10 GiB volume to the (stopped) primary
// instance, as AWS allows: the attach edits the stopped record and claims the
// volume in-use, a delete is refused while it is attached, and a detach
// releases it to available. The volume is deleted in-line on success and via
// t.Cleanup on early failure.
func runAttachToStopped(t *testing.T, fix *Fixture) {
harness.Phase(t, "Single — Attach/Detach Volume on a Stopped Instance")
inst, _ := needInstance(t, fix)
instanceID := aws.StringValue(inst.InstanceId)
az := needAZ(t, fix)
// Stop the primary instance so the IncorrectInstanceState assertion has
// something to bite on, then restore it at end so sibling Test* see the
// canonical running row.
harness.Step(t, "stop-instances %s (precondition for 7a)", instanceID)
// Stop the primary instance, then restore it at end so sibling Test* see
// the canonical running row.
harness.Step(t, "stop-instances %s (precondition)", instanceID)
_, err := fix.AWS.EC2.StopInstances(&ec2.StopInstancesInput{
InstanceIds: []*string{aws.String(instanceID)},
})
@@ -92,13 +90,16 @@ func runAttachToStoppedError(t *testing.T, fix *Fixture) {
require.NotEmpty(t, stoppedVolID, "create-volume returned empty VolumeId")
harness.Detail(t, "test_volume", stoppedVolID)
// Best-effort cleanup if the negative assertion or anything else fails
// before we reach the explicit delete-volume below.
// Best-effort cleanup if anything fails before the explicit delete below.
cleaned := false
t.Cleanup(func() {
if cleaned {
return
}
_, _ = fix.AWS.EC2.DetachVolume(&ec2.DetachVolumeInput{
VolumeId: aws.String(stoppedVolID),
InstanceId: aws.String(instanceID),
})
_, _ = fix.AWS.EC2.DeleteVolume(&ec2.DeleteVolumeInput{
VolumeId: aws.String(stoppedVolID),
})
@@ -106,16 +107,34 @@ func runAttachToStoppedError(t *testing.T, fix *Fixture) {
harness.WaitForVolumeState(t, fix.AWS, stoppedVolID, "available")
harness.Step(t, "attach-volume %s -> %s (should fail)", stoppedVolID, instanceID)
harness.ExpectError(t, "IncorrectInstanceState", func() error {
_, err := fix.AWS.EC2.AttachVolume(&ec2.AttachVolumeInput{
VolumeId: aws.String(stoppedVolID),
InstanceId: aws.String(instanceID),
Device: aws.String("/dev/sdg"),
harness.Step(t, "attach-volume %s -> %s (stopped)", stoppedVolID, instanceID)
_, err = fix.AWS.EC2.AttachVolume(&ec2.AttachVolumeInput{
VolumeId: aws.String(stoppedVolID),
InstanceId: aws.String(instanceID),
Device: aws.String("/dev/sdg"),
})
require.NoError(t, err, "attach-volume to a stopped instance")
vol := harness.WaitForVolumeState(t, fix.AWS, stoppedVolID, "in-use")
require.Len(t, vol.Attachments, 1, "attachments on %s", stoppedVolID)
require.Equal(t, instanceID, aws.StringValue(vol.Attachments[0].InstanceId), "attached instance")
require.Equal(t, "/dev/sdg", aws.StringValue(vol.Attachments[0].Device), "attached device")
harness.Step(t, "delete-volume %s while attached (should fail)", stoppedVolID)
harness.ExpectError(t, "VolumeInUse", func() error {
_, err := fix.AWS.EC2.DeleteVolume(&ec2.DeleteVolumeInput{
VolumeId: aws.String(stoppedVolID),
})
return err
})
harness.Step(t, "detach-volume %s from %s (stopped)", stoppedVolID, instanceID)
_, err = fix.AWS.EC2.DetachVolume(&ec2.DetachVolumeInput{
VolumeId: aws.String(stoppedVolID),
InstanceId: aws.String(instanceID),
})
require.NoError(t, err, "detach-volume from a stopped instance")
harness.WaitForVolumeState(t, fix.AWS, stoppedVolID, "available")
harness.Step(t, "delete-volume %s", stoppedVolID)
_, err = fix.AWS.EC2.DeleteVolume(&ec2.DeleteVolumeInput{
VolumeId: aws.String(stoppedVolID),
+2 -2
View File
@@ -135,8 +135,8 @@ func TestStopStart(t *testing.T) {
runStopStart(t, requireSingleNodeFixture(t))
}
func TestAttachToStoppedError(t *testing.T) {
runAttachToStoppedError(t, requireSingleNodeFixture(t))
func TestAttachToStopped(t *testing.T) {
runAttachToStopped(t, requireSingleNodeFixture(t))
}
// TestSpotInstanceLifecycle drives the two spot terminal transitions that need