Fix tracing of async cursors for psycopg #3324
Conversation
ibash
force-pushed
the
ibash/async_tracing
branch
from
dbd1d23 to
ecea87a
Compare
|
@federicobond would love a review when you get a chance! |
There was a problem hiding this comment.
I've validated that this indeed solves the problem. Only concern here is minor; The override of traced_execution changes the signature from sync to async, effectively also changing the return type. Another option is to extend CursorTracer with a traced_execution_async method, keeping it all in one class, but supporting both.
But as I said this works ✅
This copies the traced_execution of AsyncCursorTracer except query_method is awaited within the span. Fixes open-telemetry#2486
ibash
force-pushed
the
ibash/async_tracing
branch
from
ecea87a to
71f50a7
Compare
Thanks for testing. Not sure I follow the return type concern, AFAIU the users of that |
|
@xrmx sorry for the delay here -- added a regression test. Please let me know if there's a better way to assert this behavior. |
| async def test_tracing_is_async(self): | ||
| PsycopgInstrumentor().instrument() | ||
|
|
||
| # before this async fix cursor.execute would take 14000 ns, delaying for |
There was a problem hiding this comment.
I don't understand why we need a delay and an inner test_async_connection. Also since you had to update it, aren't we testing MockAsyncCursor?
There was a problem hiding this comment.
I wasn't sure how to assert that the coroutine was await otherwise. (versus the span completing before execution is finished).
This does use MockAsyncCursor, but it's testing that AsyncCursorTracer is awaiting the result of MockAsyncCursor.execute.
There was a problem hiding this comment.
Sure, but here we are testing the mocks and not the real code. Would it be possible to test the connection cursor_factory we get from instrument_connection ?
There was a problem hiding this comment.
This tests the real code. The test is for the tracer class AsyncCursorTracer. It doesn’t matter what Cursor class the test uses.
| else: | ||
| # no sqlcomment anywhere | ||
| self._populate_span(span, cursor, *args) | ||
| return await query_method(*args, **kwargs) |
There was a problem hiding this comment.
@xrmx this is what the bugfix is for, the await was missing before
|
@jwilm not ideal but I did publish the patched version to github, in our requirements.txt we use: |
Adds a test to check that the async tracer is actually awaiting cursor.execute. On my machine, with the bug present, the duration is 14000ns. With the bug patched the the duration is orders of magnitude larger.
ibash
force-pushed
the
ibash/async_tracing
branch
from
2fcd49d to
0d8cd74
Compare
|
@xrmx fixed the formatting issue -- any chance this can get reviewed / merged? |
Description
This copies the traced_execution of AsyncCursorTracer except query_method is awaited within the span.
Fixes #2486
Type of change
Please delete options that are not relevant.
How Has This Been Tested?
I ran this locally by making the corresponding changes in my site-packages folder. Then I checked logfire (what we're using for opentelemetry) to confirm that sql queries now had non-zero timings.
Also ran the
toxcommand to run tests.Happy to build and test the built package if you tell me how to build!
Does This PR Require a Core Repo Change?
Checklist:
See contributing.md for styleguide, changelog guidelines, and more.