Settings writes: wait for a burst to settle before reloading #51

Merged
jcoffey-dev merged 1 commits from fix/settings-write-debounce into main 2026-09-25 04:35:09 +00:00
Owner

Problem

In a cluster rehearsal, ten x:<Object>/set requests sent at the same moment caused ten full reloads on every node.

#39's coalescing (crates/common/src/cache/reload.rs, reload_after_write) only joined writes that queued behind a reload already running. The requests reached the server about 33 ms apart, and a reload takes tens of milliseconds, so none of them overlapped one.

Change 1: the reload waits for a burst to settle

After a registry write, the full reload waits for more writes before it starts:

  • it starts 75 ms after the last write (WRITE_QUIET)
  • and never later than 250 ms after the first write it covers (WRITE_MAX_WAIT), so a steady stream of writes still reloads at least four times a second

It then covers every write stored so far. Writes that arrive while it runs go to the next reload. The reload runs in a task of its own, so a client that disconnects doesn't cancel it for the other writes.

The numbers. 75 ms is a little over twice the 33 ms gap the rehearsal saw between requests. A single write pays it once, on top of the reload itself. In the tests, a settings write now takes about 140 ms instead of 60.

Each response still reports its own reload. A write takes the result of the first reload that started after it was stored. The gate keeps the last 64 results, so applied: true/false still describes the reload that covered that write.

Change 2: the 33 ms per request (the rate-limit counter)

The cause is a queue on the server, not password hashing. I timed each stage of a request (temporary instrumentation, not in this PR):

  • TLS: about 1 ms.
  • Basic credentials: cached per Authorization header (http/src/auth/authenticate.rs), so a cache hit takes 0.01–0.04 ms. A password is hashed only on the first request with a given header, or on concurrent first requests.
  • The rate limit is the slow step. is_http_authenticated_request_allowed (crates/common/src/auth/rate_limit.rs) counts every authenticated request by incrementing one counter per account in the in-memory store. Parallel requests from one account all update that key, so they queue on it:
    • PostgreSQL: a row lock. Each request waits for the one ahead of it to commit, and that transaction takes a few round trips to the database. A remote database takes about 33 ms per request.
    • RocksDB: conflict retries with a 50–300 ms backoff.

The fix. An account with unlimitedRequests (administrators, by default) passed both the rate and concurrency limits anyway. Its requests are now not counted. This changes nothing for other accounts: they still count every request, and still queue the same way. Fixing that means moving the counter out of the shared store, which isn't a cheap or safe change.

Ten parallel Core/echo calls as the admin:

before after
local PostgreSQL finish one after another, 2–20 ms all finish in 1–4 ms
RocksDB 60–450 ms all finish in 1–4 ms

One more queue, not changed here. Concurrent creates of some object types (Domain, in the probe) still spread out over about 300 ms on RocksDB. That comes from write conflicts in the store, not from anything per account.

Tests

system::auto_reload::settings_reload_tests, extended:

  • Ten concurrent writes take one reload. The gate counts reloads; the test allows two. All ten responses are applied: true, and all ten schedules are in the running settings.
  • A single write takes exactly one reload.

Results:

Setup Reloads for 10 concurrent writes Time
This branch, RocksDB (4 runs) 1 141–145 ms
This branch, PostgreSQL 1 196 ms
Old behavior: no wait, requests counted 5 409 ms (test fails)
Rate fix only, no wait 2 125 ms

Also still passing:

  • cluster::broadcast::cluster_tests (3 nodes, PostgreSQL + NATS)
  • system::reload::reload_tests

Commands:

nstest3.sh <worktree> RocksDb system::auto_reload -- --nocapture
nstest3.sh <worktree> PostgreSql --features postgres system::auto_reload -- --nocapture
COORDINATOR=Nats nstest3.sh <worktree> PostgreSql --features postgres,nats cluster::broadcast
## Problem In a cluster rehearsal, ten `x:<Object>/set` requests sent at the same moment caused ten full reloads on every node. #39's coalescing (`crates/common/src/cache/reload.rs`, `reload_after_write`) only joined writes that queued behind a reload already running. The requests reached the server about 33 ms apart, and a reload takes tens of milliseconds, so none of them overlapped one. ## Change 1: the reload waits for a burst to settle After a registry write, the full reload waits for more writes before it starts: - it starts **75 ms after the last write** (`WRITE_QUIET`) - and never later than **250 ms after the first write** it covers (`WRITE_MAX_WAIT`), so a steady stream of writes still reloads at least four times a second It then covers every write stored so far. Writes that arrive while it runs go to the next reload. The reload runs in a task of its own, so a client that disconnects doesn't cancel it for the other writes. **The numbers.** 75 ms is a little over twice the 33 ms gap the rehearsal saw between requests. A single write pays it once, on top of the reload itself. In the tests, a settings write now takes about 140 ms instead of 60. **Each response still reports its own reload.** A write takes the result of the first reload that started after it was stored. The gate keeps the last 64 results, so `applied: true/false` still describes the reload that covered that write. ## Change 2: the 33 ms per request (the rate-limit counter) **The cause is a queue on the server, not password hashing.** I timed each stage of a request (temporary instrumentation, not in this PR): - **TLS:** about 1 ms. - **Basic credentials:** cached per `Authorization` header (`http/src/auth/authenticate.rs`), so a cache hit takes 0.01–0.04 ms. A password is hashed only on the first request with a given header, or on concurrent first requests. - **The rate limit is the slow step.** `is_http_authenticated_request_allowed` (`crates/common/src/auth/rate_limit.rs`) counts every authenticated request by incrementing one counter per account in the in-memory store. Parallel requests from one account all update that key, so they queue on it: - **PostgreSQL:** a row lock. Each request waits for the one ahead of it to commit, and that transaction takes a few round trips to the database. A remote database takes about 33 ms per request. - **RocksDB:** conflict retries with a 50–300 ms backoff. **The fix.** An account with `unlimitedRequests` (administrators, by default) passed both the rate and concurrency limits anyway. Its requests are now not counted. This changes nothing for other accounts: they still count every request, and still queue the same way. Fixing that means moving the counter out of the shared store, which isn't a cheap or safe change. Ten parallel `Core/echo` calls as the admin: | | before | after | |---|---|---| | local PostgreSQL | finish one after another, 2–20 ms | all finish in 1–4 ms | | RocksDB | 60–450 ms | all finish in 1–4 ms | **One more queue, not changed here.** Concurrent creates of some object types (Domain, in the probe) still spread out over about 300 ms on RocksDB. That comes from write conflicts in the store, not from anything per account. ## Tests `system::auto_reload::settings_reload_tests`, extended: - Ten concurrent writes take **one** reload. The gate counts reloads; the test allows two. All ten responses are `applied: true`, and all ten schedules are in the running settings. - A single write takes exactly one reload. Results: | Setup | Reloads for 10 concurrent writes | Time | |---|---|---| | This branch, RocksDB (4 runs) | 1 | 141–145 ms | | This branch, PostgreSQL | 1 | 196 ms | | Old behavior: no wait, requests counted | 5 | 409 ms (test fails) | | Rate fix only, no wait | 2 | 125 ms | Also still passing: - `cluster::broadcast::cluster_tests` (3 nodes, PostgreSQL + NATS) - `system::reload::reload_tests` Commands: ``` nstest3.sh <worktree> RocksDb system::auto_reload -- --nocapture nstest3.sh <worktree> PostgreSql --features postgres system::auto_reload -- --nocapture COORDINATOR=Nats nstest3.sh <worktree> PostgreSql --features postgres,nats cluster::broadcast ```
jcoffey-dev added 1 commit 2026-09-25 04:17:25 +00:00
Settings writes: wait for a burst to settle before reloading
ci / fork-checks (pull_request) Successful in 56s
ci / build (pull_request) Successful in 12m43s
71ce11c57d
A cluster rehearsal sent ten x:<Object>/set requests at once and got
ten full reloads on every node. #39's coalescing only joined writes
that queued behind a running reload, but the requests reached the
server about 33 ms apart and a reload takes tens of milliseconds, so
none overlapped one.

A full reload after a registry write now waits for writes to settle:
75 ms after the last one, and at most 250 ms after the first it
covers, so a steady stream still reloads at least four times a
second. 75 ms is a little over twice the gap the rehearsal saw between
requests. A single write pays it once: in the tests a settings write
takes about 140 ms instead of 60. The reload runs in a task of its
own, so a request that goes away doesn't cancel it for the others.
Each write takes the result of the first reload that started after it
was stored (the gate keeps the last 64 results), so applied true or
false still describes the reload that covered that write.

The 33 ms gap was a queue on the server, not password hashing: Basic
credentials are cached per Authorization header, so they are checked
once. Every authenticated HTTP request counted itself against the
account's rate limit by incrementing one counter per account in the
in-memory store, so parallel requests from one account queued on that
key: a row lock on PostgreSQL (a few round trips to the database
each) and conflict retries with a 50-300 ms backoff on RocksDB. An
account with the unlimitedRequests permission (administrators, by
default) passes the rate and concurrency limits anyway, so its
requests are no longer counted. Ten parallel Core/echo calls as the
admin now finish in 1-4 ms; before, they finished one after another
over 20 ms on a local PostgreSQL and 300-450 ms on RocksDB. Other
accounts still count every request.

system::auto_reload::settings_reload_tests: ten concurrent writes now
take one reload (the gate counts them; at most two allowed), all are
applied: true and in the running settings, and a single write takes
exactly one reload. RocksDB and PostgreSQL, 1 reload in 141-196 ms.
With the old behavior (no wait, requests counted) the same writes
took 5 reloads; without the wait but with the rate fix, 2.
cluster::broadcast (3 nodes, PostgreSQL + NATS) and system::reload
still pass.
jcoffey-dev merged commit 9e49597ae4 into main 2026-09-25 04:35:09 +00:00
jcoffey-dev deleted branch fix/settings-write-debounce 2026-09-25 04:35:09 +00:00
Sign in to join this conversation.
No Reviewers
No labels
1 Participants
Notifications
Due Date
No due date set.
Dependencies

No dependencies set.

Reference: inbuxa/inbuxa-server#51