Problem/Motivation

I was doing a round of profiling on the simplest thing possible: a route that does

return new Response('hi!');

I'm doing this to see where baseline performance problems are.

Turns out initializing the route listener service takes ~20/25% of the response time, due to the mind boggling dependency tree that it comes with.

The critical path in that dependency tree is this:

@router_listener -> @router -> @router.no_access_checks -> @router.dynamic -> @route_enhancer.entity -> @form_builder -> @theme.manager -> @theme.initialization -> @theme_handler -> @asset.css.collection_optimizer -> @asset.css.optimizer

So we need the theme system to do routing when the entity route enhancer is present… (This also means the work dawehner et al. did in #2228093: Modernize theme initialization to not initialize the theme system on non-HTML routes was unfortunately only partially effective. All of that work still is valuable of course, it's just that the entity route enhancer is undoing quite a bit of that.)

This was introduced by #1874530: Add Symfony CMF Routing component ("route enhancers") and #2068471: Normalize Controller/View-listener behavior with a Page object (the entity route enhancer using the form builder service). Unfortunately, it makes it easy to unwantedly introduce huge additional dependency trees to the most fundamental service of all (routing).

Proposed resolution

  • Move the HTML form controller and HTML entity form controller into services (like the other wrapper controllers)
  • That means both controllers are initialized only when actually used
  • route filters / enhancers running on every request will be handled in #2368769: All route enhancers are run on every request

Remaining tasks

TBD

User interface changes

None.

API changes

TBD

Files: 
CommentFileSizeAuthor
#35 2368275-35.patch13.26 KBdawehner
PASSED: [[SimpleTest]]: [PHP 5.4 MySQL] 81,821 pass(es). View
#35 interdiff.txt5.4 KBdawehner
#32 minroute-module-do-not-test.patch1.56 KBznerol
#24 minroute-module-do-not-test.patch546 bytesznerol
#23 interdiff-17-23.txt1017 bytesmartin107
#23 2352641-greedy-enhancers-23.patch16.11 KBmartin107
PASSED: [[SimpleTest]]: [PHP 5.4 MySQL] 81,117 pass(es). View
#17 interdiff-13-17.txt1.38 KBmartin107
#17 2352641-greedy-enhancers-13.patch16.37 KBmartin107
PASSED: [[SimpleTest]]: [PHP 5.4 MySQL] 80,931 pass(es). View
#13 2352641-greedy-enhancers.patch15.93 KBCrell
FAILED: [[SimpleTest]]: [PHP 5.4 MySQL] 50,867 pass(es), 19,742 fail(s), and 1,173 exception(s). View
simple_route_for_profiling-do-not-test.patch1.2 KBWim Leers

Comments

Wim Leers’s picture

This became apparent by profiling with XHProf as follows:

  $ignored_functions = [
    // DB.
    'Drupal\Core\Database\Connection::query',
    'Drupal\Core\Database\Statement::execute',
    'Drupal\Core\Database\Query\Update::execute',
    'PDOStatement::execute',
    // FS.
    'file_exists',
    // Class loader.
    'Composer\Autoload\ClassLoader::findFileWithExtension',
    'Composer\Autoload\ClassLoader::findFile',
    'Composer\Autoload\ClassLoader::loadClass',
    'spl_autoload_call',
    // DIC.
    'Symfony\Component\DependencyInjection\Container::get',
    'Drupal\Core\DependencyInjection\Container::get',
  ];
  xhprof_enable(XHPROF_FLAGS_MEMORY, ['ignored_functions' => $ignored_functions]);

This allowed me to clearly see which service initializations took the most time (inclusive wall time) because they have a big tree of dependencies.

znerol’s picture

Does this mean that anything in the critical path which depends on form builder will potentially nuke system performance?

Wim Leers’s picture

Yes.

catch’s picture

Of the two options, if it's at all feasible I'd prefer option #2 (which reminds me of #1793520-7: Add access control mechanism for new router system two years ago...). That means an API change for route enhancers but there's not that many of them to convert.

Lazy services seems useful for things like logging, setting messages, CRUD operations - where a class might have a genuine dependency that's not required very often and where splitting up the class isn't helpful.

In this case the actual dependency chain is hidden behind event listeners, and it's the event listeners themselves that are unnecessary for the vast majority of routes. A route that just does return new Respone('hi!'); by definition doesn't need the entity route enhancer or support for _entity_form.

Gábor Hojtsy’s picture

The only route enhancer change notice I found is https://www.drupal.org/node/2012100, but route enhancers predate that...

yched’s picture

the work dawehner et al. did in #2228093: Modernize theme initialization to not initialize the theme system on non-HTML routes

Silly question: If there was work done to not initialize the theme system when not needed, wouldn't it be consistent to make @theme.manager or @theme.initialization the lazy service ?

webchick’s picture

Issue summary: View changes

Minor issue summary tidying; let's stick to the problem at hand.

moshe weitzman’s picture

Issue summary: View changes
tim.plunkett’s picture

See also #2328871: Remove FormBuilder coupling to moduleHandler/themeManager.
The patch in #20 of that issue doesn't really help directly, but the patch in #6 would have.

Crell’s picture

An API change for Route Enhancers would be problematic, as those are an upstream concept from the CMF Routing component. We couldn't change that, only add another layer on it to delay execution.

Another option I hate to mention but will for completeness is to make EntityRouteEnhancer container aware. It only conditionally needs the services it uses, and in the case of FormBuilder isn't even using it; it's just passing it along to the wrapping HtmlEntityFormController. It doesn't use it itself.

In fact, looking at that class it appears all 3 of its dependencies exist only to be passed along to HtmlEntityFormController, which suggests that should be refactored anyway. I believe the best option would be to convert HtmlEntityFormController to a service (like FormController is) and let it handle its own dependencies. That would technically mean EntityRouteEnhancer has a hard-coded service name in it, but ContentControllerSubscriber does too for the same use case anyway. We should perhaps do the same for ContentFormControllerSubscriber/HtmlFormController, too, for the same reason.

(Also, side note: The provided test case is going to skip any work done in the view listener so is not an accurate representation of a full page request.

Crell’s picture

Title: Route enhancers may (and currently do) make the routing system dependent on everything in the world » EntityRouteEnhancer and ContentFormControllerSubscriber implicitly depend on too many services

Also retitling; There's nothing special about route enhancers. They're just services. A service that depends on another service depends on all of that service's dependencies. That's just how code works. :-)

Crell’s picture

Assigned: Unassigned » Crell
Crell’s picture

Assigned: Crell » Unassigned
Status: Active » Needs review
FileSize
15.93 KB
FAILED: [[SimpleTest]]: [PHP 5.4 MySQL] 50,867 pass(es), 19,742 fail(s), and 1,173 exception(s). View

Something like this.

Turns out the dependency tree for all of the Form controller stuff was nutty. I was able to clean that up significantly. I also folded ContentFormControllerSubscriber into ContentControllerSubscriber, since once I was done refactoring it there were only 2 non-ceremony lines in it.

This should eliminate the "load all the things!" problem; the code is IMO cleaner and tidier as well, but the performance impact should be solely the load issue.

I'm a little curious why we're using a route enhancer for Entity routes but a request subscriber for the rest of them. I guess it works either way but we should normalize that, probably to an enhancer for all of them as the code is now quite simple and stand-alone.

I was very tempted to break EntityRouteEnhancerTest up into separate test methods while I was there; there's zero reason for them to all be separate, especially now. Follow-up.

Status: Needs review » Needs work

The last submitted patch, 13: 2352641-greedy-enhancers.patch, failed testing.

catch’s picture

There's nothing special about route enhancers. They're just services. A service that depends on another service depends on all of that service's dependencies. That's just how code works. :-)

There is something special about them though. When a service is executed on every page request, and especially when it's in the critical path like routing, then every request has those dependencies. So any route enhancer with a long dependency chain is going to cause this performance issue, even if it only applies to an obscure admin path where otherwise you wouldn't care.

In 6.x/7.x where for example the _load()/%placeholder callbacks were by convention and hence stored (albeit implicitly) in the routing definition itself, this particular problem just doesn't exist, and taking the ->applies() route here would be closer to that.

Cleaning up the entity route enhancer will help though, so I've opened a separate issue to address route enhancers more generally, #2368769: All route enhancers are run on every request.

martin107’s picture

I think the patch is a good step ... however it does not yet handle all cases .... yet

Instead of testing it is easy to push it over and get a stack trace, visit :-

/admin/config/development/logging ( _form: 'Drupal\system\Form\LoggingForm' )
/admin/config/development/performance ( _form: 'Drupal\system\Form\PerformanceForm' )

So form access is a little broken

I am sorry I am running out of time tonight, but in the spirit of post early partials... I have this comment

ContentControllerSubscriber::onRequestDeriveFormWrapper()

  public function onRequestDeriveFormWrapper(GetResponseEvent $event) {
    $request = $event->getRequest();
    if ($form = $request->attributes->get('_form')) {
      $defaults['_content'] = 'controller.form:getContentResult';
    }
  }

Stepping through the code as might be expected
$form equals 'Drupal\system\Form\PerformanceForm' when visiting /admin/config/development/performance AND $default['_content'] gets set BUT it is then promptly dumped on the floor - it goes nowhere as $defaults is a local variable!!!!!!

Anyway I will look more tomorrow.

martin107’s picture

Status: Needs work » Needs review
FileSize
16.37 KB
PASSED: [[SimpleTest]]: [PHP 5.4 MySQL] 80,931 pass(es). View
1.38 KB

A) Routing using _form has been restored, to pages like /admin/config/development/logging

As Described in #16 the patch from #13 just needed a little nudge

ContentControllerSubscriber::onRequestDeriveFormWrapper() -- was not changing the state of the request :-

  public function onRequestDeriveFormWrapper(GetResponseEvent $event) {
    $request = $event->getRequest();

    if ($form = $request->attributes->get('_form')) {
-      $defaults['_content'] = 'controller.form:getContentResult';
+      $request->attributes->set('_content', 'controller.form:getContentResult');
    }
  }

B) Minor housekeeping .... now that the unwanted dependencies have been stripped from EntityRouteEnhancer many 'use' statemnents can also be removed.

dawehner’s picture

  1. +++ b/core/core.services.yml
    @@ -636,12 +635,6 @@ services:
    -  route_content_form_controller_subscriber:
    

    +1 for one less subscriber

  2. +++ b/core/lib/Drupal/Core/Controller/HtmlFormController.php
    @@ -42,11 +35,16 @@ class HtmlFormController extends FormController {
    +    return $request->attributes->get('_form');
    
    +++ b/core/lib/Drupal/Core/Entity/HtmlEntityFormController.php
    @@ -29,17 +30,21 @@ class HtmlEntityFormController extends FormController {
    +    return $request->attributes->get('_entity_form');
    

    I wonder why we don't use the route object using the route match, but it seems to be the thing in all that low level code.

znerol’s picture

Issue tags: +Needs profiling
+++ b/core/lib/Drupal/Core/EventSubscriber/ContentControllerSubscriber.php
@@ -86,6 +100,7 @@ public function onRequestDeriveContentWrapper(GetResponseEvent $event) {
+    $events[KernelEvents::REQUEST][] = array('onRequestDeriveFormWrapper', 29);

@dawehner: One subscriber less, but one more listener in another subscriber :)

@Wim Leers: Would you mind rerunning your benchmark with the patch applied?

znerol’s picture

Overall the patch looks good. It is kind of weird that the ContentControllerSubscriber which according to the docs is used for "[...] setting the format of the request" is assigned more responsibility.

Two nitpicks:

  1. +++ b/core/lib/Drupal/Core/Controller/FormController.php
    @@ -81,6 +76,20 @@ public function getContentResult(Request $request) {
       }
     
    +
    +  /**
    

    Remove one of the newlines.

  2. +++ b/core/lib/Drupal/Core/Entity/HtmlEntityFormController.php
    @@ -10,6 +10,7 @@
    +use Drupal\Core\Form\FormState;
    

    No.

Crell’s picture

I don't have a strong feeling about ContentControllerSubscriber; it just seemed silly to have an event subscriber class with only 2-3 non-ceremony lines in it that wasn't just bridging to a service. We could also update the docblock on the class if we want.

martin107: Wow, how did that work in my manual testing with such an obvious screw up? :-) Thanks for fixing.

Awaiting benchmarks from Wim or whoever is able to do so...

martin107’s picture

FileSize
16.11 KB
PASSED: [[SimpleTest]]: [PHP 5.4 MySQL] 81,117 pass(es). View
1017 bytes

Minor touches from #21.

znerol’s picture

Status: Needs review » Reviewed & tested by the community
Issue tags: -Needs profiling
FileSize
546 bytes

Reproducing the test scenario outlined in the IS using the attached minroute module. The impact is as follows:

$ wget -qSO - http://localhost:3000/list-services > /tmp/service-list-head.txt
$ git apply 2352641-greedy-enhancers-23.patch
$ drush cr
$ wget -qSO - http://localhost:3000/list-services > /tmp/service-list-patch.txt
$ wc -l /tmp/service-list-*
 142 /tmp/service-list-head.txt
 116 /tmp/service-list-patch.txt

The following services are not initialized if the patch is applied to head.

$ comm -3 /tmp/service-list-*.txt
access_check.theme
asset.css.collection_grouper
asset.css.collection_optimizer
asset.css.dumper
asset.css.optimizer
batch.storage
config.installer
config.manager
form_builder
form_submitter
form_validator
info_parser
keyvalue.expirable
logger.channel.form
route_content_form_controller_subscriber
theme.initialization
theme.manager
theme.negotiator
theme.negotiator.admin_theme
theme.negotiator.ajax_base_page
theme.negotiator.block.admin_demo
theme.negotiator.default
theme.negotiator.system.batch
theme.negotiator.system.db_update
theme.registry
theme_handler

The overall performance benefit if measured with ab -k -c1 -n500 http://localhost:3000/hi:

Without patch: Time per request: 46.034 [ms] (mean)
With patch: Time per request: 42.580 [ms] (mean)

alexpott’s picture

Status: Reviewed & tested by the community » Needs work
Issue tags: +Needs issue summary update

Looking at the issue summary and the patch - I don't think we went for either option. Setting back to needs work to get an update. Also given @catch's interest in this issue we should assign to him once back to rtbc.

I think the current solution look good.

dawehner’s picture

Issue summary: View changes

Updated the IS in order to understand what is going on.

+++ b/core/lib/Drupal/Core/Controller/FormController.php
@@ -63,14 +57,15 @@ public function __construct(ControllerResolverInterface $controller_resolver, Fo
-    $request->attributes->set('form', array());
+    $request->attributes->set('form', []);
     $request->attributes->set('form_state', $form_state);
-    $args = $this->controllerResolver->getArguments($request, array($form_object, 'buildForm'));
+    $args = $this->controllerResolver->getArguments($request, [$form_object, 'buildForm']);

Well, its okay, but it makes the patch a little bit harder to review

Crell’s picture

Assigned: Unassigned » catch
Issue summary: View changes
Status: Needs work » Reviewed & tested by the community

Tweaked the description a bit more; reassigning to catch as requested.

The array() => [] conversion dawehner notes is a quirk of my IDE, I think. Apparently PHPStorm has started converting array() to [] for me at times. *shrug*

catch’s picture

Status: Reviewed & tested by the community » Needs work
  1. +++ b/core/lib/Drupal/Core/Controller/FormController.php
    @@ -82,6 +77,19 @@ public function getContentResult(Request $request) {
    +   * Extracts the form definition string from a request.
    

    We don't have the phrase 'form definition string' anywhere in core yet, and it's not clear from the method docs what it is. Maybe an example would be enough, or is 'form definition string' really a specific thing? The param for getFormObject() is $form_arg, not $form_definition_string or $form_definition, so there's a mismatch.

  2. +++ b/core/lib/Drupal/Core/EventSubscriber/ContentControllerSubscriber.php
    @@ -78,6 +78,20 @@ public function onRequestDeriveContentWrapper(GetResponseEvent $event) {
    +    if ($form = $request->attributes->get('_form')) {
    

    Form is initialized but never used later in the method, no need to assign here.

Otherwise looks good.

Crell’s picture

Note that this is going to have a not-difficult (I hope) conflict with #2376791: Move all _content routing definitions to _controller now. I just RTBCed that one so it probably wins.

I'll see if I can revisit this to find a better way to word "form definition string".

dawehner’s picture

Well, technically its a _form default value. The controller resolves names _controller as parameter 'Unable to look for the controller as the "_controller" parameter is missing'.

Wim Leers’s picture

#21:

It is kind of weird that the ContentControllerSubscriber which according to the docs is used for "[...] setting the format of the request" is assigned more responsibility.

Agreed! #2352155: Remove HtmlFragment/HtmlPage fixed those docs :)


#24: Nice! 7.5% faster.
Also: your patch only lists the git status output, not the actual files of your testing module. Could you upload those? I think it could be handy for future profiling :)


Note that the latest patch (in #23) is outdated anyway, #2352155: Remove HtmlFragment/HtmlPage has landed since and has changed ContentControllerSubscriber. Easy to fix, but the current patch doesn't apply.

  1. +++ b/core/lib/Drupal/Core/Controller/FormController.php
    @@ -82,6 +77,19 @@ public function getContentResult(Request $request) {
    +   *   The request object from which to extract a form definition string.
    +   * @return string
    

    Super nitpicky nitpick: I thought we put a newline before @return?

  2. +++ b/core/lib/Drupal/Core/EventSubscriber/ContentControllerSubscriber.php
    @@ -78,6 +78,20 @@ public function onRequestDeriveContentWrapper(GetResponseEvent $event) {
       /**
    +   * Sets the _controller on a request based on the request format.
    +   *
    +   * @param \Symfony\Component\HttpKernel\Event\GetResponseEvent $event
    +   *   The event to process.
    +   */
    +  public function onRequestDeriveFormWrapper(GetResponseEvent $event) {
    

    This method's documentation is definitely wrong.

znerol’s picture

Oh!

dawehner’s picture

One really interesting bit about this patch is that it theoretically allows you much easier to not longer have all the special cases:

_form: Drupal\foo\Form\Bar

vs.

_controller: controller.form
form: Drupal\foo\Form\Bar

----------

_entity_form: 'foo.bar'

vs.

_controller: controller.entity_form
entity_form: 'foo.bar'

--------------

_entity_view: 'foo.baz'

vs.

_controller: controller.entity_view
entity_view: foo.baz
catch’s picture

Assigned: catch » Unassigned

Unassigning me.

dawehner’s picture

Status: Needs work » Needs review
FileSize
5.4 KB
13.26 KB
PASSED: [[SimpleTest]]: [PHP 5.4 MySQL] 81,821 pass(es). View

Rerolled the patch and fix some of the existing reviews.

One thing we could do in theory: Move that logic to add the _controller into route build time,
let's do that in the future, unless someone disagrees.

dawehner’s picture

martin107’s picture

Issue tags: -Needs reroll
Wim Leers’s picture

One thing we could do in theory: Move that logic to add the _controller into route build time,
let's do that in the future, unless someone disagrees.

+1!

  1. +++ b/core/lib/Drupal/Core/Controller/FormController.php
    @@ -77,17 +77,24 @@ public function getContentResult(Request $request) {
    -  abstract protected function getFormDefinition(Request $request);
    +  abstract protected function getFormArgument(Request $request);
    

    Why this rename?

  2. +++ b/core/lib/Drupal/Core/EventSubscriber/ContentControllerSubscriber.php
    @@ -62,8 +62,8 @@ public function onRequestDeriveFormat(GetResponseEvent $event) {
    -    if ($form = $request->attributes->get('_form')) {
    ...
    +    if ($request->attributes->has('_form')) {
    

    Nice :)

dawehner’s picture

Why this rename?

Well, the goal was to keep the variable and the method name more in sync:


 public function getContentResult(Request $request) {
-    $form_object = $this->getFormObject($request, $this->formDefinition);
+    $form_arg = $this->getFormArgument($request);
+    $form_object = $this->getFormObject($request, $form_arg);

+  abstract protected function getFormArgument(Request $request);

Well, later is some code like $form_arg = $this->getFormArgument,

Wim Leers’s picture

Status: Needs review » Reviewed & tested by the community

Makes sense.

Plus, only now I notice it's protected… so then it's totally fine.

I first RTBC'd, but then noticed there's just one nit left then, from #21:

Overall the patch looks good. It is kind of weird that the ContentControllerSubscriber which according to the docs is used for "[...] setting the format of the request" is assigned more responsibility.

… but actually, the class name already makes no sense anymore. This is now basically the RequestRoutingSubscriber, to handle the special/edge cases. The format handling is also going away from it. We can clean up the naming at any time.

catch’s picture

Status: Reviewed & tested by the community » Fixed

Committed/pushed to 8.0.x, thanks!

  • catch committed 07a6a68 on 8.0.x
    Issue #2368275 by martin107, dawehner, znerol, Crell, Wim Leers:...
dawehner’s picture

… but actually, the class name already makes no sense anymore. This is now basically the RequestRoutingSubscriber, to handle the special/edge cases. The format handling is also going away from it. We can clean up the naming at any time.

Totally agreed!

Awesome, another critical fixed.

Status: Fixed » Closed (fixed)

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