mirror of
https://github.com/Kpa-clawbot/meshcore-analyzer.git
synced 2026-10-08 07:37:39 +00:00
Follow-up to #2072, which closed #2058 but left one gap named in its own description: the refresh ticker waits 2 minutes before its first run, and a query arriving in that window against a database with no statistics gets the bad plan. Deployed to staging to measure it rather than reason about it, with `sqlite_stat1` dropped first so the build path actually ran. That changed two of the numbers in #2072, both in the expensive direction. ## The gap is once per database, not once per restart `sqlite_stat1` is an ordinary table, so once `ANALYZE` has written it the statistics stay in the file. Checked four ways: - they survive closing the connection that wrote them - a `mode=ro` handle reads them back, which is how `cmd/server` opens the database - reopening the same path through a second `OpenStore` finds them and skips the rebuild (`TestPlannerStatsSurviveReopen_Issue2058`) - on staging they survived a full redeploy to a different build that has no refresh ticker at all, and that build still gets the good plan So the window opens once, on the first start after this lands, and never again for that database. ## The cost, corrected #2072 said 2.0s. Observed on staging, 9.4 GB, commit `4500cfa6`: ``` 13:51:26 [analyze] planner statistics refresh scheduled every 24h (analysis_limit=10000) 13:55:10 [analyze] planner statistics built in 3m43.874s (analysis_limit=10000, first run against this database) ``` **3m43.9s.** Every `ANALYZE` duration in #2072's ladder was timed warm, run after run; cold, on a freshly started container, the same statement takes nearly four minutes. That is the same warm/cold split #2058 work already established for the query itself, 56.7s against 0.80s, and I then repeated it for the `ANALYZE`. Every `2.0s` in the tree is now marked warm and points at the cold figure. It holds the single write connection throughout, so ingest stalls and buffers. Per minute in `observations`: | minute | rows | |---|---| | 13:49 | 220 | | 13:50 | 106 | | 13:51 | 0 | | 13:52 | 0 | | 13:53 | 0 | | 13:54 | 0 | | 13:55 | **1027** | | 13:56 | 154 | Nothing was dropped. The burst is about four minutes of traffic at the surrounding rate, and the only ingest-buffer line in the log is the startup one reporting `0 dropped`. The cost is a four-minute write stall, once, not data loss. ## This cost is not introduced here The ticker merged in #2072 pays the identical 3m43.9s two minutes later on any database with no statistics. **Live has none, so #2072 as merged will stall live ingest for about four minutes on its first run, with or without this branch.** This only moves it earlier, into the startup burst the ingest buffer is already sized for. Flagging it on #2072 as well. ## The change `Store.EnsurePlannerStats(analysisLimit)` checks before it builds: - database has statistics: one `sqlite_master` query. This is every restart after the first. - database has none: one `ANALYZE`, and a warning first. The warning is the part that earns its place operationally. Four minutes of stalled ingest with no explanation in the log looks exactly like a hang, so `EnsurePlannerStats` now says why the write path is about to pause, what it measured on 9.4 GB, and that it happens once per database. It stays silent on a restart, because a warning on every boot would be worse than none. It runs on the refresh goroutine, not the startup path, so no boot step waits for it. `hasPlannerStats` now gates a decision instead of only wording a log line, so its comment says what the swallowed error costs: a query failure reads as "no stats", which spends one unnecessary `ANALYZE` rather than skipping a necessary one. ## Verification on staging - before: plan drove from `idx_transmissions_payload_type`, no `sqlite_stat1` - after: 50 rows in `sqlite_stat1`, plan drives from `idx_tx_channel_hash` - dropping the table first flipped the plan back, so the causality holds in both directions ## Tests 13 in the file. New here: builds when absent, skips when present, disabled on a negative limit, survives close-and-reopen, warns before building, stays quiet when statistics exist. The reopen test is the guard on the whole design: if statistics ever stopped living in the file, `EnsurePlannerStats` would quietly run a four-minute `ANALYZE` on every restart and nothing else would notice. Run locally: 13/13 on the `Issue2058` tests, `go vet` clean, `gofmt` clean, and the rest of `cmd/ingestor` green apart from `TestWriteStatsAtomic_SymlinkAtDestIsReplaced`, which fails on `os.Symlink` with "A required privilege is not held by the client" on Windows without elevation, in a file this branch does not touch. ## Not done - No query rewrite, same as #2058 and #2072. - **No live deploy.** Live still has no statistics, so the four-minute stall is ahead of it whenever #2072 ships there. Worth picking the moment. - Staging has been returned to its own fork build; the statistics it built remain, so its next start exercises the skip path rather than the build path. 🤖 Generated with [Claude Code](https://claude.com/claude-code) https://claude.ai/code/session_013YAR8fdNTzqjtsggq4xCX6 --------- Co-authored-by: Claude Opus 5 (1M context) <noreply@anthropic.com>