Avoid re-scanning module directory when a filename or a module is missing

I can't remember which issue this came up in, (edit: now I can, it was #752730: Remove file_exists() during bootstrap) but someone moshe mentioned we should probably disable modules that are missing if we find they don't exist. Old core modules like ping that were removed, contrib modules that are deleted rather than uninstalled, there are lots of ways this happens.

If we did that, are there still circumstances this could run more than once? Also even if we do go for disabling those, I'm split on whether it should be a one-off or built in somewhere.

+++ includes/bootstrap.inc
@@ -702,16 +702,19 @@ function drupal_get_filename($type, $name, $filename = NULL) {
+      if (!isset($scanned[$extension][$dir])) {
...
+        $scanned[$extension][$dir] = TRUE;

1) Let's move the variable assignment right below the conditional check, so the purpose of the conditional as well as the assignment is clear.

2) Wouldn't it make more sense to flip $dir and $extension in the array? And when considering that, wouldn't $dirs be a better name than $scanned? Perhaps not, just an idea.

Powered by Dreditor.

My brain is filled up with other stuff right now, so just throwing the idea out there: Any remotely potential issues if $dir == $extension (say, 'inc') ?

Also, we should open a separate issue to fix the root cause; namely, fixing {system}.status columns on a certain page/callback.

See #1096742: Disable enabled but missing modules

+1 on this patch, this can really slow down some sites!

No, I just wanted this bug to get fixed. Didn't get around to testing it. Sorry :)

Could this issue be related to this one #733308: Add static caching for drupal_system_listing()?

I've tested the patch and it works - the speed increase is major for my upgraded site that has 17 orphaned module entries in system table (I will be removing those).

The patch provides a working solution, but I wonder if it would be better to implement #733308: Add static caching for drupal_system_listing() as that adds a static cache to drupal_system_listing(), which will catch other places this may crop up. Once that is in place, I think the performance increase by doing this high level fix will be quite small.

I think this bug is more important than it seems.

I had only 1 orphaned module in a brand new Drupal 7 site we are building. (It was a feature-module that was removed from our git repository without proper uninstall)
I discover this bug only because I was profiling it, so I can give you some real data:

BEFORE:
The frontpage load taking 20 secs.
"file_scan_directory" was executed 1162 times. Taking 9 seconds in total
*Every single* page load.

AFTER:
Frontpage load taking 7 secs.
'file_scan_directory' wasn't executed at all.

(The load times are quite increased because of the profiler tool. Without profiling, it takes about half of the time in both cases)

So, especially if you have a lot of folders it's really expensive. In my case was even worse because I placed CKEditor source code folder inside the module folder. It has 238 folders. I have put it now in /libraries/ instead. (This reduced file_scan_directory to 868 calls, 7 secs in total)

But I think it's quite easy to end up in this situation and very difficult to realize for normal users, unless you have PHP debugging tools.

That dramatic change of speed was due of my own debug patch:
If ($name == orphaned module) return;

But with the patch of #4 still file_scan_directory is called 434 times taking 4 secs.
The problem is that those 4 secs are in *every* single page load.

#4 is a drastic speed improvement.

Subscribe. This is really needed. The Problem killed 80% performance of 2 our D7 sites.

I did test and profile this on a major site of ours. The bug killed the performance and every page call did use 100% CPU power and took around 30 seconds. With suns query fix from #1096742: Disable enabled but missing modules everything runs fine again CPU usage is very low again. But still file_scan_directory eats up 16% of a page-call. With this patch it goes down to 9%. Still a lot but much nicer and there shouldn't be any endless recursion because the directories are scanned over and over again .

The patch itself is very simple. Just one more static variable. And than a check if the directory was already parsed so it is not checked again for this page-call. I say RTBC.

+1 for getting this in asap. We use this patches (this one too: #733308: Add static caching for drupal_system_listing()) in production, too. And everything works like a charm.

Since this is a performance patch, and since catch already chimed in above, moving to his queue.

Tested patch at #4
Worked and made a dramatic difference on a site.

I'd like to see the following before committing this:

Profile a site where this bug is in effect, then compare:

No patch.

This patch.

This patch and #733308: Add static caching for drupal_system_listing().

#733308: Add static caching for drupal_system_listing() without this patch.

Screenshots from either xdebug or xhprof will do fine - can show detail from drupal_system_listing() or file_scan_directory() whichever is most obvious.

Sure I do this :)

Okay I did
drush dl devel feeds job_scheduler
drush en devel feeds feeds_ui job_scheduler -y

and than deleted those modules.

With latest 7.8 bootstrap the load of "/" takes around 20 seconds.

With patch from 1081266#9 the load of "/" takes around 3 seconds.

With patch from 1081266#9 and 733308#8 the load of "/" takes around 3 seconds.

With patch from 733308#8 the load of "/" takes around 3 seconds.

Performance seems to be equal with any patch. But lowest usage of file_scan_directory() is with both. For D8 I'd say test peters a bit more and add it. BUt for D7 I would really love to see the patch from this issue in the next release. If you reorganise features your site will be dead in the current state.

Thanks for the profiling, that means there's no reason to have both patches then.

#733308: Add static caching for drupal_system_listing() is the older issue but I've marked that duplicate.

However to me it makes more sense to add the static caching to either drupal_system_listing() or file_scan_directory() - since that's called by more places (such as the installer which was the original motivation for opening that issue).

@mfb, the drupal_get_filename() cache is primed by http://api.drupal.org/api/drupal/includes--module.inc/function/module_li... on every request, so removing the cache from there isn't an option. The way that cache is primed is a bit odd so we could consider trying to clean that up elsewhere.

Since drupal_system_listing() is only really called via this error condition or otherwise very rarely it seems fine to have the static cache in two places to me - in the usual case they won't both be used at the same time.

@catch So is this issue again RTBC or what should be done?

Just ran into this myself, this a huge performance show stopper. Escalating to critical. Patch from #9 still applies. Marking for review.

Than again I set this to RTBC. But for D8 I would say it should follow the more complex path that das-peter showed in #733308: Add static caching for drupal_system_listing(). For D7 I say this is essential or any bigger system that uses features will die eventually. D7 really needs some kind of hot fix.

Committed to 7.x and 8.x. Thanks!

I'd still like to figure out why we keep looking for these files on every request. It feels like we patched the problem vs eliminated the root cause. I've updated the priority and status accordingly. Hopefully we can continue to investigate this.

Thanks & I fully agree, working on this felt always like patching a symptom and not the cause.
While the static cache is a good thing anyway, I've been asking myself if it would be a good idea to disable missing modules and flag them as broken. Idea behind this is that I would like to know if there's anything wrong with my setup.
Next question would be what's considered as broken?
Only if the full module is missing or even if registered files of a module are missing?
What about a consistency check on the module page or an extra report page?

system_list() is called on every bootstrap. But there is only a cache for the database table. The directories will be scanned on every call.

So is there any reason why we couldn't put the result from the loop in line 185 into the cache?

Only thing I currently can think of we will have a problem if a module is gone missing.

Druapl 7.9
Hi, i'm new to drupal and I believe I am suffering from poor performance because of this same reason.

on my site I keep getting Internal Server errors, not enough memory errors and My webhosting company tells me I have to upgrade to the $19.99 per month plan in stead of shared hosting [thanks greengeeks the super useful drupal hosts]

Also, images seem to drop off
Site Logo
Captcha Image
Views gallery - of small rotating logos
-this curiously only on Mac Safari and Mac Firefox

Can any one please instruct me or direct me as to how I can apply or where exactly do I execute that snippet of code so I can find out what modules are causing the super slow performance?.

This is the only post that I found that had a seeming relationship to my problem, my apologies if this is not the right place to post it.

Many Thanks

First we have to solve this in D8. The most important problem here was solved in D7 and commited in October.

I think that your problem is a suport request, open a new issue.

I've patched my bootstrap with patch #4 and the performance increase is notorious.
Any idea when this might be updated on a D7 official version?
I think it is very important, as most D7 sites I've built all suffer from the same lack of performance.

http://groups.drupal.org/node/203508

Stop subscribing, start following

What would the negative implications be of just eradicating invalid system table entries? Perhaps provide an indication on the module / theme / status report admin screens indicating references to modules or themes that don't exist and providing a button to simply delete the references.

http://drupal.org/node/1052250#comment-5113888

You can try this if the problem is related to system table references to modules that don't exist:

http://drupal.org/node/1052250#comment-5113888

Pretty worried about this. I've followed all the links here, done all the patches to 10 different installations of D7 in different combinations, and the only conclusion I can draw is that I simply have too many modules installed.

Initially, page load times were upwards of 70 seconds and file_scan_directory() was being called over 10,800 times each page view. Since updating to 7.x-dev and monkeying around with reducing the number of available modules, I've got this down to ~1500 calls but the page load is still around 16 seconds.

If it helps anyone, I initialized a variable at the top of /includes/file.inc (outside any function, as a global): $ctest = 0; and then threw at the bottom of file_scan_directory(): global $ctest; echo $ctest++. " $depth: $dir<br />\n";

My site has 77 modules installed on top of core, with 37 available but not installed. Is this simply too complex for Drupal?

You should do a debug_backtrace() from file_scan_directory() to see what's calling it. It shouldn't be called during normal operation at all, but it can be if you have a badly behaving contrib module installed.

I've seen sites with upwards of 300 modules installed, 100 is unfortunately not unusual at all.

DUDE, catch... THANK YOU for the nudge!! I rolled down that path earlier but abandoned when I couldn't get any meaningful data out of debug_backtrace(). Well this time I found the right output - and here's the results:

• drupal_bootstrap: 67 calls
• menu_execute_active_handler: 1434 calls

Crazy. What does that even mean, rogue menus? I'm looking at menu_execute_active_handler right now.

For reference, here's what the last few lines of my file_scan_directory() now looks like:

	$bt = debug_backtrace();
	$end = end($bt);
	var_dump($end);
	global $ctest; echo $ctest++. " $depth: $dir\n";
  return $files;
} // end file_scan_directory()

Any ideas by chance?

You're looking at the first function in the backtrace, instead find file_scan_directory() in the full backtrace then work up from there - the first couple of functions you find outside file.inc are a good place to concentrate on.

Dear catch: today I learned things.

1. debug_backtrace() is super handy
2. I need to be more careful about where I leave my drupal_flush_all_caches() calls
3. 16 hour days suck
4. the Drupal community is a godsend

For anyone else: drupal_flush_all_caches() slows sites down BIGTIME and seems to initiate a good number of file_scan_directory() calls through whatever cache-clearing things it does. This didn't really have much to do with the actual thread topic, but the directory scans instead turned up as a symptom. Thanks again for your help.

drupal_get_filename.patch queued for re-testing.

When I went to apply this #9 patch (manually) in D7, I saw that the *new* code is already in the version of D7 I'm running (7.14), but I'm still experiencing very slow initial loading of my front page. This is running locally on a virtual host in Win7 with WAMP. After the initial load time of 15-20 seconds, my pages load within a second or two thereafter.

Anyone have any suggestions of what else to try / look for?

@sertaconay
There is no active patch above to review, Dries in #37 committed patches to D7 (#4) & D8 (#9).

I've attached a patch for 7.x that fixes this issue for us. Once testbot gives the A-OK, go ahead and move the issue back to 8.x.

Wow.

The above patch just turned my glacial D7.14 ZWAMP dev env into a rocketship.

You all deserve beers, thanks.

Patch for D8 that should fix this issue as well.

Using the D8 caching interface now :)

What happened to CACHE_TEMPORARY?
http://drupalcode.org/project/drupal.git/blob/58964deb124e55d61f51a167d5...

API says it's still in there: http://api.drupal.org/api/drupal/core!includes!bootstrap.inc/constant/CA... and is referenced here http://api.drupal.org/api/drupal/core!lib!Drupal!Core!Cache!CacheBackend...

Going to re-roll patch with -1 instead of CACHE_TEMPORARY as a temp solution to this problem.

#730060: Replace CACHE_TEMPORARY, cache_clear_all() and minimum cache lifetime with cache tags support

The api docs have troubles with new commits. It can take weeks before it gets refreshed.

So I need to add in 'drupal_get_filename' to the list of caches getting reset in system_list_reset(), or is there a better way to do this?

I came across this issue when looking at why D6 was querying the DB on every module_load_include call and thinking of how to mitigate.

My understanding of the issue is that it fixes the edge case where the DB isn't available to lookup the module path (or its not specified in system table), and the module directory no longer exists

Is there a reason why even with the improved D7/8 drupal_get_filename doing file scans and then caching the list of bad files, why we wouldn't add the list of found files to a cache table for retrieval by future calls? I guess it would need profiling, and maybe be a configurable option depending on what caching mechanism was being used, but would looking up a value from a cache not be more efficient across requests? My thought is that on a production site the files aren't likely to change much in between requests, so the efficiency gains could be quite sizeable?

If this feels like getting off topic (or has been raised as another defect elsewhere) I'm happy to move it out of this issue and create a new one, and equally happy to attempt some work on a patch if it feels like a valid way of thinking.

Ok, so I've had a go based on my comment in #68 and @mikeytown2's good work in #64 at creating a cache which stores the "good" cache entries, and an additional cache for the "bad" or missing files being included.

I need to do more profiling to determine if there is any performance benefit of this cache on a vanilla installation, and also with alternative cache backends, but thought it best to see what testbot and others think.

My working assumption is that retrieving from the cache should always be more optimal than a db query even when the cache is in the db, (flawed assumption?) but that the benefits of this would be felt in complex sites with 100+ modules, particularly custom modules, with dedicated caching solutions.

Hm. Not sure I quite understand this. Output from the test failure is:

Basic standard + all profile upgrade path, bare database 25 passes, 33 fails, and 39 exceptions

Fatal error: Cannot use object of type stdClass as array in /var/lib/drupaltestbot/sites/default/files/checkout/core/includes/bootstrap.inc on line 2901
FATAL Drupal\system\Tests\Upgrade\LanguageUpgradePathTest: test runner returned a non-zero error code (255).
- Found database prefix 'simpletest870634' for test ID 468.
[15-Aug-2012 17:42:17] PHP Fatal error:  Cannot use object of type stdClass as array in /var/lib/drupaltestbot/sites/default/files/checkout/core/includes/bootstrap.inc on line 2901

but that doesn't appear (from what I can figure out) to be anything that calls or is related to the drupal_get_filename function which is being modified.

Any suggestions welcome (not done much of this so still getting to grips with testbot)

#69: drupal_get_filename_cache-1081266-69.patch queued for re-testing.

Ah - error in the variable name I was saving in the cache set following the file scan.

This now passes the failing test in my local environment now so resubmitting.

#74: drupal_get_filename_cache-1081266-74.patch queued for re-testing.

Definitely confused by these test failures. All upgrade path tests pass on my local site. Does anyone else get any failures from this patch?

Updated patch - passes tests locally.

Related ?
http://drupal.org/project/bootstrap_optimizer

Another solution http://drupal.org/project/clean_missing_modules

I think that every time when admin submits module list, Drupal should check all enabled modules and clean up orphaned file names from {system} table.

The patch for D7 works great, the D8 patch has issues. Thus I'm changing the tags to show this.

D7 patch looks good to me too.

#80: drupal_get_filename_cache-1081266-80.patch queued for re-testing.

If you use http://drupal.org/project/clean_missing_modules then this shouldn't be a problem right?

The patch in #80 is for D7 or D8? Just the Version is for D8, but people are talking about applying this to D7.

@tsphethean any direction on where this should be applied? It can't be for both D7 & D8.

Sorry, yes - #80 is a D8 patch but is pretty old so might need a re-roll.

Trying a re-roll against latest D8 build.

Fixing whitespace issue which prevented patch applying.

Ok think I've made a mess of my local site - rebuilding and will re-roll the patch by hand tomorrow.

Having a bit of a look at the revised drupal_get_filename in D8 I'm actually having a few second thoughts about my original approach. We're now doing:

$file_list = state()->get('system.' . $type . '.files');

To get a list of all the files in the system, and then building up the array. Not knowing too much about the new state system, is this going to be DB level state in the first instance, so would benefit from the eventual $files array being cached, or is state going to be cached anyway by the state interfaces?

Grateful for pointers... happy to proceed if it seems worthwhile. Still getting to grips with state, config and things :-)

Re-roll of #58 against the latest D7 dev

Going to test #102 on D7 via testbot. Will move issue back to D8 once patch goes green.

#102 Passed all tests.
Moving back to 8.x and needs work.

@StinkFoot
I think you need to use -p1 with your patch commands.

Dry run:

git apply --check -p1 drupal-1081266-102-drupal_get_filename-D7.patch
OR
patch --dry-run -p1 < drupal-1081266-102-drupal_get_filename-D7.patch

Apply:

git apply -v -p1 drupal-1081266-102-drupal_get_filename-D7.patch
OR
patch -p1 < drupal-1081266-102-drupal_get_filename-D7.patch

I am running the patch in #102 in production since today and I am experiencing an insane improvement. My page load times went from 2200ms down to 500ms! So far I am not facing any problems. Thank you!

Is this patch already applied on last D7?

@PlayfulWolf
Don't think so. https://api.drupal.org/api/drupal/includes!bootstrap.inc/function/drupal...

D7 patch #102 is RTBC, D8 is still needs work.

Created an issue summary.

Hi,
any idea when the #102 patch will be commited and released to the next D7 release ?
For info, the patch saved 3.5sec for each page load (7sec -> 3.5sec), for a Drupal instance with about 250 modules enabled !

Thanks for the patch anyway !

Only for information, I'm using this code since D6 to remove all missing files from system table.

Why we can't add a similar cleanup process every time we launch update.php?

/**
 * Remove missing modules.
 */
function mymodule_update_6001() {
  $result = db_query("SELECT * FROM {system}");

  $items = array();
  while ($record = db_fetch_object($result)) {
    $record->info = unserialize($record->info);
    $items[$record->name] = $record;
  }

  foreach ($items as $item) {
    if (!file_exists($item->filename)) {
      $ret[] = update_sql("DELETE FROM {system} WHERE filename = '" . $item->filename . "'");
    }
  }

  return $ret;
}

I couldn't read through all of the over 100 posts here, but I thought that I would share how I was able to determin which missing modules were causing this issue on our server.

for i in $( drush sqlq "select filename from system where filename like 'sites/SITEDIRECTORY/%'" ); do if [ ! -f PLATFORMDIRECTORY/$i ]; then echo MISSING: $i;drush sqlq "select status from system where filename = '$i'"; fi; done;

Where PLATFORMDIRECTORY = '/var/www/drupal' and SITEDIRECTORY = 'example.com' or possibly 'all' depending on your setup.

Running that from cli will give you the name of any missing files and the status of the module that is missing. Example output:

MISSING: filename
MISSING: sites/www.example.com/modules/contrib/addressfield_phone/addressfield_phone.module
status
1
MISSING: sites/www.example.com/modules/contrib/taxonomy_menu_trails/taxonomy_menu_trails.module
status
0
MISSING: sites/www.example.com/modules/contrib/views_tree/views_tree.module
status
0

As you can see I found my module causing the issue.

Adding tag to show that we have a RTBC 7.x patch in #102 but not a 8.x patch.

Applied #102 to 7.19 core, which has 148 enabled modules per drush pm-list, and runs on a well tuned cluster. We do not have any missing modules or files AFAIK.
Patch works well, no issues, but also no real speed improvement.

@ChristophWeber
The speed improvement only happens if you have a missing module. Thanks for the info on the 7.x patch though.

I have a situation where an empty string is passed as parameter $name, which causes some extra loops for no reason.

This is also causing this error message:

The following module is missing from the file system: .

See a proposed fix here https://www.drupal.org/node/2383823#comment-9385897

I applied both patches (issue 9385897 and issue 9386005) and I can see they both work well together.

ps: I am using Drupal 7.34

This issue is more relevant than ever, see the related issue.
I'll re-roll and test this patch soon.

#102 still applies with an offset of 21 lines and is RTBC from my understanding. In order for this to get into D7 a patch for D8 needs to be created OR it needs to be proven that this is fixed or is no longer relevant in D8.

Ah okay, thats good.
Checked in D8 beta 3, still seems relevant. Code got a rewrite but I think it still has the same issue.
New patch attached, created from D8 git head.

Hmm, guess watchdog isn't always available at that point. Any suggestions?

http://www.appneta.com/blog/drupal-8-watchdog/

Drupal::logger() is the way of the future; but your patch already uses that.

Drupal::logger() -> LoggerTrait::error() -> DbLog::log() which writes to the watchdog table. Having an error here seems like a separate issue.

The profile being missing has to do with the code in ExtensionInstallStorage::getAllFolders(); it calls drupal_get_profile() which returns NULL and then InstallStorage::getComponentNames
('profile', array(NULL)) is executed resulting in the error.

I've modified your patch in #120 so it won't call getComponentNames on a null array and I've also incorporated the fix for this from #2383823: drupal_get_filename() should check if $name is empty

Line 28 is where it went fatal and it's the function definition.
https://api.drupal.org/api/drupal/core!modules!system!src!Tests!Bootstra...
Not sure where to go from here

EDIT:
Running the test locally I get
ResponseText:
( ! ) Fatal error: Call to a member function get() on a non-object in /core/lib/Drupal.php on line 262
Call Stack
#TimeMemoryFunctionLocation
10.0010150168{main}( )..\index.php:0
20.16301262768Drupal\Core\DrupalKernel->handle( )..\index.php:24
30.33404883904Stack\StackedHttpKernel->handle( )..\DrupalKernel.php:579
40.33404884008Drupal\Core\StackMiddleware\ReverseProxyMiddleware->handle( )..\StackedHttpKernel.php:23
50.33404884048Drupal\Core\StackMiddleware\PageCache->handle( )..\ReverseProxyMiddleware.php:58
60.37005466664Drupal\Core\StackMiddleware\KernelPreHandle->handle( )..\PageCache.php:52
70.42908183680Symfony\Component\HttpKernel\HttpKernel->handle( )..\KernelPreHandle.php:53
80.42908183928Symfony\Component\HttpKernel\HttpKernel->handleRaw( )..\HttpKernel.php:66
90.636011414640call_user_func_array
( )..\HttpKernel.php:145
100.636011414864Drupal\system\Controller\BatchController->batchPage( )..\HttpKernel.php:145
110.637011472440_batch_page( )..\BatchController.php:60
120.649012191896_batch_do( )..\batch.inc:83
130.649012192056_batch_process( )..\batch.inc:101
140.653012232128call_user_func_array
( )..\batch.inc:256
150.653012232264_simpletest_batch_operation( )..\batch.inc:256
161.880113557656Drupal\simpletest\TestBase->run( )..\simpletest.module:320
173.962217933560Drupal\system\Tests\Bootstrap\GetFilenameUnitTest->testDrupalGetFilename( )..\TestBase.php:869
183.972217980328drupal_get_filename( )..\GetFilenameUnitTest.php:39
193.972217980616Drupal::cache( )..\bootstrap.inc:270

Will work on this some more.

OK story is the testing framework sets https://api.drupal.org/api/drupal/core!lib!Drupal.php/function/Drupal%3A... to NULL. This causes all calls to the Drupal class to fail it seems; thus I feel like I'm missing something. I've edited the code to work around this so the tests pass.

https://api.drupal.org/api/drupal/core!tests!Drupal!Tests!UnitTestCase.p...

Looks like a weird workaround. Are you sure it's the testing framework that sets it to NULL?
Maybe it's being called at a point where the Drupal class isn't initialized yet. I did not look that deep into D8 yet though so would have to do some more searching.

Not 100% sure but according to the docs that is what it does

Sets a new global container.
Parameters

\Symfony\Component\DependencyInjection\ContainerInterface $container: A new container instance to replace the current. NULL may be passed by testing frameworks to ensure that the global state of a previous environment does not leak into a test.

Brought this up in IRC and the workaround I created for this seems to be ok.

"The idea with that test is to ensure that drupal_get_filename() works in the bootstrap process in which the container is not there for a purpose." - dawehner

I'll document this so people know why we're checking types.

Added this comment to the code
In early stages of the bootstrap process the container may not be set inside of the Drupal class.

I can't see any problem in doing extra checks. Is that about having extra bytes in the code? making the execution slower?
We should seriously focus on getting this fix applied rather than debating what is better.
BTW, nothing can be worse than the current implementation.

I think @beejeebus is right though. Better fix it properly now.
You don't want to execute an SQL query (for a cache lookup) every time you hit that piece of code.

And extra checks can really make your code more unreadable, so why add extra checks when you don't need them?

And let's fix that mistake in the 7.x patch too while we're at it.

D7 patch passed, so back to D8

Changed to major as this issue keeps popping up for me, for example when you delete a module without uninstalling it (which could happen quite often when you use makefiles/profiles).

I also think more people are having this issue without them knowing it.

Both patches (#137, #138) look good. +1 from me. Also agree that this is an under reported issue.

Yes, this can really cripple your servers with high CPU loads.
Not only with deleted modules , but also if you have an unpatched version of imagecache_actions which contains a typo which triggers this bug.
#2166715: Typo causes extra query every page load

Lets get this committed, shall we?

Hmm, how we get this working for D7 and D8 at the same time. Seems impossible...

Once they apply the patch on D8 they will change the issue to be backported to D7

Re-submitting the patch

Not a fan of the extra call of cache_get so early. The changes in Drupal.php to return NULL funky and shouldn't really happen there.

I'm also leaning more to the idea of cleaning up when installing/uninstalling modules, see comment #86.

Also, needs tests.

What about adding a hook_requirements() check that looks for missing modules and gives you a link that you can click that will drop that module from the system?

That is also a good place to place a bold red warning that you should never ever just remove a module without uninstalling it first. We're putting a huge amount of efforts into D8 to make uninstallation save and not leaving behind configuration and data and not being able to uninstall when a module is still used, just removing a module breaks all that. What if that module for example provides a bundle or a field type that is still used?

+1000
See #112

I also think that it's better remove invalid entries than workaround.

jeroen.b's patch from comment # 137 and #138 makes sense to me

The following comments between #151, 152, 153 talk about Removing module schema information without having run a proper uninstall.

@swentel
I Didn't see Drupal::hasService(); will use that instead of the funky NULL as Drupal::hasService() is used elsewhere in drupal_get_filename(). Also moved the cache to right before we do a filesystem scan; prevents a cache get for the vast majority of calls. Thanks for the critique!

joseph.olstad is correct; removing module schema information without having run a proper uninstall is why this logs the missing module; so an admin can properly deal with it. Since the code is missing there is nothing drupal can should auto do.

Agree with Berdir; adding an additional check in hook_requirements for missing modules sounds like a good idea. I do think we need both solutions; hook_requirements & avoid re-scanning module directory. If we implement an additional check using hook_requirements, we could probably get rid of the logging inside of drupal_get_filename().

new patch with less php syntax errors™

Thinking I'll have to install D8 if this fails again...

I just tested this against HEAD, \Drupal::hasService('cache') and \Drupal::hasService('logger') don't return TRUE, so the cache never gets created.

How would we create tests for this?
AFAIK \Drupal::hasService('cache') returns FALSE in the testsuite so we have to find some other way to test this.

Regarding #152, I think we should do that in a separate issue.

Ah, it had to be \Drupal::hasService('cache.bootstrap') and \Drupal::hasService('logger.factory')

New patch attached which fixes that. Just tested locally and now I get cache and a watchdog message.

Regarding #137 D7 version @jeroen.b

After applying that patch I got this error:

Exception: theme() may not be called until all modules are loaded. in theme() (line 1017 of /Users/joel/Sites/mysite/html/includes/theme.inc).

And on drush rr following that message:

WD system: The following module is missing from the file system: .

Second drush rr went through ok, but didn't resolve the first on page exception.

Omega 4 is the theme being used.

@joelpittet
And you are sure those messages are related to this patch?

@joelpittet Any chance you updated rules recently? Because: #2324587: Rules might be triggered too early in the bootstrap This can trigger the theme() exception as far as I remember.

Yes it was related to this patch it was the only one applied at the time, accept it was d7 patch in #138

@das-peter I just woke up but totally, I do plan on applying that when I get in. Thanks:)

Didn't have my coffee, re-read #165, I'll try them together and report back:)

@das-peter That rules patch in #165 didn't resolve the issues mentioned in #163 but that rules patch didn't cause any new problems, so far.

@jeroen.b #138 issues I mentioned in #163 are quite repeatable.

Directly after applying the patch, run registry rebuild.

The registry has been rebuilt via registry_rebuild (A).   [success]
http://site.dev|severity=alert|type=system|ip=127.0.0.1|uri=http://site.dev/|referer=|uid=0|link=|message=The following module is missing from the file system: .
WD system: The following module is missing from the file system: .   [error]
All caches have been cleared with drush_registry_rebuild_cc_all.    [success]

@joelpittet
Can you pastebin the output of drush pm-list?
I can't reproduce, even when I use Omega.

I do think I have seen this behaviour before. I think it was when I did a drupal_get_path on a module that wasn't enabled/installed and also wasn't found on the filesystem. Nervermind that, that makes no sense.

Totally here, sorry it's long: https://gist.github.com/d7e1da8b7113e0f313cb

Woah, that's too much to debug for me. Can you try the attached patch?
It adds an backtrace to the watchdog message because I think this is in some contrib module.

@jeroen.b thanks for that it gave me an idea. The backtrace is super huge too, so weeding through that wouldn't be fun, I can still post it if you prefer, but I put a breakpoint there to see the context.

The $name is empty, but the $matched_name was addressfield.

Would that have an effect on this patch?

Digging through the callstack and two other modules were mentioned workbench_moderation and linked_field, though I have my money on workbench_moderation being the trouble maker... it's an invaluable module but has to fight harder than most to do what it does.

Nah, addressfield just was the last value in the array $matches, so the last module it was able to find.

And seeing the menu_rebuild, now I remember where I have seen it before.
It's when you have a menu_item with a wrong "file path" value. Can you gist the backtrace?

Here's the backtrace: (formatted with pre in the patch)
https://gist.github.com/bf0ee1fe8feb398647ad

Oh elysia cron comes into the call stack too as the $parent in _menu_router_build()
$item['file path'] = drupal_get_path('module', $parent['module']);'

admin/config/system/cron

@jeroen.b Aha you were right! #2407129: Missing module<empty> on menu rebuild because of bad admin/config/system/cron override

The module name is sometimes empty, I patched the elysia_cron one but the next one is with commerce commerce_tax_ui_tax_rate_title.

I'm trying to decide if this is something we can/should fix in this patch, or should I just use this and file patches on all those modules (daunting argh)

Just a heads up #1158322-199: Add backtrace to all errors is handy for error backtracing. In this case, the linked issue wouldn't have helped; but I do find the linked issue to be super helpful.

The tax one doesn't have an issue opened up for it and it's a bit different but very similar.

The 'commerce_tax_ui' builds the hook_menu with
'file' => 'includes/commerce_tax_ui.admin.inc', but without a module key again. But in the screenshot the path has already been filled out... :S

I can't reproduce that with the commerce_tax_ui.
Maybe there is some weird hook_menu_alter somewhere?

Anyway, I don't think we should fix these things in the patch. The stuff we find with this patch is already broken, only difference is that we can see what's broken now.
It's up to the maintainers now to fix their modules.

@jeroen.b very well could be, I'm a bit worried about the error produced in #137. Though I can't figure out why this patch would cause that at all... sorry for holding this up.

Grateful though that this indirectly solved elysia_cron issue.

@joelpittet
Don't worry about holding this up, this issue has been here for a few years ;)
About the error in #137. Are you talking about the error you reported in #163?

Exception: theme() may not be called until all modules are loaded. in theme() (line 1017 of /Users/joel/Sites/mysite/html/includes/theme.inc).

This one?

I could not reproduce this. Not with a clean Drupal 7 HEAD, Drupal 7.34, Drupal 7.34 with Omega and Commerce.
Can you figure out what module (indirectly) calls theme()?

After repairing elysia cron I've not seen this error since but I'm keeping my eye on it, the patch is on my staging environment till I deploy the next round of changes.

I heard you guys want tests.
Here's a D8 patch with a testDrupalGetFilename() assert. I had to change the $bad records to a drupal_static to reach it from the test.
We can't use the bootstrap drupal_get_filename:bad cache for tests as the cache isn't available in the tests.

I'll look at tests for the D7 version later.

I think these tags aren't relevant anymore

Here is a D7 patch with tests.

changing to 7.x for testing

All green. Let's get this committed?

Well, first of all, this should go in D8 first. Secondly, see comment #150 and #151. Doing this kind of optimization at run-time really isn't the proper way to fix this bug. To be clear: it is a bug (sometimes extremely annoying), I've actually hit it a couple of times as well, but I disagree that we should fix this at run time. There are better, cleaner ways (order is my preference)

1. hook_requirements() with a link to clean up
2. running update.php
3. when submitting the modules page
4. maybe, maybe, maybe when clearing full caches, although that's maybe over the top

I'm in favor of number 1 because we then also have a UI that informs the user which module(s) are actually missing. All the other variants, which may trigger watchog, are less obvious and are easily missed.

I'm in London next week for drupalcamp london, I'll try to write up a patch during those days.

I'm all for really fixing this, but sometimes that just not possible by just cleaning the registry.
Sometimes other modules call drupal_get_path manually with wrong arguments, or with disabled modules, I have seen a couple of cases.

Sometimes you can't properly uninstall a module, we deploy all sites with drush make, if we remove the module from the makefile, the record is still in the registry.

My plan was to get this patch committed and then create a new issue where we add the hook_requirements functionality. If you want to include that in this patch that's fine with me, but please also use the existing patches.
Currently if something goes wrong in drupal_get_filename, you have absolutely no idea.

I agree with jeroen.b , there's going to be situations where admins of large scale sites managed by committee that can't just decide by themselves if or when to cleanup something and determine if it was something left by a drush make or if it was a module that was removed from the filesystem by mistake. The best approach is his solution because it fixes the performance problem and also is noisy enough so that admins will be able to see what is going on and let them take a reasonable course of action without a huge performance penalty.

Prior to this patch not only are admins left in the dark but there's also a huge performance penalty. Lets get this committed. We've been running patch #102 in production for a while and I just reviewed patch 189 and it looks good. So for those working on D8, please follow the advice of jeroen.b because not only do we want to see D8 improve but we also are running production D7 sites that pay for our work on D8.

I'm using the patch from #189, I'm not sure what's wrong but it reports me this error:
"The following module is missing from the file system: mothership"
Mothership is not a module, but a theme, and this theme is present in sites/all/themes.
Mothership is not enabled(but was enabled before), I had the version 2.x before, but now I'm using 3.x.
Not sure how to fix that ?

@heyyo, do a "grep -in mothership" in your module and themes directory.
There is probably a call to a file in that module somewhere or a misspelling.

an issue where something like this occurred to me:
https://www.drupal.org/node/2428105

here is another:
https://www.drupal.org/node/2375741

Thanks a lot @SocialNicheGuru it was indeed the problem with this file mothership/mothership/panelsstyles/motherstyle/motherstyle.inc
Including 3 times :

'path'    => drupal_get_path('module', 'mothership') .'/panelsstyles/motherstyle'

The nice patch from by jeroen.b from comment #186 needed to be refactored after D8 core commit #40cc6312 for issue #2090115 by alexpott, xjm: Don't install a module when its default configuration has unmet dependencies.

Attached is a refactored patch for D8 accordingly.

D8 patch #202 passed all tests march 26, 2015 22:00 0400+gmt
D7 patch #189 passed all tests in February 2015
D6 not yet backported, lets commit the D8 and D7 patch first.

Adding a cache to this kind of low-level function looks odd to me (others above have said the same thing)... Also there is no code that ever clears the cache (except on a sitewide cache clear)? Can't it get stale?

+    if (\Drupal::hasService('logger.factory')) {
+      \Drupal::logger('system')->error('The following @type is missing from the file system: @name', array('@type' => $type, '@name' => $name));
+    }

Maybe a simple trigger_error() is better here? That should get it into the logs anyway, plus onto the screen on dev sites (a key part of this, so developers can find mistakes in their code that lead to this). This is sort of getting into the territory of #2380361: Latest tweaks to bootstrap.inc can make Drupal sluggish when there is code that tries to load a file that doesn't exist but the two issues are closely related. I tend to think warning about this problem is realtime is better than trying to fix it with a cache in realtime.

When developers are removing things from the filesystem they're usually:
A) running a drush make script
B) performing filesystem operations perhaps from a script
C) changing in or out modules, in which case a full cache clear is run.
D) upgrading a Drupal site from one distribution to another
E) upgrading a Drupal distribution from one version to another (that may be missing files seen in previous versions and lacks appropriate hook_updates)
F) upgrading Drupal core and forgot to restore a folder such as sites/all/modules/contrib
G) any combination of the above combined with updatedb

Also there is no code that ever clears the cache

operations C, D, E, F, G will trigger a site-wide cache clear, so the cache is not stale.

Adding a cache to this kind of low-level function looks odd to me

and so does re-scanning module directory when a module is missing

Maybe a simple trigger_error() is better here

sure it would be nice what about the performance issue? Example: webform_conditionals from webforms 3.x was swallowed up by webforms 4.x , but if you run a pm_uninstall on webform_conditionals 3.x are you sure that you're not going to remove tables that are now used by webforms 4.x? So now you have a performance issue while your production site which needs the new features from this new module that swallowed up another module but the schema table says it's still installed but you've removed it from the filesystem because the webforms readme.txt told you to do so. No one paid attention to this before until they realised their site was slower than it used to be so they went on to find some performance fixes and applied this patch. Now they're aware of multiple other problems that they were not aware of, but no problem, this patch fixes the performance issue without having to immediately deal with the mess undernieth that you will need a committee to sit together and point the finger and look at test results and build behat tests for and wait for approval to make the necessary changes, meanwhile the clients are frustrated that your site is slow except with this patch thankfully we get both INFORMED and RESTORED PERFORMANCE.

Meanwhile, much of the drupal community sits in ignorance wondering how entropy is creeping in and slowing down their sites, not knowing how to resolve it, they start thinking that the best solution is to re-install and start from scratch and hope that the performance problem doesn't come back. Or worse yet, they say, hey, lets install Joomla instead.

Why don't we just commit the patches, illuminate the drupal community and put the smiles back on the developers faces and the confidence back in their ability to administer sites, we get performance back and we also get informed of what is going on! Otherwise we're completely oblivious as to what is happening and why our sites become so damn slow over time. Finding this patch was a stroke of good luck. Thanks to all those that created it and pushed it forward.

RTBC + please

100% agree with joseph.olstad #205.

Will also say caching a bad list makes sense due to typo's when calling drupal_get_path(), see #199. Also see this issue where the bad module name was ''. Having your site be slow while you have no idea where to look sucks #2407129: Missing module<empty> on menu rebuild because of bad admin/config/system/cron override. These 2 issues point out that with the mothership theme or the Elysia Cron module installed and this patch not enabled results in a much slower Drupal install for those using the code; which is around 20k sites (counting the d7 installs).

I agree that in an ideal world we wouldn't need a cache here; but we're on the web where bad things happen all the time (typos) and bureaucracy can tie your hands.

A while ago I created a drush tool for detection and auto cleanup of phantom modules based on comment #112 however even with that, my tool only cleans out phantom modules and does not yet clean out phantom themes. With that said, I have run it on one production site but not on another. The patch that everyone here has worked hard on over the past 4 years correctly informs us and gives us the luxury of delaying such a cleanup without a performance penalty. There may be some scenarios where a cleanup has to be delayed for long periods of time. I think we've already outlined the importance of this but just to show you how much this issue is important it's why I am sharing this.

A small drip for Dries and D8, a nice warm douche for all of Drupal kind!

When developers are removing things from the filesystem they're usually ... trigger[ing] a site-wide cache clear, so the cache is not stale.

True, I guess the cache only goes stale if a missing module in the filesystem is added back, and most people probably do expect to have to clear the site's caches when doing something as big as adding a new module (although it's not always technically required now).

Keep in mind that for the trigger_error() solution, it would not just be that - the idea would be to combine it with something like #195 to fix the cases that actually can be fixed. (I'd add "run it on cron" as a possible option to the list of places in that comment where the fix could be done, by the way.)