From ec4367f87f537bd8692ff4a165772f521076ae0e Mon Sep 17 00:00:00 2001
From: James Robinson <james.robinson@noteable.io>
Date: Mon, 1 Aug 2022 15:16:20 -0400
Subject: [PATCH 1/2] Log timestamp, context, arguments. Skip double-logging
 same statement.

---
 asyncpg/connection.py    | 29 ++++++++++++++++++++++-------
 asyncpg/prepared_stmt.py |  8 ++++++--
 2 files changed, 28 insertions(+), 9 deletions(-)

diff --git a/asyncpg/connection.py b/asyncpg/connection.py
index 566bec30..8207b59d 100644
--- a/asyncpg/connection.py
+++ b/asyncpg/connection.py
@@ -9,6 +9,7 @@
 import asyncpg
 import collections
 import collections.abc
+from datetime import datetime, timezone
 import functools
 import itertools
 import inspect
@@ -305,6 +306,24 @@ def is_in_transaction(self):
         """
         return self._protocol.is_in_transaction()
 
+    def log_statement(self, context: str, statement: str, args=None):
+        when = datetime.now(timezone.utc)
+
+        if self._recent_statements:
+            most_recently_logged = self._recent_statements[-1]
+            (
+                prior_when,
+                prior_context,
+                prior_statement,
+                prior_args,
+            ) = most_recently_logged
+            if prior_statement == statement:
+                # Do not double-log
+                return
+
+        to_log = (when.strftime("%Y-%m-%d %H:%M:%S UTC"), context, statement, args)
+        self._recent_statements.append(to_log)
+
     async def execute(self, query: str, *args, timeout: float = None) -> str:
         """Execute an SQL command (or commands).
 
@@ -335,12 +354,8 @@ async def execute(self, query: str, *args, timeout: float = None) -> str:
         """
         self._check_open()
 
-        # Append to circular buffer of most recent executed statements
-        # for debugging.
-        self._recent_statements.append(query)
-
         if not args:
-            self._recent_statements.append(query)
+            self.log_statement("execute no args", query)
             return await self._protocol.query(query, timeout)
 
         _, status, _ = await self._execute(
@@ -541,7 +556,7 @@ def cursor(self, query, *args, prefetch=None, timeout=None, record_class=None):
         """
         self._check_open()
 
-        self._recent_statements.append(query)
+        self.log_statement("cursor", query, args)
 
         return cursor.CursorFactory(
             self,
@@ -1802,7 +1817,7 @@ async def _do_execute(
         ignore_custom_codec=False,
         record_class=None,
     ):
-        self._recent_statements.append(query)
+        self.log_statement("_do_execute", query)
         if timeout is None:
             stmt = await self._get_statement(
                 query,
diff --git a/asyncpg/prepared_stmt.py b/asyncpg/prepared_stmt.py
index 48558c14..cd46421d 100644
--- a/asyncpg/prepared_stmt.py
+++ b/asyncpg/prepared_stmt.py
@@ -15,7 +15,7 @@
 class PreparedStatement(connresource.ConnectionResource):
     """A representation of a prepared statement."""
 
-    __slots__ = ("_state", "_query", "_last_status")
+    __slots__ = ("_state", "_query", "_last_status", "_logged_args")
 
     def __init__(self, connection, query, state):
         super().__init__(connection)
@@ -219,13 +219,16 @@ async def executemany(self, args, *, timeout: float = None):
 
         .. versionadded:: 0.22.0
         """
+        self._logged_args = args
         return await self.__do_execute(
             lambda protocol: protocol.bind_execute_many(self._state, args, "", timeout)
         )
 
     async def __do_execute(self, executor):
         protocol = self._connection._protocol
-        self._connection._recent_statements.append(self._query)
+        self._connection.log_statement(
+            "preparedstatement __do_execute", self._query, self._logged_args
+        )
         try:
             return await executor(protocol)
         except exceptions.OutdatedSchemaCacheError:
@@ -238,6 +241,7 @@ async def __do_execute(self, executor):
             raise
 
     async def __bind_execute(self, args, limit, timeout):
+        self._logged_args = args
         data, status, _ = await self.__do_execute(
             lambda protocol: protocol.bind_execute(
                 self._state, args, "", limit, True, timeout

From 1bfaa0adeafceb811b6eb099c4ac4c36fc78a8c3 Mon Sep 17 00:00:00 2001
From: James Robinson <james.robinson@noteable.io>
Date: Mon, 1 Aug 2022 15:19:07 -0400
Subject: [PATCH 2/2] Comment.

---
 asyncpg/connection.py | 9 +++++----
 1 file changed, 5 insertions(+), 4 deletions(-)

diff --git a/asyncpg/connection.py b/asyncpg/connection.py
index 8207b59d..2b8a9a21 100644
--- a/asyncpg/connection.py
+++ b/asyncpg/connection.py
@@ -311,14 +311,15 @@ def log_statement(self, context: str, statement: str, args=None):
 
         if self._recent_statements:
             most_recently_logged = self._recent_statements[-1]
+            # Each entry is (timestamp, calling context, sql statement, args (if any)) tuple.
             (
-                prior_when,
-                prior_context,
+                _,
+                _,
                 prior_statement,
-                prior_args,
+                _,
             ) = most_recently_logged
             if prior_statement == statement:
-                # Do not double-log
+                # Do not double-log same query.
                 return
 
         to_log = (when.strftime("%Y-%m-%d %H:%M:%S UTC"), context, statement, args)