psycopg2 NOTICE fixup

- don't call relatively expensive isEnabledFor(), just call _log_notices
- don't reset the list if it's empty
- fix the test to use a custom function to definitely create a notice, confirmed
that PG seems to no longer create the "implicit sequence" notices
- assert that the reset of the notices works too
- update the docs to illustrate for folks who haven't worked with logging before

Change-Id: I7291e647c177d338e0ad673f3106b4d503e4b3ea

diff --git a/lib/sqlalchemy/dialects/postgresql/psycopg2.py b/lib/sqlalchemy/dialects/postgresql/psycopg2.py
index f7c5f668b4972ab362656263ea38ff7ac169e2fc..cd875e71c89a5cca5f9782c87e6525577ceea9e9 100644 (file)
--- a/lib/sqlalchemy/dialects/postgresql/psycopg2.py
+++ b/lib/sqlalchemy/dialects/postgresql/psycopg2.py
@@ -322,11 +322,25 @@ NOTICE logging
 ---------------
 
 The psycopg2 dialect will log PostgreSQL NOTICE messages
-via the ``sqlalchemy.dialects.postgresql`` logger::
+via the ``sqlalchemy.dialects.postgresql`` logger.  When this logger
+is set to the ``logging.INFO`` level, notice messages will be logged::
 
     import logging
+
+    logging.getLogger('sqlalchemy.dialects.postgresql').setLevel(logging.INFO)
+
+Above, it is assumed that logging is configured externally.  If this is not
+the case, configuration such as ``logging.basicConfig()`` must be utilized::
+
+    import logging
+
+    logging.basicConfig()   # log messages to stdout
     logging.getLogger('sqlalchemy.dialects.postgresql').setLevel(logging.INFO)
 
+.. seealso::
+
+    `Logging HOWTO <https://docs.python.org/3/howto/logging.html>`_ - on the python.org website
+
 .. _psycopg2_hstore:
 
 HSTORE type
@@ -392,7 +406,7 @@ from ... import processors
 from ... import types as sqltypes
 from ... import util
 from ...engine import result as _result
-
+from ...util import collections_abc
 
 try:
     from uuid import UUID as _python_UUID  # noqa
@@ -511,9 +525,7 @@ class PGExecutionContext_psycopg2(PGExecutionContext):
         return self._dbapi_connection.cursor(ident)
 
     def get_result_proxy(self):
-        # TODO: ouch
-        if logger.isEnabledFor(logging.INFO):
-            self._log_notices(self.cursor)
+        self._log_notices(self.cursor)
 
         if self._is_server_side:
             return _result.BufferedRowResultProxy(self)
@@ -521,6 +533,15 @@ class PGExecutionContext_psycopg2(PGExecutionContext):
             return _result.ResultProxy(self)
 
     def _log_notices(self, cursor):
+        # check also that notices is an iterable, after it's already
+        # established that we will be iterating through it.  This is to get
+        # around test suites such as SQLAlchemy's using a Mock object for
+        # cursor
+        if not cursor.connection.notices or not isinstance(
+            cursor.connection.notices, collections_abc.Iterable
+        ):
+            return
+
         for notice in cursor.connection.notices:
             # NOTICE messages have a
             # newline character at the end

diff --git a/test/dialect/postgresql/test_dialect.py b/test/dialect/postgresql/test_dialect.py
index 25cba6269c387022e2c5dd3a9b953b914e4162a6..0bbfe50fb57a86e7afc0bab5075507fbb4387f8b 100644 (file)
--- a/test/dialect/postgresql/test_dialect.py
+++ b/test/dialect/postgresql/test_dialect.py
@@ -39,6 +39,7 @@ from sqlalchemy.testing.assertions import assert_raises_message
 from sqlalchemy.testing.assertions import AssertsCompiledSQL
 from sqlalchemy.testing.assertions import AssertsExecutionResults
 from sqlalchemy.testing.assertions import eq_
+from sqlalchemy.testing.assertions import eq_regex
 from sqlalchemy.testing.assertions import ne_
 from sqlalchemy.testing.mock import Mock
 from ...engine import test_execute
@@ -267,11 +268,9 @@ class MiscBackendTest(
         )
         assert isinstance(exception, exc.OperationalError)
 
-    # currently not passing with pg 9.3 that does not seem to generate
-    # any notices here, would rather find a way to mock this
     @testing.requires.no_coverage
     @testing.requires.psycopg2_compatibility
-    def _test_notice_logging(self):
+    def test_notice_logging(self):
         log = logging.getLogger("sqlalchemy.dialects.postgresql")
         buf = logging.handlers.BufferingHandler(100)
         lev = log.level
@@ -281,15 +280,29 @@ class MiscBackendTest(
             conn = testing.db.connect()
             trans = conn.begin()
             try:
-                conn.execute("create table foo (id serial primary key)")
+                conn.execute(
+                    """
+CREATE OR REPLACE FUNCTION note(message varchar) RETURNS integer AS $$
+BEGIN
+  RAISE NOTICE 'notice: %%', message;
+  RETURN NULL;
+END;
+$$ LANGUAGE plpgsql;
+"""
+                )
+                conn.execute("SELECT note('hi there')")
+                conn.execute("SELECT note('another note')")
             finally:
                 trans.rollback()
         finally:
             log.removeHandler(buf)
             log.setLevel(lev)
         msgs = " ".join(b.msg for b in buf.buffer)
-        assert "will create implicit sequence" in msgs
-        assert "will create implicit index" in msgs
+        eq_regex(
+            msgs,
+            "NOTICE:  notice: hi there(\nCONTEXT: .*?)? "
+            "NOTICE:  notice: another note(\nCONTEXT: .*?)?",
+        )
 
     @testing.requires.psycopg2_or_pg8000_compatibility
     @engines.close_open_connections