Instantiated extensions are racy
It looks like instantiated extensions passed to Schema are racy.
Example of racy usage:
https://github.com/strawberry-graphql/strawberry/blob/d6137f02a85c8659aedebac9c9e813ff72f267fe/tests/schema/extensions/test_opentelemetry.py#L200-L202
For OpenTelemetryExtension a single instance of _span_holder is going to be created and reused.
https://github.com/strawberry-graphql/strawberry/blob/d6137f02a85c8659aedebac9c9e813ff72f267fe/strawberry/extensions/tracing/opentelemetry.py#L31
Beyond just OpenTelemetryExtension, the setting of execution_context in ExtensionsRunner is racy:
https://github.com/strawberry-graphql/strawberry/blob/d6137f02a85c8659aedebac9c9e813ff72f267fe/strawberry/extensions/runner.py#L33-L40
You can trivially show this using the following example:
-
Create
app.pyimport asyncio from typing import Optional import strawberry from strawberry.extensions import Extension from strawberry.types.execution import ExecutionContext class TestExtension(Extension): def __init__( self, *, execution_context: Optional[ExecutionContext] = None, ): if execution_context: self.execution_context = execution_context def on_request_start(self): print(f"on_request_start: self={id(self)} execution_context={id(self.execution_context)}") def on_request_end(self): print(f"on_request_end: self={id(self)} execution_context={id(self.execution_context)}") @strawberry.type class Query: @strawberry.field async def test(self, sleep: int) -> int: await asyncio.sleep(sleep) return sleep schema = strawberry.Schema(query=Query, extensions=[TestExtension()]) -
Then run the following:
strawberry server app --port 3030 -
In a new window make the following request:
curl 127.0.0.1:3030/graphql -H 'content-type: application/json' --data '{"query": "{ test(sleep: 30) }"}' -
And while that request is running, make the concurrent request:
curl 127.0.0.1:3030/graphql -H 'content-type: application/json' --data '{"query": "{ test(sleep: 1) }"}' -
If you look at the output of
app.pyyou'll see the following:Running strawberry on http://0.0.0.0:3030/graphql 🍓 [2022-08-03 13:04:24]: No operation name { test(sleep: 30) } on_request_start: self=4478445024 execution_context=4478640672 [2022-08-03 13:04:28]: No operation name { test(sleep: 1) } on_request_start: self=4478445024 execution_context=4478932016 on_request_end: self=4478445024 execution_context=4478932016 on_request_end: self=4478445024 execution_context=4478932016You'll notice there is no
on_request_endfor4478640672and a double execution of4478932016.
Upvote & Fund
- We're using Polar.sh so you can upvote and help fund this issue.
- We receive the funding once the issue is completed & confirmed by you.
- Thank you in advance for helping prioritize & fund our backlog.
FWIW this also affects the ValidationCache extension. It must run the on_validation_start hook after parsing is complete so that the execution_context.graphql_document is available - but the execution_context may have been replaced with the one for a subsequent request (so it may be None, or perhaps worse, one for a different request).
My current workaround is to replace the in built validation cache with one that is not directly instantiated: https://gist.github.com/jthorniley/f73f4866b229fd0579ac7fea37051806
I've just noticed this behavior.
I expected on_request_start to have exactly one corresponding on_request_end