Commit9757ab7bRecorded29 Jun 2026Repositorycourier

Add pre-poll-heartbeat regression test

Message

Runs courier --telegram-poller directly and asserts the child emits a heartbeat immediately after hello (gap well under the inter-poll sleep), proving the liveness heartbeat is emitted BEFORE each poll rather than only after tg-bot-tick returns -- the property that stops a slow poll from false-tripping the watchdog. Deterministic offline (a bogus token fails the tick fast; the pre-poll heartbeat fires before the tick runs).

Changed
 test/test-poller-heartbeat.py | 105 +++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++
 1 file changed, 105 insertions(+)
Diff
test/test-poller-heartbeat.pyadded
@@ -0,0 +1,105 @@
+1
#!/usr/bin/env python3
+2
"""Pre-poll-heartbeat regression test (task fix-courier-poller-watchdog-race).
+3
+4
Guards the v0.3.3 fix for the poller watchdog/heartbeat timing race. The
+5
isolated Telegram poller child used to emit its liveness heartbeat ONLY
+6
*between* polls (poller-sleep/heartbeat runs after tg-bot-tick returns),
+7
so a single poll that blocked longer than the supervisor's 30s stale
+8
window left the child silent and the watchdog killed it though it was
+9
alive and mid-request -- the recurring kill right after a fresh start
+10
(getUpdates runs over a blocking native TLS read with no timeout, and
+11
the first poll's cold TLS handshake is the slowest).
+12
+13
The fix emits a heartbeat IMMEDIATELY BEFORE each poll, so the watchdog
+14
window resets at the start of the blocking call.
+15
+16
This runs `courier --telegram-poller` directly (child mode) and reads
+17
its stdout JSON event stream. The structural assertion: the first
+18
`heartbeat` must arrive promptly after `hello` (well under the inter-poll
+19
sleep), proving the heartbeat is emitted BEFORE the first poll, not
+20
gated on the tick returning.
+21
+22
WITHOUT the fix the first heartbeat only lands after the first tick + the
+23
inter-poll sleep (>=5s with a failing token), so the hello->heartbeat gap
+24
is large. WITH the fix it is ~0s, independent of what the tick does
+25
(network present or not) -- the heartbeat is emitted before tg-bot-tick
+26
is even called, so the test is deterministic offline too.
+27
+28
Usage:
+29
COURIER_BIN=/path/to/courier python3 test-poller-heartbeat.py
+30
+31
Exit 0 = pass.
+32
"""
+33
import json, os, signal, subprocess, sys, time, select
+34
+35
COURIER = os.environ.get("COURIER_BIN",
+36
"/home/daviwil/Projects/Code/sigil/courier/build/release/bin/courier")
+37
# Generous bound: the pre-poll heartbeat lands ~immediately; the old
+38
# between-polls-only behavior would land at ~tick + inter-poll sleep
+39
# (>=5s with a failing token). 2.5s cleanly separates the two.
+40
MAX_HELLO_TO_HEARTBEAT = float(os.environ.get("MAX_HELLO_TO_HEARTBEAT", "2.5"))
+41
+42
checks = []
+43
def check(name, ok, detail=""):
+44
checks.append((name, ok, detail))
+45
print(("PASS " if ok else "FAIL ") + name + ("" if not detail else f" [{detail}]"))
+46
return ok
+47
+48
def read_event(p, timeout):
+49
"""Read one decoded JSON stdout event (with arrival time), or None."""
+50
end = time.time() + timeout
+51
while time.time() < end:
+52
r, _, _ = select.select([p.stdout], [], [], max(0.01, end - time.time()))
+53
if r:
+54
line = p.stdout.readline()
+55
if not line:
+56
return None
+57
try:
+58
return (json.loads(line), time.time())
+59
except ValueError:
+60
continue
+61
return None
+62
+63
def main():
+64
env = os.environ.copy()
+65
# Bogus token: the first tg-bot-tick fails fast (401 if online, a
+66
# connection error if not). Either way the pre-poll heartbeat is
+67
# emitted before the tick runs, so the assertion holds offline too.
+68
env["COURIER_TELEGRAM_TOKEN"] = "123456:HEARTBEAT-TEST-BAD-TOKEN"
+69
env["COURIER_TELEGRAM_CHAT_ID"] = "1"
+70
+71
p = subprocess.Popen([COURIER, "--telegram-poller"],
+72
env=env, stdin=subprocess.PIPE,
+73
stdout=subprocess.PIPE, stderr=subprocess.PIPE)
+74
try:
+75
# First event must be hello (carries pid).
+76
ev = read_event(p, 15)
+77
hello_ok = ev is not None and ev[0].get("type") == "hello"
+78
check("child emits hello", hello_ok, str(ev[0] if ev else None))
+79
if not hello_ok:
+80
return
+81
t_hello = ev[1]
+82
check("hello carries pid", isinstance(ev[0].get("pid"), int),
+83
f"pid={ev[0].get('pid')}")
+84
+85
# Next event must be the pre-poll heartbeat, arriving promptly.
+86
ev2 = read_event(p, 15)
+87
hb_ok = ev2 is not None and ev2[0].get("type") == "heartbeat"
+88
check("first event after hello is a heartbeat", hb_ok,
+89
str(ev2[0] if ev2 else None))
+90
if hb_ok:
+91
gap = ev2[1] - t_hello
+92
check("heartbeat is emitted BEFORE the first poll completes",
+93
gap < MAX_HELLO_TO_HEARTBEAT,
+94
f"hello->heartbeat gap={gap:.2f}s (bound {MAX_HELLO_TO_HEARTBEAT}s)")
+95
finally:
+96
if p.poll() is None:
+97
p.send_signal(signal.SIGKILL)
+98
p.wait()
+99
+100
failed = [c for c in checks if not c[1]]
+101
print(f"\n{len(checks) - len(failed)}/{len(checks)} checks passed")
+102
sys.exit(1 if failed else 0)
+103
+104
if __name__ == "__main__":
+105
main()