Send the daily shrink's summaries from a durable queue - #167
Merged
Conversation
…ueue The daily shrink stopped running daily. Stale_Dick_Shrinks held five days in total, and the gaps between them were growing. The loop sleeps only *after* the run returns, and at ~204k chats and ~1.3M victims a day the run never returned inside a day: it held the whole day's events in memory and sent to each chat in turn, one round trip at a time, with a user-service language call inside the loop. Six days for 199k chats is about 2.6 s per chat, which is what that code does. So a run that outlasts the day takes the next midnight with it, and every notification still waiting is lost to a restart. Split the two. The shrinking statement now writes one row per chat into Scheduled_Shrink_Broadcasts (migration 38) in the same transaction, and a worker claims them with a lease and sends them concurrently. Queueing inside the statement is the durability: there is no moment at which a shrink is committed and the summary it owes is not. The run itself walks the chats in batches, chosen by a read-only candidate query. Per chat is the granularity a summary has, so each batch stays atomic over its chats while the locks and the memory stay bounded, and a failed batch costs its own chats instead of the day. Nothing but counts comes back: the worker re-reads the page from Stale_Dick_Shrinks, which also makes page 0 come from the same sorted query as pages 1+ — the in-memory version's "next page" button could repeat or skip people. Chats.is_unreachable is now cleared on the my_chat_member update that says the bot may post again, re-added or un-muted. Telegram sends it either way, so nobody has to type a command in the chat first. For the metrics half: whether the scheduler is alive is now a gauge read from the database, because a counter moving once a day reads zero both when nothing happened and when nobody scraped it before a restart, and afterwards nothing tells the two apart. That ambiguity is what hid this. The per-chat outcomes are written where the row is finished, so the counter and the table cannot disagree. Also move telegram_request_errors_total into TelegramObserver and take it out of the error handler, which only the dispatchers reach — so a broadcast-wide outage left it flat. The observer sits below every adaptor and already classifies for the duration histogram, so one classification now feeds both. The handler is renamed to ContextLoggingErrorHandler, as it only logs. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01UBfwfCDtzZe2QNwzLQgdKh
Page the shrink over the chats instead of listing its candidates first. The candidate query needed a DISTINCT over about a million stale dicks to save visiting one chat in eight — nearly every chat has a neglected dick in it — so it is replaced by a keyset walk of Chats' primary key, one page held at a time. Report only what the alerts read, and only from the worker's tick. The gauge over the finished rows grouped a few hundred thousand of them by state every five seconds so that a graph could show what a single SQL query answers; the Grafana Postgres datasource covers that, and it costs nothing when nobody is looking. What is left is the two the alerts need, because vmalert reads Prometheus and cannot query SQL. The shrink run and the cleaner no longer report at all — the worker's tick subsumes both within a poll interval. Settle what a log level means here: it follows what was lost, not whether the code recovered. A failed shrink page is an error — those chats lost the day and nothing retries it — while a failed metric publication stays a warning, since the next tick replaces the sample and the database problem behind it has already been reported by the run that hit it. The per-page line carries the error, so the summary at the end is no longer a second error saying less. Share the back-off between the two queues, and drop the trait that let a shrink page render from two row types when only one is left. Give Count an Add to go with its AddAssign. Not Sub: saturating at zero would turn a difference that was never meant to go negative into a plausible 0. Move both queues' tests under repo/test/, where every other repository's live. CLAUDE.md claimed Gauge::set and Histogram::observe take the conversion traits so that callers hand over domain values. They don't, and they can't: domain_types implements those traits only for the pairs that lose something, on the principle that an exact conversion says From — so there is no SaturatingInto<i64> for i64, and a caller holding a timestamp could not satisfy such a bound. The callers were right and the document was wrong; it now says so. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01UBfwfCDtzZe2QNwzLQgdKh
`internal_chat_id` was byte-identical in two files, the aged-dick seeder in two more (one of them with a comment saying it mirrored the other), the lease in the two queue suites, and the bare-chat insert in two. They move to `repo/test/mod.rs`. The repositories are the bigger half. Ninety-odd tests built two to four of them by hand, three lines to say what `Repositories::new` already says; a test now destructures the ones it wants out of `repos(&db)` and names no more than that. The four left building their own are the ones that need a different configuration — a feature toggle, an announcements file — which is exactly when building it by hand still says something. Also renames announcements' `create_chat`, which seeded a chat with a player in it and now would have read like the shared one that inserts a bare row. Net: 158 lines gone, 120 added, and one place to change when the shape of a fixture does. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01UBfwfCDtzZe2QNwzLQgdKh
Three tables were read by a column that led no index and so were scanned whole every time. Dicks by uid: a promo activation spent 342 ms walking 1.77M rows to reach 39 of them, and the personal statistics did the same. Loans and Battle_Stats by chat_id when two chats merge — Battle_Stats three times over, plus a fourth for the cascade from Chats, which is where move_dependent_rows spent its 378 ms. Where every query names both columns anyway, one index serves both shapes: equality on a pair is matched whichever column comes first, so the leading column is free to be the chat, and the separate index on the user is then redundant. Loans and Battle_Stats come out of this with one index fewer than they went in with. What it costs is filtering by the user alone, which is erase_user — run by hand, on a request. Inserts are unaffected either way: a foreign key checks the parent's own primary key and never looks here. dicks_idx_updated_at goes with them. It was built for the daily scan for stale dicks, but staleness is not rare here — nine of ten positive dicks are overdue at any moment — so the condition selects almost the whole table and the planner takes the chat instead. Production shows 0 scans in six months against 100 MB and a write on nearly every update; the same holds for the batched form of the query, checked against a copy of the data. The issue proposed parallelising move_dependent_rows. Round trips are not the cost — the database is a container on the same host — and a sqlx transaction cannot be driven concurrently without giving up the atomicity that keeps a half-merged chat from failing the delete that follows. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
`EnvDuration::days` was already reading them, so a `4320` meant as minutes arrived as twelve years. Both are commented-out defaults, so nothing was set wrong anywhere, but the name promised the wrong unit. MSG_SELFDESTRUCT_TABLE_CLEANING_DELAY_MINUTES -> ..._DAYS=1 DAILY_SHRINK_BROADCAST_TABLE_CLEANING_DELAY_MINUTES -> ..._DAYS=3 The broadcast defaults spell their durations with `from_mins`/`from_hours` too, so the number in the code reads as the number in the documentation. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01UBfwfCDtzZe2QNwzLQgdKh
Nothing told you which schedulers were running, at what pace, or whether a cleaner had run at all. Working out why finished rows were not being deleted meant turning on sqlx debug logging and reading the DELETE. Each of the five tasks now announces itself with the knobs that set its pace. Both cleaners were silent when the retention was zero, which looked exactly like a task that failed to start; they now say the rows are kept for ever and name the variable. Each cleaning run logs its cutoff date at debug, which is the number that answers the question. The rest is debug too: the wait until the next UTC midnight, and the outcome of every summary and every self-destructing message. The chats one statement shrinks are a batch now, not a page. Everything around them already said batch — DAILY_SHRINK_BATCH_SIZE, the failed_batches counter, the error line — and page is taken: it is what a chat pages through with the buttons under a shrink summary. Two test helpers passed a reference to a reference, which clippy took as needless_borrow. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01UBfwfCDtzZe2QNwzLQgdKh
The bridge was built without the appender's experimental_span_attributes feature, so an exported record carried the trace and span ids and nothing else of the span it belonged to. Every #[tracing::instrument(fields(...))] in the bot was worth something to the traces and to the console, and nothing at all to VictoriaLogs: a chat_id kept out of a message could not be searched for anywhere. The test did not notice because it set chat_id on the event rather than on the span. It now sets it on the span alone, so the assertion can only hold if the span's fields arrive, and it takes the process id: the container outlives the run, and a fixed value could be matched in an earlier run's records. Every field is taken rather than a named few. A span's fields are already chosen by hand at each attribute, and an allowlist here would be a second list to keep in step with them. This is the first part of #164. What is left of it -- passing an error as an error rather than as a string, and the contexts that may then drop the ids from their text -- is 27 more files and needs a way for an escaping error to keep its span first; both are described in the issue. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01UBfwfCDtzZe2QNwzLQgdKh
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
1 participant
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
Fixes #154, fixes #160, fixes #159. First part of #164.
The daily shrink is two jobs now, not one
At ~204k chats and ~1.3M victims a day, the old
run_daily_shrinkheld the whole day's events in aHashMapand sent to each chat in turn — oneawaitper chat, with a user-service language callinside the loop. A run took days rather than minutes, and the loop sleeps only after the run
returns, so a run that outlasts the day takes the next midnight with it: five runs were logged in
the fortnight before this, with the gaps growing.
So the shrink and the summaries it owes are split.
run_daily_shrinkapplies the decay and writes arow per chat;
scheduler/broadcasts.rssends them. Nothing is held in memory between the two.committed and its summary is not owed.
Scheduled_Shrink_Broadcasts(migration 38) is atransactional outbox — the property a message broker could not provide, since publishing after
committing is a dual write and a crash in between loses exactly what this exists to keep.
time however many chats there are. A
/growat midnight waits behind one batch rather than behindevery stale dick in the database.
scheduler/deletions.rs— claim-with-lease,for_each_concurrent,exponential back-off,
finish()writing the row and the counter together.UNIQUE (chat_id, shrink_date)makes the enqueue idempotent, so re-running a day can't double-send.same payload gets the same answer, and three attempts across 199k chats is an outage rather than a
hiccup.
ApiError::Unknownstays retryable — Telegram's own 5xx answers arrive that way.Both workers now share one
Throttle(scheduler::throttled, cloned into both). Two wrapperswould be two workers with two separate histories, each allowing the full 30 requests a second, and a
pause after a 429 would stop only the one that got it.
Why the silence went unnoticed
daily_shrink_last_run_timestamp_secondsis a gauge read fromMAX(created_at)inStale_Dick_Shrinks. A counter that moves once a day reads zero both when nothing happened and whennobody scraped it before the process restarted, and nothing afterwards tells the two apart — which
is how a fortnight of silence went unnoticed. Alert on
time() - … > 26h, and ondaily_shrink_broadcast_pendingstaying above zero for hours.#159 — index the columns the slow queries filter on
The slow queries were filtering on unindexed columns. Also: the test helpers every repository was
writing out again are shared now, and the two retention variables are named after the unit they are
read in.
#164 (first part) — export the fields of a span with the records written inside it
The bridge was built without the appender's
experimental_span_attributesfeature, so an exportedrecord carried the trace and span ids and nothing else of the span it belonged to. Every
#[tracing::instrument(fields(…))]in the bot was worth something to the traces and to the console,and nothing at all to VictoriaLogs.
The test did not notice because it set
chat_idon the event rather than on the span. It now sets iton the span alone, so the assertion can only hold if the span's fields arrive.
The rest of #164 — passing an error as an error rather than as a string, and the contexts that may
then drop the ids from their text — is 27 more files and needs a way for an escaping error to keep
its span first. Both are written up in
the issue.
Deploying
One variable is renamed, and the old name goes silent rather than failing:
It has to be changed in the server-configs
docker-compose.ymland.env.sopstogether with thisdeploy; left alone, the finished self-destruction rows quietly fall back to the default.
New variables, all optional and all with defaults — but the
environment:list of the server-configsdocker-compose.ymlhas to grow with them or they never reach the container:The
THROTTLE_*variables are unchanged; what is new is that both schedulers share oneThrottlerather than holding one each.
Migrations 38 (
Scheduled_Shrink_Broadcasts) and 39 (the #159 indexes) run on startup. The twoalerts belong in
vmalert/metrics-alerts.ymlnext to the Grafana dashboard.🤖 Generated with Claude Code
https://claude.ai/code/session_01UBfwfCDtzZe2QNwzLQgdKh