test/harness/exp_chatty_vs_silent.py

1#!/usr/bin/env python3

2"""Does a bot that POSTS still notice its link has died?

4The defect: the keepalive idle clock was refreshed by outbound traffic

5as well as inbound. A write succeeds into the local kernel send buffer

6whatever the peer is doing, so a bot posting more often than the 60s

7idle threshold kept resetting its own timer and never PINGed -- and so

8never detected the dead link at all. The busier the bot, the blinder.

10MATCHED PAIR, which is what makes this a measurement rather than an

11anecdote: two workers, the SAME proxy, frozen at the SAME instant,

12differing ONLY in whether they post.

14 chatty -- posts every 20s (below the 60s idle threshold)

15 silent -- says nothing

17`silent` is the internal control. Its detection time should be

18unchanged by any of this, and if it ever moves, the run is not

19comparable to the one before it and the delta on `chatty` is not

20attributable to the code.

22A NOTE ON WHAT THE HARNESS ITSELF PROVIDES, so nobody cites it as

23safety: the freeze-proxy still forwards the server's eventual FIN even

24in frozen mode, so a bot can be rescued by the server closing the

25connection. Under a real blackhole that close travels the same dead

26path and never arrives. Detection via `Apiary reconnected` alone is

27therefore NOT evidence the bot detected anything itself; only its own

28`PONG timeout` is. Both are reported below, separately, for that

29reason.

31Run against BOTH binaries:

33 APIARY_BIN=/path/to/pre-change python3 test/harness/exp_chatty_vs_silent.py

34 APIARY_BIN=/path/to/post-change python3 test/harness/exp_chatty_vs_silent.py

35"""

36import os

37import re

38import sys

39import threading

40import time

42sys.path.insert(0, os.path.dirname(os.path.abspath(__file__)))

43from mcpdrv import (Bot, leader_env, worker_env, load_state, # noqa: E402

44 say, check, unique_nick)

45from proxy import Proxy # noqa: E402

47PROXY_PORT = int(os.environ.get("HARNESS_PROXY_PORT", "49783"))

48WATCH = float(os.environ.get("HARNESS_WATCH", "200"))

49CHAT_EVERY = float(os.environ.get("HARNESS_CHAT_EVERY", "20"))

52def main():

53 st = load_state()

54 port, token = st["PORT"], st["LEADER_TOKEN"]

55 proxy = Proxy(PROXY_PORT, int(port))

56 bots, nicks = [], {}

57 try:

58 leader = Bot("cs-leader", leader_env(port, token))

59 bots.append(leader)

60 leader.initialize()

61 if not leader.wait_connected(30):

62 raise SystemExit("leader never connected")

64 made = {}

65 for role in ("chatty", "silent"):

66 nick = unique_nick(f"{role[:4]}-")

67 nicks[role] = nick

68 out = leader.call("spawn-worker", nick=nick,

69 **{"expires-in": "60m"})

70 m = re.search(r"[a-f0-9]{64}", out)

71 if not m:

72 raise SystemExit(f"spawn {nick} failed: {out!r}")

73 b = Bot(f"cs-{role}",

74 worker_env(str(PROXY_PORT), m.group(0), nick))

75 bots.append(b)

76 b.initialize()

77 made[role] = b

78 for role, b in made.items():

79 if not b.wait_connected(30):

80 raise SystemExit(f"{role} never connected through the proxy")

81 say(f"both workers connected through the proxy "

82 f"(chatty={nicks['chatty']}, silent={nicks['silent']})")

84 say("\n== freezing BOTH sockets at the same instant ==")

85 proxy.freeze_existing()

86 t0 = time.time()

88 stop = threading.Event()

89 posts = {"n": 0}

91 def chatter():

92 while not stop.is_set():

93 posts["n"] += 1

94 try:

95 # Multi-word payload: a single-token body is relayed

96 # without its ':' and arrives empty, so a harness

97 # using one would be posting nothing.

98 made["chatty"].call(

99 "send-channel",

100 text=f"chatty milestone {posts['n']:02d}",

101 timeout=25)

102 except Exception:

103 pass

104 stop.wait(CHAT_EVERY)

105

106 threading.Thread(target=chatter, daemon=True).start()

107

108 say(f" watching {WATCH:.0f}s for each to notice on its OWN keepalive...")

109 detect = {"chatty": None, "silent": None}

110 while time.time() - t0 < WATCH:

111 for role, b in made.items():

112 if detect[role] is None and b.grep_stderr("PONG timeout"):

113 detect[role] = round(time.time() - t0, 1)

114 say(f" {role}: PONG timeout at t+{detect[role]}s")

115 if all(v is not None for v in detect.values()):

116 break

117 time.sleep(1)

118 stop.set()

119 time.sleep(1)

120

121 say("\n== reconnect status (NOT the same claim as detection) ==")

122 for role, b in made.items():

123 rec = b.grep_stderr("Apiary reconnected")

124 say(f" {role}: reconnected={bool(rec)}")

125

126 say("")

127 ok = True

128 ok &= check("INTERNAL CONTROL: the silent worker detected on its own "

129 "keepalive",

130 detect["silent"] is not None,

131 f"t+{detect['silent']}s" if detect["silent"]

132 else f"never in {WATCH:.0f}s -- the run is not comparable")

133 ok &= check("the CHATTY worker detected on its own keepalive",

134 detect["chatty"] is not None,

135 f"t+{detect['chatty']}s ({posts['n']} posts made)"

136 if detect["chatty"]

137 else f"NEVER in {WATCH:.0f}s despite {posts['n']} posts "

138 "-- posting suppressed its own detection")

139 say(f"\n chatty t+{detect['chatty']}s silent t+{detect['silent']}s"

140 f" posts={posts['n']}")

141 return 0 if ok else 1

142 finally:

143 if bots and bots[0].alive():

144 for nick in nicks.values():

145 bots[0].call("revoke-worker", nick=nick)

146 for b in bots:

147 b.close()

148 proxy.close()

149

150

151if __name__ == "__main__":

152 sys.exit(main())