more autocommit messaging

Further clarified connection-level logging to indicate the BEGIN, ROLLBACK
and COMMIT log messages do not actually indicate a real transaction when
the AUTOCOMMIT isolation level is in use; messaging has been extended to
include the BEGIN message itself, and the messaging has also been fixed to
accommodate when the :class:`.Engine` level
:paramref:`.create_engine.isolation_level` parameter was used directly.

Fixes: #7853
Change-Id: Iafc78070737ad117f84262e4bde84b81a81e4ea1
(cherry picked from commit 56366924673f88e51c74d94058c11132a057ecfa)

diff --git a/doc/build/changelog/unreleased_14/7853.rst b/doc/build/changelog/unreleased_14/7853.rst
new file mode 100644 (file)
index 0000000..66856c2
--- /dev/null
+++ b/doc/build/changelog/unreleased_14/7853.rst
@@ -0,0 +1,10 @@
+.. change::
+    :tags: bug, engine
+    :tickets: 7853
+
+    Further clarified connection-level logging to indicate the BEGIN, ROLLBACK
+    and COMMIT log messages do not actually indicate a real transaction when
+    the AUTOCOMMIT isolation level is in use; messaging has been extended to
+    include the BEGIN message itself, and the messaging has also been fixed to
+    accommodate when the :class:`.Engine` level
+    :paramref:`.create_engine.isolation_level` parameter was used directly.

diff --git a/lib/sqlalchemy/engine/base.py b/lib/sqlalchemy/engine/base.py
index cf6a14728b1caef26cc59bd14e8aa02532906e52..b5a3096e5bb3082593423edd1e5720360f1889d0 100644 (file)
--- a/lib/sqlalchemy/engine/base.py
+++ b/lib/sqlalchemy/engine/base.py
@@ -905,10 +905,15 @@ class Connection(Connectable):
             and self._nested_transaction.is_active
         )
 
-    def _is_autocommit(self):
-        return (
-            self._execution_options.get("isolation_level", None)
-            == "AUTOCOMMIT"
+    def _is_autocommit_isolation(self):
+        opt_iso = self._execution_options.get("isolation_level", None)
+        return bool(
+            opt_iso == "AUTOCOMMIT"
+            or (
+                opt_iso is None
+                and getattr(self.engine.dialect, "isolation_level", None)
+                == "AUTOCOMMIT"
+            )
         )
 
     def get_transaction(self):
@@ -939,7 +944,13 @@ class Connection(Connectable):
         assert not self.__branch_from
 
         if self._echo:
-            self._log_info("BEGIN (implicit)")
+            if self._is_autocommit_isolation():
+                self._log_info(
+                    "BEGIN (implicit; DBAPI should not BEGIN due to "
+                    "autocommit mode)"
+                )
+            else:
+                self._log_info("BEGIN (implicit)")
 
         self.__in_begin = True
 
@@ -961,7 +972,7 @@ class Connection(Connectable):
 
         if self._still_open_and_dbapi_connection_is_valid:
             if self._echo:
-                if self._is_autocommit():
+                if self._is_autocommit_isolation():
                     self._log_info(
                         "ROLLBACK using DBAPI connection.rollback(), "
                         "DBAPI should ignore due to autocommit mode"
@@ -980,7 +991,7 @@ class Connection(Connectable):
         # if a connection has this set as the isolation level, we can skip
         # the "autocommit" warning as the operation will do "autocommit"
         # in any case
-        if autocommit and not self._is_autocommit():
+        if autocommit and not self._is_autocommit_isolation():
             util.warn_deprecated_20(
                 "The current statement is being autocommitted using "
                 "implicit autocommit, which will be removed in "
@@ -993,7 +1004,7 @@ class Connection(Connectable):
             self.dispatch.commit(self)
 
         if self._echo:
-            if self._is_autocommit():
+            if self._is_autocommit_isolation():
                 self._log_info(
                     "COMMIT using DBAPI connection.commit(), "
                     "DBAPI should ignore due to autocommit mode"

diff --git a/test/engine/test_logging.py b/test/engine/test_logging.py
index 806336368b183a127330f26c215084b054015070..7a0ed6e7934bfe5c9fbfee2d6d4ab0849a5c3a0e 100644 (file)
--- a/test/engine/test_logging.py
+++ b/test/engine/test_logging.py
@@ -640,6 +640,13 @@ class TransactionContextLoggingTest(fixtures.TestBase):
         e.connect().close()
         return e
 
+    @testing.fixture()
+    def autocommit_iso_logging_engine(self, testing_engine):
+        kw = {"echo": True, "future": True, "isolation_level": "AUTOCOMMIT"}
+        e = testing_engine(options=kw)
+        e.connect().close()
+        return e
+
     @testing.fixture()
     def plain_logging_engine(self, testing_engine):
         # deliver an engine with logging using the plain logging API,
@@ -675,6 +682,38 @@ class TransactionContextLoggingTest(fixtures.TestBase):
 
         assert_buf(["BEGIN (implicit)", "ROLLBACK"])
 
+    def test_commit_as_you_go_block_commit_engine_level_autocommit(
+        self, autocommit_iso_logging_engine, assert_buf
+    ):
+        with autocommit_iso_logging_engine.connect() as conn:
+            conn.begin()
+            conn.commit()
+
+        assert_buf(
+            [
+                "BEGIN (implicit; DBAPI should not "
+                "BEGIN due to autocommit mode)",
+                "COMMIT using DBAPI connection.commit(), DBAPI "
+                "should ignore due to autocommit mode",
+            ]
+        )
+
+    def test_commit_engine_level_autocommit_exec_opt_nonauto(
+        self, autocommit_iso_logging_engine, assert_buf
+    ):
+        with autocommit_iso_logging_engine.execution_options(
+            isolation_level=testing.db.dialect.default_isolation_level
+        ).connect() as conn:
+            conn.begin()
+            conn.commit()
+
+        assert_buf(
+            [
+                "BEGIN (implicit)",
+                "COMMIT",
+            ]
+        )
+
     def test_commit_as_you_go_block_commit_autocommit(
         self, logging_engine, assert_buf
     ):
@@ -686,7 +725,8 @@ class TransactionContextLoggingTest(fixtures.TestBase):
 
         assert_buf(
             [
-                "BEGIN (implicit)",
+                "BEGIN (implicit; DBAPI should not "
+                "BEGIN due to autocommit mode)",
                 "COMMIT using DBAPI connection.commit(), DBAPI "
                 "should ignore due to autocommit mode",
             ]
@@ -703,7 +743,8 @@ class TransactionContextLoggingTest(fixtures.TestBase):
 
         assert_buf(
             [
-                "BEGIN (implicit)",
+                "BEGIN (implicit; DBAPI should not "
+                "BEGIN due to autocommit mode)",
                 "ROLLBACK using DBAPI connection.rollback(), DBAPI "
                 "should ignore due to autocommit mode",
             ]