Problem/Motivation

Drupal 11.3.2
PHP 8.3.3
Redis cache

We just ran into a very unusual issue, when using two language switchers on the same site. Blocks and content on pages are translated randomly (in our case, some were english, some were german). At first we thought, big pipe, redis, or some other cache would be the Problem, but it wasn't. The root cause is super weird and we don't really understand why it happens.

At the start of the function "$original_languages" is initiated as "$this->negotiatedLanguages". Then, an array filter is used and inside the callback method, "$this->negotiatedLanguages[LanguageInterface::TYPE_CONTENT] " and "$this->negotiatedLanguages[LanguageInterface::TYPE_INTERFACE]" is changed for a split second, but after array_filter is done, "$this->negotiatedLanguages" is ALWAYS set back to the original_language initated at the beginning. There is not a single comment explaining why it is overriden for a split second and since php runs synchronous it doesn't make much sense.

And now comes the weird part. When printing out "before" and "after", before and after the array_filter() call, we get the output: "before", "before", "after", "after", which doesn't make sense at all. Once

                $this->negotiatedLanguages[LanguageInterface::TYPE_CONTENT] = $language;
                $this->negotiatedLanguages[LanguageInterface::TYPE_INTERFACE] = $language;

Inside array_filter() is removed it displays "before", "after", "before", "after". Apart from this doesn't making any sense It still don't understand why the two code lines are even needed?
screenshot

The other workaround is to simply remove one language switchter, but it is still unclear how and why this can happen in php. I'm not too deep into php fiber, which could be the cause, but our theory is that language switch blocks are somehow loaded asynchronous but share the same state or something...

So either deleting

                $this->negotiatedLanguages[LanguageInterface::TYPE_CONTENT] = $language;
                $this->negotiatedLanguages[LanguageInterface::TYPE_INTERFACE] = $language;

or removing the second language switcher fixes the issue. But it is still unclear to me why these two lines of code are needed and how removing them fixes the issue.

This feels like it could be a fibers issue similar to #3553342: Race condition in LocalTaskManager::getLocalTasks() with fibers

Further technical information:

Further technical information can be found in the (closed as duplicate) issue here: #3573391: getLanguageSwitchLinks() leaks temporary content language into placeholder rendering via Fiber interleaving (wrong translations in breadcrumbs, blocks)

Steps to reproduce

  • Set up a multilingual Drupal project
  • Place two language switchers blocks in two different regions (in real world one would e.g. for desktop, one for mobile)
  • See that parts of the page are showing up in different languages due to unclear "race condition effects"

(To be tested in vanilla Drupal and find out if there are additional requirements for reproduction)

Proposed resolution

Use a "fiber trap" (see #3565937: Workaround PHP bug with fibers and __get()), so that if getLanguageSwitchLinks runs in a fiber, and the URL access checks suspends the fiber, it all occurs in child fibers from within getLanguageSwitchLinks(), so that the change in negotiated languages does not leak.

Remaining tasks

  • Add comments to these two lines in code to understand what they do
  • Understand the possible reasons for the effect
  • Try reproducing this in vanilla Drupal
  • Resolve this and if possible remove these side-effect lines
  • Write tests
  • Review
  • Release

User interface changes

None

Introduced terminology

None

API changes

None

Data model changes

None

Release notes snippet

TBD

Issue fork drupal-3569172

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

grevil created an issue. See original summary.

grevil’s picture

StatusFileSize
new971 bytes
grevil’s picture

Status: Active » Needs review

Static patch for the time being.

anybody’s picture

@Core maintainers: Any idea regarding the weird non-linear execution (or at least output) order?

I've tried disabling Bigpipe, but the issue is still the same. Could this somehow be related to Fibers or Bigpipe because both language switcher blocks are blocks and are maybe lazy loaded so a race condition can appear, while PHP itself is not using concurrency here?

Nonetheless these two lines of code should please be commented by someone who can tell what they do, and I'd clearly vote to remove this side effect in the filter method anyway. To me it looks like a code smell...

Adding some (possibly) related issues I found.

I think this issue is definitely major and extremely hard to find the root cause.

anybody’s picture

Issue summary: View changes
godotislate’s picture

Discussed on Slack, but those lines are probably there to affect the URL access check of each link in the language switcher. The negotiated language properties presumably affect access. They're set back after all the access checking is done.

It could be related to Fibers, but offhand I don't see how a Fiber would suspend before the negotiated languages are switched back.

grevil’s picture

anybody’s picture

Thanks @godotislate. Still it doesn't seem to be a straight forward logical issue, because that wouldn't explain (from my perspective) why unrelated parts of the page, e.g. header menu, a paragraph and a block are suddenly rendered in the wrong language, while all other parts of the page are correct.

Commenting out these lines, everything is rendered correctly.

BTW just looked into the blame, indeed it's a security and permission issue where this code was introduced!
https://git.drupalcode.org/project/drupal/-/commit/02aab21d0ea4d74fb027e...

#3553342: Race condition in LocalTaskManager::getLocalTasks() with fibers sounds quite similar, but I'm wondering where they share a cache?
Our first thought indeed was a cache (or Redis), but there was no evidence.

anybody’s picture

Issue summary: View changes
godotislate’s picture

@catch mentioned on Slack that it could be a FIber issue if the access checks trigger path alias (entity) loading.

anybody’s picture

Could fiber also have other effects in this class, especially ConfigurableLanguageManager::getLanguages() with its cache implementations? That's also called several times. Still we couldn't find effects debugging and wrangling it, but it was in our focus...

Like with #11 the effect might be broader across the class due to the class properties and caching used?

Sorry I don't have much experience with fiber and its possible side effects yet. Hope we're not on the wrong path...

smustgrave’s picture

Status: Needs review » Needs work

Don't mean to cause noise but sounds like solutions are still being worked on, so maybe needs review isn't correct just yet, based on the MR.

anybody’s picture

@smustgrave yes you're right. Was just kind of "hopefully someone with enough knowledge has a look at the *workaround* approach".

The current status is, that we don't have enough Fibers / background knowledge to understand how this can happen and how it should be fixed. =/

godotislate’s picture

MR diff is probably good enough as a workaround patch for multilingual sites that don't have language based access.

To make progress on this issue further, we'll need reproduction steps and/or a test.

anybody’s picture

Thanks @godotislate absolutely. Sadly we were not yet able to reproduce this in a simple vanilla Drupal installation. We already tried reproducing that, but it seems it needs some complexity to happen. Sadly it's still unclear which kind of complexity and root causes we need.

We'll provide more information here as soon as we can, but my hope was that someone with more Drupal Core knowledge (and maybe Fibers knowledge) has an idea to explain it theoretically from the code flow?

flemming.fridthjof’s picture

We've seen the same issue on a large amount of multilingual Drupal 11.3.3 sites.
It looks like the problem originates from the "devel" contrib module (version 5.5.0), which we have activated as default.
Deactivating this module solves the problem.
Even tried the setup on a vanilla Drupal 11.3.3 site, and as soon as the devel module is activated the problem shows.
No idea yet to why the devel module seem to be the root cause, but will investigate.

anybody’s picture

Thanks @flemming.fridthjof that's VERY helpful information we didn't have here yet. Maybe you could create an issue at devel, while keeping this for now, to see if they have an idea what could cause this and how to fix it?

I wouldn't move this one until we're 100% sure it's Devel (alone). So far this seemed to be a really complex issue.
Very much looking forward to your further information and yes, I can confirm we're also using Devel on the page where we're experiencing this! So it's absolutely possible, while I have no idea yet, how that could conflict... interesting!

flemming.fridthjof’s picture

It seems to be related to the EventSubscriber "src/EventSubscriber/ErrorHandlerSubscriber.php" in the devel module.
The subscriber binds to the following event: $events[KernelEvents::REQUEST][] = ['registerErrorHandler', 256];
Changing priority from 256 to 254 fixes the problem.
Or disabling line 30 which check permissions "if (!$this->account->hasPermission('access devel information')) {"
Going a bit deeper I find that the EventSubscriber "core/modules/language/src/EventSubscriber/LanguageRequestSubscriber.php" uses priority 255.
So it seems like if a "KernelEvents::REQUEST" event subscriber query permissions before LanguageRequestSubscriber has had it own go at it, it taints the cache build in "core/lib/Drupal/Core/Session/AccessPolicyProcessor.php".
If I disable line 81-83 in AccessPolicyProcessor.php, it also fixes the problem.

The conclusion must be that this truly is a core issue, as any module can have an event subscriber utilizing KernelEvents::REQUEST with a priority >= 255 while triggering an action within AccessPolicyProcessor like Account::hasPermission() does, and is often used.

I've build an EventSubscriber class which I used for testing


namespace Drupal\ot_broken_language_event_subscriber\EventSubscriber;

use Drupal\Core\Session\AccountProxyInterface;
use Drupal\language\LanguageNegotiatorInterface;
use Symfony\Component\EventDispatcher\EventSubscriberInterface;
use Symfony\Component\HttpKernel\Event\RequestEvent;
use Symfony\Component\HttpKernel\KernelEvents;

class OTBrokenLanguageEventSubscriber implements EventSubscriberInterface {

  public function __construct(protected AccountProxyInterface $account, protected LanguageNegotiatorInterface $languageNegotiator) {}

  public function brokenLanguageEventSubscriber(?RequestEvent $event = NULL): void {
    /* Using AccountProxyInterface::hasPermission within event messes with:
       - core/modules/language/src/EventSubscriber/LanguageRequestSubscriber.php */
    \Drupal::getContainer()->get('access_policy_processor')->processAccessPolicies($this->account);
    return;
  }

  /* Priority >= 255 messes with:
     - core/modules/language/src/EventSubscriber/LanguageRequestSubscriber.php
     - core/modules/language/src/ConfigurableLanguageManager.php */
  public static function getSubscribedEvents(): array {
    $events[KernelEvents::REQUEST][] = ['brokenLanguageEventSubscriber', 256];
    return $events;
  }
}

Services file:

services:
  ot_broken_language_event.subscriber:
    class: Drupal\ot_broken_language_event_subscriber\EventSubscriber\OTBrokenLanguageEventSubscriber
    arguments: ['@current_user', '@language_negotiator']
    tags:
      - { name: event_subscriber }
flemming.fridthjof’s picture

Have created following issue in gitlab for the devel project:
https://gitlab.com/drupalspoons/devel/-/issues/563

nicrodgers’s picture

I raised https://www.drupal.org/project/drupal/issues/3573391 the other day, but someone has pointed me here. I think mine may be a duplicate of this one, but perhaps mine has more technical details and steps to replicate?

godotislate’s picture

Opened a draft MR for this https://git.drupalcode.org/project/drupal/-/merge_requests/14877 using a similar idea of what @catch called a "fiber trap" from #3565937: Workaround PHP bug with fibers and __get(). This pattern is probably not something we want to keep repeating, but probably the better fix would be to be able to pass a language context to the url access check, instead of relying on the negotiated languages. Doing that looks to be a difficult effort, so hopefully this will do for now.

However, I was not able to reproduce the issue with either devel installed or per the steps in #3573391: getLanguageSwitchLinks() leaks temporary content language into placeholder rendering via Fiber interleaving (wrong translations in breadcrumbs, blocks). In the latter case context_active_trail is not 11.x compatible. Anyway, the MR is basically untested, but hopefully people are either able to test it out and see whether it's actually a fix, and/or provide explicit reproduction steps, in order to get closer to writing automated tests.

anybody’s picture

@nicrodgers thanks, I think we should consolidate, so I closed the issue as duplicate and referenced it here in the issue summary. Feel free to copy things over if you think it's helpful. I see too much risk of fragmentation elsewise.

PS: Once fixed, please credit @nicrodgers for the nice documentation over there!

grimreaper’s picture

StatusFileSize
new2.32 KB

Hello,

I am adding multilingual feature on my website today, with 2 language switchers (one for desktop, and on for mobile), and I encountered weird behaviors:
- menu links not displayed in the correct language
- wrong views results

Thanks for the issue and the MRs!

Attaching patch from MR 14877 for Composer usage which fixes the issue for me!

godotislate’s picture

Status: Needs work » Needs review

Since the great investigation by @nicrodgers found that issue comes from fibers being suspended within the $url->access() call, I've added a unit test to MR 14877 that forces the fiber to be suspended in the mock URL object's access() method. Then (after a lot of mocking), I had ConfigurableLanguageManager::getLanguageSwitchLinks() run in a fiber, while a second fiber ran in parallel and all the second fiber does is return the current language.

If the first fiber being suspended isn't handled correctly, the change of the current negotiated language leaks into the second fiber, as seen in the failing test-only job: https://git.drupalcode.org/issue/drupal-3569172/-/jobs/8646171

With the "fiber trap" fix, the negotiated language changes are contained within the first fiber, so they never leak to the second, and the test passes.

Since this is a unit test, there probably should still be more manual testing that the changes do address issues occurring on actual sites. Thanks to @grimreaper for confirming his site so far.

godotislate’s picture

Updated the Proposed resolution and Remaning tasks in the IS. I think the issue title could use some work, but I don't know how to make it shorter.

flemming.fridthjof’s picture

I've done the same and tested the patch from MR 14877 on my site which are impacted by the issue.
The site has the "devel" module activated and I confirmed, before hand, that issue was still occurring on the site, which was the case.

Applied the patch and re-tested.
The issue was solved with no other issues or errors.
So from my point of view the fix/patch is working as expected.

anybody’s picture

Happy to see this wonderful progress here and that our assumption that fibers might cause this were correct. Whao, I didn't expect this to be solved that fast! Thank you all!

I'll also test the proposed resolution in our project when I'm back from vacation.

mfb’s picture

Issue tags: +Needs followup

Seems strange and unhappy that $url->access() mutates global state and calls have to be wrapped with fiber boilerplate. If this issue just works around the situation then I guess a followup issue should be opened to figure out whatever rearchitecting needs to happen?

godotislate’s picture

$url->access() mutates global state

The global state is mutated before each $url->access() , then mutated back after all the access checks are complete. This is to provide the correct language context to the access checks.

              $result = array_filter($result, function (array $link): bool {
              $url = $link['url'] ?? NULL;
              $language = $link['language'] ?? NULL;
              if ($language instanceof LanguageInterface) {
                // GLOBAL STATE CHANGE.
                $this->negotiatedLanguages[LanguageInterface::TYPE_CONTENT] = $language;
                $this->negotiatedLanguages[LanguageInterface::TYPE_INTERFACE] = $language;
              }
              try {
                return $url instanceof Url && $url->access();
              }
              catch (\Exception) {
                return FALSE;
              }
            });
             // GLOBAL STATE REVERTED.
            $this->negotiatedLanguages = $original_languages;

Follow up would be how to provide language context directly to access checks instead of relying on the global language context.

mfb’s picture

@godotislate Oops, you're right I finally the rest of the code. So, yes, followup for checking access without temporarily changing global state.

nicrodgers’s picture

I've tested the MR with the usecases from my original reproduction steps in the other ticket and confirm that the MR fixes the issues I was having. Thanks for the fast work!

claudiu.cristea’s picture

I’m coming from #3576074: Current user is changed unexpectedly

Glad that the fix works.

However, it feels weird that a piece of code should be aware about the context where it runs. To me it looks like an anti-pattern. It turns out that it’s probable to have fewa lot of such “traps” in core as we discover more similar bugs. Then what about contrib and custom code? I will be a huge DX issue, devs will not understand why their code, which looks clean and simple, behaves erratically, while it perfectly worked on Drupal 8, 9, 10.

berdir’s picture

Status: Needs review » Reviewed & tested by the community
Issue tags: -Needs followup

Yes, it is a problem, I share those concerns and maybe the complexity it introduces is too high a price to pay for the for now still somewhat limited performance gains. But I think sooner or later, we're going to run into more issues like this, when starting to adopt things like revolt, frankenphp worker mode and so on. We need to work on avoiding global state to reduce the need for workarounds like this.

But for now, I think what we need to do is squash specific bugs when we see them using the tools we have.

In our case, what this did is cause menus to displayed with a language mix, this fixes this.

I also created #3576381: Ensure that URL access checks respect the language in the URL, remove global language state changes in ConfigurableLanguageManager::getLanguageSwitchLinks as a follow-up.

Setting to RTBC.

alexpott’s picture

Version: main » 11.3.x-dev
Status: Reviewed & tested by the community » Fixed

Committed and pushed fd74ffe5dd8 to main and 37780470592 to 11.x and 2c3a1b524ad to 11.3.x. Thanks!

Now that this issue is closed, review the contribution record.

As a contributor, attribute any organization that helped you, or if you volunteered your own time.

Maintainers, credit people who helped resolve this issue.

  • alexpott committed 2c3a1b52 on 11.3.x
    fix: #3569172 Weird language negotiation behavior inside...

  • alexpott committed 37780470 on 11.x
    fix: #3569172 Weird language negotiation behavior inside...
godotislate’s picture

@alexpott did you push to main?

godotislate changed the visibility of the branch 3569172-weird-language-negotiation to hidden.

  • alexpott committed fd74ffe5 on main
    fix: #3569172 Weird language negotiation behavior inside...

Status: Fixed » Closed (fixed)

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