fix(gateway): redeliver a flood-refused final reply once the penalty passes - #103669
AlexxRussell wants to merge 5 commits into
Conversation
alt-glitch
added
type/bug
1ca8fbb to
067cc9a
Compare
There was a problem hiding this comment.
Verified on 067cc9a3. Two reproduced gaps:
-
flood_non_delivery_is_certainassumes raw text under 4096 UTF-16 units means one Telegram request. With"." * 3000, Markdown escaping produces 6000 units. Accept chunk 1 and returnRetryAfter=185on chunk 2: recovery incorrectly setsneeds_marker=False. Delete the raw-length certainty check and its UTF-16 helper/constant; keep the duplicate warning for flood recovery. That removes the faulty assumption without adding delivery tracking. The tradeoff is a warning even when nothing was delivered. -
In
_redeliver_failed_obligations_for_platform, makeclear_resume_pendingfail once when a flood retry becomes due._release_runtime_claim_quietchanges the error tosend_path_degraded, sopending_flood_retries()drops the row and the timer ends. Observed: no send, row('failed', 0, 'send_path_degraded'). Preserve flood retry eligibility when releasing that unsent claim, while retaining the resume-flag check.
Validation through scripts/run_tests.sh: 166 existing tests passed; two added regressions failed and their two controls passed. Tests use the real adapter/ledger/runner with a fake transport and clock. Full suite not run.
|
Thanks, both reproduced here as well, and both are fixed in the follow-up commit.
40 tests in |
|
Second pass after re-reviewing the branch end to end (f779842):
Body updated to match (43 tests, the mutation list, and the wording about what the platform may have accepted). |
|
Third pass (4914486): reverted the flood re-arm's ledger read to synchronous. Making it read in a worker thread (an earlier reviewer suggestion) opened a race — a flood refusal recorded during the thread's yield had its own reschedule request declined while the timer held its slot, and the timer then cleared the slot on a stale snapshot, stranding that reply until the next reconnect. The read is a single indexed SELECT, so the arm decision is now atomic with respect to concurrent schedule requests. Added a test that refuses a final during the timer's own send and asserts the same timer arms it. Body corrected. |
…passes, without a false duplicate marker The Telegram adapter fails a flood-controlled final send closed as flood_control:<seconds> so the send coroutine never sleeps a long penalty (NousResearch#91969), on the understanding that the delivery ledger owns the wait. The ledger did not: sweep_failed_for_runtime only replayed send_path_degraded rows, so a flood-refused row sat in 'failed' until the next restart, whose sweep_recoverable then redelivered it hours late prefixed with "Recovered reply, the gateway restarted during delivery, so this may be a duplicate". Observed: a reply refused at 08:58 UTC (both the MarkdownV2 send and the plain fallback got flood_control:185) arrived at 12:15 UTC after a restart, labelled as a possible duplicate although the platform had never accepted it. Ledger (gateway/delivery_ledger.py): - flood_control rows are runtime-retryable, but only once their own deadline has passed: the refusal's updated_at plus the platform's wait (flood_not_before). Neither an early timer nor a reconnect sweep spends a redelivery attempt inside the penalty window. - A flood refusal of a reply that fits in one Telegram message (4096 UTF-16 units) proves non-delivery, so that redelivery carries no duplicate marker. A chunked reply may have had its first chunk accepted before the refusal and keeps the marker. - Claiming a flood row clears the stale refusal (last_error NULL, state 'attempting'), so a resend interrupted before mark_delivered is seen as uncertain by the next boot and gets the marker. - At boot, a dead owner's flood row that is not yet due is adopted (owner re-stamped, no attempt spent) instead of being resent early. - pending_flood_retries() lists this process's waiting flood rows per adapter identity with the earliest deadline. Runner (gateway/run_startup.py): - _schedule_flood_redelivery arms one timer per adapter identity that runs the existing runtime sweep after the wait (capped at 15 minutes per sleep; the row's deadline, not the timer, decides eligibility, so a capped timer wakes early, sends nothing, and re-arms for the remainder). The slot stays occupied until the timer ends and only the running timer may arm its successor into it, so a refusal during the sweep can never strand the row. - _arm_flood_timers_for_waiting_rows runs after every redelivery pass (boot and runtime), covering adopted rows, rows skipped as not yet due, and rows refused again. Adapter (gateway/platforms/base.py): _finalize_delivery_obligation arms the timer on a flood_control failure, best-effort inside the existing try. Tests: 35 in tests/gateway/test_delivery_ledger_flood_retry.py, with a controllable clock shared by ledger and runner. Each guard was mutation tested. Existing ledger, reconnect and redelivery suites (131 tests) pass.
…laim on the timer Review on the first cut reproduced two gaps. The raw UTF-16 length of the stored reply said nothing about how many requests the adapter made: MarkdownV2 escaping turns 3000 dots into 6000 units, two Telegram messages, and the send result does not say which chunk the platform refused. Drop the length-based certainty (and its helper and constant) and mark every flood redelivery with the rate-limit marker, at runtime and at boot. The cost is a marker on a reply nothing of which was delivered; the alternative was a silent duplicate. Releasing an unsent runtime claim always wrote send_path_degraded, so a flood row whose resume flag could not be cleared (or whose adapter vanished before dispatch) left the flood timer's list and stayed stranded until a reconnect or restart. The claimed row now carries its pre-claim error and the release writes it back, so the row waits the platform's figure once more and is sent on the next timer.
…es reach the timer Second review pass on the flood-retry change. - sweep_recoverable returns a dead owner's not-yet-due flood row flagged `adopted` (with its `not_before`) instead of dropping it from the result, so _claim_pending_obligations clears its session's resume_pending flag like every other claimed row; the answer is in the ledger and the turn must not be re-run at boot. _redeliver_claimed_obligations skips adopted rows and still arms the timer for them. - A legacy row without adapter_profile is normalised to 'default' when the boot sweep claims or adopts it: the runtime sweep matches profiles exactly and the timer asks for 'default', so an adopted NULL row could only wake the timer without ever being sent. - A sleeping timer is replaced by a shorter refusal's timer; the shorter one re-arms for the longer row after its sweep. A timer already sweeping is never cancelled from outside. - pending_flood_retries is read in a worker thread like the other ledger calls. - Adoption tests seed a distinct dead-owner stamp and assert ownership moves. - Scratch tags and long comment lines removed.
…ep refusal is not lost Round-2 review. Making _arm_flood_timers_for_waiting_rows read the ledger in a worker thread introduced a race: a flood refusal recorded during that thread's yield had its own _schedule_flood_redelivery request declined (the timer still held the slot), and the timer then cleared its slot on a snapshot taken before the new row committed, leaving that reply with no timer until the next reconnect or restart. The read is a single indexed SELECT; doing it synchronously keeps the arm decision atomic with respect to concurrent schedule requests. A test drives a refusal during the timer's own redelivery send and asserts the same timer arms it.
…nonical one The redelivery hook keyed on the canonical flood_control:<seconds> result, so two real refusals slipped past it and armed no timer, leaving the reply for the next restart. A short wait that outlived the send retries raised instead of failing closed, and an edit refused again after its inline wait returned the platform's raw text. Both now fail closed canonically, the second carrying the new delay rather than the first refusal's. The ledger also accepts a row still carrying the platform's own wording, so a row persisted by an unnormalized path is dated from the delay it states instead of the generic default. Without that a boot sweep claims it at once and spends its one attempt inside the penalty. Matching requires the flood wording as well as a delay, so an unrelated retry suggestion is never read as a flood. Six new assertions fail without this change. 770 passed across the ledger, Telegram, send-retry and queued suites.
4914486 to
7a87be7
Compare
|
Rebased onto current main ( #104370 now returns a typed failure in two new places: when the server's The hook here keyed only on the canonical
Six new assertions fail without the change. 770 passed, 2 skipped across the ledger, Telegram, send-retry and queued suites. |
|
Landed via #104950 at The salvage keeps your ledger deadline gates and adapter normalization. On top, the synchronous timer re-arm was replaced by one event-woken, shutdown-tracked worker per bot identity: SQLite reads stay off the event loop while a refusal during a read/send leaves a wake. Timer-specific tests were replaced by two ledger invariants and a repeatable local-wire probe; no contributor commit was dropped. Thanks also @gertsio for reproducing the escaped-chunk warning and released-claim gaps, and @pvdb2178 for independently documenting the missing runtime trigger in #103877. Post-merge verification on an archive of current origin/main: both ledger invariants passed. The real Telegram SDK/adapter → SQLite → runner loopback probe recovered a 61-second flood refusal automatically at runtime and after a real producer-process exit; each recovered once after expiry, spent zero attempts during the penalty, retained thread 77, and cleared resume_pending. Foreign-profile and permanent-rejection runtime controls were not sent. This is local HTTP evidence, not a live Telegram service claim. Scope is ledger-bracketed final text, not every media/notification producer. Closing this source PR as landed via the salvage. |
|
Superseded, and happy to see it land. #104950 merged today as I checked upstream main rather than assuming, and the whole mechanism is there: The one substantive difference is worth recording for anyone reading this later: the merged version replaces the synchronous SQLite timer re-arm used here with one event-woken worker per bot identity, which keeps the database work off the event loop. That is the better shape, and it means the tests in this branch describe a mechanism upstream no longer has, so they should not be carried over. Nothing here is still needed. This can be closed whenever suits you. I have already retired the corresponding local patch on my own deployment so it does not fight the native implementation on the next update. |
4 participants
What does this PR do?
The Telegram adapter fails a flood-controlled final send closed as
SendResult(success=False, error="flood_control:<seconds>")so the sendcoroutine never sleeps a long penalty (#91969). The comment at that site says
the caller's retry machinery, the delivery ledger, owns the wait. The ledger
did not:
sweep_failed_for_runtimeonly replayssend_path_degradedrows, soa flood-refused row sat in
faileduntil the next restart, whosesweep_recoverablethen redelivered it prefixed with the restart marker("Recovered reply, the gateway restarted during delivery, so this may be a
duplicate").
Observed on a live gateway:
The reply reached the user three hours late, only because the gateway happened
to restart, and under a marker describing a restart that had nothing to do with
it. Whether Telegram had accepted an earlier chunk of that reply is not knowable
from the logs, which is why the marker below says so.
Related Issue
No existing issue. Reproduction and log evidence are above; #91969 is the
change that introduced the fail-closed flood result this completes.
Type of Change
Changes Made
gateway/delivery_ledger.pyflood_control:*rows become runtime-retryable, but only once their owndeadline has passed: the refusal's
updated_atplus the platform's wait(
flood_not_before). Neither an early timer nor a reconnect sweep spends aredelivery attempt inside the penalty window.
FLOOD_MARKERsays theplatform's rate limit refused the original, so part of it may already have
arrived. The stored text's raw length cannot say how many requests the
adapter made (MarkdownV2 escaping alone turns 3000 dots into two Telegram
messages) and the send result does not say which chunk was refused, so there
is no length-based "nothing was delivered" shortcut. The restart and reconnect
markers would describe an event that never happened.
adapter vanished before dispatch) goes back to
failedwith its own pre-claimerror instead of
send_path_degraded, so a flood row stays on the floodtimer's list and is retried after the platform's figure rather than stranded
until a reconnect or restart.
last_errorNULL, stateattempting), so a resend interrupted beforemark_deliveredis seen asuncertain by the next boot and gets the marker as before.
re-stamped, no attempt spent) instead of being resent early. The adopted row
is returned to the caller flagged
adoptedwith itsnot_before, so thecaller clears its session's
resume_pendingflag exactly as it does forevery other claimed row (the answer is in the ledger; the turn must not be
re-run) while the row itself is left to the timer.
adapter_profile(recorded before that column existed)is normalised to
defaultwhen the boot sweep claims or adopts it. The bootsweep accepts such rows only on a non-multiplexed gateway, but the runtime
sweep matches profiles exactly and the timer asks for
default, so withoutthis an adopted legacy row could only ever wake the timer without being sent.
pending_flood_retries()lists this process's waiting flood rows peradapter identity with the earliest deadline.
gateway/run_startup.py_schedule_flood_redeliveryarms one timer per adapter identity that runsthe existing runtime sweep after the wait. Sleeps are capped at 15 minutes;
the row's deadline, not the timer, decides eligibility, so a capped timer
wakes early, sends nothing, and re-arms for the remainder. The slot stays
occupied until the timer ends and only the running timer may arm its
successor into it, and the post-sweep re-arm reads the ledger synchronously so
a refusal that lands during the sweep is picked up before the slot is freed.
A timer that is still asleep is replaced when a shorter refusal arrives (a
10s row must not wait behind a 185s sibling); the shorter timer re-arms for
the longer row after its sweep.
_redeliver_claimed_obligationsskips adopted rows (their resume flags werecleared with the others) and arms the timers afterwards, so a boot with only
adopted rows still gets its timer.
_arm_flood_timers_for_waiting_rowsruns after the boot redelivery pass andafter every timer sweep, covering adopted rows, rows skipped as not yet due,
and rows refused again. Timer-triggered runtime sweeps that find nothing to
claim return early and rely on the timer's own re-arm. That re-arm reads the
ledger synchronously so its snapshot cannot miss a row recorded by a
concurrent flood refusal whose own timer request was declined while the slot
was held.
gateway/platforms/base.py_finalize_delivery_obligationarms the timer on aflood_controlfailure,best-effort inside the existing try, alongside the
send_path_degradedbranch.
Deliberately unchanged: permanent rejections (blocked bot, bad auth, missing
chat) are never replayed by runtime recovery (the boot sweep's handling of
failed rows is as before);
send_path_degradedhandling is untouched.How to Test
pytest tests/gateway/test_delivery_ledger_flood_retry.py -q(43 tests).They drive the real ledger against an isolated
state.dband the realGatewayRunnerredelivery methods with a controllable clock shared by theledger and the runner, and cover: the deadline (a 10s and a 185s refusal
arriving together in either order, only the due row is sent and the timer
re-arms for the other), a capped timer that wakes early and never sends
early, a refusal during redelivery arming a successor, adoption at boot with
ownership actually moving from a dead stamp, the adopted row's session
having its resume flag cleared without the row being sent, the legacy
NULL-profile row being claimable by the timer, the interrupted resend
keeping its marker, the chunked reply keeping its marker, and the adapter
hook.
pytest tests/gateway/test_delivery_ledger.py tests/gateway/test_delivery_ledger_producer.py tests/gateway/test_restart_redelivery_dedup.py tests/gateway/test_platform_reconnect.py tests/gateway/test_silent_partial_delivery_95382.py tests/gateway/test_multiplex_adapter_registry.py -q(130 tests, unchanged behaviour for every non-flood path).
stale-error clearing, the unconditional marker, the boot adoption, the
adopted-row return, the profile normalisation, the timer cap, the successor
arming, the sleeping-timer replacement or the adapter hook fails at least
one test.
Checklist
Code
fix(scope):,feat(scope):, etc.)Documentation & Housekeeping
cli-config.yaml.example: N/A, no config keys added or changedCONTRIBUTING.mdorAGENTS.md: N/A, no architecture or workflow change