test/test-poller-heartbeat.py

1#!/usr/bin/env python3

2"""Pre-poll-heartbeat regression test (task fix-courier-poller-watchdog-race).

4Guards the v0.3.3 fix for the poller watchdog/heartbeat timing race. The

5isolated Telegram poller child used to emit its liveness heartbeat ONLY

6*between* polls (poller-sleep/heartbeat runs after tg-bot-tick returns),

7so a single poll that blocked longer than the supervisor's 30s stale

8window left the child silent and the watchdog killed it though it was

9alive and mid-request -- the recurring kill right after a fresh start

10(getUpdates runs over a blocking native TLS read with no timeout, and

11the first poll's cold TLS handshake is the slowest).

13The fix emits a heartbeat IMMEDIATELY BEFORE each poll, so the watchdog

14window resets at the start of the blocking call.

16This runs `courier --telegram-poller` directly (child mode) and reads

17its stdout JSON event stream. The structural assertion: the first

18`heartbeat` must arrive promptly after `hello` (well under the inter-poll

19sleep), proving the heartbeat is emitted BEFORE the first poll, not

20gated on the tick returning.

22WITHOUT the fix the first heartbeat only lands after the first tick + the

23inter-poll sleep (>=5s with a failing token), so the hello->heartbeat gap

24is 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

26is even called, so the test is deterministic offline too.

28Usage:

29 COURIER_BIN=/path/to/courier python3 test-poller-heartbeat.py

31Exit 0 = pass.

32"""

33import json, os, signal, subprocess, sys, time, select

35COURIER = 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.

40MAX_HELLO_TO_HEARTBEAT = float(os.environ.get("MAX_HELLO_TO_HEARTBEAT", "2.5"))

42checks = []

43def 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

48def 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

63def 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"

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')}")

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()

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

104if __name__ == "__main__":

105 main()