Second loop in module_implements() being repeated for no reason.

I gave this patch a go on our D7 dev box. Without the patch I get 739ms cumulative time on 1,623 calls to module_implements. With the patch I get 83ms cumulative time on 1,623 calls to module_implements. I would call that an improvement :) Thanks for the hat tip as well. This is a RTBC from me.

In terms of module_invoke_all() my cachegrind says that token_generate() is by far the slowest. I think the reason this is slow is due to all the calls to array_merge_recursive(). According to the docs, array_merge_recursive can take N number of arguments; could we call array_merge_recursive once at the end instead of calling it on every hook function call?

It should be in a different issue. Talking about it, it sounds simple enough, but in reality the complexity needed to get it right might wash out any gains.

I do have one question about the patch; why did this

module_load_include('inc', $module, "$module.$group");

change to this

module_load_include($group . '.inc', $module);

The first variant in #8 is the common standard in Drupal core. I agree it's the most weird/useless function signature ever, but that's for another issue... Let's revert to passing $module.$group in the 3rd argument.

This patch adds some comments after / to the bottom of performed operations, which doesn't make much sense to me... those potential / expected effects should be described/documented in an inline comment that precedes the code block.

Didn't study the actual proposed change to the code logic (yet).

1. + * @return string[]|null
   

   In D7 (and actually even most of D8), we're simply using "array|null"

   That said, I'm fairly sure that D7 doesn't have a single instance of alternative data types in @return tags...

2. +    $drupal_static_fast['verified'] = &drupal_static(__FUNCTION__ . '.verified');
   

   The common delimiter for custom/additional drupal_static() names throughout core is a colon (:).

3. +  if (empty($verified[$hook])) {
   

   As this whole code is about performance, the condition should use !isset() instead.

I'm seeing a 5~10% increase in speed in production.

See #2254203: Fix test performance of Drupal\system\Tests\Module\ModuleApiTest

Didn't look at the latest patches yet.

I like #17a - I also see good speed improvements, I don't see any issues with the D8 patch, so I am gonna be bold and RTBC it for #23 - if this still passes tests.

This should go to 7.x ASAP.

Sadly, CNW

Rerolled #23

Fixed the two changes mentioned in the edits in #23

Read through this, looks like a great change, shame we missed it when we initially added the cache.

The test was not firing because it was still in the PSR-0 namespace - fixed up a few other minor things.

Nice catch, back to RTBC.

Committed/pushed to 8.0.x, thanks! Moving to 7.x for backport.

Code needs review for patch in #17a.

**RTBM** for #17a, but unfortunately this needs test before commit so CNW.

As Tests exist in D8, might be a novice task.

I implemented 17a, seems to be serving pages about 10% faster.

Please! D7 performance is important.. :(

Yes, please expedite commit for this patch to core

I've been using this patch in #17a in production for about 4 months.

This needs tests

We're now using #17a as well. Very pleased with the improved performance.

The status was reset by #45, (testing the D8-patch). But #48 proves that #176 is still OK.

This unfortunately still needs tests.

Tests can be ported from D8.

Huge thanks to smccabe for backporting the D8 tests to D7.

Ok I took a shot at porting the tests over from D8, I left out some out as they seemed to be specific to D8 and I don't understand why we check for implementations.inc exactly. Hopefully I didn't butcher things too badly.

Thanks for the backport, still needs some work :).

1. +++ b/modules/simpletest/tests/module.test
   @@ -302,3 +302,49 @@ class ModuleUninstallTestCase extends DrupalWebTestCase {
   +    $modules = module_implements('permission');
   +    $this->assertTrue(in_array('module_test', $modules), 'module_test implements hook_module_implements_alter().');
   

   should say hook_permission in the help text.

2. +++ b/modules/simpletest/tests/module.test
   @@ -302,3 +302,49 @@ class ModuleUninstallTestCase extends DrupalWebTestCase {
   +    // Assert that module_test_module_implements_alter(*, 'altered_test_hook')
   +    // has added an implementation
   +    module_load_include('inc', 'module_test', 'module_test.implementations');
   ...
   +    // Assert that module_test.implementations.inc was included as part of the process.
   +    $this->assertTrue(function_exists('module_test_altered_test_hook'),
   +      'The file module_test.implementations.inc was included.');
   

   This does not make sense to me, I thought this should be included automatically?

3. +++ b/modules/simpletest/tests/module_test.module
   @@ -129,3 +129,23 @@ function module_test_modules_uninstalled($modules) {
   +    // Add a hook implementation, that will be found in
   +    // module_test.implementation.inc.
   +    $implementations['module_test'] = 'implementations';
   

   implementation vs. implementations

   --

   I did not know that functionality ... Interesting ...

1. Fixed
2. Ah yes, I looked closer and I understand this now, module load removed.
3. Fixed, I believe this typo was in the D8 patch as well.

Actually just noticed one more thing, I still had some code in there for testing for an unimplemented hook throwing an exception, which isn't in D7, I've rerolled the patch with that removed.

+++ b/modules/simpletest/tests/module_test.implementations.inc
@@ -0,0 +1,10 @@
\ No newline at end of file

+++ b/modules/simpletest/tests/module_test.module
@@ -129,3 +129,17 @@ function module_test_modules_uninstalled($modules) {
\ No newline at end of file

nit - Please fix those and add newlines to the end of files.

Nitpick on patch #56—there are still a couple of comments referencing D8 classes.

+   * @see \Drupal\Core\Extension\ModuleHandler::buildImplementationInfo()
+ * @see \Drupal\system\Tests\Module\ModuleImplementsAlterTest::testModuleImplementsAlter()

Newlines added and D8 comments removed.

RTBC, looks great now!

Looks good!

Works! RTBC++

This may seem dumb, but there is no loops removed from this patch. Only a new one added... does this need a title update?

Joelpittet, good observation, what would be really good is a few xhprof performance profiling runs with stats before and after the patch. When in doubt put it to the test. I highly recommend xhprof, the devel module has optional xhprof integration. Set up a virtualhost for xhprof according to the installation instructions, then put that config info into devel module config. Xhprof makes a nice diagram easy to understand. This would really help us determine what type of improvements (or regressions) that we can expect. I dont have time right at this moment as I recently changed jobs and was unable to retain my dev vm environment(security paranoia) so I have a lot of setup work to do before I can be back in business. Huge thanks if you can do this xhprof for me this time, it is fun and really worth the effort.

@joseph.olstad FYI xhprof was removed from devel module but it has it's own module which I've been using since it was removed. https://www.drupal.org/project/xhprof

So I've got xhprof and would love to profile this! What do you suppose a decent scenario is for testing this?

@joelpittet , what I'd do is a very simple test plan

test 1

Prior to applying patch #60
1) drush cc all (get the xhprof profile for this)
2) hit landing page (get the xhprof profile for this)
3) hit landing page again after first time (get the xhprof profile for this)

Apply patch #60 THEN:
1) drush cc all (get the xhprof profile for this)
2) hit landing page (get the xhprof profile for this)
3) hit landing page again after first time (get the xhprof profile for this)

test 2

Repeat the same test as above, except authenticated as admin user.

see if that produces anything, repeat the test several times if necessary to get an average. Make sure this is running on hardware that you have full control over (don't run this on a Virtual Machine where you have no control over the VMHost, because this could skew the results, best if you have a controlled environment such as a LOCAL VM that is idle (no virus scans running, no scheduled tasks running, etc)

Thanks

The 2nd loop that is repeated is no longer repeated, because the verification step is now cached as well.

As this did go in successfully for D8, I assume it should be fine for D7 as well, but I am _never_ against any profiling. :-D

@joseph.olstad didn't get quite the scenario going on that but I have something...

Did drush cc all and loaded my commerce cart page. This is not a VM it's native OSX apache + brew PHP 55 with opcache enabled and xdebug is disabled.

Screenshot of the details:

Looks like a memory for time tradeoff is present but I'll do a few more scenarios and see what I get.
400ms for 4.5MB, no call differences.

Do these values look way off to any of you or what you'd expect?

Looks like a good tradeoff to me.

That negative memory looks suspiciously like GC at the wrong point ...

Can we get the overall run instead of just the function?

Donquixote has interesting observation, maybe beyond scope of this issue, yet deserving of an answer. I am pleased with the improvement, perhaps rtbc this and open new issue to answer donquixote above comment, this could possibly lead to further improvements in both 7.x and 8.x or to php itself.
Thanks to joelpittet for confirming performance gains!

Rtbc+1

@donquixote as a comparison my module_implements cache item is 70.6 KB
@Fabianx Sorry don't seem to have those runs any longer on my machine:(

I've done a similar test with similar results the only thing is I don't have the same function calls as I did last time which is strange... but the end result was very similar. ~0.5s WT savings and 4MB mem loss.

Overall on these runs:

Here's after a few runs of the same page as before was immediately after drush cc all.

Overall

One naive question, should the module_implements cache be different before and after this patch?

I seem to only have a 48 kb patch on this page after the patch (a couple of runs). The results slightly change between the patches being applied and not but not as big as I had at first after switching back and forth a few times.

Edit: getting the module_implements cache via:

drush cg module_implements cache_bootstrap > module_implements-before.txt
drush cg module_implements cache_bootstrap > module_implements-after.txt

If someone wants to try it out too

Well, as long as we loose 4 MB and hence have less memory used and get faster, I won't complain :).

module_implements_cache in itself would not change, but there is a new cache entry IIRC.

been running this patch for awhile without issue, just adding to the RTBC crowd

Another ++ from me, we've been running this patch on a few larger production sites for months now and have no issues. We also notice similar speed improvements to those listed in the summary.

This patch works well against the latest drupal 7.39
still rtbc

Patch looks great and seems to have been very well-tested. Committed to 7.x - thanks!

I fixed a few small things on commit (the first two just because the $reset parameter to module_implements() is for internal use only, so I thought having the PHPDoc reference the case where it's TRUE too much would be confusing for most developers trying to use this function):

diff --git a/includes/module.inc b/includes/module.inc
index f4a752d..076992c 100644
--- a/includes/module.inc
+++ b/includes/module.inc
@@ -677,8 +677,8 @@ function module_hook($module, $hook) {
  * Determines which modules are implementing a hook.
  *
  * Lazy-loaded include files specified with "group" via hook_hook_info() or
- * hook_module_implements_alter() will be automatically included as part of
- * module_implements(*, *, FALSE).
+ * hook_module_implements_alter() will be automatically included by this
+ * function when necessary.
  *
  * @param string $hook
  *   The name of the hook (e.g. "help" or "menu").
@@ -690,7 +690,7 @@ function module_hook($module, $hook) {
  *   implementations to be regenerated (such as after enabling a new module,
  *   before processing hook_enable).
  *
- * @return string[]|null
+ * @return
  *   An array with the names of the modules which are implementing this hook.
  *
  * @see module_implements_write_cache()
@@ -722,7 +722,7 @@ function module_implements($hook, $sort = FALSE, $reset = FALSE) {
     drupal_static_reset('module_hook_info');
     drupal_static_reset('drupal_alter');
     cache_clear_all('hook_info', 'cache_bootstrap');
-    return NULL;
+    return;
   }
 
   // Fetch implementations from cache.
@@ -778,7 +778,7 @@ function module_implements($hook, $sort = FALSE, $reset = FALSE) {
         }
       }
     }
-    // Implementations for this hook are now "verified"
+    // Implementations for this hook are now "verified".
     $verified[$hook] = TRUE;
   }
   elseif (!isset($verified[$hook])) {
diff --git a/modules/simpletest/tests/module.test b/modules/simpletest/tests/module.test
index 73f6327..eea3b51 100644
--- a/modules/simpletest/tests/module.test
+++ b/modules/simpletest/tests/module.test
@@ -307,7 +307,7 @@ class ModuleImplementsAlterTestCase extends DrupalWebTestCase {
   public static function getInfo() {
     return array(
       'name' => 'Module implements alter',
-      'description' => 'Tests the hook_module_implements_alter.',
+      'description' => 'Tests hook_module_implements_alter().',
       'group' => 'Module',
     );
   }