Remove query parameters from logs

CHANGELOG.rst

@@ -10,8 +10,14 @@ Changelog
 0.25
 ====
 
+0.25.2
+------
+Fixed
+^^^^^
+- Remove sensitive query parameters from debug logging to prevent exposure of passwords, tokens, and personal data (#1996)
+
 0.25.1
-------------------
+------
 Changed
 ^^^^^
 - Force async task switch every 2000 rows when converting db objects to python objects to avoid blocking the event loop (#1939)

tests/test_logging_security.py

@@ -0,0 +1,100 @@
+"""Test that sensitive data is not exposed in debug logging."""
+
+import logging
+from io import StringIO
+
+from tests.testmodels import User
+from tortoise.contrib.test import TestCase
+
+
+class TestLoggingSecurity(TestCase):
+    """Test cases for ensuring sensitive data is not logged by Tortoise ORM."""
+
+    async def test_query_parameters_not_logged_in_tortoise_db_client(self):
+        """Test that query parameters are not logged by tortoise.db_client logger."""
+        # Create a string IO to capture log output
+        log_capture = StringIO()
+
+        # Get the tortoise db_client logger and add our handler
+        logger = logging.getLogger("tortoise.db_client")
+        original_level = logger.level
+        handler = logging.StreamHandler(log_capture)
+        handler.setLevel(logging.DEBUG)
+        formatter = logging.Formatter("%(name)s:%(levelname)s:%(message)s")
+        handler.setFormatter(formatter)
+
+        # Set up logging
+        logger.setLevel(logging.DEBUG)
+        logger.addHandler(handler)
+
+        try:
+            # Create a user with potentially sensitive data
+            sensitive_email = "[email protected]"
+            sensitive_username = "admin_with_secret_key_123"
+            sensitive_bio = "bio with password: my_secret_password_123"
+
+            user = await User.create(
+                username=sensitive_username, mail=sensitive_email, bio=sensitive_bio
+            )
+
+            # Get the captured log output
+            log_output = log_capture.getvalue()
+
+            # Verify that the SQL query structure is still logged
+            self.assertIn("INSERT INTO", log_output)
+            self.assertIn("user", log_output.lower())
+
+            # Verify that sensitive data is NOT in the log output
+            self.assertNotIn(
+                sensitive_email, log_output, f"Sensitive email found in log output: {log_output}"
+            )
+            self.assertNotIn(
+                sensitive_username,
+                log_output,
+                f"Sensitive username found in log output: {log_output}",
+            )
+            self.assertNotIn(
+                sensitive_bio, log_output, f"Sensitive bio found in log output: {log_output}"
+            )
+            self.assertNotIn(
+                "my_secret_password_123",
+                log_output,
+                f"Sensitive password found in log output: {log_output}",
+            )
+
+            # Test UPDATE operation
+            log_capture.seek(0)  # Reset the capture
+            log_capture.truncate(0)
+
+            new_sensitive_email = "[email protected]"
+            user.mail = new_sensitive_email
+            await user.save()
+
+            log_output = log_capture.getvalue()
+            self.assertNotIn(
+                new_sensitive_email,
+                log_output,
+                f"Sensitive email found in UPDATE log: {log_output}",
+            )
+
+            # Test SELECT operation
+            log_capture.seek(0)  # Reset the capture
+            log_capture.truncate(0)
+
+            await User.filter(username=sensitive_username).first()
+
+            log_output = log_capture.getvalue()
+            self.assertNotIn(
+                sensitive_username,
+                log_output,
+                f"Sensitive username found in SELECT log: {log_output}",
+            )
+
+            # Clean up
+            await user.delete()
+
+        finally:
+            # Restore original logging setup
+            logger.removeHandler(handler)
+            logger.setLevel(original_level)
+            handler.close()

tortoise/backends/asyncpg/client.py

@@ -107,14 +107,14 @@ def _in_transaction(self) -> TransactionContext:
     @translate_exceptions
     async def execute_insert(self, query: str, values: list) -> asyncpg.Record | None:
         async with self.acquire_connection() as connection:
-            self.log.debug("%s: %s", query, values)
+            self.log.debug("%s", query)
             # TODO: Cache prepared statement
             return await connection.fetchrow(query, *values)
 
     @translate_exceptions
     async def execute_many(self, query: str, values: list) -> None:
         async with self.acquire_connection() as connection:
-            self.log.debug("%s: %s", query, values)
+            self.log.debug("%s", query)
             # TODO: Consider using copy_records_to_table instead
             transaction = connection.transaction()
             await transaction.start()
@@ -129,7 +129,7 @@ async def execute_many(self, query: str, values: list) -> None:
     @translate_exceptions
     async def execute_query(self, query: str, values: list | None = None) -> tuple[int, list[dict]]:
         async with self.acquire_connection() as connection:
-            self.log.debug("%s: %s", query, values)
+            self.log.debug("%s", query)
             if values:
                 params = [query, *values]
             else:
@@ -148,7 +148,7 @@ async def execute_query(self, query: str, values: list | None = None) -> tuple[i
     @translate_exceptions
     async def execute_query_dict(self, query: str, values: list | None = None) -> list[dict]:
         async with self.acquire_connection() as connection:
-            self.log.debug("%s: %s", query, values)
+            self.log.debug("%s", query)
             if values:
                 return list(map(dict, await connection.fetch(query, *values)))
             return list(map(dict, await connection.fetch(query)))
@@ -180,7 +180,7 @@ def acquire_connection(self) -> ConnectionWrapper[asyncpg.Connection]:
     @translate_exceptions
     async def execute_many(self, query: str, values: list) -> None:
         async with self.acquire_connection() as connection:
-            self.log.debug("%s: %s", query, values)
+            self.log.debug("%s", query)
             # TODO: Consider using copy_records_to_table instead
             await connection.executemany(query, values)
 

tortoise/backends/mssql/client.py

@@ -51,7 +51,7 @@ def _in_transaction(self) -> TransactionContext:
     @translate_exceptions
     async def execute_insert(self, query: str, values: list) -> int:
         async with self.acquire_connection() as connection:
-            self.log.debug("%s: %s", query, values)
+            self.log.debug("%s", query)
             async with connection.cursor() as cursor:
                 await cursor.execute(query, values)
                 await cursor.execute("SELECT @@IDENTITY;")

tortoise/backends/mysql/client.py

@@ -179,15 +179,15 @@ def _in_transaction(self) -> TransactionContext:
     @translate_exceptions
     async def execute_insert(self, query: str, values: list) -> int:
         async with self.acquire_connection() as connection:
-            self.log.debug("%s: %s", query, values)
+            self.log.debug("%s", query)
             async with connection.cursor() as cursor:
                 await cursor.execute(query, values)
                 return cursor.lastrowid  # return auto-generated id
 
     @translate_exceptions
     async def execute_many(self, query: str, values: list) -> None:
         async with self.acquire_connection() as connection:
-            self.log.debug("%s: %s", query, values)
+            self.log.debug("%s", query)
             async with connection.cursor() as cursor:
                 if self.capabilities.supports_transactions:
                     await connection.begin()
@@ -204,7 +204,7 @@ async def execute_many(self, query: str, values: list) -> None:
     @translate_exceptions
     async def execute_query(self, query: str, values: list | None = None) -> tuple[int, list[dict]]:
         async with self.acquire_connection() as connection:
-            self.log.debug("%s: %s", query, values)
+            self.log.debug("%s", query)
             async with connection.cursor() as cursor:
                 await cursor.execute(query, values)
                 rows = await cursor.fetchall()
@@ -244,7 +244,7 @@ def acquire_connection(self) -> ConnectionWrapper[mysql.Connection]:
     @translate_exceptions
     async def execute_many(self, query: str, values: list) -> None:
         async with self.acquire_connection() as connection:
-            self.log.debug("%s: %s", query, values)
+            self.log.debug("%s", query)
             async with connection.cursor() as cursor:
                 await cursor.executemany(query, values)
 

tortoise/backends/odbc/client.py

@@ -123,7 +123,7 @@ def acquire_connection(self) -> ConnWrapperType:
     @translate_exceptions
     async def execute_many(self, query: str, values: list) -> None:
         async with self.acquire_connection() as connection:
-            self.log.debug("%s: %s", query, values)
+            self.log.debug("%s", query)
             async with connection.cursor() as cursor:
                 try:
                     await cursor.executemany(query, values)
@@ -136,7 +136,7 @@ async def execute_many(self, query: str, values: list) -> None:
     @translate_exceptions
     async def execute_query(self, query: str, values: list | None = None) -> tuple[int, list[dict]]:
         async with self.acquire_connection() as connection:
-            self.log.debug("%s: %s", query, values)
+            self.log.debug("%s", query)
             async with connection.cursor() as cursor:
                 if values:
                     await cursor.execute(query, values)
@@ -184,7 +184,7 @@ def acquire_connection(self) -> ConnWrapperType:
     @translate_exceptions
     async def execute_many(self, query: str, values: list) -> None:
         async with self.acquire_connection() as connection:
-            self.log.debug("%s: %s", query, values)
+            self.log.debug("%s", query)
             cursor = await connection.cursor()
             await cursor.executemany(query, values)
 

tortoise/backends/oracle/client.py

@@ -92,7 +92,7 @@ async def execute_script(self, query: str) -> None:
     @translate_exceptions
     async def execute_insert(self, query: str, values: list) -> int:
         async with self.acquire_connection() as connection:
-            self.log.debug("%s: %s", query, values)
+            self.log.debug("%s", query)
             await connection.execute(query, values)
             return 0
 

tortoise/backends/psycopg/client.py

@@ -133,7 +133,7 @@ async def execute_many(self, query: str, values: list) -> None:
         connection: psycopg.AsyncConnection
         async with self.acquire_connection() as connection:
             async with connection.cursor() as cursor:
-                self.log.debug("%s: %s", query, values)
+                self.log.debug("%s", query)
                 await cursor.executemany(query, values)
 
     @postgres_client.translate_exceptions
@@ -147,7 +147,7 @@ async def execute_query(
         async with self.acquire_connection() as connection:
             cursor: psycopg.AsyncCursor | psycopg.AsyncServerCursor
             async with connection.cursor(row_factory=row_factory) as cursor:
-                self.log.debug("%s: %s", query, values)
+                self.log.debug("%s", query)
                 await cursor.execute(query, values)
 
                 rowcount = int(cursor.rowcount or cursor.rownumber or 0)

tortoise/backends/sqlite/client.py

@@ -127,13 +127,13 @@ def _in_transaction(self) -> TransactionContext:
     @translate_exceptions
     async def execute_insert(self, query: str, values: list) -> int:
         async with self.acquire_connection() as connection:
-            self.log.debug("%s: %s", query, values)
+            self.log.debug("%s", query)
             return (await connection.execute_insert(query, values))[0]
 
     @translate_exceptions
     async def execute_many(self, query: str, values: list[list]) -> None:
         async with self.acquire_connection() as connection:
-            self.log.debug("%s: %s", query, values)
+            self.log.debug("%s", query)
             # This code is only ever called in AUTOCOMMIT mode
             await connection.execute("BEGIN")
             try:
@@ -150,7 +150,7 @@ async def execute_query(
     ) -> tuple[int, Sequence[dict]]:
         query = query.replace("\x00", "'||CHAR(0)||'")
         async with self.acquire_connection() as connection:
-            self.log.debug("%s: %s", query, values)
+            self.log.debug("%s", query)
             start = connection.total_changes
             rows = await connection.execute_fetchall(query, values)
             return (connection.total_changes - start) or len(rows), rows
@@ -159,7 +159,7 @@ async def execute_query(
     async def execute_query_dict(self, query: str, values: list | None = None) -> list[dict]:
         query = query.replace("\x00", "'||CHAR(0)||'")
         async with self.acquire_connection() as connection:
-            self.log.debug("%s: %s", query, values)
+            self.log.debug("%s", query)
             return list(map(dict, await connection.execute_fetchall(query, values)))
 
     @translate_exceptions
@@ -229,7 +229,7 @@ def _in_transaction(self) -> TransactionContext:
     @translate_exceptions
     async def execute_many(self, query: str, values: list[list]) -> None:
         async with self.acquire_connection() as connection:
-            self.log.debug("%s: %s", query, values)
+            self.log.debug("%s", query)
             # Already within transaction, so ideal for performance
             await connection.executemany(query, values)