Include newlines in StatementError formatting

Revised the formatting for :class:`.StatementError` when stringified. Each
error detail is broken up over multiple newlines instead of spaced out on a
single line.  Additionally, the SQL representation now stringifies the SQL
statement rather than using ``repr()``, so that newlines are rendered as is.
Pull request courtesy Nate Clark.

Fixes: #4500
Closes: #4501
Pull-request: https://github.com/sqlalchemy/sqlalchemy/pull/4501
Pull-request-sha: 60cc0ee68dc96b8f483a60d37bcb26b6c6d53efe

Change-Id: I79d8418b7495e5691c9a56f41e79495c26a967ff

diff --git a/doc/build/changelog/migration_13.rst b/doc/build/changelog/migration_13.rst
index c133bd6620c8d22a7597bb891a41b3534bdbf8fa..f08c5940500590b413030df07870701f8e9e111d 100644 (file)
--- a/doc/build/changelog/migration_13.rst
+++ b/doc/build/changelog/migration_13.rst
@@ -1662,3 +1662,33 @@ primary key column::
 :ticket:`4362`
 
 :ticket:`4235`
+
+.. _change_4500:
+
+Changed StatementError formatting (newlines and %s)
+=================================================================================
+
+Two changes are introduced to the string representation for ``StatementError``.
+The "detail" and "SQL" portions of the string representation are now
+separated by newlines, and newlines that are present in the original SQL
+statement are maintained.   The goal is to improve readability while still
+keeping the original error message on one line for logging purposes.
+
+This means that an error message that previously looked like this::
+
+    sqlalchemy.exc.StatementError: (sqlalchemy.exc.InvalidRequestError) A value is required for bind parameter 'id' [SQL: 'select * from reviews\nwhere id = ?'] (Background on this error at: http://sqlalche.me/e/cd3x)
+
+Will now look like this::
+
+    sqlalchemy.exc.StatementError: (sqlalchemy.exc.InvalidRequestError) A value is required for bind parameter 'id'
+    [SQL: select * from reviews
+    where id = ?]
+    (Background on this error at: http://sqlalche.me/e/cd3x)
+
+The primary impact of this change is that consumers can no longer assume that
+a complete exception message is on a single line, however the original
+"error" portion that is generated from the DBAPI driver or SQLAlchemy internals
+will still be on the first line.
+
+:ticket:`4500`
+

diff --git a/doc/build/changelog/unreleased_13/4500.rst b/doc/build/changelog/unreleased_13/4500.rst
new file mode 100644 (file)
index 0000000..9aea02f
--- /dev/null
+++ b/doc/build/changelog/unreleased_13/4500.rst
@@ -0,0 +1,13 @@
+.. change::
+   :tags: feature, engine
+   :tickets: 4500
+
+   Revised the formatting for :class:`.StatementError` when stringified. Each
+   error detail is broken up over multiple newlines instead of spaced out on a
+   single line.  Additionally, the SQL representation now stringifies the SQL
+   statement rather than using ``repr()``, so that newlines are rendered as is.
+   Pull request courtesy Nate Clark.
+
+   .. seealso::
+
+        :ref:`change_4500`

diff --git a/lib/sqlalchemy/exc.py b/lib/sqlalchemy/exc.py
index b9e2f933965afce395dbf6784710c9585c1b0a5e..5ce2d5df22a74e8d858a7604833cae957ca9e09b 100644 (file)
--- a/lib/sqlalchemy/exc.py
+++ b/lib/sqlalchemy/exc.py
@@ -76,7 +76,7 @@ class SQLAlchemyError(Exception):
         return self._sql_message(compat.py3k)
 
     def __unicode__(self):
-        return self._sql_message(True)
+        return self._sql_message(as_unicode=True)
 
 
 class ArgumentError(SQLAlchemyError):
@@ -346,14 +346,20 @@ class StatementError(SQLAlchemyError):
 
         details = [self._message(as_unicode=as_unicode)]
         if self.statement:
-            details.append("[SQL: %r]" % self.statement)
+            if not as_unicode and not compat.py3k:
+                stmt_detail = "[SQL: %s]" % compat.safe_bytestring(
+                    self.statement
+                )
+            else:
+                stmt_detail = "[SQL: %s]" % self.statement
+            details.append(stmt_detail)
             if self.params:
                 params_repr = util._repr_params(self.params, 10)
                 details.append("[parameters: %r]" % params_repr)
         code_str = self._code_str()
         if code_str:
             details.append(code_str)
-        return " ".join(["(%s)" % det for det in self.detail] + details)
+        return "\n".join(["(%s)" % det for det in self.detail] + details)
 
 
 class DBAPIError(StatementError):

diff --git a/lib/sqlalchemy/util/compat.py b/lib/sqlalchemy/util/compat.py
index ff644cd36f18995324e708b287f4ce10b954964d..c12f2d3798b3b31fd69c176c2f9fe2f9ee2b40ae 100644 (file)
--- a/lib/sqlalchemy/util/compat.py
+++ b/lib/sqlalchemy/util/compat.py
@@ -227,6 +227,15 @@ else:
             # error callback"
             return repr(text)[1:-1].decode()
 
+    def safe_bytestring(text):
+        # py2k only
+        if not isinstance(text, string_types):
+            return unicode(text).encode("ascii", errors="backslashreplace")
+        elif isinstance(text, unicode):
+            return text.encode("ascii", errors="backslashreplace")
+        else:
+            return text
+
     # not as nice as that of Py3K, but at least preserves
     # the code line where the issue occurred
     exec(

diff --git a/test/base/test_except.py b/test/base/test_except.py
index 58943902ce3aa3a14b690f99cfc7756f92adcaa0..7dcfbb1f0923ab97d77fc93d06a6da6c7bf72a22 100644 (file)
--- a/test/base/test_except.py
+++ b/test/base/test_except.py
@@ -70,9 +70,26 @@ class WrapTest(fixtures.TestBase):
         except sa_exceptions.DBAPIError as exc:
             eq_(
                 str(exc),
-                "(test.base.test_except.OperationalError)  "
-                "[SQL: 'this is a message'] (Background on this error at: "
-                "http://sqlalche.me/e/e3q8)",
+                "(test.base.test_except.OperationalError) \n"
+                "[SQL: this is a message]\n"
+                "(Background on this error at: http://sqlalche.me/e/e3q8)",
+            )
+
+    def test_tostring_with_newlines(self):
+        try:
+            raise sa_exceptions.DBAPIError.instance(
+                "this is a message\nthis is the next line\nthe last line",
+                None,
+                OperationalError(),
+                DatabaseError,
+            )
+        except sa_exceptions.DBAPIError as exc:
+            eq_(
+                str(exc),
+                "(test.base.test_except.OperationalError) \n"
+                "[SQL: this is a message\nthis is the next line\n"
+                "the last line]\n"
+                "(Background on this error at: http://sqlalche.me/e/e3q8)",
             )
 
     def test_statement_error_no_code(self):
@@ -86,8 +103,8 @@ class WrapTest(fixtures.TestBase):
         except sa_exceptions.StatementError as err:
             eq_(
                 str(err),
-                "(sqlalchemy.exc.InvalidRequestError) hello "
-                "[SQL: 'select * from table'] [parameters: [{'x': 1}]]",
+                "(sqlalchemy.exc.InvalidRequestError) hello\n"
+                "[SQL: select * from table]\n[parameters: [{'x': 1}]]",
             )
             eq_(err.args, ("(sqlalchemy.exc.InvalidRequestError) hello",))
 
@@ -102,8 +119,9 @@ class WrapTest(fixtures.TestBase):
         except sa_exceptions.StatementError as err:
             eq_(
                 str(err),
-                "(sqlalchemy.exc.InvalidRequestError) hello "
-                "[SQL: 'select * from table'] [parameters: [{'x': 1}]] "
+                "(sqlalchemy.exc.InvalidRequestError) hello\n"
+                "[SQL: select * from table]\n"
+                "[parameters: [{'x': 1}]]\n"
                 "(Background on this error at: http://sqlalche.me/e/abcd)",
             )
             eq_(err.args, ("(sqlalchemy.exc.InvalidRequestError) hello",))
@@ -114,7 +132,7 @@ class WrapTest(fixtures.TestBase):
         orig.args = [2006, "Test raise operational error"]
         eq_(
             str(orig),
-            "(2006, 'Test raise operational error') "
+            "(2006, 'Test raise operational error')\n"
             "(Background on this error at: http://sqlalche.me/e/dbapi)",
         )
 
@@ -125,7 +143,7 @@ class WrapTest(fixtures.TestBase):
         eq_(
             compat.text_type(orig),
             compat.u(
-                "méil (Background on this error at: "
+                "méil\n(Background on this error at: "
                 "http://sqlalche.me/e/dbapi)"
             ),
         )
@@ -153,8 +171,9 @@ class WrapTest(fixtures.TestBase):
             )
         except sa_exceptions.DBAPIError as exc:
             assert str(exc).startswith(
-                "(test.base.test_except.OperationalError)  "
-                "[SQL: 'this is a message'] [parameters: {"
+                "(test.base.test_except.OperationalError) \n"
+                "[SQL: this is a message]\n"
+                "[parameters: {"
             )
 
     def test_tostring_large_list(self):
@@ -165,10 +184,10 @@ class WrapTest(fixtures.TestBase):
                 OperationalError(),
                 DatabaseError,
             )
-        except sa_exceptions.DBAPIError as exc:
-            assert str(exc).startswith(
-                "(test.base.test_except.OperationalError)  "
-                "[SQL: 'this is a message'] [parameters: "
+        except sa_exceptions.DBAPIError as ex:
+            assert str(ex).startswith(
+                "(test.base.test_except.OperationalError) \n"
+                "[SQL: this is a message]\n[parameters: "
                 "[1, 2, 3, 4, 5, 6, 7, 8, 9, 10, 11]]"
             )
 
@@ -194,11 +213,11 @@ class WrapTest(fixtures.TestBase):
         except sa_exceptions.DBAPIError as exc:
             eq_(
                 str(exc),
-                "(test.base.test_except.OperationalError) sql error "
-                "[SQL: 'this is a message'] [parameters: [{1: 1}, "
-                "{1: 1}, {1: 1}, {1: 1}, {1: 1}, {1: 1}, {1: 1}, {1: "
-                "1}, {1: 1}, {1: 1}]] (Background on this error at: "
-                "http://sqlalche.me/e/e3q8)",
+                "(test.base.test_except.OperationalError) sql error\n"
+                "[SQL: this is a message]\n"
+                "[parameters: [{1: 1}, {1: 1}, {1: 1}, {1: 1}, {1: 1},"
+                " {1: 1}, {1: 1}, {1: 1}, {1: 1}, {1: 1}]]\n"
+                "(Background on this error at: http://sqlalche.me/e/e3q8)",
             )
             eq_(
                 exc.args,
@@ -226,11 +245,12 @@ class WrapTest(fixtures.TestBase):
         except sa_exceptions.DBAPIError as exc:
             eq_(
                 str(exc),
-                "(test.base.test_except.OperationalError)  "
-                "[SQL: 'this is a message'] [parameters: [{1: 1}, "
+                "(test.base.test_except.OperationalError) \n"
+                "[SQL: this is a message]\n"
+                "[parameters: [{1: 1}, "
                 "{1: 1}, {1: 1}, {1: 1}, {1: 1}, {1: 1}, "
                 "{1: 1}, {1: 1}  ... displaying 10 of 11 total "
-                "bound parameter sets ...  {1: 1}, {1: 1}]] "
+                "bound parameter sets ...  {1: 1}, {1: 1}]]\n"
                 "(Background on this error at: http://sqlalche.me/e/e3q8)",
             )
         try:
@@ -244,9 +264,10 @@ class WrapTest(fixtures.TestBase):
         except sa_exceptions.DBAPIError as exc:
             eq_(
                 str(exc),
-                "(test.base.test_except.OperationalError)  "
-                "[SQL: 'this is a message'] [parameters: [(1,), "
-                "(1,), (1,), (1,), (1,), (1,), (1,), (1,), (1,), (1,)]] "
+                "(test.base.test_except.OperationalError) \n"
+                "[SQL: this is a message]\n"
+                "[parameters: [(1,), "
+                "(1,), (1,), (1,), (1,), (1,), (1,), (1,), (1,), (1,)]]\n"
                 "(Background on this error at: http://sqlalche.me/e/e3q8)",
             )
         try:
@@ -271,11 +292,12 @@ class WrapTest(fixtures.TestBase):
         except sa_exceptions.DBAPIError as exc:
             eq_(
                 str(exc),
-                "(test.base.test_except.OperationalError)  "
-                "[SQL: 'this is a message'] [parameters: [(1,), "
+                "(test.base.test_except.OperationalError) \n"
+                "[SQL: this is a message]\n"
+                "[parameters: [(1,), "
                 "(1,), (1,), (1,), (1,), (1,), (1,), (1,)  "
                 "... displaying 10 of 11 total bound "
-                "parameter sets ...  (1,), (1,)]] "
+                "parameter sets ...  (1,), (1,)]]\n"
                 "(Background on this error at: http://sqlalche.me/e/e3q8)",
             )
 

diff --git a/test/engine/test_deprecations.py b/test/engine/test_deprecations.py
index 35226a09720f04f29e4bb7e8d62d263c2e23d78e..29bda0ac2004e2a09274fe4ce0371be3d5be4bce 100644 (file)
--- a/test/engine/test_deprecations.py
+++ b/test/engine/test_deprecations.py
@@ -1114,7 +1114,7 @@ class HandleErrorTest(fixtures.TestBase):
         with engine.connect() as conn:
             assert_raises_message(
                 tsa.exc.StatementError,
-                r"\(.*SomeException\) " r"nope \[SQL\: u?'SELECT 1 ",
+                r"\(.*SomeException\) " r"nope\n\[SQL\: u?SELECT 1 ",
                 conn.execute,
                 select([1]).where(column("foo") == literal("bar", MyType())),
             )

diff --git a/test/engine/test_execute.py b/test/engine/test_execute.py
index ad9144a382ed1561ab1fef9ea97ab2b6d493e234..e18cdfad4cf8758490414e55ba1f1b86e8122b7a 100644 (file)
--- a/test/engine/test_execute.py
+++ b/test/engine/test_execute.py
@@ -371,7 +371,7 @@ class ExecuteTest(fixtures.TestBase):
         def _go(conn):
             assert_raises_message(
                 tsa.exc.StatementError,
-                r"\(.*.SomeException\) " r"nope \[SQL\: u?'SELECT 1 ",
+                r"\(.*.SomeException\) " r"nope\n\[SQL\: u?SELECT 1 ",
                 conn.execute,
                 select([1]).where(column("foo") == literal("bar", MyType())),
             )
@@ -410,12 +410,12 @@ class ExecuteTest(fixtures.TestBase):
             assert_raises_message(
                 tsa.exc.StatementError,
                 util.u(
-                    "A value is required for bind parameter 'uname'"
-                    r".*SELECT users.user_name AS .m\\xe9il."
+                    "A value is required for bind parameter 'uname'\n"
+                    r".*SELECT users.user_name AS .m\xe9il."
                 )
                 if util.py2k
                 else util.u(
-                    "A value is required for bind parameter 'uname'"
+                    "A value is required for bind parameter 'uname'\n"
                     ".*SELECT users.user_name AS .méil."
                 ),
                 conn.execute,
@@ -2184,7 +2184,7 @@ class HandleErrorTest(fixtures.TestBase):
         with engine.connect() as conn:
             assert_raises_message(
                 tsa.exc.StatementError,
-                r"\(.*.SomeException\) " r"nope \[SQL\: u?'SELECT 1 ",
+                r"\(.*.SomeException\) " r"nope\n\[SQL\: u?SELECT 1 ",
                 conn.execute,
                 select([1]).where(column("foo") == literal("bar", MyType())),
             )

diff --git a/test/engine/test_logging.py b/test/engine/test_logging.py
index 8190a3fcde44903e3717da04372600721fb23492..bd425c940daf1707ee953f21bb96ca75a1098ed8 100644 (file)
--- a/test/engine/test_logging.py
+++ b/test/engine/test_logging.py
@@ -103,7 +103,7 @@ class LogParamsTest(fixtures.TestBase):
         exception = tsa.exc.IntegrityError("foo", {"x": "y"}, None)
         eq_regex(
             str(exception),
-            r"\(.*.NoneType\) None \[SQL: 'foo'\] \[parameters: {'x': 'y'}\]",
+            r"\(.*.NoneType\) None\n\[SQL: foo\]\n\[parameters: {'x': 'y'}\]",
         )
 
     def test_exception_format_unexpected_parameter(self):
@@ -112,7 +112,7 @@ class LogParamsTest(fixtures.TestBase):
         exception = tsa.exc.IntegrityError("foo", "bar", "bat")
         eq_regex(
             str(exception),
-            r"\(.*.str\) bat \[SQL: 'foo'\] \[parameters: 'bar'\]",
+            r"\(.*.str\) bat\n\[SQL: foo\]\n\[parameters: 'bar'\]",
         )
 
     def test_exception_format_unexpected_member_parameter(self):
@@ -121,7 +121,7 @@ class LogParamsTest(fixtures.TestBase):
         exception = tsa.exc.IntegrityError("foo", ["bar", "bat"], "hoho")
         eq_regex(
             str(exception),
-            r"\(.*.str\) hoho \[SQL: 'foo'\] \[parameters: \['bar', 'bat'\]\]",
+            r"\(.*.str\) hoho\n\[SQL: foo\]\n\[parameters: \['bar', 'bat'\]\]",
         )
 
     def test_result_large_param(self):
@@ -169,7 +169,7 @@ class LogParamsTest(fixtures.TestBase):
     def test_error_large_dict(self):
         assert_raises_message(
             tsa.exc.DBAPIError,
-            r".*'INSERT INTO nonexistent \(data\) values \(:data\)'\] "
+            r".*INSERT INTO nonexistent \(data\) values \(:data\)\]\n"
             r"\[parameters: "
             r"\[{'data': '0'}, {'data': '1'}, {'data': '2'}, "
             r"{'data': '3'}, {'data': '4'}, {'data': '5'}, "
@@ -186,7 +186,7 @@ class LogParamsTest(fixtures.TestBase):
         assert_raises_message(
             tsa.exc.DBAPIError,
             r".*INSERT INTO nonexistent \(data\) values "
-            r"\(\?\)'\] \[parameters: \[\('0',\), \('1',\), \('2',\), "
+            r"\(\?\)\]\n\[parameters: \[\('0',\), \('1',\), \('2',\), "
             r"\('3',\), \('4',\), \('5',\), \('6',\), \('7',\)  "
             r"... displaying "
             r"10 of 100 total bound parameter sets ...  "

diff --git a/test/orm/test_session.py b/test/orm/test_session.py
index 2bc11398dc6600fcbab0ae3802343f9020ae7ceb..ad7ff2d35ae38144cbee6b0e77e308c941a92cc7 100644 (file)
--- a/test/orm/test_session.py
+++ b/test/orm/test_session.py
@@ -1037,7 +1037,7 @@ class DeferredRelationshipExpressionTest(_fixtures.FixtureTest):
         assert_raises_message(
             sa.exc.StatementError,
             "Can't resolve value for column users.id on object "
-            ".User.*.; the object is detached and the value was expired ",
+            ".User.*.; the object is detached and the value was expired",
             q.one,
         )
 

diff --git a/test/sql/test_insert_exec.py b/test/sql/test_insert_exec.py
index fafe7cc9ba97d7304c15423db76d0bfaf074235d..7905dc4bc915252ba607c44bd188b2cc732b9fb9 100644 (file)
--- a/test/sql/test_insert_exec.py
+++ b/test/sql/test_insert_exec.py
@@ -60,8 +60,8 @@ class InsertExecTest(fixtures.TablesTest):
             exc.StatementError,
             r"\(sqlalchemy.exc.InvalidRequestError\) A value is required for "
             "bind parameter 'user_name', in "
-            "parameter group 2 "
-            r"\[SQL: u?'INSERT INTO users",
+            "parameter group 2\n"
+            r"\[SQL: u?INSERT INTO users",
             users.insert().execute,
             {"user_id": 7, "user_name": "jack"},
             {"user_id": 8, "user_name": "ed"},