VariationCache needs to be more defensive about cache context manipulation to avoid broken redirects

Marked as major because we have a few sleeper bugs in core that this might uncover.

MR needs work, first item in the chain is always the stored item or a redirect, so we can't have this "we already checked initially" stuff in there. Working on it.

Okay tests have thorough coverage now. Let's see if this breaks core and why.

Oof, I was afraid we'd see this many test fails. Let's start digging, I suppose.

CommentNonNodeTest message was:
Trying to set a redirect at an address that already had a redirect with nothing in common, old redirect at address "languages:language_interface, theme, user.permissions" was pointing to "url.path.parent, url.path.is_front", new redirect at same address points to "route".

Sucks how browser tests obscure these, so far I always put the following in these tests so I'd happily learn about a better way of debugging this:

    $this->assertEquals('foo', $this->getSession()->getPage()->getContent());

Okay so figured out where these are coming from: CommentBreadcrumbBuilder::build() and PathBasedBreadcrumbBuilder::build(). It seems like either one or the other fires, but not both, leading to the exception we introduced here as the same cache ID now triggers a completely different redirect.

Yup, from CommentBreadcrumbBuilder:

  public function applies(RouteMatchInterface $route_match) {
    return $route_match->getRouteName() == 'comment.reply' && $route_match->getParameter('entity');
  }

This conditional applies return value is never represented by the 'route' cache context when the result is FALSE.

I'm sure we'll find plenty similar core bugs while combing over the test fails here.

Found an issue that reports this, moving on.

Seems like the other bug is with jsonapi:

Trying to set a redirect at an address that already had a redirect with nothing in common, old redirect at address "url.site, route, request_format" was pointing to "url.query_args", new redirect at same address points to "url.query_args:fields, url.query_args:include, user.permissions".

The data it was trying to set:

\Drupal\Core\Cache\CacheableResponse::__set_state(array(
   'headers' => 
  \Symfony\Component\HttpFoundation\ResponseHeaderBag::__set_state(array(
     'headers' => 
    array (
      'cache-control' => 
      array (
        0 => 'no-cache, private',
      ),
      'date' => 
      array (
        0 => 'Mon, 03 Jun 2024 16:26:31 GMT',
      ),
      'content-type' => 
      array (
        0 => 'application/vnd.api+json',
      ),
    ),
     'cacheControl' => 
    array (
    ),
     'computedCacheControl' => 
    array (
      'no-cache' => true,
      'private' => true,
    ),
     'cookies' => 
    array (
    ),
     'headerNames' => 
    array (
      'cache-control' => 'Cache-Control',
      'date' => 'Date',
      'content-type' => 'Content-Type',
    ),
  )),
   'content' => '{"jsonapi":{"version":"1.0","meta":{"links":{"self":{"href":"http:\\/\\/jsonapi.org\\/format\\/1.0\\/"}}}},"data":{"type":"entity_view_display--entity_view_display","id":"643f166a-a78e-4bad-941c-493d34d10dff","links":{"self":{"href":"http:\\/\\/web\\/jsonapi\\/entity_view_display\\/entity_view_display\\/643f166a-a78e-4bad-941c-493d34d10dff"}},"attributes":{"langcode":"en","status":true,"dependencies":{"config":["node.type.camelids"],"module":["layout_builder","user"]},"third_party_settings":{"layout_builder":{"enabled":true,"allow_custom":true}},"drupal_internal__id":"node.camelids.default","targetEntityType":"node","bundle":"camelids","mode":"default","content":{"links":{"settings":[],"third_party_settings":[],"weight":100,"region":"content"}},"hidden":{"layout_builder__layout":true}}},"links":{"self":{"href":"http:\\/\\/web\\/jsonapi\\/entity_view_display\\/entity_view_display\\/643f166a-a78e-4bad-941c-493d34d10dff"}}}',
   'version' => '1.0',
   'statusCode' => 200,
   'statusText' => 'OK',
   'charset' => NULL,
   'cacheabilityMetadata' => 
  \Drupal\Core\Cache\CacheableMetadata::__set_state(array(
     'cacheContexts' => 
    array (
      0 => 'url.query_args:fields',
      1 => 'url.query_args:include',
      2 => 'url.site',
      3 => 'user.permissions',
    ),
     'cacheTags' => 
    array (
      0 => 'config:core.entity_view_display.node.camelids.default',
    ),
     'cacheMaxAge' => -1,
  )),
))'

Will try to debug that one further when I have time, but that might be Thursday at the earliest.

These are coming from JsonApiRequestValidator::validateQueryParams() and EntityResource:buildWrappedResponse() in that order. So probably also some check not making it into the cache contexts.

... defensive by checking for all previously set cache contexts every step of a redirect chain. If one is missing, we should immediately throw an exception and bail out. This should catch a lot of insecurely written code that doesn't properly set the right cache contexts by letting people know there is something wrong with their code.

Could this be also achieved/enforced by PHPStan (Drupal) too? (cc @mglaman)

I think I've figured out (some of) the jsonapi module failures -- will work more on them tomorrow.

I got as far as Drupal\jsonapi\Access\EntityAccessChecker::checkEntityAccess() where we have this:

      $access = AccessResult::neutral()->addCacheContexts(['url.query_args:' . JsonApiSpec::VERSION_QUERY_PARAMETER])->orIf($access);

with no user.roles context.

Current findings:

1. DPC sets the initial cache contexts of 'route' and 'request_format'
2. This ends up at a redirect to 'url.site', set by JsonApiDocumentTopLevelNormalizer::normalize()

Then, the first time we try to store the return value of JsonApiRequestValidator::validateQueryParams(), leading to the creation of a second CacheRedirect, pointing to 'url.query_args'

But the second time, we try to store the return value of EntityResource::buildWrappedResponse(), which adds 'url.query_args:fields' and 'url.query_args:include' and somewhere along the line 'user.permissions' also makes it in there. Probably an access check, but have to figure that one out.

So the redirect at address response:[request_format]=api_json:[route]=jsonapi.entity_view_display--entity_view_display.individual_SOME_HASH_1:[url.site]=http://web used to point at 'url.query_args', but now points to those new cache contexts leading to the final cache ID of:

response:[request_format]=api_json:[route]=jsonapi.entity_view_display--entity_view_display.individual_SOME_HASH_1:[url.query_args:fields]=:[url.query_args:include]=:[url.site]=http://web:[user.permissions]=_SOME_HASH_2

This means that whatever code comes after JsonApiDocumentTopLevelNormalizer::normalize() is currently inconsistent in setting cache contexts.

Fixed it. JsonApiRequestValidator::validateQueryParams() only sets url.query_args when validation fails, but obviously it also needs to set that when validation succeeds. Because if the query args change, so can the validity.

Okay so this shows that there's only two detectable bugs in core right now:

CommentBreadcrumbBuilder::applies(), I "fixed" this the wrong way here to make tests go green. This caused StandardPerformanceTest to fail as there are now 2 more cache gets, which makes sense because we added a cache context. It also made phpunit tests report an unknown failure.

JsonApiRequestValidator::validateQueryParams(), I fixed this properly here but it needs a dedicated issue. Will create that one next.

There might be more core bugs, such as the one we just fixed in 🐛 Insufficient cacheability information bubbled up by UserAccessControlHandler Active , but we don't always have tests that are extensive enough for this VC fix to throw exceptions there. I.e.: They are flying under the radar and this exception will over time throw an exception on sites that have warmed their caches enough to run into the buggy code.

@kristiaanvandeneynde some tests are still failing as I can see, needs work? :-/

https://git.drupalcode.org/issue/drupal-3452181/-/pipelines/197002/test_...

some tests are still failing as I can see, needs work?

Those fails stem from my "fix" for breadcrumbs. The actual fails caused by the VC changes are all green now. If we split off the breadcrumb and jsonapi fix everything will be green.

The Needs Review Queue Bot → tested this issue. It no longer applies to Drupal core. Therefore, this issue status is now "Needs work".

This does not mean that the patch necessarily needs to be re-rolled or the MR rebased. Read the Issue Summary, the issue tags and the latest discussion here to determine what needs to be done.

Consult the Drupal Contributor Guide → to find step-by-step guides for working with issues.

I know it doesn't apply, that's the whole point :)

Blocking issues have been fixed, simplifying MR and seeing what testbot thinks. Might add a little bit more hardening after tests go green.

All green, now to add a bit more hardening. May change my mind but let's see what this catches.

All green!

Ideally I add another test case for that last bit I just added. Don't have time right now, but hopefully over the next week or so. Shouldn't take too long but this week is really busy.

Blocking issues have been fixed,

\o/

All green!

\o/

Loosely been trying to keep up with one.

Ran the test-only feature https://git.drupalcode.org/issue/drupal-3452181/-/jobs/2411247 and appears to have coverage.

Reading the threads I believe all feedback/questions have been addressed

Applied some super nitpicky void returns directly.

Believe this could be ready so going to mark it.

One question on the MR - not sure about the 'redirect address' language in the exception.

I am working on the final comment and reverted the extra hardening locally. Just making sure we have ample test coverage.

At this point I'm content with the new tests. We could always add more and more to prove things work, but right now we have extra test coverage for when things don't work. Which is what this issue was about.

Now final concern is how do we proceed? I think it was Alex Pott who raised the question that we cannot be throwing exceptions for things we previously allowed people to do wrong. The whole reason this MR started with exceptions was to catch the places in core that were broken and we've since fixed those in the spin-off issues.

Yet @mxr576 has an issue lined up which depends on this one so we can easily tell if his DPC changes open up even more cans of worms. So he would definitely benefit from this MR introducing the hardening as exceptions.

We could set a flag somewhere and log an error when its one value and throw an exception when its the other, but then the VariationCache service would need to get a logger injected only for us to remove it again in a next major version. So it would instantly be deprecated.

Any thoughts?

I'd be all for logging first then exceptions in 12 (or 13 if the totality of work is done to late).

Logging errors will make contrib and sites fix it eventually. I might even prefer it to stay logged on upgrades and be exceptions on new installs in a future maybe actually. Although not sure how much we've done that for core.

The thing is we need tests to fail if they uncover incorrect (or dangerous) cache context use. I'm not sure we can achieve that for all types of tests if we switch to error logging.

Existing vs new sites shouldn't be a cut-off point as, if there is a bug in core, it would mean people couldn't install new Drupal websites whereas existing ones would continue working.

E_USER_WARNING will cause any test to fail afaik. PHPUnit 10 makes it harder to assert warnings compared to exceptions, which is a bit annoying, but otherwise it should work fine. In general I think it's a good idea when introducing a new exception to use E_USER_WARNING first, unless the exception is replacing a fatal error or similar.

The thing is we need tests to fail if they uncover incorrect (or dangerous) cache context use.

We have three environments where we want to handle this differently:

• Development
• Testing
• Production

In my opinion:

• In Production, you might want to reduce log noise by disabling logging for these events altogether. While not ideal, it's understandable given that E_*DEPRECATED warnings already generate significant log volume.
• In Development, it's crucial to confront any issues head-on, so the logs should reflect the full truth. You may also consider enabling a "hardcore" mode that throws exceptions to highlight these problems immediately.
• In Testing, failed tests triggered by exceptions should be the default behavior, ensuring that issues are caught early. However, in certain cases, you might temporarily suppress these exceptions. While silencing isn't ideal, it's acknowledged that developers may have previously misused changeability data. With the introduction of new tools and better examples, developers will need time to re-learn the fundamentals.

E_USER_WARNING will cause any test to fail afaik.

In that case, it might work, but I’m not sure it fully addresses the issue: The VariationCache still needs a logger dependency, whether it's a NullLogger or a real logger, to support the "lenient" mode based on configuration. We could use setter injection to keep the constructor cleaner, though I generally prefer optional dependencies to be included in the constructor and represented with a null object when not required. This approach makes dependencies more explicit and easier to manage.
How about introducing a new service parameter, like variation_cache.cache_manipulation.reporting_mode, with three different options?

• none - All issues are silenced.
• log - Issues are logged.
• exception - Issues are reported via exceptions.

Based on this value, a different logger could be injected into the VariationCache service. Exception throwing could also be managed by a logger, although that isn't strictly necessary. This approach would allow for flexible configuration while keeping the handling of cache manipulation issues consistent and clear.

I'd be all for logging first then exceptions in 12 (or 13 if the totality of work is done to late).

We cannot foresee how long we would need to support different favor of lenient modes, but following my idea, in D12 we could change the default mode to "exception" in development environments in development.services.yml in a hope that we can start throwing exceptions only in D13.

While sometimes I would agree with a multi-tiered approach, here I'm not a fan. I'd like to keep the VariationCache as lightweight as possible and introducing all these options seems to complicate matters even more for a piece of core that few people understand. If we can trigger_error() with E_USER_WARNING and make tests fail on those, we're already in the sweet spot IMO: Tests will fail, but sites will not.

Then, in a next major we should turn the trigger_error into exceptions because we really want to prevent people from setting incorrect cache contexts. It would stop a lot of potential security issues dead in its tracks before they can even get a chance to make it into core/contrib.

@kristiaanvandeneynde I see the value in your suggestion and basically what we would lose in contrast with my suggestion that a service level switch between "appear in logs or not", but in other layers, E_USER_WARNING-s can be silenced. (Unless we hit: #267246: wrong order of taxonomy input fields in "create content" → ;S)

So you have got my vote on E_USER_WARNING.

Looks like we can no longer test for E_USER_ERROR. It's still there in PhpUnit 10 (even though it claims otherwise), but will be removed.

    /**
     * @deprecated https://github.com/sebastianbergmann/phpunit/issues/5062
     */
    public function expectError(): void
    {
        $this->addWarning('Expecting E_ERROR and E_USER_ERROR is deprecated and will no longer be possible in PHPUnit 10.');

        $this->expectedException = Error::class;
    }

So now what? :/

Okay, did some digging and following 📌 [meta] Replace calls to ::expectError*() and ::expectWarning*() Active it seems we actually changed errors into exceptions in other places in core. Which means that, there too, existing code could start breaking.

With that in mind, would it be fine to just commit the MR as is (with the exception) and deal with the fallout as people stumble upon broken/unsafe cache context assignment? Keep in mind that a site which violates the thing we're detecting here will have broken caching and potentially even a security issue, so maybe we have to break loudly to detect these flaws ASAP?

Looks like we can no longer test for E_USER_ERROR. It's still there in PhpUnit 10 (even though it claims otherwise), but will be removed.

:-(

Okay, did some digging and following #3417650: [meta] Replace calls to ::expectError*() and ::expectWarning*() it seems we actually changed errors into exceptions in other places in core.

To be honest, the results are mixed. While I understand and even sympathize with the idea of failing with an exception—especially when security is involved—this approach could lead to more work for us during the next minor release, as these exceptions will only surface at runtime.

Changed to logging:

• https://git.drupalcode.org/project/drupal/-/commit/25697a17e82a42a0fd3d5...
• https://git.drupalcode.org/project/drupal/-/commit/56c078e592b1f3ab99720...

Changed to throwing a exception:

• https://git.drupalcode.org/project/drupal/-/commit/ea5932e49008e7f1931bb...
• https://git.drupalcode.org/project/drupal/-/commit/1c017c0e81e9682a6f42d...

and these exceptions are only going to be thrown in runtime...

I’m starting to reconsider the idea of exception throwing in Production. While there may be an underlying issue that has existed for months, if it hasn’t been discovered yet, it shouldn’t be exposed to end users.

Unless the issue is easy to detect, you have extensive automated test coverage, or exceptionally thorough manual testers, there’s a risk that upgrading to a new Drupal minor/major version with this change could result in issues only being caught in Production—despite significant testing efforts beforehand.

Who could be the explicit call on exception or not? @alexpott? @catch?

Index: core/tests/Drupal/Tests/Core/Cache/VariationCacheTest.php
IDEA additional info:
Subsystem: com.intellij.openapi.diff.impl.patch.CharsetEP
<+>UTF-8
===================================================================
diff --git a/core/tests/Drupal/Tests/Core/Cache/VariationCacheTest.php b/core/tests/Drupal/Tests/Core/Cache/VariationCacheTest.php
--- a/core/tests/Drupal/Tests/Core/Cache/VariationCacheTest.php	(revision 78f227ba3c70cea6308a49753d2e5cae81c9d4f9)
+++ b/core/tests/Drupal/Tests/Core/Cache/VariationCacheTest.php	(date 1723705927868)
@@ -407,6 +407,9 @@
     // cache using context A and then tries to store something using context B,
     // something is wrong. There should always be at least one shared context at
     // the top level or else the cache cannot do its job.
+    set_error_handler(static function (int $errno, string $errstr): never {
+      throw new \LogicException($errstr, $errno);
+    }, E_USER_WARNING);
     $this->expectException(\LogicException::class);
     $this->expectExceptionMessage("The complete set of cache contexts for a variation cache item must contain all of the initial cache contexts, missing: garden.type.");
 
@@ -418,8 +421,12 @@
     $garden_cacheability = (new CacheableMetadata())
       ->setCacheContexts(['garden.type']);
 
-    $this->setVariationCacheItem('You have a nice garden!', $garden_cacheability, $garden_cacheability);
-    $this->setVariationCacheItem('You have a nice house!', $house_cacheability, $garden_cacheability);
+    try {
+      $this->setVariationCacheItem('You have a nice garden!', $garden_cacheability, $garden_cacheability);
+      $this->setVariationCacheItem('You have a nice house!', $house_cacheability, $garden_cacheability);
+    } finally {
+      restore_error_handler();
+    }
   }
 
   /**

This could work as an alternative workaround for the removed support of "PHPUnit 10 no longer converts E_* to exceptions, therefore E_* can no longer be expected.". When error handler is not restored before tearDown(), PHPUnit rightfully complains about that.

PHPUnit has dropped support for expecting errors, it hasn't stopped failing on E_USER_WARNING, so the dropped support only makes it a pain to test the warning itself, not to get a test failure on an unexpected warning. It's still possible to test for warnings by swapping out the error handler mid-test too iirc.

Okay, let's do #44. Seems like a really nice temporary solution until we can switch to exceptions.

btw E_USER_ERROR is deprecated, see related 📌 Stop passing E_USER_ERROR to trigger_error() on PHP 8.4 Active

The E_USER_ERROR is only temporary, though. Will be removed in Drupal 12.0.0 and then we'll throw a proper exception. Your issue seems to also have a MR targeted at D12, so I suppose we're fine? I adjusted the MR, will push in a second after creating a follow-up to point to.

Updated the MR, follow-up here: 📌 Convert trigger_error in VariationCache into a LocigException. Active

Using E_USER_WARNING looks ok here but beware using E_USER_ERROR it should be deprecates in 10.4 or at least silenced to work on PHP 8.4

Yeah I switched to E_USER_WARNING to be sure.

Wait... it just came to my mind, how the current version with trigger_error() will help with catching any unwanted side-effects in 📌 Cacheability information from route access checker access results are ignored by dynamic_page_cache Needs review , since as we identified, trigger_error() only makes PHPUnit tests fail with a custom error handler...

... I tried to summarize what the latest version of MR means for Drupal core and contrib and this was the time when I realized that neither core tests (?) nor contrib tests are going to fail automatically when this prevention mechanism gets triggered inside VariationCache.

Am I missing something?

From #45:

PHPUnit has dropped support for expecting errors, it hasn't stopped failing on E_USER_WARNING, so the dropped support only makes it a pain to test the warning itself, not to get a test failure on an unexpected warning.

So we double checked the actual behavior with @kristiaanvandeneynde and here a quick summary of our Slack conversation.

FTR: For the results below I have removed expectException... and the custom error handler from the test and replaced it with a simple self::assertTrue(1 === 1);.

PHPUnit CLI fails with a non-zero exit code that should make both Drupal Core tests on Gitlab CI and contrib modules fail.

 $ vendor/bin/phpunit -c core core/tests/Drupal/Tests/Core/Cache/VariationCacheTest.php 
PHPUnit 10.5.20 by Sebastian Bergmann and contributors.

Runtime:       PHP 8.3.9
Configuration: /mnt/files/local_mount/build/core/phpunit.xml.dist

......W...                                                        10 / 10 (100%)

Time: 00:00.118, Memory: 14.00 MB

1 test triggered 1 warning:

1) /mnt/files/local_mount/build/core/lib/Drupal/Core/Cache/VariationCache.php:120
Trying to overwrite a cache redirect with one that has nothing in common, old one at address "house.type" was pointing to "garden.type:zen", new one points to "garden.type".

Triggered by:

* Drupal\Tests\Core\Cache\VariationCacheTest::testIncompleteRedirectException
  /mnt/files/local_mount/build/core/tests/Drupal/Tests/Core/Cache/VariationCacheTest.php:431

OK, but there were issues!
Tests: 10, Assertions: 161, Warnings: 1.

PHPStorm's PHPUnit reports the same result, the only thing that concerns me that the test execution is flagged as successful, which could lead to DX issues... but that could be a PHPStorm issue/misconfiguration. (See attached screenshot)

Based on the previous comment, moving this to RTBC

Also this no longer depends on other parts of core being fixed, so review bot can return.

...also this issue should not be related because E_USER_WARNING is in use. See #50 #51

One question on the MR - just moving an additional explanatory comment from the test to the place we actually trigger the error. Other than this, it looks good to me though.

Moved from VariationCacheTest to VariationCache and added the following to it to make it even more clear:

// Another way this might happen is if a new object that can specify
// cacheable metadata is instantiated without inheriting the cache
// contexts of all the logic that happened up until that point. A
// common example of this is when people immediately return the
// result of one of the factory methods on AccessResult, without
// adding the cacheability from previous access checks that did not
// lead to a value being returned.

Comments look much better!

Committed/pushed to 11.x and cherry-picked to 10.4.x, thanks!

catch → closed merge request !8271

Awesome, thanks!

There are failures on 10.4.x in the following tests and those test pass locally when this change is reverted.

• core/modules/book/tests/src/Functional/BookBreadcrumbTest.php
• core/modules/book/tests/src/Functional/BookContentModerationTest.php
• core/modules/book/tests/src/Functional/BookContentModerationTest.php

I have already addressed this on Drupal Slack. I even fixed something in there: 🐛 BookBreadcrumbBuilder needs to always set the route.book_navigation cache context Fixed

The point is that the tests now fail if your cache contexts are broken or insecure. This was the whole point of this issue. While we shied away from straight up breaking existing sites by throwing exceptions, the compromise was that we would be breaking tests instead to show people something was wrong.

Tests broke in Book, I had a look and fixed it. There may be more to fix, but that is really a bug in Book and not core.

@kristiaanvandeneynde, thanks for fixing the Book contrib module. Is there an issue to make a similar fix for 10.4.x?

Changing status because the daily tests are failing on 10.4.x.

Opened 📌 Fix Book so 10.4 tests will run Active will have an MR up in a few seconds.

Very good hardening, I'm very glad to have you watching over us as a guardian, @kristiaanvandeneynde! 🙏👏 This feels like an oversight of me, @FabianX and others who landed the "cache redirect" concept originally in Drupal core a ~decade ago.

Thanks for improving the DX with such clear messages 👍👏 Impressive that we can now automatically detect errors in the logic!

Thanks for the kind words @wim leers, much appreciated.

Keep in mind the detection only works in tests as far as the caches are properly warmed. It will over time catch everything on a live site, especially when things are about to go wrong. The goal is to catch as many of these logic errors now so we can fix them and then throw exceptions in the next major.

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