Skip to content

fix(log): panel round 1 for #765/#766 — keyset redaction, hashed secret set, one log-off seam - #772

Merged
0x054 merged 2 commits into
feat/700-sql-inspectionfrom
sdd/765-fix-panel-round-1
Oct 21, 2026
Merged

0x054 merged 2 commits into
feat/700-sql-inspectionfrom
sdd/765-fix-panel-round-1

Conversation

@0x054

@0x054 0x054 commented Oct 21, 2026

Copy link
Copy Markdown
Contributor

Part of #700 (panel round 1 on PR #771). Fixes F1, F2, F4, F5, F7 and F11 from the panel report, all in files #765 owned.

F1 (Critical): a plain keyset position on a secret key is now ***

Before, with token: SecretStr and a cursor decoded from a page token:

await (
    Account.select()
    .order_by(lambda account: account.token)
    .order_by(lambda account: account.id)
    .after(("sk_live_CURSOR", 0))
    .all()
)
# ferro.sql DEBUG SELECT ... WHERE "account"."token" > $1 OR ... params=('sk_live_CURSOR', 'sk_live_CURSOR', 0, ...)

After: params=(***, ***, 0, ...), in the log and in .all.sql(). plan_secret_values now pairs each after / before value with its order key. A traversed key (order_by(lambda note: note.account.token)) resolves through the joins the same way collect_secret_leaf_binds does. It is added when that column is secret.

The other places a value binds against a secret column were checked (I-6). Predicate literals, exists bodies and literal SETs were already covered. A SET expression (+, -, merge) cannot target a secret column, because the compiler accepts only numeric or JSON targets. Model.delete() and get run through the query terminals. The Rust fetch_one / delete_record PK entries have no Python caller.

Tests: tests/test_statement_log.py::test_a_plain_position_on_a_secret_order_key_is_redacted (after, before, traversed key) and three new parity-pin cases in tests/test_rendered_statement.py: all-after-plain-position-on-a-secret-key, all-before-plain-position-on-a-secret-key, first-after-plain-position-on-a-traversed-secret-key. Each runs on both dialects.

RED on bcb9931:

$ uv run --no-sync pytest tests/test_statement_log.py tests/test_rendered_statement.py -q --no-cov -p no:cacheprovider --db-backends=sqlite,postgres -k "secret_order_key or secret-key"
... params=('sk_live_CURSOR', 'sk_live_CURSOR', 0, 1) 0.6ms
8 failed, 110 deselected in 0.96s

GREEN: the same command, 8 passed.

F7: one query_secret_values

query_secret_values(py, name, plan, python_collected) builds the set for fetch_filtered, count_filtered, update_filtered, delete_filtered and all four render_* twins. That is how F1 reached every terminal in one place. Writes use payload_secret_values(py, name, rows, python_collected) and raw statements use python_secret_values. operation_secret_values is gone. Covered by the F1 tests and the existing parity pin (15 cases × 2 dialects).

F2 (Important): redaction is one hash lookup per bind

sql_log::SecretValues replaces the Vec. Text and bytes are looked up without copying the bind. The other scalars are kept by equality class: a float by its bits, with -0.0 stored as 0.0. A NaN matches a NaN, which over-masks. NULL is never a secret. A value collected by both Python (from the SecretStr) and the engine (from the secret column) is stored once. The mask is computed before Python::attach, both in observe and in rendered_parts. StatementContext.secret_values is an Arc<SecretValues>, so the scope clones in with_operation / with_subject stay cheap.

Tests:

  • Rust: sql_log::tests::a_value_collected_twice_is_held_once and membership_is_by_value_for_every_kind_of_bind.
  • Python: test_redacting_a_bulk_create_costs_one_lookup_per_bind bulk-creates 20k secret-bearing rows with the log on and off, and asserts on < 4 * off + 1.0.

RED on bcb9931:

$ uv run --no-sync pytest tests/test_statement_log.py ... -k one_lookup_per_bind
E       assert 13.240169166005217 < ((4 * 0.2383655410085339) + 1.0)
E       assert 13.40509979199851 < ((4 * 0.33289599999261554) + 1.0)
2 failed

GREEN: 2 passed. The measured times were 0.33 s on against 0.25 s off on SQLite, and 0.41 s against 0.29 s on Postgres.

F4 + F5: one switch read and one collector

Python no longer reads ferro.sql's level. Each operation's single read of the switch is the engine's operation_log, at the FFI entry.

  • One collector, ferro._bind_payload.secret_values_in(values). It searches lists, tuples and sets. A query's compile, a write and a raw statement each call it once. secret_values_of and secret_values(instance) were folded into it.
  • A write or raw statement passes deferred_secret_values(...), a lazy generator. The engine iterates it only when its switch read says the log is on. The two _secrets_to_mask copies are deleted.
  • A query still collects as it compiles, because .sql() masks with the same values (accepted in feat: every operation's statements on the statement log, secrets redacted (#765) #769's review).

Test: test_with_the_log_off_no_operation_emits_or_collects_secrets is replaced by test_secret_values_are_collected_once_and_only_when_needed[log-on|log-off]. It spies the one collector and emit, and runs save new, save fetched, bulk_create, the three raw calls and a save inside transaction(). It then runs first, count, exists, Query.update, Query.delete and Model.delete.

  • Log on: 7 write collections, including ("sk_live_1", b"k\x00\xff"), and records are emitted.
  • Log off: no write collections and no emit.
  • Either way: exactly 6 query collections, one per compile and none extra.

The log-on case also shows the spy is on the seam the operations actually use.

RED on bcb9931: AttributeError: module 'ferro._bind_payload' has no attribute 'secret_values_in', 4 failed. GREEN: 4 passed.

F11: ADR-0057 amended

A dated Amended 2026-10-21 (panel F11 on #771): paragraph sits under the redaction section. It records the value-set rule, the over-redaction of a plain value that equals a secret, the column-bound values Rust adds from the plan and payload (keyset positions included), and the engine's single switch read. The rest of the ADR is unchanged.

Interfaces changed

  • The FFI keyword secret_values on fetch_filtered, count_filtered, update_filtered, delete_filtered, save_record, update_record, save_bulk_records, raw_execute, raw_fetch_all, raw_fetch_one and the four render_* twins: list[object] became Iterable[object], default None/(). The engine iterates it only when it needs it. _core.pyi is updated.
  • ferro._bind_payload: secret_values_of(fields) and secret_values(instance) are replaced by secret_values_in(values), deferred_secret_values(values) and field_values(instances). These are private modules.
  • Rust: sql_log::StatementContext.secret_values is Arc<SecretValues>. sql_log::shown_params(py, binds, mask: &[bool]) now takes the mask. literal_secret_binds writes into &mut SecretValues.
  • CompiledQuery.secret_values is unchanged.

No file owned by fix-764 (src/run.rs, src/backend.rs, src/ddl_exec.rs, docs/pages/guide/connections.md, tests/test_ddl_lock_timeout.py) was touched or needs to change for these findings.

Verify

Verify block corrected: no

On 06bc945, with FERRO_POSTGRES_URL=postgresql://postgres:password@localhost:5432/postgres (Postgres accepted connections; the Postgres cases ran):

$ uv run maturin develop
$ uv run --no-sync pytest tests/test_statement_log.py tests/test_compiled_query.py tests/test_ir_vectors_contract.py tests/test_secret_fields.py tests/test_session_set_config.py tests/test_rendered_statement.py tests/test_query_typing.py tests/test_static_contracts.py -q --no-cov -p no:cacheprovider --db-backends=sqlite,postgres
211 passed
$ cargo test --no-default-features --features testing
test result: ok. 384 passed; 0 failed
$ uv run --no-sync ruff check src/ferro tests
All checks passed!
$ uv run --no-sync ty check src/ferro/query tests/test_query_typing.py tests/test_static_contracts.py tests/test_alembic_typing.py
All checks passed!
$ uv run --no-sync pytest tests -q --no-cov -p no:cacheprovider --db-backends=sqlite,postgres -n auto
4887 passed, 77 skipped, 2 xfailed, 7 warnings

The tests._docs_checks line of #766's Verify block was skipped because that module is not on this branch. cargo clippy --all-targets and cargo fmt --check are also clean.

Exit steps

🤖 Generated with Claude Code
https://claude.ai/code/session_01Hb9U9A7Zu9ypdHTsDvdScP

0x054 and others added 2 commits October 21, 2026 08:16
…, read the switch once

Panel round 1 on #771 (F1, F2, F4, F5, F7).

- F1: plan_secret_values now pairs each after/before value with its order
  key, resolving a traversed key through the joins, and adds it when the
  key's column is secret. A plain-str cursor on a SecretStr order key is
  *** in the log and in .sql().
- F7: one query_secret_values(py, name, plan, python_collected) serves
  every query terminal and its .sql() twin.
- F2: the secret-value set is sql_log::SecretValues, hashed (text and bytes
  looked up without copying; other scalars by equality class, a float by its
  bits), so redaction is one lookup per bind and a value collected by both
  Python and the engine is held once. The mask is computed before
  Python::attach.
- F4/F5: Python no longer reads the log switch. Every operation collects
  through one function, _bind_payload.secret_values_in; a write or raw
  statement hands the engine a lazy iterable it reads only when its one
  switch read says the log is on. The two _secrets_to_mask copies are gone.
  The FFI keyword secret_values now takes any iterable.

Co-Authored-By: Claude Fable 5.1 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01Hb9U9A7Zu9ypdHTsDvdScP
Panel F11 on #771: the ADR described a positional per-bind mask decided in
Python; the shipped rule is a per-operation set of secret values matched by
equality, with Rust adding the values bound to declared secret columns.

Co-Authored-By: Claude Fable 5.1 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01Hb9U9A7Zu9ypdHTsDvdScP

@0x054 0x054 left a comment

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Spec: PASS

Spec = panel findings F1, F2, F4, F5, F7, F11 (PR #771 panel report); #765/#766 bodies and the #700 plan's Deviated line for everything else.

  • F1 ADDRESSED · src/operations.rs:1630 at 06bc945 · plan_secret_values zips each after/before value with its order key (1:1 is enforced by position_condition, src/query.rs:787), resolves the table through table_for_path, and adds the value when the column is secret. Pinned by tests/test_statement_log.py:826 (after, before, traversed) and three parity-pin cases at tests/test_rendered_statement.py:174, 187, 200 (both dialects). They fail on bcb9931, where the plan's positions were never read. Throwaway probe on SQLite and Postgres: .after(("CUR2", 0)).first.sql() renders (***, ***, 0, 1); before(...).first() logs (***, ***, 0, 1).
  • F2 ADDRESSED · src/sql_log.rs:220, 354 at 06bc945 · SecretValues is hashed. Text and bytes are looked up borrowed. The SecretScalar::of match over EngineBindValue is exhaustive, so a new variant is a compile error and cannot silently miss. A float is matched by its bits with -0.0 folded; NaN matching NaN only over-masks; NULL is never inserted. Membership agrees with the old derived PartialEq for every variant except that it adds NaN. String and Bytes stay distinct, as before. Both sides of the comparison go through the same conversions as before the PR: Python's values through python_to_engine_bind_value (str to String, bytes to Bytes), and plan literals through literal_secret_binds. So the hashing opens no canonicalization gap. The mask is computed before Python::attach in observe and rendered_parts. Pinned by the Rust tests a_value_collected_twice_is_held_once and membership_is_by_value_for_every_kind_of_bind, and by tests/test_statement_log.py:977. That test fails on bcb9931, which the panel measured at 20k rows: 9.99 s with the log on against 0.13 s off.
  • F4 ADDRESSED · tests/test_statement_log.py:888 at 06bc945 · The test spies the one collector, _bind_payload.secret_values_in, through the module attribute that wire.py, deferred_secret_values and therefore models.py and raw.py all resolve. It also spies _sql_log.emit, which the engine looks up at each call. It covers save new, save fetched, bulk_create, the three raw calls, a transaction, first, count, exists, Query.update, Query.delete and Model.delete. With the log off: no emit and no write collection. A query collects at compile time whatever the level; #769's review accepted that because CompiledQuery.secret_values is part of the .sql() artifact. The log-on run proves the spy sits on the seam the operations actually use.
  • F5 ADDRESSED · src/operations.rs:1413 at 06bc945 · No isEnabledFor or getEffectiveLevel call on ferro.sql is left in src/ferro (grepped). Every sql_log::enabled call site is an operation entry. Writes and raw statements pass a lazy generator that the engine iterates only after its own switch read.
  • F7 ADDRESSED · src/operations.rs:1648 at 06bc945 · query_secret_values serves the four query entries and the four render_* twins. Writes go through payload_secret_values (:1668), and operation_secret_values is gone.
  • F11 ADDRESSED · docs/adr/0057-sql-is-seen-through-the-statement-log-and-a-terminals-sql.md:38 at 06bc945 · Checked the amendment against the shipped rule and found it accurate on each point: the value set, the Python and Rust sources (keyset positions included), one lookup per bind before the GIL, over-redaction in the safe direction, the engine's single switch read, and query values collected at compile time.
  • Interface deviations checked: (1) the secret_values keyword is Option<Bound<PyAny>> iterated with try_iter on all 14 entries; _core.pyi declares Iterable[object] = ... on the same 14, and Rust's default None matches. All callers checked: builder.py:1308, 1336, 1404, 1448 and 1884 pass compiled.secret_values (a tuple) to call and render twins alike; models.py:465 and 818, and raw.py:120, 136, 151, 178, 185 and 192 pass deferred_secret_values(...). In save() the one generator reaches exactly one FFI call on every branch, so it is never re-iterated after being exhausted. (2) secret_values_of/secret_values are replaced by secret_values_in/deferred_secret_values/field_values: no remaining reference in src/ferro or tests (grepped). Both are in-repo private signatures, and the reasons given (one collector, laziness for F5) show the old signatures could not deliver the findings. Accepted.

Cannot verify: none

Quality: PASS

  • Depth check: SecretValues (new; three-method interface hiding the per-kind hashing, tested through insert/contains/mask), query_secret_values/payload_secret_values (one entry per terminal family, earning their keep by the deletion test: removing them re-spreads F7's eight pastes), secret_values_in/deferred_secret_values/field_values: no check fired.
  • Checked I-3: no unwrap/expect added outside #[cfg(test)]; secret_binds_from_py propagates iteration and conversion errors as PyErr.

Verify: PR head 06bc945 passed (#765 + #766 pytest files together, 211 passed with --db-backends=sqlite,postgres, Postgres live; cargo test --no-default-features --features testing 384 passed; ruff check and ty check clean; tests._docs_checks line skipped, module absent on this branch). Full suite -n auto: 4887 passed, 77 skipped, 2 xfailed.
Trial merge: not run (base unchanged)

@0x054
0x054 merged commit 8fe1815 into feat/700-sql-inspection Oct 21, 2026
6 checks passed
@0x054
0x054 deleted the sdd/765-fix-panel-round-1 branch October 21, 2026 12:29
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant