Skip to content

fix(db): quiet routine timing logs and prepare 0.2.1 - #58

Merged
eldonm merged 2 commits into
mainfrom
codex/db-operation-debug-logging
Oct 12, 2026
Merged

eldonm merged 2 commits into
mainfrom
codex/db-operation-debug-logging

Conversation

@eldonm

@eldonm eldonm commented Oct 12, 2026 •

Copy link
Copy Markdown
Member

Routine db.find and other successful operation timings currently emit at INFO, flooding application logs when observability is enabled. Emit these timings at DEBUG so applications can opt into detailed telemetry without losing important warnings.

Slow operations retain WARNING. Fast failed operations now also use WARNING with a FAILED prefix, preserving failure visibility when routine timings are filtered. Structured fields, slow-query thresholds, exception propagation, metrics, and operation counters remain unchanged. Update the observability guide and technical specification, and record the fix in the 0.2.1 changelog. Bump the single-source package version to 0.2.1.

Validation:

  • Reproduced the old behavior with failing regression tests before the fix.
  • Database and observability suites: 573 passed, 70 skipped (optional backend/integration lanes unavailable locally).
  • All pre-commit checks passed, including formatting, lint, mypy, and secret detection.
  • Built the 0.2.1 wheel and verified both METADATA and its packaged version.py report 0.2.1.
  • After the version bump, relevant database/observability regression tests passed: 40 passed, 1 skipped.
  • Coverage verifies quiet INFO-level get/find calls with metrics intact, DEBUG structured fields, slow-query warnings, failure warnings and propagated exceptions, and residual-scan telemetry.

Applications that collect routine operation timing logs must enable DEBUG for jvspatial.db.observable and their handler. The version bump prepares 0.2.1; merging to main triggers the existing release workflow. Publication has not yet been verified.

@github-actions

Copy link
Copy Markdown

Benchmark comparison

Threshold: ±25% (informational, does not block merge)

benchmark baseline (s) current (s) delta status
tests/benchmarks/test_deferred_save_benchmarks.py::test_bench_deferred_save_batched_100 0.022033 0.027640 +25.4% REGRESSION (+25.4%)
tests/benchmarks/test_deferred_save_benchmarks.py::test_bench_immediate_save_100 0.022288 0.027342 +22.7% OK
tests/benchmarks/test_graph_projection_benchmarks.py::test_warm_projection_capture[hierarchy] 0.003766 0.005057 +34.3% REGRESSION (+34.3%)
tests/benchmarks/test_graph_projection_benchmarks.py::test_warm_projection_capture[ontology] 0.004022 0.005304 +31.9% REGRESSION (+31.9%)
tests/benchmarks/test_graph_projection_benchmarks.py::test_warm_projection_capture[relationships] 0.003781 0.005257 +39.1% REGRESSION (+39.1%)
tests/benchmarks/test_graph_projection_benchmarks.py::test_warm_rich_projection_capture[hierarchy] 0.003514 0.004346 +23.7% OK
tests/benchmarks/test_graph_projection_benchmarks.py::test_warm_rich_projection_capture[ontology] 0.003319 0.004139 +24.7% OK
tests/benchmarks/test_graph_projection_benchmarks.py::test_warm_rich_projection_capture[relationships] 0.003308 0.004217 +27.5% REGRESSION (+27.5%)
tests/benchmarks/test_jsondb_benchmarks.py::test_bench_jsondb_batched_saves_500 0.404674 0.466547 +15.3% OK
tests/benchmarks/test_jsondb_benchmarks.py::test_bench_jsondb_count_empty_query 0.001994 0.002002 +0.4% OK
tests/benchmarks/test_jsondb_benchmarks.py::test_bench_jsondb_count_filtered 0.094640 0.105151 +11.1% OK
tests/benchmarks/test_jsondb_benchmarks.py::test_bench_jsondb_find_filtered 0.096290 0.102572 +6.5% OK
tests/benchmarks/test_jsondb_benchmarks.py::test_bench_jsondb_save_throughput 0.001503 0.001782 +18.6% OK
tests/benchmarks/test_postgres_benchmarks.py::test_bench_postgres_find_many_bulk 0.001012 0.001088 +7.6% OK
tests/benchmarks/test_postgres_benchmarks.py::test_bench_postgres_traverse_depth 0.000639 0.000683 +6.9% OK
tests/benchmarks/test_sqlite_benchmarks.py::test_bench_sqlite_count_empty 0.000233 0.000309 +32.5% REGRESSION (+32.5%)
tests/benchmarks/test_sqlite_benchmarks.py::test_bench_sqlite_count_fallback_via_regex 0.028622 0.031094 +8.6% OK
tests/benchmarks/test_sqlite_benchmarks.py::test_bench_sqlite_count_pushdown 0.001327 0.001564 +17.8% OK
tests/benchmarks/test_sqlite_benchmarks.py::test_bench_sqlite_find_fallback_via_regex 0.028730 0.030286 +5.4% OK
tests/benchmarks/test_sqlite_benchmarks.py::test_bench_sqlite_find_pushdown 0.000397 0.000464 +16.8% OK
tests/benchmarks/test_sqlite_benchmarks.py::test_bench_sqlite_sort_limit_pushdown 0.002377 0.002741 +15.3% OK

@eldonm eldonm changed the title fix(db): move routine operation timing logs to DEBUG fix(db): quiet routine timing logs and prepare 0.2.1 Oct 12, 2026
@github-actions

Copy link
Copy Markdown

Benchmark comparison

Threshold: ±25% (informational, does not block merge)

benchmark baseline (s) current (s) delta status
tests/benchmarks/test_deferred_save_benchmarks.py::test_bench_deferred_save_batched_100 0.022033 0.016616 -24.6% OK
tests/benchmarks/test_deferred_save_benchmarks.py::test_bench_immediate_save_100 0.022288 0.016012 -28.2% IMPROVED (-28.2%)
tests/benchmarks/test_graph_projection_benchmarks.py::test_warm_projection_capture[hierarchy] 0.003766 0.002961 -21.4% OK
tests/benchmarks/test_graph_projection_benchmarks.py::test_warm_projection_capture[ontology] 0.004022 0.003064 -23.8% OK
tests/benchmarks/test_graph_projection_benchmarks.py::test_warm_projection_capture[relationships] 0.003781 0.003141 -16.9% OK
tests/benchmarks/test_graph_projection_benchmarks.py::test_warm_rich_projection_capture[hierarchy] 0.003514 0.002626 -25.3% IMPROVED (-25.3%)
tests/benchmarks/test_graph_projection_benchmarks.py::test_warm_rich_projection_capture[ontology] 0.003319 0.002524 -24.0% OK
tests/benchmarks/test_graph_projection_benchmarks.py::test_warm_rich_projection_capture[relationships] 0.003308 0.002509 -24.2% OK
tests/benchmarks/test_jsondb_benchmarks.py::test_bench_jsondb_batched_saves_500 0.404674 0.465665 +15.1% OK
tests/benchmarks/test_jsondb_benchmarks.py::test_bench_jsondb_count_empty_query 0.001994 0.001540 -22.8% OK
tests/benchmarks/test_jsondb_benchmarks.py::test_bench_jsondb_count_filtered 0.094640 0.072841 -23.0% OK
tests/benchmarks/test_jsondb_benchmarks.py::test_bench_jsondb_find_filtered 0.096290 0.074592 -22.5% OK
tests/benchmarks/test_jsondb_benchmarks.py::test_bench_jsondb_save_throughput 0.001503 0.001529 +1.7% OK
tests/benchmarks/test_postgres_benchmarks.py::test_bench_postgres_find_many_bulk 0.001012 0.000761 -24.8% OK
tests/benchmarks/test_postgres_benchmarks.py::test_bench_postgres_traverse_depth 0.000639 0.000475 -25.6% IMPROVED (-25.6%)
tests/benchmarks/test_sqlite_benchmarks.py::test_bench_sqlite_count_empty 0.000233 0.000175 -24.8% OK
tests/benchmarks/test_sqlite_benchmarks.py::test_bench_sqlite_count_fallback_via_regex 0.028622 0.021930 -23.4% OK
tests/benchmarks/test_sqlite_benchmarks.py::test_bench_sqlite_count_pushdown 0.001327 0.001064 -19.8% OK
tests/benchmarks/test_sqlite_benchmarks.py::test_bench_sqlite_find_fallback_via_regex 0.028730 0.021658 -24.6% OK
tests/benchmarks/test_sqlite_benchmarks.py::test_bench_sqlite_find_pushdown 0.000397 0.000305 -23.1% OK
tests/benchmarks/test_sqlite_benchmarks.py::test_bench_sqlite_sort_limit_pushdown 0.002377 0.001884 -20.7% OK

@eldonm eldonm self-assigned this Oct 12, 2026
@eldonm
eldonm merged commit 4cc06dd into main Oct 12, 2026
6 checks passed
@eldonm
eldonm deleted the codex/db-operation-debug-logging branch October 12, 2026 16:54
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