amadan
harness: Run 9 (B) start and seal PASS, flip refused on stale reports (finding 7), the roll as a runbook block
Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
2 files changed,
+98
−6
harness/RUNLOG.md+84 −0harness/scenarios/cohort1/blocks/r9-move.host.sh+14 −6
CI cancelled — superseded by a newer push — run details
CI log
=== gate === cd launchctx && go vet ./... && go test ./... -count=1 ok amadan.net/carlos/platform.git/launchctx 0.011s ? amadan.net/carlos/platform.git/launchctx/controlname [no test files] ? amadan.net/carlos/platform.git/launchctx/wireid [no test files] go vet ./... gofmt -l .: clean go test ./... -count=1 -timeout 30m ok github.com/carlosframework/platform 319.070s ? github.com/carlosframework/platform/cmd/changelog [no test files] ok github.com/carlosframework/platform/cmd/console 3.013s ok github.com/carlosframework/platform/cmd/moveprobe 92.264s ok github.com/carlosframework/platform/cmd/zddprobe 0.701s ? github.com/carlosframework/platform/harness/apps/wakecheck [no test files] ok github.com/carlosframework/platform/internal/activator 250.320s ok github.com/carlosframework/platform/internal/agentsock 0.016s ok github.com/carlosframework/platform/internal/alerting 0.005s ok github.com/carlosframework/platform/internal/analytics 0.019s ok github.com/carlosframework/platform/internal/appconfig 2.540s ok github.com/carlosframework/platform/internal/apperr 0.071s ok github.com/carlosframework/platform/internal/applog 0.134s ok github.com/carlosframework/platform/internal/awsinv 0.005s ok github.com/carlosframework/platform/internal/boxchoice 0.007s ok github.com/carlosframework/platform/internal/boxid 0.582s ? github.com/carlosframework/platform/internal/boxid/boxidtest [no test files] ? github.com/carlosframework/platform/internal/boxid/internal/signtest [no test files] ok github.com/carlosframework/platform/internal/boxvolumes 0.008s ok github.com/carlosframework/platform/internal/caps 0.012s ok github.com/carlosframework/platform/internal/certwarm 0.002s ok github.com/carlosframework/platform/internal/cgroup 0.698s ok github.com/carlosframework/platform/internal/changelog 0.319s ok github.com/carlosframework/platform/internal/claimactivation 0.787s ok github.com/carlosframework/platform/internal/clamd 0.054s ? github.com/carlosframework/platform/internal/cliflag [no test files] amadan: job cancelled — a newer push superseded it
diff --git a/harness/RUNLOG.md b/harness/RUNLOG.md| index 7be348fb8..d4b8814e7 100644 |
| --- a/harness/RUNLOG.md |
| +++ b/harness/RUNLOG.md |
| @@ -1576,6 +1576,57 @@ install-console has put it there (it checks against any persisted identity, `hos |
| Snapshot **`post-0285`** (16:37Z): every box v0.28.6, router/stable and router/canary at v0.28.6, the console on |
| `dd24213d...` by E1, claims off. |
| +### The v0.28.5 roll as a runbook block for real dev (from Run 9) |
| + |
| +Values: `CONSOLE=https://platform.dev.carlosframework.com`, profile `kass`, bucket `carlos-dev-640012953448`, |
| +leo `i-046c7fe43620944bc` (stable, armed), sophie `i-05498eada6f0afd23` (canary, armed, console box), dennis |
| +`i-009d593f451cfd562` (stable, unarmed). `$REL` = the operator's directory with v0.28.5's signed |
| +`SHA256SUMS.txt(.sig)`, `carlos-linux-arm64` and the prebuilt console; `CV` = 54ae7fb9's console ship version. Run 9 |
| +ran every line below with the harness substitutions in step 9's table (and tag v0.28.6 for v0.28.5). |
| + |
| +```bash |
| +# (a) The signing session (C2 first). Operator, DOCS-T1: |
| +CARLOS_BIN=$CARLOS ~/infra/scripts/ship-app.sh kass carlos-dev-640012953448 console "$CV" canary/console binary "$REL/console-linux-arm64" |
| +"$CARLOS" channels --app console --account-id bab # canary/console $CV ... yes |
| +# then the signer: open the session as signing-host.md says, and 6.1's publish-identity for v0.28.5 with |
| +# identity.console.version = $CV. Pass: one create-only write of control/system/router/releases/v0.28.5.json whose |
| +# router sha = the signed sums' carlos-linux-arm64 and console sha = the prebuilt console's. |
| + |
| +# (b) Leo: G4's seven steps, exactly. On leo (root), BEFORE the promote: |
| +systemctl stop carlos-system-update.path; systemctl show carlos-system-update.path -p ActiveState # inactive |
| +# Operator: |
| +carlos system update --console "$CONSOLE" --channel stable --version v0.28.5 --yes # (dennis rolls from this too) |
| +# then refresh REV on the signer (the console re-signs the roster: rev +1, one activation) |
| +# On leo (root), with SUMS_SHA = the signed sums' line and IDENT_SHA = the identity's .current.artifacts["linux-arm64"].sha256: |
| +for i in $(seq 1 120); do [ -f /data/system/router/v0.28.5/carlos ] && break; sleep 5; done # "fetched by the agent": 49 s in Run 9 |
| +test "$(sha256sum < /data/system/router/v0.28.5/carlos | cut -d' ' -f1)" = "$IDENT_SHA" |
| +install -m 0700 -o root -g root <staged copy> /root/carlos-v0.28.5 |
| +test "$(sha256sum < /root/carlos-v0.28.5 | cut -d' ' -f1)" = "$SUMS_SHA"; test "$SUMS_SHA" = "$IDENT_SHA" |
| +systemd-run --wait --pipe -p EnvironmentFile=-/etc/carlos/host.env -p UMask=0022 /root/carlos-v0.28.5 system apply # ~19 s |
| +cat /opt/carlos/system/router/applied.json /opt/carlos/system/router/result.json # "applied" |
| +ls /opt/carlos/system/guard/identities # v0.28.4.json v0.28.5.json |
| +P=$(systemctl show -p MainPID --value carlos-edge); sha256sum < /proc/$P/exe # = IDENT_SHA |
| +systemctl show carlos-edge -p NRestarts # 0 |
| +/opt/carlos/carlos version; /opt/carlos/carlos.prev version # v0.28.5 / v0.28.4 |
| +systemctl start carlos-system-update.path; shred -u /root/carlos-v0.28.5 |
| +# Operator: leo's next report activation_complete true; roster activations [] (Run 9: 3 min 44 s after the promote, |
| +# rev +2 in all); carlos system status: leo current. |
| + |
| +# (c) Dennis: nothing to run. Read result.json "applied" and `carlos system status` current within the 5 m spread. |
| + |
| +# (d) Sophie's router: (b) with canary for stable, on sophie: |
| +systemctl stop carlos-system-update.path # on sophie first |
| +carlos system update --console "$CONSOLE" --channel canary --version v0.28.5 --yes # operator |
| +# then (b)'s leo lines on sophie, unchanged. The console keeps running its protected build throughout. |
| + |
| +# (e) Sophie's guarded console: BLOCKED. `system claims install-console --identity identity.v0.28.5.json --source |
| +# /opt/carlos/versions/$CV/console ...` refuses once a console is installed (defect 5). Needs a ruling before |
| +# dev's console can move off v0.28.4 (and before any offline move: the doors are only in the new console). |
| + |
| +# (f) The dev check (README "Checking dev"), with R9-1: step 3's pinned request to carlos-dev-ie-b answers by |
| +# backhaul from carlos-dev-ie (leo has no wakecheck row since step 4.3), so its host= is the console box. |
| +``` |
| + |
| ### (A5) The normal road: PASS (16:38:08-16:48:26Z) |
| `blocks/r9-normal.host.sh` from the rolled state (leo on v0.28.6, its installed updater now 54ae7fb9, which carries |
| @@ -1667,3 +1718,36 @@ next try; `bg` 915 rows, object `probe/e598fcd53c2d4462.txt`). Not a move defect |
| Snapshot **`pre-move-r9`** (17:07Z). |
| +### B2. The move of moveapp, sophie (home/ie) -> dennis (uk): `blocks/r9-move.host.sh moveapp move` |
| + |
| +Every verb is the v0.28.5 CLI (harness v0.28.6) as the operator against sophie's console: |
| +`carlos move offline <verb> --host moveapp.dev.harness.test --app moveapp --account bab --console http://127.0.0.1:8090`. |
| + |
| +**Before (17:20:28Z, woken on sophie by the request):** `/report` `bg` 2042 rows seq 1-2042, `worker` 1022, `tick` 17, |
| +`fired` every-minute ticks; sophie: env file `27ff170a...`, instance key sha256 `067b3156a105cea1` (= the app's |
| +`platform_key_sha256`), `config.env` names `HARNESS_NOTE MOVEPROBE_ACCESS_KEY MOVEPROBE_BUCKET MOVEPROBE_ENDPOINT |
| +MOVEPROBE_REGION MOVEPROBE_SECRET MOVEPROBE_SECRET_KEY`, files `instance.key` `95b88862...`, row `ready` nested, |
| +timers `every-minute` (schedule) and `once-1` (once, due 1792517863 = 17:37:43Z); dennis and leo: nothing. |
| +Lease `harness-data-ie instances/<host>/lock.json` owner `sophie:230` (awake), none in data-uk. |
| + |
| +| step | at | took | result | |
| +|---|---|---|---| |
| +| start | 17:20:31.070Z | 2.2 s | `Moving moveapp.dev.harness.test from ie to uk.` / `... is offline from now until the move opens or is aborted.` / `Waiting for ada-letterpress in ie ...` / `Every box in ie has stopped moveapp.dev.harness.test. Run carlos move offline seal ...` exit 0. App log 17:20:31 `instance stopping`, `instance exited (exit 0)`. Source reports: ada-letterpress and kathleen-juggling `stopped`, held, fenced, quiesced (leo: no row, no local state) | |
| +| seal | 17:20:33.333Z | 6.1 s | `Copying ... to uk.` / `Copied and checked. Run carlos move offline flip ...` exit 0. Sophie: `checkpointed the local database (position 117, replica 117)`, `sealed at TXID 117 (107 staged objects, files sha256:b0a45754...)`. Lease now `moved:mv_twameyccfp7ryimabnjg32ltla` (the tombstone). `db-tail ok: every source box is at or below TXID 117`, `build-state ok`, `sidecar ok` | |
| +| flip (1st) | 17:23:13.940Z | 0.3 s | **refused**, exit 5: `ada-letterpress still runs a process for moveapp.dev.harness.test. wait for it to stop, then flip`; status: every report `Its report is not current` | |
| + |
| +**Finding 7 (code): flip and open refuse for most of every moves-pass cycle, and flip says the wrong thing.** The |
| +source reports (`control/offline-moves/<host>/<id>/source/*.json`) said `held true, fenced true, quiesced true` and no |
| +process (`procs` omitted = 0); the sophie slice `carlos-instances-moveapp.dev.harness.test.slice` held no process. |
| +But they were written at 17:20:44-45Z, by the moves pass the seal door's serial bump set off, and nothing rewrote |
| +them: the moves pass runs on a serial bump (`internal/host/agent.go:2695`, the fast leg) or every 5 minutes plus up to |
| +1 minute of jitter (`agent.go:3262-3263`, `runMovesPass` at `:3277`). The doors believe a report for 2 minutes |
| +(`offlineReportFresh`, `internal/console/apiinstancemove_offline.go:57`). So after any door, flip and open can pass |
| +only in the first 2 minutes, then refuse for 3 to 4 minutes until the timed pass. And `offlineFlipCheck` answers a |
| +stale report with MV-O31's process sentence (`apiinstancemove_offline.go:848-849`, `processRefusal`), not M-C10's |
| +wait or a "report not current" sentence: an operator reading "still runs a process" will look for a process that |
| +isn't there. (My first flip came 2 min 40 s after the seal because my own process check was wrong: `pgrep -f` inside |
| +`sh -c` matched its own command line. It is fixed to read the host's cgroup.) Runbook correction below (M2): run |
| +`flip` and `open` straight after the previous door, or retry them every 15 s until the next pass. The script's `MVR` |
| +does that and logs each try. |
| + |
diff --git a/harness/scenarios/cohort1/blocks/r9-move.host.sh b/harness/scenarios/cohort1/blocks/r9-move.host.sh| index 6c7b1cea3..44edce09f 100644 |
| --- a/harness/scenarios/cohort1/blocks/r9-move.host.sh |
| +++ b/harness/scenarios/cohort1/blocks/r9-move.host.sh |
| @@ -9,6 +9,11 @@ C=http://127.0.0.1:8090 |
| K=/run/harness/keys; S=$(grep ^MOVEPROBE_SECRET= $K/$APP.store.env | cut -d= -f2) |
| MV() { runuser -l operator -c "carlos move offline $1 --host $H --app $APP --account bab --console $C ${2:-}" 2>&1 | grep -v ALERT; return ${PIPESTATUS[0]}; } |
| ts() { date -u +%T.%3NZ; } |
| +# MVR <verb>: the verb, retried every 15 s for up to 9 minutes while the door refuses only for stale reports |
| +# (finding 7: reports are rewritten by the 5-6 minute moves pass, the doors want them under 2 minutes old, and a |
| +# stale report reads "still runs a process" at flip). |
| +MVR() { local i out rc; for i in $(seq 1 36); do out=$(MV "$1"); rc=$?; echo " try $i $(ts) exit=$rc: $(echo "$out" | tail -1)" |
| + case "$rc:$out" in 5:*"still runs a process"*|5:*"Waiting for"*|5:*"not current"*|4:*) sleep 15;; *) echo "$out"; return $rc;; esac; done; return $rc; } |
| REQ() { # REQ <box> <path>: a request through that box's edge |
| incus exec $1 -- curl -s -m 60 --cacert /root/harness-ca.pem -H "Authorization: Bearer $S" --resolve $H:443:127.0.0.1 -w '\n[%{http_code} %{time_total}s]' "https://$H$2"; } |
| facts() { # facts <box>: the instance's local state, key digests, config names, timers, the row |
| @@ -35,6 +40,7 @@ lock() { # the data buckets' lease object for H |
| echo " $bk instances/$H/lock.json: $(runuser -l operator -c "aws s3 cp --quiet s3://$bk/instances/$H/lock.json - 2>/dev/null" | jq -c '{owner: (.owner // .Owner), expires: (.expires // .Expires)}' 2>/dev/null || echo absent)" |
| done |
| } |
| +if [ "${3:-}" != resume ]; then |
| echo "== before ($(ts))" |
| REQ sophie /report | head -c 900; echo |
| for b in sophie dennis leo; do echo "-- $b"; facts $b; done; lock |
| @@ -46,14 +52,16 @@ MV seal; echo "seal exit=$? at $(ts) took $(echo "$(date +%s.%N) $T" | awk "{pri |
| MV status; lock |
| echo "== process check before flip: carlos logs 'instance exited', worker gone ($(ts))" |
| runuser -l operator -c "carlos logs --app $APP --account bab --console $C --since 15m" 2>&1 | grep -v ALERT | grep -E "exited|stopp|fence" | tail -3 |
| -for i in $(seq 1 30); do n=$(incus exec sophie -- sh -c "pgrep -fc 'moveprobe|/live/$H' || true"); [ "$n" = 0 ] && break; sleep 5; done; echo "sophie processes for $H: $n ($(ts))" |
| +for i in $(seq 1 30); do n=$(incus exec sophie -- sh -c "cat /sys/fs/cgroup/carlos.slice/carlos-instances.slice/carlos-instances-$H.slice/cgroup.procs 2>/dev/null | wc -l"); [ "$n" = 0 ] && break; sleep 5; done; echo "sophie processes in carlos-instances-$H.slice: $n ($(ts))" |
| +fi |
| +[ "${3:-}" = resume ] && T_START=$(date -d "${4:?start time}" +%s.%N) |
| echo "== flip ($(ts))"; T=$(date +%s.%N) |
| -MV flip; echo "flip exit=$? at $(ts) took $(echo "$(date +%s.%N) $T" | awk "{printf \"%.1f\", \$1-\$2}")s" |
| +MVR flip; echo "flip exit=$? at $(ts) took $(echo "$(date +%s.%N) $T" | awk "{printf \"%.1f\", \$1-\$2}")s" |
| MV status |
| for b in sophie dennis; do echo "-- $b"; facts $b; done |
| if [ "$MODE" = abort ]; then |
| echo "== abort ($(ts))"; T=$(date +%s.%N) |
| - MV abort; echo "abort exit=$? at $(ts) took $(echo "$(date +%s.%N) $T" | awk "{printf \"%.1f\", \$1-\$2}")s" |
| + MVR abort; echo "abort exit=$? at $(ts) took $(echo "$(date +%s.%N) $T" | awk "{printf \"%.1f\", \$1-\$2}")s" |
| MV status |
| echo "== finish ($(ts))"; MV finish; echo "finish exit=$? at $(ts)" |
| MV status; lock |
| @@ -64,16 +72,16 @@ if [ "$MODE" = abort ]; then |
| exit 0 |
| fi |
| echo "== open ($(ts))"; T=$(date +%s.%N) |
| -MV open; echo "open exit=$? at $(ts) took $(echo "$(date +%s.%N) $T" | awk "{printf \"%.1f\", \$1-\$2}")s" |
| +MVR open; echo "open exit=$? at $(ts) took $(echo "$(date +%s.%N) $T" | awk "{printf \"%.1f\", \$1-\$2}")s" |
| echo "== first request on dennis ($(ts))" |
| -for i in $(seq 1 20); do c=$(REQ dennis /ready | tail -1); echo "dennis /ready $c $(ts)"; case "$c" in *"[200 "*) break;; esac; sleep 3; done |
| +for i in $(seq 1 60); do c=$(REQ dennis /ready | tail -1); echo "dennis /ready $c $(ts)"; case "$c" in *"[200 "*) break;; esac; sleep 3; done |
| echo "serving from dennis at $(ts): offline $(echo "$(date +%s.%N) $T_START" | awk "{printf \"%.1f\", \$1-\$2}")s since start" |
| REQ dennis /report | head -c 1200; echo |
| echo "-- backhaul: through sophie's edge (the IE box) and leo's"; REQ sophie /ready | tail -1; echo; REQ leo /ready | tail -1; echo |
| for b in sophie dennis; do echo "-- $b"; facts $b; done; lock |
| MV status |
| echo "== finish ($(ts))"; T=$(date +%s.%N) |
| -MV finish; echo "finish exit=$? at $(ts) took $(echo "$(date +%s.%N) $T" | awk "{printf \"%.1f\", \$1-\$2}")s" |
| +MVR finish; echo "finish exit=$? at $(ts) took $(echo "$(date +%s.%N) $T" | awk "{printf \"%.1f\", \$1-\$2}")s" |
| MV status; lock |
| for b in sophie dennis leo; do echo "-- $b"; facts $b; done |
| runuser -l operator -c "aws s3 cp --quiet s3://harness-deployment/apps/bab/$APP/instances/$H.json -" | jq -c '{region, move, last_move, record_seq}' |