diff --git a/CHANGELOG.md b/CHANGELOG.md index 236d43c..754ba28 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -11,6 +11,32 @@ RFC; a release that bumps one says so here. ## [Unreleased] +### Installers (`vibemon-install.sh` 0.2.15+install.2) + +Driven by the 67 failed install reports of 2026-09-05..10-11 (43 distinct +client addresses; 28 never reported a later success). + +- **A systemd user service that refuses to register no longer ends the + install.** `attempt daemon install` failed on five Linux machines whose + `systemctl --user` had passed the pre-check, *after* the pairing token was + spent and the hooks were in: a paired machine that uploaded nothing, and the + same command could not be pasted again. Where the session supervisor can run + (`nohup`, `setsid`, `flock`) the script now continues with it, reports the + refusal as its own `daemon` report (with the failing command's words and the + environment facts) and finishes `done` with the fallback named in `error`. + Where it cannot (macOS, or a tool missing) it stops as before and now says + that the machine is paired and to run the same command again without a token. +- **The network steps get a second and third try**: the legacy-key exchange + (11 reports of "This operation was aborted"; a key the web does not know is + still answered once), the pairing check (no answer or 5xx) and the first + upload (4 reports of `Network Err`). Every request is bounded + (`--connect-timeout`, `--max-time`); before, the exchange and the check had no + limit and a dead server hung the script. `VIBEMON_INSTALL_RETRY_DELAY` + (default 3 s) scales the wait between tries. +- A run that stops at the gate that changes nothing (no token, never connected) + is reported `ok` whatever its exit status; two Linux reports said `exit 1` + there (not reproduced on macOS with dash, sh or bash). + ## [0.2.15] — 2026-10-07 A server release: the client binaries differ from 0.2.14 only in their version diff --git a/PROGRESS.md b/PROGRESS.md index 16390ad..2075289 100644 --- a/PROGRESS.md +++ b/PROGRESS.md @@ -2,6 +2,28 @@ Execution log for `TODO.md`. Newest session first. Read this before working. +## 2026-10-12 — installer failures: fallback and retries (not released) + +Read the 67 failed install reports (`attemptdb_install_reports`, 355 total, vibemon Supabase +`sirpdtcwawcidhgtltps`) against the script. Nothing new was breaking after 0.2.15 was served +(10/8 21:24 KST: 5 successes, 1 non-bug), but three causes were still in the code. + +**Changed (working tree, uncommitted, not tagged, not pushed).** `docs/migration/vibemon-install.sh` +(`0.2.15+install.2`): systemd registration failure falls back to the session supervisor and is +reported on its own; key exchange / pairing check / first upload retried three times and bounded; +the no-credentials gate is reported ok. `tests/installers/test_vibemon_install.py`: 13 new tests +(9 fail on the old script), the failing-daemon tests now remove `setsid` so they still mean "no +fallback"; full `tests/installers` 160 OK (7 CI-only skips), also under dash. vibemon-web (separate +repo, uncommitted): `mintPairing` 15 s + one retry on no-answer/5xx, `maxDuration = 60` on the pair +route, test. + +**Not done.** To ship the script: commit, CI + `Install and sync smoke` green, new immutable +`install-YYYY-MM-DD.N` tag, vibemon-web `install-pins.ts` ref bump (the Windows script is unchanged, +so `INSTALLER_REF` stays). The web change deploys on merge to `main` (E2E has been red since 10/8, +unrelated). The `exit 1` on the no-credentials gate (2 Linux reports) was not reproduced; the report +fix is a guard, not a cause. Linux `init` (2) and `connect` (2) failures have no log: 0.2.15 will +capture the next ones. + ## 2026-10-08 — 0.2.15 released and deployed; installers moved to it Follows the 2026-10-07 install check (see the memory note and git history for the rehearsal diff --git a/docs/migration/vibemon-hooks.md b/docs/migration/vibemon-hooks.md index 32354f3..7d0a93a 100644 --- a/docs/migration/vibemon-hooks.md +++ b/docs/migration/vibemon-hooks.md @@ -91,6 +91,20 @@ container/WSL hints and free disk on Linux; the GUI domain on macOS; the Windows build, admin and the Scheduled Task on Windows. No file contents, no secrets. The admin install-reports page shows it. +### What the script retries and what it falls back to + +- The legacy-key exchange, the pairing check and the first upload are tried up + to three times (a slow or restarting server is not a failed install); each + request is bounded. A key the web does not know, and a spent pairing token, + are answers and are not tried again. +- If `attempt daemon install` fails on Linux (systemd answered the pre-check + but would not register the unit) and `nohup`, `setsid` and `flock` exist, the + script continues with the session supervisor and says so. Two reports result: + a `daemon` failure carrying the command's output and the environment facts, + then `done` with the fallback in `error`. Without those tools, and on macOS, + it stops, and the saved connection is finished by running the same command + again **without** a token. + ## Removing `~/.vibemon` `vibemon-install.sh --purge-legacy` deletes the directory only after checking diff --git a/docs/migration/vibemon-install.sh b/docs/migration/vibemon-install.sh index f0e9ebe..ce0284d 100755 --- a/docs/migration/vibemon-install.sh +++ b/docs/migration/vibemon-install.sh @@ -20,7 +20,7 @@ # key, proven by an authenticated handshake, saved only on success # 5. installs the agent hooks next to any existing ones # 6. registers the background daemon (launchd / systemd --user), or -# starts a Linux session supervisor when no user service is available +# starts a Linux session supervisor when systemd --user cannot do it # 7. uploads once and requires the server to accept it # 8. only then removes the legacy VibeMon hooks (~/.vibemon/notify.sh) # 9. shows `attempt doctor` @@ -108,8 +108,12 @@ INSTALL_TMP="" # ATTEMPTDB_VERSION to the workspace version so a release cannot leave it # behind again. A newer `attempt` already on the machine is kept. ATTEMPTDB_VERSION="${ATTEMPTDB_VERSION:-0.2.15}" -INSTALLER_VERSION="0.2.15+install.1" +INSTALLER_VERSION="0.2.15+install.2" INSTALLER_REF="install-2026-10-07.1" +# Seconds between tries of the network steps that are worth a second try (the +# key exchange, the pairing check, the first upload): n x this. Tests set 0. +RETRY_DELAY="${VIBEMON_INSTALL_RETRY_DELAY:-3}" +case "$RETRY_DELAY" in ""|*[!0-9]*) RETRY_DELAY=3 ;; esac ATTEMPTDB_INSTALLER="${ATTEMPTDB_INSTALLER:-https://raw.githubusercontent.com/nullarch/attemptdb/v${ATTEMPTDB_VERSION}/install.sh}" export ATTEMPTDB_VERSION @@ -262,16 +266,34 @@ run_live() { pair_check() { if [ "$LOG_MODE" = tee ]; then _ce="$LOG.$$.curl" - _cs="$(curl -sS -o /dev/null -w '%{http_code}' "$1" 2>"$_ce")" || _cs=000 + _cs="$(curl -sS --connect-timeout 10 --max-time 30 -o /dev/null -w '%{http_code}' "$1" 2>"$_ce")" || _cs=000 if [ -s "$_ce" ]; then cat "$_ce" >&2; cat "$_ce" >>"$LOG" 2>/dev/null || true; fi rm -f "$_ce" 2>/dev/null || true else - _cs="$(curl -sS -o /dev/null -w '%{http_code}' "$1")" || _cs=000 + _cs="$(curl -sS --connect-timeout 10 --max-time 30 -o /dev/null -w '%{http_code}' "$1")" || _cs=000 fi case "$_cs" in 000|[1-5][0-9][0-9]) ;; *) _cs=000 ;; esac printf '%s' "$_cs" return 0 } +# The same check, tried up to three times when the request got no answer or a +# 5xx: a slow or restarting server is not a reason to throw the pairing away. +# A 2xx/4xx is an answer and is returned at once. +pair_check_retry() { + _pn=1 + while :; do + _pc="$(pair_check "$1")" + case "$_pc" in + 000|5[0-9][0-9]) [ "$_pn" -lt 3 ] || break ;; + *) break ;; + esac + say "vibemon: the sync server did not answer the pairing check (try $_pn of 3); trying again" >&2 + sleep $((_pn * RETRY_DELAY)) + _pn=$((_pn + 1)) + done + printf '%s' "$_pc" + return 0 +} case "$PROFILE" in metadata_only|semantic|messages|full) ;; *) fail "unknown --profile $PROFILE (metadata_only | semantic | messages | full)" ;; @@ -339,15 +361,12 @@ fingerprint() { probe attempt attempt --version return 0 } -# On a failed service step, write the facts above. With no log to write to -# they go to a temporary file the report reads instead. -diagnose() { - [ "$1" -ne 0 ] || return 0 - case "$STEP" in daemon|environment) ;; *) return 0 ;; esac - [ "$DRY_RUN" -eq 0 ] || return 0 +# Write the facts above after whatever the log holds now. With no log to +# write to they go to a temporary file the report reads instead. +record_fingerprint() { _dst="$LOG" if [ -z "$_dst" ]; then - FPTMP="$(mktemp 2>/dev/null)" || FPTMP="" + [ -n "$FPTMP" ] || { FPTMP="$(mktemp 2>/dev/null)" || FPTMP=""; } _dst="$FPTMP" fi [ -n "$_dst" ] || return 0 @@ -355,6 +374,29 @@ diagnose() { [ -n "$REPORT_SRC" ] || REPORT_SRC="$_dst" return 0 } +# On a failed service step, write the facts above. +diagnose() { + [ "$1" -ne 0 ] || return 0 + case "$STEP" in daemon|environment) ;; *) return 0 ;; esac + [ "$DRY_RUN" -eq 0 ] || return 0 + record_fingerprint + return 0 +} +# What the Linux session runtime needs that this machine lacks: the reason, +# or nothing when it can run. It is the way out when systemd --user is missing +# and also when it is there but cannot register the daemon. +session_tools_error() { + for tool in nohup setsid flock; do + if ! command -v "$tool" >/dev/null 2>&1; then + printf 'Linux session sync requires nohup, setsid and flock; missing %s' "$tool" + return 0 + fi + done + if ! command -v sha256sum >/dev/null 2>&1 && ! command -v shasum >/dev/null 2>&1; then + printf 'Linux session sync requires sha256sum or shasum' + fi + return 0 +} # The end of the log as a report field: control characters dropped, keys, # tokens, credentials and home/temp paths blanked, JSON-escaped, the last @@ -373,12 +415,14 @@ build_tail() { report() { code="$1" [ "$REPORT" -eq 1 ] && [ "$DRY_RUN" -eq 0 ] || return 0 - ok=false; [ "$code" -eq 0 ] && ok=true + # The gate that changes nothing (step noop) ends with exit 0 and has nothing + # after it that can fail; two Linux reports said `exit 1` there anyway. + ok=false; if [ "$code" -eq 0 ] || [ "$STEP" = noop ]; then ok=true; fi unattended=false; [ "$UNATTENDED" -eq 1 ] && unattended=true os="$(uname -s 2>/dev/null || echo unknown)" arch="$(uname -m 2>/dev/null || echo unknown)" av="$(attempt --version 2>/dev/null | sed -n 's/^attempt //p' | head -n 1)" - if [ "$code" -ne 0 ] && [ -z "$LAST_ERROR" ]; then + if [ "$ok" = false ] && [ -z "$LAST_ERROR" ]; then LAST_ERROR="command failed during $STEP (${LAST_CMD:-exit $code}); see the install log" fi err="$(printf '%s' "$LAST_ERROR" | head -n 1 | tr -d '"\\' | tr '\t\r' ' ' \ @@ -492,12 +536,7 @@ if [ "$DRY_RUN" -eq 0 ]; then Linux) if ! command -v systemctl >/dev/null 2>&1 || ! systemctl --user show-environment >/dev/null 2>&1; then RUNTIME=session - for tool in nohup setsid flock; do - command -v "$tool" >/dev/null 2>&1 || service_error="Linux session sync requires nohup, setsid and flock; missing $tool" - done - if ! command -v sha256sum >/dev/null 2>&1 && ! command -v shasum >/dev/null 2>&1; then - service_error="Linux session sync requires sha256sum or shasum" - fi + service_error="$(session_tools_error)" say "vibemon: systemd user service unavailable; selecting Linux session sync" fi ;; @@ -529,11 +568,28 @@ if [ -n "$LEGACY_KEY" ] && [ -z "$TOKEN" ] && [ "$connected" -eq 0 ]; then say "+ curl -fsS -X POST $WEB/api/attemptdb/pair (vbm_… → pair_…)" TOKEN="pair_dryrun" else - resp="$(curl -sS -X POST -H 'Content-Type: application/json' \ - --data "{\"api_key\":\"$LEGACY_KEY\"}" "$WEB/api/attemptdb/pair" 2>/dev/null || true)" - TOKEN="$(printf '%s' "$resp" | sed -n 's/.*"token": *"\(pair_[A-Za-z0-9_-]*\)".*/\1/p')" - if [ -z "$TOKEN" ]; then + # The web asks the sync server for the token with an 8 s limit, so a + # slow server shows up here as "This operation was aborted" (11 failed + # installs, 2026-09 to 2026-10). Nothing has changed yet, so a try or + # two more is free; an answer that says the key itself is wrong is not + # tried again. Each request is bounded, so a dead server cannot hang + # the script. + _xn=1 + while :; do + resp="$(curl -sS --connect-timeout 10 --max-time 40 -X POST -H 'Content-Type: application/json' \ + --data "{\"api_key\":\"$LEGACY_KEY\"}" "$WEB/api/attemptdb/pair" 2>/dev/null || true)" + TOKEN="$(printf '%s' "$resp" | sed -n 's/.*"token": *"\(pair_[A-Za-z0-9_-]*\)".*/\1/p')" + [ -z "$TOKEN" ] || break reason="$(printf '%s' "$resp" | sed -n 's/.*"error": *"\([^"]*\)".*/\1/p')" + case "$reason" in + "unknown API key"*|"api_key must be"*|"account deleted"*|"device pairing is not enabled"*) break ;; + esac + [ "$_xn" -lt 3 ] || break + say "vibemon: the web did not answer the key exchange (${reason:-no usable answer}); trying again" >&2 + sleep $((_xn * RETRY_DELAY)) + _xn=$((_xn + 1)) + done + if [ -z "$TOKEN" ]; then fail "the web did not accept this API key: ${reason:-no usable answer from $WEB} (nothing changed; get a command at $WEB/devices)" fi web_server="$(printf '%s' "$resp" | sed -n 's/.*"sync_url": *"\([^"]*\)".*/\1/p')" @@ -557,7 +613,7 @@ if [ -n "$TOKEN" ]; then if [ "$DRY_RUN" -eq 1 ]; then say "+ curl -fsS $SERVER/v1/pair/$TOKEN" else - code="$(pair_check "$SERVER/v1/pair/$TOKEN")" + code="$(pair_check_retry "$SERVER/v1/pair/$TOKEN")" case "$code" in 200) ;; 410) fail "the pairing token has expired or was already used; get a new one at https://vibemon.dev/devices" ;; @@ -727,15 +783,48 @@ STEP=daemon # every few seconds. Re-running re-registers. if [ "$RUNTIME" = session ]; then attempt daemon status >/dev/null 2>&1 || fail "Linux session daemon stopped; legacy hooks unchanged" -else - run attempt daemon install || fail "background service registration failed; legacy hooks unchanged (see the install log)" +elif ! run attempt daemon install; then + # By now the pairing token is spent and the hooks are in, so stopping here + # leaves a paired machine that uploads nothing, and the same command cannot + # be pasted again. Five Linux installs ended this way between 2026-09-26 + # and 2026-10-08 (systemd answered the pre-check, then refused the unit). + # Where the session supervisor can run, run it: the person gets a working + # install that lasts as long as the environment, and the report keeps what + # systemd said. Elsewhere (macOS, or no nohup/setsid/flock) stop, and say + # how to finish without a new token. + _why="$(session_tools_error)" + if [ "$(uname -s)" = Linux ] && [ -z "$_why" ]; then + LAST_ERROR="background service registration failed; continued with Linux session sync (see the install log)" + say "vibemon: the systemd user service could not be registered; continuing with Linux session sync instead" + record_fingerprint + report 1 + RUNTIME=session + start_session_runtime + else + say "vibemon: this machine is paired and its hooks are installed, but nothing uploads until a background" >&2 + say " service runs. Fix the cause above, then run the same install command again without a pairing" >&2 + say " token: the saved connection is kept and the remaining steps run." >&2 + fail "background service registration failed; legacy hooks unchanged (see the install log)" + fi fi STEP=upload # 7. One upload now; the server must accept it before anything is removed. +# Three tries: a network blip or a restarting server (four installs ended +# here on `Network Err`) should not leave the switch half done. +upload_now() { + _un=1 + while :; do + if logged attempt sync now; then return 0; fi + [ "$_un" -lt 3 ] || return 1 + say "vibemon: the first upload did not go through (try $_un of 3); trying again" >&2 + sleep $((_un * RETRY_DELAY)) + _un=$((_un + 1)) + done +} if [ "$DRY_RUN" -eq 1 ]; then say "+ attempt sync now" -elif ! logged attempt sync now; then +elif ! upload_now; then say "" >&2 say "vibemon: the first upload did not go through. AttemptDB is installed and hooks are in place," >&2 say " but the legacy VibeMon hooks were left untouched so collection continues as before." >&2 diff --git a/tests/installers/test_vibemon_install.py b/tests/installers/test_vibemon_install.py index dd7ca06..ba08b9d 100644 --- a/tests/installers/test_vibemon_install.py +++ b/tests/installers/test_vibemon_install.py @@ -22,6 +22,10 @@ args = sys.argv[1:] with open(os.environ["CALLS"], "a") as out: out.write(json.dumps([name, *args]) + "\n") +def nth(match): + """How many calls so far (this one included) are of the given kind.""" + history = [json.loads(line) for line in pathlib.Path(os.environ["CALLS"]).read_text().splitlines()] + return sum(1 for c in history if match(c)) if name == "attempt": with open(os.environ["CALLS"] + ".env", "a") as out: out.write(json.dumps({v: os.environ.get(v) for v in ("CLAUDE_CONFIG_DIR", "CODEX_HOME", "CURSOR_CONFIG_DIR", "GEMINI_CONFIG_DIR")}) + "\n") @@ -47,20 +51,28 @@ if os.environ.get("DAEMON_STDERR"): print(os.environ["DAEMON_STDERR"], file=sys.stderr) print("service registration failed" if os.environ.get("DAEMON_EXIT") else "service registered") sys.exit(int(os.environ.get("DAEMON_EXIT", "0"))) - elif args == ["sync", "now"]: sys.exit(int(os.environ.get("UPLOAD_EXIT", "0"))) + elif args == ["sync", "now"]: + # UPLOAD_FAILS=N: only the first N uploads fail (a blip), else all do. + failing = nth(lambda c: c[:3] == ["attempt", "sync", "now"]) <= int(os.environ.get("UPLOAD_FAILS", "999")) + sys.exit(int(os.environ.get("UPLOAD_EXIT", "0")) if failing else 0) # `status` succeeds when a database exists; `--json` says which mode it is in. elif args == ["status"]: sys.exit(int(os.environ.get("STATUS_EXIT", "0"))) elif args == ["status", "--json"]: print(json.dumps({"capture_mode": os.environ.get("EXISTING_MODE", "local_semantic")})) elif name == "curl": url = next((x for x in args if x.startswith("https://")), "") if url.endswith("/api/attemptdb/pair"): - if os.environ.get("PAIR_API_ERROR"): print('{"error":"' + os.environ["PAIR_API_ERROR"] + '"}') + # PAIR_API_FAILS=N: only the first N exchanges answer with the error. + exchange = nth(lambda c: c[0] == "curl" and any(a.endswith("/api/attemptdb/pair") for a in c[1:])) + if os.environ.get("PAIR_API_ERROR") and exchange <= int(os.environ.get("PAIR_API_FAILS", "999")): + print('{"error":"' + os.environ["PAIR_API_ERROR"] + '"}') else: print('{"token":"pair_fixture","sync_url":"https://sync.example.test"}') elif "/v1/pair/" in url: - if os.environ.get("PAIR_CURL_FAIL"): + # PAIR_CHECK_FAILS=N: only the first N checks fail (a blip), else all do. + check = nth(lambda c: c[0] == "curl" and any("/v1/pair/" in a for a in c[1:])) + if os.environ.get("PAIR_CURL_FAIL") and check <= int(os.environ.get("PAIR_CHECK_FAILS", "999")): # A request that never got an answer: curl -w still prints 000, then fails. print("000"); print("curl: (6) Could not resolve host: sync.example.test", file=sys.stderr); sys.exit(6) - print("200") + print(os.environ.get("PAIR_CHECK_STATUS", "200")) elif url.endswith("/install.sh") and "-o" in args: # The binary installer: record what it was asked to do, install nothing. pathlib.Path(args[args.index("-o") + 1]).write_text( @@ -68,7 +80,9 @@ elif url.endswith(".ps1") and "-o" in args: pathlib.Path(args[args.index("-o") + 1]).write_text("# fixture only\n") elif url.endswith("install-report"): - pathlib.Path(os.environ["REPORT_FILE"]).write_text(args[args.index("--data") + 1]) + # One line per report: the script may report twice (a recovered failure, then the end). + with open(os.environ["REPORT_FILE"], "a") as out: + out.write(args[args.index("--data") + 1] + "\n") elif name == "cygpath": print(args[-1]) elif name == "powershell.exe": # What the native installer would inherit from the environment. @@ -145,7 +159,8 @@ def run_install(self, args=(), legacy=False, missing=(), attended=False, **setti (root / ".vibemon/api-key").write_text("vbm_fixture") env = {**scrubbed_environ(), "HOME": temp, "XDG_STATE_HOME": str(root / "state"), "PATH": str(bin_dir), "ATTEMPTDB_BIN_DIR": str(bin_dir), - "CALLS": str(root / "calls"), "REPORT_FILE": str(root / "report"), **settings} + "CALLS": str(root / "calls"), "REPORT_FILE": str(root / "report"), + "VIBEMON_INSTALL_RETRY_DELAY": "0", **settings} cmd = [os.environ.get("VIBEMON_TEST_SHELL") or "/bin/sh", str(SCRIPT), *args] if attended: result = run_on_a_terminal(cmd, env) @@ -156,7 +171,8 @@ def run_install(self, args=(), legacy=False, missing=(), attended=False, **setti self.log_text = logs[0].read_text() if logs else None self.log_mode = (logs[0].stat().st_mode & 0o777) if logs else None calls =[json.loads(line) for line in (root / "calls").read_text().splitlines()] if (root / "calls").exists() else [] - report = json.loads((root / "report").read_text()) if (root / "report").exists() else None + self.reports = [json.loads(line) for line in (root / "report").read_text().splitlines()] if (root / "report").exists() else [] + report = self.reports[-1] if self.reports else None self.last = result seen = root / "calls.env" self.agent_env = [json.loads(line) for line in seen.read_text().splitlines()] if seen.exists() else [] @@ -327,9 +343,10 @@ def test_the_windows_handoff_forwards_exactly_the_mode_that_was_asked_for(self): self.assertIn(["powershell-env", env_mode], calls) def test_service_and_upload_failure_preserve_legacy(self): + # (setsid missing: with it, a failing systemd registration is not a failure any more) for setting, step in (("DAEMON_EXIT", "daemon"), ("UPLOAD_EXIT", "upload")): with self.subTest(step=step): - code, calls, report = self.run_install(legacy=True, **{setting: "1"}) + code, calls, report = self.run_install(legacy=True, missing=("setsid",), **{setting: "1"}) self.assertEqual((code, report["step"]), (1, step)) self.assertTrue(report["error"]) self.assertFalse(any("--remove-legacy" in c for c in calls)) @@ -355,7 +372,7 @@ def test_native_failure_is_not_reported_as_success(self): def test_long_diagnostics_remain_valid_json_and_redacted(self): diagnostic = ('error: "fixture" \\ invalid vbm_fixture /home/dev/example/project\n' * 100) - code, calls, report = self.run_install(legacy=True, DAEMON_EXIT="1", DIAGNOSTIC=diagnostic) + code, calls, report = self.run_install(legacy=True, missing=("setsid",), DAEMON_EXIT="1", DIAGNOSTIC=diagnostic) self.assertEqual(code, 1) self.assertNotIn("vbm_fixture", report["log_tail"]) self.assertNotIn("/home/dev", report["log_tail"]) @@ -383,7 +400,7 @@ def lines(self, text): # -- the failing command's output reaches the report ------------------------ def test_an_attended_daemon_failure_reports_the_commands_stderr_and_the_machine(self): - code, calls, report = self.run_install(["pair_fixture"], attended=True, DAEMON_EXIT="1", DAEMON_STDERR=self.STDERR) + code, calls, report = self.run_install(["pair_fixture"], attended=True, missing=("setsid",), DAEMON_EXIT="1", DAEMON_STDERR=self.STDERR) self.assertEqual((code, report["step"], report["unattended"]), (1, "daemon", False)) tail = report["log_tail"] self.assertIn(self.STDERR, tail) @@ -402,7 +419,7 @@ def test_an_attended_daemon_failure_reports_the_commands_stderr_and_the_machine( self.assertEqual(self.log_mode, 0o600) def test_an_unattended_daemon_failure_reports_the_same(self): - code, calls, report = self.run_install(["pair_fixture"], DAEMON_EXIT="1", DAEMON_STDERR=self.STDERR) + code, calls, report = self.run_install(["pair_fixture"], missing=("setsid",), DAEMON_EXIT="1", DAEMON_STDERR=self.STDERR) self.assertEqual((code, report["step"], report["unattended"]), (1, "daemon", True)) self.assertIn(self.STDERR, report["log_tail"]) self.assertIn("--- environment", report["log_tail"]) @@ -420,7 +437,7 @@ def test_the_facts_reach_the_report_even_when_there_is_nowhere_to_keep_a_log(sel with tempfile.TemporaryDirectory(prefix="attempt-nolog-") as other: blocked = Path(other) / "a-file-not-a-directory" blocked.write_text("") - code, calls, report = self.run_install(["pair_fixture"], attended=True, DAEMON_EXIT="1", XDG_STATE_HOME=str(blocked)) + code, calls, report = self.run_install(["pair_fixture"], attended=True, missing=("setsid",), DAEMON_EXIT="1", XDG_STATE_HOME=str(blocked)) self.assertIsNone(self.log_file, "no place to write: no log, silently") self.assertEqual((code, report["step"]), (1, "daemon")) self.assertIn("--- environment", report["log_tail"]) @@ -447,7 +464,7 @@ def test_a_successful_attended_run_prints_what_an_unattended_run_logs(self): def test_the_exit_status_of_a_failed_command_is_the_commands_own(self): for setting, step in (("DAEMON_EXIT", "daemon"), ("UPLOAD_EXIT", "upload")): with self.subTest(step=step): - code, calls, report = self.run_install(["pair_fixture"], attended=True, **{setting: "1"}) + code, calls, report = self.run_install(["pair_fixture"], attended=True, missing=("setsid",), **{setting: "1"}) self.assertEqual((code, report["step"]), (1, step)) self.assertFalse(any("--remove-legacy" in c for c in calls)) @@ -465,7 +482,7 @@ def test_captured_output_is_scrubbed_before_it_is_reported(self): "Authorization: Bearer sk-live-0123456789 and vbm_fixturekey0123") for attended in (True, False): with self.subTest(attended=attended): - code, calls, report = self.run_install(["pair_fixture"], attended=attended, DAEMON_EXIT="1", DAEMON_STDERR=words) + code, calls, report = self.run_install(["pair_fixture"], attended=attended, missing=("setsid",), DAEMON_EXIT="1", DAEMON_STDERR=words) self.assertEqual(report["step"], "daemon") text = json.dumps(report) for secret in ("atk_0123456789abcdef", "/home/dev", "sk-live-0123456789", "vbm_fixturekey0123"): @@ -475,7 +492,7 @@ def test_captured_output_is_scrubbed_before_it_is_reported(self): def test_a_flood_of_output_keeps_the_end_and_the_report_inside_the_receivers_limits(self): flood = "\n".join(f'line {i}: "quoted" \\ backslash {"x" * 150}' for i in range(300)) - code, calls, report = self.run_install(["pair_fixture"], attended=True, DAEMON_EXIT="1", DIAGNOSTIC=flood, DAEMON_STDERR=self.STDERR) + code, calls, report = self.run_install(["pair_fixture"], attended=True, missing=("setsid",), DAEMON_EXIT="1", DIAGNOSTIC=flood, DAEMON_STDERR=self.STDERR) self.assertEqual(report["step"], "daemon") self.assertLessEqual(len(json.dumps(report)), 8192, "the web answers 413 above 8 KB and drops the report") self.assertLessEqual(len(report["log_tail"]), 4096, "the web keeps the first 4 KB of the tail") @@ -483,7 +500,7 @@ def test_a_flood_of_output_keeps_the_end_and_the_report_inside_the_receivers_lim self.assertIn("--- environment", report["log_tail"]) def test_terminal_control_characters_never_break_the_json(self): - code, calls, report = self.run_install(["pair_fixture"], attended=True, DAEMON_EXIT="1", DAEMON_STDERR="\x1b[31mred\x1b[0m error\x07") + code, calls, report = self.run_install(["pair_fixture"], attended=True, missing=("setsid",), DAEMON_EXIT="1", DAEMON_STDERR="\x1b[31mred\x1b[0m error\x07") self.assertEqual(report["step"], "daemon") self.assertIn("red", report["log_tail"]) self.assertNotIn("\x1b", report["log_tail"]) @@ -531,5 +548,143 @@ def test_a_refused_api_key_exchange_is_a_pairing_failure_not_an_environment_one( self.assertNotIn("--- environment", report["log_tail"]) +class RecoveryTests(unittest.TestCase): + """An install that hits a snag should finish, or say how to finish. + + Between 2026-09-26 and 2026-10-08 five Linux installs ended at the + `daemon` step: systemd answered the pre-check, then refused to register + the unit, after the pairing token was spent and the hooks were in. The + same command could not be pasted again (the token was used). Eleven more + ended at the key exchange with "This operation was aborted" (the web gives + the sync server 8 s), and four at the first upload with `Network Err`. + """ + + run_install = MigrationTests.run_install + + STDERR = "Failed to connect to bus: No medium found" + + @staticmethod + def count(calls, *prefix): + return sum(1 for c in calls if c[:len(prefix)] == list(prefix)) + + @staticmethod + def exchanges(calls): + return sum(1 for c in calls if c[0] == "curl" and any(a.endswith("/api/attemptdb/pair") for a in c[1:])) + + @staticmethod + def pair_checks(calls): + return sum(1 for c in calls if c[0] == "curl" and any("/v1/pair/" in a for a in c[1:])) + + # -- the daemon step ----------------------------------------------------------- + + def test_a_systemd_service_that_cannot_register_falls_back_to_session_sync(self): + code, calls, report = self.run_install(["pair_fixture"], attended=True, DAEMON_EXIT="1", DAEMON_STDERR=self.STDERR) + self.assertEqual((code, report["step"], report["ok"]), (0, "done", True), self.last.stdout) + self.assertEqual(self.count(calls, "attempt", "daemon", "install"), 1) + install = calls.index(["attempt", "daemon", "install"]) + # The pairing and the hooks came first (that is why stopping was a dead end) ... + self.assertLess(next(i for i, c in enumerate(calls) if c[:3] == ["attempt", "sync", "connect"]), install) + # ... and after the refusal the session runtime is looked at and the install goes on. + after = calls[install + 1:] + self.assertTrue(any(c[:3] == ["attempt", "daemon", "status"] for c in after)) + self.assertIn(["attempt", "sync", "now"], after) + self.assertIn(["attempt", "hook", "install", "--remove-legacy", "vibemon"], after) + self.assertIn("continuing with Linux session sync", self.last.stdout) + self.assertIn("Linux session sync runs while this environment is alive", self.last.stdout) + + def test_the_refusal_is_reported_on_its_own_with_what_systemd_said(self): + code, calls, report = self.run_install(["pair_fixture"], attended=True, DAEMON_EXIT="1", DAEMON_STDERR=self.STDERR) + failed = [r for r in self.reports if not r["ok"]] + self.assertEqual(len(failed), 1, self.reports) + self.assertEqual(failed[0]["step"], "daemon") + self.assertIn(self.STDERR, failed[0]["log_tail"]) + self.assertIn("--- environment", failed[0]["log_tail"]) + self.assertLess(failed[0]["log_tail"].index(self.STDERR), failed[0]["log_tail"].index("--- environment")) + # The run itself ends well, and says it did so by falling back. + self.assertEqual((report["ok"], report["step"]), (True, "done")) + self.assertIn("continued with Linux session sync", report["error"]) + + def test_the_same_fallback_when_nobody_is_watching(self): + code, calls, report = self.run_install(legacy=True, DAEMON_EXIT="1", DAEMON_STDERR=self.STDERR) + self.assertEqual((code, report["step"], report["unattended"]), (0, "done", True)) + self.assertTrue(any(not r["ok"] and r["step"] == "daemon" and self.STDERR in r["log_tail"] for r in self.reports)) + + def test_without_the_session_tools_it_stops_and_says_how_to_finish_without_a_new_token(self): + code, calls, report = self.run_install(["pair_fixture"], attended=True, missing=("setsid",), DAEMON_EXIT="1", DAEMON_STDERR=self.STDERR) + self.assertEqual((code, report["step"], report["ok"]), (1, "daemon", False)) + self.assertEqual(len(self.reports), 1, "nothing was recovered, so nothing is reported twice") + shown = " ".join(self.last.stdout.split()) + self.assertIn("this machine is paired and its hooks are installed", shown) + self.assertIn("again without a pairing token", shown) + self.assertFalse(any("--remove-legacy" in c for c in calls)) + + def test_macos_has_no_session_runtime_to_fall_back_to(self): + code, calls, report = self.run_install(["pair_fixture"], attended=True, FAKE_OS="Darwin", DAEMON_EXIT="1", DAEMON_STDERR=self.STDERR) + self.assertEqual((code, report["step"], report["ok"]), (1, "daemon", False)) + self.assertIn("again without a pairing token", " ".join(self.last.stdout.split())) + + def test_a_working_service_is_not_replaced_by_the_fallback(self): + code, calls, report = self.run_install(["pair_fixture"]) + self.assertEqual((code, report["step"]), (0, "done")) + self.assertEqual([r for r in self.reports if not r["ok"]], []) + self.assertNotIn("Linux session sync", self.log_text) + + # -- the network steps --------------------------------------------------------- + + def test_the_pairing_check_is_tried_three_times_for_a_server_that_does_not_answer(self): + code, calls, report = self.run_install(["pair_fixture"], attended=True, PAIR_CURL_FAIL="1", PAIR_CHECK_FAILS="2") + self.assertEqual((code, report["step"]), (0, "done"), self.last.stdout) + self.assertEqual(self.pair_checks(calls), 3) + code, calls, report = self.run_install(["pair_fixture"], attended=True, PAIR_CURL_FAIL="1") + self.assertEqual((code, report["step"]), (1, "pair")) + self.assertEqual(self.pair_checks(calls), 3) + self.assertIn("cannot reach", report["error"]) + + def test_a_spent_pairing_token_is_an_answer_and_is_not_asked_again(self): + code, calls, report = self.run_install(["pair_fixture"], PAIR_CHECK_STATUS="410") + self.assertEqual((code, report["step"]), (1, "pair")) + self.assertEqual(self.pair_checks(calls), 1) + self.assertIn("expired or was already used", report["error"]) + + def test_the_key_exchange_is_retried_when_the_web_could_not_reach_the_server(self): + code, calls, report = self.run_install(["vbm_fixturekey0123"], PAIR_API_ERROR="This operation was aborted", PAIR_API_FAILS="2") + self.assertEqual((code, report["step"]), (0, "done")) + self.assertEqual(self.exchanges(calls), 3) + code, calls, report = self.run_install(["vbm_fixturekey0123"], PAIR_API_ERROR="This operation was aborted") + self.assertEqual((code, report["step"]), (1, "pair")) + self.assertEqual(self.exchanges(calls), 3) + self.assertIn("This operation was aborted", report["error"]) + self.assertFalse(any(c[:2] == ["attempt", "init"] for c in calls), "nothing changed") + + def test_a_key_the_web_does_not_know_is_not_asked_again(self): + for answer in ("unknown API key", "api_key must be a vbm_… key", "account deleted"): + with self.subTest(answer=answer): + code, calls, report = self.run_install(["vbm_fixturekey0123"], PAIR_API_ERROR=answer) + self.assertEqual((code, report["step"]), (1, "pair")) + self.assertEqual(self.exchanges(calls), 1) + + def test_a_first_upload_that_fails_once_is_tried_again(self): + code, calls, report = self.run_install(["pair_fixture"], attended=True, UPLOAD_EXIT="1", UPLOAD_FAILS="1") + self.assertEqual((code, report["step"]), (0, "done"), self.last.stdout) + self.assertEqual(self.count(calls, "attempt", "sync", "now"), 2) + self.assertIn(["attempt", "hook", "install", "--remove-legacy", "vibemon"], calls) + + def test_an_upload_that_keeps_failing_ends_after_three_tries_with_legacy_hooks_untouched(self): + code, calls, report = self.run_install(["pair_fixture"], attended=True, UPLOAD_EXIT="1") + self.assertEqual((code, report["step"]), (1, "upload")) + self.assertEqual(self.count(calls, "attempt", "sync", "now"), 3) + self.assertFalse(any("--remove-legacy" in c for c in calls)) + self.assertIn("the first upload did not go through", report["error"]) + + # -- the gate that changes nothing --------------------------------------------- + + def test_running_without_credentials_is_reported_as_a_success_that_changed_nothing(self): + for attended in (True, False): + with self.subTest(attended=attended): + code, calls, report = self.run_install(attended=attended) + self.assertEqual((code, report["step"], report["ok"]), (0, "noop", True)) + self.assertIsNone(report["error"] or None) + + if __name__ == "__main__": unittest.main()