added Stopwatch support in debug mode, added a timeline representing …

…the stopwatch events in the web profiler

Enjoy!

src/Symfony/Bridge/Doctrine/Logger/DbalLogger.php

@@ -12,6 +12,7 @@
 namespace Symfony\Bridge\Doctrine\Logger;
 
 use Symfony\Component\HttpKernel\Log\LoggerInterface;
+use Symfony\Component\HttpKernel\Debug\Stopwatch;
 use Doctrine\DBAL\Logging\DebugStack;
 
 /**
@@ -22,15 +23,18 @@
 class DbalLogger extends DebugStack
 {
     protected $logger;
+    protected $stopwatch;
 
     /**
      * Constructor.
      *
-     * @param LoggerInterface $logger A LoggerInterface instance
+     * @param LoggerInterface $logger    A LoggerInterface instance
+     * @param Stopwatch       $stopwatch A Stopwatch instance
      */
-    public function __construct(LoggerInterface $logger = null)
+    public function __construct(LoggerInterface $logger = null, Stopwatch $stopwatch = null)
     {
         $this->logger = $logger;
+        $this->stopwatch = $stopwatch;
     }
 
     /**
@@ -40,11 +44,27 @@ public function startQuery($sql, array $params = null, array $types = null)
     {
         parent::startQuery($sql, $params, $types);
 
+        if (null !== $this->stopwatch) {
+            $this->stopwatch->start('doctrine', 'doctrine');
+        }
+
         if (null !== $this->logger) {
             $this->log($sql.' ('.json_encode($params).')');
         }
     }
 
+    /**
+     * {@inheritdoc}
+     */
+    public function stopQuery()
+    {
+        parent::stopQuery();
+
+        if (null !== $this->stopwatch) {
+            $this->stopwatch->stop('doctrine');
+        }
+    }
+
     /**
      * Logs a message.
      *

src/Symfony/Bundle/DoctrineBundle/Resources/config/dbal.xml

@@ -22,6 +22,7 @@
         <service id="doctrine.dbal.logger" class="%doctrine.dbal.logger.class%" public="false">
             <tag name="monolog.logger" channel="doctrine" />
             <argument type="service" id="logger" on-invalid="null" />
+            <argument type="service" id="debug.stopwatch" on-invalid="null" />
         </service>
 
         <service id="data_collector.doctrine" class="%doctrine.data_collector.class%" public="false">

src/Symfony/Bundle/FrameworkBundle/ContainerAwareEventDispatcher.php

@@ -140,6 +140,11 @@ public function dispatch($eventName, Event $event = null)
         parent::dispatch($eventName, $event);
     }
 
+    public function getContainer()
+    {
+        return $this->container;
+    }
+
     /**
      * Lazily loads listeners for this event from the dependency injection
      * container.

src/Symfony/Bundle/FrameworkBundle/Controller/TraceableControllerResolver.php

@@ -0,0 +1,71 @@
+<?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\Bundle\FrameworkBundle\Controller;
+
+use Symfony\Component\HttpKernel\Log\LoggerInterface;
+use Symfony\Component\HttpKernel\Debug\Stopwatch;
+use Symfony\Component\HttpFoundation\Request;
+use Symfony\Component\DependencyInjection\ContainerInterface;
+use Symfony\Bundle\FrameworkBundle\Controller\ControllerNameParser;
+
+/**
+ * TraceableControllerResolver.
+ *
+ * @author Fabien Potencier <fabien@symfony.com>
+ */
+class TraceableControllerResolver extends ControllerResolver
+{
+    private $stopwatch;
+
+    /**
+     * Constructor.
+     *
+     * @param ContainerInterface   $container A ContainerInterface instance
+     * @param ControllerNameParser $parser    A ControllerNameParser instance
+     * @param Stopwatch            $stopwatch A Stopwatch instance
+     * @param LoggerInterface      $logger    A LoggerInterface instance
+     */
+    public function __construct(ContainerInterface $container, ControllerNameParser $parser, Stopwatch $stopwatch, LoggerInterface $logger = null)
+    {
+        parent::__construct($container, $parser, $logger);
+
+        $this->stopwatch = $stopwatch;
+    }
+
+    /**
+     * @{inheritdoc}
+     */
+    public function getController(Request $request)
+    {
+        $e = $this->stopwatch->start('controller.get_callable');
+
+        $ret = parent::getController($request);
+
+        $e->stop();
+
+        return $ret;
+    }
+
+    /**
+     * @{inheritdoc}
+     */
+    public function getArguments(Request $request, $controller)
+    {
+        $e = $this->stopwatch->start('controller.get_arguments');
+
+        $ret = parent::getArguments($request, $controller);
+
+        $e->stop();
+
+        return $ret;
+    }
+}

src/Symfony/Bundle/FrameworkBundle/Debug/TraceableEventDispatcher.php

@@ -12,10 +12,13 @@
 namespace Symfony\Bundle\FrameworkBundle\Debug;
 
 use Symfony\Bundle\FrameworkBundle\ContainerAwareEventDispatcher;
+use Symfony\Component\HttpKernel\Debug\Stopwatch;
 use Symfony\Component\HttpKernel\Log\LoggerInterface;
 use Symfony\Component\HttpKernel\Debug\TraceableEventDispatcherInterface;
 use Symfony\Component\DependencyInjection\ContainerInterface;
 use Symfony\Component\EventDispatcher\Event;
+use Symfony\Component\HttpKernel\Profiler\Profiler;
+use Symfony\Component\HttpKernel\Profiler\Profile;
 
 /**
  * Extends the ContainerAwareEventDispatcher to add some debugging tools.
@@ -26,21 +29,53 @@ class TraceableEventDispatcher extends ContainerAwareEventDispatcher implements
 {
     private $logger;
     private $called;
+    private $stopwatch;
 
     /**
      * Constructor.
      *
      * @param ContainerInterface $container A ContainerInterface instance
+     * @param Stopwatch          $stopwatch A Stopwatch instance
      * @param LoggerInterface    $logger    A LoggerInterface instance
      */
-    public function __construct(ContainerInterface $container, LoggerInterface $logger = null)
+    public function __construct(ContainerInterface $container, Stopwatch $stopwatch, LoggerInterface $logger = null)
     {
         parent::__construct($container);
 
+        $this->stopwatch = $stopwatch;
         $this->logger = $logger;
         $this->called = array();
     }
 
+    public function dispatch($eventName, Event $event = null)
+    {
+        if ('kernel.request' === $eventName) {
+            $this->stopwatch->startSection();
+        } elseif ('kernel.view' === $eventName || 'kernel.response' === $eventName) {
+            // stop only if a controller has been executed
+            try {
+                $this->stopwatch->stop('controller');
+            } catch (\LogicException $e) {
+            }
+        }
+
+        $e1 = $this->stopwatch->start($eventName, 'section');
+
+        parent::dispatch($eventName, $event);
+
+        $e1->stop();
+
+        if ('kernel.controller' === $eventName) {
+            $this->stopwatch->start('controller', 'section');
+        } elseif ('kernel.response' === $eventName) {
+            $token = $event->getResponse()->headers->get('X-Debug-Token');
+
+            $this->stopwatch->stopSection($token);
+
+            $this->updateProfile($token);
+        }
+    }
+
     /**
      * {@inheritDoc}
      *
@@ -79,8 +114,12 @@ protected function doDispatch($listeners, $eventName, Event $event)
 
             $this->called[$eventName.'.'.$info['pretty']] = $info;
 
+            $e2 = $this->stopwatch->start(substr($info['class'], strrpos($info['class'], '\\') + 1), 'event_listener');
+
             call_user_func($listener, $event);
 
+            $e2->stop();
+
             if ($event->isPropagationStopped()) {
                 if (null !== $this->logger) {
                     $this->logger->debug(sprintf('Listener "%s" stopped propagation of the event "%s".', $info['pretty'], $eventName));
@@ -115,6 +154,18 @@ protected function doDispatch($listeners, $eventName, Event $event)
         }
     }
 
+    /**
+     * {@inheritDoc}
+     */
+    protected function lazyLoad($eventName)
+    {
+        $e = $this->stopwatch->start($eventName.'.loading', 'event_listener_loading');
+
+        parent::lazyLoad($eventName);
+
+        $e->stop();
+    }
+
     /**
      * {@inheritDoc}
      */
@@ -199,4 +250,25 @@ private function getListenerInfo($listener, $eventName)
 
         return $info;
     }
+
+    private function updateProfile($token)
+    {
+        if (!$this->getContainer()->has('profiler')) {
+            return;
+        }
+
+        $profiler = $this->getContainer()->get('profiler');
+        if (!$profile = $profiler->loadProfile($token)) {
+            return;
+        }
+
+        $profile->getCollector('time')->setEvents($this->stopwatch->getSectionEvents($profile->getToken()));
+        $profiler->saveProfile($profile);
+
+        // children
+        foreach ($profile->getChildren() as $child) {
+            $child->getCollector('time')->setEvents($this->stopwatch->getSectionEvents($child->getToken()));
+            $profiler->saveProfile($child);
+        }
+    }
 }

src/Symfony/Bundle/FrameworkBundle/DependencyInjection/FrameworkExtension.php

@@ -53,6 +53,9 @@ public function load(array $configs, ContainerBuilder $container)
             $loader->load('debug.xml');
             $container->setDefinition('event_dispatcher', $container->findDefinition('debug.event_dispatcher'));
             $container->setAlias('debug.event_dispatcher', 'event_dispatcher');
+
+            $container->setDefinition('controller_resolver', $container->findDefinition('debug.controller_resolver'));
+            $container->setAlias('debug.controller_resolver', 'controller_resolver');
         }
 
         $configuration = new Configuration($container->getParameter('kernel.debug'));

src/Symfony/Bundle/FrameworkBundle/HttpKernel.php

@@ -21,6 +21,7 @@
 /**
  * This HttpKernel is used to manage scope changes of the DI container.
  *
+ * @author Fabien Potencier <fabien@symfony.com>
  * @author Johannes M. Schmitt <schmittjoh@gmail.com>
  */
 class HttpKernel extends BaseHttpKernel

src/Symfony/Bundle/FrameworkBundle/Resources/config/collectors.xml

@@ -10,7 +10,7 @@
         <parameter key="data_collector.exception.class">Symfony\Component\HttpKernel\DataCollector\ExceptionDataCollector</parameter>
         <parameter key="data_collector.events.class">Symfony\Component\HttpKernel\DataCollector\EventDataCollector</parameter>
         <parameter key="data_collector.logger.class">Symfony\Component\HttpKernel\DataCollector\LoggerDataCollector</parameter>
-        <parameter key="data_collector.timer.class">Symfony\Component\HttpKernel\DataCollector\TimerDataCollector</parameter>
+        <parameter key="data_collector.time.class">Symfony\Component\HttpKernel\DataCollector\TimeDataCollector</parameter>
         <parameter key="data_collector.memory.class">Symfony\Component\HttpKernel\DataCollector\MemoryDataCollector</parameter>
     </parameters>
 
@@ -21,7 +21,6 @@
         </service>
 
         <service id="data_collector.request" class="%data_collector.request.class%">
-            <tag name="kernel.event_listener" event="kernel.controller" method="onKernelController"/>
             <tag name="data_collector" template="WebProfilerBundle:Collector:request" id="request" priority="255" />
         </service>
 
@@ -42,8 +41,8 @@
             <argument type="service" id="logger" on-invalid="ignore" />
         </service>
 
-        <service id="data_collector.timer" class="%data_collector.timer.class%" public="false">
-            <tag name="data_collector" template="WebProfilerBundle:Collector:timer" id="timer" priority="255" />
+        <service id="data_collector.time" class="%data_collector.time.class%" public="false">
+            <tag name="data_collector" template="WebProfilerBundle:Collector:time" id="time" priority="255" />
             <argument type="service" id="kernel" />
         </service>
 

src/Symfony/Bundle/FrameworkBundle/Resources/config/debug.xml

@@ -6,14 +6,27 @@
 
     <parameters>
         <parameter key="debug.event_dispatcher.class">Symfony\Bundle\FrameworkBundle\Debug\TraceableEventDispatcher</parameter>
+        <parameter key="debug.stopwatch.class">Symfony\Component\HttpKernel\Debug\Stopwatch</parameter>
         <parameter key="debug.container.dump">%kernel.cache_dir%/%kernel.container_class%.xml</parameter>
+        <parameter key="debug.controller_resolver.class">Symfony\Bundle\FrameworkBundle\Controller\TraceableControllerResolver</parameter>
     </parameters>
 
     <services>
+        <service id="debug.stopwatch" class="%debug.stopwatch.class%" />
+
         <service id="debug.event_dispatcher" class="%debug.event_dispatcher.class%">
             <tag name="monolog.logger" channel="event" />
             <argument type="service" id="service_container" />
+            <argument type="service" id="debug.stopwatch" />
             <argument type="service" id="logger" on-invalid="null" />
         </service>
+
+        <service id="debug.controller_resolver" class="%debug.controller_resolver.class%">
+            <tag name="monolog.logger" channel="request" />
+            <argument type="service" id="service_container" />
+            <argument type="service" id="controller_name_converter" />
+            <argument type="service" id="debug.stopwatch" />
+            <argument type="service" id="logger" on-invalid="ignore" />
+        </service>
     </services>
 </container>

src/Symfony/Bundle/FrameworkBundle/Tests/Debug/TraceableEventDispatcherTest.php

@@ -13,6 +13,7 @@
 
 use Symfony\Bundle\FrameworkBundle\Tests\TestCase;
 use Symfony\Bundle\FrameworkBundle\Debug\TraceableEventDispatcher;
+use Symfony\Component\HttpKernel\Debug\Stopwatch;
 
 class TraceableEventDispatcherTest extends TestCase
 {
@@ -23,7 +24,7 @@ class TraceableEventDispatcherTest extends TestCase
     public function testThrowsAnExceptionWhenAListenerMethodIsNotCallable()
     {
         $container = $this->getMock('Symfony\Component\DependencyInjection\ContainerInterface');
-        $dispatcher = new TraceableEventDispatcher($container);
+        $dispatcher = new TraceableEventDispatcher($container, new Stopwatch());
         $dispatcher->addListener('onFooEvent', new \stdClass());
     }
 }