deploy-vps healthcheck wait is a hard-coded 60s #23

Closed
opened 2026-09-02 20:54:28 +00:00 by ahmad · 1 comment
Owner

Context

deploy-vps waits for every container named in healthcheck-containers to report healthy
before it calls a deployment successful. The wait is a fixed seq 1 30 with sleep 2 — sixty
seconds, hard-coded, with no input to change it.

Sixty seconds is fine on a fast host and impossible on a slow one. On 2026-09-02 the
ahmad/portfolio deploy (run 2156) failed this way while the deployment itself was fine:

20:48:59Z   containers recreated
20:50:45Z   deploy run 2156 reported FAILURE (60s wait exhausted)
20:51:48Z   api logged "api listening" on port 3000
20:52:25Z   /api/health -> 200, container healthy, RestartCount=0

The container took 169 seconds to bind. Nothing was wrong with it — the apps host is
currently I/O saturated (io_full avg300 65.8, load 6.6), so process start is slow. The wait
gave up 63 seconds before the application had even opened its port, then printed
did not become healthy and 50 lines of an empty log, which is the least informative possible
output for this failure.

The trigger is host saturation; the fragility is that the timeout cannot be raised without
editing the shared action. Any repo deploying to a loaded host hits this, and a false deploy
failure is worse than a slow one — it trains people to ignore red deploys.

Scope

  • In: make the healthcheck wait duration an input on deploy-vps with a default at least as
    generous as today's behaviour; report the elapsed wait and the container's last health status
    in the failure message; when a container has never logged anything, say so rather than
    printing an empty log tail.
  • Out: changing any repo's start_period (that is the calling repo's own compose), and the
    apps host saturation itself (tracked in amtronics/infrastructure-vps).

Acceptance criteria

  • Given a caller that sets no new input, when it deploys, then the wait behaves as it does today.
  • Given a caller that sets the new timeout input, when a container takes longer than 60s but less than that timeout to become healthy, then the deploy succeeds.
  • Given a container that never becomes healthy, when the wait expires, then the failure message names the container, the elapsed seconds and the last observed health status.
  • Given a container that produced no log output, when the wait expires, then the message says the log was empty instead of printing nothing.
  • Given the README, when the new input is added, then it is documented in the input table.
### Context `deploy-vps` waits for every container named in `healthcheck-containers` to report `healthy` before it calls a deployment successful. The wait is a fixed `seq 1 30` with `sleep 2` — sixty seconds, hard-coded, with no input to change it. Sixty seconds is fine on a fast host and impossible on a slow one. On 2026-09-02 the `ahmad/portfolio` deploy (run 2156) failed this way while the deployment itself was fine: ``` 20:48:59Z containers recreated 20:50:45Z deploy run 2156 reported FAILURE (60s wait exhausted) 20:51:48Z api logged "api listening" on port 3000 20:52:25Z /api/health -> 200, container healthy, RestartCount=0 ``` The container took 169 seconds to bind. Nothing was wrong with it — the `apps` host is currently I/O saturated (`io_full` avg300 65.8, load 6.6), so process start is slow. The wait gave up 63 seconds before the application had even opened its port, then printed `did not become healthy` and 50 lines of an empty log, which is the least informative possible output for this failure. The trigger is host saturation; the fragility is that the timeout cannot be raised without editing the shared action. Any repo deploying to a loaded host hits this, and a false deploy failure is worse than a slow one — it trains people to ignore red deploys. ### Scope - In: make the healthcheck wait duration an input on `deploy-vps` with a default at least as generous as today's behaviour; report the elapsed wait and the container's last health status in the failure message; when a container has never logged anything, say so rather than printing an empty log tail. - Out: changing any repo's `start_period` (that is the calling repo's own compose), and the `apps` host saturation itself (tracked in `amtronics/infrastructure-vps`). ### Acceptance criteria - [ ] Given a caller that sets no new input, when it deploys, then the wait behaves as it does today. - [ ] Given a caller that sets the new timeout input, when a container takes longer than 60s but less than that timeout to become healthy, then the deploy succeeds. - [ ] Given a container that never becomes healthy, when the wait expires, then the failure message names the container, the elapsed seconds and the last observed health status. - [ ] Given a container that produced no log output, when the wait expires, then the message says the log was empty instead of printing nothing. - [ ] Given the README, when the new input is added, then it is documented in the input table.
ahmad self-assigned this 2026-09-03 00:03:18 +00:00
Author
Owner

Taking this, and it needs a status note first: we filed the same defect twice, an hour apart, from different evidence. #22 came from the pipeline side (two red deploys on ahmad/portfolio while production served the version they had just deployed); this one came from the host side, with the timing that actually explains it — the container took 169 seconds to bind, and the wait gave up 63 seconds before the application had even opened its port. That number is the better evidence, and it is why the default in the fix is 600 rather than 120.

Already delivered by v3.5.2 (#24, merged; the moving v3 tag now points at it):

  • Criterion 2 — health-timeout, so a container taking longer than sixty seconds succeeds.
  • Criterion 5 — the input, its default and the unhealthy behaviour are in the README table and prose.
  • Beyond what this issue asked: unhealthy fails immediately rather than waiting out the budget, and a container reporting no health status at all — a wrong name, or an image with no HEALTHCHECK — fails after a thirty-second grace.

Not delivered, and what I am doing here:

  • Criterion 3 — the failure message names the container and its last status, but not the elapsed seconds. Adding it.
  • Criterion 4 — an empty log tail still prints as nothing at all, which is the "least informative possible output" this issue objects to. It will say so explicitly.

Criterion 1 I am going to fail deliberately, and would rather say so than quietly pass it. It asks that a caller setting nothing behaves as today. v3.5.2 changed exactly that: the default wait went from 60s to 600s. Preserving the old default would have left every repository on the broken behaviour until each one opted out, and the argument in #22 is that the rollout has already happened by then — a short budget does not undo anything, it only decides whether the pipeline tells the truth. If you would rather have the old default back, that is a one-line change and I will make it.

Taking this, and it needs a status note first: we filed the same defect twice, an hour apart, from different evidence. #22 came from the pipeline side (two red deploys on `ahmad/portfolio` while production served the version they had just deployed); this one came from the host side, with the timing that actually explains it — the container took **169 seconds** to bind, and the wait gave up 63 seconds before the application had even opened its port. That number is the better evidence, and it is why the default in the fix is 600 rather than 120. **Already delivered by v3.5.2** (#24, merged; the moving `v3` tag now points at it): - Criterion 2 — `health-timeout`, so a container taking longer than sixty seconds succeeds. - Criterion 5 — the input, its default and the `unhealthy` behaviour are in the README table and prose. - Beyond what this issue asked: `unhealthy` fails immediately rather than waiting out the budget, and a container reporting no health status at all — a wrong name, or an image with no `HEALTHCHECK` — fails after a thirty-second grace. **Not delivered, and what I am doing here:** - Criterion 3 — the failure message names the container and its last status, but not the **elapsed** seconds. Adding it. - Criterion 4 — an empty log tail still prints as nothing at all, which is the "least informative possible output" this issue objects to. It will say so explicitly. **Criterion 1 I am going to fail deliberately, and would rather say so than quietly pass it.** It asks that a caller setting nothing behaves as today. v3.5.2 changed exactly that: the default wait went from 60s to 600s. Preserving the old default would have left every repository on the broken behaviour until each one opted out, and the argument in #22 is that the rollout has already happened by then — a short budget does not undo anything, it only decides whether the pipeline tells the truth. If you would rather have the old default back, that is a one-line change and I will make it.
ahmad 2026-09-03 02:02:42 +00:00
Sign in to join this conversation.
No description provided.