Currently file_scan_directory() call is taking the longest time in terms of Drupal bootstrap performance.

It may take 10-20 seconds on the standard environment just to scan the modules folder over and over again.

See: file_scan_directory() takes about 10 seconds to execute

On the environment with 750 .module files where memcached is present and opcache.enable_cli is enabled, this function may be called over 1500 times (via recursive calls).

See sample profiler stats by running empty command or enabling dummy module e.g. drush en "":

There are 2 calls:

- modules-/^[a-zA-Z_\x7f-\xff][a-zA-Z0-9_\x7f-\xff]*\.module$/-name
- sites/all/modules-/^[a-zA-Z_\x7f-\xff][a-zA-Z0-9_\x7f-\xff]*\.module$/-name

each of them generating 500-1000 calls (depending on the environment and number of modules) which can call PHP functions is_dir, readdir and opendir which are very expensive, since they're I/O calls, secondly they're not always cached, because Drupal uses relative paths, so most likely they're ignored by caching mechanism (like OPCache/APC).

During normal run, you're not expecting modifying module files, placing, removing or renaming files, mostly they're there fixed. The same way when you define some new hook or create template file, you're not expecting to see this file immediately, but it's obvious that you need to clear your caches first.

So idea is to cache the results of file_scan_directory() in order to speed up the bootstrap timings. With memcached it can speed up Drupal by 2x.

Here are the tests performed in VM (within mentioned environment above) before the patch:

1st run (cold run):

[vagrant@html]$ echo flush_all > /dev/tcp/localhost/11211
[vagrant@html]$ time drush ev ""
Drush bootstrap completed in 5s [Mem: 58 of 1024 MB]                                   
Drush operation 'page' completed in 5s. [Mem: 58 of 1024 MB]                           
Drush operation 'ev ' completed in 0s. [Mem: 58 of 1024 MB]                            

real	0m5.962s
user	0m1.858s
sys	0m2.032s
[vagrant@html]$ time drush en ""
Drush bootstrap completed in 5s [Mem: 58 of 1024 MB]                                   
There were no extensions that could be enabled.                                        
Drush operation 'page' completed in 17s. [Mem: 73 of 1024 MB]                          
Drush operation 'en ' completed in 0s. [Mem: 73 of 1024 MB]                            

real	0m17.357s
user	0m3.035s
sys	0m7.479s

2nd run (warm run):

[vagrant@html]$ time drush ev ""
Drush bootstrap completed in 3s [Mem: 26 of 1024 MB]                                   
Drush operation 'page' completed in 3s. [Mem: 26 of 1024 MB]                           
Drush operation 'ev ' completed in 0s. [Mem: 26 of 1024 MB]                            

real	0m3.486s
user	0m0.852s
sys	0m1.496s
[vagrant@html]$ time drush en ""
Drush bootstrap completed in 3s [Mem: 26 of 1024 MB]                                   
There were no extensions that could be enabled.                                        
Drush operation 'page' completed in 14s. [Mem: 41 of 1024 MB]                          
Drush operation 'en ' completed in 0s. [Mem: 41 of 1024 MB]                            

real	0m14.966s
user	0m2.282s
sys	0m6.782s

With the patch (warm):

[vagrant@html]$ time drush ev ""
Drush bootstrap completed in 3s [Mem: 26 of 1024 MB]                                   
Drush operation 'page' completed in 3s. [Mem: 26 of 1024 MB]                           
Drush operation 'ev ' completed in 0s. [Mem: 26 of 1024 MB]                            

real	0m3.208s
user	0m0.847s
sys	0m1.375s
[vagrant@html]$ time drush en ""
Drush bootstrap completed in 3s [Mem: 26 of 1024 MB]                                   
There were no extensions that could be enabled.                                        
Drush operation 'page' completed in 15s. [Mem: 41 of 1024 MB]                          
Drush operation 'en ' completed in 0s. [Mem: 41 of 1024 MB]                            

real	0m15.643s
user	0m2.262s
sys	0m6.975s
[vagrant@html]$ time drush en ""
Drush bootstrap completed in 3s [Mem: 26 of 1024 MB]                                   
There were no extensions that could be enabled.                                        
Drush operation 'page' completed in 7s. [Mem: 41 of 1024 MB]                           
Drush operation 'en ' completed in 0s. [Mem: 41 of 1024 MB]                            

real	0m8.025s
user	0m2.119s
sys	0m3.189s

During run two cached objects are 19488 & 153701 bytes long ( print("Len: " . strlen(serialize($files_to_add)) . "\n"); ).

Patch is probably not useful for running empty command, but there are some cases that this function is called quite often, e.g. on fra (reverting all the features via drush), where each revert invoking bootstrap takes 10-20 seconds, so for 200 features it may take over 2000 seconds (> 30 mins or even hours).

Comments

kenorb created an issue. See original summary.

kenorb’s picture

Issue summary: View changes
kenorb’s picture

Issue summary: View changes

Another test with 'cc all', with the patch:

[vagrant@html]$ time drush -y cc all
Drush bootstrap completed in 11s [Mem: 58 of 1024 MB]                                    
Cid: modules-/^[a-zA-Z_\x7f-\xff][a-zA-Z0-9_\x7f-\xff]*\.module$/-name-0
Cid: sites/all/modules-/^[a-zA-Z_\x7f-\xff][a-zA-Z0-9_\x7f-\xff]*\.module$/-name-0
Cid: themes-/^[a-zA-Z_\x7f-\xff][a-zA-Z0-9_\x7f-\xff]*\.info$/-name-1
Cid: sites/all/themes-/^[a-zA-Z_\x7f-\xff][a-zA-Z0-9_\x7f-\xff]*\.info$/-name-1
Cid: themes/engines-/^[a-zA-Z_\x7f-\xff][a-zA-Z0-9_\x7f-\xff]*\.engine$/-name-1
Cid: sites/all/themes/engines-/^[a-zA-Z_\x7f-\xff][a-zA-Z0-9_\x7f-\xff]*\.engine$/-name-1
'all' cache was cleared.                                                                 
Drush operation 'cc all' completed in 0s. [Mem: 208 of 1024 MB]                          
Drush operation 'page' completed in 51s. [Mem: 208 of 1024 MB]                           
Drush operation 'cc all' completed in 0s. [Mem: 208 of 1024 MB]                          

real	0m52.517s
user	0m21.447s
sys	0m13.537s

Without the patch:

[vagrant@html]$ time drush -y cc all
Drush bootstrap completed in 10s [Mem: 58 of 1024 MB]                                 
'all' cache was cleared.                                                              
Drush operation 'cc all' completed in 0s. [Mem: 209 of 1024 MB]                       
Drush operation 'page' completed in 64s. [Mem: 208 of 1024 MB]                        
Drush operation 'cc all' completed in 0s. [Mem: 208 of 1024 MB]                       

real	1m4.799s
user	0m24.863s
sys	0m16.392s

Which gives around 13 seconds difference as it seems the file_scan_directory was called 6 times during one 'cc all' command.

kenorb’s picture

StatusFileSize
new893 bytes

Re-uploading since tests didn't run.

Status: Needs review » Needs work

The last submitted patch, 4: file_scan_directory-caching-2710289.patch, failed testing.

kenorb’s picture

The CI build fails with:

08:32:53 Fatal error: Call to undefined function cache_get() in /var/www/html/includes/common.inc on line 5522

This is potential drush bug. Reported at: GH-2143 (PR: GH-2144).

Status: Needs work » Closed (outdated)

Automatically closed because Drupal 7 security and bugfix support has ended as of 5 January 2025. If the issue verifiably applies to later versions, please reopen with details and update the version.