micronaut-projects / micronaut-core

Micronaut Application Framework
http://micronaut.io
Apache License 2.0
6.08k stars 1.07k forks source link

Sporadic HTTP Attribute Loss #7621

Open ytoh opened 2 years ago

ytoh commented 2 years ago

Expected Behavior

Once set an HTTP attribute will be always present in the request.

Actual Behaviour

Some HTTP attributes are sporadically missing from the request.

Our use case is a scatter-gather flow where we are sending a bunch of requests to different backends but in each request we are embedding a tracing id from the "parent" server request's attribute. We also have a custom log4j2 ContextDataInjector that resolves data from the server request. By mistake in this injector we were also setting attributes on the server request. This resulted in a race condition as the storage for HTTP attributes in NettyHttpRequest is a HashMap with initial size of 4. The symptoms of this problem were that from time to time our server request was missing an attribute for a very brief period of time and that caused sporadic hard to diagnose errors in production and tests.

Would it be possible to change this map to a concurrent one? Or somehow make sure on the API level that you cannot set request attributes out side of server filters? (I expect the filters run on the same thread) Or do you have another suggestion for us?

As a remedy we have moved all of our request attribute modification to a server filters. We did not experience missing attributes since then.

Steps To Reproduce

While I can reproduce this issue pretty reliably in our codebase I am having trouble creating a reproducer. The gist of the approach is:

Environment Information

Example Application

No response

Version

3.5.1

yawkat commented 2 years ago

Even making it a ConcurrentMap would not make the rest of the code thread safe.

Also I don't think it's always unsafe to modify on other threads, what's important is that the request is "owned" by one thread at a time. Inside filters, that's the event loop thread. When you're inside a controller, it might be whatever IO thread is responsible for running that controller. When that controller terminates, it goes back to being owned by the event loop thread.

What is the structure of your code such that you're accessing the attributes from multiple threads at the same time? Is the log4j ContextDataInjector accessing the attributes from a different (async logging?) thread?

ytoh commented 2 years ago

I see what you are saying. I am trying to reproduce the problem to see which thread is actually writing. But with any delay I add I am loosing the ability to reproduce the problem. I will keep at it and I will let you know what I find out.

Just for some more context, we are also using AsyncCache and circuit breakers if that might give you any clue what could be causing this.