Add query logging callbacks and context manager #1043

dcwatson · 2023-06-30T19:26:36Z

Another take on query logging (#629), with a similar approach to existing listeners. Consider this a WIP - I'm happy to write documentation and more tests if this approach is preferable to #630.

elprans · 2023-07-06T21:06:49Z

asyncpg/connection.py

+        record = LoggedQuery(query, args, timeout, elapsed)
+        for cb in self._query_loggers:
+            if cb.is_async:
+                self._loop.create_task(cb.cb(con_ref, record))


Passing a con_ref is probably unnecessary?

I likely wouldn't use it, so happy to remove it, but I put it there so you could potentially log queries by host.

A concern here is potentially retaining references to free-d connections. Other callbacks take it, of course, but that's an API decision I've come to regret. Perhaps we can pass connection's addr and params instead?

Works for me!

elprans · 2023-07-06T21:08:04Z

asyncpg/connection.py

@@ -314,7 +339,11 @@ async def execute(self, query: str, *args, timeout: float=None) -> str:
        self._check_open()

        if not args:
-            return await self._protocol.query(query, timeout)
+            start = time.monotonic()


I think a context manager would probably be nicer/reduce duplication.

Agreed, change incoming.

elprans · 2023-07-07T02:07:45Z

asyncpg/connection.py

+        with utils.timer() as t:
+            result, stmt = await self._do_execute(
+                query,
+                executor,
+                timeout,
+                record_class=record_class,
+                ignore_custom_codec=ignore_custom_codec,
+            )
+        self._log_query(query, args, timeout, t.elapsed)


You could go further and pull self._log_query into the context manager and that way you'll be able to log query errors too, e.g.

Suggested change

with utils.timer() as t:

result, stmt = await self._do_execute(

query,

executor,

timeout,

record_class=record_class,

ignore_custom_codec=ignore_custom_codec,

)

self._log_query(query, args, timeout, t.elapsed)

with self._time_and_log(query, args, timeout):

result, stmt = await self._do_execute(

query,

executor,

timeout,

record_class=record_class,

ignore_custom_codec=ignore_custom_codec,

)

Great idea, I feel silly for not considering error logging as part of this.

elprans · 2023-07-07T17:05:41Z

asyncpg/connection.py

@@ -2327,6 +2414,12 @@ class _ConnectionProxy:
    __slots__ = ()


+LoggedQuery = collections.namedtuple(
+    'LoggedQuery',
+    ['query', 'args', 'timeout', 'elapsed', 'exception', 'addr', 'params'])


Suggested change

['query', 'args', 'timeout', 'elapsed', 'exception', 'addr', 'params'])

['query', 'args', 'timeout', 'elapsed', 'exception', 'conn_addr', 'conn_params'])

@elprans

Minor fixes and improvements. Improvements ============ * Python 3.12 and PostgreSQL 16 support (#1084) (by @elprans in deea86c) * Add support for tuple-format custom codecs on composite types (#1061) (by @elprans in 922fcd1) * Support `target_session_attrs` in URL format, add tests (#1073) (by @elprans in 7cb4e70) * Infinity numeric support (#1067) (by @krokoziabla in 0c3bf60 for #1020) * Add support for the `WHERE` clause in `copy_to` methods (#941) (by @kaylynn234 in b7ffab6) * Add query logging callbacks and context manager (#1043) (by @dcwatson in b2697ff) Fixes ===== * When prepared statements are disabled, avoid relying on them harder (#1065) (by @elprans in cbf64e1) * Handle environments with HOME set to a not-a-directory (#1063) (by @elprans in af922bc) * Fix handling of non-ASCII passwords (#1062) (by @elprans in 89d5bd0) * Disable JIT while doing type introspection (#1082) (by @elprans in f21ebf6) * Remove connection parameter caching in `Pool` (#1053) (by @ermakov-oleg in 4ddb039) * Switch to Python 3.12-style `wait_for` (#1086) (by @elprans in 4bdd8a7) * Update automatic PostGIS type conversion for Shapely 2.0 (#1085) (by @ChimneySwift in 8b45beb) * Use the `timeout` context manager in the connection path (#1087) (by @elprans in 313b2b2) * Small fix for documentation on using SSL in Connection (#995) (by @ScottFred in ccc7baf) * Use cleanup_ctx in pool usage doc (#878) (by @ir4y in 70c8bd8) * Close cursor portals once the iterator is exhausted (#1088) (by @elprans in ca9f03b) * Cut BaseProtocol circular reference on close. (#1049) (by @pteromys in 93a6f79) * Allow passing hosts as tuples to `connect()` (in addition to lists) (#1021) (by @lezram in d7faaff) Other ===== * Drop support for Python 3.7 (#1064) (by @bryanforbes in 87ab143)

@elprans

Minor fixes and improvements. Improvements ============ * Python 3.12 and PostgreSQL 16 support (#1084) (by @elprans in deea86c) * Add support for tuple-format custom codecs on composite types (#1061) (by @elprans in 922fcd1) * Support `target_session_attrs` in URL format, add tests (#1073) (by @elprans in 7cb4e70) * Infinity numeric support (#1067) (by @krokoziabla in 0c3bf60 for #1020) * Add support for the `WHERE` clause in `copy_to` methods (#941) (by @kaylynn234 in b7ffab6) * Add query logging callbacks and context manager (#1043) (by @dcwatson in b2697ff) Fixes ===== * When prepared statements are disabled, avoid relying on them harder (#1065) (by @elprans in cbf64e1) * Handle environments with HOME set to a not-a-directory (#1063) (by @elprans in af922bc) * Fix handling of non-ASCII passwords (#1062) (by @elprans in 89d5bd0) * Disable JIT while doing type introspection (#1082) (by @elprans in f21ebf6) * Remove connection parameter caching in `Pool` (#1053) (by @ermakov-oleg in 4ddb039) * Switch to Python 3.12-style `wait_for` (#1086) (by @elprans in 4bdd8a7) * Update automatic PostGIS type conversion for Shapely 2.0 (#1085) (by @ChimneySwift in 8b45beb) * Use the `timeout` context manager in the connection path (#1087) (by @elprans in 313b2b2) * Small fix for documentation on using SSL in Connection (#995) (by @ScottFred in ccc7baf) * Use cleanup_ctx in pool usage doc (#878) (by @ir4y in 70c8bd8) * Close cursor portals once the iterator is exhausted (#1088) (by @elprans in ca9f03b) * Cut BaseProtocol circular reference on close. (#1049) (by @pteromys in 93a6f79) * Allow passing hosts as tuples to `connect()` (in addition to lists) (#1021) (by @lezram in d7faaff) Other ===== * Drop support for Python 3.7 (#1064) (by @bryanforbes in 87ab143)

Add query logging callbacks and context manager

8f8671a

elprans reviewed Jul 6, 2023

View reviewed changes

dcwatson added 4 commits July 6, 2023 21:03

Wrap timing in a context manager

f64a8ea

Merge branch 'master' into query-logging

ab61adf

More docs, test multiple loggers

937890d

Appease flake8

107f196

elprans reviewed Jul 7, 2023

View reviewed changes

dcwatson added 2 commits July 6, 2023 23:41

Log query errors, clean up context managers

92baac1

Fix docs

67dbc42

elprans reviewed Jul 7, 2023

View reviewed changes

dcwatson and others added 4 commits July 7, 2023 14:48

Renamed LoggedQuery attrs

a21d9c5

Merge branch 'master' into query-logging

a9c6182

Merge branch 'master' into query-logging

8c29bbd

Avoid use of logging context when no loggers are configured

3d2924a

elprans approved these changes Oct 9, 2023

View reviewed changes

s/logger/query_logger/, report BaseException too

040892d

elprans force-pushed the query-logging branch from f59af17 to 040892d Compare October 9, 2023 19:53

elprans merged commit b2697ff into MagicStack:master Oct 9, 2023

This was referenced Oct 9, 2023

Add query logging #630

Closed

feature request: query logging #629

Closed

elprans mentioned this pull request Nov 5, 2023

asyncpg v0.29.0 #1098

Merged

aryadovoy mentioned this pull request Nov 7, 2023

IndexError when use elastic-apm #1100

Open

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Uh oh!

Add query logging callbacks and context manager #1043

Add query logging callbacks and context manager #1043

Uh oh!

dcwatson commented Jun 30, 2023

Uh oh!

elprans Jul 6, 2023

Uh oh!

dcwatson Jul 7, 2023

Uh oh!

elprans Jul 7, 2023

Uh oh!

dcwatson Jul 7, 2023

Uh oh!

elprans Jul 6, 2023

Uh oh!

dcwatson Jul 7, 2023

Uh oh!

elprans Jul 7, 2023

Uh oh!

dcwatson Jul 7, 2023

Uh oh!

elprans Jul 7, 2023

Uh oh!

Uh oh!

	['query', 'args', 'timeout', 'elapsed', 'exception', 'addr', 'params'])
	['query', 'args', 'timeout', 'elapsed', 'exception', 'conn_addr', 'conn_params'])

Add query logging callbacks and context manager #1043

Add query logging callbacks and context manager #1043

Uh oh!

Conversation

dcwatson commented Jun 30, 2023

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Uh oh!