fix(xceadmin): retry transient scheduler-admin failures after a redirect (bug-1713, bug-1715)
Once bug-1700/1701's server-side redirect fix landed, xceadmin scheduler
record status/start/stop against a standby correctly redirects to the
primary -- but the redirected request can still transiently fail if that
node is mid-(re-)election (-10013 E_XCE_NOT_READY, expected/normal right
after a redirect on a freshly-booted or just-failed-over cluster) or if
the scheduler connection was mid-reconnect (schedadminreplymsg{ok=false,
error="scheduler disconnected"}, a different, non-numeric signaling path
via bug-1693's disconnect-detection mechanism).
bug-1713: _send_admin_request() wraps the request/redirect/decode cycle
in a bounded retry loop, re-running follow_redirects() FROM SCRATCH each
attempt (not a bare resend to the same host:port) so a later attempt can
discover a newly-settled or different primary.
bug-1715: extends the same retry loop to the second, differently-signaled
transient family -- checks admin_reply.error against a module-level
frozenset of known-transient reason strings.
Live-verified on a real 3-node cluster.
Co-Authored-By: Claude Sonnet 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01AgYRU3zDTqNGV5Jk8aiKLg
This commit is contained in:
parent
0ebf3a817f
commit
cfd7db8cd1
2 changed files with 591 additions and 34 deletions
|
|
@ -330,12 +330,30 @@ def test_record_stop_not_recording_raises_sched_admin_error(mock_controller, wra
|
|||
|
||||
|
||||
@pytest.mark.parametrize(
|
||||
"error_reason", ["scheduler not connected", "request timeout", "invalid record file name"]
|
||||
"error_reason",
|
||||
[
|
||||
"invalid record file name",
|
||||
"record directory not found",
|
||||
"permission denied accessing record file",
|
||||
],
|
||||
)
|
||||
def test_record_start_error_codes_raise_sched_admin_error(mock_controller, wrap_reply, error_reason):
|
||||
"""requirements.md's "Error codes reference" table -- every listed
|
||||
``SchedAdminReply{ok=false, error=...}`` reason raises the same typed
|
||||
error, regardless of which specific reason string the reply carries.
|
||||
``SchedAdminReply{ok=false, error=...}`` PERMANENT reason (driver.c's
|
||||
``validation_error_text()`` filename/path-rejection strings) raises the
|
||||
same typed error immediately, on the first attempt, regardless of which
|
||||
specific reason string the reply carries. Uses the one-shot
|
||||
``mock_controller`` fixture deliberately (not ``sequential_mock_
|
||||
controller``): if bug-1715's new admin-reason retry logic ever
|
||||
incorrectly treated one of these as transient, a second connection
|
||||
attempt against this one-shot server would fail with a connection
|
||||
error instead of the expected ``SchedAdminError``, independently
|
||||
proving single-attempt behavior.
|
||||
|
||||
bug-1715: "scheduler not connected" and "request timeout" used to be
|
||||
tested here too, but are now confirmed-transient reasons (module
|
||||
comment on ``scheduler._TRANSIENT_ADMIN_REASONS``) and are retried, not
|
||||
raised immediately -- moved to the dedicated retry tests below.
|
||||
"""
|
||||
mod = load_schema()
|
||||
|
||||
|
|
@ -400,6 +418,409 @@ def test_record_start_propagates_no_primary_error_on_connection_timeout(monkeypa
|
|||
scheduler.record_start("127.0.0.1:9991")
|
||||
|
||||
|
||||
# ---------------------------------------------------------------------------
|
||||
# bug-1713: E_XCE_NOMASTER (-10011) / E_XCE_NOT_READY (-10013) are transient
|
||||
# "no settled primary right now" conditions -- retried with a bounded
|
||||
# budget instead of failing immediately, unlike every other nonzero status.
|
||||
# E_XCE_STANDBY (-10014) is deliberately NOT part of this: it is resolved
|
||||
# purely by follow_redirects()'s existing redirect-following (bug-1701),
|
||||
# regression-locked at the bottom of this section.
|
||||
#
|
||||
# Uses a dedicated multi-connection mock server (_SequentialMockController)
|
||||
# rather than the module's single-shot ``mock_controller`` fixture:
|
||||
# scheduler.py's retry loop re-runs follow_redirects() from scratch on each
|
||||
# attempt (a fresh TCP connection), not a resend over one held connection,
|
||||
# so these tests must let the mock server accept more than one connection
|
||||
# on the same port.
|
||||
# ---------------------------------------------------------------------------
|
||||
|
||||
|
||||
class _SequentialMockController:
|
||||
"""Like ``_MockController`` above, but accepts exactly ``len(handlers)``
|
||||
connections in sequence on the same port (not just one), handing each
|
||||
accepted TLS connection to the next handler in ``handlers`` in order --
|
||||
module section docstring above explains why this is needed for
|
||||
bug-1713's retry tests specifically, instead of reusing
|
||||
``_MockController``. Callers pass exactly as many handlers as
|
||||
connections they expect (proven independently via
|
||||
``connection_count``) -- the accept loop is a plain, finite ``for``
|
||||
over ``handlers``, so it never blocks waiting for a connection beyond
|
||||
what the test itself expects, and closes/joins promptly in ``close()``
|
||||
even when a test ends early. A short accept timeout is still set as a
|
||||
safety net: if a regression ever made the client under test connect
|
||||
MORE times than the test provisioned handlers for, this server exits
|
||||
its loop and closes within one timeout window rather than blocking
|
||||
``close()``'s ``join()`` for its full grace period.
|
||||
"""
|
||||
|
||||
_ACCEPT_TIMEOUT_S = 2.0
|
||||
|
||||
def __init__(self, handlers, cert_file: Path, key_file: Path):
|
||||
self._handlers = list(handlers)
|
||||
self._cert_file = cert_file
|
||||
self._key_file = key_file
|
||||
self._listener = socket.socket(socket.AF_INET, socket.SOCK_STREAM)
|
||||
self._listener.bind(("127.0.0.1", 0))
|
||||
self._listener.listen(5)
|
||||
self._listener.settimeout(self._ACCEPT_TIMEOUT_S)
|
||||
self.port = self._listener.getsockname()[1]
|
||||
self.connection_count = 0
|
||||
self._thread = threading.Thread(target=self._run, daemon=True)
|
||||
self._thread.start()
|
||||
|
||||
def _run(self) -> None:
|
||||
for handler in self._handlers:
|
||||
try:
|
||||
raw_conn, _ = self._listener.accept()
|
||||
except OSError:
|
||||
return
|
||||
self.connection_count += 1
|
||||
try:
|
||||
tls_conn = _server_context(self._cert_file, self._key_file).wrap_socket(
|
||||
raw_conn, server_side=True
|
||||
)
|
||||
except (ssl.SSLError, OSError):
|
||||
raw_conn.close()
|
||||
continue
|
||||
try:
|
||||
handler(tls_conn)
|
||||
except OSError:
|
||||
pass
|
||||
finally:
|
||||
tls_conn.close()
|
||||
|
||||
def close(self) -> None:
|
||||
self._listener.close()
|
||||
self._thread.join(timeout=self._ACCEPT_TIMEOUT_S + 1)
|
||||
|
||||
|
||||
@pytest.fixture
|
||||
def sequential_mock_controller(tls_certs):
|
||||
servers: list[_SequentialMockController] = []
|
||||
|
||||
def _make(handlers) -> _SequentialMockController:
|
||||
srv = _SequentialMockController(handlers, tls_certs.cert_file, tls_certs.key_file)
|
||||
servers.append(srv)
|
||||
return srv
|
||||
|
||||
yield _make
|
||||
for srv in servers:
|
||||
srv.close()
|
||||
|
||||
|
||||
@pytest.mark.parametrize(
|
||||
"transient_status",
|
||||
[scheduler._E_XCE_NOT_READY, scheduler._E_XCE_NOMASTER],
|
||||
ids=["not_ready", "nomaster"],
|
||||
)
|
||||
def test_record_status_retries_on_transient_status_then_succeeds(
|
||||
sequential_mock_controller, wrap_reply, monkeypatch, transient_status
|
||||
):
|
||||
"""bug-1713's core proof: a mocked server returning a transient status
|
||||
(E_XCE_NOT_READY or E_XCE_NOMASTER) twice, then succeeding on the 3rd
|
||||
attempt, results in the CLIENT EVENTUALLY SUCCEEDING -- not an
|
||||
immediate raise. FAILS against the pre-fix code (which raises
|
||||
SchedAdminError on the very first reply)."""
|
||||
mod = load_schema()
|
||||
sleep_calls: list[float] = []
|
||||
monkeypatch.setattr(scheduler.time, "sleep", lambda s: sleep_calls.append(s))
|
||||
|
||||
def _not_ready_handler(conn):
|
||||
wire.recv_frame(conn)
|
||||
reply = mod.RequestReply.new_message()
|
||||
reply.status = transient_status
|
||||
reply.data.nodata = None
|
||||
wire.send_frame(conn, wrap_reply(reply))
|
||||
|
||||
def _success_handler(conn):
|
||||
wire.recv_frame(conn)
|
||||
reply = mod.RequestReply.new_message()
|
||||
reply.status = 0
|
||||
admin_reply = reply.data.init("schedadminreplymsg")
|
||||
admin_reply.ok = True
|
||||
admin_reply.error = ""
|
||||
admin_reply.recording = True
|
||||
admin_reply.file = "settled.replay"
|
||||
admin_reply.eventCount = 0
|
||||
admin_reply.startedAt = 6000
|
||||
wire.send_frame(conn, wrap_reply(reply))
|
||||
|
||||
srv = sequential_mock_controller([_not_ready_handler, _not_ready_handler, _success_handler])
|
||||
|
||||
result = scheduler.record_status(f"127.0.0.1:{srv.port}")
|
||||
|
||||
assert result.file == "settled.replay"
|
||||
assert srv.connection_count == 3
|
||||
# Slept between attempt 1->2 and 2->3, but not after the final success.
|
||||
assert sleep_calls == [scheduler._TRANSIENT_RETRY_DELAY_S] * 2
|
||||
|
||||
|
||||
def test_record_status_retry_exhaustion_raises_distinguishable_error(
|
||||
sequential_mock_controller, wrap_reply, monkeypatch
|
||||
):
|
||||
"""A mocked server that ALWAYS returns E_XCE_NOT_READY (never
|
||||
recovers) must make the client eventually give up with a clear,
|
||||
distinguishable SchedAdminError after the retry budget is exhausted --
|
||||
not a silent hang or an infinite loop. ``time.sleep`` is monkeypatched
|
||||
so this test does not actually wait out the real retry delay."""
|
||||
mod = load_schema()
|
||||
sleep_calls: list[float] = []
|
||||
monkeypatch.setattr(scheduler.time, "sleep", lambda s: sleep_calls.append(s))
|
||||
|
||||
def _not_ready_handler(conn):
|
||||
wire.recv_frame(conn)
|
||||
reply = mod.RequestReply.new_message()
|
||||
reply.status = scheduler._E_XCE_NOT_READY
|
||||
reply.data.nodata = None
|
||||
wire.send_frame(conn, wrap_reply(reply))
|
||||
|
||||
# Exactly the retry budget's worth of handlers: connection_count is
|
||||
# asserted below to equal _MAX_TRANSIENT_ATTEMPTS exactly, proving the
|
||||
# client stops on its OWN bounded budget -- not a weaker "it didn't
|
||||
# exceed however many the mock happened to provide" proof.
|
||||
srv = sequential_mock_controller([_not_ready_handler] * scheduler._MAX_TRANSIENT_ATTEMPTS)
|
||||
|
||||
with pytest.raises(SchedAdminError) as exc_info:
|
||||
scheduler.record_status(f"127.0.0.1:{srv.port}")
|
||||
|
||||
assert srv.connection_count == scheduler._MAX_TRANSIENT_ATTEMPTS
|
||||
assert len(sleep_calls) == scheduler._MAX_TRANSIENT_ATTEMPTS - 1
|
||||
# Distinguishable from an immediate, non-retried hard failure: the
|
||||
# message names both the raw status and that retries were exhausted.
|
||||
assert str(scheduler._E_XCE_NOT_READY) in exc_info.value.error
|
||||
assert "giving up" in exc_info.value.error
|
||||
assert f"{scheduler._MAX_TRANSIENT_ATTEMPTS} attempts" in exc_info.value.error
|
||||
|
||||
|
||||
def test_record_status_standby_without_redirect_not_retried(mock_controller, wrap_reply, monkeypatch):
|
||||
"""A standby rejection with NO populated redirect (the genuine "op is
|
||||
primary-only, no known primary to redirect to" case) is a hard,
|
||||
non-transient failure -- bug-1713's new retry logic must NOT retry it.
|
||||
Regression-locks E_XCE_STANDBY (-10014) being excluded from
|
||||
``_TRANSIENT_STATUSES``. Uses the single-shot ``mock_controller``
|
||||
fixture deliberately: if this ever DID retry, the client's second
|
||||
connection attempt would stall against a listener with no more
|
||||
accepting thread, independently proving single-attempt behavior beyond
|
||||
just the ``sleep_calls`` assertion below.
|
||||
"""
|
||||
mod = load_schema()
|
||||
sleep_calls: list[float] = []
|
||||
monkeypatch.setattr(scheduler.time, "sleep", lambda s: sleep_calls.append(s))
|
||||
|
||||
def _handler(conn):
|
||||
wire.recv_frame(conn)
|
||||
reply = mod.RequestReply.new_message()
|
||||
reply.status = -10014 # E_XCE_STANDBY, errnox.h XCE_ERRNO_BASE+13
|
||||
reply.data.nodata = None
|
||||
wire.send_frame(conn, wrap_reply(reply))
|
||||
|
||||
srv = mock_controller(_handler)
|
||||
|
||||
with pytest.raises(SchedAdminError) as exc_info:
|
||||
scheduler.record_status(f"127.0.0.1:{srv.port}")
|
||||
|
||||
assert "-10014" in exc_info.value.error
|
||||
assert sleep_calls == []
|
||||
|
||||
|
||||
def test_record_status_standby_with_redirect_follows_redirect_not_retried(
|
||||
mock_controller, wrap_reply, monkeypatch
|
||||
):
|
||||
"""Mirrors the real controller's actual on-wire behavior for a standby
|
||||
hit that DOES know the primary (bug-1700/1701's fill_redirect_reply()
|
||||
call sends ``status=-XCE_ERR_STANDBY`` TOGETHER WITH a populated
|
||||
redirect) -- unlike ``test_record_start_follows_one_redirect_to_primary``'s
|
||||
``status=0`` placeholder. Proves this fix does not disturb that
|
||||
already-fixed, live-verified path: the redirect is followed exactly as
|
||||
before, with zero involvement of the new retry logic (no sleep calls).
|
||||
"""
|
||||
mod = load_schema()
|
||||
sleep_calls: list[float] = []
|
||||
monkeypatch.setattr(scheduler.time, "sleep", lambda s: sleep_calls.append(s))
|
||||
|
||||
def _standby_handler(conn):
|
||||
wire.recv_frame(conn)
|
||||
reply = mod.RequestReply.new_message()
|
||||
reply.status = -10014 # E_XCE_STANDBY
|
||||
reply.redirectHost = "127.0.0.1"
|
||||
reply.redirectPort = _standby_handler.primary_port
|
||||
reply.data.nodata = None
|
||||
wire.send_frame(conn, wrap_reply(reply))
|
||||
|
||||
def _primary_handler(conn):
|
||||
wire.recv_frame(conn)
|
||||
reply = mod.RequestReply.new_message()
|
||||
reply.status = 0
|
||||
admin_reply = reply.data.init("schedadminreplymsg")
|
||||
admin_reply.ok = True
|
||||
admin_reply.error = ""
|
||||
admin_reply.recording = True
|
||||
admin_reply.file = "on-primary-after-standby-redirect.replay"
|
||||
admin_reply.eventCount = 0
|
||||
admin_reply.startedAt = 3000
|
||||
wire.send_frame(conn, wrap_reply(reply))
|
||||
|
||||
primary_srv = mock_controller(_primary_handler)
|
||||
_standby_handler.primary_port = primary_srv.port
|
||||
standby_srv = mock_controller(_standby_handler)
|
||||
|
||||
result = scheduler.record_status(f"127.0.0.1:{standby_srv.port}")
|
||||
|
||||
assert result.file == "on-primary-after-standby-redirect.replay"
|
||||
assert sleep_calls == []
|
||||
|
||||
|
||||
# ---------------------------------------------------------------------------
|
||||
# bug-1715: a SECOND, differently-signaled transient family on top of
|
||||
# bug-1713's numeric-status one above -- RequestReply.status == 0 (RPC
|
||||
# succeeded) but SchedAdminReply{ok=false, error=<reason>} for one of the
|
||||
# four confirmed-transient reason strings in
|
||||
# ``scheduler._TRANSIENT_ADMIN_REASONS`` ("scheduler disconnected",
|
||||
# "scheduler not connected", "request timeout", "server busy, try again").
|
||||
# Reuses the exact same retry loop/budget/delay and the same
|
||||
# ``sequential_mock_controller`` fixture bug-1713 introduced above --
|
||||
# these replies also require a fresh reconnect per attempt.
|
||||
# ---------------------------------------------------------------------------
|
||||
|
||||
|
||||
@pytest.mark.parametrize(
|
||||
"transient_reason",
|
||||
sorted(scheduler._TRANSIENT_ADMIN_REASONS),
|
||||
)
|
||||
def test_record_status_retries_on_transient_admin_reason_then_succeeds(
|
||||
sequential_mock_controller, wrap_reply, monkeypatch, transient_reason
|
||||
):
|
||||
"""bug-1715's core proof: a mocked server returning
|
||||
``ok=false, error=<transient_reason>`` twice, then succeeding on the
|
||||
3rd attempt, results in the CLIENT EVENTUALLY SUCCEEDING -- not an
|
||||
immediate raise. FAILS against the bug-1713-only code (which has no
|
||||
concept of ``_TRANSIENT_ADMIN_REASONS`` and raises SchedAdminError on
|
||||
the very first ok=false reply, regardless of reason string)."""
|
||||
mod = load_schema()
|
||||
sleep_calls: list[float] = []
|
||||
monkeypatch.setattr(scheduler.time, "sleep", lambda s: sleep_calls.append(s))
|
||||
|
||||
def _transient_handler(conn):
|
||||
wire.recv_frame(conn)
|
||||
reply = mod.RequestReply.new_message()
|
||||
reply.status = 0
|
||||
admin_reply = reply.data.init("schedadminreplymsg")
|
||||
admin_reply.ok = False
|
||||
admin_reply.error = transient_reason
|
||||
admin_reply.recording = False
|
||||
admin_reply.file = ""
|
||||
admin_reply.eventCount = 0
|
||||
admin_reply.startedAt = 0
|
||||
wire.send_frame(conn, wrap_reply(reply))
|
||||
|
||||
def _success_handler(conn):
|
||||
wire.recv_frame(conn)
|
||||
reply = mod.RequestReply.new_message()
|
||||
reply.status = 0
|
||||
admin_reply = reply.data.init("schedadminreplymsg")
|
||||
admin_reply.ok = True
|
||||
admin_reply.error = ""
|
||||
admin_reply.recording = True
|
||||
admin_reply.file = "settled-after-admin-retry.replay"
|
||||
admin_reply.eventCount = 0
|
||||
admin_reply.startedAt = 7000
|
||||
wire.send_frame(conn, wrap_reply(reply))
|
||||
|
||||
srv = sequential_mock_controller([_transient_handler, _transient_handler, _success_handler])
|
||||
|
||||
result = scheduler.record_status(f"127.0.0.1:{srv.port}")
|
||||
|
||||
assert result.file == "settled-after-admin-retry.replay"
|
||||
assert srv.connection_count == 3
|
||||
assert sleep_calls == [scheduler._TRANSIENT_RETRY_DELAY_S] * 2
|
||||
|
||||
|
||||
@pytest.mark.parametrize(
|
||||
"transient_reason",
|
||||
sorted(scheduler._TRANSIENT_ADMIN_REASONS),
|
||||
)
|
||||
def test_record_status_retry_exhaustion_on_transient_admin_reason_raises_distinguishable_error(
|
||||
sequential_mock_controller, wrap_reply, monkeypatch, transient_reason
|
||||
):
|
||||
"""A mocked server that ALWAYS returns the same transient admin reason
|
||||
(never recovers) must make the client eventually give up with a clear,
|
||||
distinguishable SchedAdminError after the retry budget is exhausted --
|
||||
not a silent hang or an infinite loop. ``time.sleep`` is monkeypatched
|
||||
so this test does not actually wait out the real retry delay."""
|
||||
mod = load_schema()
|
||||
sleep_calls: list[float] = []
|
||||
monkeypatch.setattr(scheduler.time, "sleep", lambda s: sleep_calls.append(s))
|
||||
|
||||
def _transient_handler(conn):
|
||||
wire.recv_frame(conn)
|
||||
reply = mod.RequestReply.new_message()
|
||||
reply.status = 0
|
||||
admin_reply = reply.data.init("schedadminreplymsg")
|
||||
admin_reply.ok = False
|
||||
admin_reply.error = transient_reason
|
||||
admin_reply.recording = False
|
||||
admin_reply.file = ""
|
||||
admin_reply.eventCount = 0
|
||||
admin_reply.startedAt = 0
|
||||
wire.send_frame(conn, wrap_reply(reply))
|
||||
|
||||
# Exactly the retry budget's worth of handlers: connection_count is
|
||||
# asserted below to equal _MAX_TRANSIENT_ATTEMPTS exactly, proving the
|
||||
# client stops on its OWN bounded budget.
|
||||
srv = sequential_mock_controller([_transient_handler] * scheduler._MAX_TRANSIENT_ATTEMPTS)
|
||||
|
||||
with pytest.raises(SchedAdminError) as exc_info:
|
||||
scheduler.record_status(f"127.0.0.1:{srv.port}")
|
||||
|
||||
assert srv.connection_count == scheduler._MAX_TRANSIENT_ATTEMPTS
|
||||
assert len(sleep_calls) == scheduler._MAX_TRANSIENT_ATTEMPTS - 1
|
||||
# Distinguishable from an immediate, non-retried hard failure: the
|
||||
# message names both the original reason and that retries were
|
||||
# exhausted.
|
||||
assert transient_reason in exc_info.value.error
|
||||
assert "giving up" in exc_info.value.error
|
||||
assert f"{scheduler._MAX_TRANSIENT_ATTEMPTS} attempts" in exc_info.value.error
|
||||
|
||||
|
||||
def test_record_stop_not_recording_never_retried(sequential_mock_controller, wrap_reply, monkeypatch):
|
||||
"""bug-1715 non-regression: "not recording" (driver.c:426, rc==
|
||||
-EALREADY on an already-stopped recorder) is a genuine, PERMANENT
|
||||
domain rejection -- NOT in ``_TRANSIENT_ADMIN_REASONS`` -- so it must
|
||||
keep failing on the very first attempt, exactly like today's (pre-
|
||||
bug-1715) behavior, with zero retries/sleeps. Uses
|
||||
``sequential_mock_controller`` (rather than the plain one-shot
|
||||
``mock_controller``) specifically so ``connection_count`` can assert
|
||||
``== 1`` explicitly, on top of the implicit proof that a real retry
|
||||
attempt against a server with only one handler queued would raise a
|
||||
connection error instead of ``SchedAdminError``.
|
||||
"""
|
||||
mod = load_schema()
|
||||
sleep_calls: list[float] = []
|
||||
monkeypatch.setattr(scheduler.time, "sleep", lambda s: sleep_calls.append(s))
|
||||
|
||||
def _handler(conn):
|
||||
wire.recv_frame(conn)
|
||||
reply = mod.RequestReply.new_message()
|
||||
reply.status = 0
|
||||
admin_reply = reply.data.init("schedadminreplymsg")
|
||||
admin_reply.ok = False
|
||||
admin_reply.error = "not recording"
|
||||
admin_reply.recording = False
|
||||
admin_reply.file = ""
|
||||
admin_reply.eventCount = 0
|
||||
admin_reply.startedAt = 0
|
||||
wire.send_frame(conn, wrap_reply(reply))
|
||||
|
||||
srv = sequential_mock_controller([_handler])
|
||||
|
||||
with pytest.raises(SchedAdminError) as exc_info:
|
||||
scheduler.record_stop(f"127.0.0.1:{srv.port}")
|
||||
|
||||
assert exc_info.value.error == "not recording"
|
||||
assert srv.connection_count == 1
|
||||
assert sleep_calls == []
|
||||
|
||||
|
||||
# ---------------------------------------------------------------------------
|
||||
# _split_controller(): same default-port convention as push.py
|
||||
# ---------------------------------------------------------------------------
|
||||
|
|
|
|||
Loading…
Add table
Add a link
Reference in a new issue