Proposed commit message (D7)

Issue #1081266 by stefan.r, jeroen.b, mikeytown2, tsphethean, mfb, joseph.olstad, marcelovani, Fabianx: Avoid re-scanning module directory when a filename or a module is missing

Problem/Motivation

Drupal occurs a performance deficit when multiple filenames (ie. modules, themes) are missing or moved. The deficit occurs because we do a file scan perpetually to look for missing modules on certain pages, such as admin/config.

Proposed resolution

For D8: We remove the "missing file scan" that happens in drupal_get_filename() altogether and do various workarounds to deal with this scan in places where we haven't cached file locations yet, such as in the installer and in some tests (see #351). Instead of a file scan, we now do a trigger_error(), informing the developer/administrator about the missing file.

For D7: We cache any missing files in a static variable as well as in cache_bootstrap (for 24 hours, or until we visit the themes/modules overview page). We also do a trigger_error() as soon as we find a missing file in the drupal_get_filename() call.

In a followup issue we can check for this in hook_requirements() as well.

Remaining tasks

None.

User interface changes

None.

API changes

In D8, we remove the file scan from drupal_get_filename(), which also affects drupal_get_path(). The lack of this is only a "problem" in the installer, in tests and during module rebuild, which are not part of the API.

Original report by mfb

This patch provides a performance boost for sites that are missing modules (common on old sites which have been maintained for many years). In this case, drupal_system_listing() and file_scan_directory() will be called over and over looking for missing modules on certain pages, such as admin/config.

This patch adds an additional static variable to drupal_get_filename() to store an array of mask-directory combinations that have been scanned. Once one scan has been performed for a particular extension in a particular directory, there is no need to run the same scan later in the same request.

This information will be cached in 'drupal_get_filename:missing' in cache_bootstrap as well. Invalidation of this cache happens upon running cron, and upon visiting the themes/modules overview pages.

Beta phase evaluation

Reference: https://www.drupal.org/core/beta-changes
Issue category Bug because significant performance slowdown
Issue priority Major because significant performance slowdown.
Prioritized changes The main goal of this issue is performance
Disruption N/A
Files: 
CommentFileSizeAuthor
#512 interdiff-499-511.txt762 bytesstefan.r
#512 1081266-511.patch22.8 KBstefan.r
PASSED: [[SimpleTest]]: [MySQL] 41,497 pass(es).
[ View ]
#499 interdiff-498-499.txt1.43 KBstefan.r
#499 1081266-499.patch22.64 KBstefan.r
PASSED: [[SimpleTest]]: [MySQL] 41,484 pass(es).
[ View ]
#498 1081266-498.patch22.65 KBstefan.r
PASSED: [[SimpleTest]]: [MySQL] 41,486 pass(es).
[ View ]
#498 interdiff-496-498.txt5.9 KBstefan.r
#496 1081266-496.patch20.94 KBstefan.r
PASSED: [[SimpleTest]]: [MySQL] 41,483 pass(es).
[ View ]
#496 interdiff-492-496.txt887 bytesstefan.r
#492 1081266-492.patch20.94 KBstefan.r
PASSED: [[SimpleTest]]: [MySQL] 41,488 pass(es).
[ View ]
#492 interdiff-491-492.txt1.03 KBstefan.r
#491 1081266-491.patch20.94 KBstefan.r
PASSED: [[SimpleTest]]: [MySQL] 41,491 pass(es).
[ View ]
#491 interdiff-483-491.txt3.08 KBstefan.r
#483 interdiff-481-483.txt3.32 KBstefan.r
#483 1081266-483.patch19.92 KBstefan.r
PASSED: [[SimpleTest]]: [MySQL] 41,488 pass(es).
[ View ]
#480 interdiff-480-481.txt2.03 KBstefan.r
#480 1081266-481.patch19.73 KBstefan.r
PASSED: [[SimpleTest]]: [MySQL] 41,488 pass(es).
[ View ]
#479 1081266-480.patch19.78 KBstefan.r
PASSED: [[SimpleTest]]: [MySQL] 41,480 pass(es).
[ View ]
#479 interdiff-479-480.txt9.83 KBstefan.r
#478 interdiff-478-479.txt4.38 KBstefan.r
#478 1081266-479.patch19.09 KBstefan.r
PASSED: [[SimpleTest]]: [MySQL] 41,482 pass(es).
[ View ]
#475 1081266-478.patch19.9 KBstefan.r
PASSED: [[SimpleTest]]: [MySQL] 41,488 pass(es).
[ View ]
#475 interdiff-456-478.txt21.68 KBstefan.r
#456 1081266-456.patch15.89 KBstefan.r
PASSED: [[SimpleTest]]: [MySQL] 41,487 pass(es).
[ View ]
#456 interdiff-453-456.txt786 bytesstefan.r
#453 interdiff-452-453.txt2.23 KBstefan.r
#453 1081266-453.patch15.79 KBstefan.r
PASSED: [[SimpleTest]]: [MySQL] 41,501 pass(es).
[ View ]
#452 interdiff-449-452.txt9.34 KBstefan.r
#452 1081266-452.patch15.44 KBstefan.r
PASSED: [[SimpleTest]]: [MySQL] 41,492 pass(es).
[ View ]
#449 interdiff-437-449.txt5.7 KBstefan.r
#449 interdiff-445-449.txt3.06 KBstefan.r
#449 1081266-449.patch12.27 KBstefan.r
PASSED: [[SimpleTest]]: [MySQL] 41,483 pass(es).
[ View ]
#445 1081266-445.patch12.09 KBstefan.r
FAILED: [[SimpleTest]]: [MySQL] 41,493 pass(es), 1 fail(s), and 0 exception(s).
[ View ]
#445 interdiff-444-445.txt2 KBstefan.r
#444 interdiff-437-444.txt4.04 KBstefan.r
#444 1081266-444.patch11.59 KBstefan.r
FAILED: [[SimpleTest]]: [MySQL] 41,486 pass(es), 1 fail(s), and 0 exception(s).
[ View ]
#437 interdiff-425-437.txt9.13 KBstefan.r
#437 1081266-437.patch8.24 KBstefan.r
PASSED: [[SimpleTest]]: [MySQL] 41,491 pass(es).
[ View ]
#436 interdiff-425-436.txt7.34 KBstefan.r
#436 1081266-436.patch8.12 KBstefan.r
PASSED: [[SimpleTest]]: [MySQL] 41,477 pass(es).
[ View ]
#425 1081266-425.patch7.52 KBjeroen.b
PASSED: [[SimpleTest]]: [MySQL] 41,488 pass(es).
[ View ]
#425 interdiff-1081266-419-425.txt2.15 KBjeroen.b
#419 1081266-419.patch7.5 KBjeroen.b
PASSED: [[SimpleTest]]: [MySQL] 41,487 pass(es).
[ View ]

Comments

catch’s picture

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.

mfb’s picture

Disabling modules would not address this issue. system_status() calls drupal_load_updates() which calls drupal_get_installed_schema_version() which loads everything of type module from the system table, regardless of status. module_load_install() is called as long as the schema version is 0 or higher, even if the module is disabled.

sun’s picture

Status:Needs review» Needs work
+++ 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.

mfb’s picture

Status:Needs work» Needs review
StatusFileSize
new2.37 KB
FAILED: [[SimpleTest]]: [MySQL] Unable to apply patch 1081266-drupal_get_filename-D7.patch. Unable to apply patch. See the log in the details link for more information.
[ View ]

OK changed to $dirs and moved that line (hope $dirs variable is ok coding standards wise).

sun’s picture

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.

sun’s picture

mfb’s picture

$dir should be one of themes, themes/engines, modules, profiles and $extension should be one of info, engine, module, profile. But I don't think there'd be any problem if $dir == $extension.

As mentioned in #2, this code is running for all modules, disabled and enabled, so disabling missing modules wouldn't help here.

Damien Tournoud’s picture

Version:7.x-dev» 8.x-dev
Issue tags:+needs backport to D7
mfb’s picture

StatusFileSize
new1.99 KB
PASSED: [[SimpleTest]]: [MySQL] 29,486 pass(es).
[ View ]

Here's the D8 version.

Peter Bex’s picture

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

mfb’s picture

hopefully "+1" means you reviewed the patch? it's not totally clear :)

Peter Bex’s picture

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

das-peter’s picture

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

mfb’s picture

Related, but this is a higher-level fix to add (more) static caching to drupal_get_filename() so as to avoid unnecessary calls to drupal_system_listing() altogether.

Mark Theunissen’s picture

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.

mfb’s picture

Hmm #733308: Add static caching for drupal_system_listing() seems like redundant static caching of a large array, when drupal_get_filename() already has a static cache of $files found via drupal_system_listing()?

corbacho’s picture

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.

corbacho’s picture

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.

mfb’s picture

You might want to figure out why the scan is happening on every page load. Theoretically it should only happen on certain paths, such as admin/config which calls system_status().

MaxWesten’s picture

#4 is a drastic speed improvement.

Kars-T’s picture

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

Kars-T’s picture

Status:Needs review» Reviewed & tested by the community

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.

das-peter’s picture

+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.

webchick’s picture

Assigned:Unassigned» catch

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

alanburke’s picture

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

catch’s picture

Status:Reviewed & tested by the community» Needs review
Issue tags:+Needs profiling

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.

Kars-T’s picture

Status:Needs review» Reviewed & tested by the community
StatusFileSize
new40.7 KB
new35.19 KB
new43.2 KB
new54.12 KB

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.
Default

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

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

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

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.

catch’s picture

Status:Reviewed & tested by the community» Needs work

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’s picture

@catch: since drupal_get_filename() already has a static cache of $files found via drupal_system_listing(), are you suggesting moving the static cache from drupal_get_filename() to drupal_system_listing()?

catch’s picture

@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.

Kars-T’s picture

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

klausi’s picture

Priority:Normal» Critical
Status:Needs work» Needs review

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

Kars-T’s picture

Status:Needs review» Reviewed & tested by the community

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.

Dries’s picture

Priority:Critical» Normal
Status:Reviewed & tested by the community» Needs work

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.

das-peter’s picture

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?

Kars-T’s picture

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.

flock’s picture

Version:8.x-dev» 7.x-dev

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

oriol_e9g’s picture

Version:7.x-dev» 8.x-dev

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.

bmateus’s picture

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.

klausi’s picture

Tor Arne Thune’s picture

bensnyder’s picture

Priority:Normal» Major
onelittleant’s picture

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

onelittleant’s picture

Priority:Major» Normal

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

emcniece’s picture

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):

<?php
 $ctest
= 0;
?>

and then threw at the bottom of file_scan_directory():

<?php
 
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?

catch’s picture

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.

emcniece’s picture

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:

<?php
    $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?

catch’s picture

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.

emcniece’s picture

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.

sertaconay’s picture

Status:Needs work» Needs review

drupal_get_filename.patch queued for re-testing.

ExTexan’s picture

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?

mikeytown2’s picture

Version:8.x-dev» 7.x-dev
StatusFileSize
new1.75 KB
PASSED: [[SimpleTest]]: [MySQL] 39,062 pass(es).
[ View ]

@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.

DerekL’s picture

Wow.

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

You all deserve beers, thanks.

mikeytown2’s picture

Version:7.x-dev» 8.x-dev
StatusFileSize
new1.77 KB
FAILED: [[SimpleTest]]: [MySQL] Drupal installation failed.
[ View ]

Patch for D8 that should fix this issue as well.

mikeytown2’s picture

Status:Needs work» Needs review
StatusFileSize
new1.79 KB
FAILED: [[SimpleTest]]: [MySQL] 36,999 pass(es), 0 fail(s), and 130 exception(s).
[ View ]

Using the D8 caching interface now :)

mikeytown2’s picture

StatusFileSize
new1.78 KB
PASSED: [[SimpleTest]]: [MySQL] 36,983 pass(es).
[ View ]

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.

aspilicious’s picture

#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.

mikeytown2’s picture

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?

tsphethean’s picture

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.

tsphethean’s picture

StatusFileSize
new7.1 KB
FAILED: [[SimpleTest]]: [MySQL] Failed to run tests: PHP Fatal error encountered during run_tests.sh. See review log for details..
[ View ]

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.

tsphethean’s picture

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)

tsphethean’s picture

Status:Needs work» Needs review
Issue tags:-Performance, -needs backport to D7, -Needs profiling
tsphethean’s picture

StatusFileSize
new7.09 KB
FAILED: [[SimpleTest]]: [MySQL] 40,038 pass(es), 97 fail(s), and 82 exception(s).
[ View ]

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.

tsphethean’s picture

Status:Needs work» Needs review
tsphethean’s picture

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

tsphethean’s picture

Status:Needs work» Needs review
StatusFileSize
new7.24 KB
Test request sent.
Previous result: FAILED: [[SimpleTest]]: [MySQL] 40,161 pass(es), 97 fail(s), and 82 exception(s).
[ View ]

Updated patch - passes tests locally.

disasm’s picture

corbacho’s picture

andypost’s picture

Spleshka’s picture

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.

mikeytown2’s picture

Issue tags:-needs backport to D7

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

Spleshka’s picture

D7 patch looks good to me too.

mgifford’s picture

Status:Needs work» Needs review
mgifford’s picture

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.

tsphethean’s picture

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

tsphethean’s picture

StatusFileSize
new7.09 KB
FAILED: [[SimpleTest]]: [MySQL] Unable to apply patch drupal_get_filename_cache-1081266-93.patch. Unable to apply patch. See the log in the details link for more information.
[ View ]

Trying a re-roll against latest D8 build.

tsphethean’s picture

StatusFileSize
new7.09 KB
FAILED: [[SimpleTest]]: [MySQL] Unable to apply patch drupal_get_filename_cache-1081266-95.patch. Unable to apply patch. See the log in the details link for more information.
[ View ]

Fixing whitespace issue which prevented patch applying.

tsphethean’s picture

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

tsphethean’s picture

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 :-)

beejeebus’s picture

Anonymous’s picture

Output of dry-run 1081266-58-drupal_get_filename-D7.patch on Drupal 7.18

patch --dry-run < bootstrap.patch
patching file bootstrap.inc
Hunk #1 succeeded at 816 (offset -27 lines).
Hunk #2 succeeded at 867 (offset -27 lines).
patch unexpectedly ends in middle of line
Hunk #3 succeeded at 895 with fuzz 1 (offset -27 lines).

mikeytown2’s picture

StatusFileSize
new1.75 KB
PASSED: [[SimpleTest]]: [MySQL] 39,617 pass(es).
[ View ]

Re-roll of #58 against the latest D7 dev

mikeytown2’s picture

Version:8.x-dev» 7.x-dev
Status:Needs work» Needs review

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

mikeytown2’s picture

Version:7.x-dev» 8.x-dev
Status:Needs review» Needs work

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

Anonymous’s picture

patch --dry-run < bootstrap.patch
patching file bootstrap.inc
Hunk #1 succeeded at 816 (offset 1 line).
Hunk #2 succeeded at 867 (offset 1 line).
patch unexpectedly ends in middle of line
Hunk #3 succeeded at 895 with fuzz 1 (offset 1 line).

After that, used TextWrangler to ´normalize´ line endings, same result.

mikeytown2’s picture

@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
Anonymous’s picture

@Mikeytown2

Thanks for your support!

After reading what the option does, I´ve looked inside the file and - please correct me if I´m getting this wrong - I see that patch will be looking at

a/includes/bootstrap.inc
b/includes/bootstrap.inc

Patch documentation reads:

For all pathnames in the patch file that indicate the names of files to be patched, delete num pathname components from the beginning of each pathname. If the pathname in the patch file is absolute, any leading slashes shall be considered the first component (that is, -p 1 shall remove the leading slashes). Specifying -p 0 shall cause the full pathname to be used. If -p is not specified, only the basename (the final pathname component) shall be used.

So, NUM would be 3.

Omitting -p should result in patch using the final component and since I run patch in the same directory, that should work.

I tried p0 up to p4 and get the same result every time, so... I am not to sure about your suggestion.

But, always eager to learn, so please enlighten me if I don´t know what I am doing:-)

Merry Xmas!

Update:

After reading my own comment, decided to test the procedure by creating the directories and try to apply the patch from their mutual parent.
Failed.

Lukas von Blarer’s picture

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!

PlayfulWolf’s picture

Is this patch already applied on last D7?

mikeytown2’s picture

@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.

mikeytown2’s picture

Issue summary:View changes

Created an issue summary.

nbourdial’s picture

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 !

oriol_e9g’s picture

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?

<?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;
}
?>
nicholas.alipaz’s picture

Issue summary:View changes

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.

mikeytown2’s picture

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

ChristophWeber’s picture

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.

mikeytown2’s picture

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

marcelovani’s picture

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

jeroen.b’s picture

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

mikeytown2’s picture

#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.

jeroen.b’s picture

StatusFileSize
new2.89 KB
FAILED: [[SimpleTest]]: [PHP 5.4 MySQL] 81,956 pass(es), 2 fail(s), and 1 exception(s).
[ View ]

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.

jeroen.b’s picture

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

mikeytown2’s picture

Status:Needs work» Needs review
StatusFileSize
new4.12 KB
FAILED: [[SimpleTest]]: [PHP 5.4 MySQL] 81,957 pass(es), 1 fail(s), and 0 exception(s).
[ View ]

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

mikeytown2’s picture

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.

mikeytown2’s picture

StatusFileSize
new5.32 KB
PASSED: [[SimpleTest]]: [PHP 5.4 MySQL] 81,994 pass(es).
[ View ]

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...

jeroen.b’s picture

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.

mikeytown2’s picture

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.

mikeytown2’s picture

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.

mikeytown2’s picture

StatusFileSize
new5.54 KB
PASSED: [[SimpleTest]]: [PHP 5.4 MySQL] 82,037 pass(es).
[ View ]

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

beejeebus’s picture

passing NULL/FALSE/'' to method_exists is safe, so this:

<?php
+      if (!empty($cache_object) && is_object($cache_object) && method_exists($cache_object, 'get')) {
?>

can be shortened to:

<?php
+      if (method_exists($cache_object, 'get')) {
?>

this check:

<?php
+    if (empty($bad)) {
?>

will be true over and over again there's no data in $cache_object->get('drupal_get_filename:bad', TRUE);, which doesn't seem to fit the intention of the static. better to initialize the static as $bad as NULL, and check for is_null.

marcelovani’s picture

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.

jeroen.b’s picture

StatusFileSize
new5.39 KB
PASSED: [[SimpleTest]]: [PHP 5.4 MySQL] 82,039 pass(es).
[ View ]

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?

jeroen.b’s picture

StatusFileSize
new1.8 KB
FAILED: [[SimpleTest]]: [PHP 5.4 MySQL] Unable to apply patch drupal-1081266-138-drupal_get_filename-D7.patch. Unable to apply patch. See the log in the details link for more information.
[ View ]

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

jeroen.b’s picture

Version:8.0.x-dev» 7.x-dev
jeroen.b’s picture

Version:7.x-dev» 8.0.x-dev

D7 patch passed, so back to D8

jeroen.b’s picture

Priority:Normal» Major

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.

mikeytown2’s picture

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

askibinski’s picture

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

marcelovani’s picture

Status:Needs review» Reviewed & tested by the community

Lets get this committed, shall we?

jeroen.b’s picture

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

marcelovani’s picture

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

marcelovani’s picture

Status:Needs work» Reviewed & tested by the community
StatusFileSize
new5.39 KB
PASSED: [[SimpleTest]]: [PHP 5.4 MySQL] 82,441 pass(es).
[ View ]

Re-submitting the patch

swentel’s picture

Status:Reviewed & tested by the community» Needs work
Issue tags:+Needs tests

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.

Berdir’s picture

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?

oriol_e9g’s picture

+1000
See #112

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

joseph.olstad’s picture

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.

mikeytown2’s picture

Status:Needs work» Needs review
StatusFileSize
new3.75 KB
FAILED: [[SimpleTest]]: [PHP 5.4 MySQL] Invalid PHP syntax in core/includes/bootstrap.inc.
[ View ]

@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().

mikeytown2’s picture

Status:Needs work» Needs review
StatusFileSize
new3.76 KB
FAILED: [[SimpleTest]]: [PHP 5.4 MySQL] Invalid PHP syntax in core/includes/bootstrap.inc.
[ View ]

new patch with less php syntax errors™

mikeytown2’s picture

StatusFileSize
new3.76 KB
PASSED: [[SimpleTest]]: [PHP 5.4 MySQL] 82,539 pass(es).
[ View ]

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

mikeytown2’s picture

Title:Avoid re-scanning module directory when multiple modules are missing» Avoid re-scanning module directory when a module is missing
Status:Needs work» Needs review
jeroen.b’s picture

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.

jeroen.b’s picture

StatusFileSize
new3.78 KB
PASSED: [[SimpleTest]]: [PHP 5.4 MySQL] 84,136 pass(es).
[ View ]

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.

joelpittet’s picture

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.

jeroen.b’s picture

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

das-peter’s picture

@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.

joelpittet’s picture

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:)

joelpittet’s picture

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

joelpittet’s picture

@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]
jeroen.b’s picture

@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.

joelpittet’s picture

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

jeroen.b’s picture

StatusFileSize
new1.87 KB
FAILED: [[SimpleTest]]: [PHP 5.4 MySQL] Unable to apply patch drupal-1081266-171-drupal_get_filename-extra-debug-do-not-test-D7.patch. Unable to apply patch. See the log in the details link for more information.
[ View ]

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.

joelpittet’s picture

Issue summary:View changes
StatusFileSize
new198.21 KB

@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?

joelpittet’s picture

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.

jeroen.b’s picture

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?

joelpittet’s picture

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

joelpittet’s picture

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

joelpittet’s picture

joelpittet’s picture

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)

mikeytown2’s picture

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.

joelpittet’s picture

StatusFileSize
new225.58 KB

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

jeroen.b’s picture

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.

joelpittet’s picture

@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.

jeroen.b’s picture

@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()?

joelpittet’s picture

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.

jeroen.b’s picture

StatusFileSize
new5.44 KB
PASSED: [[SimpleTest]]: [PHP 5.4 MySQL] 87,309 pass(es).
[ View ]

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.

jeroen.b’s picture

I think these tags aren't relevant anymore

jeroen.b’s picture

StatusFileSize
new3.31 KB
PASSED: [[SimpleTest]]: [MySQL] 41,135 pass(es).
[ View ]

Here is a D7 patch with tests.

mikeytown2’s picture

Version:8.0.x-dev» 7.x-dev

changing to 7.x for testing

jeroen.b’s picture

Issue tags:-Needs tests

All green. Let's get this committed?

swentel’s picture

Version:7.x-dev» 8.0.x-dev
Assigned:Unassigned» swentel
Status:Needs review» Needs work

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.

jeroen.b’s picture

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.

mikeytown2’s picture

Assigned:swentel» Unassigned
joseph.olstad’s picture

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.

heyyo’s picture

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 ?

SocialNicheGuru’s picture

@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

heyyo’s picture

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

<?php
'path'    => drupal_get_path('module', 'mothership') .'/panelsstyles/motherstyle'
?>
joseph.olstad’s picture

StatusFileSize
new4.42 KB
PASSED: [[SimpleTest]]: [PHP 5.4 MySQL] 90,705 pass(es).
[ View ]

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.

joseph.olstad’s picture

Status:Needs work» Needs review

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.

David_Rothstein’s picture

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.

joseph.olstad’s picture

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

mikeytown2’s picture

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.

joseph.olstad’s picture

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.

joseph.olstad’s picture

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

David_Rothstein’s picture

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.)

jeroen.b’s picture

Replacing the watchdog with trigger_error() is fine with me. I'll see if I can update the patch soon.

I also agree with joseph.olstad here. Why don't we RTBC this and figure out #195 in another issue?
As in my opinion idea 1 (which I think is the way to go) from #195 requires a new discussion and it only addresses a small part (dirty system table) of what this patch addresses.

Fabianx’s picture

Status:Needs review» Reviewed & tested by the community

I am moving this back to RTBC, I think the cache is okay, because it can only get stale if you add a new module or move a module and then the module_implements cache is as much a problem as this cache.

stefan.r’s picture

Is the D7 patch in #189 in sync with the D8 patch, and equally RTBC, so both can be committed at the same time? Or does the D7 patch need work still?

jeroen.b’s picture

D7 and D8 patches are in sync, they contain the same fixes and tests.

Fabianx’s picture

#212 However 8.0.x needs to be committed first and then the D7 patch is discussed.

alexpott’s picture

Status:Reviewed & tested by the community» Needs work
+++ b/core/includes/bootstrap.inc
@@ -208,10 +208,23 @@ function config_get_config_directory($type = CONFIG_ACTIVE_DIRECTORY) {
+  // We use drupal static for the bad records so we can test it.
...
+    $drupal_static_fast['bad'] = &drupal_static(__FUNCTION__ . ':bad');

bad is a really odd name. How about missing or something more descriptive.

Also the issue summary needs a update since it says that we're only going to statically cache this but no we're putting it in cache_bootstrap too. Which like others before me I'm incredibly dubious of. If you move a module by mistake and break your site, it ends up in the cache, you quickly fix your mistake and then it is still not fixed until you obliterate all the caches. I'd prefer to be more conservative here and just implement the static cache.

jeroen.b’s picture

Yes, in that one example, the cache might be a bit of a struggle. However, in most other examples the cache will come in very handy as this function might be very heavy on every page load.

When I would do something like moving a module by mistake and then place it back, my first idea would be to drush rr and drush cc all...

joseph.olstad’s picture

Jeroen.b makes another valid point in #216 that re-iterates what I already described in #205. We have a high performance solution here that is very practical in realworld use, many have been using it in production (at least the D7 version) and is urgently needed for those that are unaware that they need it (because everyone running Drupal should have this fix). I'm not sure why we keep going back to needs work. 4 years of work, it's more than enough time. IMHO, there aren't enough valid reasons to redesign at this point something that is practical in the realworld as this is and guarantees that performance will not be affected by bone-head operations. Meanwhile admins will be aware of what is going on. All of this has been stated many times.

*everybody* using Drupal needed this 4 years ago when this issue was openned (or even 8 years ago when people didn't know the problem existed but they should have had this fix) and people still need this today and they'll need it tomorrow, those that don't have it should have it.

alexpott’s picture

Caching a cache miss - which is what we are doing is generally a really bad idea. That said perhaps it is an acceptable trade-off if we ignore or clear this cache when we list modules or themes. Or rebuild it on cron as suggested by @David_Rothstein in #209

And bad is still a bad name :)

Fabianx’s picture

At least in Drupal 7 we can use CACHE_TEMPORARY for clearing on cron and a low ttl (24 hours?) for Drupal 8 instead of CACHE_PERMANENT.

In addition to that clearing this when visiting the admin/modules page sounds good to me.

We used to rebuild block caches since ages when visiting the blocks page, so that makes sense.

#218

Caching cache-misses is strange, right, but not caching cache misses is kind of an anti pattern too.

Usually:

<?php
$cached
= cache_get('key');

if (
$cached) {
  return
$cached->data;
}

// rebuild $data
$data = complex_operation();

cache_set('key', $data);

return
$data;
?>

So every cache_get() should usually be followed by a cache_set, which includes setting empty values or FALSE.

That said, we can't store the information that the module is not there in the original modules files cache?

#217: Keep pushing with good focus (and address feedback) and it will get in - one day :). Most issues that have someone dedicated to them found their way into core eventually.

Issues like this stall only for years, because they are sitting waiting for review or feedback or ... And usually that is lack of "resources" rather than lack of interest.

joseph.olstad’s picture

Alexpott, you proposed two options: "ignore or clear this cache when we list modules or themes"
this seems like a reasonable option (to ignore the cache for that case, clearing it is really not necessary as Jereon.b and I have previously explained)

However : "Or rebuild it on cron as suggested by @David_Rothstein in #209"
I am less favourable of this option because cron is already very resource intensive and doesn't need more load.

with that said, I like even better the "acceptable tradeoff" as you stated that the current patch gives. Slam dunk this.

stefan.r’s picture

Status:Needs work» Needs review
StatusFileSize
new5.64 KB
new6.83 KB
PASSED: [[SimpleTest]]: [PHP 5.4 MySQL] 90,917 pass(es).
[ View ]

I concur with joseph.olstad about the importance of fixing this ASAP, and while I agree this is not an ideal implementation I quite like both suggestions in #219 as acceptable workarounds.

This path renames bad to missing and invalidates the missing file cache on cron runs as well as when visiting module/theme list pages.

stefan.r’s picture

Actually this patch doesn't clear the static cache so whoever visits the site right after a cron run may still be hit with a slowdown, correct?

I assume that if we have missing files, clearing up the static cache as well as the Drupal cache in the middle of a cron run will mean that we rebuild it further down that same cron run as there's likely new calls to drupal_get_filename()? Or should we clear the caches of the module/theme lists for that as well?).

I realize that load going up during cron runs is a concern, but that's what we can do a hook_requirements() thing for in a follow-up issue, and besides, I think it still beats giving significant load slowdowns to unlucky users visiting right after a cache clear :)

stefan.r’s picture

StatusFileSize
new7.01 KB
PASSED: [[SimpleTest]]: [PHP 5.4 MySQL] 90,919 pass(es).
[ View ]
new1.58 KB
stefan.r’s picture

So I assume this patch would also fix this performance regression listed in the 7.33 release notes?

There is a performance regression after updating to Drupal 7.33 on sites that have code which tries to load a file that doesn't exist - this can cause a file system scan every time the code is called. Finding and fixing the offending code is the best solution. See #2380361: Latest tweaks to bootstrap.inc can make Drupal sluggish when there is code that tries to load a file that doesn't exist for further details.

stefan.r’s picture

Created followup issue over at #2464601: Check for missing modules in hook_requirements so we can do both the caching fix as well as a hook_requirements fix as suggested by many in this issue.

Just wondering if checking the system table in D7 and checking system.module.files / system.theme.data in D8 is enough, or if these missing files can come from elsewhere as well? (in which case we may want to get a list of these files by checking the missing files cache)

joseph.olstad’s picture

ok, so Stefan.r played it safe and went with both recommendations by Alexpott. Good job.

Alexpott, please review this and commit it to D8 so we can agree on a backport to D7 and commit that too!

stefan.r’s picture

@joseph.olstad I had missed your comment over in #220.

I am fine with updating the patch so it merely ignores the cache on admin theme/module pages instead of invalidating it, if we can get a committer to sign off on that :)

Fabianx’s picture

Status:Needs review» Reviewed & tested by the community

As {system} is more a registry than a cache I am okay with the patch to catch misses, lets see what Alex says.

Invalidation is better than ignoring, else you wonder why the module page is correct, but your system still does not see the new module, which is worse DX. Invalidation on cron is also not costly.

#227: Please do not tell core committers what to do or not do. There is a lot of voluntary work in there as well and it borderline almost violates our code-of-conduct (not really, but please treat core committers as other fellow co-workers).

I know that the core process can be slow at times, but all recommendations by core committers are done for the whole good of the whole Drupal ecosystem!

I have seen both in Drupal as well as in client work, lines of code that have been 'very simple change', it is so obvious, etc.

And some of them have made quite big problems later. Trust me in the end following the process and getting through good peer review will make Drupal for all of us better in the end.

joseph.olstad’s picture

@Fabianx , invalidation has a performance cost, so it's not necessarily better than ignoring. Stefan.r sees the point in #227. See reasons outlined by Jereon.b in #216 and myself in #205.

I'm fine either way, prefer ignoring the cache to invalidation as I stated previously (because invalidation defeats the purpose of a cache and again for the same reasons already explained). But close enough.

jeroen.b’s picture

#225, yes, I think it's the same issue, maybe it should be marked as duplicate?
Also, what about the trigger_error() idea from #204? trigger_error() will make the error be catched by Drupal's error handler which is more advanced than just a watchdog call.

Rest of the patch in #223 looks fine to me.

stefan.r’s picture

Status:Reviewed & tested by the community» Needs work

Yes @David_Rothstein's suggestion makes sense, let me do a patch.

stefan.r’s picture

Status:Needs work» Needs review
StatusFileSize
new684 bytes
new6.96 KB
FAILED: [[SimpleTest]]: [PHP 5.4 MySQL] 90,964 pass(es), 0 fail(s), and 6 exception(s).
[ View ]

This adds the trigger_error().

stefan.r’s picture

OK so this test fails because we do things like this in the tests:

GetFilenameUnitTest.php:

<?php
   
// Searching for an item that does not exist returns NULL.
   
$this->assertNull(drupal_get_filename('module', uniqid("", TRUE)), 'Searching for an item that does not exist returns NULL.');
?>

AttachedAssetsTest.php

<?php
  $build
['#attached']['library'][] = 'unknown/unknown';
   
$assets = AttachedAssets::createFromRenderArray($build);

   
$this->assertIdentical([], $this->assetResolver->getJsAssets($assets, FALSE)[0], 'Unknown library was not added to the page.');
?>
Fabianx’s picture

  1. +++ b/core/includes/bootstrap.inc
    @@ -251,13 +264,24 @@ function drupal_get_filename($type, $name, $filename = NULL) {
    +      if (is_null($missing)) {

    We use !isset() instead of is_null() in core.

    See http://3v4l.org/11S72 - it works.

  2. +++ b/core/includes/bootstrap.inc
    @@ -251,13 +264,24 @@ function drupal_get_filename($type, $name, $filename = NULL) {
    +        if (\Drupal::hasService('cache.bootstrap')) {
    +          $cache = \Drupal::cache('bootstrap')->get('drupal_get_filename:missing', TRUE);
    +          if ($cache && $cache->data) {

    We don't want to use , TRUE here as we don't deal with invalid data.

  3. +++ b/core/includes/bootstrap.inc
    @@ -265,6 +289,16 @@ function drupal_get_filename($type, $name, $filename = NULL) {
    +      \Drupal::cache('bootstrap')->set('drupal_get_filename:missing', $missing, REQUEST_TIME);

    Third parameter should be omitted.

    Currently we cache this for < 1s, hence the need to use TRUE above ...

    Edit:

    Use REQUEST_TIME + 24 * 60 * 60

    to store this for 24 hours.

    It will then automatically be cleaned up by the next cron run.

  4. +++ b/core/modules/system/src/Controller/SystemController.php
    @@ -186,6 +186,12 @@ public function systemAdminMenuBlockPage() {
    +    //  Clean up the bootstrap "missing files" cache when listing themes.
    +    if (\Drupal::hasService('cache.bootstrap')) {
    +      \Drupal::cache('bootstrap')->invalidate('drupal_get_filename:missing');
    +      drupal_static_reset('drupal_get_filename:missing');
    +    }

    Should use ->delete() and no need to check for the service.

    I think we want to inject the cache.bootstrap service instead here, but that we can do once the rest of the patch is sound.

  5. +++ b/core/modules/system/src/Form/ModulesListForm.php
    @@ -174,6 +174,12 @@ public function buildForm(array $form, FormStateInterface $form_state) {
    +    //  Clean up the "missing files" cache when listing modules.
    +    if (\Drupal::hasService('cache.bootstrap')) {
    +      \Drupal::cache('bootstrap')->invalidate('drupal_get_filename:missing');
    +      drupal_static_reset('drupal_get_filename:missing');
    +    }

    Should use ->delete(), and this can rely on the cache.bootstrap being available already.

  6. +++ b/core/modules/system/system.module
    @@ -1201,6 +1201,12 @@ function system_cron() {
    +  if (\Drupal::hasService('cache.bootstrap')) {
    +    \Drupal::cache('bootstrap')->invalidate('drupal_get_filename:missing');
    +    drupal_static_reset('drupal_get_filename:missing');

    Should use ->delete() instead of ->invalidate().

    And yes, re-calculating system files once after each cron run is acceptable.

    That said I think we should let garbage collection do the job for us.

Here is a more extensive review.

Fabianx’s picture

#235: That is a unit test, which should probably be moved to its own method with @expectedException annotation present:

https://phpunit.de/manual/current/en/writing-tests-for-phpunit.html#writ...

stefan.r’s picture

Probably expectedExceptionMessage would be better as if I give the exception type to expectedException it will work like the "@" operator and hide all errors which would hurt the test. There's also 6 test fails and not all of those are PHPUnit tests...

For the other ones maybe we could temporarily set a different error handler which ignores "file not found" warnings?

E_USER_NOTICE still triggers exceptions on the testbot right?

Berdir’s picture

Those are kernel tests. phpunit tests could not be calling functions.

stefan.r’s picture

So currently I'm leaning toward setting set_error_handler() / restore_error_handler() before and after the problematic statements and filtering out file not found warnings...

<?php
 set_error_handler
(function($severity, $message, $file, $line) {
     
// Skip error handling if this is a "file not found" error.
     
if (!(error_reporting() & $severity) || strstr($message, 'is missing from the file system:')) {
        return;
      }
      throw new
ErrorException($message, 0, $severity, $file, $line);
    }


   
// Look for missing file

   
restore_error_handler();
?>
stefan.r’s picture

Status:Needs work» Needs review
StatusFileSize
new9.84 KB
FAILED: [[SimpleTest]]: [PHP 5.4 MySQL] Invalid PHP syntax in core/modules/system/src/Tests/Bootstrap/GetFilenameUnitTest.php.
[ View ]
new7.14 KB
stefan.r’s picture

Status:Needs work» Needs review
StatusFileSize
new11.8 KB
FAILED: [[SimpleTest]]: [PHP 5.4 MySQL] Invalid PHP syntax in core/modules/system/src/Controller/SystemController.php.
[ View ]
new3.56 KB
stefan.r’s picture

StatusFileSize
new11.88 KB
FAILED: [[SimpleTest]]: [PHP 5.4 MySQL] 90,717 pass(es), 201 fail(s), and 81 exception(s).
[ View ]

Missed a comma.

stefan.r’s picture

Status:Needs work» Needs review
stefan.r’s picture

Status:Needs work» Needs review
StatusFileSize
new11.91 KB
PASSED: [[SimpleTest]]: [PHP 5.4 MySQL] 90,981 pass(es).
[ View ]
new3.56 KB
stefan.r’s picture

Status:Needs work» Needs review

Queueing this for re-testing this to make sure this wasn't a fluke as I haven't seen the current test fail in MigrateFileTest with this patch before.

Also just to summarize for reviewers, in terms of changes to the last reviewed patch, this patch:

  • Fixes failing tests, where we remove nonexistent modules or set a custom error handler.
  • Cleans up code as per @Fabianx suggestions.
  • Sets an expiration of 24 hours on the "missing files" cache as suggested by @Fabianx. This means the cache ceases to explicitly clear during every cron run. Instead, it relies on garbage collection, as the cache will be invalidated once it's expired.

@Fabianx just to double check that this invalidation won't break anything, why did you ask to delete instead of invalidate the cache on the admin/theme pages? Won't an invalid cache mean just that when we try to do a get() the cache won't return anything (as $allow_invalid is now set to FALSE), and the cache will just be reset next time we try to do a cache_set(), or during garbage collection in cron?

Lastly, I may be wrong but I think ceasing to explicitly clean up the cache on every cron run also means that the cache will only be cleared once it's been fully built and all missing files have been found. This as any time a new missing file is found the expiration date is set further into the future. In the edge case of any code referring to a nonexisting file with a random file name, that could mean the cache never gets cleaned up. Is that something we can live with? If not, maybe we could set a fixed expiration date of 24 hours that doesn't get bumped further into the future every time the cache is updated?

stefan.r’s picture

StatusFileSize
new9.05 KB

OK this is green again.

joseph.olstad’s picture

Here's my test plan for D8:

1) install fresh with the patch
2) create a dummy module, enable it
3) remove the dummy module from the filesystem
4) check for expected results (error message)
5) if possible, performance profile

repeat same tests as above without patch

stefan.r’s picture

StatusFileSize
new11.94 KB
PASSED: [[SimpleTest]]: [PHP 5.4 MySQL] 90,982 pass(es).
[ View ]

So I discussed this with @Fabianx on IRC and apparently the concerns in #250 won't pose a problem. The last point would just need feedback from a core committer.

Just a tiny tweak to the last patch in the attachment:

+++ b/core/modules/system/src/Tests/Entity/EntitySchemaTest.php

@@ -28,7 +28,7 @@ class EntitySchemaTest extends EntityUnitTestBase  {
    *
    * @var array
    */
-  public static $modules = array('menu_link');
+  public static $modules = array('menu_link_content');

I'll just delete that altogether, looks like no extra modules are needed in that test anyway.

arosboro’s picture

Patch #189 helped me identify a missing module. Profiling reports a significant decrease in function calls and a savings of 2,000,000 microseconds. (Yes I'm testing a very slow site, but this patch made an improvement none the less)

joseph.olstad’s picture

My dev box is running off of a failover drive (like a human on one kidney) so I'll delay my D8 tests until I get the replacement drive up. I did some preliminary D8 tests but was right in the middle of this when I discovered a hardware problem. Keep up the good work Stefan.r .

jeroen.b’s picture

Just tested this on a fresh install from 8.0.x-dev with the patch from #254 and steps from #253, worked great.
Got the following message in WD:
<em class="placeholder">User warning</em>: The following module is missing from the file system: dummy in <em class="placeholder">drupal_get_filename()</em> (line <em class="placeholder">300</em> of <em class="placeholder">/home/vhosts/jeroen/drupal/d8-patch/core/includes/bootstrap.inc</em>).

stefan.r’s picture

StatusFileSize
new9.3 KB

Interdiff with last RTBC'ed patch for reviewers

Wim Leers’s picture

Assigned:Unassigned» Fabianx
Status:Needs review» Needs work

Only nitpicks. I think it'd be better if e.g. Fabianx reviews this. Assigning.

  1. +++ b/core/includes/bootstrap.inc
    @@ -208,10 +208,23 @@ function config_get_config_directory($type = CONFIG_ACTIVE_DIRECTORY) {
    +  // We use drupal static for the missing records so we can test it.

    s/drupal static/drupal_static()/

  2. +++ b/core/includes/bootstrap.inc
    @@ -208,10 +208,23 @@ function config_get_config_directory($type = CONFIG_ACTIVE_DIRECTORY) {
    +  // Drupal static fast pattern is used as this function may be called often.

    s/Drupal static fast/The drupal_static_fast()/

  3. +++ b/core/modules/system/src/Tests/Bootstrap/GetFilenameUnitTest.php
    @@ -70,7 +70,26 @@ function testDrupalGetFilename() {
    +    // Generate a non-existing module name.
    +    $non_existing_module = uniqid("", TRUE);

    Creative :D

  4. +++ b/core/modules/system/src/Tests/Bootstrap/GetFilenameUnitTest.php
    @@ -70,7 +70,26 @@ function testDrupalGetFilename() {
    +    // Get the missing records static from drupal_get_filename.
    ...
    +    $this->assertTrue($missing['module'][$non_existing_module], 'Searching for an item that does not exist creates a static record in drupal_get_filename.');

    s/drupal_get_filename/drupal_get_filename()/

  5. +++ b/core/modules/system/src/Tests/Bootstrap/GetFilenameUnitTest.php
    @@ -70,7 +70,26 @@ function testDrupalGetFilename() {
    +    // Searching for an item that does not exist creates a static record in drupal_get_filename.

    80 cols, and same remark as above.

Wim Leers’s picture

stefan.r’s picture

Status:Needs work» Needs review
StatusFileSize
new1.51 KB
new11.95 KB
PASSED: [[SimpleTest]]: [PHP 5.4 MySQL] 91,428 pass(es).
[ View ]
Fabianx’s picture

Status:Needs review» Needs work
  1. +++ b/core/modules/system/src/Tests/Common/AttachedAssetsTest.php
    @@ -74,10 +74,20 @@ function testDefault() {
    +    // Set a custom error handler so we can ignore the file not found error.
    +    set_error_handler(function($severity, $message, $file, $line) {
    ...
         $build['#attached']['library'][] = 'unknown/unknown';
         $assets = AttachedAssets::createFromRenderArray($build);
    ...
    +    // Restore the original error handler.
    +    restore_error_handler();

    This should be using an existing module, but a non-existing library.

    That would be a better test anyway and the error_handler handling should be removed here.

  2. +++ b/core/modules/system/src/Tests/Entity/EntitySchemaTest.php
    @@ -24,13 +24,6 @@ class EntitySchemaTest extends EntityUnitTestBase  {
    -   */
    -  public static $modules = array('menu_link');
    -

    It has been a while, so pardon if I re-ask this question:

    Why do we need to remove that line again?

  3. +++ b/core/modules/taxonomy/src/Tests/TermKernelTest.php
    @@ -23,7 +23,7 @@ class TermKernelTest extends KernelTestBase {
    -  public static $modules = array( 'filter', 'taxonomy', 'taxonomy_term', 'text', 'user' );
    +  public static $modules = array( 'filter', 'taxonomy', 'text', 'user' );

    Why do we remove that?

    Does that module not exist?

  4. +++ b/core/modules/views/src/Tests/Plugin/RowEntityTest.php
    @@ -24,7 +24,7 @@ class RowEntityTest extends ViewUnitTestBase {
    -  public static $modules = ['taxonomy', 'text', 'filter', 'field', 'entity', 'system', 'node', 'user'];
    +  public static $modules = ['taxonomy', 'text', 'filter', 'field', 'system', 'node', 'user'];

    Why do we remove that?

    Does that module not exist?

CNW for #1, the rest looks good. I assume core used some non-existing modules in tests. Is that right?

stefan.r’s picture

Status:Needs work» Needs review

re #2, #3, #4: those modules don't exist, so they trigger errors.

stefan.r’s picture

StatusFileSize
new1.16 KB
new11.5 KB
PASSED: [[SimpleTest]]: [PHP 5.4 MySQL] 91,695 pass(es).
[ View ]
stefan.r’s picture

Issue summary:View changes

Updated issue summary and added beta evaluation

stefan.r’s picture

Assigned:Fabianx» Unassigned
Fabianx’s picture

Status:Needs review» Reviewed & tested by the community

Setting to RTBC, this looks great to me now and really needs more feedback by a core committer now.

alexpott’s picture

Status:Reviewed & tested by the community» Needs review
+++ b/core/includes/bootstrap.inc
@@ -208,10 +208,23 @@ function config_get_config_directory($type = CONFIG_ACTIVE_DIRECTORY) {
+  // Return NULL right away if $type or $name is empty.
+  if (empty($type) || empty($name)) {
+    return NULL;
+  }

Should we be triggering an error here if this occurs. It strikes me that this is a bug too and that we'd want to report it.

stefan.r’s picture

I actually don't know that we need to be checking for that there, in any case it seems outside of the scope of this patch.

@joseph.olstad added it in #202 citing #2090115: Don't install a module when its default configuration has unmet dependencies as the reason but I don't really see how that would be passing empty values for those. Maybe he can clarify?

stefan.r’s picture

StatusFileSize
new551 bytes
new11.16 KB
FAILED: [[SimpleTest]]: [PHP 5.4 MySQL] 91,714 pass(es), 0 fail(s), and 799 exception(s).
[ View ]

Removing this for now, unless anyone can give any examples where $type/$name would actually be empty. Will ping @joseph.olstad for feedback.

The check would probably be better dealt with in a follow-up issue, along with fixing this at the source instead if there's actually any cases of core sending odd values for those.

stefan.r’s picture

Ah perfect, seems it already triggers an error anyway, as we have a bug in ExtensionInstallStorage::getAllFolders(), where we look for a file even if drupal_get_profile() == NULL:

<?php
     
if ($this->includeProfile) {
       
// The install profile can override module default configuration. We do
        // this by replacing the config file path from the module/theme with the
        // install profile version if there are any duplicates.
       
$profile_folders = $this->getComponentNames('profile', array(drupal_get_profile()));
       
$this->folders = $profile_folders + $this->folders;
      }
?>
stefan.r’s picture

Status:Needs work» Needs review
StatusFileSize
new12.17 KB
FAILED: [[SimpleTest]]: [PHP 5.4 MySQL] Invalid PHP syntax in core/lib/Drupal/Core/Config/ExtensionInstallStorage.php.
[ View ]
new907 bytes
stefan.r’s picture

Status:Needs work» Needs review
StatusFileSize
new363 bytes
new12.13 KB
FAILED: [[SimpleTest]]: [PHP 5.4 MySQL] 91,726 pass(es), 0 fail(s), and 730 exception(s).
[ View ]
stefan.r’s picture

Status:Needs work» Needs review
StatusFileSize
new1.23 KB
new13.47 KB
FAILED: [[SimpleTest]]: [PHP 5.4 MySQL] 91,705 pass(es), 0 fail(s), and 719 exception(s).
[ View ]

The piece of code in the interdiff doesn't really makes sense to me, why do we pass the type "module" if we're looking for a profile?

stefan.r’s picture

StatusFileSize
new1.48 KB
new13.77 KB
FAILED: [[SimpleTest]]: [PHP 5.4 MySQL] Invalid PHP syntax in core/lib/Drupal/Core/Config/ConfigInstaller.php.
[ View ]

Adding comment.

stefan.r’s picture

Status:Needs work» Needs review
StatusFileSize
new2.91 KB
new13.77 KB
FAILED: [[SimpleTest]]: [PHP 5.4 MySQL] 91,767 pass(es), 0 fail(s), and 11 exception(s).
[ View ]

In any case I don't think #281 is pertinent to this issue.

Opening #2476055: ConfigInstaller searches for profile overrides in module paths for that, let's stick to test failures here :)

stefan.r’s picture

Status:Needs work» Needs review
StatusFileSize
new1.24 KB
new15.23 KB
FAILED: [[SimpleTest]]: [PHP 5.4 MySQL] 91,759 pass(es), 0 fail(s), and 4 exception(s).
[ View ]
stefan.r’s picture

Status:Needs work» Needs review
StatusFileSize
new4.06 KB
new15.11 KB
PASSED: [[SimpleTest]]: [PHP 5.4 MySQL] 91,862 pass(es).
[ View ]

That took a few tries, let's see if this is green now :)

Interdiff is with the patch that was RTBC'ed in #266

joseph.olstad’s picture

@stefan.r
regarding comments #274, #273 and #272 and #202

I saw you made the spoken changes in #274, looks good to me. My refactoring in #202 kept a regression from #186 because of the flux upstream it was difficult to figure out what part of 186 should remain and what part should be refactored from core commit #40cc6312 for issue #2090115. I imagine that there's been other changes to the d8 dev branch since. Looks like that code snippet spoken of in comment #272 and #273 came in during patch #186 by jeroen.b #124 (see next comment) which may have actually come from another older core commit.

I see #289 passed testing, great work Stefan.r! Stefan.r I know you've done already a lot of work on this but can you please summarize the current status of #289 so everyone else can focus on what is the current status for the D8 patch? I've got a few ideas for test plans but just want to double confirm so that we're all on the same page.

jeroen.b’s picture

Indeed great work @stefan.r!
I think the code snippet from #272 was added in #124, not in #186.

stefan.r’s picture

The patch in 266 was RTBC and the concern was this NULL check, which I am fine with removing. It exposed a few test fails, which have been fixed in the latest patch.

As far as I'm concerned this is ready. Someone just needs to review the interdiff in #289 to make sure the test fail fixes are correct.

jeroen.b’s picture

I think it's good that the empty check was removed.
Returning null on an empty $name or $type is rather a workaround than a bugfix and such errors should be fixed at the source. (like you did)

Can't really tell if your fixes from the interdiff are correct so someone else should look at that.

stefan.r’s picture

Thanks for pointing out that the NULL check came from #124. That confirms it was just about a couple of test fails and should be safe to remove at this point.

@joseph.olstad I wouldn't worry too much about profiling this, the performance penalty is obvious at this point, the current patch doesn't differ functionality-wise from the previous RTBC patch (which had been profiled already).

alexpott’s picture

+++ b/core/lib/Drupal/Core/Config/ConfigInstaller.php
@@ -157,17 +157,23 @@ public function installDefaultConfig($type, $name) {
   public function installOptionalConfig(StorageInterface $storage = NULL, $dependency = []) {
+    $profile = $this->drupalGetProfile();
     if (!$storage) {
       // Search the install profile's optional configuration too.
       $storage = new ExtensionInstallStorage($this->getActiveStorages(StorageInterface::DEFAULT_COLLECTION), InstallStorage::CONFIG_OPTIONAL_DIRECTORY, StorageInterface::DEFAULT_COLLECTION, TRUE);
       // The extension install storage ensures that overrides are used.
       $profile_storage = NULL;
     }
-    else {
+    elseif (isset($profile)) {
       // Creates a profile storage to search for overrides.
-      $profile_install_path = $this->drupalGetPath('module', $this->drupalGetProfile()) . '/' . InstallStorage::CONFIG_OPTIONAL_DIRECTORY;
+      $profile_install_path = $this->drupalGetPath('module', $profile) . '/' . InstallStorage::CONFIG_OPTIONAL_DIRECTORY;
       $profile_storage = new FileStorage($profile_install_path, StorageInterface::DEFAULT_COLLECTION);
     }
+    else {
+      // Profile has not been set yet. For example during the first steps of the
+      // installer or during unit tests.
+      $profile_storage = NULL;
+    }

These changes surprise me - which tests fail for this?

stefan.r’s picture

@alexpott: removing the NULL check causes 799 exceptions altogether now that we have the trigger_error warning: https://qa.drupal.org/pifr/test/1031513

The piece of code you isolated (ConfigInstaller::installOptionalConfig()), makes about all of the tests listed in this other test run fail (other than the QuickEdit and CKEditor tests, which have separate fixes):
https://qa.drupal.org/pifr/test/1031653

stefan.r’s picture

Just to reiterate, we just need someone to review the interdiff in #289 in order to move this issue forward now :)

It's just a few test fixes to make sure we don't do unnecessary calls to drupal_get_filename() if we haven't set a theme/profile yet.

jeroen.b’s picture

Status:Needs review» Reviewed & tested by the community

Reviewed the fixes in the interdiff, looks good to me.
As the rest of the patch was RTBC before... RTBC for me.

catch’s picture

Status:Reviewed & tested by the community» Needs review

Hmm like David in #204 I'd also have just gone for the trigger_error() here. This is adding complexity for what is a very rare case, and the trigger_error() should mean the problem is found and fixed quickly.

jeroen.b’s picture

Status:Needs review» Reviewed & tested by the community

But we did go for the trigger_error():

trigger_error(SafeMarkup::format('The following @type is missing from the file system: @name', array('@type' => $type, '@name' => $name)), E_USER_WARNING);

catch’s picture

Status:Reviewed & tested by the community» Needs review

Yes, I'd have only done that.

stefan.r’s picture

@catch in #204 David Rothstein was suggesting to do the trigger_error on top of the caching, not just to "replace" it. (seems we may have misread, see @alexpott's comment in #218)

In D7 a missing/moved module is not such a rare case at all (hence the 92 followers on this issue). A trigger_error() by itself will mean the problem is found/fixed quickly on dev environments, but not so much on all the production environments out there, hence why we need the caching.

stefan.r’s picture

Just to add to this, I've actually run into this issue on at least 4 different Drupal installs. And version 7.34 may have introduced this issue in further installs per #2380361: Latest tweaks to bootstrap.inc can make Drupal sluggish when there is code that tries to load a file that doesn't exist. I'd be fine with a simple trigger_error() if we didn't do a filesystem scan when a module is missing, but this is causing a serious performance hit where I strongly doubt a simple trigger_error will make even half of sites with missing files clean up their stuff.

I think around #206 we had a similar argument about how in the real world typo's happen, bureaucracy exists, not everyone watches their logs, and not all sites are being actively developed anymore?

joseph.olstad’s picture

@stefan.r ya, my organisation has invested several million dollars into Drupal (three years straight of well paid Drupal consultants, consulting firms, several well paid full time staff dedicated to Drupal, infrastructure, management, support) and every single one of our sites was afflicted by "Drupal sluggish when there is code that tries to load a file that doesn't exist. ". We have sites that have relatively high loads and we need to squeeze every bit of performance we can out of Drupal. Had this performance fix already been in core we might have been able to get many millions more of business for Drupal. Thanks to Mikeytown2s' work we were able to bring in a lot of performance enhancements in the form of drupal core patches , it'd be nice to see this stuff already in core because performance becomes very important once your site scales up and you have higher loads and more and more complexity. Complexity is something we cannot avoid in this case. Either way it's going to be complicated, either we maintain core patches or maintain core it'self. We greatly appreciate your hard work stefan.r (and jereon.b and others here as well as mikeytown2 ), you've helped us with contrib modules, and now the great work here, keep up the great work. It is appreciated.

catch’s picture

Status:Needs review» Needs work

The fact there are existing production sites running 7.x where this is a problem and it silently does the scanning is a decent reason to do the caching in 7.x - on the assumption that some sites get a core update but no other monitoring.

However there are no such sites for 8.x, and I can't see a situation where you'd go from a working site to this issue, and the trigger_error() wouldn't be sufficient warning (unless you're randomly deleting folders on prod). So please upload an 8.x patch with just the trigger_error(), the backport can have the additional safeguards (assuming David's fine with that).

Fabianx’s picture

I talked with catch about this.

The outcome was:

For D7 especially the caching makes sense, it does make less sense for D8 as there are no production sites out there, yet.

If you delete a module from production that is still used you usually have other problems workflow, etc. wise than that the path is no longer found. Also there is no longer the option to disable a module in Drupal 8, but only to uninstall it, which you should definitely do, which also removes the entry.

And hopefully adding new modules either goes via a dev cycle so you see the errors and also in Drupal 8 that function should be way less used as it is all moving to classes.

It is great that the patch has found so many bugs in core though, which shows the usefulness of the trigger_error.

Therefore compromise:

- trigger_error for D8
- Caching + trigger_error for D7 (as we never warned before so its good to handle gracefully)

#304: In our profiling wetkit and the used stack (bean) etc. also had been performance bottle necks in itself and many issues. So the reason why you need many core performance patches is partially also because you use a rather 'inefficient' (or partially overly complex) setup to start. Also while mikeytown2's work is very very great, it is also important to note that some of it is still a little risky and e.g. for drupal.org the opposite approach (cache synchronization) instead of async-ness has been used.

Please also remember that we are a community, it is free software and we work on consensus approach. The best way to ensure getting an issue into core quickly is to work _with_ the core committers, not against them.

They usually have good reasons for their decisions and the best of the project in mind.

jeroen.b’s picture

I don't think anyone is working against the core committers here. We just didn't understand why we would leave caching out.
I see catch's point now and leaving the caching out only in D8 seems like a very good consensus to me.

Fabianx’s picture

Thought some more and I think instead of caching misses we should start for Drupal 8 to avoid the auto-healing in the first place. That also solves the performance issue as it would no longer scan the system as fallback, but just fail.

Already before we had the consensus in here once that if system misbehaves you just clear caches.

The auto-healing was meant to find moved modules, etc. without having to clear caches.

However as we have seen that approach is flawed and with class loader in Drupal 8 and caches on that front it is needed to clear caches afterwards or call /core/rebuild.php.

Note also:

The auto-healing never updates the actual cache, so in the case of a fallback system scan we do this fallback system scan again and again (without a trigger_error) until the cache is cleared finally.

So as we now finally found out this whole approach is flawed my new take (for Drupal 8) is:

- Remove the automatic system scan
- Use trigger_error instead always.

Be done with all cases.

Fabianx’s picture

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

Clarified title, this is not just about missing or moved modules.

catch’s picture

Yes +1 on removing the automatic scan altogether for 8.x, that would only be useful in the case that discovery hasn't run at all yet - and those cases we could fix individually rather than relying on multiple layers of fallback.

stefan.r’s picture

Yes this is a great solution, thanks so much Fabianx for staying on top of this.

The whole reason we need the caching magic is we have the file scan magic, happy to get rid of that for D8 :)

stefan.r’s picture

Status:Needs work» Needs review
StatusFileSize
new13.3 KB
FAILED: [[SimpleTest]]: [PHP 5.4 MySQL] Setup environment: Test cancelled by admin prior to completion.
[ View ]
new2.7 KB

This patch removes the filesystem scan and the caching for D8.

stefan.r’s picture

Note the information returned by the module handler / saved in state may be outdated and the file might have disappeared/moved in the mean time. Are we fine with that or should we check whether the file exists in drupal_get_filename()?

catch’s picture

We use include()/include_once() in most places in 8.x now after #752730: Remove file_exists() during bootstrap so no need for file_exists() - it'll error but shouldn't be fatal.

stefan.r’s picture

StatusFileSize
new9.34 KB
FAILED: [[SimpleTest]]: [PHP 5.4 MySQL] Setup environment: Test cancelled by admin prior to completion.
[ View ]
new3.79 KB
jeroen.b’s picture

Status:Needs work» Needs review
jeroen.b’s picture

Whoops, I noticed https://www.drupal.org/node/2480027 a little too late...

stefan.r’s picture

StatusFileSize
new18.96 KB
FAILED: [[SimpleTest]]: [PHP 5.4 MySQL] Failed to run tests: failed during invocation of run-tests.sh.
[ View ]
new9.75 KB

This required some refactoring and hackery, patch is not final but some feedback would still be good. Just to summarize the changes:

1. We do separate ExtensionDiscovery scans in ExtensionInstallStorage::getAllFolders(), InstallStorage::getAllFolders() and <code>drupal_check_profile().
2. As we can't know what the location of the system module is before having installed the system module, we hardcode it in install_drupal(). I realize it's ugly but this ought to be a stop-gap solution before we have a proper extension listing service.
3. We do a system_rebuild_module_data before installing the user module in the installer so we know where it's located. This is expensive so maybe we need to use solution (1) or (2) instead here.

stefan.r’s picture

Status:Needs work» Needs review
StatusFileSize
new19.25 KB
FAILED: [[SimpleTest]]: [PHP 5.4 MySQL] 53,495 pass(es), 7,561 fail(s), and 7,642 exception(s).
[ View ]
new10.04 KB
stefan.r’s picture

Status:Needs work» Needs review
StatusFileSize
new20.81 KB
FAILED: [[SimpleTest]]: [PHP 5.4 MySQL] Failed to run tests: failed during invocation of run-tests.sh.
[ View ]

KernelTestBase::enableModules() has a similar problem.

As a workaround, just to see if I can get the patch green I'll do another ExtensionDiscovery scan there :/

stefan.r’s picture

Still a few more failures to fix here:

Drupal\system\Tests\Bootstrap\GetFilenameUnitTest              3 passes   4 fails   4 exceptions
Drupal\config\Tests\ConfigDependencyTest                      79 passes             2 exceptions

Fatal error: Call to a member function getPath() on a non-object in /var/lib/drupaltestbot/sites/default/files/checkout/core/modules/simpletest/src/KernelTestBase.php on line 497
FATAL Drupal\system\Tests\Extension\ModuleHandlerTest: test runner returned a non-zero error code (255).

Drupal\system\Tests\Extension\ThemeHandlerTest                84 passes   4 fails   2 exceptions
Drupal\system\Tests\File\RemoteFileScanDirectoryTest          18 passes  17 fails  16 exceptions
Drupal\system\Tests\File\ScanDirectoryTest                    18 passes  17 fails  16 exceptions
Drupal\system\Tests\Installer\InstallerLanguageTest            1 passes   3 fails   1 exceptions

Fatal error: Call to undefined function Drupal\system\Tests\Path\system_schema() in /var/lib/drupaltestbot/sites/default/files/checkout/core/modules/system/src/Tests/Path/UrlAliasFixtures.php on line 84
FATAL Drupal\system\Tests\Path\AliasTest: test runner returned a non-zero error code (255).

stefan.r’s picture

Status:Needs work» Needs review
StatusFileSize
new26.92 KB
FAILED: [[SimpleTest]]: [PHP 5.4 MySQL] 91,889 pass(es), 3 fail(s), and 0 exception(s).
[ View ]
new6.04 KB
stefan.r’s picture

StatusFileSize
new22.99 KB
new27.79 KB
PASSED: [[SimpleTest]]: [PHP 5.4 MySQL] 91,896 pass(es).
[ View ]

This should be green now. Would be good to have some feedback on the attached interdiff with #312, and ideas on what to do with the GetFilenameUnitTest test now that we don't have the filescan anymore.

stefan.r’s picture

Status:Needs work» Needs review
stefan.r’s picture

Now that drupal_get_filename doesn't have the file scan anymore we'll need to change the testing strategy in the unit test for that function a bit (GetFileNameUnitTest). Just to describe the current logic:

  1. The path for the "core extension" is hardcoded
  2. Profiles are falsely exposed as modules
  3. We look in the static cache for any previously set values. These may have been primed elsewhere in core (ie. at the bottom of system_list())
  4. If nothing found and it's a module, get the path from ModuleHandler
  5. If still unknown, get from list in state prepared by system_rebuild_module_data and ThemeHandler::rebuildThemeData().
  6. Do a file scan (which this patch removes).

As to where values are saved:

  • The files state data for modules as well as the current profile is saved in system_rebuild_module_data()
  • The files state data for themes is saved in ThemHandler::rebuildThemeData()
  • The ModuleHandler list is set up by DrupalKernel from the the container.modules parameter.

In the current implementation, we can't scan for theme engines anymore as there's no listing available for them, so we can either build a way to retrieve a cached list for them, we do a file scan for or we drop support for them in drupal_get_filename() (which would be an API break).

The ugliness of this patch in a way exposes the need for an extension listing service, there was talk about this with some core committers on IRC but "this is such a tangled mess that it will confuse developers and may introduce bugs outside of core" and "this might possibly improve performance as we do less unnecessary rebuilds" are not really strong enough arguments here, so it's currently looking like a bit of a long shot to get the extension listing as envisioned by @sun in #2208429: Extension System, Part III: ExtensionList/ExtensionHandler into the beta.

stefan.r’s picture

stefan.r’s picture

StatusFileSize
new32.27 KB
PASSED: [[SimpleTest]]: [PHP 5.4 MySQL] 91,923 pass(es).
[ View ]
new6.09 KB

This addresses the comments in #333 by saving theme engines into state in the theme handler and scanning profiles before modules in _system_module_rebuild_info(), as well as various changes to GetFileNameUnitTest so it can deal with the lack of a file scan.

If this is green this just needs some feedback now from someone familiar with the extension system.

joseph.olstad’s picture

Head of D8 is broken, I couldn't run my test plan even when I did a hard reset to HEAD with no patches.

Modules aren't installing and cannot run a cache-rebuild without an error:

drush cache-rebuild

PHP Fatal error:  Class name must be a valid object or a string in
drupal/core/modules/field/src/FieldStorageConfigStorage.php on line 160

This isn't a problem with your patch, but a problem with HEAD of D8 dev.
I also tried Beta 10 and it also had similar problems.

*EDIT*
I reinstalled again from D8 head, without patching , but was still unable to install a module according to my test plan. @stefan.r do you have a test module you can share that works with recent commits of D8 ?

I'm testing using the migrate_plus module that was recently updated in April to work with D8 but it's not installing.

drush en migrate_plus
PHP Fatal error:  Class 'Drupal\taxonomy\Plugin\Field\FieldType\TaxonomyTermReferenceItem' not found in drupal/core/modules/field/src/FieldStorageConfigStorage.php on line 160

also, I see that the test failed for the patch, what commit were you developing from? it seems the rapid flux of D8 dev is putting a curv ball on development of this patch.
*END EDIT*

**DOUBLE EDIT**

retesting, double checking config

**END DOUBLE EDIT

** triple EDIT **
ok, configuratoin issue resolved, retesting
** end triple EDIT **

stefan.r’s picture

HEAD is fine according to https://qa.drupal.org/8.0.x-status, I think this is a testbot issue so I've queued the patch for re-testing.

joseph.olstad’s picture

ok, I applied your patch after installing HEAD
, should also test installing HEAD with patch (haven't yet)
here's what I noticed:

installed migrate_plus (some module from github)
removed it from the filesystem
ran a cache-rebuild
didn't notice anything

then ran drush updatedb

rm migrate_plus -rf
[joseph@srv1 contrib]$ drush cache-rebuild
Cache rebuild complete.                                                                                                                                                      [ok]
[joseph@srv1 contrib]$ drush updatedb
The following module is missing from the file system: migrate_plus bootstrap.inc:254                                                                                         [warning]
PHP Fatal error:  Call to a member function getPath() on a non-object in drupal/core/lib/Drupal/Core/Config/InstallStorage.php on line 226

Fatal error: Call to a member function getPath() on a non-object in drupal/core/lib/Drupal/Core/Config/InstallStorage.php on line 226
Drush command terminated abnormally due to an unrecoverable error.                                                                                                           [error]
Error: Call to a member function getPath() on a non-object in drupal/core/lib/Drupal/Core/Config/InstallStorage.php, line 226

I expected the message "The following module is missing from the file system: migrate_plus"

This is good

as for the getPath error:

related to these lines changed in InstallStorage.php

-  protected function getComponentFolder($type, $name) {
-    return drupal_get_path($type, $name) . '/' . $this->getCollectionDirectory();
+  protected function getComponentFolder(Extension $extension) {
+    return $extension->getPath() . '/' . $this->getCollectionDirectory();

Here`s where the problem is, however I'll let @stefan.r weigh in on this.

stefan.r’s picture

Yes, that's to be expected if the file is missing. It's an ugly errror that we'll need to fix :)

But the patch is green now, so before digging into details too much ideally I would first like some high level feedback from someone familiar with the extension system as to whether this is the right approach at all.

joseph.olstad’s picture

ok so that is expected behaviour?

what also happens now is the site no longer is functional. Trying to use the UI interface gives this error:

LogicException: A stray drupal_render() invocation with $is_root_call = TRUE is causing bubbling of attached assets to break. in Drupal\Core\Render\Renderer->doRender() (line 393 of core/lib/Drupal/Core/Render/Renderer.php).

*edit*
I guess paralysing the site is one way of dealing with missing files. Definately a change from D7.*edit*

joseph.olstad’s picture

If we could show an error to the interface (web site error message/warning) saying the same message that comes up in drush then that'd be more helpful.

So example: go to the site and you'd see something like: "error: The following module is missing from the file system: migrate_plus bootstrap.inc:254" then maybe the end user site admin might know what caused it.

I was sort of expecting what D7 would behave but yes things change, D7 was pretty forgiving when it came to moving modules around and having things appear and disappear. I understand however that there may be really good reasons for making changes in D8 and that the D8 core maintainers are busy with that.

stefan.r’s picture

StatusFileSize
new32.67 KB
PASSED: [[SimpleTest]]: [PHP 5.4 MySQL] 91,920 pass(es).
[ View ]
new4.29 KB

@joseph.olstad this should fix your issue.

Not saying it will fix your broken site (which may need a cache rebuild or similar), but it should prevent the getPath() error from appearing and breaking your site in the first place :)

joseph.olstad’s picture

ok, patch 344 fixed the broken site problem. I'll do a few more tests maybe in a few days. Got some young sick kids to take care of, signing out.

joseph.olstad’s picture

Status:Needs work» Needs review

lets trigger the test bot

stefan.r’s picture

StatusFileSize
new3.76 KB
new32.53 KB
PASSED: [[SimpleTest]]: [PHP 5.4 MySQL] 91,930 pass(es).
[ View ]

nitpicks

dawehner’s picture

  1. +++ b/core/lib/Drupal/Core/Config/InstallStorage.php
    @@ -196,18 +197,45 @@ public function getComponentNames($type, array $list) {
    +  public function getCoreNames() {

    I think we should document why we can't use the extension discovery

  2. +++ b/core/lib/Drupal/Core/Config/InstallStorage.php
    @@ -196,18 +197,45 @@ public function getComponentNames($type, array $list) {
    +      $files = new \GlobIterator(DRUPAL_ROOT . '/' . $directory . '/*' . $extension);

    Can't we at least use \Drupal::root() at some point here?

  3. +++ b/core/modules/simpletest/src/KernelTestBase.php
    @@ -483,6 +484,10 @@ protected function installEntitySchema($entity_type_id) {
    +    $listing = new ExtensionDiscovery(DRUPAL_ROOT);
    +    $module_list = $listing->scan('module');
    +    // In ModuleHandlerTest we pass in a profile as if it were a module.
    +    $module_list += $listing->scan('profile');

    @@ -492,7 +497,7 @@ protected function enableModules(array $modules) {
    -      $module_handler->addModule($module, drupal_get_path('module', $module));
    +      $module_handler->addModule($module, $module_list[$module]->getPath());

    This is kinda odd ... why can't we rely on drupal_get_path() here? Every new introduction of ExtensionDiscovery feels kinda wrong in this patch.

  4. +++ b/core/modules/system/system.module
    @@ -883,14 +883,19 @@ function system_get_info($type, $name = NULL) {
    +    // Prime drupal_get_filename() with the profile info file location.
    +    drupal_get_filename('profile', $profile, $profiles[$profile]->getPathname());

    Mh, so we couple those two methods together? Not sure whether this is really the right thing to do regarding stability.

stefan.r’s picture

@dawehner thanks, as to 3 and 4: I agree they are ugly as mentioned in #321/ #325, but we can't rely on drupal_get_path() there. #333 explains why; basically because we don't do a file scan anymore.

So we need to get their path some other way. Do you have any idea what to do there instead? I asked @catch for advice and he suggested priming the drupal_get_filename() cache, which we can only do if we actually know about the location, so for now I only saw a couple of ExtensionDiscoverys as a realistic way out without making too many changes elsewhere. Longer term we'd probably want to get rid of those though...

For instance in 3, as drupal_get_path() only works for the current profile, and in ModuleHandlerTest we pass on another profile to that function, we don't have any way to allow for that without making changes elsewhere.

As to 4, do you have any suggestion as to what to do there instead? The problem is, when we do a module scan we have to know about the profile location as it calls drupal_get_path({profile}) in ExtensionDiscovery::scan()/setProfileDirectoriesFromSettings().

Also keep in mind, everywhere we do workarounds like these now, we used to do a file scan anyway :)

stefan.r’s picture

StatusFileSize
new3.98 KB
new33.3 KB
PASSED: [[SimpleTest]]: [PHP 5.4 MySQL] 92,189 pass(es).
[ View ]

This replaces the DRUPAL_ROOT usage in this patch by \Drupal::root() and documents the concern in point number 1 from @dawehner's comment.

As to the different workarounds used, I don't really see any way around those without significant re-work elsewhere -- which I would be all for, but for now we may have to live with this, unless core committers change their minds when they see to what extent we need workarounds when we get rid of the file scan.

I'll try to document the individual instances for every single workaround, but just to summarize for now, the reasoning used was:

a. If we know the physical location of the file, if possible skip the drupal_get_path() call altogether and just hardcode the location. Otherwise, if we can't get around the drupal_get_path() call, just prime the drupal_get_filename() static cache.
b. If the physical location of the file is unknown and system module is available, do a module rebuild.
c. If the physical location of the file is unknown and the system module is not available or we are in the middle of a rebuild, perform an ExtensionDiscovery scan.

stefan.r’s picture

Just to document all the individual changes that the removal of a file scan and the inability to get an extension listing required:

1. drupal_check_profile() @ core/includes/install.inc:
Performs an ExtensionDiscovery as this function is only called in the installer, when the system module is still unavailable and we don't yet know where all the modules are located. This way we prevent a call to drupal_get_filename() in module_load_install which would have needed a file scan.

2. install_begin_request() @ core/includes/install.core.inc:
Before installing the system module, primes the drupal_get_filename() static cache with the location of the system module as we know its exact location.

3. install_begin_request() @ core/includes/install.core.inc:
Before installing the user module, performs a module rebuild as the system module is now available. Before installing the user module, primes the drupal_get_filename() static cache with the location of the user module as we know its exact location.

4. InstallStorage/ExtensionInstallStorage::getAllFolders():
Performs an ExtensionDiscovery scan on themes/modules/profiles instead of relying on a drupal_get_filename() file scan in ExtensionDiscovery::getComponentFolder(), as this method is called during install where the system module is not yet available. This had been marked as a @todo anyway: "// @todo Refactor getComponentNames() to use the extension list directly." Note this also required a small change in TestInstallStorage.

5. system_get_info() @ system.module:
The order of the ExtensionDiscovery scans changes: we have to scan for profiles before being able to scan for modules, as a module scan requires knowing where the active profile is located (which we don't always do here). We save the result of this scan into the drupal_get_filename() static cache so we can use drupal_get_path() in ExtensionDiscovery::setProfileDirectoriesFromSettings()

As to the changes in tests:

- ConfigDependencyTest::testConfigEntityUninstall():
Performs a module rebuild as the system module is now available.

- KernelTestBase::enableModules():
Performs an ExtensionDiscovery scan as this function receives a profile that is not the current profile. We don't yet have a way to receive inactive profile information in an uncached way.

- GetFilenameUnitTest::testDrupalGetFilename():
Performs a module rebuild as the system module is available.

- ModuleHandlerTest::setUp():
Performs a module rebuild as the system module is available. Hardcodes the location of the testing and minimal profiles as these are known and shouldn't change.

- ThemeHandlerTest::testThemeInfoAlter():
Performs a module rebuild as we are looking to install a new module while the drupal_get_filename state data is still unavailable.

- ScanDirectoryTest::setUp()/testOptionKey() and InstallerLanguageTest::testInstallerTranslationFiles():
Hardcodes the location of the simpletest files directory as it is already known and shouldn't change.

- UrlAliasFixtures::sampleUrlAliases():
Primes the drupal_get_filename static cache as we are looking to install the system module here and its location is known and shouldn't change.

Tangentially related:

- ThemeHandler::rebuildThemeData():
Now caches theme engine data as well, as otherwise drupal_get_filename has no way to retrieve this information without a file scan.

stefan.r’s picture

StatusFileSize
new35.14 KB
PASSED: [[SimpleTest]]: [PHP 5.4 MySQL] 92,170 pass(es).
[ View ]
new35.14 KB
PASSED: [[SimpleTest]]: [PHP 5.4 MySQL] 92,177 pass(es).
[ View ]

This documents the individual workarounds in code as well.

stefan.r’s picture

StatusFileSize
new8.08 KB
catch’s picture

+++ b/core/includes/install.core.inc
@@ -1029,6 +1034,9 @@ function install_base_system(&$install_state) {
+  system_rebuild_module_data();

This could hard-code the user module location too - would save the full rebuild.

stefan.r’s picture

StatusFileSize
new36.45 KB
FAILED: [[SimpleTest]]: [PHP 5.4 MySQL] 26,761 pass(es), 982 fail(s), and 1,048 exception(s).
[ View ]
new10.07 KB
new33.54 KB

I pinged @catch for feedback and in terms of the overall approach this should be OK as all the workarounds are far from the critical path and there's only 5 of them in the actual code. Most are in tests.

A lot of this will need to be removed as part of the refactoring suggested in #2186491: [meta] D8 Extension System: Discovery/Listing/Info, so just to keep track of this we've settled on adding a @todo in all the affected spots, as opposed to adding a separate method.

I'm including an interdiff with the previously RTBC'ed patch in #289 for easier reviewing.

stefan.r’s picture

Issue summary:View changes
Status:Needs work» Needs review
StatusFileSize
new652 bytes
new36.41 KB
PASSED: [[SimpleTest]]: [PHP 5.4 MySQL] 92,252 pass(es).
[ View ]

Updating issue summary and removing a typo that I accidentally introduced in the previous patch.

stefan.r’s picture

StatusFileSize
new36.43 KB
FAILED: [[SimpleTest]]: [PHP 5.4 MySQL] 92,241 pass(es), 0 fail(s), and 10 exception(s).
[ View ]
new806 bytes

As to installing the user module in the installer, let's hardcode its location as well as @catch had suggested in #354.

Previously I had thought we could do the module rebuild there and could skip the other rebuild in the installer that was happening anyway, but this is less of a change in the logic and consistent with what we do with the system module.

stefan.r’s picture

Hmm, this test failure exposes the fact that any ExtensionDiscovery::scan() for a list of modules needs to be able to get the profile path from drupal_get_filename(), which is a problem if we haven't ever run system_module_rebuild().

We've already implemented a workaround for this in this patch in _system_rebuild_module_data(), and @dawehner indicated he didn't much like the coupling with drupal_get_path() that this introduces.

I see three ways out here:

a) Do the same workaround as in _system_rebuild_module_data() in ExtensionInstallStorage::getAllFolders() -- ie. do a profile scan before a module scan and save the location of the profile into the drupal_get_filename() static cache. Again, this introduces the same coupling @dawehner was worried about, but we're hopefully removing all this for #2186491: [meta] D8 Extension System: Discovery/Listing/Info anyway.

b) Keep the module rebuild right after installing the system module. The next module rebuild is in install_profile_modules() -- this data is only statically cached and we are looking for dependencies (which are not cached anywhere), so as this happens in another request we make the installer some 200 milliseconds slower :/

c) Refactor ExtensionDiscovery::scan() to lose the drupal_get_filename dependency -- maybe doing a recursive call to itself to figure out the location of the profile directory. This is a speed decrease on every module scan though, so probably the worst option out of the three. However it would remove the need for the workaround in _system_rebuild_module_data(), which could just remain as is.

As a) introduces the smallest performance hit, likely that's the "least worst" option?

stefan.r’s picture

Status:Needs work» Needs review
StatusFileSize
new36.97 KB
PASSED: [[SimpleTest]]: [PHP 5.4 MySQL] 92,265 pass(es).
[ View ]
new36.97 KB
PASSED: [[SimpleTest]]: [PHP 5.4 MySQL] 92,279 pass(es).
[ View ]

This is what #359.a) would look like...

stefan.r’s picture

StatusFileSize
new2.16 KB
stefan.r’s picture

StatusFileSize
new34.24 KB

Just FYI, I am finished working on this and this patch just needs further review now on the newly introduced changes since #289.

I am including with this comment an interdiff with the latest RTBC patch in #289.

Fabianx’s picture

Assigned:Unassigned» catch

Assigning to catch for review

stefan.r’s picture

Thanks, just sharing our little IRC conversation from 10 minutes ago here for everyone's information:

<stefan_r> Fabianx-screen: did you manage to have a look at the changes in the filescan issue yourself?
...
<Fabianx-screen> stefan_r: I was mostly fine with the changes.
<Fabianx-screen> stefan_r: I think its very verbose, but that just shows how much code did depend on kinda broken behavior.
<Fabianx-screen> stefan_r: That was quite a code smell. :)
<Fabianx-screen> stefan_r: Thanks also for the great interdiff, that was helpful from last RTBC.

Also tiny nits I found on final review, for future reference after @catch reviews:

  1. +++ b/core/includes/install.core.inc
    @@ -1029,6 +1035,11 @@ function install_base_system(&$install_state) {
    +  // Prime the drupal_get_filename() static cache with the user module's

    +++ b/core/lib/Drupal/Core/Extension/ExtensionDiscovery.php
    @@ -134,8 +134,9 @@ public function __construct($root) {
    +    // unless explicit profile directories have been set. Exclude profiles
    +    // as we can't have profiles within profiles.

    needs reflowing

  2. +++ b/core/lib/Drupal/Core/Config/ExtensionInstallStorage.php
    @@ -80,26 +81,57 @@ public function createCollection($collection) {
    +          // Prime the drupal_get_filename() static cache with the profile info file
    +          // location so we can use drupal_get_path() on the active profile during
    +          // the module scan.

    80 cols

  3. +++ b/core/modules/config/src/Tests/ConfigDependencyTest.php
    @@ -184,6 +184,10 @@ public function testConfigEntityUninstall() {
    +    // Perform a module rebuild so we can know where the node module is located.
    +    // and uninstall it.

    stray dot

  4. +++ b/core/modules/system/src/Tests/Extension/ModuleHandlerTest.php
    @@ -184,6 +197,11 @@ function testUninstallProfileDependency() {
    +    drupal_get_filename('profile', 'minimal', 'core/profiles/' . $profile . '/' . $profile . '.info.yml');

    +++ b/core/modules/system/src/Tests/File/ScanDirectoryTest.php
    @@ -28,7 +28,11 @@ class ScanDirectoryTest extends FileTestBase {
    +    // location from drupal_get_filename() in a cached way.

    s/'minimal'/$profile/

Pages