UnitTestBase became very slow since #1608842: Replace list of bootstrap modules, enabled modules, enabled themes, and default theme with config.

Try to run this set on HEAD: (takes 12 secs for me)

Drupal\system\Tests\Plugin\DerivativeTest,Drupal\system\Tests\Plugin\DiscoveryTest,Drupal\system\Tests\Plugin\FactoryTest,Drupal\system\Tests\Plugin\InspectionTest

Further unit tests in core for running benchmarks can be found in this recent test failure.

Support from Acquia helps fund testing for Drupal Acquia logo

Comments

sun’s picture

I'd love if someone could confirm this - my local PHP version is old and I'm on Windows, so I'm not 100% sure that this actually applies to all setups.

sun’s picture

Assigned: Unassigned » sun
Status: Active » Needs review
FileSize
12.08 KB

Let's see how far we get with this.

Status: Needs review » Needs work

The last submitted patch, test.perf_.2.patch, failed testing.

sun’s picture

Status: Needs work » Needs review
FileSize
2.57 KB
13.71 KB
  1. Merged HEAD.
  2. Fixed drupal_get_filename() test.
sun’s picture

FileSize
53.3 KB
3.16 KB
15.47 KB
  1. Fixed 2,155 unnecessary calls into file_stream_wrapper_uri_normalize().
  2. Fixed drupal_system_listing() recurses into templates, css, and js directories.
  3. Fixed run-tests.sh bootstraps higher than it needs to.

The following cachegrind proves that the filesystem scans are the primary offender:

test-perf-5.png

The attached patch is all we can reasonably do for this issue.

The numbers for TestBase::setUp() and tearDown() are also concerning, but should be investigated and addressed in a separate issue.

The rest regarding filesystem scans needs to be done in #1808220: Remove run-tests.sh dependency on existing/installed parent site — that issue is the exact reason for why a too simple hack, as originally contained in the system config list conversion patch, does not work, because any assumption on a pre-installed/existing Drupal site is bogus.

Status: Needs review » Needs work

The last submitted patch, test.perf_.5.patch, failed testing.

sun’s picture

Status: Needs work » Needs review
FileSize
1.19 KB
15.7 KB

Fixed file_scan_directory() adds a third slash to files when scanning stream wrapper URI itself.

sun’s picture

FileSize
582 bytes
15.68 KB

Simplified trailing slash check.

Status: Needs review » Needs work
Issue tags: -Performance, -Testing system

The last submitted patch, test.perf_.8.patch, failed testing.

sun’s picture

Status: Needs work » Needs review

#8: test.perf_.8.patch queued for re-testing.

Status: Needs review » Needs work
Issue tags: +Performance, +Testing system

The last submitted patch, test.perf_.8.patch, failed testing.

Berdir’s picture

Status: Needs work » Needs review
+++ b/core/includes/bootstrap.inc
@@ -884,7 +884,7 @@ function drupal_get_filename($type, $name, $filename = NULL) {
-  if (!empty($filename) && file_exists($filename)) {
+  if (!empty($filename)) {
     $files[$type][$name] = $filename;
   }

Coudn't this cause troubles with removed modules and things like that? Or is that handled in the changed code below, haven't read that in detail.

+++ b/core/scripts/run-tests.sh
@@ -190,6 +190,7 @@ function simpletest_script_parse_args() {
+    'profile' => FALSE,
     'test_names' => array(),
     // Used internally.
     'test-id' => 0,
@@ -408,7 +409,11 @@ function simpletest_script_run_one_test($test_id, $test_class) {

@@ -408,7 +409,11 @@ function simpletest_script_run_one_test($test_id, $test_class) {
 function simpletest_script_command($test_id, $test_class) {
   global $args, $php;
 
-  $command = escapeshellarg($php) . ' ' . escapeshellarg('./core/scripts/' . $args['script']);
+  $command = escapeshellarg($php);
+  if ($args['profile']) {
+    $command .= ' -d xdebug.profiler_enable=On';
+  }

This looks useful, I've thought about this as well. Wondering if we should get it in as a separate issue, though, because we're for example missing documentation here.

sun’s picture

Thanks for your review!

1) The only case in which drupal_get_filename() would operate on a possibly non-existing filename is when system_list() primes drupal_get_filename() with previously recorded module and theme filepaths. However, we removed file_exists() all over core for D8 in the meantime, so if a previously known filename suddenly vanishes, then this missing file_exists() is certainly not the last that will blow up.

That said, off-hand I do not know whether we're supporting modules to be moved to different locations in D8 and how that would work (only update.php would be able to rebuild the system lists without fataling). We should probably create an issue for that, and potentially replace a couple of require_once calls in the critical path with include_once, so that you'd get PHP warnings, but would still be able to get past the WSOD in order to flush all caches.

2) Yes, we can certainly move the profiling parameter into a follow-up. It should probably renamed to --xdebug-profile, too, so as to leave room for alternatives. So yeah, separate issue. :)

Anyway, this param and webgrind (which is a zero-conf setup, just slap it somewhere) really is a great way to benchmark test runs.

catch’s picture

Just a note on file_exists(), there's #1715222: Remove almost all file_exists() and is_file() calls from core and #752730: Remove file_exists() during bootstrap so I'm fine with that being done (we might need to mark those as duplicate unless they're touching other areas). We already use include_once() in drupal_load(), so it's a non-fatal error there, but yeah it'd be good to check for require_once() in other situations.

Patch looks good so far.

sun’s picture

I think the patch is actually done already.

Sorry for not having attached profiling data for HEAD, but the short version is: The filesystem scan numbers were 2-3x larger.

The only possible remaining improvement would be to resolve the @todo I've added about skipping ./config directories, but without skipping the modules/config directory, since those ./config directories start to add up more and more and definitely presented a considerable amount of needless directory recursions in cowboy debugging tests, but I think this can be investigated in a follow-up patch/issue.

Lastly, I had to some more cowboy debugging in order to understand how the $depth argument actually works, so that's why I revamped and corrected the entire phpDoc for drupal_system_listing(). I was highly tempted to change the entire function signature; first and foremost to remove the DRUPAL_PHP_FUNCTION_PATTERN from all callers and just have $dir and $extension, and only optionally $min_depth and $key in there, but decided to do that in a separate follow-up issue, which I'll create once this patch has landed.

sun’s picture

FileSize
14.86 KB

Safety merge/re-roll against HEAD.

sun’s picture

#16: test.perf_.16.patch queued for re-testing.

Fabianx’s picture

Looks good, don't know it enough, else I would say its RTBC.

sun’s picture

Berdir’s picture

Same feedback as Fabianx, this looks ok, catch confirmed that removing the file_exists() there is fine. I don't really know that area well enough either to RTBC.

Some more notes/feedback:

I picked a random unit test that seems to be running fast and executed it a few times. These improvements are low-level and generic, it doesn't matter if we run different tests or repeat the same one.

$ php core/scripts/run-tests.sh --url http://d8/ --class "Drupal\system\Tests\Uuid\UuidUnitTest,Drupal\system\Tests\Uuid\UuidUnitTest,Drupal\system\Tests\Uuid\UuidUnitTest,Drupal\system\Tests\Uuid\UuidUnitTest,Drupal\system\Tests\Uuid\UuidUnitTest,Drupal\system\Tests\Uuid\UuidUnitTest,Drupal\system\Tests\Uuid\UuidUnitTest,Drupal\system\Tests\Uuid\UuidUnitTest,Drupal\system\Tests\Uuid\UuidUnitTest"

Execution time before the patch: 7s, with the patch, 3s. I tried running different tests and other tests too and while the improvements are always a bit different based on the actual execution time of the test, it always was a considerable improvement, especially considering that many of these improvements also apply to normal page requests, especially when simpletest.module is enabled.

So, possible remaining tasks:
- Maybe someone with a deep knowledge of drupal_system_listing() and drupal_get_filename() functions can sign this off?
- The problem with excluding config also indicates that it is no longer possible to have modules called lib, templates, css or js. js/css/templates exist in 6.x versions on d.o. Is that really ok? If so, we should document it somewhere (not necessarly in this issue/code, but somewhere)
- We should check the issues mentioned by catch if they're still relevant after this and if there are maybe any indications in the discussions there about things that could be included here as well or need to be done differently.
- EDIT: Also, we should confirm that it's possible to remove modules without completely breaking the site. This is something that happens quite frequently when working together on sites in a team/multiple environments. Idea: Mess with the stored filename of a module (we still store that somewhere, right?) to fake a deletion. Check what happens.

sun’s picture

FileSize
457 bytes
14.58 KB

Reverted removal of file_exists() in drupal_get_filename() as it needlessly blocks this issue.

Fabianx’s picture

+++ b/core/modules/system/lib/Drupal/system/Tests/Bootstrap/GetFilenameUnitTest.phpundefined
@@ -50,6 +60,6 @@ function testDrupalGetFilename() {
     // for (e.g.) 'module' files in core/modules.
-    $this->assertIdentical(drupal_get_filename('script', 'test'), 'core/scripts/test.script', 'Retrieve test script location.');
+    $this->assertIdentical(drupal_get_filename('script', 'test'), 'core/scripts/test/test.script');
   }

Is the removal of the message on purpose?

Besides that it is RTBC now!

sun’s picture

Yes, custom assertion messages like that are nonsensical, because they hide the actual assertion error in case of a failure.

Fabianx’s picture

Status: Needs review » Reviewed & tested by the community

#23: Makes sense.

Looks good then for me. => RTBC

webchick’s picture

Status: Reviewed & tested by the community » Fixed

Committed and pushed to 8.x. Awesome!

Random testbot result before this patch: http://qa.drupal.org/pifr/test/379968 shows about a 45 minute test run. Let's see what happens next.

amateescu’s picture

Status: Fixed » Active

I thought this patch was supposed to help somehow, but the 8.x branch test is actually 5 minutes slower after the commit, from 45 to 50 minutes..

Berdir’s picture

Status: Active » Fixed

This does help.

Testbots are different, they take between 45 and almost 60 minutes for a test run. It's not possible to compare two different runs without at least making sure that it was executed on the same bot and even then there could be considerable differences (I think testbots are all virtual servers, so something else on the same physical machine could have affected it).

sun’s picture

+      // Do not recurse into ./lib directories; they cannot contain extensions.
+      // We also skip templates, css, and js directories.
+      // @todo Find a way to skip ./config directories (but not modules/config).
+      'nomask' => '/^(CVS|lib|templates|css|js)$/',
+    ));

Created a follow-up issue for this @todo: #1833732: Find a way to skip ./config directories without skipping core/modules/config directory in drupal_system_listing()

Automatically closed -- issue fixed for 2 weeks with no activity.