Repository navigation
Conversation
…a-clawbot#2058) ANALYZE has never run against these databases, so sqlite_stat1 does not exist and the planner works from built-in guesses. On the channel queries it guesses wrong: it drives from the plain idx_transmissions_payload_type instead of idx_tx_channel_hash, the partial index (WHERE payload_type = 5) the schema already carries for that exact filter. Reported in Kpa-clawbot#2058 by anieto with measurements against a 464,667-transmission production database. A plain ANALYZE, no query and no schema change, moved GetChannels from 13.19s to 4.25s for one region and 10.44s to 2.45s for another, and the GROUP BY temp b-tree disappeared because the partial index is already in channel_hash order. The same report rules out the obvious alternative: forcing the plan to drive from the observer side measured 56.71s, worse than the 13.19s it was meant to fix. Verified independently on this deployment before writing any of this: the sqlite_master query for sqlite_stat% returns nothing against the live 9.7 GB meshcore.db, and there is no occurrence of ANALYZE, PRAGMA optimize or sqlite_stat anywhere under cmd/ or internal/. So the gap is real here too, at roughly 20x the row count of the reported database. The refresh runs from the ingestor, not the server: cmd/server/db.go:145 opens its handle with mode=ro and ANALYZE writes sqlite_stat1. analysis_limit is what makes this schedulable. A bare ANALYZE walks every index in full, which is not something to point at a 9.7 GB file on a ticker; the bounded form stops after N index rows. 400 is the value SQLite's documentation gives. PRAGMA optimize then re-analyzes only the tables whose statistics it judges missing or stale, so later runs do less than the first. Wired next to the existing WAL checkpoint ticker at 24h with a 2 minute startup stagger, following the surrounding maintenance pattern, and configurable through db.analysisLimit (negative disables it). Note analysis_limit=0 means *no* limit to SQLite rather than "use a default", which is why Config.AnalysisLimit maps an unset config to 400 and why a test covers that specific case. NOT verified, and it is the open question on this change: anieto measured a full ANALYZE, while this ships the bounded form. Whether analysis_limit=400 produces statistics good enough to flip the same plan is untested on a database of this size. The 9.4 GB staging database is the place to measure it, and that measurement has not been run. Go tests were not run locally: this dev box has CGO_ENABLED=0 and no C compiler, so the ingestor module does not build here (github.com/mattn/go-sqlite3 needs cgo). gofmt is clean. CI is the only verification these six tests have had. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_013YAR8fdNTzqjtsggq4xCX6 (cherry picked from commit 05c8bf2)
…#2058) Measurement on the 9.4 GB staging database showed the previous commit did nothing, twice over. Both faults are corrected here. PRAGMA optimize was the wrong statement. It analyzes only tables that the calling connection has itself queried during the session, and a maintenance call has queried none, so it writes nothing: run against staging it left sqlite_stat1 absent, and PRAGMA optimize(0x03) returned no statements at all. Replaced with ANALYZE, which is deterministic. Confirmed on an empty database too (SQLite 3.45.1): ANALYZE creates sqlite_stat1, PRAGMA optimize does not, which is what makes the behavioural test a real guard rather than a no-op. analysis_limit=400 was the wrong value. Staging is 1,250,489 transmissions and 14,169,329 observations; the region-filtered GetChannels plan there is identical to the one reported in Kpa-clawbot#2058, so the diagnosis transfers, but the remedy needed measuring. Counting page-cache misses rather than wall time, because wall time on that file is dominated by the OS page cache (the same query and plan measures 56.7s cold and 0.80s warm): analysis_limit ANALYZE driving index page misses none (no stats) - idx_transmissions_payload_type 143,442 400 171ms idx_transmissions_payload_type 143,449 1000 171ms idx_transmissions_payload_type 143,450 10000 2.0s idx_tx_channel_hash 107,429 0 (unbounded) 242.9s idx_tx_channel_hash 107,429 400 and 1000 sample too few rows to separate the 126,336-row partial index from the 920,700-row plain one, and leave the plan exactly as it was. 10000 buys the whole change for 2.0s, and the four-minute unbounded ANALYZE buys nothing further. Default is now 10000, with a test that fails if it is ever lowered back into the range measured ineffective. What this is worth, stated as measured: 25% fewer pages read per query (143,442 to 107,429, about 147 MB at a 4 KB page). Warm wall time does not move, 0.80s either way. The gain lands on the cold path, which is the one that measured 56.7s, so the honest claim is fewer pages read rather than a warm speedup. This is a smaller and differently-shaped win than the 3-4x in Kpa-clawbot#2058, whose database is 2.7x smaller in transmissions and 7x in observations. Renamed Store.OptimizeStats to RefreshPlannerStats, since it no longer runs PRAGMA optimize, and the test file with it. Staging was left carrying limit-10000 statistics, matching what this code produces. Reversible throughout: DROP TABLE sqlite_stat1 was verified on a scratch database before any of this ran. The staging container is up and unaffected. Still not run locally: the Go tests. This box has CGO_ENABLED=0 and no C compiler, so the ingestor module does not build here. gofmt is clean. The SQLite behaviours above were measured against 3.45.1 on the server, not against the amalgamation mattn/go-sqlite3 bundles in CI. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_013YAR8fdNTzqjtsggq4xCX6 (cherry picked from commit df6c7ed)
…a-clawbot#2058) Kpa-clawbot#2072 left the 2 minute startup stagger as an open gap: a query arriving in that window against a database with no statistics runs the plan measured there at 143,442 pages read, 56.7s cold on the 9.4 GB staging file. This closes it. The gap is narrower than it first looks, and the fix is shaped by that. sqlite_stat1 is an ordinary table, so once ANALYZE has written it the statistics stay in the file: verified that they survive closing the connection, that a mode=ro handle reads them back, and, in a test here, that reopening the same path through a second OpenStore finds them and skips the rebuild. So the window exists once per database, on the first start after this code lands, and not on any restart after that. EnsurePlannerStats therefore checks before it builds. On the common path it costs one sqlite_master query; only a never-analyzed database pays the ANALYZE, measured at 2.0s on 9.4 GB. It runs on the refresh goroutine rather than the startup path, so no boot step waits for it. Writes serialise through the store's single connection either way (SetMaxOpenConns(1), db.go:142), so this queues behind the boot migrations rather than contending with them. The staggered refresh 2 minutes later stays. On a first start it re-runs work that is 2 minutes old, which is 2s wasted once; on every restart it is the run that does the work. Keeping both means the emergency path and the routine path each have one job. hasPlannerStats now gates a decision rather than only wording a log line, so its comment says what its swallowed error costs: a query failure reads as "no stats", which spends one unnecessary ANALYZE instead of skipping a necessary one. Four tests added, 11 in the file now: builds when absent, skips when present, stays disabled on a negative limit, and survives a close-and-reopen. That last one is the guard on the whole design: if statistics ever stopped persisting, EnsurePlannerStats would quietly run a full ANALYZE on every restart. Ran locally this time, with the mingw-w64 toolchain that Kpa-clawbot#2072's description wrongly said did not exist here: 11/11 on the Kpa-clawbot#2058 tests, go vet clean, gofmt clean, and the rest of cmd/ingestor green apart from TestWriteStatsAtomic_SymlinkAtDestIsReplaced, which fails on os.Symlink ("A required privilege is not held by the client") on Windows without elevation and lives in a file this branch does not touch. Not done: nothing here re-plans the query itself, and no deployment has run this yet. Live still carries no statistics at all; staging carries the limit-10000 set I wrote by hand while measuring, on a container still running the older code. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_013YAR8fdNTzqjtsggq4xCX6 (cherry picked from commit 4500cfa)
…e it Deployed this branch to staging with sqlite_stat1 dropped first, so the build path actually ran. It works, and it costs far more than this branch claimed. Observed, 9.4 GB staging database, commit 4500cfa: 13:51:26 [analyze] refresh scheduled every 24h (analysis_limit=10000) 13:55:10 [analyze] planner statistics built in 3m43.874s (first run) 3m43.9s, not the 2.0s written into this branch and into Kpa-clawbot#2072. Every ANALYZE duration in that ladder was timed warm, one run after another; cold, on a freshly started container, the same statement at limit 10000 takes nearly four minutes. That is the same warm/cold confusion this work already identified for the query itself (56.7s against 0.80s) and then repeated for the ANALYZE. Every 2.0s in the tree is now marked as warm and points at the cold figure. It holds the single write connection throughout, so ingest stalls and buffers. Measured per minute in observations: 13:49 220 13:50 106 13:51 0 <- ANALYZE running 13:52 0 13:53 0 13:54 0 13:55 1027 <- backlog drained in one burst 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. So the cost is a four-minute write stall, once, not data loss. That cost is not introduced here. The refresh ticker in Kpa-clawbot#2072 pays the identical 3m43.9s two minutes later on any database with no statistics, so Kpa-clawbot#2072 as merged will stall live ingest for about four minutes on its first run. This branch only moves it earlier. Said plainly because it affects the live deploy either way. What is added is the warning an operator needs to tell it apart from a hang: EnsurePlannerStats now logs why ingest is about to pause, how long it took on 9.4 GB, and that it happens once per database, before starting the ANALYZE. Two tests pin it, including that it stays quiet on a restart, since a warning on every boot would be worse than none. End state on staging verified: 50 rows in sqlite_stat1, and the region-filtered channels plan drives from idx_tx_channel_hash. Dropping the table first flipped the plan back to idx_transmissions_payload_type, so the causality holds in both directions. 13 tests in the file, all passing locally, go vet and gofmt clean. The rest of cmd/ingestor is green apart from TestWriteStatsAtomic_SymlinkAtDestIsReplaced, the Windows os.Symlink privilege failure in a file this branch does not touch. Not done: staging currently runs this upstream-based branch, so it has lost the fork-local features until I redeploy the fork branch. No live deploy yet. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_013YAR8fdNTzqjtsggq4xCX6 (cherry picked from commit 7bae162)
…pa-clawbot#2058) Self-review catch, comment only. The block still justified the 2 minute stagger as keeping the ANALYZE clear of the initial ingest burst, while the first statement in the goroutine now deliberately runs inside that burst. Both are intended, for different reasons, so the comment says which is which: the routine refresh waits so it also sees the rows the burst added, the one-off build does not wait because a database with no statistics has nothing better to offer the queries arriving in those two minutes. No behaviour change. gofmt, go vet and the 13 Issue2058 tests still pass. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_013YAR8fdNTzqjtsggq4xCX6 (cherry picked from commit 5fbf114)
…ssue #100) Fork adaptation of the `Kpa-clawbot#2072` and `Kpa-clawbot#2074` port. Upstream starts EnsurePlannerStats on its own goroutine next to startup. This fork also starts the #89 route_mask backfill at that point, and both hold the single writer for one long statement: the first ANALYZE (3m43.9s cold on upstream's 9.4 GB staging file) and the backfill's pending-index CREATE INDEX (~20 s on a staging-sized DB). Started side by side they run back to back on writerMu and the ingest pause is their sum; started the moment the ingest buffer opens, either also sits on top of the backlog the buffer collected during the startup migrations. startPlannerStatsThenRouteMaskBackfill now runs them in sequence on one goroutine: drain the ingest buffer, EnsurePlannerStats, drain again, StartRouteMaskBackfill. Statistics first, because the channel queries wait on them, while the backfill is background repair whose batch phase runs for minutes. Each drain is bounded (2 min) so a buffer that never reads empty cannot hold the backfill back. On a restart EnsurePlannerStats is one sqlite_master query, so the backfill starts after the first drain only. The routine refresh (schedulePlannerStatsRefresh) starts its 2 minute stagger after that sequence hands over, so it cannot land on either hold, and is stopped on shutdown. Also: - EnsurePlannerStats returns early on a negative limit; upstream logged its "ingest will pause" warning even when nothing was built. - Line references to db.go:142 replaced; SetMaxOpenConns(1) is in OpenStore here. - db.analysisLimit documented in config.example.json, docs/user-guide/configuration.md and database.md, with rollback. Tests (test-first): both startup writers under live ingest through the real IngestBuffer without deadlock or loss; the order drain -> ANALYZE -> drain -> backfill; no ANALYZE when sqlite_stat1 exists (sentinel row); analysis_limit < 0 disables build and refresh but not the backfill; the drain wait is bounded; cancel between the writers does not schedule the backfill; hasPlannerStats errors read as "absent"; a refresh rewrites existing statistics (upstream's PRAGMA optimize guard is vacuous on the SQLite 3.46.0 bundled with modernc.org/sqlite, where optimize does analyze a never-analyzed table). In cmd/server, a read-only test: sqlite_stat1 written by a separate connection reaches the mode=ro handle (open and reopened), flips the region channel plan from idx_transmissions_payload_type to idx_tx_channel_hash, and ANALYZE fails on that handle. Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01Ut9z1opV6nVhm2vzqNz8ZV
…issue #100) TestMain_StartsRouteMaskBackfillAfterBufferReady looked for the literal store.StartRouteMaskBackfill( call in main.go. Since 521fab1 main starts the backfill through startPlannerStatsThenRouteMaskBackfill, which runs the one-off ANALYZE first, so the marker moves to that call. The guarantee is unchanged (after MQTT subscribe and ingestBuffer.Ready, cancelled before the MQTT disconnect); that the sequence itself starts the backfill is pinned by the behavioural tests in planner_stats_startup_test.go. Missed before 521fab1 because only the targeted tests ran there; the full go test -race ./... in cmd/ingestor caught it. Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01Ut9z1opV6nVhm2vzqNz8ZV
Owner
Author
|
Closing without merge: superseded by #107 (merged as Staging-iso measurement of this PR (2026-09-27) showed that a cold The branch is kept. If planner statistics become relevant again (for example for queries #107 does not cover), this port can be revisited. |
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
2 participants
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.
Summary
Ports upstream
Kpa-clawbot/CoreScope#2072andKpa-clawbot/CoreScope#2074(SQLite planner statistics via a boundedANALYZEin the ingestor). Decision issue: issue #100.What upstream adds:
Store.RefreshPlannerStats:PRAGMA analysis_limit(default 10000) followed byANALYZE.Store.EnsurePlannerStats: builds statistics at startup, but only on a database withoutsqlite_stat1. It runs once per database and logs a warning before it starts.db.analysisLimitininternal/dbconfig. A negative value disables the feature.This fork adds one thing on top: a fixed startup order against the route_mask backfill from #93.
The DB writes stay in
cmd/ingestor.cmd/serveronly gains a read-only test.Upstream was unreviewed. Both upstream PRs were written and merged by the same author with 0 reviews. The only comments are the author's own correction. Treat the code here as unreviewed until the separate review.
Cherry-picks (
git cherry-pick -x, upstream order)9bfa9cd905c8bf295fd0(#2072)197845a9df6c7ed5c9b4(#2072)d24e917e4500cfa66601(#2074)main.goauto-merged)e5b0b5027bae1626d6ce(#2074)main.goauto-merged)5bd942245fbf11471329(#2074)main.goauto-merged)All five applied cleanly. The added and removed lines are identical to upstream
d14317b0..6e121ff8forcmd/ingestorandinternal/dbconfig(verified by diffing the hunks).Fork commits (author and committer dborup):
521fab1c: the fork adaptation described below.528dfa25:TestMain_StartsRouteMaskBackfillAfterBufferReady(from Record every observed route per transmission and show mixed ADVERTs in Relay Airtime Share #93) now looks for the new call site. Before, the literalstore.StartRouteMaskBackfill(inmain.gowas the marker. I only caught this in the fullgo test -race ./...run, after521fab1chad been pushed.Fork adaptation: startup order against the route_mask backfill
Two startup steps each hold the single writer (
writerMu,SetMaxOpenConns(1)) for one long statement:EnsurePlannerStats: the firstANALYZE(upstream measured 3m43.9s cold on 9.4 GB).CREATE INDEXon the pending index (~20 s on staging size), followed by short batches.Started side by side (as upstream would do next to our #93), they queue behind each other on
writerMu. Started the momentingestBuffer.Ready()fires, either of them also sits on top of the backlog collected during the startup migrations.startPlannerStatsThenRouteMaskBackfill(cmd/ingestor/planner_stats_startup.go) therefore runs one goroutine:EnsurePlannerStatsis a singlesqlite_masterquery, so the backfill starts after the first drain, i.e. at the same point as before, give or take a few seconds.schedulePlannerStatsRefreshstarts its 2 minute stagger when the sequence hands over, so it cannot land on either hold. It is also stopped on shutdown.writerMu. They add seconds, not another long hold.Other adaptations:
EnsurePlannerStatsreturns early on a negative limit. Upstream logged its "ingest will pause" warning even when nothing was built.db.go:142references now say "in OpenStore". HereSetMaxOpenConns(1)is on line 150.db.analysisLimitis documented inconfig.example.json,docs/user-guide/configuration.mdanddocs/user-guide/database.md, including rollback. Upstream had no docs for it; our docs describe the sibling knobincrementalVacuumPages.Tests
The upstream file
refresh_planner_stats_test.gopasses on our schema: 13/13.New tests in
planner_stats_startup_test.go(written first; red before the implementation):TestPlannerStatsAndRouteMaskBackfillAtStartup_Issue100:EnsurePlannerStatsand the backfill both run under live ingest through a realIngestBuffer. No deadlock, statistics built, backfilldone, no NULL rows left. All packets fed during the run are written (0 dropped, 0 failed), and a packet sent afterwards is written too.TestPlannerStatsBeforeRouteMaskBackfillWithDrains_Issue100: the order is drain → ANALYZE → drain → backfill start → index build.TestStartupSkipsAnalyzeWhenStatsExist_Issue100: with an existingsqlite_stat1there is no ANALYZE at startup. A sentinel row insqlite_stat1survives, and the backfill still runs.TestNegativeAnalysisLimitDisablesBothStartupAndRefresh_Issue100:analysis_limit < 0disables both the build and the refresh, but not the backfill.TestPlannerStatsRefreshWaitsForStartupThenTicks_Issue100,TestStartupDrainWaitIsBounded_Issue100,TestStartupSequenceStopsOnCancel_Issue100(cancel between the two writers).TestHasPlannerStatsErrorReadsAsAbsent_Issue100,TestEnsurePlannerStatsDisabledIsSilent_Issue100.TestRefreshPlannerStatsRewritesExistingStats_Issue100: a refresh rewrites existing statistics. This is needed because upstream's guard againstPRAGMA optimizeis vacuous here: modernc.org/sqlite bundles SQLite 3.46.0, wherePRAGMA optimizedoes analyze a never-analyzed table. Upstream measured on 3.45.1.In
cmd/server,TestServerReadsPlannerStatsThroughReadOnlyHandle_Issue100only reads:sqlite_stat1, written by a separate connection, reaches the server'smode=rohandle, both an already-open one and a freshly opened one.idx_transmissions_payload_typetoidx_tx_channel_hash.ANALYZEfails on the server handle.GetChannelsstill answers.Mutations (15)
Each mutation was run against
go test -run '_Issue100$|_Issue2058$'. Final round on the pushed code: 15/15 killed, 0 survivors. In the first round M9 and M11 survived; each got a new test (the cancel window between the writers, andTestRefreshPlannerStatsRewritesExistingStats_Issue100).ANALYZE→PRAGMA optimizeMeasurements (local, not staging)
Hardware: KVM guest with 4 vCPU (Intel Xeon @ 2.80 GHz), 16 GB RAM, virtio disk, Linux 6.18. SQLite 3.46.0 (modernc.org/sqlite v1.34.5). "Cold" means
sync; echo 3 > /proc/sys/vm/drop_cachesinside the guest; the host's cache is outside my control.Synthetic DB: 1.94 GB, created with the ingestor's own
OpenStoreschema.#publicdominant) and 55 % areenc_XX(200 values).Channel queries, without and with
sqlite_stat1(identical copies)Plan for
GetChannels(region):idx_transmissions_payload_type+ TEMP B-TREE GROUP BYidx_tx_channel_hash, no GROUP BY b-treeThe plan for
GetEncryptedChannels(region)does not change:LIKE 'enc_%'cannot use the partial index.Cache dropped before each call, 3 repetitions × 2 passes:
First ANALYZE (limit 10000) and the ingest buffer
handleMessage(channel-message path) through a realIngestBuffer(cap 50,000).Order against the backfill (cold, no stats, 20,454 NULL route_mask rows, 600/min, 2 runs each)
writerMu, gets one write in between, because the backfill's bookkeeping first queues on the connection.writerMufirst, and the backfill no longer lands on top of the startup backlog.Expected ingest pause per database (one time)
ANALYZEat startup on a database withoutsqlite_stat1. Upstream measured 3m43.9s cold on 9.4 GB (staging, 1.25M tx / 14.2M obs); here 8.7–9.2 s cold on 1.94 GB.Known limitation (upstream design, unchanged here): the routine refresh 2 minutes after every restart is a full bounded ANALYZE. Warm it took 0.3 s here (upstream: 2.0 s). With a cold cache it cost as much as the first build (8.25 s against 9.2 s here). If the host cache is cold after a staging/production restart, that means a pause of the same size as the first build on every restart. The staging test should measure this.
Rollback
sqlite_stat1. SQLite itself uses it for planning, but nothing in the old code writes or requires it.DROP TABLE sqlite_stat1;, only via the ingestor side, with the ingestor stopped. The server's handle ismode=roand must not do it. WithanalysisLimitenabled, the next start rebuilds the table."db": {"analysisLimit": -1}.Staging test plan
SELECT count(*) FROM sqlite_master WHERE name='sqlite_stat1'andEXPLAIN QUERY PLANfor the region channel query (read-only).[analyze] this database has no planner statistics; building them now …and thenplanner statistics built in …. Record the duration.[ingest-buffer]lines: expect 0 dropped, a pause of the same length and a catch-up burst.planner statistics builtbefore"tx_route_mask_backfill_v1" starting(if the backfill has work).idx_tx_channel_hash. Measure GetChannels/GetEncryptedChannels cold and warm against the pre-deploy figures (the local result above does not settle this).planner statistics refreshed in …duration 2 min later (cold/warm, see the known limitation).DROP TABLE sqlite_stat1, confirm the plan flips back.Checks
go vet ./...clean in cmd/ingestor.gofmtclean on touched files (some untouched files on master are not gofmt-clean; unchanged).go test -race -timeout 20m ./...in cmd/ingestor: ok (663 s).go vet ./...clean in cmd/server.go test -race ./...in cmd/server: ok (616 s).internal/dbconfigok. Read-only invariant (readonly_invariant_test.go, 4 tests) ok.🤖 Generated with Claude Code
https://claude.ai/code/session_01Ut9z1opV6nVhm2vzqNz8ZV
Generated by Claude Code