feat: 🗄️ Jules02: Database reliability improvement — Slow query logging and SQLite hardening (#1164)

* feat: 🗄️ Jules02: Database reliability improvement — Slow query logging and SQLite hardening

Implement enterprise-grade database observability and reliability:
- Add SLOW_QUERY_THRESHOLD = 1.0s and SQLAlchemy event listeners for query timing.
- Harden SQLite with busy_timeout=5000 to reduce lock contention errors.
- Optimize SQLite with synchronous=NORMAL for better WAL mode performance.
- Add comprehensive integration tests in tests/test_database_performance.py.

Co-authored-by: xnessom <255288032+xnessom@users.noreply.github.com>

* feat: 🗄️ Jules02: Database reliability improvement — Slow query logging and SQLite hardening

Implement enterprise-grade database observability and reliability:
- Add SLOW_QUERY_THRESHOLD = 1.0s and SQLAlchemy event listeners for query timing.
- Harden SQLite with busy_timeout=5000 to reduce lock contention errors.
- Optimize SQLite with synchronous=NORMAL for better WAL mode performance.
- Document database improvements in DATABASE_STANDARDS.md to satisfy auto-merge policy.
- Fix linting violations in main.py (SIM201, SIM105) and tests.
- Add comprehensive integration tests in tests/test_database_performance.py.

Co-authored-by: xnessom <255288032+xnessom@users.noreply.github.com>

---------

Co-authored-by: google-labs-jules[bot] <161369871+google-labs-jules[bot]@users.noreply.github.com>
Co-authored-by: xnessom <255288032+xnessom@users.noreply.github.com>

DATABASE_STANDARDS.md

@@ -388,3 +388,8 @@ To ensure enterprise-grade reliability when using SQLite:
 - **Foreign Key Enforcement**: Enabled via SQLAlchemy event listeners (`PRAGMA foreign_keys=ON`). This ensures relational integrity that is disabled by default in SQLite.
 - **Write-Ahead Logging (WAL)**: Enabled via `PRAGMA journal_mode=WAL` to improve concurrency (allowing multiple readers and one writer) and provide better durability and performance.
 - **File Permissions**: Enforced `0o600` (owner read/write only) on file-based SQLite databases to prevent unauthorized local access to sensitive trade and audit data.
+- **Lock Contention**: `PRAGMA busy_timeout=5000` is used to allow connections to wait up to 5 seconds for a lock to clear, reducing "database is locked" errors.
+- **Optimized Durability**: `PRAGMA synchronous=NORMAL` is used in WAL mode to provide high performance for writes while maintaining excellent durability.
+
+### Implementation Note (v1.3) - Observability
+- **Slow Query Logging**: The system implements automated slow query detection via SQLAlchemy event listeners. Queries exceeding `SLOW_QUERY_THRESHOLD` (default: 1.0s) are logged as warnings for performance monitoring.

src/core/database.py

@@ -11,6 +11,7 @@ from __future__ import annotations
 import logging
 import os
 import stat
+import time
 from functools import lru_cache
 from pathlib import Path
 from typing import Any
@@ -21,6 +22,28 @@ from sqlalchemy.orm import Session, sessionmaker
 
 logger = logging.getLogger(__name__)
 
+# Slow query logging threshold (seconds) as per DATABASE_STANDARDS.md
+SLOW_QUERY_THRESHOLD = 1.0
+
+
+@event.listens_for(Engine, "before_cursor_execute")
+def before_cursor_execute(conn, cursor, statement, parameters, context, executemany):
+    """Record the start time of a query."""
+    context._query_start_time = time.perf_counter()
+
+
+@event.listens_for(Engine, "after_cursor_execute")
+def after_cursor_execute(conn, cursor, statement, parameters, context, executemany):
+    """Log a warning if the query execution time exceeds the threshold."""
+    total_time = time.perf_counter() - context._query_start_time
+    if total_time > SLOW_QUERY_THRESHOLD:
+        logger.warning(
+            "Slow query detected: %s (%.2f seconds)",
+            statement,
+            total_time,
+            extra={"duration": total_time, "statement": statement},
+        )
+
 
 @event.listens_for(Engine, "connect")
 def set_sqlite_pragma(dbapi_connection, connection_record):
@@ -34,8 +57,10 @@ def set_sqlite_pragma(dbapi_connection, connection_record):
         cursor = dbapi_connection.cursor()
         cursor.execute("PRAGMA foreign_keys=ON")
         cursor.execute("PRAGMA journal_mode=WAL")
+        cursor.execute("PRAGMA busy_timeout=5000")
+        cursor.execute("PRAGMA synchronous=NORMAL")
         cursor.close()
-        logger.debug("SQLite pragmas (foreign_keys, WAL) enabled.")
+        logger.debug("SQLite pragmas (foreign_keys, WAL, busy_timeout, synchronous) enabled.")
 
 
 @lru_cache(maxsize=16)

tests/test_database_performance.py

@@ -0,0 +1,81 @@
+import logging
+from unittest.mock import patch
+
+from sqlalchemy import create_engine, text
+
+from src.core.database import SLOW_QUERY_THRESHOLD, get_engine
+
+
+def test_sqlite_pragmas_applied(tmp_path):
+    """
+    Verify that the hardened SQLite pragmas are applied to new connections.
+    """
+    # Use a file-based SQLite because :memory: doesn't support WAL mode
+    db_file = tmp_path / "test_pragmas.db"
+    db_url = f"sqlite:///{db_file}"
+
+    # Use a fresh engine to ensure the connect event triggers
+    get_engine.cache_clear()
+    engine = get_engine(db_url)
+
+    with engine.connect() as conn:
+        # Check foreign keys
+        fk = conn.execute(text("PRAGMA foreign_keys")).scalar()
+        assert fk == 1 or fk == "ON"
+
+        # Check journal mode
+        jm = conn.execute(text("PRAGMA journal_mode")).scalar()
+        assert jm.lower() == "wal"
+
+        # Check busy timeout
+        bt = conn.execute(text("PRAGMA busy_timeout")).scalar()
+        assert bt == 5000
+
+        # Check synchronous mode
+        sync = conn.execute(text("PRAGMA synchronous")).scalar()
+        # 1 = NORMAL
+        assert sync == 1 or sync == "NORMAL"
+
+
+def test_slow_query_logging(caplog):
+    """
+    Verify that slow queries trigger a warning log.
+    """
+    caplog.set_level(logging.WARNING)
+
+    # We'll use a real engine but mock time.perf_counter to simulate a delay
+    engine = create_engine("sqlite:///:memory:")
+
+    # The listeners are already registered globally on the Engine class in src.core.database
+    # But for this test, we want to ensure they are active.
+    # Since they are registered on the 'Engine' class, they should apply to any engine instance.
+
+    # Mock time.perf_counter to return 0.0 then 2.0 (exceeding 1.0s threshold)
+    with patch("src.core.database.time.perf_counter") as mock_time:
+        mock_time.side_effect = [10.0, 10.0 + SLOW_QUERY_THRESHOLD + 0.1]
+
+        with engine.connect() as conn:
+            conn.execute(text("SELECT 1"))
+
+    # Check if the warning was logged
+    assert any("Slow query detected" in record.message for record in caplog.records)
+    assert any(record.levelno == logging.WARNING for record in caplog.records)
+
+
+def test_fast_query_no_logging(caplog):
+    """
+    Verify that fast queries do NOT trigger a warning log.
+    """
+    caplog.set_level(logging.WARNING)
+    caplog.clear()
+
+    engine = create_engine("sqlite:///:memory:")
+
+    with patch("src.core.database.time.perf_counter") as mock_time:
+        mock_time.side_effect = [10.0, 10.0 + SLOW_QUERY_THRESHOLD - 0.1]
+
+        with engine.connect() as conn:
+            conn.execute(text("SELECT 1"))
+
+    # Check if the warning was NOT logged
+    assert not any("Slow query detected" in record.message for record in caplog.records)