diff --git a/app/Services/Deployment/UpdateChannel.php b/app/Services/Deployment/UpdateChannel.php index 93b1272..dca5d86 100644 --- a/app/Services/Deployment/UpdateChannel.php +++ b/app/Services/Deployment/UpdateChannel.php @@ -109,6 +109,23 @@ final class UpdateChannel /** Written by the agent after every check and every run. */ private const STATUS = 'deploy/update-status.json'; + /** + * Das Lebenszeichen — geschrieben als ERSTES bei jedem Lauf des Agenten. + * + * STATUS allein konnte die Frage „läuft der Agent noch" nicht beantworten. + * Es wird erst am Ende eines Laufs geschrieben; ein Lauf, der vorher + * aussteigt, weil ein anderer Vorgang die Sperre hält, hinterlässt nichts. + * Die Konsole sah dann zwanzig Minuten lang keine neue Zahl und schloss + * daraus, der Dienst sei tot — er lief die ganze Zeit, kam nur nicht an + * die Arbeit. Ein Betreiber hat deswegen zweiundachtzig Minuten lang ein + * Installationsskript gefahren, das an dieser Lage nichts ändert. + * + * Die Datei trennt beides: `at` heißt „der Agent war eben hier", `state` + * sagt, ob er arbeiten konnte. Ältere Agenten schreiben sie nicht — dann + * bleibt es beim alten Verhalten (siehe agentIsAlive()). + */ + private const ALIVE = 'deploy/agent-alive.json'; + /** * The outcome of the last actual run, kept apart from the periodic check. * @@ -177,14 +194,28 @@ final class UpdateChannel $restartLastRun = $this->readJson(self::RESTART_LAST_RUN); $request = $this->pendingRequest(); + $alive = $this->readJson(self::ALIVE); + $checkedAt = $this->timestamp($status['checked_at'] ?? null); - $agentAlive = $this->agentIsAlive($status); + $agentAlive = $this->agentIsAlive($status, $alive); + + // Der Agent läuft, kommt aber nicht an die Sperre. Ein eigener + // Zustand, weil er weder „tot" ist noch „in Ordnung": seine Zahlen + // stammen von vor der Blockade und altern still weiter. + $blockedSince = ($alive['state'] ?? null) === 'blocked' && $agentAlive + ? $this->timestamp($alive['since'] ?? null) + : null; + + // Was der Agent zuletzt gemeldet hat, gilt nur, wenn er auch arbeiten + // konnte. „Drei Updates zurück" von vor einer Stunde liest sich genau + // wie von jetzt. + $agentWorking = $agentAlive && $blockedSince === null; // Missing on a request an older panel wrote — see KIND_RUN. $requestKind = $request['kind'] ?? self::KIND_RUN; // A figure from an agent that has since stopped is not current, and // "three updates behind" from last week reads exactly like now. - $behind = $agentAlive && isset($status['behind']) ? (int) $status['behind'] : null; + $behind = $agentWorking && isset($status['behind']) ? (int) $status['behind'] : null; return [ 'version' => $release->version, @@ -199,13 +230,17 @@ final class UpdateChannel // The tag an update would install, e.g. "v1.1.0". An update is // always to a released version now — a commit landing on main is // not an update, and the console has nothing to say about it. - 'target_release' => $agentAlive && ! empty($status['target_release']) + 'target_release' => $agentWorking && ! empty($status['target_release']) ? (string) $status['target_release'] : null, 'remote_commit' => isset($status['remote_commit']) ? (string) $status['remote_commit'] : null, 'checked_at' => $checkedAt, 'agent_seen' => $agentAlive, + // Seit wann der Agent nur noch überspringt, und wer die Sperre + // hält. Beides null, solange er arbeitet. + 'blocked_since' => $blockedSince, + 'blocked_by' => $blockedSince !== null ? trim((string) ($alive['held_by'] ?? '')) : null, // A pending CHECK or RESTART must never read as "running": nothing // is being deployed, the site never enters maintenance mode, and // the full-screen overlay (layouts/admin.blade.php) exists only @@ -353,10 +388,29 @@ final class UpdateChannel /** * Has the agent checked in recently enough to be considered alive? * + * Das Lebenszeichen zuerst, die Statusdatei nur als Rückfall. Der + * Unterschied ist der ganze Punkt: STATUS bedeutet „zuletzt ERFOLGREICH + * nachgesehen", ALIVE bedeutet „zuletzt überhaupt gelaufen". Ein Agent, + * der jede Minute anspringt und an einer gehaltenen Sperre wieder + * aussteigt, erneuert nur das zweite — und genau der Fall wurde vorher als + * „Dienst läuft nicht" gemeldet, mitsamt der Aufforderung, ein + * Installationsskript zu fahren, das daran nichts ändert. + * + * Fehlt das Lebenszeichen ganz, läuft dort ein Agent von vor dieser + * Änderung: dann gilt wieder die alte Regel, statt ihn für tot zu erklären, + * weil er eine Datei nicht kennt. + * * @param array $status + * @param array $alive */ - private function agentIsAlive(array $status): bool + private function agentIsAlive(array $status, array $alive = []): bool { + $heartbeat = $this->timestamp($alive['at'] ?? null); + + if ($heartbeat !== null) { + return $heartbeat->gt(Carbon::now()->subMinutes(self::AGENT_STALE_AFTER_MINUTES)); + } + $checkedAt = $this->timestamp($status['checked_at'] ?? null); return $checkedAt !== null @@ -368,7 +422,8 @@ final class UpdateChannel { $status = $this->readJson(self::STATUS); - return ($status['state'] ?? null) === 'running' && $this->agentIsAlive($status); + return ($status['state'] ?? null) === 'running' + && $this->agentIsAlive($status, $this->readJson(self::ALIVE)); } /** Is an update run already asked for, and still current? */ diff --git a/deploy/update-agent.sh b/deploy/update-agent.sh index e647e77..f207aa5 100755 --- a/deploy/update-agent.sh +++ b/deploy/update-agent.sh @@ -43,6 +43,21 @@ RESTARTLAST="$STATE_DIR/restart-last-run.json" # initial admin password an instance holds until somebody notes it down. ARCHIVE_KEY="$STATE_DIR/archive-key.json" LOCK="$STATE_DIR/.agent.lock" +# Ein Lebenszeichen, geschrieben als ERSTES bei jedem Lauf — vor dem Abruf der +# Gegenstelle, vor allem, was blockieren kann. +# +# Bis hierher war "wann hat der Agent zuletzt geschrieben" dasselbe wie "wann +# hat er zuletzt ERFOLGREICH nachgesehen": beides stand nur in der Statusdatei, +# und die wird erst nach rund 190 Zeilen geschrieben. Steigt ein Lauf davor aus +# — weil ein anderer die Sperre haelt —, sieht die Konsole zwanzig Minuten lang +# gar nichts und schliesst daraus, der Dienst sei tot. Er lief die ganze Zeit; +# er kam nur nicht an die Arbeit. Ein Betreiber wurde dadurch zweiundachtzig +# Minuten lang zu install-agent.sh geschickt, das an dieser Lage nichts aendert. +# +# Zwei Zustaende, eine Datei: "running" heisst, dieser Lauf hat die Sperre und +# arbeitet; "blocked" heisst, er ist ausgestiegen, weil jemand anderes sie +# haelt — mit `since` (seit wann ununterbrochen) und `held_by` (wer). +ALIVE="$STATE_DIR/agent-alive.json" # The reverse proxy's console allowlist, generated from the one the owner keeps # in the console. Without this the proxy has its own hard-coded list that runs # FIRST, so everything added in the console has no effect at all — and when the @@ -76,10 +91,57 @@ fi mkdir -p "$STATE_DIR" +# Schreibt das Lebenszeichen. Bewusst ohne json_escape (das steht weiter unten, +# und hier oben darf noch nichts von unten gebraucht werden): der einzige freie +# Text ist die Ausgabe von ps, aus der Anfuehrungszeichen, Backslashes und +# Zeilenumbrueche entfernt werden. +write_alive() { + local state="$1" since="${2-}" held_by="${3-}" + held_by="$(printf '%s' "$held_by" | tr -d '"\\' | tr '\n\r\t' ' ')" + + cat > "$ALIVE.tmp" 2>/dev/null </dev/null || true +} + # One agent at a time. Two overlapping runs of update.sh fight over the # checkout, and the loser leaves it half-updated. exec 9>"$LOCK" -flock -n 9 || exit 0 + +if ! flock -n 9; then + # Der uebersprungene Lauf war bis hierher voellig stumm — kein Eintrag im + # Journal (systemd sieht einen sauberen Lauf), keine Zeile in der + # Statusdatei, nichts in der Konsole. Genau diese Stille hat einen Ausfall + # ueber achtzig Minuten unsichtbar gemacht. Jetzt hinterlaesst er, dass er + # uebersprungen hat, seit wann ununterbrochen, und wer die Sperre haelt. + # + # `since` wird aus dem vorigen Lebenszeichen uebernommen, solange die Serie + # laeuft — sonst stuende dort immer "seit einer Minute", und ein Zustand, + # der seit einer Stunde klemmt, laese sich von einem gesunden Ueberholen + # zweier Laeufe nicht unterscheiden. + HOLDER="$( { fuser "$LOCK" 2>/dev/null || true; } | tr -s ' ' | sed 's/^ *//;s/ *$//' )" + HOLDER_CMD='' + if [[ -n "$HOLDER" ]]; then + HOLDER_CMD="$(ps -o pid=,etime=,args= -p $HOLDER 2>/dev/null | head -2 | tr '\n' ' ' || true)" + fi + + PREVIOUS_SINCE="$(sed -n 's/.*"since"[[:space:]]*:[[:space:]]*"\([^"]*\)".*/\1/p' "$ALIVE" 2>/dev/null | head -1 || true)" + PREVIOUS_STATE="$(sed -n 's/.*"state"[[:space:]]*:[[:space:]]*"\([^"]*\)".*/\1/p' "$ALIVE" 2>/dev/null | head -1 || true)" + if [[ "$PREVIOUS_STATE" != "blocked" || -z "$PREVIOUS_SINCE" ]]; then + PREVIOUS_SINCE="$(date -u +%Y-%m-%dT%H:%M:%SZ)" + fi + + write_alive blocked "$PREVIOUS_SINCE" "${HOLDER_CMD:-$HOLDER}" + exit 0 +fi + +write_alive running sync_console_allowlist() { [[ -w "$(dirname "$ALLOWFILE")" || -w "$ALLOWFILE" ]] || return 0 @@ -89,7 +151,11 @@ sync_console_allowlist() { # artisan command that logs anything as root leaves storage/logs owned by # root, after which the application cannot append to its own log — and every # page that logs answers 500 with nothing written to say why. - generated="$(docker compose exec -T -u www-data app php artisan clupilot:console-access caddy 2>/dev/null)" || return 0 + # `timeout`, weil dieser Aufruf die Sperre haelt: haengt der Behaelter — + # gerade neu gestartet, ueberlastet, halb tot —, haengt der Agent mit, und + # jeder folgende Takt steigt still aus. Lieber diese Runde ohne Allowlist + # als eine Konsole, die minutenlang nichts mehr von sich hoert. + generated="$(timeout 45 docker compose exec -T -u www-data app php artisan clupilot:console-access caddy 2>/dev/null)" || return 0 # Never write an empty matcher: in Caddy that matches nothing, and the # console would be unreachable from everywhere including the shell. grep -q '@allowed remote_ip .' <<<"$generated" || return 0 @@ -237,7 +303,12 @@ FETCH_ERROR='' DEPLOYED_VERSION="$(release_manifest_version)" [[ -n "$DEPLOYED_VERSION" ]] || DEPLOYED_VERSION="$(release_version)" -if git fetch --quiet --tags --force origin 2>/dev/null; then +# `timeout`, aus demselben Grund wie beim Aufruf in sync_console_allowlist: ein +# Abruf gegen eine tote Verbindung wartet, bis das Betriebssystem ihn nach +# vielen Minuten aufgibt — und haelt dabei die Sperre. Zwei Minuten sind +# grosszuegig fuer einen fetch gegen EINE Gegenstelle; laenger ist kein +# langsames Netz mehr, sondern eines, das nicht antwortet. +if timeout 120 git fetch --quiet --tags --force origin 2>/dev/null; then # Newest by version order, not by tag date. Through the helper rather than # `| head -1`: head exits after one line, git takes SIGPIPE, and pipefail # ends the agent — see release_newest_tag. diff --git a/lang/de/admin_settings.php b/lang/de/admin_settings.php index 4aa5bbd..07587e7 100644 --- a/lang/de/admin_settings.php +++ b/lang/de/admin_settings.php @@ -115,6 +115,7 @@ return [ 'update_check_requested' => 'Prüfung angefordert.', 'update_already_requested' => 'Es ist schon etwas angefordert — bitte kurz warten.', 'update_no_agent' => 'Der Update-Dienst auf dem Server läuft nicht. Einmalig auf dem Server einrichten: sudo bash /opt/clupilot/deploy/install-agent.sh', + 'update_agent_blocked' => 'Der Update-Dienst läuft, kommt aber seit :since nicht an die Arbeit — ein anderer Vorgang hält die Sperre. Solange das so ist, stammen die Angaben oben von vorher. Löst es sich nicht von selbst, hilft ein Blick auf den Prozess unten.', 'update_log' => 'Protokoll des letzten Laufs', 'update_error' => [ diff --git a/lang/en/admin_settings.php b/lang/en/admin_settings.php index ed8f930..2a77d7d 100644 --- a/lang/en/admin_settings.php +++ b/lang/en/admin_settings.php @@ -115,6 +115,7 @@ return [ 'update_check_requested' => 'Check requested.', 'update_already_requested' => 'Something has already been requested — please wait a moment.', 'update_no_agent' => 'The server-side update service is not running. Set it up once on the server: sudo bash /opt/clupilot/deploy/install-agent.sh', + 'update_agent_blocked' => 'The update service is running but has been unable to work since :since — another process holds the lock. While that lasts, the figures above are from before. If it does not clear on its own, look at the process named below.', 'update_log' => 'Log of the last run', 'update_error' => [ diff --git a/resources/views/livewire/admin/settings.blade.php b/resources/views/livewire/admin/settings.blade.php index 23b5d85..8df61f1 100644 --- a/resources/views/livewire/admin/settings.blade.php +++ b/resources/views/livewire/admin/settings.blade.php @@ -168,6 +168,19 @@ @if (! $update['agent_seen']) {{ __('admin_settings.update_no_agent') }} + @elseif ($update['blocked_since']) + {{-- Der Dienst LÄUFT, kommt aber nicht an die Arbeit. + Vorher stand hier die Meldung darüber — „läuft + nicht", samt der Aufforderung, install-agent.sh zu + fahren, das an einer gehaltenen Sperre nichts + ändert. Ein Betreiber hat dem zweiundachtzig + Minuten lang geglaubt. --}} + + {{ __('admin_settings.update_agent_blocked', ['since' => $update['blocked_since']->local()->isoFormat('HH:mm')]) }} + @if ($update['blocked_by']) + {{ $update['blocked_by'] }} + @endif + @elseif ($update['last_error']) {{ $update['last_error'] }} @elseif (! $update['available'] && ! $update['running'] && ! $update['checking']) diff --git a/tests/Feature/Admin/UpdateButtonTest.php b/tests/Feature/Admin/UpdateButtonTest.php index e1a5ff0..cb08c65 100644 --- a/tests/Feature/Admin/UpdateButtonTest.php +++ b/tests/Feature/Admin/UpdateButtonTest.php @@ -5,6 +5,7 @@ use App\Models\User; use App\Services\Deployment\UpdateChannel; use Illuminate\Support\Carbon; use Illuminate\Support\Facades\File; +use Illuminate\Support\Str; use Livewire\Livewire; /** @@ -778,11 +779,11 @@ it('shows one design while updating, not two swapping mid-run', function () { // // Both render the same partial now, so there is nothing left that can // disagree. - $console = Illuminate\Support\Facades\File::get(resource_path('views/layouts/admin.blade.php')); - $maintenance = Illuminate\Support\Facades\File::get(resource_path('views/errors/503.blade.php')); + $console = File::get(resource_path('views/layouts/admin.blade.php')); + $maintenance = File::get(resource_path('views/errors/503.blade.php')); - expect($console)->toContain("partials.updating-panel") - ->and($maintenance)->toContain("partials.updating-panel") + expect($console)->toContain('partials.updating-panel') + ->and($maintenance)->toContain('partials.updating-panel') // And nothing left behind that would render a second look. ->and($console)->not->toContain('update_overlay_title') ->and($maintenance)->not->toContain('