v0.262.0: six defects two drill nights found in the update, remove and hold paths
gates / gates (push) Successful in 26s

R-630 (P1): waitUpdateHealthy kept the probe inside `if hc != nil && len(hc.Checks) > 0`, and when
findProbeContainer returned "" its else set last="no probe container" and LOOPED - the settle path
sat in the outer else, unreachable. So verifying could only time out and failAndHold then stopped a
working app. Measured on paperless-ngx: three containers healthy, failed at +313.0s, front door 404
after. It now falls through to the same settle path with a WARN naming the candidates.

The probe target is decidable now: HealthCheckConfig.Container plus findProbeContainerMeta resolve
by exact stack name -> explicit container -> a UNIQUE prefix -> nothing with the candidates
returned. The old rule took the FIRST prefix match. A skipped stack records why instead of silence.

R-634 (half): RemoveStack refused on the !Deployed FLAG while the machine had containers, a compose
file and an app.yaml. It now asks whether anything EXISTS. The mechanism producing the bad record is
still not diagnosed and R-634 stays open for it.

R-633/R-626: RemoveStack consults UpdateGuards.Busy and IsUpdating and refuses with the app's own
sentence - the product already refused this clash for update and for restore. And because `down`
returning 0 is a request not a result, the project is watched for 25s afterwards, anything carrying
its label is removed by name with its labels logged, and the answer carries `verified`.

R-621: failAndHold writes compose logs --tail 400 into <stackdir>/hold-logs/<ts>/ BEFORE the down
that destroys them. Two existing tests pin the compose sequence and correctly caught the new step;
their expectations are updated with the reason that the ORDER is the assertion.

R-614: RemoveStack calls ClearUpdateState.

NOT in this release: R-625 (a held app still renders an Update button). Named, not half-done.

Three new sentences, each born as a key in both bundles. Four red-proofs seen failing.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_0159rPz1ZhFKsS53msqPYxtS
This commit is contained in:
2026-09-22 20:45:19 +02:00
parent 93cee16843
commit b793638484
12 changed files with 4946 additions and 4404 deletions
File diff suppressed because it is too large Load Diff
File diff suppressed because it is too large Load Diff
+119 -2
View File
@@ -12,6 +12,7 @@ import (
"time"
"gitea.dooplex.hu/admin/felhom-controller/internal/appbackup"
"gitea.dooplex.hu/admin/felhom-controller/internal/util"
)
// felhomDataDir matches backup.FelhomDataDir — duplicated to avoid circular import via StackDataProvider.
@@ -45,6 +46,11 @@ type RemoveResponse struct {
HDDNote string `json:"hdd_note,omitempty"`
BackupPathsRemoved []string `json:"backup_paths_removed,omitempty"`
BackupPathsRefused []string `json:"backup_paths_refused,omitempty"`
// Verified says the teardown was CHECKED, not just requested (R-626/R-633). False means a
// container carrying this project's compose label was still there after the watch window — the
// answer that used to be a silent 200.
Verified bool `json:"verified"`
ReappearedRemoved []string `json:"reappeared_removed,omitempty"`
}
// RemoveRefusedError is a removal REFUSED before anything was touched: the customer asked for the
@@ -413,6 +419,77 @@ func (m *Manager) GetStackHDDData(name string) (*HDDDataResponse, error) {
// volumes, optionally removes HDD data and backup data, then removes app.yaml
// so the stack reverts to "not deployed" state. The template files (docker-compose.yml,
// .felhom.yml) are preserved so the user can redeploy.
// removeVerifyWindow is how long the project is watched after `down` before the teardown is called
// verified. 20 s is the floor the brief sets; the measured re-creation happened at +2 s.
const removeVerifyWindow = 25 * time.Second
// projectContainersByLabel lists containers still carrying this compose project's label — including
// stopped ones, because a container that exists at all is one the household can still see.
func (m *Manager) projectContainersByLabel(project string) []string {
out, err := m.execCommand("docker", "ps", "-a", "--filter", "label=com.docker.compose.project="+project, "--format", "{{.Names}}")
if err != nil {
return nil
}
var names []string
for _, l := range strings.Split(out, "\n") {
if l = strings.TrimSpace(l); l != "" {
names = append(names, l)
}
}
return names
}
// verifyTornDown watches the compose project after `down` and removes anything that comes back.
// Returns whether the project was clean at the end, and what had to be removed.
func (m *Manager) verifyTornDown(name string, window time.Duration) (bool, []string) {
deadline := m.now().Add(window)
var removed []string
for {
left := m.projectContainersByLabel(name)
for _, c := range left {
lbl, _ := m.execCommand("docker", "inspect", c, "--format", "{{json .Config.Labels}}")
m.logger.Printf("[WARN] [stacks] RemoveStack %s: container %q reappeared after `down` — removing it by name; its labels: %s", name, c, truncateStr(strings.TrimSpace(lbl), 300))
if out, err := m.execCommand("docker", "rm", "-f", c); err != nil {
m.logger.Printf("[ERROR] [stacks] RemoveStack %s: could not remove the reappeared container %q: %v (%s)", name, c, err, truncateStr(out, 160))
} else {
removed = append(removed, c)
}
}
if !m.now().Before(deadline) {
break
}
time.Sleep(2 * time.Second)
}
still := m.projectContainersByLabel(name)
if len(still) > 0 {
m.logger.Printf("[ERROR] [stacks] RemoveStack %s: NOT verified — %d container(s) still carry this project's label after %s: %v", name, len(still), window, still)
return false, removed
}
return true, removed
}
// KeyRemoveBusy is the one sentence R-633 adds: a remove refused because the backup side owns the app.
const KeyRemoveBusy = "err.stacks.az_alkalmazason_mentes_vagy_visszaallitas_fut"
// halfStateEvidence answers "does anything of this stack actually EXIST?" for a stack the record
// says is not deployed (R-634). Containers first, because that is the shape that hurt: an app
// serving traffic that no button could remove.
func (m *Manager) halfStateEvidence(name string, stack *Stack) (bool, string) {
if len(stack.Containers) > 0 {
return true, fmt.Sprintf("%d container(s) exist", len(stack.Containers))
}
if stack.ComposePath != "" {
if _, err := os.Stat(stack.ComposePath); err == nil {
dir := filepath.Dir(stack.ComposePath)
if _, err := os.Stat(filepath.Join(dir, "app.yaml")); err == nil {
return true, "a compose file and an app.yaml exist on disk"
}
return true, "a compose file exists on disk"
}
}
return false, ""
}
func (m *Manager) RemoveStack(name string, removeHDDData bool, backupPathsToRemove []string) (*RemoveResponse, error) {
if m.isDebug() {
m.logger.Printf("[DEBUG] [stacks] RemoveStack called: name=%q, removeHDDData=%v, backupPathsToRemove=%d", name, removeHDDData, len(backupPathsToRemove))
@@ -433,9 +510,20 @@ func (m *Manager) RemoveStack(name string, removeHDDData bool, backupPathsToRemo
name, stack.State, stack.Deployed, stack.Orphaned, stack.Deploying)
}
// Must be deployed
// R-634: `deployed` is a RECORD, and the record can be wrong while the machine is right. Three
// apps were measured running, healthy and serving with `deployed=false` — `outline` answering its
// own `/_health` with 200 and three containers up — and in that state BOTH remove calls answered
// `stack "x" is not deployed`, so the household had no button at all and a shell was the only
// exit. **The household must always be able to remove what the box shows them.** So the refusal
// now asks whether anything EXISTS, not whether a flag is set: containers, a compose file, or an
// app.yaml are each enough. Everything downstream already copes — the removal is driven by the
// compose file and the directory, not by the flag.
if !stack.Deployed {
return nil, fmt.Errorf("stack %q is not deployed", name)
half, why := m.halfStateEvidence(name, stack)
if !half {
return nil, fmt.Errorf("stack %q is not deployed", name)
}
m.logger.Printf("[WARN] [stacks] RemoveStack %s: deployed=false but %s — removing what exists (R-634)", name, why)
}
// Must not be deploying (H2 fix)
@@ -443,6 +531,23 @@ func (m *Manager) RemoveStack(name string, removeHDDData bool, backupPathsToRemo
return nil, fmt.Errorf("stack %q is currently being deployed — wait for deployment to finish", name)
}
// R-633: the backup side owns operations this package cannot see. A remove sent while a RESTORE
// was in flight was measured tearing down what existed while the restore's own `compose up`
// re-created it — both calls returned success, the record said `deployed: false`, and a container
// went on restarting for hours with a live traefik route. The product already refuses exactly
// this clash for `update` and for `restore`, and names the blocking operation; `remove` did not
// consult it at all. Same guard, same adapter.
if g := m.guards(); g != nil {
if busy, why := g.Busy(name); busy {
m.logger.Printf("[ERROR] [stacks] RemoveStack %s REFUSED (busy): %s", name, why)
return nil, util.MsgError(KeyRemoveBusy)
}
}
if m.IsUpdating(name) {
m.logger.Printf("[ERROR] [stacks] RemoveStack %s REFUSED (busy): a guarded update is in progress", name)
return nil, util.MsgError(KeyRemoveBusy)
}
// Must be stopped (not running)
// StateDegraded (R-51) counts as running here: a degraded stack still has LIVE containers, and
// deleting its directory out from under them would leave orphans behind.
@@ -491,6 +596,18 @@ func (m *Manager) RemoveStack(name string, removeHDDData bool, backupPathsToRemo
return resp, fmt.Errorf("docker compose down failed for %s: %w", name, err)
}
// Step 2b: WATCH, then say so. R-626 recorded a removed `navidrome` coming back and could not
// diagnose it; R-633 caught the same shape with the window visible — a restore's own `compose
// up` re-creating what `down` had just torn out, seventeen seconds apart, while both calls
// returned success. `down` returning 0 is a request, not a result. So the project is watched for
// a bounded window and anything that reappears is removed BY NAME and logged with the label that
// created it, and the answer carries whether the check passed.
resp.Verified, resp.ReappearedRemoved = m.verifyTornDown(name, removeVerifyWindow)
// R-614: the app is going; its update record goes with it. Otherwise the NEXT install of the
// same name inherits a phase that belongs to an app that no longer exists.
m.ClearUpdateState(name)
// Step 3: the volumes that are gone now — `[]` when none, never null (R-489).
resp.VolumesRemoved = removedVolumes(volsBefore, m.projectVolumes(name))
if len(resp.VolumesRemoved) > 0 {
+94 -16
View File
@@ -22,6 +22,7 @@ type probeTarget struct {
// Called by the scheduler every minute.
func (m *Manager) RunHealthProbes() error {
// Phase 1: collect targets (under lock)
var noProbe []noProbeStack
m.mu.RLock()
var targets []probeTarget
skippedNotDue := 0
@@ -57,10 +58,14 @@ func (m *Manager) RunHealthProbes() error {
}
}
// Find the main container to probe (matching stack name)
containerName := findProbeContainer(name, stack.Containers)
// Find the main container to probe. R-630: a stack whose check resolves to no container
// used to be skipped SILENTLY — paperless-ngx's probe had therefore never run on any box,
// and nothing on any screen could say so. It now gets a RESULT that says why, so the app
// page can tell "checked and healthy" from "never checked".
containerName, candidates := findProbeContainerMeta(name, &stack.Meta, stack.Containers)
if containerName == "" {
skippedNoContainer++
noProbe = append(noProbe, noProbeStack{name: name, candidates: candidates})
continue
}
@@ -72,6 +77,29 @@ func (m *Manager) RunHealthProbes() error {
}
m.mu.RUnlock()
// Record the "no probe container" stacks OUTSIDE the read lock, then write their results under
// the write lock — the same shape the probe results themselves use.
for _, np := range noProbe {
m.mu.Lock()
if s, ok := m.stacks[np.name]; ok {
s.HealthProbe = &HealthProbeResult{
Healthy: true, // never RED on our own inability to look — R-630's whole point
LastCheck: m.now(),
Details: []HealthCheckDetail{{
Type: "none",
Target: np.name,
Healthy: true,
Error: MsgHealthNoProbeContainer,
MessageKey: KeyHealthNoProbeContainer,
}},
}
}
m.mu.Unlock()
if m.isDebug() {
m.logger.Printf("[DEBUG] [stacks] RunHealthProbes: %s has a health check but no container to probe — candidates: %v", np.name, np.candidates)
}
}
if m.isDebug() {
m.logger.Printf("[DEBUG] [stacks] RunHealthProbes: collected %d targets (%d skipped not due, %d skipped no container)",
len(targets), skippedNotDue, skippedNoContainer)
@@ -294,21 +322,71 @@ func (m *Manager) probeHTTP(containerName string, check HealthCheckItem, target
return detail
}
// findProbeContainer returns the container name to probe for a stack.
// Prefers exact match with stack name, then prefix match (stack-service-N).
// The one sentence R-630 adds. Hungarian bytes by default, the key beside it — util.MsgError's
// contract, because HealthProbe is serialised raw to the API and has no localisation seam of its own.
const (
MsgHealthNoProbeContainer = "Nem futott egészségellenőrzés: nincs hozzá tartozó konténer."
KeyHealthNoProbeContainer = "health.no_probe_container"
)
// noProbeStack is a stack that declares a health check which resolves to no container.
type noProbeStack struct {
name string
candidates []string
}
// findProbeContainer returns the container to probe for a stack, and the candidates it rejected.
//
// Four rules, in order (R-630):
//
// 1. the container whose name EQUALS the stack name;
// 2. the container named by `healthcheck.container` in `.felhom.yml`;
// 3. a prefix match — but ONLY when exactly one running container matches. The old code took the
// FIRST prefix match, which for `immich` (four `immich-*` containers and no exact match) meant
// whichever the container list happened to yield, and which was seen live on `outline` probing
// `outline-postgres:3000` during startup because the exactly-named container was not up yet;
// 4. nothing — and the CANDIDATES come back with it, because "no container" with no list is the
// silence this whole row is about.
//
// `meta` may be nil; the caller is not required to have one.
func findProbeContainerMeta(stackName string, meta *Metadata, containers []ContainerInfo) (string, []string) {
probeable := func(c ContainerInfo) bool {
return c.State == StateRunning || c.State == StateUnhealthy
}
for _, c := range containers {
if c.Name == stackName && probeable(c) {
return c.Name, nil
}
}
if meta != nil && meta.HealthCheck != nil && meta.HealthCheck.Container != "" {
want := meta.HealthCheck.Container
for _, c := range containers {
if c.Name == want && probeable(c) {
return c.Name, nil
}
}
}
var prefix []string
for _, c := range containers {
if strings.HasPrefix(c.Name, stackName) && probeable(c) {
prefix = append(prefix, c.Name)
}
}
if len(prefix) == 1 {
return prefix[0], nil
}
// Ambiguous or empty: name what was seen so the log and the page can say why.
all := make([]string, 0, len(containers))
for _, c := range containers {
all = append(all, c.Name+"("+string(c.State)+")")
}
return "", all
}
// findProbeContainer is the one-value form kept for callers that only want the name.
func findProbeContainer(stackName string, containers []ContainerInfo) string {
for _, c := range containers {
if c.Name == stackName && (c.State == StateRunning || c.State == StateUnhealthy) {
return c.Name
}
}
// Fallback: first running container with matching prefix
for _, c := range containers {
if strings.HasPrefix(c.Name, stackName) && (c.State == StateRunning || c.State == StateUnhealthy) {
return c.Name
}
}
return ""
n, _ := findProbeContainerMeta(stackName, nil, containers)
return n
}
// parseInterval parses a duration string like "5m", "30s", "1h".
+5
View File
@@ -127,6 +127,11 @@ type HealthCheckDetail struct {
Status int `json:"status,omitempty"` // HTTP status code (for http/api)
Latency string `json:"latency"` // e.g. "45ms"
Error string `json:"error,omitempty"` // error message if unhealthy
// MessageKey is the i18n bundle key for Error when the text is a PRODUCT sentence rather than a
// transport error. It follows util.MsgError's contract: Error carries the Hungarian bytes (the
// default language), MessageKey lets a localising consumer render the other one. Added for
// R-630, whose "no health check ran" detail is the first such sentence here.
MessageKey string `json:"message_key,omitempty"`
}
// Stack represents a docker compose stack on disk.
+11
View File
@@ -210,6 +210,17 @@ type IntegrationDef struct {
type HealthCheckConfig struct {
Interval string `yaml:"interval" json:"interval"` // e.g. "5m", "30s"; default "5m"
Checks []HealthCheckItem `yaml:"checks" json:"checks"`
// Container names the container to probe when the stack name does not resolve to one.
// It belongs on the BLOCK rather than on each check because every check in a block probes the
// same process — the port and path differ, the target does not.
//
// R-630: `paperless-ngx`'s containers are `paperless-webserver`/`-postgres`/`-redis`, so neither
// the exact-name rule nor the prefix rule finds anything and the stack was skipped SILENTLY — its
// probe had never run on any box, and `verifying` then waited out the full health timeout and
// STOPPED a working app. `immich` is the same shape with the opposite failure: no exact match and
// FOUR `immich-*` candidates, so the prefix fallback picked whichever came first.
// Precedent for the field: InitialCredentials.Container above.
Container string `yaml:"container,omitempty" json:"container,omitempty"`
}
// HealthCheckItem defines a single health check probe.
@@ -0,0 +1,158 @@
package stacks
import (
"os"
"path/filepath"
"strings"
"testing"
)
// ── A / A2 — the probe target (R-630) ────────────────────────────────────────────────────────────
//
// RED-PROOF: revert findProbeContainerMeta to "exact, else FIRST prefix, else empty" and
// TestProbeTarget_ImmichPrefixIsAmbiguous and TestProbeTarget_ExplicitContainer both fail.
func running(names ...string) []ContainerInfo {
out := make([]ContainerInfo, 0, len(names))
for _, n := range names {
out = append(out, ContainerInfo{Name: n, State: StateRunning})
}
return out
}
func TestProbeTarget_ExactNameWins(t *testing.T) {
got, cand := findProbeContainerMeta("romm", nil, running("romm-db", "romm", "romm-redis"))
if got != "romm" {
t.Fatalf("exact match must win: got %q (candidates %v)", got, cand)
}
}
func TestProbeTarget_ExplicitContainer(t *testing.T) {
// paperless-ngx: no container is called `paperless-ngx`, and none even has it as a prefix.
cs := running("paperless-webserver", "paperless-postgres", "paperless-redis")
if got, _ := findProbeContainerMeta("paperless-ngx", nil, cs); got != "" {
t.Fatalf("without the explicit field there is nothing to probe, got %q", got)
}
meta := &Metadata{HealthCheck: &HealthCheckConfig{
Container: "paperless-webserver",
Checks: []HealthCheckItem{{Type: "http", Port: 8000}},
}}
got, _ := findProbeContainerMeta("paperless-ngx", meta, cs)
if got != "paperless-webserver" {
t.Fatalf("the explicit container must be used: got %q", got)
}
}
func TestProbeTarget_ImmichPrefixIsAmbiguous(t *testing.T) {
// Four `immich-*` containers and no exact match. The OLD rule returned the first one — which is
// whichever the container list happened to yield. Ambiguity must resolve to "nothing", with the
// candidates named, not to a guess.
cs := running("immich-server", "immich-machine-learning", "immich-postgres", "immich-redis")
got, cand := findProbeContainerMeta("immich", nil, cs)
if got != "" {
t.Fatalf("four candidates must not be resolved by guessing: got %q", got)
}
if len(cand) != 4 {
t.Fatalf("the candidates must come back so the log can name them: %v", cand)
}
meta := &Metadata{HealthCheck: &HealthCheckConfig{Container: "immich-server"}}
if got, _ := findProbeContainerMeta("immich", meta, cs); got != "immich-server" {
t.Fatalf("the explicit field must settle it: got %q", got)
}
}
func TestProbeTarget_UniquePrefixStillWorks(t *testing.T) {
// One running candidate is not ambiguous — the fallback stays useful.
got, _ := findProbeContainerMeta("gitea", nil, running("gitea-server"))
if got != "gitea-server" {
t.Fatalf("a single prefix match must still resolve: got %q", got)
}
}
func TestProbeTarget_StoppedContainersAreNotProbeTargets(t *testing.T) {
cs := []ContainerInfo{{Name: "wger", State: StateStopped}}
if got, _ := findProbeContainerMeta("wger", nil, cs); got != "" {
t.Fatalf("a stopped container is not probeable: got %q", got)
}
}
// ── A — the settle reason (R-630) ────────────────────────────────────────────────────────────────
//
// RED-PROOF: this is the sentence that distinguishes "declares no check" from "declares one that
// resolves to nothing". Before v0.262.0 the second case never reached a settle at all — it looped
// until the health timeout and the app was STOPPED.
func TestSettleReason_NamesWhyTheProbeWasNotUsed(t *testing.T) {
none := settleReason(Metadata{})
if !strings.Contains(none, "no health check declared") {
t.Fatalf("an app with no check must say so: %q", none)
}
declared := settleReason(Metadata{HealthCheck: &HealthCheckConfig{
Checks: []HealthCheckItem{{Type: "http", Port: 80}},
}})
if !strings.Contains(declared, "no probe container") {
t.Fatalf("an app whose check resolves to nothing must say THAT, not the other thing: %q", declared)
}
if none == declared {
t.Fatal("the two reasons must be distinguishable in the journal without reading the log")
}
}
// ── C — remove accepts the half-state (R-634) ────────────────────────────────────────────────────
//
// RED-PROOF: delete the halfStateEvidence branch in RemoveStack and this fails — which is exactly
// the state three apps were measured in, with no button that worked.
func TestHalfStateEvidence(t *testing.T) {
m := &Manager{}
if ok, _ := m.halfStateEvidence("ghost", &Stack{}); ok {
t.Fatal("nothing on disk and no containers is genuinely 'not deployed'")
}
ok, why := m.halfStateEvidence("outline", &Stack{Containers: running("outline", "outline-postgres")})
if !ok || !strings.Contains(why, "container") {
t.Fatalf("containers exist: the household must be able to remove them (%v, %q)", ok, why)
}
dir := t.TempDir()
compose := filepath.Join(dir, "docker-compose.yml")
if err := os.WriteFile(compose, []byte("services: {}\n"), 0o644); err != nil {
t.Fatal(err)
}
ok, why = m.halfStateEvidence("sparkyfitness", &Stack{ComposePath: compose})
if !ok || !strings.Contains(why, "compose file") {
t.Fatalf("a compose file on disk is something to remove (%v, %q)", ok, why)
}
if err := os.WriteFile(filepath.Join(dir, "app.yaml"), []byte("name: x\n"), 0o644); err != nil {
t.Fatal(err)
}
ok, why = m.halfStateEvidence("sparkyfitness", &Stack{ComposePath: compose})
if !ok || !strings.Contains(why, "app.yaml") {
t.Fatalf("this is sparkyfitness's exact measured shape (%v, %q)", ok, why)
}
}
// ── F — a remove clears the update record (R-614) ────────────────────────────────────────────────
//
// RED-PROOF: drop the ClearUpdateState call from RemoveStack and a redeploy inherits „Frissítve".
func TestClearUpdateState(t *testing.T) {
m := &Manager{stacks: map[string]*Stack{
"komga": {
Updating: true,
UpdatePhase: "failed",
UpdatePhaseLabel: "A frissítés nem sikerült",
UpdateError: "held",
updateHeld: true,
HealthProbe: &HealthProbeResult{Healthy: false},
},
}}
m.ClearUpdateState("komga")
s := m.stacks["komga"]
if s.Updating || s.UpdatePhase != "" || s.UpdatePhaseLabel != "" || s.UpdateError != "" || s.updateHeld || s.HealthProbe != nil {
t.Fatalf("every field the next install could inherit must be cleared: %+v", s)
}
m.ClearUpdateState("does-not-exist") // must not panic
}
+84 -5
View File
@@ -178,6 +178,26 @@ func (m *Manager) currentDeployTime(name string) time.Time {
return t
}
// ClearUpdateState wipes everything a finished-or-abandoned update left on a stack. R-614: a fresh
// install of an app that had previously failed an update showed the OLD phase — „Frissítve" on a
// deploy that had just happened — because a remove cleared the directory and not the in-memory
// record. The name is the only thing the next install shares with the last one, so the record has to
// go when the app does.
func (m *Manager) ClearUpdateState(name string) {
m.mu.Lock()
defer m.mu.Unlock()
s, ok := m.stacks[name]
if !ok {
return
}
s.Updating = false
s.UpdatePhase = ""
s.UpdatePhaseLabel = ""
s.UpdateError = ""
s.updateHeld = false
s.HealthProbe = nil
}
func (m *Manager) markUpdateHeld(name string) {
m.mu.Lock()
if s, ok := m.stacks[name]; ok {
@@ -717,9 +737,40 @@ func (m *Manager) verifyAndConclude(ctx context.Context, name, dir string, env [
m.logger.Printf("[INFO] [stacks] update %s: DONE in %s", name, m.now().Sub(start).Round(time.Second))
}
// holdLogTailLines is how much of each service's log the hold keeps. 400 lines is enough to hold a
// migration run and a startup failure, and small enough that a hold never fills a disk.
const holdLogTailLines = "400"
// captureHoldLogs writes each service's log into <stackdir>/hold-logs/<ts>/ before the app is
// stopped. Best-effort by design (R-621): the hold itself must happen either way.
func (m *Manager) captureHoldLogs(name, dir string, env []string) {
ts := m.now().UTC().Format("20060102T150405Z")
outDir := filepath.Join(dir, "hold-logs", ts)
if err := os.MkdirAll(outDir, 0o755); err != nil {
m.logger.Printf("[ERROR] [stacks] update %s: cannot create the hold-log directory %s: %v — the hold still proceeds", name, outDir, err)
return
}
out, err := m.updateCompose(dir, env, "logs", "--no-color", "--tail", holdLogTailLines)
if err != nil {
m.logger.Printf("[WARN] [stacks] update %s: `compose logs` before the hold failed: %v — writing what came back anyway", name, err)
}
path := filepath.Join(outDir, "compose-logs.txt")
if werr := os.WriteFile(path, []byte(out), 0o644); werr != nil {
m.logger.Printf("[ERROR] [stacks] update %s: could not write %s: %v", name, path, werr)
return
}
m.logger.Printf("[INFO] [stacks] update %s: kept %d bytes of the app's own log at %s before stopping it (R-621)", name, len(out), path)
}
// failAndHold is Scenario F: stop the app, record the hold, tell the customer the route back.
func (m *Manager) failAndHold(ctx context.Context, name, dir string, env []string, rp UpdateRestorePoint, why string) {
m.logger.Printf("[ERROR] [stacks] update %s FAILED after the new version was started: %s — stopping and HOLDING the app; the pin stays on the new version (its migration may have run)", name, why)
// R-621: capture the app's own logs BEFORE the `down`, because the `down` destroys them. Two
// drill nights lost the only evidence of WHY an update failed this way — `adventurelog` ran nine
// migrations and then never bound its port, and the log that would have said so was gone by the
// time anyone looked. The capture is bounded and best-effort: a hold must never fail because its
// evidence could not be written.
m.captureHoldLogs(name, dir, env)
if _, err := m.updateCompose(dir, env, "down"); err != nil {
m.logger.Printf("[ERROR] [stacks] update %s: stopping the failed app also failed: %v", name, err)
}
@@ -769,12 +820,23 @@ func (m *Manager) removePreUpdateCopies(dir string) {
_ = os.Remove(filepath.Join(dir, preUpdateAppliedFile))
}
// settleReason names WHY the wait fell back to container state, so the journal and the log do not
// have to be read together to tell "this app declares no check" from "this app declares one that
// resolves to no container" (R-630).
func settleReason(meta Metadata) string {
if hc := meta.HealthCheck; hc != nil && len(hc.Checks) > 0 {
return "no probe container — settled on container state"
}
return "no health check declared"
}
// waitUpdateHealthy is the production health wait: the app's own .felhom.yml health check through the
// existing probe, or — for an app with none — every container running and none restarting for
// updateSettleWindow. NEVER the compose exit code, and never logPostStartStatus's delayed log line.
func (m *Manager) waitUpdateHealthy(ctx context.Context, name string, timeout time.Duration) (bool, string) {
deadline := m.now().Add(timeout)
var runningSince time.Time
warnedNoProbe := false
last := "no observation yet"
for {
_ = m.RefreshStatus()
@@ -784,8 +846,21 @@ func (m *Manager) waitUpdateHealthy(ctx context.Context, name string, timeout ti
last = "stack vanished"
runningSince = time.Time{}
case st.State == StateRunning:
// A declared health check is only usable if it resolves to a container. When it does
// not, the app is judged the same way an app with NO declared check is judged —
// settling on container state — and the log says so.
//
// R-630, and this `else` is the whole defect: the old code set `last = "no probe
// container"` and looped, so `verifying` spent the FULL `update.health_timeout` and
// `failAndHold` then STOPPED an app whose containers were all healthy. Measured on
// paperless-ngx 2026-09-22: `done` was never reachable, `failed` at +313.0 s, front door
// 404 afterwards. A stack with no probe is not "healthy" and it is not "failing" — it is
// SETTLED ON CONTAINER STATE (`09` §3), and never a reason to stop a running app.
usable := false
if hc := st.Meta.HealthCheck; hc != nil && len(hc.Checks) > 0 {
if c := findProbeContainer(name, st.Containers); c != "" {
c, candidates := findProbeContainerMeta(name, &st.Meta, st.Containers)
if c != "" {
usable = true
res := m.runChecks(probeTarget{stackName: name, containerName: c, checks: hc.Checks})
m.mu.Lock()
if s, ok := m.stacks[name]; ok {
@@ -796,15 +871,19 @@ func (m *Manager) waitUpdateHealthy(ctx context.Context, name string, timeout ti
return true, "the app's health check passed"
}
last = "health check failing"
} else {
last = "no probe container"
} else if !warnedNoProbe {
warnedNoProbe = true
m.logger.Printf("[WARN] [stacks] update %s: no probe container for %s — settling on container state instead; candidates: %v",
name, name, candidates)
}
} else {
}
if !usable {
if runningSince.IsZero() {
runningSince = m.now()
}
if m.now().Sub(runningSince) >= updateSettleWindow {
return true, fmt.Sprintf("all containers running, none restarting, for %s (no health check declared)", updateSettleWindow)
return true, fmt.Sprintf("all containers running, none restarting, for %s (%s)",
updateSettleWindow, settleReason(st.Meta))
}
last = "running, settling"
}
+8 -4
View File
@@ -433,8 +433,11 @@ func TestSlice4_F_HealthFailureHoldsTheAppAndKeepsTheNewPin(t *testing.T) {
if got := pinOf(t, dir); got != "nextcloud:34.0.1-apache" {
t.Errorf("the pin must STAY on the new version (its migration may have run), got %q", got)
}
if got := strings.Join(c.list(), " | "); got != "pull | up -d --remove-orphans | down" {
t.Errorf("the failed app must be stopped; compose calls = %q", got)
// The `logs` call between `up` and `down` is R-621: the hold keeps the app's own log BEFORE the
// `down` destroys it. The order is the assertion — a capture after the `down` would read empty,
// which is exactly how two drill nights lost the only evidence of why an update failed.
if got := strings.Join(c.list(), " | "); got != "pull | up -d --remove-orphans | logs --no-color --tail 400 | down" {
t.Errorf("the failed app must be stopped, and its log kept FIRST; compose calls = %q", got)
}
if journalExists(m) {
t.Error("the journal is cleared once the hold (the durable record) is written")
@@ -537,8 +540,9 @@ func TestSlice4_G_InterruptedAfterUpResumesTheHealthWait(t *testing.T) {
if held, _ := g.HoldFor("nextcloud"); !held || st.UpdatePhase != UpdatePhaseFailed {
t.Errorf("a resumed update that is still unhealthy must end HELD; held=%v phase=%q", held, st.UpdatePhase)
}
if got := strings.Join(c.list(), " | "); got != "up -d --remove-orphans | down" {
t.Errorf("resumption re-runs `up` then stops the failed app; compose calls = %q", got)
// Same R-621 capture on the resumed path — a hold reached by resumption keeps its evidence too.
if got := strings.Join(c.list(), " | "); got != "up -d --remove-orphans | logs --no-color --tail 400 | down" {
t.Errorf("resumption re-runs `up`, keeps the log, then stops the failed app; compose calls = %q", got)
}
if !g.holdRP.ProvenAt.Equal(slice4T0.Add(-time.Hour)) || g.holdRP.Tier != UpdateTierLocal {
t.Errorf("the resumed hold must name the journaled copy (tier %d at %s), got %+v", UpdateTierLocal, slice4T0.Add(-time.Hour), g.holdRP)