-
Notifications
You must be signed in to change notification settings - Fork 174
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
Move delete failure detection to the cache fetcher. #296
base: main
Are you sure you want to change the base?
Conversation
Different cache stores return a different value from their delete methods, so we don't try to detect whether it failed, since a falsey return value could mean the key wasn't present or it couldn't send the command to the server. This is less ambiguous for write, which is used by the cache fetcher, so failure detection was moved into there.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Writing a test to ensure no-one moves this back to cause this problem again would be helpful. You can likely reproduce this with mocks, based on your comment.
@@ -11,7 +11,9 @@ def write(key, value) | |||
end | |||
|
|||
def delete(key) | |||
@cache_backend.write(key, IdentityCache::DELETED, :expires_in => IdentityCache::DELETED_TTL.seconds) | |||
result = @cache_backend.write(key, IdentityCache::DELETED, expires_in: IdentityCache::DELETED_TTL.seconds) | |||
IdentityCache.logger.debug { "[IdentityCache] delete #{ result ? 'recorded' : 'failed' } for #{key}" } |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
The reason you're using blocks here is to avoid allocating the logging string unless you're at the debugging level?
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I was just doing it the way we were doing it before, but I think that is probably the reason.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
That is the reason.
@@ -11,7 +11,9 @@ def write(key, value) | |||
end | |||
|
|||
def delete(key) | |||
@cache_backend.delete(key) | |||
result = @cache_backend.delete(key) |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Why is it OK to do this in the fallback fetcher? What is the fallback fetcher?
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
The fallback fetcher is just for compatibility for cache backends that don't support CAS operations. memcached_store is the only active support cache store that I know of that supports CAS.
The difference is that now it will just unconditionally log [IdentityCache] delete for #{key}
with debug logging and won't attempt to indicate whether it failed or not.
Sure, I'll add a test for this. Also, I think we should probably use a higher log level for logging that the delete failed, since normally we wouldn't log at the debug level in production, yet this could be useful to investigating cache corruption. |
So, TL;DR the one reason to do this is to make the non-CAS capable adaptors logging less noisy? Or is most of that logging just useless now? This LGTM in isolation but I wonder if we should make CAS a requirement it has improved a bunch of cache desynchronization things for us cc @fbogsany |
@daniellaniyo, @sirupsen please review
Fixes #211
Problem
IdentityCache::MemoizedCacheProxy#delete was assuming the delete failed if cache_fetcher.delete returned falsey. However, that falsey value could either mean the memcached request failed or the key wasn't present, and different cache stores aren't consistent about whether
nil
orfalse
means as a return value for their delete method as I detailed in #211 (comment).This was confusing because we were logging something like
[IdentityCache] delete failed for IDC:5:blob:App:18240036282024875059:41
which sounds like a probably with expiring the cache, but it could just mean that the value wasn't cached yet.Solution
If IdentityCache::MemoizedCacheProxy#cache_fetcher is an IdentityCache::CacheFetcher, then it writes a IdentityCache::DELETED value instead of using a delete memcached request. In that case the return value isn't as ambiguous, it just returns falsey if the request failed. So, I was able to move the failure detection into IdentityCache::CacheFetcher#delete where we can rely on it and put a generic
[IdentityCache] delete for #{key}
message in IdentityCache::FallbackFetcher#delete.