fix: Log internal error body if present (#340)

Author: ptiurin

src/firebolt/async_db/cursor.py

@@ -53,7 +53,7 @@
 if TYPE_CHECKING:
     from firebolt.async_db.connection import Connection
 
-from firebolt.utils.util import Timer
+from firebolt.utils.util import Timer, _print_error_body
 
 logger = logging.getLogger(__name__)
 
@@ -121,6 +121,7 @@ async def _raise_if_error(self, resp: Response) -> None:
                 f"Firebolt engine {self.connection.engine_url} "
                 "needs to be running to run queries against it."
             )
+        _print_error_body(resp)
         resp.raise_for_status()
 
     async def _validate_set_parameter(self, parameter: SetParameter) -> None:

src/firebolt/db/cursor.py

@@ -45,6 +45,7 @@
     ProgrammingError,
 )
 from firebolt.utils.urls import DATABASES_URL, ENGINES_URL
+from firebolt.utils.util import _print_error_body
 
 if TYPE_CHECKING:
     from firebolt.db.connection import Connection
@@ -107,6 +108,7 @@ def _raise_if_error(self, resp: Response) -> None:
                 f"Firebolt engine {self.connection.engine_url} "
                 "needs to be running to run queries against it."  # pragma: no mutate # noqa: E501
             )
+        _print_error_body(resp)
         resp.raise_for_status()
 
     @abstractmethod

src/firebolt/utils/util.py

@@ -147,6 +147,19 @@ def validate_engine_name_and_url_v1(
         )
 
 
+def _print_error_body(resp: Response) -> None:
+    """log error body if it exists, since it's not always logged by default"""
+    try:
+        if (
+            codes.is_error(resp.status_code)
+            and "Content-Length" in resp.headers
+            and int(resp.headers["Content-Length"]) > 0
+        ):
+            logger.error(f"Something went wrong: {resp.read().decode('utf-8')}")
+    except Exception:
+        pass
+
+
 class Timer:
     def __init__(self, message: str = ""):
         self._message = message

tests/unit/async_db/V1/test_cursor.py

@@ -2,7 +2,7 @@
 from unittest.mock import patch
 
 from httpx import HTTPStatusError, StreamError, codes
-from pytest import raises
+from pytest import LogCaptureFixture, raises
 from pytest_httpx import HTTPXMock
 
 from firebolt.async_db import Cursor
@@ -857,3 +857,24 @@ async def test_server_side_header_database(
     httpx_mock.add_callback(query_callback_with_headers, url=query_url_updated)
     await cursor.execute("select 1")
     assert cursor.database == db_name_updated
+
+
+async def test_cursor_unknown_error_body_logging(
+    httpx_mock: HTTPXMock,
+    auth_callback: Callable,
+    auth_url: str,
+    cursor: Cursor,
+    caplog: LogCaptureFixture,
+    query_url: str,
+):
+    httpx_mock.add_callback(auth_callback, url=auth_url)
+    actual_error_body = "Your query was incorrect"
+    httpx_mock.add_callback(
+        lambda *args, **kwargs: Response(
+            status_code=codes.NOT_IMPLEMENTED, content=actual_error_body
+        ),
+        url=query_url,
+    )
+    with raises(HTTPStatusError):
+        await cursor.execute("select 1")
+    assert actual_error_body in caplog.text

tests/unit/async_db/V2/test_cursor.py

@@ -2,7 +2,7 @@
 from unittest.mock import patch
 
 from httpx import HTTPStatusError, StreamError, codes
-from pytest import raises
+from pytest import LogCaptureFixture, raises
 from pytest_httpx import HTTPXMock
 
 from firebolt.async_db import Cursor
@@ -878,3 +878,18 @@ async def test_server_side_header_database(
     httpx_mock.add_callback(query_callback_with_headers, url=query_url_updated)
     await cursor.execute("select 1")
     assert cursor.database == db_name_updated
+
+
+async def test_cursor_unknown_error_body_logging(
+    httpx_mock: HTTPXMock, cursor: Cursor, caplog: LogCaptureFixture, query_url: str
+):
+    actual_error_body = "Your query was incorrect"
+    httpx_mock.add_callback(
+        lambda *args, **kwargs: Response(
+            status_code=codes.NOT_IMPLEMENTED, content=actual_error_body
+        ),
+        url=query_url,
+    )
+    with raises(HTTPStatusError):
+        await cursor.execute("select 1")
+    assert actual_error_body in caplog.text

tests/unit/db/V1/test_cursor.py

@@ -2,7 +2,7 @@
 from unittest.mock import patch
 
 from httpx import HTTPStatusError, StreamError, codes
-from pytest import raises
+from pytest import LogCaptureFixture, raises
 from pytest_httpx import HTTPXMock
 
 from firebolt.db import Cursor
@@ -716,3 +716,24 @@ def test_server_side_header_database(
     httpx_mock.add_callback(query_callback_with_headers, url=query_url_updated)
     cursor.execute("select 1")
     assert cursor.database == db_name_updated
+
+
+def test_cursor_unknown_error_body_logging(
+    httpx_mock: HTTPXMock,
+    auth_callback: Callable,
+    auth_url: str,
+    cursor: Cursor,
+    caplog: LogCaptureFixture,
+    query_url: str,
+):
+    httpx_mock.add_callback(auth_callback, url=auth_url)
+    actual_error_body = "Your query was incorrect"
+    httpx_mock.add_callback(
+        lambda *args, **kwargs: Response(
+            status_code=codes.NOT_IMPLEMENTED, content=actual_error_body
+        ),
+        url=query_url,
+    )
+    with raises(HTTPStatusError):
+        cursor.execute("select 1")
+    assert actual_error_body in caplog.text

tests/unit/db/V2/test_cursor.py

@@ -2,7 +2,7 @@
 from unittest.mock import patch
 
 from httpx import HTTPStatusError, StreamError, codes
-from pytest import raises
+from pytest import LogCaptureFixture, raises
 from pytest_httpx import HTTPXMock
 
 from firebolt.db import Cursor
@@ -783,3 +783,18 @@ def test_server_side_header_database(
     httpx_mock.add_callback(query_callback_with_headers, url=query_url_updated)
     cursor.execute("select 1")
     assert cursor.database == db_name_updated
+
+
+def test_cursor_unknown_error_body_logging(
+    httpx_mock: HTTPXMock, cursor: Cursor, caplog: LogCaptureFixture, query_url: str
+):
+    actual_error_body = "Your query was incorrect"
+    httpx_mock.add_callback(
+        lambda *args, **kwargs: Response(
+            status_code=codes.NOT_IMPLEMENTED, content=actual_error_body
+        ),
+        url=query_url,
+    )
+    with raises(HTTPStatusError):
+        cursor.execute("select 1")
+    assert actual_error_body in caplog.text