snok / asgi-correlation-id

Request ID propagation for ASGI apps
MIT License
370 stars 29 forks source link

Weird issues with Correlation id... thread safety maybe? #8

Closed evinism closed 2 years ago

evinism commented 2 years ago

Started trying to use this on a server -- started getting a large set of these errors: Generating new UUID, since header value '035873B9-9CBC_AC14000A-0050_6196BA3C_5350B2D7-1A16' is invalid. Those UUID valuess are complete nonsense, so I'm a tad confused. Locally, the project worked fine, and this error occurred on maybe 50% of the requests under a reasonable load.

Additionally, I was getting weird looking values in x-request-id:

x-request-id: 0351335E-5C3E_AC14010B-0050_6196B87B_530A0198-560B

Env: Python 3.6, gunicorn, fastapi

Middleware installed via:

app = FastAPI(middleware=[Middleware(CorrelationIdMiddleware)])
evinism commented 2 years ago

Here's a list of the invalid header values I got. Weird patterns in there: https://gist.githubusercontent.com/evinism/46780060605fa63ceda50ad86c907b39/raw/bc0f36d9253b9290ffdb73485d3a462dd3a363a5/weird_uuids.txt

looks like 6196BA3C is certainly the unix timestamp of the servers, which hints towards weird "mix of representation and/or threading" issues.

sondrelg commented 2 years ago

Hi!

If you look at the code here, what we're doing is actually very simple. We validate the incoming UUID and if it fails UUID-validation (you can disable validation if you wish - it's a setting), we generate a new one using uuid4().hex.

This uuid module comes with python, so I'd be surprised if there was anything wrong with the code in general, but is it possible that your setup is doing something unexpected?

Can you run this code locally?

>>> from uuid import uuid4
>>> uuid4().hex
'7ced06b713a640e0ad732bee6abde5ec'
>>> from asgi_correlation_id.middleware import is_valid_uuid
>>> is_valid_uuid('035873B9-9CBC_AC14000A-0050_6196BA3C_5350B2D7-1A16')
False

And what headers are you sending in exactly?

evinism commented 2 years ago

OHHHHH Sorry about that! You're so right -- X-Request-ID is being sent as a header to begin with!!

My bad!!

sondrelg commented 2 years ago

No problem. Glad it resolved itself 🙂