Merge pull request #156 from encode/tweak-logging

Tweak logging

Author: lovelydinosaur

databases/backends/mysql.py

@@ -10,7 +10,7 @@
 from sqlalchemy.sql import ClauseElement
 from sqlalchemy.types import TypeEngine
 
-from databases.core import DatabaseURL
+from databases.core import LOG_EXTRA, DatabaseURL
 from databases.interfaces import ConnectionBackend, DatabaseBackend, TransactionBackend
 
 logger = logging.getLogger("databases")
@@ -179,7 +179,8 @@ def _compile(
             compiled._textual_ordered_columns,
         )
 
-        logger.debug("Query: %s\nArgs: %s", compiled.string, args)
+        query_message = compiled.string.replace(" \n", " ").replace("\n", " ")
+        logger.debug("Query: %s Args: %s", query_message, repr(args), extra=LOG_EXTRA)
         return compiled.string, args, CompilationContext(execution_context)
 
     @property

databases/backends/postgres.py

@@ -9,7 +9,7 @@
 from sqlalchemy.sql.schema import Column
 from sqlalchemy.types import TypeEngine
 
-from databases.core import DatabaseURL
+from databases.core import LOG_EXTRA, DatabaseURL
 from databases.interfaces import ConnectionBackend, DatabaseBackend, TransactionBackend
 
 logger = logging.getLogger("databases")
@@ -192,7 +192,10 @@ def _compile(self, query: ClauseElement) -> typing.Tuple[str, list, tuple]:
             for key, val in compiled_params
         ]
 
-        logger.debug("Query: %s\nArgs: %s", compiled_query, args)
+        query_message = compiled_query.replace(" \n", " ").replace("\n", " ")
+        logger.debug(
+            "Query: %s Args: %s", query_message, repr(tuple(args)), extra=LOG_EXTRA
+        )
         return compiled_query, args, compiled._result_columns
 
     @property

databases/backends/sqlite.py

@@ -9,7 +9,7 @@
 from sqlalchemy.sql import ClauseElement
 from sqlalchemy.types import TypeEngine
 
-from databases.core import DatabaseURL
+from databases.core import LOG_EXTRA, DatabaseURL
 from databases.interfaces import ConnectionBackend, DatabaseBackend, TransactionBackend
 
 logger = logging.getLogger("databases")
@@ -154,7 +154,10 @@ def _compile(
             compiled._textual_ordered_columns,
         )
 
-        logger.debug("Query: %s\nArgs: %s", compiled.string, args)
+        query_message = compiled.string.replace(" \n", " ").replace("\n", " ")
+        logger.debug(
+            "Query: %s Args: %s", query_message, repr(tuple(args)), extra=LOG_EXTRA
+        )
         return compiled.string, args, CompilationContext(execution_context)
 
     @property

databases/core.py

@@ -1,5 +1,6 @@
 import asyncio
 import functools
+import logging
 import sys
 import typing
 from types import TracebackType
@@ -16,6 +17,27 @@
 else:  # pragma: no cover
     from aiocontextvars import ContextVar
 
+try:  # pragma: no cover
+    import click
+
+    # Extra log info for optional coloured terminal outputs.
+    LOG_EXTRA = {
+        "color_message": "Query: " + click.style("%s", bold=True) + " Args: %s"
+    }
+    CONNECT_EXTRA = {
+        "color_message": "Connected to database " + click.style("%s", bold=True)
+    }
+    DISCONNECT_EXTRA = {
+        "color_message": "Disconnected from database " + click.style("%s", bold=True)
+    }
+except ImportError:  # pragma: no cover
+    LOG_EXTRA = {}
+    CONNECT_EXTRA = {}
+    DISCONNECT_EXTRA = {}
+
+
+logger = logging.getLogger("databases")
+
 
 class Database:
     SUPPORTED_BACKENDS = {
@@ -63,6 +85,9 @@ async def connect(self) -> None:
         assert not self.is_connected, "Already connected."
 
         await self._backend.connect()
+        logger.info(
+            "Connected to database %s", self.url.obscure_password, extra=CONNECT_EXTRA
+        )
         self.is_connected = True
 
         if self._force_rollback:
@@ -80,6 +105,11 @@ async def disconnect(self) -> None:
             await self._global_transaction.__aexit__()
 
         await self._backend.disconnect()
+        logger.info(
+            "Disconnected from database %s",
+            self.url.obscure_password,
+            extra=DISCONNECT_EXTRA,
+        )
         self.is_connected = False
 
     async def __aenter__(self) -> "Database":
@@ -412,14 +442,17 @@ def replace(self, **kwargs: typing.Any) -> "DatabaseURL":
         components = self.components._replace(**kwargs)
         return self.__class__(components.geturl())
 
+    @property
+    def obscure_password(self) -> str:
+        if self.password:
+            return self.replace(password="********")._url
+        return self._url
+
     def __str__(self) -> str:
         return self._url
 
     def __repr__(self) -> str:
-        url = str(self)
-        if self.password:
-            url = str(self.replace(password="********"))
-        return f"{self.__class__.__name__}({repr(url)})"
+        return f"{self.__class__.__name__}({repr(self.obscure_password)})"
 
     def __eq__(self, other: typing.Any) -> bool:
         return str(self) == str(other)