From 70e99c52e11fb017c2ab43ef4b19bebbee6df8e4 Mon Sep 17 00:00:00 2001 From: zhao vistart Date: Tue, 10 Nov 2026 05:30:35 +0800 Subject: [PATCH 1/5] feat(logging): adapt execution logging and shared contracts --- .../impl/clickhouse/backend/backend.py | 84 ++++++++++--------- .../backend/impl/clickhouse/cli/info.py | 5 +- .../impl/clickhouse/mixins/backend_mixin.py | 13 --- .../impl/clickhouse/mixins/transaction.py | 4 +- .../feature/basic/nopk/test_keyless_models.py | 4 + .../basic/readonly/test_readonly_models.py | 4 + .../query/basic/test_find_one_or_create.py | 4 + .../ordering/test_has_many_order_by.py | 4 + 8 files changed, 66 insertions(+), 56 deletions(-) create mode 100644 tests/rhosocial/activerecord_clickhouse_test/feature/basic/nopk/test_keyless_models.py create mode 100644 tests/rhosocial/activerecord_clickhouse_test/feature/basic/readonly/test_readonly_models.py create mode 100644 tests/rhosocial/activerecord_clickhouse_test/feature/query/basic/test_find_one_or_create.py create mode 100644 tests/rhosocial/activerecord_clickhouse_test/feature/relation/ordering/test_has_many_order_by.py diff --git a/src/rhosocial/activerecord/backend/impl/clickhouse/backend/backend.py b/src/rhosocial/activerecord/backend/impl/clickhouse/backend/backend.py index 722f824..5ecdbcd 100644 --- a/src/rhosocial/activerecord/backend/impl/clickhouse/backend/backend.py +++ b/src/rhosocial/activerecord/backend/impl/clickhouse/backend/backend.py @@ -7,45 +7,44 @@ specific behaviors and SQL dialect. """ -import datetime import logging +import time from typing import Any, List, Optional, Tuple try: import clickhouse_connect from clickhouse_connect.dbapi import connect as clickhouse_connect_dbapi_connect from clickhouse_connect.driver.exceptions import ( - DatabaseError as ClickHouseDatabaseError, Error as ClickHouseError, - IntegrityError as ClickHouseIntegrityError, OperationalError as ClickHouseOperationalError, ) except ImportError: # pragma: no cover clickhouse_connect = None # type: ignore clickhouse_connect_dbapi_connect = None # type: ignore - ClickHouseDatabaseError = Exception ClickHouseError = Exception - ClickHouseIntegrityError = Exception ClickHouseOperationalError = Exception from rhosocial.activerecord.backend.base import StorageBackend -from rhosocial.activerecord.backend.errors import ( - ConnectionError, - DatabaseError, - IntegrityError, - QueryError, +from rhosocial.activerecord.backend.base.execution_logging import ( + log_batch_start, + log_batch_summary, + log_execution_error, ) +from rhosocial.activerecord.backend.base.operations import execution_log_context +from rhosocial.activerecord.backend.errors import ConnectionError, DatabaseError from rhosocial.activerecord.backend.options import ( BulkInsertOptions, BulkUpdateOptions, 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.explain import SyncExplainBackendMixin +from rhosocial.activerecord.logging.redaction import unwrap_sensitive from ..config import ClickHouseConnectionConfig from ..dialect import ClickHouseDialect from ..transaction import ClickHouseTransactionManager @@ -211,6 +210,7 @@ def bulk_insert(self, options: BulkInsertOptions) -> QueryResult: returning_columns=options.returning_columns, auto_commit=options.auto_commit, primary_key=options.primary_key, + log_context=execution_log_context(options, "bulk_insert"), ) result = super().bulk_insert(options) @@ -245,6 +245,7 @@ def update(self, options: UpdateOptions) -> QueryResult: returning_columns=options.returning_columns, auto_commit=options.auto_commit, primary_key=options.primary_key, + log_context=execution_log_context(options, "update"), ) # ClickHouse cannot report how many rows a mutation affected, so capture # the matching-row count BEFORE running the mutation (the WHERE columns @@ -422,7 +423,10 @@ def connect(self) -> None: ) self._fetch_concurrency_hint() except ClickHouseError as e: - self.log(logging.ERROR, f"Failed to connect to ClickHouse database: {str(e)}") + self.log( + logging.DEBUG, + f"Failed to connect to ClickHouse database, exception will be re-raised: {str(e)}", + ) raise ConnectionError(f"Failed to connect to ClickHouse: {str(e)}") from e def disconnect(self) -> None: @@ -479,22 +483,34 @@ def _get_cursor(self) -> Any: return self._connection.cursor() - def execute_many(self, sql: str, params_list: List[Tuple]) -> QueryResult: - """Execute the same SQL statement multiple times with different parameters.""" + 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. + + ClickHouse executes the statement once per parameter set, because the + driver's ``executemany`` path does not report per-row counts. The batch + DEBUG record and its INFO summary come from the shared execution-logging + helpers, so the canonical SQL line is not duplicated here. + """ + 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) + if not self._connection: self.connect() cursor = None - start_time = datetime.datetime.now() + start_time = time.perf_counter() try: cursor = self._get_cursor() - # Log the batch operation if logging is enabled - 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") - # Execute multiple statements escaped_sql = self._escape_literal_percent(sql) affected_rows = 0 @@ -502,24 +518,17 @@ def execute_many(self, sql: str, params_list: List[Tuple]) -> QueryResult: cursor.execute(escaped_sql, params) affected_rows += cursor.rowcount - duration = (datetime.datetime.now() - start_time).total_seconds() + duration = time.perf_counter() - start_time result = QueryResult(affected_rows=affected_rows, data=None, duration=duration) - self.log( - logging.INFO, f"Batch operation completed, affected {affected_rows} rows, duration={duration:.3f}s" - ) + log_batch_summary(self, sql, params_list, affected_rows, duration, options) return result - except ClickHouseIntegrityError as e: - self.log(logging.ERROR, f"Integrity error in batch: {str(e)}") - raise IntegrityError(str(e)) from e - except ClickHouseError as e: - self.log(logging.ERROR, f"ClickHouse error in batch: {str(e)}") - raise DatabaseError(str(e)) from e except Exception as e: - self.log(logging.ERROR, f"Unexpected error during batch execution: {str(e)}") - raise QueryError(str(e)) from e + log_execution_error(self, e, options) + self._handle_error(e) + return None finally: if cursor: cursor.close() @@ -700,8 +709,6 @@ def execute( Raises: DatabaseError: If execution fails after all retries """ - from rhosocial.activerecord.backend.options import StatementType - # If no options provided, create default options from kwargs if options is None: # Determine statement type based on SQL @@ -748,7 +755,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: # Not a connection error or max retries reached @@ -772,9 +779,7 @@ def executescript(self, sql_script: str) -> None: sql_script: A string containing one or more SQL statements separated by semicolons. """ - import time - - self.log(logging.INFO, "Executing SQL script.") + self.log(logging.DEBUG, "Executing SQL script.") start_time = time.perf_counter() if not self._connection: @@ -791,7 +796,10 @@ def executescript(self, sql_script: str) -> None: self.log(logging.INFO, f"SQL script executed successfully, duration={duration:.3f}s") except ClickHouseError 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) finally: if cursor: diff --git a/src/rhosocial/activerecord/backend/impl/clickhouse/cli/info.py b/src/rhosocial/activerecord/backend/impl/clickhouse/cli/info.py index 3d1d1ca..f6242dc 100644 --- a/src/rhosocial/activerecord/backend/impl/clickhouse/cli/info.py +++ b/src/rhosocial/activerecord/backend/impl/clickhouse/cli/info.py @@ -8,9 +8,10 @@ import argparse import inspect import json -import logging from typing import Any, Dict, List, Tuple +from rhosocial.activerecord.logging.defaults import get_logger + from rhosocial.activerecord.backend.dialect.protocols import ( WindowFunctionSupport, CTESupport, @@ -52,7 +53,7 @@ from .connection import add_connection_args, add_version_arg, resolve_connection_config_from_args from .output import INFO_OUTPUT_CHOICES, create_provider, RICH_AVAILABLE -logger = logging.getLogger(__name__) +logger = get_logger(__name__) # Groups that are specific to ClickHouse dialect DIALECT_SPECIFIC_GROUPS = {"ClickHouse-specific"} diff --git a/src/rhosocial/activerecord/backend/impl/clickhouse/mixins/backend_mixin.py b/src/rhosocial/activerecord/backend/impl/clickhouse/mixins/backend_mixin.py index 77ed5dd..d10c684 100644 --- a/src/rhosocial/activerecord/backend/impl/clickhouse/mixins/backend_mixin.py +++ b/src/rhosocial/activerecord/backend/impl/clickhouse/mixins/backend_mixin.py @@ -124,13 +124,6 @@ def get_default_adapter_suggestions(self) -> Dict[Type, Tuple[SQLTypeAdapter, Ty return suggestions - def log(self, level: int, message: str): - """Log a message with the specified level.""" - if hasattr(self, "_logger") and self._logger: - self._logger.log(level, message) - else: - print(f"[{logging.getLevelName(level)}] {message}") - CONNECTION_ERROR_CODES = { 503, 504, @@ -178,19 +171,13 @@ def _handle_error(self, error: Exception) -> None: if isinstance(error, ClickHouseIntegrityError): if "UNIQUE constraint" in error_msg or "Violates unique constraint" in error_msg: - self.log(logging.ERROR, f"Unique constraint violation: {error_msg}") raise IntegrityError(f"Unique constraint violation: {error_msg}") - self.log(logging.ERROR, f"Integrity error: {error_msg}") raise IntegrityError(error_msg) elif isinstance(error, ClickHouseDatabaseError): - self.log(logging.ERROR, f"Database error: {error_msg}") raise DatabaseError(error_msg) elif isinstance(error, ClickHouseOperationalError): - self.log(logging.ERROR, f"Operational error: {error_msg}") raise OperationalError(error_msg) elif isinstance(error, ClickHouseError): - self.log(logging.ERROR, f"ClickHouse error: {error_msg}") raise DatabaseError(error_msg) else: - self.log(logging.ERROR, f"Unexpected error: {error_msg}") raise error diff --git a/src/rhosocial/activerecord/backend/impl/clickhouse/mixins/transaction.py b/src/rhosocial/activerecord/backend/impl/clickhouse/mixins/transaction.py index e7c612b..b7cf3d4 100644 --- a/src/rhosocial/activerecord/backend/impl/clickhouse/mixins/transaction.py +++ b/src/rhosocial/activerecord/backend/impl/clickhouse/mixins/transaction.py @@ -27,16 +27,14 @@ def isolation_level(self, level: Optional[IsolationLevel]): self.log(logging.DEBUG, f"Setting isolation level to {level}") if self.is_active: - self.log(logging.ERROR, "Cannot change isolation level during active transaction") raise IsolationLevelError("Cannot change isolation level during active transaction") if level is not None and level not in self._ISOLATION_LEVELS: error_msg = f"Unsupported isolation level: {level}" - self.log(logging.ERROR, error_msg) raise IsolationLevelError(error_msg) self._isolation_level = level - self.log(logging.INFO, f"Isolation level set to {level}") + self.log(logging.DEBUG, f"Isolation level set to {level}") def _build_set_isolation_sql(self, level: IsolationLevel) -> Tuple[str, tuple]: """Build SET TRANSACTION ISOLATION LEVEL SQL statement.""" diff --git a/tests/rhosocial/activerecord_clickhouse_test/feature/basic/nopk/test_keyless_models.py b/tests/rhosocial/activerecord_clickhouse_test/feature/basic/nopk/test_keyless_models.py new file mode 100644 index 0000000..cd693a1 --- /dev/null +++ b/tests/rhosocial/activerecord_clickhouse_test/feature/basic/nopk/test_keyless_models.py @@ -0,0 +1,4 @@ +# tests/rhosocial/activerecord_clickhouse_test/feature/basic/nopk/test_keyless_models.py +"""Bridge file for the testsuite keyless model contract (sync and async).""" +from rhosocial.activerecord.testsuite.feature.basic.nopk.test_keyless_models import * # noqa: F403 +from rhosocial.activerecord.testsuite.feature.basic.nopk.test_keyless_models_async import * # noqa: F403 diff --git a/tests/rhosocial/activerecord_clickhouse_test/feature/basic/readonly/test_readonly_models.py b/tests/rhosocial/activerecord_clickhouse_test/feature/basic/readonly/test_readonly_models.py new file mode 100644 index 0000000..b77018e --- /dev/null +++ b/tests/rhosocial/activerecord_clickhouse_test/feature/basic/readonly/test_readonly_models.py @@ -0,0 +1,4 @@ +# tests/rhosocial/activerecord_clickhouse_test/feature/basic/readonly/test_readonly_models.py +"""Bridge file for the testsuite read-only model contract (sync and async).""" +from rhosocial.activerecord.testsuite.feature.basic.readonly.test_readonly_models import * # noqa: F403 +from rhosocial.activerecord.testsuite.feature.basic.readonly.test_readonly_models_async import * # noqa: F403 diff --git a/tests/rhosocial/activerecord_clickhouse_test/feature/query/basic/test_find_one_or_create.py b/tests/rhosocial/activerecord_clickhouse_test/feature/query/basic/test_find_one_or_create.py new file mode 100644 index 0000000..22f13e0 --- /dev/null +++ b/tests/rhosocial/activerecord_clickhouse_test/feature/query/basic/test_find_one_or_create.py @@ -0,0 +1,4 @@ +# tests/rhosocial/activerecord_clickhouse_test/feature/query/basic/test_find_one_or_create.py +"""Bridge file for the testsuite natural-key find_one_or_create contract.""" +from rhosocial.activerecord.testsuite.feature.query.basic.test_find_one_or_create import * # noqa: F403 +from rhosocial.activerecord.testsuite.feature.query.basic.test_find_one_or_create_async import * # noqa: F403 diff --git a/tests/rhosocial/activerecord_clickhouse_test/feature/relation/ordering/test_has_many_order_by.py b/tests/rhosocial/activerecord_clickhouse_test/feature/relation/ordering/test_has_many_order_by.py new file mode 100644 index 0000000..58374bd --- /dev/null +++ b/tests/rhosocial/activerecord_clickhouse_test/feature/relation/ordering/test_has_many_order_by.py @@ -0,0 +1,4 @@ +# tests/rhosocial/activerecord_clickhouse_test/feature/relation/ordering/test_has_many_order_by.py +"""Bridge file for the testsuite ordered HasMany contract (sync and async).""" +from rhosocial.activerecord.testsuite.feature.relation.ordering.test_has_many_order_by import * # noqa: F403 +from rhosocial.activerecord.testsuite.feature.relation.ordering.test_has_many_order_by_async import * # noqa: F403 From 3f7606257bd3191b10f4a5e6acc1181f0d63114b Mon Sep 17 00:00:00 2001 From: zhao vistart Date: Tue, 10 Nov 2026 10:20:19 +0800 Subject: [PATCH 2/5] ci: track core logging-execution branch --- .github/workflows/test.yml | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/.github/workflows/test.yml b/.github/workflows/test.yml index a0c218c..77edb14 100644 --- a/.github/workflows/test.yml +++ b/.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 From 899adc0ba95c1a116228dd5748ec9aa0bb13986c Mon Sep 17 00:00:00 2001 From: zhao vistart Date: Tue, 10 Nov 2026 10:34:22 +0800 Subject: [PATCH 3/5] fix(clickhouse): classify NULL-to-non-nullable as an integrity error --- .../backend/impl/clickhouse/mixins/backend_mixin.py | 7 +++++++ 1 file changed, 7 insertions(+) diff --git a/src/rhosocial/activerecord/backend/impl/clickhouse/mixins/backend_mixin.py b/src/rhosocial/activerecord/backend/impl/clickhouse/mixins/backend_mixin.py index d10c684..9c6596d 100644 --- a/src/rhosocial/activerecord/backend/impl/clickhouse/mixins/backend_mixin.py +++ b/src/rhosocial/activerecord/backend/impl/clickhouse/mixins/backend_mixin.py @@ -174,6 +174,13 @@ def _handle_error(self, error: Exception) -> None: raise IntegrityError(f"Unique constraint violation: {error_msg}") raise IntegrityError(error_msg) elif isinstance(error, ClickHouseDatabaseError): + # ClickHouse enforces NOT NULL through its type system, so a + # assignment of NULL to a non-nullable column arrives as a generic + # database error (CANNOT_CONVERT_TYPE) rather than as an integrity + # error. Preserve the cross-backend contract and classify it as a + # not-null violation. + if "Cannot convert NULL to a non-nullable type" in error_msg: + raise IntegrityError(f"cannot be null: {error_msg}") raise DatabaseError(error_msg) elif isinstance(error, ClickHouseOperationalError): raise OperationalError(error_msg) From 03963ddf0c6c74e0d9c497e8958369b5fb85f55b Mon Sep 17 00:00:00 2001 From: zhao vistart Date: Tue, 10 Nov 2026 12:37:22 +0800 Subject: [PATCH 4/5] chore: add changelog fragment for PR #11 --- changelog.d/11.changed.md | 1 + 1 file changed, 1 insertion(+) create mode 100644 changelog.d/11.changed.md diff --git a/changelog.d/11.changed.md b/changelog.d/11.changed.md new file mode 100644 index 0000000..fb085a3 --- /dev/null +++ b/changelog.d/11.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. From 93b12a81771f6eba2e2213afb23dc2bca431f48b Mon Sep 17 00:00:00 2001 From: zhao vistart Date: Tue, 10 Nov 2026 13:39:00 +0800 Subject: [PATCH 5/5] test(logging): cover execution logging branches --- .../logging/test_execution_logging_unit.py | 262 ++++++++++++++++++ 1 file changed, 262 insertions(+) create mode 100644 tests/rhosocial/activerecord_clickhouse_test/feature/logging/test_execution_logging_unit.py diff --git a/tests/rhosocial/activerecord_clickhouse_test/feature/logging/test_execution_logging_unit.py b/tests/rhosocial/activerecord_clickhouse_test/feature/logging/test_execution_logging_unit.py new file mode 100644 index 0000000..718d715 --- /dev/null +++ b/tests/rhosocial/activerecord_clickhouse_test/feature/logging/test_execution_logging_unit.py @@ -0,0 +1,262 @@ +# tests/rhosocial/activerecord_clickhouse_test/feature/logging/test_execution_logging_unit.py +"""Database-free coverage for ClickHouse execution logging. + +The ClickHouse driver is not needed to import the changed modules, build a +backend, or drive ``execute_many`` against a fake connection. Only the error +classification cases construct real ``clickhouse_connect`` exceptions, so +those skip when the driver is not installed. +""" + +import logging +from contextlib import contextmanager + +import pytest + +from rhosocial.activerecord.backend.errors import DatabaseError, IntegrityError +from rhosocial.activerecord.backend.impl.clickhouse.backend import ClickHouseBackend +from rhosocial.activerecord.backend.impl.clickhouse.cli import info as info_cli +from rhosocial.activerecord.backend.impl.clickhouse.config import ClickHouseConnectionConfig +from rhosocial.activerecord.backend.impl.clickhouse.mixins import ( + ClickHouseBackendMixin, + ClickHouseTransactionMixin, +) +from rhosocial.activerecord.backend.impl.clickhouse.transaction import ( + ClickHouseTransactionManager, +) +from rhosocial.activerecord.backend.options import ExecutionOptions, StatementType +from rhosocial.activerecord.backend.transaction import IsolationLevel +from rhosocial.activerecord.logging.defaults import get_logger +from rhosocial.activerecord.logging.redaction import SensitiveValue + +#: Sync and async ClickHouse backends share this logger; the backend name is +#: derived from the class name, not the module path. +CANONICAL_LOGGER = "rhosocial.activerecord.backend.clickhouse" + +#: The CLI module keeps its own module-named logger. +CLI_LOGGER = "rhosocial.activerecord.backend.impl.clickhouse.cli.info" + + +class _FakeCursor: + """Minimal DB-API cursor: executes, reports a row count, closes.""" + + def __init__(self, execute_error=None): + self.rowcount = 1 + self.execute_error = execute_error + self.executed = [] + self.closed = False + + def execute(self, sql, params=None): + if self.execute_error is not None: + raise self.execute_error + self.executed.append((sql, params)) + + def fetchone(self): + return (1,) + + def close(self): + self.closed = True + + +class _FakeConnection: + """Minimal connection whose first cursor serves the probe query. + + ``_get_cursor`` opens a probe cursor to verify the connection is alive and + then returns a fresh cursor. The fake therefore lets the first cursor + succeed and makes the second one raise when ``execute_error`` is set. + """ + + def __init__(self, execute_error=None): + self.execute_error = execute_error + self.cursors = [] + + def cursor(self): + error = self.execute_error if self.cursors else None + cursor = _FakeCursor(error) + self.cursors.append(cursor) + return cursor + + def close(self): + pass + + +class _ListHandler(logging.Handler): + """Collect records emitted by one logger.""" + + def __init__(self, records): + super().__init__(logging.DEBUG) + self._records = records + + def emit(self, record): + self._records.append(record) + + +@contextmanager +def _capture_logger(logger): + """Capture records on the logger itself, independent of propagation.""" + records = [] + handler = _ListHandler(records) + previous_level = logger.level + logger.addHandler(handler) + logger.setLevel(logging.DEBUG) + try: + yield records + finally: + logger.removeHandler(handler) + logger.setLevel(previous_level) + + +def _make_backend(): + """Build a backend without opening a connection.""" + return ClickHouseBackend( + connection_config=ClickHouseConnectionConfig( + host="localhost", + database="test_db", + ) + ) + + +@pytest.fixture +def clickhouse_exceptions(): + """The driver exception types ``_handle_error`` classifies.""" + pytest.importorskip("clickhouse_connect") + from clickhouse_connect.driver.exceptions import ( + DatabaseError as ClickHouseDatabaseError, + IntegrityError as ClickHouseIntegrityError, + ) + + return { + "database": ClickHouseDatabaseError, + "integrity": ClickHouseIntegrityError, + } + + +class TestChangedModulesImport: + """Importing the changed modules records their import-time lines.""" + + def test_changed_modules_are_imported(self): + assert issubclass(ClickHouseBackend, ClickHouseBackendMixin) + assert issubclass(ClickHouseTransactionManager, ClickHouseTransactionMixin) + assert info_cli.logger is get_logger(info_cli.__name__) + + +class TestBackendLogger: + def test_backend_uses_canonical_clickhouse_logger(self): + backend = _make_backend() + + assert backend._get_logger_name() == CANONICAL_LOGGER + assert backend.logger.name == CANONICAL_LOGGER + assert isinstance(backend.transaction_manager, ClickHouseTransactionManager) + + +class TestExecuteMany: + def test_execute_many_logs_batch_and_unwraps_sensitive_values(self): + backend = _make_backend() + backend._connection = _FakeConnection() + params_list = [(1, "alpha"), (SensitiveValue("secret"), "beta")] + + with _capture_logger(backend.logger) as records: + result = backend.execute_many("INSERT INTO t VALUES (%s, %s)", params_list) + + assert result.affected_rows == 2 + assert result.duration >= 0 + # The wrapped value reaches the driver unwrapped, never as a wrapper. + assert backend._connection.cursors[-1].executed == [ + ("INSERT INTO t VALUES (%s, %s)", (1, "alpha")), + ("INSERT INTO t VALUES (%s, %s)", ("secret", "beta")), + ] + assert backend._connection.cursors[-1].closed is True + + debug_messages = [ + record.getMessage() + for record in records + if record.name == CANONICAL_LOGGER and record.levelno == logging.DEBUG + ] + assert any("parameter_sets: 2" in message for message in debug_messages) + + summaries = [ + record for record in records if getattr(record, "event", None) == "dml.batch" + ] + assert summaries + fields = summaries[-1].activerecord + assert fields["rows_affected"] == 2 + assert fields["parameter_sets"] == 2 + + def test_execute_many_accepts_explicit_options(self): + backend = _make_backend() + backend._connection = _FakeConnection() + + result = backend.execute_many( + "INSERT INTO t VALUES (%s)", + [(1,), (2,)], + options=ExecutionOptions(stmt_type=StatementType.DML), + ) + + assert result.affected_rows == 2 + + def test_execute_many_error_branch_logs_and_maps_null_error(self, clickhouse_exceptions): + backend = _make_backend() + null_error = clickhouse_exceptions["database"]( + "Cannot convert NULL to a non-nullable type" + ) + backend._connection = _FakeConnection(execute_error=null_error) + + with _capture_logger(backend.logger) as records: + with pytest.raises(IntegrityError, match="cannot be null"): + backend.execute_many("INSERT INTO t VALUES (%s)", [(None,)]) + + failures = [ + record.getMessage() + for record in records + if "Query failed, exception will be re-raised" in record.getMessage() + ] + assert failures + assert backend._connection.cursors[-1].closed is True + + +class TestHandleError: + def test_generic_database_error_maps_to_database_error(self, clickhouse_exceptions): + backend = _make_backend() + error = clickhouse_exceptions["database"]("Syntax error near FROM") + + with pytest.raises(DatabaseError, match="Syntax error near FROM"): + backend._handle_error(error) + + def test_null_to_non_nullable_maps_to_integrity_error(self, clickhouse_exceptions): + backend = _make_backend() + error = clickhouse_exceptions["database"]( + "Cannot convert NULL to a non-nullable type" + ) + + with pytest.raises(IntegrityError, match="cannot be null"): + backend._handle_error(error) + + def test_driver_integrity_error_maps_to_integrity_error(self, clickhouse_exceptions): + backend = _make_backend() + error = clickhouse_exceptions["integrity"]("Violates unique constraint") + + with pytest.raises(IntegrityError, match="Unique constraint violation"): + backend._handle_error(error) + + +class TestIsolationLevelLogging: + def test_isolation_level_setter_logs_debug(self): + backend = _make_backend() + manager = backend.transaction_manager + + with _capture_logger(manager.logger) as records: + manager.isolation_level = IsolationLevel.READ_COMMITTED + + assert manager.isolation_level is IsolationLevel.READ_COMMITTED + messages = [ + record.getMessage() + for record in records + if record.name == CANONICAL_LOGGER + ] + assert any("Setting isolation level to" in message for message in messages) + assert any("Isolation level set to" in message for message in messages) + + +class TestCliLogger: + def test_cli_info_uses_module_logger(self): + assert isinstance(info_cli.logger, logging.Logger) + assert info_cli.logger.name == CLI_LOGGER