diff --git a/CHANGELOG b/CHANGELOG index 9dcf0ba601..d6d4f08977 100644 --- a/CHANGELOG +++ b/CHANGELOG @@ -1,5 +1,6 @@ -* 1.17.1 (2015-XX-XX) +* 1.18.0 (2015-XX-XX) + * added a profiler * fixed filesystem loader cache when different file paths are used for the same template * 1.17.0 (2015-01-14) diff --git a/composer.json b/composer.json index f35873b612..6f7e50ce12 100644 --- a/composer.json +++ b/composer.json @@ -36,7 +36,7 @@ }, "extra": { "branch-alias": { - "dev-master": "1.17-dev" + "dev-master": "1.18-dev" } } } diff --git a/doc/api.rst b/doc/api.rst index 937f6b8009..3ff5d1a2ac 100644 --- a/doc/api.rst +++ b/doc/api.rst @@ -285,6 +285,9 @@ Twig comes bundled with the following extensions: * *Twig_Extension_Sandbox*: Adds a sandbox mode to the default Twig environment, making it safe to evaluate untrusted code. +* *Twig_Extension_Profiler*: Enabled the built-in Twig profiler (as of Twig + 1.18). + * *Twig_Extension_Optimizer*: Optimizes the node tree before compilation. The core, escaper, and optimizer extensions do not need to be added to the @@ -453,6 +456,37 @@ the extension constructor:: $sandbox = new Twig_Extension_Sandbox($policy, true); +Profiler Extension +~~~~~~~~~~~~~~~~~~ + +.. versionadded:: 1.18 + The Profile extension was added in Twig 1.18. + +The ``profiler`` extension enables a profiler for Twig templates; it should +only be used on your development machines as it adds some overhead:: + + $profile = new Twig_Profiler_Profile(); + $twig->addExtension(new Twig_Extension_Profiler($profile)); + + $dumper = new Twig_Profiler_Dumper_Text(); + echo $dumper->dump($profile); + +A profile contains information about time and memory consumption for template, +block, and macro executions. + +You can also dump the data in a `Blackfire.io `_ +compatible format:: + + $dumper = new Twig_Profiler_Dumper_Blackfire(); + file_put_contents('/path/to/profile.prof', $dumper->dump($profile)); + +Upload the profile to visualize it (create a `free account +`_ first): + +.. code-block:: sh + + blackfire --slot=7 upload /path/to/profile.prof + Optimizer Extension ~~~~~~~~~~~~~~~~~~~ diff --git a/ext/twig/php_twig.h b/ext/twig/php_twig.h index eeb202f044..c03d08cb2e 100644 --- a/ext/twig/php_twig.h +++ b/ext/twig/php_twig.h @@ -15,7 +15,7 @@ #ifndef PHP_TWIG_H #define PHP_TWIG_H -#define PHP_TWIG_VERSION "1.17.1-DEV" +#define PHP_TWIG_VERSION "1.18.0-DEV" #include "php.h" diff --git a/lib/Twig/Environment.php b/lib/Twig/Environment.php index 0b8db4d32f..88101f06a2 100644 --- a/lib/Twig/Environment.php +++ b/lib/Twig/Environment.php @@ -16,7 +16,7 @@ */ class Twig_Environment { - const VERSION = '1.17.1-DEV'; + const VERSION = '1.18.0-DEV'; protected $charset; protected $loader; diff --git a/lib/Twig/Extension/Profiler.php b/lib/Twig/Extension/Profiler.php new file mode 100644 index 0000000000..35e04a0130 --- /dev/null +++ b/lib/Twig/Extension/Profiler.php @@ -0,0 +1,52 @@ +actives = array($profile); + } + + public function enter(Twig_Profiler_Profile $profile) + { + $this->actives[0]->addProfile($profile); + array_unshift($this->actives, $profile); + } + + public function leave(Twig_Profiler_Profile $profile) + { + $profile->leave(); + array_shift($this->actives); + + if (1 === count($this->actives)) { + $this->actives[0]->leave(); + } + } + + /** + * {@inheritdoc} + */ + public function getNodeVisitors() + { + return array(new Twig_Profiler_NodeVisitor_Profiler($this->getName())); + } + + /** + * {@inheritdoc} + */ + public function getName() + { + return 'profiler'; + } +} diff --git a/lib/Twig/Node/Module.php b/lib/Twig/Node/Module.php index 745d2d7e7f..f3288f8480 100644 --- a/lib/Twig/Node/Module.php +++ b/lib/Twig/Node/Module.php @@ -20,7 +20,19 @@ class Twig_Node_Module extends Twig_Node public function __construct(Twig_NodeInterface $body, Twig_Node_Expression $parent = null, Twig_NodeInterface $blocks, Twig_NodeInterface $macros, Twig_NodeInterface $traits, $embeddedTemplates, $filename) { // embedded templates are set as attributes so that they are only visited once by the visitors - parent::__construct(array('parent' => $parent, 'body' => $body, 'blocks' => $blocks, 'macros' => $macros, 'traits' => $traits), array('filename' => $filename, 'index' => null, 'embedded_templates' => $embeddedTemplates), 1); + parent::__construct(array( + 'parent' => $parent, + 'body' => $body, + 'blocks' => $blocks, + 'macros' => $macros, + 'traits' => $traits, + 'display_enter' => new Twig_Node(), + 'display_leave' => new Twig_Node(), + ), array( + 'filename' => $filename, + 'index' => null, + 'embedded_templates' => $embeddedTemplates, + ), 1); } public function setIndex($index) @@ -271,12 +283,14 @@ protected function compileDisplayHeader(Twig_Compiler $compiler) $compiler ->write("protected function doDisplay(array \$context, array \$blocks = array())\n", "{\n") ->indent() + ->subcompile($this->getNode('display_enter')) ; } protected function compileDisplayFooter(Twig_Compiler $compiler) { $compiler + ->subcompile($this->getNode('display_leave')) ->outdent() ->write("}\n\n") ; diff --git a/lib/Twig/Profiler/Dumper/Blackfire.php b/lib/Twig/Profiler/Dumper/Blackfire.php new file mode 100644 index 0000000000..b82747a943 --- /dev/null +++ b/lib/Twig/Profiler/Dumper/Blackfire.php @@ -0,0 +1,68 @@ + + */ +class Twig_Profiler_Dumper_Blackfire +{ + public function dump(Twig_Profiler_Profile $profile) + { + $data = array(); + $this->dumpProfile('main()', $profile, $data); + $this->dumpChildren('main()', $profile, $data); + + $start = microtime(true); + $str = << $values) { + $str .= "{$name}//{$values['ct']} {$values['wt']} {$values['mu']} {$values['pmu']}\n"; + } + + return $str; + } + + private function dumpChildren($parent, Twig_Profiler_Profile $profile, &$data) + { + foreach ($profile as $p) { + if ($p->isTemplate()) { + $name = $p->getTemplate(); + } else { + $name = sprintf('%s::%s(%s)', $p->getTemplate(), $p->getType(), $p->getName()); + } + $this->dumpProfile(sprintf('%s==>%s', $parent, $name), $p, $data); + $this->dumpChildren($name, $p, $data); + } + } + + private function dumpProfile($edge, Twig_Profiler_Profile $profile, &$data) + { + if (isset($data[$edge])) { + $data[$edge]['ct'] += 1; + $data[$edge]['wt'] += floor($profile->getDuration() * 1000000); + $data[$edge]['mu'] += $profile->getMemoryUsage(); + $data[$edge]['pmu'] += $profile->getPeakMemoryUsage(); + } else { + $data[$edge] = array( + 'ct' => 1, + 'wt' => floor($profile->getDuration() * 1000000), + 'mu' => $profile->getMemoryUsage(), + 'pmu' => $profile->getPeakMemoryUsage(), + ); + } + } +} diff --git a/lib/Twig/Profiler/Dumper/Html.php b/lib/Twig/Profiler/Dumper/Html.php new file mode 100644 index 0000000000..c89852064f --- /dev/null +++ b/lib/Twig/Profiler/Dumper/Html.php @@ -0,0 +1,43 @@ + + */ +class Twig_Profiler_Dumper_Html extends Twig_Profiler_Dumper_Text +{ + static private $colors = array( + 'block' => '#dfd', + 'macro' => '#ddf', + 'template' => '#ffd', + 'big' => '#d44', + ); + + public function dump(Twig_Profiler_Profile $profile) + { + return '
'.parent::dump($profile).'
'; + } + + protected function formatTemplate(Twig_Profiler_Profile $profile, $prefix) + { + return sprintf('%s└ %s', $prefix, self::$colors['template'], $profile->getTemplate()); + } + + protected function formatNonTemplate(Twig_Profiler_Profile $profile, $prefix) + { + return sprintf('%s└ %s::%s(%s)', $prefix, $profile->getTemplate(), $profile->getType(), isset(self::$colors[$profile->getType()]) ? self::$colors[$profile->getType()] : 'auto', $profile->getName()); + } + + protected function formatTime(Twig_Profiler_Profile $profile, $percent) + { + return sprintf('%.2fms/%.0f%%', $percent > 20 ? self::$colors['big'] : 'auto', $profile->getDuration() * 1000, $percent); + } +} diff --git a/lib/Twig/Profiler/Dumper/Text.php b/lib/Twig/Profiler/Dumper/Text.php new file mode 100644 index 0000000000..998e210d3d --- /dev/null +++ b/lib/Twig/Profiler/Dumper/Text.php @@ -0,0 +1,68 @@ + + */ +class Twig_Profiler_Dumper_Text +{ + private $root; + + public function dump(Twig_Profiler_Profile $profile) + { + return $this->dumpProfile($profile); + } + + protected function formatTemplate(Twig_Profiler_Profile $profile, $prefix) + { + return sprintf('%s└ %s', $prefix, $profile->getTemplate()); + } + + protected function formatNonTemplate(Twig_Profiler_Profile $profile, $prefix) + { + return sprintf('%s└ %s::%s(%s)', $prefix, $profile->getTemplate(), $profile->getType(), $profile->getName()); + } + + protected function formatTime(Twig_Profiler_Profile $profile, $percent) + { + return sprintf('%.2fms/%.0f%%', $profile->getDuration() * 1000, $percent); + } + + private function dumpProfile(Twig_Profiler_Profile $profile, $prefix = '', $sibling = false) + { + if ($profile->isRoot()) { + $this->root = $profile->getDuration(); + $start = $profile->getName(); + } else { + if ($profile->isTemplate()) { + $start = $this->formatTemplate($profile, $prefix); + } else { + $start = $this->formatNonTemplate($profile, $prefix); + } + $prefix .= $sibling ? '│ ' : ' '; + } + + $percent = $this->root ? $profile->getDuration() / $this->root * 100 : 0; + + if ($profile->getDuration() * 1000 < 1) { + $str = $start."\n"; + } else { + $str = sprintf("%s %s\n", $start, $this->formatTime($profile, $percent)); + } + + $nCount = count($profile->getProfiles()); + foreach ($profile as $i => $p) { + $str .= $this->dumpProfile($p, $prefix, $i + 1 !== $nCount); + } + + return $str; + } +} diff --git a/lib/Twig/Profiler/Node/EnterProfile.php b/lib/Twig/Profiler/Node/EnterProfile.php new file mode 100644 index 0000000000..11c1114a8e --- /dev/null +++ b/lib/Twig/Profiler/Node/EnterProfile.php @@ -0,0 +1,40 @@ + + */ +class Twig_Profiler_Node_EnterProfile extends Twig_Node +{ + public function __construct($extensionName, $type, $name, $varName) + { + parent::__construct(array(), array('extension_name' => $extensionName, 'name' => $name, 'type' => $type, 'var_name' => $varName)); + } + + /** + * {@inheritdoc} + */ + public function compile(Twig_Compiler $compiler) + { + $compiler + ->write(sprintf("\$%s = \$this->env->getExtension(", $this->getAttribute('var_name'))) + ->repr($this->getAttribute('extension_name')) + ->raw(");\n") + ->write(sprintf("\$%s->enter(\$%s = new Twig_Profiler_Profile(\$this->getTemplateName(), ", $this->getAttribute('var_name'), $this->getAttribute('var_name').'_prof')) + ->repr($this->getAttribute('type')) + ->raw(", ") + ->repr($this->getAttribute('name')) + ->raw("));\n\n") + ; + } +} diff --git a/lib/Twig/Profiler/Node/LeaveProfile.php b/lib/Twig/Profiler/Node/LeaveProfile.php new file mode 100644 index 0000000000..88074c2f66 --- /dev/null +++ b/lib/Twig/Profiler/Node/LeaveProfile.php @@ -0,0 +1,34 @@ + + */ +class Twig_Profiler_Node_LeaveProfile extends Twig_Node +{ + public function __construct($varName) + { + parent::__construct(array(), array('var_name' => $varName)); + } + + /** + * {@inheritdoc} + */ + public function compile(Twig_Compiler $compiler) + { + $compiler + ->write("\n") + ->write(sprintf("\$%s->leave(\$%s);\n\n", $this->getAttribute('var_name'), $this->getAttribute('var_name').'_prof')) + ; + } +} diff --git a/lib/Twig/Profiler/NodeVisitor/Profiler.php b/lib/Twig/Profiler/NodeVisitor/Profiler.php new file mode 100644 index 0000000000..38debd758e --- /dev/null +++ b/lib/Twig/Profiler/NodeVisitor/Profiler.php @@ -0,0 +1,72 @@ + + */ +class Twig_Profiler_NodeVisitor_Profiler implements Twig_NodeVisitorInterface +{ + private $extensionName; + + public function __construct($extensionName) + { + $this->extensionName = $extensionName; + } + + /** + * {@inheritdoc} + */ + public function enterNode(Twig_NodeInterface $node, Twig_Environment $env) + { + return $node; + } + + /** + * {@inheritdoc} + */ + public function leaveNode(Twig_NodeInterface $node, Twig_Environment $env) + { + if ($node instanceof Twig_Node_Module) { + $varName = $this->getVarName(); + $node->setNode('display_enter', new Twig_Node(array(new Twig_Profiler_Node_EnterProfile($this->extensionName, Twig_Profiler_Profile::TEMPLATE, $node->getAttribute('filename'), $varName), $node->getNode('display_enter')))); + $node->setNode('display_leave', new Twig_Node(array(new Twig_Profiler_Node_LeaveProfile($varName), $node->getNode('display_leave')))); + } elseif ($node instanceof Twig_Node_Block) { + $varName = $this->getVarName(); + $node->setNode('body', new Twig_Node_Body(array( + new Twig_Profiler_Node_EnterProfile($this->extensionName, Twig_Profiler_Profile::BLOCK, $node->getAttribute('name'), $varName), + $node->getNode('body'), + new Twig_Profiler_Node_LeaveProfile($varName), + ))); + } elseif ($node instanceof Twig_Node_Macro) { + $varName = $this->getVarName(); + $node->setNode('body', new Twig_Node_Body(array( + new Twig_Profiler_Node_EnterProfile($this->extensionName, Twig_Profiler_Profile::MACRO, $node->getAttribute('name'), $varName), + $node->getNode('body'), + new Twig_Profiler_Node_LeaveProfile($varName), + ))); + } + + return $node; + } + + private function getVarName() + { + return sprintf('__internal_%s', hash('sha256', uniqid(mt_rand(), true), false)); + } + + /** + * {@inheritdoc} + */ + public function getPriority() + { + return 0; + } +} diff --git a/lib/Twig/Profiler/Profile.php b/lib/Twig/Profiler/Profile.php new file mode 100644 index 0000000000..fe48a4d2f2 --- /dev/null +++ b/lib/Twig/Profiler/Profile.php @@ -0,0 +1,150 @@ + + */ +class Twig_Profiler_Profile implements IteratorAggregate, Serializable +{ + const ROOT = 'ROOT'; + const BLOCK = 'block'; + const TEMPLATE = 'template'; + const MACRO = 'macro'; + + private $template; + private $name; + private $type; + private $starts = array(); + private $ends = array(); + private $profiles = array(); + + public function __construct($template = 'main', $type = Twig_Profiler_Profile::ROOT, $name = 'main') + { + $this->template = $template; + $this->type = $type; + $this->name = 0 === strpos($name, '__internal_') ? 'INTERNAL' : $name; + $this->enter(); + } + + public function getTemplate() + { + return $this->template; + } + + public function getType() + { + return $this->type; + } + + public function getName() + { + return $this->name; + } + + public function isRoot() + { + return self::ROOT === $this->type; + } + + public function isTemplate() + { + return self::TEMPLATE === $this->type; + } + + public function isBlock() + { + return self::BLOCK === $this->type; + } + + public function isMacro() + { + return self::MACRO === $this->type; + } + + public function getProfiles() + { + return $this->profiles; + } + + public function addProfile(Twig_Profiler_Profile $profile) + { + $this->profiles[] = $profile; + } + + /** + * Returns the duration in microseconds. + * + * @return int + */ + public function getDuration() + { + return isset($this->ends['wt']) && isset($this->starts['wt']) ? $this->ends['wt'] - $this->starts['wt'] : 0; + } + + /** + * Returns the memory usage in bytes. + * + * @return int + */ + public function getMemoryUsage() + { + return isset($this->ends['mu']) && isset($this->starts['mu']) ? $this->ends['mu'] - $this->starts['mu'] : 0; + } + + /** + * Returns the peak memory usage in bytes. + * + * @return int + */ + public function getPeakMemoryUsage() + { + return isset($this->ends['pmu']) && isset($this->starts['pmu']) ? $this->ends['pmu'] - $this->starts['pmu'] : 0; + } + + /** + * Starts the profiling. + */ + public function enter() + { + $this->starts = array( + 'wt' => microtime(true), + 'mu' => memory_get_usage(), + 'pmu' => memory_get_peak_usage(), + ); + } + + /** + * Stops the profiling. + */ + public function leave() + { + $this->ends = array( + 'wt' => microtime(true), + 'mu' => memory_get_usage(), + 'pmu' => memory_get_peak_usage(), + ); + } + + public function getIterator() + { + return new ArrayIterator($this->profiles); + } + + public function serialize() + { + return serialize(array($this->template, $this->name, $this->type, $this->starts, $this->ends, $this->profiles)); + } + + public function unserialize($data) + { + list($this->template, $this->name, $this->type, $this->starts, $this->ends, $this->profiles) = unserialize($data); + } +} diff --git a/test/Twig/Tests/Profiler/Dumper/AbstractTest.php b/test/Twig/Tests/Profiler/Dumper/AbstractTest.php new file mode 100644 index 0000000000..9020d3f390 --- /dev/null +++ b/test/Twig/Tests/Profiler/Dumper/AbstractTest.php @@ -0,0 +1,44 @@ +addProfile($index); + $body = new Twig_Profiler_Profile('embedded.twig', Twig_Profiler_Profile::BLOCK, 'body'); + $body->leave(); + $index->addProfile($body); + $embedded = new Twig_Profiler_Profile('embedded.twig', Twig_Profiler_Profile::TEMPLATE); + $included = new Twig_Profiler_Profile('included.twig', Twig_Profiler_Profile::TEMPLATE); + $embedded->addProfile($included); + $index->addProfile($embedded); + $included->leave(); + $embedded->leave(); + + $macro = new Twig_Profiler_Profile('index.twig', Twig_Profiler_Profile::MACRO, 'foo'); + $macro->leave(); + $index->addProfile($macro); + + $embedded = clone $embedded; + $index->addProfile($embedded); + $a = range(1, 1000); + $embedded->leave(); + $profile->leave(); + + usleep(5000); + $index->leave(); + + return $profile; + } +} diff --git a/test/Twig/Tests/Profiler/Dumper/BlackfireTest.php b/test/Twig/Tests/Profiler/Dumper/BlackfireTest.php new file mode 100644 index 0000000000..1a1b9d299b --- /dev/null +++ b/test/Twig/Tests/Profiler/Dumper/BlackfireTest.php @@ -0,0 +1,32 @@ +assertStringMatchesFormat(<<index.twig//1 %d %d %d +index.twig==>embedded.twig::block(body)//1 %d %d 0 +index.twig==>embedded.twig//2 %d %d %d +embedded.twig==>included.twig//2 %d %d %d +index.twig==>index.twig::macro(foo)//1 %d %d %d +EOF + , $dumper->dump($this->getProfile())); + } +} diff --git a/test/Twig/Tests/Profiler/Dumper/HtmlTest.php b/test/Twig/Tests/Profiler/Dumper/HtmlTest.php new file mode 100644 index 0000000000..1593a031cf --- /dev/null +++ b/test/Twig/Tests/Profiler/Dumper/HtmlTest.php @@ -0,0 +1,30 @@ +assertStringMatchesFormat(<<main +└ index.twig %d.%dms/%d% + └ embedded.twig::block(body) + └ embedded.twig + │ └ included.twig + └ index.twig::macro(foo) + └ embedded.twig + └ included.twig + +EOF + , $dumper->dump($this->getProfile())); + } +} diff --git a/test/Twig/Tests/Profiler/Dumper/TextTest.php b/test/Twig/Tests/Profiler/Dumper/TextTest.php new file mode 100644 index 0000000000..2fac9a7180 --- /dev/null +++ b/test/Twig/Tests/Profiler/Dumper/TextTest.php @@ -0,0 +1,30 @@ +assertStringMatchesFormat(<<dump($this->getProfile())); + } +} diff --git a/test/Twig/Tests/Profiler/ProfileTest.php b/test/Twig/Tests/Profiler/ProfileTest.php new file mode 100644 index 0000000000..43f5bc42fa --- /dev/null +++ b/test/Twig/Tests/Profiler/ProfileTest.php @@ -0,0 +1,99 @@ +assertEquals('template', $profile->getTemplate()); + $this->assertEquals('type', $profile->getType()); + $this->assertEquals('name', $profile->getName()); + } + + public function testIsRoot() + { + $profile = new Twig_Profiler_Profile('template', Twig_Profiler_Profile::ROOT); + $this->assertTrue($profile->isRoot()); + + $profile = new Twig_Profiler_Profile('template', Twig_Profiler_Profile::TEMPLATE); + $this->assertFalse($profile->isRoot()); + } + + public function testIsTemplate() + { + $profile = new Twig_Profiler_Profile('template', Twig_Profiler_Profile::TEMPLATE); + $this->assertTrue($profile->isTemplate()); + + $profile = new Twig_Profiler_Profile('template', Twig_Profiler_Profile::ROOT); + $this->assertFalse($profile->isTemplate()); + } + + public function testIsBlock() + { + $profile = new Twig_Profiler_Profile('template', Twig_Profiler_Profile::BLOCK); + $this->assertTrue($profile->isBlock()); + + $profile = new Twig_Profiler_Profile('template', Twig_Profiler_Profile::ROOT); + $this->assertFalse($profile->isBlock()); + } + + public function testIsMacro() + { + $profile = new Twig_Profiler_Profile('template', Twig_Profiler_Profile::MACRO); + $this->assertTrue($profile->isMacro()); + + $profile = new Twig_Profiler_Profile('template', Twig_Profiler_Profile::ROOT); + $this->assertFalse($profile->isMacro()); + } + + public function testGetAddProfile() + { + $profile = new Twig_Profiler_Profile(); + $profile->addProfile($a = new Twig_Profiler_Profile()); + $profile->addProfile($b = new Twig_Profiler_Profile()); + + $this->assertSame(array($a, $b), $profile->getProfiles()); + $this->assertSame(array($a, $b), iterator_to_array($profile)); + } + + public function testGetDuration() + { + $profile = new Twig_Profiler_Profile(); + $profile->leave(); + + $this->assertTrue($profile->getDuration() > 0); + } + + public function testSerialize() + { + $profile = new Twig_Profiler_Profile('template', 'type', 'name'); + $profile1 = new Twig_Profiler_Profile('template1', 'type1', 'name1'); + $profile->addProfile($profile1); + $profile->leave(); + $profile1->leave(); + + $profile2 = unserialize(serialize($profile)); + $profiles = $profile->getProfiles(); + $this->assertCount(1, $profiles); + $profile3 = $profiles[0]; + + $this->assertEquals($profile->getTemplate(), $profile2->getTemplate()); + $this->assertEquals($profile->getType(), $profile2->getType()); + $this->assertEquals($profile->getName(), $profile2->getName()); + $this->assertEquals($profile->getDuration(), $profile2->getDuration()); + + $this->assertEquals($profile1->getTemplate(), $profile3->getTemplate()); + $this->assertEquals($profile1->getType(), $profile3->getType()); + $this->assertEquals($profile1->getName(), $profile3->getName()); + } +}