Problem/Motivation
Found in #3421881: Track cache tag queries separately in performance tests.
Cache tag operations don't do anything if an empty array is passed, which is fine, but because we now track them separately from database queries, we see a lot of operations that are non-ops. If we instead return early or avoid calling the methods with an empty tags list, we'll only see the ones that actually result in lookups.
This will in turn make it easier to see if we're doing unexpected cache tag look-ups anywhere.
Steps to reproduce
Proposed resolution
Remaining tasks
User interface changes
API changes
Data model changes
Release notes snippet
Issue fork drupal-3422981
Show commands
Start within a Git clone of the project using the version control instructions.
Or, if you do not have SSH keys set up on git.drupalcode.org:
Comments
Comment #4
gorkagr commentedHi!
I hope is fine, i have added the snippet of @Wim Leers in https://www.drupal.org/project/drupal/issues/3421881#comment-15456992 in here :)
Comment #5
gorkagr commentedComment #6
wim leersThe code looks fine (😇), but the comment doesn't quite make sense to me: the comment is more complicated than the logic here 😄 It's much simpler: if there's no cache tags, then there is no cache tag to invalidate, hence it's always valid.
Comment #7
catchI think the change here is good, but also just realised we could do the same early return in the decorator in #3421881: Track cache tag queries separately in performance tests too.
Comment #8
gorkagr commentedAgreed on the comment, it is always the hardest part :D :D , but i liked your last sentence so i have used it ;)
@catch, you mean in
core/modules/system/tests/modules/performance_test/src/Cache/CacheTagsChecksumDecorator.php::isValid(), correct?if we do as well there the
should we also do a
$this->logCacheTagOperation([], 0, 0, CacheTagOperation::isValid);(or smth like that before the return? Or there is no need to log the operation?Comment #9
catchThinking about it - we should call the child class so it's a proper decorator, but skip logging because we know there's nothing to log. Probably needs a comment similar to the one in the trait. The empty cache tag operations create a lot of noise in grafana tempo, not having them there will make it easier to find things we need to change.
#3421881: Track cache tag queries separately in performance tests just landed which means we can do that change here now, it'll mean also adjusting the assertions we just added.
Comment #10
catchWent ahead and implemented #9. I also noticed that we were still sending some cache tag queries to grafana, so moved that logic to a helper so it's the same in both places we check.
Comment #11
wim leersJust a nit — this looks great!
Also, am I missing something, or is this actually saving DB queries?! Nonsensical queries like
🙈
Comment #12
catchIt doesn't save any real database queries, we already check that there is something new to query in
CacheTagChecksumTrait::calculateChecksumand similar places, so it's mostly removing noise when profiling (either traces in grafana tempo or less function calls to look at in xhprof and similar too) and a small micro-optimization.Comment #13
kristiaanvandeneyndeI noticed we're only changing isValid(), what about the other two methods we're tracking in our performance tests: getCurrentChecksum and invalidateTags?
Re #11, not really:
If $tags is empty, then so will $query_tags so we weren't running a query for that. It was showing up in OpenTelemtry, though, because we were tracking all calls in the decorator. This patch fixes that so you'll see a significantly reduced amount of them being tracked.
Comment #14
alexpottCommitted and pushed 02c07301fc to 11.x and 86594c44d6 to 10.3.x. Thanks!
Comment #17
kristiaanvandeneyndeSooooo... a follow-up for getCurrentChecksum and invalidateTags then? :D
Comment #18
kristiaanvandeneyndeMore specifically, I was thinking about:
Comment #19
catchGood point, not sure if those are also polluting the grafana traces but even if they're not it makes some things easier to follow, opened #3423272: Return early from more cache tag operations.
Comment #20
slashrsm commented