[Profiler] Allow profiling the terminate event

This commit is contained in:
Victor Berchet 2012-01-30 16:14:38 +01:00
parent 4ccdc530bb
commit eb540bef29
5 changed files with 157 additions and 28 deletions

View File

@ -49,14 +49,21 @@ class TraceableEventDispatcher extends ContainerAwareEventDispatcher implements
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) {
}
switch ($eventName) {
case 'kernel.request':
$this->stopwatch->startSection();
break;
case 'kernel.view':
case 'kernel.response':
// stop only if a controller has been executed
try {
$this->stopwatch->stop('controller');
} catch (\LogicException $e) {
}
break;
case 'kernel.terminate':
$this->stopwatch->startSection();
break;
}
$e1 = $this->stopwatch->start($eventName, 'section');
@ -65,14 +72,20 @@ class TraceableEventDispatcher extends ContainerAwareEventDispatcher implements
$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);
switch ($eventName) {
case 'kernel.controller':
$this->stopwatch->start('controller', 'section');
break;
case 'kernel.response':
$token = $event->getResponse()->headers->get('X-Debug-Token');
$this->stopwatch->stopSection($token);
$this->updateProfile($token);
break;
case 'kernel.terminate':
$token = $event->getResponse()->headers->get('X-Debug-Token');
$this->stopwatch->stopSection($token.'.terminate');
$this->updateProfile($token);
break;
}
}
@ -236,6 +249,11 @@ class TraceableEventDispatcher extends ContainerAwareEventDispatcher implements
return $info;
}
/**
* Updates the profile data.
*
* @param string $token Profile token
*/
private function updateProfile($token)
{
if (!$this->getContainer()->has('profiler')) {
@ -247,7 +265,18 @@ class TraceableEventDispatcher extends ContainerAwareEventDispatcher implements
return;
}
$profile->getCollector('time')->setEvents($this->stopwatch->getSectionEvents($profile->getToken()));
$events = $this->stopwatch->getSectionEvents($token);
$origin = $events['section']->getOrigin();
foreach ($this->stopwatch->getSectionEvents($token.'.terminate') as $name => $event) {
if (isset($events[$name])) {
$events[$name]->merge($event);
} else {
$events[$name] = $event->setOrigin($origin);
}
}
$profile->getCollector('time')->setEvents($events);
$profiler->saveProfile($profile);
// children

View File

@ -68,14 +68,13 @@ class TimeDataCollector extends DataCollector
/**
* Gets the request elapsed time.
*
* @return integer The elapsed time
* @return float The elapsed time
*/
public function getTotalTime()
{
$values = array_values($this->data['events']);
$lastEvent = $values[count($values) - 1];
$lastEvent = $this->data['events']['section'];
return $lastEvent->getOrigin() + $lastEvent->getEndTime() - $this->data['start_time'];
return $lastEvent->getOrigin() + $lastEvent->getTotalTime() - $this->data['start_time'];
}
/**
@ -83,7 +82,7 @@ class TimeDataCollector extends DataCollector
*
* This is the time spent until the beginning of the request handling.
*
* @return integer The elapsed time
* @return float The elapsed time
*/
public function getInitTime()
{

View File

@ -26,7 +26,7 @@ class StopwatchEvent
/**
* Constructor.
*
* @param integer $origin The origin time in milliseconds
* @param float $origin The origin time in milliseconds
* @param string $category The event category
*
* @throws \InvalidArgumentException When the raw time is not valid
@ -59,10 +59,51 @@ class StopwatchEvent
return $this->origin;
}
/**
* Updates the origin.
*
* @param float $origin The origin time in milliseconds
*
* @return StopwatchEvent The event
*
* @throws \InvalidArgumentException When the raw time is not valid
*/
public function setOrigin($origin)
{
$origin = $this->formatTime($origin);
$delta = $this->origin - $origin;
$this->origin = $origin;
foreach ($this->started as $i => $time) {
$this->started[$i] = $this->formatTime($time + $delta);
}
foreach ($this->periods as $i => $period) {
$this->periods[$i] = array(
$this->formatTime($period[0] + $delta),
$this->formatTime($period[1] + $delta)
);
}
return $this;
}
/**
* Merges two events.
*
* @param StopWatchEvent $event The event to merge
*
* @return StopwatchEvent The event
*/
public function merge(StopWatchEvent $event)
{
$this->periods = array_merge($this->periods, $event->setOrigin($this->origin)->getPeriods());
return $this;
}
/**
* Starts a new event period.
*
* @return StopwatchEvent The event.
* @return StopwatchEvent The event
*/
public function start()
{
@ -74,7 +115,7 @@ class StopwatchEvent
/**
* Stops the last started event period.
*
* @return StopwatchEvent The event.
* @return StopwatchEvent The event
*/
public function stop()
{
@ -90,7 +131,7 @@ class StopwatchEvent
/**
* Stops the current period and then starts a new one.
*
* @return StopwatchEvent The event.
* @return StopwatchEvent The event
*/
public function lap()
{
@ -152,7 +193,12 @@ class StopwatchEvent
return $this->formatTime($total);
}
private function getNow()
/**
* Return the current time relative to origin.
*
* @return float Time in ms
*/
protected function getNow()
{
return $this->formatTime(microtime(true) * 1000 - $this->origin);
}

View File

@ -157,7 +157,7 @@ class Profiler
* @param Response $response A Response instance
* @param \Exception $exception An exception instance if the request threw one
*
* @return Profile|null A Profile instance or false if the profiler is disabled
* @return Profile|null A Profile instance or null if the profiler is disabled
*/
public function collect(Request $request, Response $response, \Exception $exception = null)
{

View File

@ -149,4 +149,59 @@ class StopwatchEventTest extends \PHPUnit_Framework_TestCase
{
new StopwatchEvent("abc");
}
public function testSetOrigin()
{
$event = $this
->getMockBuilder('Symfony\\Component\\HttpKernel\\Debug\\StopwatchEvent')
->setMethods(array('getNow'))
->setConstructorArgs(array(0))
->getMock()
;
$event
->expects($this->exactly(4))
->method('getNow')
->will($this->onConsecutiveCalls(10, 20, 30, 40))
;
$this->assertEquals(
array(array(0, 10), array(20, 40)),
$event->start()->stop()->start()->setOrigin(10)->stop()->getPeriods()
);
}
public function testMerge()
{
$e1 = $this
->getMockBuilder('Symfony\\Component\\HttpKernel\\Debug\\StopwatchEvent')
->setMethods(array('getNow'))
->setConstructorArgs(array(0))
->getMock()
;
$e1
->expects($this->exactly(2))
->method('getNow')
->will($this->onConsecutiveCalls(0, 10))
;
$e2 = $this
->getMockBuilder('Symfony\\Component\\HttpKernel\\Debug\\StopwatchEvent')
->setMethods(array('getNow'))
->setConstructorArgs(array(10))
->getMock()
;
$e2
->expects($this->exactly(2))
->method('getNow')
->will($this->onConsecutiveCalls(50, 60))
;
$this->assertEquals(
array(array(0, 10), array(60, 70)),
$e1->start()->stop()->merge($e2->start()->stop())->getPeriods()
);
}
}