feature #26833 [HttpKernel] Added support for timings in ArgumentValu…

…eResolvers (iltar)

This PR was squashed before being merged into the 4.1-dev branch (closes #26833).

Discussion
----------

[HttpKernel] Added support for timings in ArgumentValueResolvers

| Q             | A
| ------------- | ---
| Branch?       | master
| Bug fix?      | no
| New feature?  | yes
| BC breaks?    | no
| Deprecations? | no
| Tests pass?   | yes
| Fixed tickets | ~
| License       | MIT
| Doc PR        | ~

This feature provides timings for the supports and resolve methods for each individual argument value resolver. It was already possible to see the `controller.get_arguments` timing, but it was impossible to track a possible performance issue any further without using different tools. I've explicitly added the `supports` method as well, as it might otherwise hide performance issues. The `ServiceValueResolver` for example, does a `container::has`, which in turn might trigger a factory method, which might trigger a query for example.

~~Due to the feature freeze I've already added this to 4.2. If for some reason it's okay to still merge it into 4.1, I can update the upgrade files.~~ - Changed to 4.1

##### *Without performance issue*
![image](https://user-images.githubusercontent.com/1754678/38416250-6cf45528-3994-11e8-91d4-2472c97c6c50.png)

##### *With performance issue*
![image](https://user-images.githubusercontent.com/1754678/38416266-7966eb7c-3994-11e8-9dc5-a99daa8f9a69.png)

Commits
-------

1c0d892 [HttpKernel] Added support for timings in ArgumentValueResolvers

src/Symfony/Component/HttpKernel/CHANGELOG.md

@@ -7,6 +7,8 @@ CHANGELOG
  * added orphaned events support to `EventDataCollector`
  * `ExceptionListener` now logs and collects exceptions at priority `2048` (previously logged at `-128` and collected at `0`)
  * Deprecated `service:action` syntax with a single colon to reference controllers. Use `service::method` instead.
+ * Added the ability to profile individual argument value resolvers via the
+   `Symfony\Component\HttpKernel\Controller\ArgumentResolver\TraceableValueResolver`
 
 4.0.0
 -----

src/Symfony/Component/HttpKernel/Controller/ArgumentResolver/TraceableValueResolver.php

@@ -0,0 +1,62 @@
+<?php
+
+/*
+ * This file is part of the Symfony package.
+ *
+ * (c) Fabien Potencier <fabien@symfony.com>
+ *
+ * For the full copyright and license information, please view the LICENSE
+ * file that was distributed with this source code.
+ */
+
+namespace Symfony\Component\HttpKernel\Controller\ArgumentResolver;
+
+use Symfony\Component\HttpFoundation\Request;
+use Symfony\Component\HttpKernel\Controller\ArgumentValueResolverInterface;
+use Symfony\Component\HttpKernel\ControllerMetadata\ArgumentMetadata;
+use Symfony\Component\Stopwatch\Stopwatch;
+
+/**
+ * Provides timing information via the stopwatch.
+ *
+ * @author Iltar van der Berg <kjarli@gmail.com>
+ */
+final class TraceableValueResolver implements ArgumentValueResolverInterface
+{
+    private $inner;
+    private $stopwatch;
+
+    public function __construct(ArgumentValueResolverInterface $inner, ?Stopwatch $stopwatch = null)
+    {
+        $this->inner = $inner;
+        $this->stopwatch = $stopwatch ?? new Stopwatch();
+    }
+
+    /**
+     * {@inheritdoc}
+     */
+    public function supports(Request $request, ArgumentMetadata $argument): bool
+    {
+        $method = \get_class($this->inner).'::'.__FUNCTION__;
+        $this->stopwatch->start($method);
+
+        $return = $this->inner->supports($request, $argument);
+
+        $this->stopwatch->stop($method);
+
+        return $return;
+    }
+
+    /**
+     * {@inheritdoc}
+     */
+    public function resolve(Request $request, ArgumentMetadata $argument): iterable
+    {
+        $method = \get_class($this->inner).'::'.__FUNCTION__;
+        $this->stopwatch->start($method);
+
+        yield from $this->inner->resolve($request, $argument);
+
+        $this->stopwatch->stop($method);
+    }
+}

src/Symfony/Component/HttpKernel/DependencyInjection/ControllerArgumentValueResolverPass.php

@@ -15,6 +15,10 @@
 use Symfony\Component\DependencyInjection\Compiler\CompilerPassInterface;
 use Symfony\Component\DependencyInjection\Compiler\PriorityTaggedServiceTrait;
 use Symfony\Component\DependencyInjection\ContainerBuilder;
+use Symfony\Component\DependencyInjection\ContainerInterface;
+use Symfony\Component\DependencyInjection\Reference;
+use Symfony\Component\HttpKernel\Controller\ArgumentResolver\TraceableValueResolver;
+use Symfony\Component\Stopwatch\Stopwatch;
 
 /**
  * Gathers and configures the argument value resolvers.
@@ -40,9 +44,20 @@ public function process(ContainerBuilder $container)
             return;
         }
 
+        $resolvers = $this->findAndSortTaggedServices($this->argumentValueResolverTag, $container);
+
+        if ($container->getParameter('kernel.debug') && class_exists(Stopwatch::class)) {
+            foreach ($resolvers as $resolverReference) {
+                $id = (string) $resolverReference;
+                $container->register("debug.$id", TraceableValueResolver::class)
+                    ->setDecoratedService($id)
+                    ->setArguments(array(new Reference("debug.$id.inner"), new Reference('debug.stopwatch', ContainerInterface::NULL_ON_INVALID_REFERENCE)));
+            }
+        }
+
         $container
             ->getDefinition($this->argumentResolverService)
-            ->replaceArgument(1, new IteratorArgument($this->findAndSortTaggedServices($this->argumentValueResolverTag, $container)))
+            ->replaceArgument(1, new IteratorArgument($resolvers))
         ;
     }
 }

src/Symfony/Component/HttpKernel/Tests/Controller/ArgumentResolver/TraceableValueResolverTest.php

@@ -0,0 +1,76 @@
+<?php
+
+/*
+ * This file is part of the Symfony package.
+ *
+ * (c) Fabien Potencier <fabien@symfony.com>
+ *
+ * For the full copyright and license information, please view the LICENSE
+ * file that was distributed with this source code.
+ */
+
+namespace Symfony\Component\HttpKernel\Tests\Controller\ArgumentResolver;
+
+use PHPUnit\Framework\TestCase;
+use Symfony\Component\HttpFoundation\Request;
+use Symfony\Component\HttpKernel\Controller\ArgumentResolver\TraceableValueResolver;
+use Symfony\Component\HttpKernel\Controller\ArgumentValueResolverInterface;
+use Symfony\Component\HttpKernel\ControllerMetadata\ArgumentMetadata;
+use Symfony\Component\Stopwatch\Stopwatch;
+
+class TraceableValueResolverTest extends TestCase
+{
+    public function testTimingsInSupports()
+    {
+        $stopwatch = new Stopwatch();
+        $resolver = new TraceableValueResolver(new ResolverStub(), $stopwatch);
+        $argument = new ArgumentMetadata('dummy', 'string', false, false, null);
+        $request = new Request();
+
+        $this->assertTrue($resolver->supports($request, $argument));
+
+        $event = $stopwatch->getEvent(ResolverStub::class.'::supports');
+        $this->assertCount(1, $event->getPeriods());
+    }
+
+    public function testTimingsInResolve()
+    {
+        $stopwatch = new Stopwatch();
+        $resolver = new TraceableValueResolver(new ResolverStub(), $stopwatch);
+        $argument = new ArgumentMetadata('dummy', 'string', false, false, null);
+        $request = new Request();
+
+        $iterable = $resolver->resolve($request, $argument);
+
+        foreach ($iterable as $index => $resolved) {
+            $event = $stopwatch->getEvent(ResolverStub::class.'::resolve');
+            $this->assertTrue($event->isStarted());
+            $this->assertEmpty($event->getPeriods());
+            switch ($index) {
+                case 0:
+                    $this->assertEquals('first', $resolved);
+                    break;
+                case 1:
+                    $this->assertEquals('second', $resolved);
+                    break;
+            }
+        }
+
+        $event = $stopwatch->getEvent(ResolverStub::class.'::resolve');
+        $this->assertCount(1, $event->getPeriods());
+    }
+}
+
+class ResolverStub implements ArgumentValueResolverInterface
+{
+    public function supports(Request $request, ArgumentMetadata $argument)
+    {
+        return true;
+    }
+
+    public function resolve(Request $request, ArgumentMetadata $argument)
+    {
+        yield 'first';
+        yield 'second';
+    }
+}

src/Symfony/Component/HttpKernel/Tests/DependencyInjection/ControllerArgumentValueResolverPassTest.php

@@ -42,8 +42,50 @@ public function testServicesAreOrderedAccordingToPriority()
             $container->register($id)->addTag('controller.argument_value_resolver', $tag);
         }
 
+        $container->setParameter('kernel.debug', false);
+
         (new ControllerArgumentValueResolverPass())->process($container);
         $this->assertEquals($expected, $definition->getArgument(1)->getValues());
+
+        $this->assertFalse($container->hasDefinition('n1.traceable'));
+        $this->assertFalse($container->hasDefinition('n2.traceable'));
+        $this->assertFalse($container->hasDefinition('n3.traceable'));
+    }
+
+    public function testInDebug()
+    {
+        $services = array(
+            'n3' => array(array()),
+            'n1' => array(array('priority' => 200)),
+            'n2' => array(array('priority' => 100)),
+        );
+
+        $expected = array(
+            new Reference('n1'),
+            new Reference('n2'),
+            new Reference('n3'),
+        );
+
+        $definition = new Definition(ArgumentResolver::class, array(null, array()));
+        $container = new ContainerBuilder();
+        $container->setDefinition('argument_resolver', $definition);
+
+        foreach ($services as $id => list($tag)) {
+            $container->register($id)->addTag('controller.argument_value_resolver', $tag);
+        }
+
+        $container->setParameter('kernel.debug', true);
+
+        (new ControllerArgumentValueResolverPass())->process($container);
+        $this->assertEquals($expected, $definition->getArgument(1)->getValues());
+
+        $this->assertTrue($container->hasDefinition('debug.n1'));
+        $this->assertTrue($container->hasDefinition('debug.n2'));
+        $this->assertTrue($container->hasDefinition('debug.n3'));
+
+        $this->assertTrue($container->hasDefinition('n1'));
+        $this->assertTrue($container->hasDefinition('n2'));
+        $this->assertTrue($container->hasDefinition('n3'));
     }
 
     public function testReturningEmptyArrayWhenNoService()
@@ -52,6 +94,8 @@ public function testReturningEmptyArrayWhenNoService()
         $container = new ContainerBuilder();
         $container->setDefinition('argument_resolver', $definition);
 
+        $container->setParameter('kernel.debug', false);
+
         (new ControllerArgumentValueResolverPass())->process($container);
         $this->assertEquals(array(), $definition->getArgument(1)->getValues());
     }