-
Notifications
You must be signed in to change notification settings - Fork 31
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
NHibernate Redis Caches goes into closed loop with multiple threads #124
Comments
Would you be able to reproduce the trouble with the NHibernate-Caches test project? It will confirm this is not specific to your application. |
I found those lines in the end of Debug.log
Is this only SQL flush? |
Which test project? |
@fredericDelaporte, I observed that the issue happens with LookupGroup. So when a record of EntityRelationship with a reference to LookupGroup then it tries to GetMany (I have As you can see it it tries to fetch 25 keys from Redis which says that
After that for some weird reason it goes into fetching all rest of LookupGroup keys:
imho, that's so strange and after that it seems to hit DB to load LookupGroup#1
And then it tries to cache that record into Redis:
After that it will repeat the same pattern with new LookupGroup id = 2
Maybe that key is locked in Redis that's why it reports missed cache? @fredericDelaporte, can you please check it as it kills the application. And why does it load all other LookupGroup keys not just that 25 ones? Btw, I can see those keys inside Redis. Here is the log file |
It is hard to reproduce and debug a trouble only from debug logs. That is was I was asking if you can reproduce it with the test project. For Redis, the test project is here, but better clone the whole repository, it has dependencies. Cache tests currently are done without actually using NHibernate. Your trouble may require using NHibernate to be reproduced. In such case you may have it easier to write a test within the NHibernate test project, see Contributing for getting started with it.
It could be a special case of settings used by your application which triggers the trouble, or whatever. The Redis Cache provider NuGet has got around 300 000 downloads since it enabled batching by default. So, your trouble does not look to be a systematic one, but one that needs special conditions to be triggered. Without a reliable way for contributors to reproduce the trouble, we will likely not be able to fix it, if that is a trouble in NHibernate or the cache provider. By the way, I thought there was a note of you somewhere about the Redis client version being outdated, but I am not finding it. If that is a concern to you, the cache provider simply states the minimal version of the Redis client with which it is compatible. If you want a more recent one, simply add it as a dependency of your application. Here are detailed explanations about this. |
One enhancement which could be done, after checking SLC and find it is missed then it goes to DB |
@fredericDelaporte, the logs should help understanding the pattern which is occurring by tracking the logs I could see that it could not find the keys inside Redis for some reason! What could be the reason for such behavior? especially keep trying to load many keys even more than 25 in the batch. I am not sure if I would be able to create that test which you are asking me for. Also as I mentioned this issue does not occur when I run each application separately, it only happens when the 2 applications run at the same time |
From the logs I can see that after calling GetMany then it calls GetValue which logs that the cached item was locked and this is the main issue.
So lockable is not null which means |
@fredericDelaporte, I have added a log to check how IsGettable returns false and here is the log: My understanding is that you are trying to compare the timestamp when a CachedItem was created vs when session was created and if the CachedItem timestamp is greater then you believe that the key was locked before (or maybe updated, right?) But what if the key was updated before because the session was created long time ago then why do not we get the last updated value from the cache? I am not fully understanding this logic. Also I see from the logs that first it returned |
@fredericDelaporte, I have removed that check |
@fredericDelaporte, I believe I fixed the issue. There is function This makes sure that we do not try to call the cache again when we find out the cache is missed or locked and it prevents that strange behavior. |
Are you using transactions around queries using the cache? If no, it can work correctly. I am thinking about it because of the timestamp: that is typically what occurs when not using transactions. See the documentation:
|
Yes, I am using transactions around queries. |
@fredericDelaporte did you check all my comments? |
@fredericDelaporte, any updates please? |
Nope, no time available. |
@fredericDelaporte, please have a look into those changes |
You're welcome to contribute, Please also check contributing. It seems you change a public API: in such case the change would have to wait a new major version, or you should do it while preserving the current API. (Like, obsolete the previous method, add a new one. If changing an interface, even adding a method is a breaking change and would require a new version. So instead we use extension methods with TODO comments for merging them in the interface on the next major version. |
@EngSayed - you're not alone. We too, are seeing this behavior in production, and it is most worrisome. @fredericDelaporte - I might be missing something, but is there no way, via configuration to disable PreferMultipleGet with this provider? If there isn't, what is a workable option to avoid using this behavior? |
Ok, answering my own question here. Overridding RedisCache and RedisCacheProvider is the way to do this, so I'll be giving that a shot as a temporary solution. This is an aside from the original issue, but making this configurable in the future may be a good idea. |
I have multiple applications sharing the same backend code and after enabling SLC with Redis provider then application hangs in startup.
In the startup of each application it goes load thousands of data and tries to load/get from/into Redis. When I start 2 applications at the same moment then one manages to start while the second hangs and when I montiored Redis, I found that it keeps looping in getting a lot of keys over and over again.
This happens when Redis is empty and two applications would try to write the data into Redis. I have set
cache.region_strategy.default.retry_times
to 5 but no differenceDebug.log
Attached log file.
The text was updated successfully, but these errors were encountered: