diff --git a/debian/changelog b/debian/changelog index faf736c..74ae3e1 100644 --- a/debian/changelog +++ b/debian/changelog @@ -1,3 +1,28 @@ +keel (0.23.16) unstable; urgency=medium + + * A write in flight at a planned promote waited 15 s for its answer, + and the new primary took 10 s to take writes (keel#138). The 10 s + were the announcement to a member outside the pair that was down, + which keel#137 takes out of the handover. The write: the old primary + dropped the VIP while the commit waited for the replica's + acknowledgement, so the answer had no address to come from. Now the + old primary, when it declares a database, turns it read only before + it releases the VIP: SET GLOBAL read_only = ON returns once the + commits in flight ended, which the replica, still connected, + acknowledges; then the address goes. A failure is logged and the + release goes on. + * With etcd, a planned promote waited for the controller's next lease + renewal before the VIP was on wg0 (a 5.6 s write gap at 250 ms). + The majority granted the lease and wrote the claim with it, as a + renewal confirms it, so the promote now adds the address itself, + for what is left of the release time after the lease was asked for; + the controller extends it once it renewed, and the promote checks + that renewal before it returns. A primary that released the VIP + dropped the address and revoked its own lease first, so the promote + claims at once instead of waiting for that lease to go. + + -- Marcos Méndez Sat, 10 Oct 2026 14:00:00 +0000 + keel (0.23.15) unstable; urgency=medium * In cloud simple, one member outside the pair that is down made every diff --git a/docs/replication.md b/docs/replication.md index fe8664e..d319bda 100644 --- a/docs/replication.md +++ b/docs/replication.md @@ -227,7 +227,10 @@ declared. **`keel database promote [--old-primary-gone]`** on the replica, as today, in this order: `keel vip promote` (release before take; refused without the flag when the old primary does not answer: 0049, second -round, point 3), then the database: drain the relay log, `STOP SLAVE`, +round, point 3; the old primary turns its database read only before it +drops the address, so the commits in flight end, and their clients get +the answer, while the replica is still connected: keel#138), then the +database: drain the relay log, `STOP SLAVE`, `RESET SLAVE ALL`, `read_only = OFF`, `READ_ONLY ADMIN` back. The semi-synchronous roles need no flip (both sides enabled on both nodes). When the old primary is gone, `STOP SLAVE IO_THREAD` takes seconds diff --git a/docs/vip.md b/docs/vip.md index 925ce4e..a67d6b7 100644 --- a/docs/vip.md +++ b/docs/vip.md @@ -206,8 +206,12 @@ record: carries the VIP only when a majority of the peers that answered took it**; with no peer answering (a mesh of the two nodes alone, the other one gone), the operator's flag is the acceptance. With - etcd, the claim is the counter's compare-and-swap, and the controller - adds the address once it renewed the claim's lease. A transaction + etcd, the claim is the counter's compare-and-swap. The promote adds + the address at once, for what is left of the release time after it + asked for the lease (the majority granted it and wrote the claim with + it, as a renewal confirms it), and the controller extends it once it + renewed the claim's lease; the promote checks that renewal before it + returns (keel#138). A transaction that etcd does not answer in time may have committed (keel#135): the counter is read first; this node's own claim at the epoch is the claim made, and is recorded with its lease; another claim ends the diff --git a/keel/__init__.py b/keel/__init__.py index 73036bd..94d620e 100644 --- a/keel/__init__.py +++ b/keel/__init__.py @@ -12,7 +12,7 @@ # an image's tree read offline): debian/changelog's and pyproject.toml's, # which tests/test_version.py keeps in step. Installed, the metadata # dpkg put beside the package answers (keel#98). -FALLBACK_VERSION = "0.23.15" +FALLBACK_VERSION = "0.23.16" def version() -> str: diff --git a/keel/mesh/vippromote.py b/keel/mesh/vippromote.py index 65cb47e..b36cc22 100644 --- a/keel/mesh/vippromote.py +++ b/keel/mesh/vippromote.py @@ -501,8 +501,20 @@ def promoted_etcd(here: Here, vip: str, gone: bool, return exits.OK if holder is not None and not same_key(holder.holder, own): epoch = max(now.epoch.epoch if now.epoch else 0, holder.epoch) + 1 - if not released(here, vip, holder, epoch, gone, out): + why = asked_release(here, vip, holder, epoch, out) + if why and not gone: + out(f"the primary at {holder.address} did not release it: {why}." + " Nothing was changed. Only you know whether that node is" + " gone: if it is, run keel vip promote --old-primary-gone") return exits.MESH_REFUSED + if why is None: + # it dropped the address first and revoked its own lease; the + # compare-and-swap is on the counter alone: claimed at once + # (keel#138), on the counter read before the release + return claimed_etcd(here, vip, now, own, out) + out(f"the primary at {holder.address} did not answer ({why});" + " --old-primary-gone: it will drop the VIP when it learns the" + " newer claim") out("waiting for the primary's lease to go" f" (at most {GONE_WAIT:g} s)…") now = gone_lease(here, vip, holder.lease, GONE_WAIT) @@ -512,6 +524,13 @@ def promoted_etcd(here: Here, vip: str, gone: bool, return exits.MESH_REFUSED if now.epoch is not None and same_key(now.epoch.holder, own): return raced(here, vip, own, out) + return claimed_etcd(here, vip, now, own, out) + + +def claimed_etcd(here: Here, vip: str, now: vipetcd.Seen, own: str, + out: Callable[[str], None]) -> int: + """The claim by compare-and-swap on the counter read in `now`, the + address carried, the peers told""" try: made = vipetcd.claim( here.local(), here.mesh_id(), vip, now, @@ -526,14 +545,25 @@ def promoted_etcd(here: Here, vip: str, gone: bool, vipnode.hold(here, made[0], False, made[1]) out(f"this node holds {vip} at epoch {made[0].epoch}, by etcd's lease" f" {made[1]}") + # the majority granted the lease and wrote the claim with it after + # `asked`, as a renewal would confirm it: the address is carried now, + # for what is left of the release time after that moment, and the + # controller extends it once it renewed (keel#138: the wait for its + # next renewal was most of a planned promote's write gap) + carried = vipnode.carry_held(here, vip, here.monotonic() - made[2]) + # etcd holds the claim; the peers are told in the background (keel#137), + # as soon as the address is here, so they route the VIP to it at once + out("the peers are told in the background") + if carried: + in_background(here, made[0], set()) if not carried_soon(here, vip): - out(f"keel-vip.service did not add {vip} to {here.iface()} within" - f" {CARRY_WAIT:g} s: is it running? Its lease expires" - f" {vipetcd.TTL} s after its last renewal") + out(f"keel-vip.service did not carry {vip} on {here.iface()} and" + f" renew its lease within {CARRY_WAIT:g} s: is it running? The" + f" address goes {vipetcd.RELEASE_AFTER:g} s after the claim, and" + f" the lease {vipetcd.TTL} s after its last renewal") return exits.APPLY_FAILED - # etcd holds the claim; the peers are told in the background (keel#137) - out("the peers are told in the background") - in_background(here, made[0], set()) + if not carried: + in_background(here, made[0], set()) return exits.OK @@ -579,12 +609,30 @@ def raced(here: Here, vip: str, own: str, def carried_soon(here: Here, vip: str) -> bool: + """Whether keel-vip.service carries the VIP within CARRY_WAIT: the + address on wg0 and, for a claim on an etcd lease, a renewal of that + lease by the controller (its time to live goes up), since the promote + adds the address itself for the release time alone (keel#138)""" deadline = here.monotonic() + CARRY_WAIT - while not vipnet.carried(here.iface(), vip, here.node.output): + lease = vipnode.current(here, vip).lease + first = None + while True: + if vipnet.carried(here.iface(), vip, here.node.output): + if lease is None: + return True + try: + left = here.local().time_to_live(lease) + except EtcdError: + left = None + now = here.monotonic() + if left is not None: + if first is None: + first = (now, left) + elif left > first[1] - (now - first[0]) + 1: + return True if here.monotonic() >= deadline: return False here.sleep(POLL) - return True def check(here: Here, out: Callable[[str], None]) -> int: diff --git a/keel/mesh/vipserve.py b/keel/mesh/vipserve.py index 7d0b4e5..ab90064 100644 --- a/keel/mesh/vipserve.py +++ b/keel/mesh/vipserve.py @@ -15,15 +15,19 @@ and the epoch this node knows; - `release` is taken only by a node whose own spec declares that VIP, from the other member its pair record names, fresh, for an epoch - newer than any this node knows: it drops the address, then answers; + newer than any this node knows: it turns its database read only + when it declares one (the commits in flight end first, keel#138), + drops the address, then answers; - `pair` is the other member's pair record (keel.mesh.vippair), signed here too when this node's spec declares that VIP, and kept; - `secret` is answered with a secret the pair shares, only to the other member of the pair record, fresh (keel.system.dbsecret); 404 while this node holds none, and the asker tries again later. -Nothing here applies a change under 0018's window, and nothing waits: -each answer is the time of an `ip` or a `wg set`. +Nothing here applies a change under 0018's window, and nothing waits +but a release on a database: each answer is the time of an `ip` or a +`wg set`, and a release also waits for SET GLOBAL read_only = ON (up to +dbreadonly.QUIESCE_TIMEOUT). """ import json @@ -198,5 +202,27 @@ def released(here: Here, message: vipmsg.Message) -> Answer: def revoke(lease: str) -> None: here.local().revoke(lease) + quiesced(here, vip) vipnode.release(here, vip, revoke) return Answer(200, b'{"released": true}') + + +def quiesced(here: Here, vip: str) -> None: + """The database of a node that declares one made read only before + the VIP goes (keel#138): the commits in flight end first, their + clients get the answer while the address is still here, and no new + write is taken. A failure is logged and the release goes on: the + database follows the VIP's state after, as before""" + try: + doc = here.node.document() + except NodeError: + return + if not (doc.get("database") or {}).get("server"): + return + from keel.system import dbreadonly + problem = dbreadonly.quiesce() + if problem: + here.err(f"vip {vip}: the database could not be made read only" + f" first ({problem}); the release goes on") + return + here.err(f"vip {vip}: the database is read only before the release") diff --git a/keel/system/dbreadonly.py b/keel/system/dbreadonly.py index 53ea51f..4df0b8d 100644 --- a/keel/system/dbreadonly.py +++ b/keel/system/dbreadonly.py @@ -54,6 +54,9 @@ STATUS_QUESTION = mariadb.CLIENT + ("--execute", "SHOW REPLICA STATUS\\G") NO_BINLOG = "SET SESSION sql_log_bin = 0;\n" POLL_SECONDS = 1.0 +# how long the old primary waits for read_only before it releases the +# VIP: the semi-synchronous timeout (10 s) and room +QUIESCE_TIMEOUT = 15 # the lock follow and spec apply take around the replication's statements REPLICATION_LOCK = "var/lib/keel/database/follow.lock" IO_STOP = "STOP SLAVE IO_THREAD" @@ -231,6 +234,31 @@ def promote( return None +def quiesce(runner=subprocess.run) -> str | None: + """read_only on, before the old primary lets the VIP go (keel#138); + None, or why not + + SET GLOBAL read_only = ON returns once the commits in flight ended, + and a commit with semi-synchronous replication ends when the + replica, still connected then, acknowledged it. So a client whose + write was in flight gets its answer before the address goes, and no + new write is taken. Bounded by QUIESCE_TIMEOUT: a replica that does + not acknowledge costs rpl_semi_sync_master_timeout (10 s) at most.""" + statements = mariadb.set_read_only(True) + try: + done = runner(list(mariadb.CLIENT), input=statements.text, + capture_output=True, text=True, check=False, + timeout=QUIESCE_TIMEOUT) + except subprocess.TimeoutExpired: + return f"the server did not turn read only within" \ + f" {QUIESCE_TIMEOUT} s" + except OSError as e: + return f"cannot run {mariadb.CLIENT[0]}: {e.strerror}" + if done.returncode != 0: + return (done.stderr or "").strip() or f"exited {done.returncode}" + return None + + @contextlib.contextmanager def replication_locked(root: str) -> Iterator[None]: """One writer of the replication's statements at a time: keel diff --git a/pyproject.toml b/pyproject.toml index 52c0f48..70e3f49 100644 --- a/pyproject.toml +++ b/pyproject.toml @@ -4,7 +4,7 @@ build-backend = "setuptools.build_meta" [project] name = "keel" -version = "0.23.15" +version = "0.23.16" authors = [{name = "KeelLinux maintainers"}] description = "Declarative management of one appliance instance" readme = "README.md" diff --git a/tests/mariadb_netns.py b/tests/mariadb_netns.py index b06989b..230b056 100644 --- a/tests/mariadb_netns.py +++ b/tests/mariadb_netns.py @@ -680,6 +680,8 @@ def play(report: dict, pids: list[int], pairs, roots: list[str], report["b_bypass"] = agent_send( "B", "sql SELECT GRANTEE FROM information_schema.USER_PRIVILEGES" " WHERE PRIVILEGE_TYPE = 'READ_ONLY ADMIN'") + planned(report, pids, pairs, roots, "B", "k138_to_b") + planned(report, pids, pairs, roots, "A", "k138_to_a") crashed(report, pids, roots) report["alerts"] = [one.get("text", "")[:160] for one in HOOKS["alerts"]] for process in vip_netns.AGENTS.values(): @@ -708,8 +710,9 @@ class Writer: """C writes one row at the VIP every 0.1 s, a new connection each time with a 2 s connect timeout, as the real-node test's writer""" - def __init__(self, pid: int): + def __init__(self, pid: int, name: str = "crash"): self.pid = pid + self.name = name self.done: list[dict] = [] self.halt = threading.Event() self.thread = threading.Thread(target=self.run, daemon=True) @@ -733,7 +736,7 @@ def run(self) -> None: "--batch", "--connect-timeout=2", "-h", vip_netns.VIP, "-u", APP_USER, f"--password={APP_PASSWORD}", "--skip-ssl-verify-server-cert", APP_DB, "--execute", - f"INSERT INTO t (v, at) VALUES ('crash-{n}'," + f"INSERT INTO t (v, at) VALUES ('{self.name}-{n}'," f" {started:.3f})"], capture_output=True, text=True, check=False, timeout=30) ok, err = one.returncode == 0, one.stderr.strip()[:12] @@ -806,15 +809,86 @@ def since(at): "acked": len(ok)} -def acked_missing(writer: Writer, agent_send) -> list[str]: - """The rows C had acknowledged that the new primary B lacks""" - acked = {f"crash-{one['n']}" for one in writer.done if one["ok"]} - found = agent_send("B", f"sql SELECT v FROM {APP_DB}.t WHERE v LIKE" - " 'crash-%'") +def acked_missing(writer: Writer, agent_send, + node: str = "B") -> list[str]: + """The rows C had acknowledged that the new primary lacks""" + acked = {f"{writer.name}-{one['n']}" for one in writer.done + if one["ok"]} + found = agent_send(node, f"sql SELECT v FROM {APP_DB}.t WHERE v LIKE" + f" '{writer.name}-%'") held = set((found.get("out") or "").split()) return sorted(acked - held)[:20] +def planned(report: dict, pids: list[int], pairs, roots: list[str], + to: str, key: str) -> None: + """keel#138: a planned promote while C writes at the VIP: the + longest gap between two acknowledged writes, the writes that waited, + and the acknowledged rows the new primary lacks""" + import vip_netns + from vip_netns import NAMES, agent_send, wait_until + writer = Writer(pids[2], key) + writer.start() + report[f"{key}_first_ack_s"] = wait_until( + lambda: any(one["ok"] for one in writer.done), 60, 0.2) + time.sleep(3) + old = "A" if to == "B" else "B" + marks: dict[str, float] = {} + halt = threading.Event() + + def watch() -> None: + """When each step of the handover is seen, every 0.05 s""" + checks = { + "old_read_only": lambda: read_only_of( + roots[NAMES.index(old)]) == "1", + "old_dropped": lambda: not vip_netns.holds( + pids[NAMES.index(old)]), + "new_carries": lambda: vip_netns.holds(pids[NAMES.index(to)]), + "c_routes_new": lambda: vip_netns.routed_to(pids[2]) == + pairs[NAMES.index(to)][1], + "new_writable": lambda: read_only_of( + roots[NAMES.index(to)]) == "0"} + while not halt.is_set(): + for name, check in checks.items(): + if name not in marks and check(): + marks[name] = time.time() + halt.wait(0.05) + watcher = threading.Thread(target=watch, daemon=True) + promote_at = time.time() + watcher.start() + report[key] = agent_send(to, "dbpromote", 300) + promoted_at = time.time() + root = roots[NAMES.index(to)] + report[f"{key}_writable_s"] = wait_until( + lambda: read_only_of(root) == "0", 60, 0.2) + time.sleep(5) + halt.set() + watcher.join() + writer.stop() + report[f"{key}_marks"] = {name: round(at - promote_at, 2) + for name, at in sorted(marks.items(), + key=lambda one: one[1])} + before = [one["end"] for one in writer.done + if one["ok"] and one["end"] < promote_at + 1] + after = [one["end"] for one in writer.done + if one["ok"] and one["t"] > promote_at] + report[f"{key}_marks"]["last_ok"] = round(max(before) - promote_at, 2) \ + if before else None + report[f"{key}_marks"]["first_ok_after"] = round( + min(after) - promote_at, 2) if after else None + ok = sorted(one["end"] for one in writer.done if one["ok"]) + window = [t for t in ok if t >= promote_at - 2] + gaps = [b - a for a, b in zip(window, window[1:])] + report[f"{key}_gap"] = { + "promote_took_s": round(promoted_at - promote_at, 2), + "longest_gap_s": round(max(gaps), 2) if gaps else None, + "longest_write_s": round(max(one["end"] - one["t"] for one in + writer.done), 2), + "failed": sum(1 for one in writer.done if not one["ok"]), + "acked": len(ok)} + report[f"{key}_missing"] = acked_missing(writer, agent_send, to) + + def promote_gone(agent_send) -> dict: """keel database promote --old-primary-gone on B, as an operator runs it: run again when etcd had no leader to answer (A, cut off, may diff --git a/tests/test_mariadb_netns.py b/tests/test_mariadb_netns.py index 49e0d44..8063a39 100644 --- a/tests/test_mariadb_netns.py +++ b/tests/test_mariadb_netns.py @@ -223,6 +223,24 @@ def test_the_unplanned_write_downtime_and_no_acked_row_lost(self): self.assertLess(found["first_ok_after_s"] - found["carried_s"], 3.0, found) + def test_a_planned_promote_s_write_gap_is_under_3_s(self): + """keel#138: a write in flight at the release got its answer + late (the old primary dropped the VIP while the commit waited + for the replica), and the new primary took 10 s to take writes. + Both ways, A to B and back: the longest gap between two + acknowledged writes under 3 s, no write waiting 10 s, no + acknowledged row lost""" + for key in ("k138_to_b", "k138_to_a"): + with self.subTest(promote=key): + found = self.found[f"{key}_gap"] + print(f"{key}: {found} {self.found.get(key + '_marks')}", + file=sys.stderr) + self.assertEqual(self.found[key]["code"], 0, self.found[key]) + self.assertIsNotNone(self.found[f"{key}_writable_s"], found) + self.assertLess(found["longest_gap_s"], 3.0, found) + self.assertLess(found["longest_write_s"], 10.0, found) + self.assertEqual(self.found[f"{key}_missing"], [], found) + def test_no_two_nodes_ever_carry_the_vip(self): self.assertEqual(self.found["max_holders"], 1, self.found["double_holder_samples"]) diff --git a/tests/test_mesh_vipclaim.py b/tests/test_mesh_vipclaim.py index 9bbbe45..0eb4425 100644 --- a/tests/test_mesh_vipclaim.py +++ b/tests/test_mesh_vipclaim.py @@ -262,3 +262,57 @@ def test_a_claim_older_than_the_file_is_not_taken(self): code, said = self.raced() self.assertEqual(code, exits.APPLY_FAILED) self.assertIn("epoch 4 is known", said) + + +class TestThePromoteCarriesItAtOnce(ClaimCase): + """keel#138: after the compare-and-swap the promote waited for the + controller's next renewal before the VIP was on wg0 (5.6 s write gap + at 250 ms). The lease was granted and the claim written with it by + the majority, after the moment `asked`: the promote carries the + address itself, for what is left of the release time after that + moment, and the controller extends it once it renewed""" + + def test_the_address_is_on_wg0_when_the_promote_returns(self): + with mock.patch.object(vippromote, "carried_soon", + side_effect=lambda here, vip: self.carried( + self.all.index(here))): + said: list[str] = [] + code = vippromote.promote(self.all[0], False, said.append) + self.assertEqual(code, exits.OK, said) + self.assertTrue(self.carried(0)) + lifetime = self.nets[0].lifetimes[f"{VIP}/128"] + self.assertIsNotNone(lifetime) + self.assertLessEqual(lifetime, vipetcd.RELEASE_AFTER) + + def test_too_old_a_lease_is_left_to_the_controller(self): + real = vipetcd.claim + + def slow(*args, **kwargs): + made = real(*args, **kwargs) + self.sleep(vipetcd.RELEASE_AFTER) + return made + with mock.patch.object(vipetcd, "claim", side_effect=slow), \ + mock.patch.object(vippromote, "carried_soon", + side_effect=self.carry_soon): + said: list[str] = [] + code = vippromote.promote(self.all[0], False, said.append) + self.assertEqual(code, exits.OK, said) + self.assertTrue(self.carried(0)) + + +class TestAPlannedPromoteDoesNotWaitForTheLease(ClaimCase): + def test_a_released_primary_s_lease_is_not_waited_for(self): + """keel#138: the primary that released dropped the address first + and revoked its own lease; the claim's compare-and-swap is on the + counter alone, so the promote claims at once (a second of etcd + calls at 250 ms)""" + self.promote(0) + self.turn() + self.kv.calls.clear() + code, said = self.promote(1) + self.assertEqual(code, exits.OK, said) + self.assertIn("released by", said) + self.assertNotIn("waiting for the primary's lease", said) + self.assertNotIn("time_to_live", self.kv.calls[:self.kv.calls.index( + "swap")]) + self.assertEqual(self.holds(), [1]) diff --git a/tests/test_mesh_vipetcd.py b/tests/test_mesh_vipetcd.py index a3a99a2..5f07e53 100644 --- a/tests/test_mesh_vipetcd.py +++ b/tests/test_mesh_vipetcd.py @@ -313,14 +313,18 @@ def test_another_node_s_claim_came_first_or_its_own(self): said.append), exits.APPLY_FAILED) def test_promote_finds_its_own_controller_claimed_while_it_waited(self): + """With the old primary gone (a released one is not waited for, + keel#138), the promote waits for its lease, and its own + controller may claim meanwhile""" self.promote(0) self.turn() + self.down.add(address(0)) with mock.patch.object(vippromote, "gone_lease", side_effect=lambda here, vip, lease, wait: self.own_claim(1)): with mock.patch.object(vippromote, "carried_soon", return_value=True): - code, said = self.promote(1) + code, said = self.promote(1, gone=True) self.assertEqual(code, exits.OK, said) self.assertIn("claimed by its controller", said) diff --git a/tests/test_mesh_vipmove.py b/tests/test_mesh_vipmove.py index 5e4105f..fec1e5b 100644 --- a/tests/test_mesh_vipmove.py +++ b/tests/test_mesh_vipmove.py @@ -575,3 +575,60 @@ def test_an_epoch_answer_for_another_vip_or_unverified(self): if __name__ == "__main__": unittest.main() + + +class TestTheReleaseQuiescesTheDatabase(Pair): + """keel#138: a write in flight at the release lost its answer: the + old primary dropped the VIP while the commit waited for the + replica's acknowledgement. The database turns read only first, + which waits for the commits in flight (the replica is still + connected), and only then is the address dropped""" + + def promote(self, index: int) -> tuple[int, str]: + said: list[str] = [] + code = vippromote.promote(self.all[index], False, said.append) + return code, "\n".join(said) + + def test_the_database_is_read_only_before_the_address_goes(self): + from unittest import mock + from keel.mesh import vipserve + self.nodes() + self.promote(0) + order: list[str] = [] + node = self.all[0].node + real = node.run + + def run(argv): + if argv[:4] == ("ip", "-6", "addr", "del"): + order.append("drop") + return real(argv) + node.run = run + with mock.patch.object(vipserve, "quiesced", + side_effect=lambda here, vip: + order.append("read only")): + code, said = self.promote(1) + self.assertEqual(code, exits.OK, said) + self.assertEqual(order[:2], ["read only", "drop"], order) + + def test_quiesced_asks_the_database_only_where_one_is_declared(self): + from unittest import mock + from keel.mesh import vipserve + self.nodes() + here = self.all[0] + with mock.patch("keel.system.dbreadonly.quiesce", + return_value=None) as asked: + vipserve.quiesced(here, VIP) + asked.assert_not_called() + doc = here.node.document() + doc["database"] = {"server": {"engine": "mariadb", + "role": "primary"}} + here.node.write(doc) + with mock.patch("keel.system.dbreadonly.quiesce", + return_value=None) as asked: + vipserve.quiesced(here, VIP) + asked.assert_called_once() + self.assertIn("read only before the release", self.text(0)) + with mock.patch("keel.system.dbreadonly.quiesce", + return_value="ERROR 2002"): + vipserve.quiesced(here, VIP) + self.assertIn("ERROR 2002); the release goes on", self.text(0)) diff --git a/tests/test_system_dbreadonly.py b/tests/test_system_dbreadonly.py index 9e3443f..4dafa34 100644 --- a/tests/test_system_dbreadonly.py +++ b/tests/test_system_dbreadonly.py @@ -603,3 +603,30 @@ def test_the_actions_say_what_they_do(self): self.assertIn(dbreadonly.RECORD, LockReplica(()).describe()) self.assertIn("READ_ONLY ADMIN back", UnlockAccounts().describe()) self.assertIn("wait up to 60 s", PromoteReplica(60).describe()) + + +class TestQuiesce(unittest.TestCase): + """keel#138: read_only on, waited for up to QUIESCE_TIMEOUT: it + waits for the commits in flight, which wait for the replica""" + + def test_read_only_on_by_the_server_s_own_account(self): + runner = Runner() + self.assertIsNone(dbreadonly.quiesce(runner)) + self.assertEqual(runner.calls[0][1], "SET GLOBAL read_only = ON;\n") + self.assertEqual(runner.argv[0][:4], ["runuser", "-u", "mysql", + "--"]) + + def test_a_server_that_does_not_answer_in_time_is_said(self): + def slow(argv, **kwargs): + self.assertEqual(kwargs["timeout"], dbreadonly.QUIESCE_TIMEOUT) + raise subprocess.TimeoutExpired(argv, kwargs["timeout"]) + self.assertIn("did not turn read only within", + dbreadonly.quiesce(slow)) + + def test_a_failure_is_said(self): + self.assertIn("ERROR 2002", dbreadonly.quiesce( + Runner({"other": (1, "", "ERROR 2002")}))) + + def missing(argv, **kwargs): + raise FileNotFoundError(2, "No such file or directory") + self.assertIn("cannot run runuser", dbreadonly.quiesce(missing))