feat(logging): adapt execution logging and shared contracts

.github/workflows/test.yml

@@ -66,7 +66,7 @@ jobs:
 
       - name: Install activerecord and testsuite
         run: |
-          pip install "rhosocial-activerecord @ git+https://github.com/rhosocial/python-activerecord.git@feature/partition-maintenance"  # NOSONAR
+          pip install "rhosocial-activerecord @ git+https://github.com/rhosocial/python-activerecord.git@feature/logging-execution"  # NOSONAR
           pip install "rhosocial-activerecord-testsuite @ git+https://github.com/rhosocial/python-activerecord-testsuite.git@release/v1.0.0.dev17"
 
       - name: Install dependencies
@@ -153,7 +153,7 @@ jobs:
 
       - name: Install activerecord and testsuite
         run: |
-          pip install "rhosocial-activerecord @ git+https://github.com/rhosocial/python-activerecord.git@feature/partition-maintenance"  # NOSONAR
+          pip install "rhosocial-activerecord @ git+https://github.com/rhosocial/python-activerecord.git@feature/logging-execution"  # NOSONAR
           pip install "rhosocial-activerecord-testsuite @ git+https://github.com/rhosocial/python-activerecord-testsuite.git@release/v1.0.0.dev17"
 
       - name: Install dependencies

changelog.d/16.changed.md

@@ -0,0 +1 @@
+Adapted this backend to the core execution logging contract: structured execution summaries, shared sync/async logger ownership, redacted SQL logging, and bridges for the shared relation/query/basic contracts.

src/rhosocial/activerecord/backend/impl/mariadb/async_transaction.py

@@ -107,7 +107,7 @@ async def _do_create_savepoint(self, name: str) -> None:
             await cursor.close()
         except Exception as e:
             error_msg = f"Failed to create savepoint {name}: {str(e)}"
-            self.log(logging.ERROR, error_msg)
+            self.log(logging.DEBUG, error_msg)
             raise TransactionError(error_msg) from e
 
     async def _do_release_savepoint(self, name: str) -> None:
@@ -121,7 +121,7 @@ async def _do_release_savepoint(self, name: str) -> None:
             await cursor.close()
         except Exception as e:
             error_msg = f"Failed to release savepoint {name}: {str(e)}"
-            self.log(logging.ERROR, error_msg)
+            self.log(logging.DEBUG, error_msg)
             raise TransactionError(error_msg) from e
 
     async def _do_rollback_savepoint(self, name: str) -> None:
@@ -135,5 +135,5 @@ async def _do_rollback_savepoint(self, name: str) -> None:
             await cursor.close()
         except Exception as e:
             error_msg = f"Failed to rollback to savepoint {name}: {str(e)}"
-            self.log(logging.ERROR, error_msg)
+            self.log(logging.DEBUG, error_msg)
             raise TransactionError(error_msg) from e

src/rhosocial/activerecord/backend/impl/mariadb/backend/async_backend.py

@@ -6,23 +6,25 @@
 adaptations tailored for MariaDB's specific behaviors and SQL dialect.
 """
 
-import datetime
 import logging
 import time
-from typing import List, Optional, Tuple, Any, Dict
+from typing import List, Optional, Tuple, Any
 
 from rhosocial.activerecord.backend.base import AsyncStorageBackend
+from rhosocial.activerecord.backend.base.execution_logging import (
+    log_batch_start,
+    log_batch_summary,
+    log_execution_error,
+)
 from rhosocial.activerecord.backend.errors import (
     ConnectionError,
-    DatabaseError,
-    DeadlockError,
-    IntegrityError,
     OperationalError,
-    QueryError,
 )
+from rhosocial.activerecord.backend.options import ExecutionOptions, StatementType
 from rhosocial.activerecord.backend.result import QueryResult
 from rhosocial.activerecord.backend.introspection.backend_mixin import IntrospectorBackendMixin
 from rhosocial.activerecord.backend.explain import AsyncExplainBackendMixin
+from rhosocial.activerecord.logging.redaction import unwrap_sensitive
 
 from ..config import MariaDBConnectionConfig
 from ..dialect import MariaDBDialect
@@ -44,6 +46,9 @@ class AsyncMariaDBBackend(
     Connector/Python 2.0 through ``mariadb.asyncConnect``.
     """
 
+    # Sync and async backends share one library logger name.
+    _logger_name = "rhosocial.activerecord.backend.mariadb"
+
     def __init__(self, **kwargs):
         """Initialize async MariaDB backend with connection configuration.
 
@@ -93,7 +98,7 @@ def __init__(self, **kwargs):
 
         self._register_mariadb_adapters()
 
-        self.log(logging.INFO, "AsyncMariaDBBackend initialized")
+        self.log(logging.DEBUG, "AsyncMariaDBBackend initialized")
 
     async def executescript(self, sql_script: str) -> None:
         """Execute a multi-statement SQL script asynchronously.
@@ -123,7 +128,10 @@ async def executescript(self, sql_script: str) -> None:
             duration = time.perf_counter() - start_time
             self.log(logging.DEBUG, f"SQL script executed successfully, duration={duration:.3f}s")
         except Exception as e:
-            self.log(logging.ERROR, f"Error executing SQL script: {str(e)}")
+            self.log(
+                logging.DEBUG,
+                f"Error executing SQL script, exception will be re-raised: {str(e)}",
+            )
             self._handle_error(e)
 
     def _parse_explain_result(self, raw_rows, sql, duration):
@@ -196,7 +204,7 @@ async def _connect_mariadb_async(self):
             await self._fetch_concurrency_hint()
             await self.introspect_and_adapt()
         except mariadb.Error as e:
-            self.log(logging.ERROR, f"Failed to connect to MariaDB database: {str(e)}")
+            self.log(logging.DEBUG, f"Failed to connect to MariaDB database: {str(e)}")
             raise ConnectionError(f"Failed to connect to MariaDB: {str(e)}") from e
 
     async def disconnect(self):
@@ -210,7 +218,7 @@ async def disconnect(self):
                 self._connection = None
                 self.log(logging.INFO, "Disconnected from MariaDB database")
             except Exception as e:
-                self.log(logging.ERROR, f"Error during disconnect: {str(e)}")
+                self.log(logging.DEBUG, f"Error during disconnect: {str(e)}")
                 raise OperationalError(f"Error during MariaDB disconnect: {str(e)}") from e
 
     async def _get_cursor(self):
@@ -220,43 +228,44 @@ async def _get_cursor(self):
 
         return self._connection.cursor()
 
-    async def execute_many(self, sql: str, params_list: List[Tuple]) -> QueryResult:
+    async def execute_many(
+        self,
+        sql: str,
+        params_list: List[Tuple],
+        *,
+        options: Optional[ExecutionOptions] = None,
+    ) -> QueryResult:
         """Execute the same SQL statement multiple times with different parameters."""
+        if options is None:
+            options = ExecutionOptions(stmt_type=StatementType.DML)
+        params_list = [unwrap_sensitive(params) for params in params_list]
+        log_batch_start(self, sql, params_list, options)
+        start_time = time.perf_counter()
+
         if not self._connection:
+            self.log(logging.DEBUG, "No active connection, establishing new connection")
             await self.connect()
 
         cursor = None
-        start_time = datetime.datetime.now()
-
         try:
             cursor = await self._get_cursor()
 
-            if getattr(self.config, 'log_queries', False):
-                self.log(logging.DEBUG, f"Executing batch operation: {sql}")
-                self.log(logging.DEBUG, f"With {len(params_list)} parameter sets")
-
             affected_rows = 0
             for params in params_list:
                 await cursor.execute(sql, params)
                 affected_rows += cursor.rowcount
 
-            duration = (datetime.datetime.now() - start_time).total_seconds()
+            duration = time.perf_counter() - start_time
+            log_batch_summary(self, sql, params_list, affected_rows, duration, options)
 
-            result = QueryResult(
+            return QueryResult(
                 affected_rows=affected_rows,
                 data=None,
                 duration=duration
             )
 
-            self.log(
-                logging.INFO,
-                f"Batch operation completed, affected {affected_rows} rows, "
-                f"duration={duration:.3f}s"
-            )
-            return result
-
         except Exception as e:
-            self.log(logging.ERROR, f"Error in batch operation: {str(e)}")
+            log_execution_error(self, e, options)
             await self._handle_error(e)
         finally:
             if cursor:
@@ -331,7 +340,7 @@ async def ping(self, reconnect: bool = True) -> bool:
                     await self.connect()
                     return True
                 except Exception as connect_error:
-                    self.log(logging.ERROR, f"Failed to reconnect: {str(connect_error)}")
+                    self.log(logging.WARNING, f"Failed to reconnect: {str(connect_error)}")
                     return False
             return False
 
@@ -357,12 +366,10 @@ async def execute(
         sql: str,
         params: Optional[Tuple] = None,
         *,
-        options=None,
+        options: Optional[ExecutionOptions] = None,
         **kwargs
     ) -> QueryResult:
         """Execute a SQL statement with optional parameters asynchronously."""
-        from rhosocial.activerecord.backend.options import ExecutionOptions, StatementType
-
         if options is None:
             sql_upper = sql.strip().upper()
             if sql_upper.startswith(('SELECT', 'WITH', 'SHOW', 'DESCRIBE', 'EXPLAIN')):

src/rhosocial/activerecord/backend/impl/mariadb/backend/backend.py

@@ -16,33 +16,47 @@
 
 import logging
 import time
-import datetime
 import mariadb
-from typing import Any, Dict, List, Optional, Tuple, Union
+from typing import Dict, List, Optional, Tuple, Union
 
 from rhosocial.activerecord.backend.base import StorageBackend
+from rhosocial.activerecord.backend.base.execution_logging import (
+    log_batch_start,
+    log_batch_summary,
+    log_execution_error,
+)
 from rhosocial.activerecord.backend.config import ConnectionConfig
 from rhosocial.activerecord.backend.errors import (
     ConnectionError,
     DatabaseError,
-    IntegrityError,
     OperationalError,
-    QueryError,
-    DeadlockError,
 )
-from rhosocial.activerecord.backend.options import DeleteOptions, ExecutionOptions, InsertOptions, StatementType, UpdateOptions
+from rhosocial.activerecord.backend.options import (
+    DeleteOptions,
+    ExecutionOptions,
+    InsertOptions,
+    StatementType,
+    UpdateOptions,
+)
 from rhosocial.activerecord.backend.result import QueryResult
 from rhosocial.activerecord.backend.introspection.backend_mixin import IntrospectorBackendMixin
 from rhosocial.activerecord.backend.introspection.executor import IntrospectorExecutor
 from rhosocial.activerecord.backend.explain import SyncExplainBackendMixin
+from rhosocial.activerecord.logging.redaction import unwrap_sensitive
 
 from ..config import MariaDBConnectionConfig
 from ..dialect import MariaDBDialect
 from ..expression.status import MariaDBVersionQuery
 from ..transaction import MariaDBTransactionManager
 from ..mixins import CONNECTION_ERROR_CODES, MariaDBBackendMixin, MariaDBConcurrencyMixin
 
-class MariaDBBackend(MariaDBBackendMixin, MariaDBConcurrencyMixin, SyncExplainBackendMixin, IntrospectorBackendMixin, StorageBackend):
+class MariaDBBackend(
+    MariaDBBackendMixin,
+    MariaDBConcurrencyMixin,
+    SyncExplainBackendMixin,
+    IntrospectorBackendMixin,
+    StorageBackend,
+):
     """Synchronous MariaDB backend implementation.
 
     Provides:
@@ -56,6 +70,9 @@ class MariaDBBackend(MariaDBBackendMixin, MariaDBConcurrencyMixin, SyncExplainBa
     Plan B (Retry): If connection error occurs mid-query, retry up to max_retries
     """
 
+    # Sync and async backends share one library logger name.
+    _logger_name = "rhosocial.activerecord.backend.mariadb"
+
     def __init__(
         self,
         connection_config: Optional[Union[ConnectionConfig, MariaDBConnectionConfig]] = None,
@@ -163,7 +180,7 @@ def connect(self) -> None:
             self._fetch_concurrency_hint()
             self.introspect_and_adapt()
         except mariadb.Error as e:
-            self.log(logging.ERROR, f"Failed to connect to MariaDB database: {str(e)}")
+            self.log(logging.DEBUG, f"Failed to connect to MariaDB database: {str(e)}")
             raise ConnectionError(f"Failed to connect: {str(e)}") from e
 
     def disconnect(self) -> None:
@@ -185,7 +202,7 @@ def disconnect(self) -> None:
             else:
                 self.log(logging.DEBUG, "Disconnect called on already closed connection")
         except mariadb.Error as e:
-            self.log(logging.ERROR, f"Error during disconnect: {str(e)}")
+            self.log(logging.DEBUG, f"Error during disconnect: {str(e)}")
             raise ConnectionError(f"Failed to disconnect: {str(e)}") from e
 
     def ping(self, reconnect: bool = True) -> bool:
@@ -289,7 +306,7 @@ def _reconnect(self) -> bool:
             self.log(logging.INFO, "Reconnection successful")
             return True
         except Exception as e:
-            self.log(logging.ERROR, f"Reconnection failed: {str(e)}")
+            self.log(logging.WARNING, f"Reconnection failed: {str(e)}")
             return False
 
     def _handle_error(self, error: Exception) -> None:
@@ -344,7 +361,7 @@ def execute(
         sql: str,
         params: Optional[Union[Tuple, Dict, List]] = None,
         *,
-        options=None,
+        options: Optional[ExecutionOptions] = None,
         max_retries: int = 2,
         **kwargs
     ) -> Optional[QueryResult]:
@@ -403,7 +420,7 @@ def execute(
                     if self._reconnect():
                         continue
                     else:
-                        self.log(logging.ERROR, "Reconnection failed, aborting retry")
+                        self.log(logging.DEBUG, "Reconnection failed, aborting retry")
                         break
                 else:
                     break
@@ -413,17 +430,27 @@ def execute(
 
         raise DatabaseError(f"Execution failed after {max_retries + 1} attempts")
 
-    def execute_many(self, sql: str, params_list: List[Tuple]) -> Optional[QueryResult]:
+    def execute_many(
+        self,
+        sql: str,
+        params_list: List[Tuple],
+        *,
+        options: Optional[ExecutionOptions] = None,
+    ) -> Optional[QueryResult]:
         """Execute batch operations with the same SQL statement and multiple parameter sets.
 
         Args:
             sql: The SQL statement to execute.
             params_list: List of parameter tuples.
+            options: Optional ExecutionOptions carrying the logging context.
 
         Returns:
             QueryResult or None.
         """
-        self.log(logging.DEBUG, f"Executing batch operation with {len(params_list)} parameter sets")
+        if options is None:
+            options = ExecutionOptions(stmt_type=StatementType.DML)
+        params_list = [unwrap_sensitive(params) for params in params_list]
+        log_batch_start(self, sql, params_list, options)
         start_time = time.perf_counter()
 
         try:
@@ -436,13 +463,10 @@ def execute_many(self, sql: str, params_list: List[Tuple]) -> Optional[QueryResu
             rowcount = cursor.rowcount
             duration = time.perf_counter() - start_time
 
-            self.log(
-                logging.DEBUG,
-                f"Batch operation completed, affected {rowcount} rows, duration={duration:.3f}s"
-            )
+            log_batch_summary(self, sql, params_list, rowcount, duration, options)
             return QueryResult(affected_rows=rowcount, duration=duration)
         except Exception as e:
-            self.log(logging.ERROR, f"Error in batch operation: {str(e)}")
+            log_execution_error(self, e, options)
             self._handle_error(e)
             return None
 
@@ -477,7 +501,10 @@ def executescript(self, sql_script: str) -> None:
             duration = time.perf_counter() - start_time
             self.log(logging.DEBUG, f"SQL script executed successfully, duration={duration:.3f}s")
         except Exception as e:
-            self.log(logging.ERROR, f"Error executing SQL script: {str(e)}")
+            self.log(
+                logging.DEBUG,
+                f"Error executing SQL script, exception will be re-raised: {str(e)}",
+            )
             self._handle_error(e)
 
     @property
@@ -518,7 +545,7 @@ def get_server_version(self) -> Tuple[int, int, int]:
             return self._server_version_cache
         except Exception as e:
             error_msg = f"Failed to determine MariaDB version: {str(e)}"
-            self.log(logging.ERROR, error_msg)
+            self.log(logging.DEBUG, error_msg)
             raise OperationalError(error_msg) from e
 
     def introspect_and_adapt(self) -> None: