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

Command icon 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

catch created an issue. See original summary.

gorkagr made their first commit to this issue’s fork.

gorkagr’s picture

Hi!
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 :)

gorkagr’s picture

Status: Active » Needs review
wim leers’s picture

Status: Needs review » Needs work

The 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.

catch’s picture

I 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.

gorkagr’s picture

Agreed 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

    if (empty($tags)) {
      return TRUE;
    }

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?

catch’s picture

Thinking 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.

catch’s picture

Status: Needs work » Needs review

Went 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.

wim leers’s picture

Status: Needs review » Reviewed & tested by the community
Issue tags: +D8 cacheability, +Performance

Just a nit — this looks great!

Also, am I missing something, or is this actually saving DB queries?! Nonsensical queries like

SELECT [tag], [invalidations] FROM {cachetags} WHERE [tag] IN ()'

🙈

catch’s picture

It doesn't save any real database queries, we already check that there is something new to query in CacheTagChecksumTrait::calculateChecksum and 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.

kristiaanvandeneynde’s picture

I 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:

    $query_tags = array_diff($tags, array_keys($this->tagCache));
    if ($query_tags) {
      $tag_invalidations = $this->getTagInvalidationCounts($query_tags);
      $this->tagCache += $tag_invalidations;
      // Fill static cache with empty objects for tags not found in the storage.
      $this->tagCache += array_fill_keys(array_diff($query_tags, array_keys($tag_invalidations)), 0);
    }

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.

alexpott’s picture

Status: Reviewed & tested by the community » Fixed

Committed and pushed 02c07301fc to 11.x and 86594c44d6 to 10.3.x. Thanks!

  • alexpott committed 86594c44 on 10.3.x
    Issue #3422981 by catch, gorkagr, Wim Leers: Return early in...

  • alexpott committed 02c07301 on 11.x
    Issue #3422981 by catch, gorkagr, Wim Leers: Return early in...
kristiaanvandeneynde’s picture

Sooooo... a follow-up for getCurrentChecksum and invalidateTags then? :D

kristiaanvandeneynde’s picture

More specifically, I was thinking about:

  • Only the top of CacheTagsChecksumDecorator::invalidateTags() because CacheTagsChecksumTrait already short-circuits if the list of tags is empty.
  • The top of CacheTagsChecksumDecorator::getCurrentChecksum()
  • The top of CacheTagsChecksumTrait::getCurrentChecksum() because it runs a bunch of code that will end up doing nothing if the list of tags is empty
catch’s picture

Good 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.

slashrsm’s picture

Status: Fixed » Closed (fixed)

Automatically closed - issue fixed for 2 weeks with no activity.