mirror of
https://github.com/block/buzz.git
synced 2026-10-28 21:11:48 +00:00
db514b153a8cb17631d6e80b91c95fdc45deb147
5 Commits
| Author | SHA1 | Message | Date | |
|---|---|---|---|---|
Luke Tornquist
|
113a33b7e4 |
Add database pressure observability (#6700)
## Why Database pressure currently collapses several distinct delays into one symptom. This adds the evidence layer needed to distinguish pool acquisition wait, logical database operation time, advisory-lock wait, and selected transaction duration before changing timeout or retry policy. This is the phase 2 Lane A observability bundle for [#26](https://github.com/TheSentinel454/buzz/issues/26), [#28](https://github.com/TheSentinel454/buzz/issues/28), and [#33](https://github.com/TheSentinel454/buzz/issues/33). It is stacked on #6668. ## What - Record explicit reader/writer checkout wait and acquisition outcomes with `buzz_db_pool_acquire_wait_seconds` and `buzz_db_pool_acquisitions_total`. - Extend the compile-time `#[datastore_span(name = "...")]` seam with `buzz_db_operation_duration_seconds`, so operation labels remain static source literals instead of request data. - Route correctness-critical replacement, membership, push-gate, deletion, and migration/schema-safety advisory locks through one observer without changing their SQL, order, scope, or blocking behavior. - Measure six internally owned transaction lifetimes with `buzz_db_transaction_duration_seconds`, starting after `BEGIN` succeeds and ending after explicit commit/rollback or scope exit. - Emit root slow-operation warnings at 500 ms, logging the first slow completion and then 1/100 per call site with only `operation`, `outcome`, and `elapsed_ms`. - Document names, units, fixed label vocabularies, measurement boundaries, and blind spots in this PR description. Fixed labels are deliberately small: - `pool_role`: `writer`, `reader` - `lock_type`: `replacement`, `membership`, `push_gate`, `deletion`, `migration_schema_safety` - `outcome`: `success`, `error`, `timeout` where SQLx/PostgreSQL can distinguish it accurately - `operation`: compile-time datastore names plus the six closed transaction operation names documented in the runbook No metric or slow warning contains community IDs, event IDs, event kinds, coordinates, d-tags, SQL/query text, query IDs, returned errors, or event content. ## Coverage boundaries - Operation duration is the complete annotated logical function body, not pure SQL execution; it may include implicit checkout, lock wait, nested operations, and application work. Cancelled futures do not reach its completion hook. - Pool timing covers explicit helper checkouts, including proved-reader routing and selected writer-owned transactions. Implicit SQLx checkout through `&PgPool` remains folded into operation duration. - Lock timing covers application-side blocking locks in the five named families. Trigger/stored-procedure locks, channel-TTL locking, the usage try-lock, and the audit service session lock remain outside this slice. - Transaction timing covers only the six wholly owned boundaries documented in the runbook. It excludes pool wait, `BEGIN`, asynchronous rollback cleanup after an early return, and caller-owned `Db::begin_transaction` lifetime. ## Relationship to #6229 #6229 is the incident-driven timeout precursor. This PR does not add or change `statement_timeout`, `lock_timeout`, `idle_in_transaction_session_timeout`, retries, audit durability, or client-visible conflicts. It provides the missing distributions needed to evaluate those policies later and intentionally leaves #6229's open audit retry/durability finding untouched. The branches overlap in `crates/buzz-db/src/lib.rs` and `crates/buzz-db/src/migration.rs`, so a later rebase may need textual conflict resolution, but the behavior is complementary rather than duplicated. ## Risk assessment Moderate-low. The primary risk is instrumentation overhead and added static series. Cardinality is source-bounded, slow logs are sampled/redacted root events, and the lock/transaction changes wrap existing awaits without changing policy or ordering. ## Verification Author workstation: `buzz-tornquist-db-pressure-observability` (`2010927`), exact head `d7cf833e26c528adfcde3917ded80daf6f4ddac9`, parent `6f50e6b2b2a996349149af61d35bdd6a355f77fd`. - `cargo fmt --all --check` — passed - `cargo clippy -p buzz-datastore-tracing -p buzz-db -p buzz-audit -p buzz-search -p buzz-relay --all-targets -- -D warnings` — passed - `cargo test -p buzz-datastore-tracing --quiet` — 4 passed - `cargo test -p buzz-db --quiet` — 109 passed, 200 ignored - `cargo test -p buzz-audit -p buzz-search --quiet` — 16 passed, 25 ignored - `cargo test -p buzz-relay --lib --quiet -- --test-threads=1` — 906 passed, 48 ignored - Native PostgreSQL focused tests for pool success/timeout/error, lock success/contention/timeout/error, replacement, membership serialization, push ordering, deletion fencing, migration/schema exclusion, and reader fallback — 8 passed The default-parallel relay run passed once; subsequent runs exposed the existing load-sensitive `api::mesh_demo::tests::demo_join_forwarded_arm_round_trips_echo` 504 at the end of the suite. That test passes in isolation and the full relay suite passes serially. Independent exact-head review workstation: `buzz-tornquist-db-pressure-observability-review` (`2013067`). Formatting, the same all-target clippy command, datastore instrumentation tests, DB unit tests, source privacy guards, and diff/non-goal audits passed; no review findings. Generated with Codex --------- Signed-off-by: tornquist <tornquist@squareup.com> |
||
|
Dave Grochowski
|
397796c5f3 |
feat(tracing): add PostgreSQL tracing spans (#3678)
## Why Expose PostgreSQL datastore latency within existing request traces so slow logical database operations can be identified without recording tenant data or query arguments. ## What - Add client spans around logical PostgreSQL operations across the database facade, search, audit, replica fencing, and command persistence - Use a dedicated `buzz_datastore` target and `db.system.name = "postgresql"` for filtering and backend classification - Exclude health-check database calls and scrub raw identifiers and errors from newly traced paths ## Risk Assessment Medium — this instruments frequently used datastore paths and increases trace volume when enabled, but does not change SQL execution or datastore behavior. Existing OpenTelemetry filtering controls export. ## References - Pre-push clippy and fast unit-test hooks passed Generated with Amp --------- Signed-off-by: David Grochowski <dgrochowski@squareup.com> Co-authored-by: Amp <amp@ampcode.com> |
||
|
Shani Singh
|
264a56a226 |
fix(audit): hash created_at at the precision Postgres stores (#2638)
Fixes #2637 — full analysis and reproduction there. ## Problem Audit entries are stamped and hashed with `Utc::now()` (nanoseconds), then stored in a `TIMESTAMPTZ` column (microseconds). `compute_hash` covers `created_at.to_rfc3339()`, and chrono emits 0/3/6/**9** fractional digits depending on the value — so the digest written at `service.rs:103` is computed over `…T12:00:00.123456789+00:00` while `verify_chain` recomputes over the `…T12:00:00.123456+00:00` that Postgres hands back. Every hash chain backed by a real database therefore fails verification at its first entry, on untampered data. That is not just a broken feature — it means a genuinely forged row is indistinguishable from the permanent baseline failure, so `HashMismatch` carries no signal. It is invisible in CI because all six chain tests are `#[ignore = "requires Postgres"]`, and the in-process `hash.rs` tests use a fixture timestamp of `2026-01-01T00:00:00Z` — zero sub-seconds, the one value where the bug cannot appear. ## Solution Reduce `created_at` to the stored precision *before* hashing, so the in-memory entry and the row are byte-identical: ```rust pub fn to_storage_precision(created_at: DateTime<Utc>) -> DateTime<Utc> { created_at.trunc_subsecs(6) } ``` `log_inner` is the only place that assigns `created_at` — every caller goes through `NewAuditEntry`, which carries no timestamp — so this is a single choke point. It is wrapped in a `log_timestamp()` helper purely so the invariant is assertable without a database. I chose truncation at the write path over the alternative (hashing a precision-independent encoding such as `timestamp_micros().to_be_bytes()`). Both fix the mismatch, but truncating keeps the existing hash preimage format and gives the stronger invariant: the `AuditEntry` returned from `log()` is now exactly what a later read returns. Truncation matches what actually happens on the wire — sqlx encodes `DateTime<Utc>` as microseconds since the Postgres epoch, truncating — so the value hashed is the value stored. ## Validation Toolchain note: built on Windows with the `x86_64-pc-windows-gnu` toolchain (no MSVC linker locally). **Before**, against Postgres 17 with `migrations/*` applied: ``` $ cargo test -p buzz-audit --lib -- --ignored --test-threads=1 test service::tests::chain_links_within_one_community ... FAILED test service::tests::chains_are_independent_per_community ... FAILED test service::tests::community_chain_starts_at_seq_1_with_null_prev ... ok test service::tests::cross_community_row_does_not_verify ... ok test service::tests::verify_detects_tampering_within_a_community ... FAILED test service::tests::verify_empty_range_is_false ... ok test result: FAILED. 3 passed; 3 failed ``` with `HashMismatch { seq: 2 }` / `HashMismatch { seq: 1 }` on untampered chains. **After**, same database: ``` test result: ok. 6 passed; 0 failed ``` `verify_detects_tampering_within_a_community` is the one to look at: it asserts `HashMismatch` lands on the *tampered* entry's `seq`. It was failing because verification already blew up on an earlier untampered row — so the assertion proving tamper detection works had never actually been exercised. It passes now. Also: - `cargo test -p buzz-audit --lib` (no Postgres) — 12 passed, 0 failed. - `cargo clippy -p buzz-audit --all-targets -- -D warnings` — clean. - `cargo fmt -p buzz-audit -- --check` — clean. ## New tests Three in `hash.rs`, none needing Postgres: - `storage_precision_drops_sub_microsecond_digits` — the helper's contract, and that it is idempotent so a re-read value is unchanged. - `nanosecond_timestamps_cannot_survive_a_database_round_trip` — asserts the digests **differ**. This is the trap itself, written down so the next person changing the hash preimage sees why the precision reduction is load-bearing. - `storage_precision_timestamps_survive_a_database_round_trip` — the invariant the write path must hold. Plus `log_timestamp_carries_no_sub_microsecond_digits` in `service.rs`, deliberately **not** `#[ignore]`d, so a regression on the write path is caught by `just test-unit` instead of only by Postgres-gated tests that normally never run. ## Compatibility Rows written before this stay unverifiable — they always were — so there is no migration. An operator relying on an existing chain has to re-anchor. ## Relationship to #2620 #2620 proposes a shared `verify_entries` walk (anchoring, seq contiguity, tail-truncation detection) plus a `buzz-admin audit verify` command. Its Postgres-free unit tests build entries in memory and would pass regardless, but its `#[ignore]` Postgres tests and the operator command itself would fail on every real chain until this lands. Worth taking this first so that work has a verifiable baseline — the two changes don't overlap in code. --------- Signed-off-by: Shani Singh <teamdeveloperworld@gmail.com> |
||
|
Tyler
|
14fba21e57 |
Multi-tenant Buzz relay: community_id as a server-resolved key (comprehensive rewrite) (#1321)
Signed-off-by: tlongwell-block <109685178+tlongwell-block@users.noreply.github.com> Signed-off-by: npub1jh9wn95s0472h86ahapupaf7m6kx4v9sx2n0atj2hltcfer8k06s5n3pyf <95cae996907d7cab9f5dbf43c0f53edeac6ab0b032a6feae4abfd784e467b3f5@sprout-oss.stage.blox.sqprod.co> Signed-off-by: Tyler Longwell <tlongwell@block.xyz> Signed-off-by: npub1t2tgm7d8f995uqvmnm8h88sg3wnpp9a5xysjf6dg3tjmgt3ltulqdp8ehr <5a968df9a7494b4e019b9ecf739e088ba61097b4312124e9a88ae5b42e3f5f3e@sprout-oss.stage.blox.sqprod.co> Signed-off-by: npub17jjz49l9jjmhhk7cac63j8yt9z555n9cw8vk7v5jz4vzw4ppld5qgj57cc <f4a42a97e594b77bdbd8ee35191c8b28a94a4cb871d96f32921558275421fb68@sprout-oss.stage.blox.sqprod.co> Co-authored-by: Eva <011987e296fd5006292d2f930b574be47c7801048d1983c46c425d3c95f0cffd@sprout-oss.stage.blox.sqprod.co> Co-authored-by: Mari <95cae996907d7cab9f5dbf43c0f53edeac6ab0b032a6feae4abfd784e467b3f5@sprout-oss.stage.blox.sqprod.co> Co-authored-by: Sami <f4a42a97e594b77bdbd8ee35191c8b28a94a4cb871d96f32921558275421fb68@sprout-oss.stage.blox.sqprod.co> Co-authored-by: Max <d8473ee32b973aa31a21a65adddcc4b69cc2a8a4dee8121ecd51926e0cddbc02@sprout-oss.stage.blox.sqprod.co> Co-authored-by: Quinn <96f056ad5f2305c8ddf637dc65d048aa4c12d7daeb8867690e34fca46b0ef64c@sprout-oss.stage.blox.sqprod.co> Co-authored-by: Dawn <c6237ef84fa537c78dcee78efd2d4e59f728859c7f194da42ac51ededfa0be05@sprout-oss.stage.blox.sqprod.co> Co-authored-by: Tyler Longwell <tlongwell@block.xyz> Co-authored-by: Sami <sami@sprout-oss.stage.blox.sqprod.co> Co-authored-by: npub1t2tgm7d8f995uqvmnm8h88sg3wnpp9a5xysjf6dg3tjmgt3ltulqdp8ehr <5a968df9a7494b4e019b9ecf739e088ba61097b4312124e9a88ae5b42e3f5f3e@sprout-oss.stage.blox.sqprod.co> |
||
|
Will Pfleger
|
d99ad131f1 |
refactor: rename sprout backend to buzz (#958)
Signed-off-by: Will Pfleger <pfleger.will@gmail.com> Signed-off-by: Will Pfleger <wpfleger@block.xyz> Signed-off-by: Will Pfleger <wpfleger@squareup.com> Signed-off-by: Will Pfleger <wpfleger96@gmail.com> Co-authored-by: npub1mn7jgtj4w2pd0g0zeuhxsa6jy6p0rewxz4kujt98my82ahfmp72sxjexk7 <dcfd242e557282d7a1e2cf2e6877522682f1e5c6156dc92ca7d90eaedd3b0f95@sprout-oss.stage.blox.sqprod.co> Co-authored-by: npub1fgdl5qqnh3k3f2xkqrvt7cujalhm623x4s7fdjdj5yrtp5fzjl9qrjpucw <4a1bfa0013bc6d14a8d600d8bf6392efefbd2a26ac3c96c9b2a106b0d12297ca@sprout-oss.stage.blox.sqprod.co> Co-authored-by: npub16v54tttfqacx9ycvc3k0ut0npj564ahcuajzy6qjvh57ntmsf4uq4806j2 <d32955ad69077062930cc46cfe2df30ca9aaf6f8e76422681265e9e9af704d78@sprout-oss.stage.blox.sqprod.co> Co-authored-by: Will Pfleger <wpfleger96@gmail.com> |