Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

@CacheResult on Uni is delayed until Uni is resolved, this allows several concurrent Uni to be active and overwrite cache #31681

Closed
flygarej opened this issue Mar 8, 2023 · 10 comments
Labels
area/cache kind/bug Something isn't working

Comments

@flygarej
Copy link

flygarej commented Mar 8, 2023

Describe the bug

With normal calls that are cached using @CacheResult concurrent calls all get the value returned by the first call.
This means that if a slow backend service is called additional calls will still get the first value returned.
Reactive calls do the opposite, since the cache value is not set until the Uni is resolved, additional reactive calls may start and will then overwrite the cache value of the preceeding calls.
The effect is that after a bunch of concurrent reactive calls have been run, the cache value is that of the last call - and all calls will
wait for the slow backend service.

Expected behavior

I was expecting the @CacheResult and Uni memoize() to behave similar to blocking calls, so that the first call would set the cache and the value then used by the other reactive calls waiting for resolution.
The waiting time for 4 concurrent calls should be ended when the first call resolved.

Actual behavior

The cache value is that of the last call - and all calls will wait for the slow backend service. The waiting time for each call is the full time of the backend call.

How to Reproduce?

Two projects, one to simulate the slow backend, providing a 10 second delay before result is returned, the other to test blocking cached calls, reactive cached calls that show the above behaviour and also a fixed version that might be useful for a fix.

The slow backend service (runs on localhost:8090)
https://github.com/flygarej/quarkus-cache-slowservice

The test bench (runs on localhost:8080):
https://github.com/flygarej/quarkus-cache-test-clientside

Start both projects in separate terminals, then add two or more terminals to test concurrency:

To test normal cache behaviour for blocking calls, in each window run:
curl http://localhost/test/gettokenb
within the 10 second window the slow backend provides. All calls will return when the first one get a result.
Subsequent calls get the cached value until a test/invalidateb is done

To test normal cache behaviour for reactive calls, in each window run:
curl http://localhost/test/gettokennaive
within the 10 second window the slow backend provides. Each call will wait for 10 seconds. The cache
will be set to the value of the last call.
Subsequent calls will get the cached value until a test/invalidatenaive is done.
If cache is invalidated while waiting for resolution, the resolved value is not cached.

To test the wanted reactive behaviour (modulo me being a reactive noob) in each window run:
curl http://localhost/test/gettoken
within the 10 second window the slow backend provides. The behaviour is the same as for blocking calls.
A call to test/invalidate invalidates cache unless a call is pending resolution, if so the pending call will be cached.

Output of uname -a or ver

Linux deadpool 5.19.0-35-generic #36~22.04.1-Ubuntu SMP PREEMPT_DYNAMIC Fri Feb 17 15:17:25 UTC 2 x86_64 x86_64 x86_64 GNU/Linux

Output of java -version

openjdk version "19.0.2" 2023-01-17
OpenJDK Runtime Environment Zulu19.32+13-CA (build 19.0.2+7)
OpenJDK 64-Bit Server VM Zulu19.32+13-CA (build 19.0.2+7, mixed mode, sharing)

GraalVM version (if different from Java)

No response

Quarkus version or git rev

2.16.4.Final

Build tool (ie. output of mvnw --version or gradlew --version)

Apache Maven 3.8.6 (84538c9988a25aec085021c365c560670ad80f63)
Maven home: /home/flax/.m2/wrapper/dists/apache-maven-3.8.6-bin/67568434/apache-maven-3.8.6
Java version: 17.0.6, vendor: Azul Systems, Inc., runtime: /usr/lib/jvm/zulu17-ca-amd64
Default locale: sv_SE, platform encoding: UTF-8
OS name: "linux", version: "5.19.0-35-generic", arch: "amd64", family: "unix"

Additional information

No response

@flygarej flygarej added the kind/bug Something isn't working label Mar 8, 2023
@quarkus-bot
Copy link

quarkus-bot bot commented Mar 8, 2023

/cc @gwenneg (cache)

@geoand
Copy link
Contributor

geoand commented Mar 8, 2023

To be honest, the current behavior makes more sense to me than the alternative described here.

@cescoffier @jponge WDYT?

@flygarej
Copy link
Author

flygarej commented Mar 8, 2023

Current behaviour is doable but the difference between caching blocking calls and caching Uni's is confusing.
Rationale of why current behaviour is right or better might be good to put into guide on caching?
Googling this behaviour turns up other people having the same problem. Not a lot, but enough to warrant an explanation or improved guide maybe?

@geoand
Copy link
Contributor

geoand commented Mar 8, 2023

Yeah, I think we can mention this in the guide

@flygarej
Copy link
Author

flygarej commented Mar 8, 2023

We've been discussing the issue here and the thing that breaks our use case (make only one call to get new token when old is invalidated) is that the Uni is being held until resolved, and the cache then stores the resolved value.
Having an additional annotation to "guard" the Uni so that the same Uni is used until resolution is done would be a nice way to get both variants. At the moment I'll have to build on the hack I put together.

@mkouba
Copy link
Contributor

mkouba commented Mar 9, 2023

I was expecting the @CacheResult and Uni memoize() to behave similar to blocking calls

Well, Uni.memoize().indefinitely() does not block but merely instructs Mutiny to return the same item whenever someone subscribes to the Uni.

To test normal cache behaviour for reactive calls... The cache will be set to the value of the last call.

Hm, this is weird. I need to take a look at the reproducer...

@mkouba
Copy link
Contributor

mkouba commented Mar 9, 2023

So the first thing I noticed is that the Uni<String> getToken() resource method declared on eu.flygare.quarkus.test.GreetingResource is annotated with @Blocking. I'm not quite sure how this plays together with Uni<String> getToken() declared on the eu.flygare.quarkus.test.TokenSource rest client interface. Anyway, that's not the reason why you observe the aforementioned behavior.

@flygarej
Copy link
Author

flygarej commented Mar 9, 2023

Sloppyness on my part, it's there because I was lazy and used a Thread.sleep in the body of that function.
It doesn't change anything but you don't get complaints about the method blocking for too long. It also works to replace it with a Uni.createFrom().Item().onItem().delayBy(...) but then the delay is "running on return" rather than in the "slow and expensive" method. In one of the iterations I wanted to see if the service being a normal blocking method returning String while the Rest client had the signature Uni made any difference (it shouldn't and didn't) and I took an ugly shortcut when reverting back.

@mkouba
Copy link
Contributor

mkouba commented Mar 10, 2023

Ok, I can see the issue now. This problem was fixed in the Cache programmatic API - support asynchronous value loader pull request and delivered in quarkus 3.0.0.Alpha4. Previously, there was no async value loader and the computation was not atomic.

I've verified your reproducer with 3.0.0.Alpha5 (javax imports need to be changed to jakarta) and getToken called is only logged once (as excpected).

@flygarej
Copy link
Author

flygarej commented Mar 10, 2023

Ok, that is great news. This is an ongoing project which still have some distance until completion and I can live with the behaviour (and our fix for it) as long as I know an upgrade to 3.0.0 will fix it.
Considering how few have been hit by the current behaviour I'm unsure if backporting the fix to Quarkus 2 is worth the trouble, so
I'll close the issue as resolved, thanks for the help and feedback. Looking forward to seeing Quarkus 3 out of alpha (and beta).

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
area/cache kind/bug Something isn't working
Projects
None yet
Development

No branches or pull requests

3 participants