Fixed performance on the Modules listing page /admin/modules

[alanmels]

Description of the bug

I've been always bothered by how quickly the Functionality (admin/modules) page gets really slow with larger number of contributed modules enabled. So I decided to find out the culprit.

Steps To Reproduce

1. Enable the Devel module;
2. Open the system.module, find the system_rebuild_module_data() function and put sdpm($modules_cache); like so:

function system_rebuild_module_data() {
  $modules_cache = &backdrop_static(__FUNCTION__);
  sdpm($modules_cache);

Refresh the modules page and see $modules_cache always returns empty, so the if condition further below is completely useless.

However, caching for the modules page starts working as expected if the $modules_cache = &backdrop_static('__FUNCTION__'); is replaced with $modules_cache = &backdrop_static('modules_cache'); like so:

function system_rebuild_module_data() {
  $modules_cache = &backdrop_static('modules_cache');
  // Only rebuild once per request. $modules and $modules_cache cannot be
  // combined into one variable, because the $modules_cache variable is reset by
  // reference from system_list_reset() during the rebuild.
  if (!isset($modules_cache)) {
    $modules = _system_rebuild_module_data();
    ksort($modules);
    system_get_files_database($modules, 'module');
    system_update_files_database($modules, 'module');
    $modules = _module_build_dependencies($modules);
    $modules_cache = $modules;
  }
  return $modules_cache;
}

Finally, I have really fast Modules page.

To describe the problem: Two modules try to reset the caches on /admin/modules.

• The system module (which provides the page)
• The update module (which has nothing to do with this page)

To my understanding this happened by mistake (many years back) and should get fixed, so that only the module that's responsible for that page flushes caches on that page.

---

PR by @docwilmot backdrop/backdrop#3601

[indigoxela]

Interesting... I could verify this with debug():

function system_rebuild_module_data() {
  $modules_cache = &backdrop_static(__FUNCTION__);
  debug('Function gets called: ' . __FUNCTION__);
  // Only rebuild once per request. $modules and $modules_cache cannot be
  // combined into one variable, because the $modules_cache variable is reset by
  // reference from system_list_reset() during the rebuild.
  if (!isset($modules_cache)) {
    $modules = _system_rebuild_module_data();
    ksort($modules);
    system_get_files_database($modules, 'module');
    system_update_files_database($modules, 'module');
    $modules = _module_build_dependencies($modules);
    $modules_cache = $modules;
    debug('Code runs, no cache.');
  }
  return $modules_cache;
}

Although __FUNCTION__ is the same, subsequent calls to system_rebuild_module_data() still run the code inside the if clause, so there's effectively no caching.

Changing __FUNCTION__ to the string system_rebuild_module_data (note, still the function name), and the cache still isn't working as expected.
Changing the string to foobarbazbla and the cache works fine. 😕

For what it's worth, if I change it to &backdrop_static(__FUNCTION__ . 'bla') caching also works.

What's so problematic with "system_rebuild_module_data", that it breaks the static cache? Can someone with better knowledge of the backdrop_static cache shed a light on this, please?

[indigoxela]

Ha! There it is: https://github.com/backdrop/backdrop/blob/a259d2d276e5f43db925a408a2f06944eee25324/core/includes/module.inc#L230

The cache is ineffective, because it gets reset.

[klonos]

@alanmels I would look for calls to backdrop_static_reset('system_rebuild_module_data'); or system_list_reset() to blame.

[klonos]

@indigoxela jinx! 😆

[klonos]

...I was looking through d.org issues like the following:

• https://www.drupal.org/project/drupal/issues/794936
• https://www.drupal.org/project/drupal/issues/651086
• https://www.drupal.org/project/drupal/issues/1436684#comment-6575322 (mentions static cache misses - including system_rebuild_module_data())

[klonos]

...it seems quite likely to me that we may be too overzealous at some place, and we might be doing system_list_reset() instead of just reseting say only the theme cache. But that's just a thought/hunch.

[docwilmot]

This is an interesting conundrum here. I have no clue how to resolve this.

FYI since it hasnt been explicitly stated, system_list_reset() is being called at the end of system_update_files_database() which is itself called from within system_rebuild_module_data(), thus immediately resetting the static cache each time.

[alanmels]

Thank you for the inputs. It seems there is more here than just replacing a single string. I'm not sure anymore what would be the ideal fix, but let's get this - seemingly long time D7 problem - finally fixed.

[alanmels]

Ha! There it is: https://github.com/backdrop/backdrop/blob/a259d2d276e5f43db925a408a2f06944eee25324/core/includes/module.inc#L230

The cache is ineffective, because it gets reset.

I've reverted the change I made, then commented out the backdrop_static_reset('system_rebuild_module_data'); line in the system_list_reset() function and, unfortunately, the problem is still there - the modules page is called twice, because caching is not working.

[klonos]

This is an interesting conundrum here. I have no clue how to resolve this.

Same here. Seems like a catch 22.

[klonos]

...I just compared system_list_reset(), system_update_files_database(), and system_rebuild_module_data() between D7 and Backdrop, and they are basically identical. So if we are having this issue, then D7 has the same issue. Perhaps it's worth opening an issue in d.org with our findings, and allow the collective minds of our brethren to chime in with thoughts/ideas on how this could be solved 🤔

[alanmels]

@klonos, that would be nice if it really helps. However, we all know some issues on D take forever to be properly resolved. It's basically the same issue that you've referenced earlier https://www.drupal.org/project/drupal/issues/794936, however it was for D6, never resolved and now is closed.

Another pointer that could help: the admin/modules/list page is always faster, because it loads modules only once. So if fixing the issue for admin/modules is too cumbersome, then we could point all the menu links that previously lead to admin/modules to admin/modules/list instead.

[alanmels]

Interestingly, the admin/appearance/list page also reads from cache, whereas the admin/appearance goes through the broken system_rebuild_module_data() function.

And, if the function serves not only the modules, but also the themes page then the naming is controversial - maybe something like system_rebuild_project_data() instead would be a better fit?

[indigoxela]

@klonos Waiting for Drupal to resolve something means waiting for a long time, potentially forever. I wouldn't rely on that.

@alanmels Whatever we figure out as a solution, two things are important:

1. We must not rename functions that are potentially used by contrib modules (it would break them)
2. We must not break cache flushing, because for a real rebuild (module enable/disable) this is important

And now I'm curious, who can solve our nice little catch 22. 😏

[klonos]

that would be nice if it really helps. However, we all know some issues on D take forever to be properly resolved.

Waiting for Drupal to resolve something means waiting for a long time, potentially forever. I wouldn't rely on that.

I never implied to wait for this to be fixed in D7. Just to start a discussion there, and see if more brainpower can help come up with a solution.

So then the naming is little controversial...

We must not rename functions that are potentially used by contrib modules (it would break them)

I agree with both these points ^^ ...and we have a place to discuss trying to bring consistency to these functions: #2548

[indigoxela]

admin/modules - unlike the .../list page this page runs system_rebuild_module_data twice, the tracebacks are:

array (
  0 => 'system_rebuild_module_data',
  1 => 'update_get_projects',
  2 => 'update_get_available',
  3 => 'update_requirements',
  4 => 'update_init',
  5 => 'module_invoke_all',
  6 => '_backdrop_bootstrap_full',
  7 => 'backdrop_bootstrap',
)

array (
  0 => 'system_rebuild_module_data',
  1 => 'system_modules',
  2 => 'backdrop_retrieve_form',
  3 => 'backdrop_build_form',
  4 => 'backdrop_get_form',
  5 => 'system_block_view',
  6 => 'module_invoke',
  7 => 'buildBlock',
  8 => 'getContent',
  9 => 'renderBlock',
  10 => 'renderBlocks',
  11 => 'renderLayout',
  12 => 'render',
  13 => 'layout_route_handler',
  14 => 'menu_execute_active_handler',
)

^^ The first of the above calls does not happen on admin/modules/list.

[alanmels]

So since admin/modules/list is faster, could we replace the menu link to it while it's not clear how long resolving the problem for admin/modules would take?

[alanmels]

@indigoxela, while I agree that, if ever, the change in the function's name must be done with caution:

1. We must not rename functions that are potentially used by contrib modules (it would break them)

the system_rebuild_module_data() is a core function that is needed for the specific feature, so I doubt there are large number of contributed modules which ever interacted with it. If few modules indeed did, then it's easy for them to adjust their code.

Generally and not only for this specific case, I wish Backdrop community were bolder to make changes in core that make sense sooner then leaving them hanging around for years as it often happened for Drupal 6/7.

2. We must not break cache flushing, because for a real rebuild (module enable/disable) this is important

Isn't it broken already? As I noted in the very beginning the $modules_cache int the system_rebuild_module_data() function always returns empty, so the if condition is completely useless. Also, I've made sure to enable/disable modules after the suggested change was made and the modules list properly gets rebuilt.

[docwilmot]

I'm a bit surprised that admin/modules/list does a different thing from admin/modules. Both paths load the same page callback which is system_modules(). How are we testing this?

[alanmels]

I'm a bit surprised that admin/modules/list does a different thing from admin/modules. Both paths load the same page callback which is system_modules(). How are we testing this?

Just place sdpm('test'); in the function like so:

function system_rebuild_module_data() {
  sdpm('test');

and you will see duplicated output on admin/modules whereas the admin/modules/list always returns single output or do debug traceback as @indigoxela did.

[indigoxela]

I'm a bit surprised that admin/modules/list does a different thing from admin/modules. Both paths load the same page callback which is system_modules(). How are we testing this?

@docwilmot look at my previous comment. I did a debug_backtrace() in function system_rebuild_module_data() and extracted the functions that led there to display the trace with debug().

I'm not sure if there's a way to fix that, which isn't too radical. Didn't dig deeper yet, though.

[klonos]

Generally and not only for this specific case, I wish Backdrop community were bolder to make changes in core that make sense sooner then leaving them hanging around for years as it often happened for Drupal 6/7.

@alanmels our first principle is backwards compatibility: https://backdropcms.org/philosophy#principles

We cannot remove/rename functions, but what we can do is introduce new ones with the proper names, and then have the old ones "redirect" to the new ones, along with a watchdog_deprecated_function(). Either way, not a matter of discussion for this issue feel free to add a comment in #2548 or even start working on it 😉

[indigoxela]

Not sure if it helps, but the double call to function system_rebuild_module_data() is caused by update_init().

Potentially a small change there could fix the problem, but that needs more recherche.

[quicksketch]

I filed a new issue to discuss refactoring when we show update notifications at #5083.

[alanmels]

@quicksketch I supposed there is a reason behind @docwilmot's insisting on his take of the issue, but really wanted to see some kind of proof-case. Which you've given on backdrop/backdrop#3600 (comment) with plenty of details. Still I find your alternative suggestion to solve this much appealing: displaying update messages on the Available Updates and the Status page would be just enough as users never go to the Modules page to check updates, but other reasons as enabling, disabling, reviewing the modules.

[klonos]

Code in backdrop/backdrop#3601 looks good to me 👍🏼

[klonos]

...not sure how to best test this 🤷🏼 ...do we need to install heaps of modules, and then benchmark how fast the modules pages loads before/after the fix?

[docwilmot]

...not sure how to best test this 🤷🏼 ...do we need to install heaps of modules, and then benchmark how fast the modules pages loads before/after the fix?

We just need to test that the static cache on system_rebuild_module_data() works now with this PR. So a dpm() after the line if (!isset($modules_cache)) { and a few consecutive calls tosystem_rebuild_module_data() should only show one hit with this PR, whereas without this PR each call would show a hit.

[stpaultim]

@klonos - Can an issue be RTBC and "PR-Needs Testing"?

[klonos]

@stpaultim yes. The RTBC acronym has 2 meanings:

• in Drupal-land it means "reviewed and tested by the community", which covers both code review and testing
• in Backdrop, since we have a separate "works for me" label specifically for testing, RTBC means (code) "ready to be committed"

My understanding is that one person can review the code, and if no issues are found with coding standards, and it makes sense, they can mark it as RTBC. Another person can then do the manual testing, and add the WFM label.

[stpaultim]

@klonos - I see that the logic. However, I find it very confusing. Because, how can something be "Ready to be Committed" if it hasn't been tested yet.

I've always assumed that the "RTBC" should only be applied after "PR-Works for Me." Until we an issue is marked "Works for Me," we can't really be sure that the code is final yet, let alone RTBC?

(I moved this discussion to here: backdrop-ops/backdrop-community#13)

[ghost]

Since there are two open PRs, and some discrepancy between whether one of the PRs is actually ready to be committed or not, I'm removing the RTBC label.

[docwilmot]

Instructions for quick test right here: #5046 (comment)

[docwilmot]

This was meant to be a quick simple fix, can we get an RTBC for this please? DOnt think it even needs testing manually TBH.

[quicksketch]

Per my comment above I've closed backdrop/backdrop#3593 for the more conservative approach in backdrop/backdrop#3601.

I QA'd this out-of-box and found a modest performance improvement even without any additional modules.

Before patch, caches set: 98.45 ms
After patch, caches set: 65.29 ms

Before patch, no caches: 113.77 ms
After patch, no caches: 86.14 ms

I timed these simply with the Devel page timer.

These times seemed pretty consistent across 3 consecutive tests, an improvement of 50% when caches are set and an improvement of 30% when caches are empty.

[quicksketch]

I merged backdrop/backdrop#3601 into 1.x and 1.20.x.

Thanks @docwilmot, @alanmels, and @indigoxela for the different approaches and PRs! Thanks @hosef and @klonos for their reviews and feedback.