signal-bot/tests/test_liveness.py
Krzysztof kuhy Rudnicki d5c63b423b feat: refuse to look healthy while deaf, and heal the container by itself
Today the bot was up, healthy and answering nothing for three hours. A host
firewall change (fixed in testsAndMisc 334c0cd9) cut every Docker container
off the internet; signal-cli lost Signal and reconnected in a loop from
15:32:50 onward. Nothing noticed:

  - the container's own healthcheck answered 204
  - /v1/groups answered 200 out of local state, so discovery saw no change
  - the bot's WebSocket to the container stayed OPEN, so the transport's
    reconnect logic never fired
  - /healthz answered {"status": "ok"} the entire time

The only symptom was silence, which is also what a quiet evening looks like.

signal_bot/liveness.py asks the one question that cannot be answered from a
cache -- GET /v1/devices, which needs a live round trip -- but only after
SILENCE_SECONDS (120) with no frame of any kind, so a busy group costs
nothing and an idle one costs one request per window. Three consecutive
failures and /healthz answers 503 with the reason. Verified end to end in
scripts/e2e.sh against the real process: 503 after 84s with the fake's
connection cut, back to 200 on its own 30s after restoring it.

scripts/signal_api_watchdog.sh + a two-minute user timer do the recovery the
bot cannot do for itself, since a wedged bot cannot restart the container it
depends on. Two tiers, so the steady state costs no Signal round trip at
all: the bot's own /healthz first, the authenticated probe only when that is
not 200. It stops after 3 restarts in 6 hours and escalates instead -- a
deregistered account or a blocked network is not fixable by restarting, and
a restart loop would hide it. Its own bash suite stubs curl and docker and
drives every branch including the give-up cap.

signal_bot/trust.py answers the other half: TRUSTED_INVITERS decides who may
put this bot in a group. The gate sits in GroupDirectory._permitted, which
both _join_pending and _adopt already route through -- gating only invites
would gate the door nobody uses, since prime_profile.sh exists precisely so
that an add becomes a direct join. Evidence is either the group-update
envelope, which is the only frame naming an inviter, or a trusted identity
being a full member in the listing. A refusal is logged once, with that
group's members, so the operator can see which string to add.

verify_allowlist moved to membership.py to keep discovery.py under the
250-line gate; it was already the module that owns MembershipError.

Verified live, by stopping the container by hand and touching nothing else:

  18:54:35  docker stop signal-api
  18:56:36  liveness: failure 1 of 3 after 123s of silence
  18:57:36  failure 3 of 3 -> /healthz answers 503 from 18:57:45
  18:58:18  watchdog: probe failed (1/2)
  19:00:28  watchdog: probe failed (2/2) -> docker restart signal-api
  19:00:36  liveness: receive path recovered after 8 failed probe(s)
  19:01:13  watchdog: signal-api is back

Six minutes, unattended, against three hours of silence this afternoon. All
four real groups are still adopted with TRUSTED_INVITERS=+48123456789 set,
and no group was refused.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01KbjfWdAyHbCubac7wJKJZW
2026-08-29 19:01:55 +02:00

178 lines
5.4 KiB
Python

# Copyright (c) 2026 Krzysztof Rudnicki. MIT licence.
"""The deafness gate: silence plus a failing probe is not health."""
from __future__ import annotations
import logging
from typing import TYPE_CHECKING
import httpx
from signal_bot.liveness import Liveness
if TYPE_CHECKING:
from collections.abc import Callable
import pytest
from signal_bot.config import Config
DEAD_BODY = {"error": "Failed to get linked devices: Closed unexpectedly"}
class Clock:
"""A monotonic clock the test moves by hand."""
def __init__(self) -> None:
self.seconds = 0.0
def __call__(self) -> float:
return self.seconds
def gate(
config: Config,
handler: Callable[[httpx.Request], httpx.Response],
clock: Clock,
*,
slept: list[float] | None = None,
) -> Liveness:
"""A Liveness wired to a mock API and a hand-cranked clock."""
async def sleeper(seconds: float) -> None:
if slept is not None:
slept.append(seconds)
return Liveness(
config,
httpx.AsyncClient(transport=httpx.MockTransport(handler)),
ticker=clock,
sleeper=sleeper,
)
async def test_it_starts_healthy_without_asking_anybody(config: Config) -> None:
"""A cold start must not 503: the installer waits on /healthz."""
calls: list[str] = []
def handler(request: httpx.Request) -> httpx.Response:
calls.append(str(request.url))
return httpx.Response(200, json=[])
assert gate(config, handler, Clock()).healthy is True
assert calls == []
async def test_a_live_account_answers_the_probe(config: Config) -> None:
def handler(request: httpx.Request) -> httpx.Response:
assert request.url.path == "/v1/devices/+15550000000"
return httpx.Response(200, json=[{"id": 1}])
assert await gate(config, handler, Clock()).probe() is True
async def test_the_real_outage_shape_fails_the_probe(config: Config) -> None:
live = gate(config, lambda r: httpx.Response(400, json=DEAD_BODY), Clock())
assert await live.probe() is False
assert "Closed unexpectedly" in live.reason
async def test_a_hanging_api_fails_the_probe_rather_than_the_loop(config: Config) -> None:
"""/v1/devices was seen to hang past 20s during the outage."""
timed_out = "timed out"
def handler(request: httpx.Request) -> httpx.Response:
raise httpx.TimeoutException(timed_out, request=request)
live = gate(config, handler, Clock())
assert await live.probe() is False
assert "TimeoutException" in live.reason
async def test_silence_alone_never_probes(config: Config) -> None:
"""A quiet group is normal; only long silence is worth a round trip."""
calls: list[str] = []
clock = Clock()
slept: list[float] = []
def handler(request: httpx.Request) -> httpx.Response:
calls.append(str(request.url))
return httpx.Response(200, json=[])
live = gate(config, handler, clock, slept=slept)
await live.run(iterations=2)
assert slept == [30.0, 30.0]
assert calls == []
assert live.healthy is True
async def test_a_successful_probe_resets_the_silence_clock(config: Config) -> None:
"""One probe per silence window, not one per tick."""
calls: list[str] = []
clock = Clock()
def handler(request: httpx.Request) -> httpx.Response:
calls.append(str(request.url))
clock.seconds += 30.0
return httpx.Response(200, json=[])
live = gate(config, handler, clock)
async def tick() -> None:
clock.seconds += 30.0
await live.run(iterations=1)
for _ in range(8):
await tick()
assert len(calls) == 2
assert live.healthy is True
async def test_three_failures_make_the_bot_admit_it_is_deaf(
config: Config, caplog: pytest.LogCaptureFixture
) -> None:
clock = Clock()
live = gate(config, lambda r: httpx.Response(400, json=DEAD_BODY), clock)
with caplog.at_level(logging.WARNING):
for _ in range(3):
clock.seconds += 200.0
await live.run(iterations=1)
if live.healthy:
assert "cannot reach Signal" in caplog.text
assert live.healthy is False
assert "nothing received for" in live.reason
assert caplog.text.count("cannot reach Signal") == 3
# A fourth failure must not say "failure 4 of 3": the verdict is in.
with caplog.at_level(logging.WARNING):
clock.seconds += 200.0
await live.run(iterations=1)
assert caplog.text.count("cannot reach Signal") == 3
assert "still deaf: 4 failed probe(s)" in caplog.text
async def test_one_frame_clears_the_alarm(config: Config, caplog: pytest.LogCaptureFixture) -> None:
clock = Clock()
live = gate(config, lambda r: httpx.Response(400, json=DEAD_BODY), clock)
for _ in range(3):
clock.seconds += 200.0
await live.run(iterations=1)
assert live.healthy is False
with caplog.at_level(logging.WARNING):
live.note_envelope()
assert live.healthy is True
assert "recovered after 3 failed probe(s)" in caplog.text
assert live.silent_for == 0.0
async def test_a_frame_while_healthy_says_nothing(
config: Config, caplog: pytest.LogCaptureFixture
) -> None:
"""The recovery line must mean something, so it cannot fire per frame."""
live = gate(config, lambda r: httpx.Response(200, json=[]), Clock())
with caplog.at_level(logging.WARNING):
live.note_envelope()
assert caplog.text == ""