fix: the new primary takes writes as soon as it carries the VIP (keel#118) #122

Merged

marcos-mendez merged 1 commit from fix/follow-writable-when-the-vip-lands into main

2026-10-09 06:09:11 -03:00

marcos-mendez commented

2026-10-09 02:06:26 -03:00

(Migrated from github.com)

Fixes #118 (finding N2 of the 0.23.7 rollout, Keel-Linux/handbook#62). Rebased on main after #121 and #127; version 0.23.10.

Problem

After keel vip promote --old-primary-gone, the new primary refused writes (ERROR 1290) for 11.7 s while it carried the VIP. keel database follow promoted the database 7.5 s after the VIP landed.

Cause (measured on MariaDB 11.8)

Not the path unit, the poll or the follow lock: STOP SLAVE IO_THREAD returns only when the I/O thread ends. With the primary gone:

a thread that tries to connect ends when the try times out, slave_net_timeout (6.9 s after a 3 s wait; 2.96 s with 3 s);
a connected thread with semi-synchronous replication tries to connect to the primary to end its dump thread ("cannot connect to master to kill slave io_thread's connection"): 5.06 s; 0.07 s without semi-synchronous replication;
a KILL of the thread does not shorten either; STOP SLAVE SQL_THREAD waits behind the I/O stop (4.71 s).

The status shows Ending IO thread at once: the thread receives nothing from the moment the stop marks it killed.

Change (after the safety reviews)

keel/system/dbreadonly.py (promote): the stop runs in a client of its own. read_only goes off before the stop ends only when all of this holds:

the stop is in the server's killing phase (its process list STATE is Killing slave; INFO is set at dispatch, before the stop takes its lock, so it is not used alone), or it ended without an error, before the drain and again after it: the server marks the I/O thread killed in that phase, and a killed thread receives no more events (it leaves its read loop; one that connects again, MASTER_CONNECT_RETRY=2, ends before it asks for the binary log);
the SQL thread applied everything received (the drain);
the received position read after the drain is the drained one.

Otherwise the old order applies: the stop waited for, the drain again, then STOP SLAVE; RESET SLAVE ALL; read_only OFF. The guarantee is the old order's: read_only goes off only once the I/O thread receives nothing and the SQL thread applied all it received. The SQL thread is not stopped first (it has nothing more to apply, and STOP SLAVE SQL_THREAD waits behind the I/O stop). STOP SLAVE; RESET SLAVE ALL run while the server already takes writes, and the stop is waited for.

A planned promote now takes the same path; its stop ends at once, since the primary answers.

A stop client that failed after the server may have taken the statement starts the I/O thread again (START SLAVE IO_THREAD), and says nothing was promoted.
Spec apply's SeedReplica and PromoteReplica (keel/system/effects.py) take follow's lock (dbreadonly.replication_locked, /var/lib/keel/database/follow.lock), so apply, follow and watch never interleave between the checks and read_only OFF.
PROOF_POLL 0.2 s. docs/replication.md; debian/changelog 0.23.10.

Against a frozen primary on the local 11.8: writable 0.33 s after the promotion started (0.26 s with the thread connecting), against 5 s and 7 s before.

Tests

The writes before the stop ends; a stop not in the killing phase after the drain takes the old order; anything received after the drain takes the old order; a failed stop client resumes the I/O thread; a stop the server does not show is waited for first; a stop that fails changes nothing; each failure. tests/mariadb_netns.py: dbpromote no longer holds the agent's lock, as on a machine; the crash case asserts writable within 3 s after the VIP lands and 0 acknowledged rows lost.

Measured (`mariadb / trixie`, etcd, 250 ms ±25 ms, 2 % loss)

	before (#121 alone)	`572d20d`
server writable after the VIP landed	8.8 s	1.39 s
acknowledged rows lost	0	0

The write downtime (24.7 s in this run) is the old primary's lease (0049, the VIP landed at 20.9 s) plus 2.4 s; #124 measures cloud simple. The crash case now kills A only once C's writes were acknowledged, and runs the promote again (at most three times, attempts kept) when etcd had no leader to answer; in this run one attempt was enough.

CI record

Green at 572d20d at the first run, no rerun. 0b6d90f (the rebase on #127) failed mariadb / trixie in the harness: no write was acknowledged before the kill (no start for the downtime), and in #124's run of the same commit the promote met etcd did not answer (A, cut off, was etcd's leader); both fixed in the harness in 572d20d. Earlier heads: see the history of this PR.

Fixes #118 (finding N2 of the 0.23.7 rollout, Keel-Linux/handbook#62). Rebased on main after #121 and #127; version 0.23.10. ## Problem After `keel vip promote --old-primary-gone`, the new primary refused writes (ERROR 1290) for 11.7 s while it carried the VIP. `keel database follow` promoted the database 7.5 s after the VIP landed. ## Cause (measured on MariaDB 11.8) Not the path unit, the poll or the follow lock: `STOP SLAVE IO_THREAD` returns only when the I/O thread ends. With the primary gone: - a thread that tries to connect ends when the try times out, `slave_net_timeout` (6.9 s after a 3 s wait; 2.96 s with 3 s); - a connected thread with semi-synchronous replication tries to connect to the primary to end its dump thread ("cannot connect to master to kill slave io_thread's connection"): 5.06 s; 0.07 s without semi-synchronous replication; - a `KILL` of the thread does not shorten either; `STOP SLAVE SQL_THREAD` waits behind the I/O stop (4.71 s). The status shows `Ending IO thread` at once: the thread receives nothing from the moment the stop marks it killed. ## Change (after the safety reviews) `keel/system/dbreadonly.py` (`promote`): the stop runs in a client of its own. read_only goes off before the stop ends only when all of this holds: - the stop is in the server's killing phase (its process list `STATE` is `Killing slave`; `INFO` is set at dispatch, before the stop takes its lock, so it is not used alone), or it ended without an error, **before the drain and again after it**: the server marks the I/O thread killed in that phase, and a killed thread receives no more events (it leaves its read loop; one that connects again, `MASTER_CONNECT_RETRY=2`, ends before it asks for the binary log); - the SQL thread applied everything received (the drain); - the received position read after the drain is the drained one. Otherwise the old order applies: the stop waited for, the drain again, then `STOP SLAVE; RESET SLAVE ALL; read_only OFF`. The guarantee is the old order's: read_only goes off only once the I/O thread receives nothing and the SQL thread applied all it received. The SQL thread is not stopped first (it has nothing more to apply, and `STOP SLAVE SQL_THREAD` waits behind the I/O stop). `STOP SLAVE; RESET SLAVE ALL` run while the server already takes writes, and the stop is waited for. **A planned promote now takes the same path**; its stop ends at once, since the primary answers. - A stop client that failed after the server may have taken the statement starts the I/O thread again (`START SLAVE IO_THREAD`), and says nothing was promoted. - Spec apply's `SeedReplica` and `PromoteReplica` (`keel/system/effects.py`) take follow's lock (`dbreadonly.replication_locked`, `/var/lib/keel/database/follow.lock`), so apply, follow and watch never interleave between the checks and `read_only OFF`. - `PROOF_POLL` 0.2 s. `docs/replication.md`; `debian/changelog` 0.23.10. Against a frozen primary on the local 11.8: writable 0.33 s after the promotion started (0.26 s with the thread connecting), against 5 s and 7 s before. ## Tests The writes before the stop ends; a stop not in the killing phase after the drain takes the old order; anything received after the drain takes the old order; a failed stop client resumes the I/O thread; a stop the server does not show is waited for first; a stop that fails changes nothing; each failure. `tests/mariadb_netns.py`: `dbpromote` no longer holds the agent's lock, as on a machine; the crash case asserts writable within 3 s after the VIP lands and 0 acknowledged rows lost. ## Measured (`mariadb / trixie`, etcd, 250 ms ±25 ms, 2 % loss) | | before (#121 alone) | 572d20d | | --- | --- | --- | | server writable after the VIP landed | 8.8 s | 1.39 s | | acknowledged rows lost | 0 | 0 | The write downtime (24.7 s in this run) is the old primary's lease (0049, the VIP landed at 20.9 s) plus 2.4 s; #124 measures cloud simple. The crash case now kills A only once C's writes were acknowledged, and runs the promote again (at most three times, attempts kept) when etcd had no leader to answer; in this run one attempt was enough. ## CI record Green at 572d20d at the first run, no rerun. 0b6d90f (the rebase on #127) failed `mariadb / trixie` in the harness: no write was acknowledged before the kill (no start for the downtime), and in #124's run of the same commit the promote met `etcd did not answer` (A, cut off, was etcd's leader); both fixed in the harness in 572d20d. Earlier heads: see the history of this PR.

github-advanced-security[bot] (Migrated from github.com) reviewed

2026-10-09 02:56:03 -03:00

keel/system/dbreadonly.py

bandit /

Possible SQL injection vector through string-based query construction.

Show more details

## bandit / Possible SQL injection vector through string-based query construction. [Show more details](https://github.com/Keel-Linux/keel/security/code-scanning/29)