feature twigphp#1597 added a profiler (fabpot)

This PR was merged into the 1.17-dev branch. Discussion ---------- added a profiler This profiler allows to better understand what's going on when rendering templates. It should be used when debug is true only as it adds some overhead. Here is a sample output in the text format: ``` main 567.04ms/100% └ index 463.28ms/82% └ base 463.24ms/82% └ base::block(header) └ index::block(content) 306.29ms/54% │ └ included 50.18ms/9% │ └ included 45.42ms/8% │ └ included 35.42ms/6% │ └ base::block(content) 104.97ms/19% │ │ └ included 34.90ms/6% │ └ included 35.84ms/6% └ base::block(footer) 156.84ms/28% └ included 38.96ms/7% └ base::macro(foo) ``` You can also dump a profile in a Blackfire compatible format to [visualise the data as a graph](http://goo.gl/RwNGFH). A profile is also a great way to be able to list all templates/blocks/macros that were used when rendering a template. A PR on Symfony (symfony/symfony#13428) integrates this profiler in the Symfony web profiler to replace the current TimedTwigEngine and to add a new Twig panel. ![symfony-web-profiler](https://cloud.githubusercontent.com/assets/47313/5755461/019cd6a4-9ca5-11e4-8762-68e2a709c336.png) Commits ------- 4408caa added a profiler
pounard · Jan 20, 2015 · a60a522 · a60a522
2 parents b40c555 + 4408caa
commit a60a522
Show file tree

Hide file tree

Showing 19 changed files with 816 additions and 5 deletions.
diff --git 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
@@ -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
@@ -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 <https://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
+<https://blackfire.io/signup>`_ 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
@@ -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
@@ -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
@@ -0,0 +1,52 @@
+<?php
+
+/*
+ * This file is part of Twig.
+ *
+ * (c) 2015 Fabien Potencier
+ *
+ * For the full copyright and license information, please view the LICENSE
+ * file that was distributed with this source code.
+ */
+
+class Twig_Extension_Profiler extends Twig_Extension
+{
+    private $actives;
+
+    public function __construct(Twig_Profiler_Profile $profile)
+    {
+        $this->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
@@ -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
@@ -0,0 +1,68 @@
+<?php
+
+/*
+ * This file is part of Twig.
+ *
+ * (c) 2015 Fabien Potencier
+ *
+ * For the full copyright and license information, please view the LICENSE
+ * file that was distributed with this source code.
+ */
+
+/**
+ * @author Fabien Potencier <[email protected]>
+ */
+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 = <<<EOF
+file-format: BlackfireProbe
+cost-dimensions: wt mu pmu
+request-start: {$start}
+
+
+EOF;
+
+        foreach ($data as $name => $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
@@ -0,0 +1,43 @@
+<?php
+
+/*
+ * This file is part of Twig.
+ *
+ * (c) 2015 Fabien Potencier
+ *
+ * For the full copyright and license information, please view the LICENSE
+ * file that was distributed with this source code.
+ */
+
+/**
+ * @author Fabien Potencier <[email protected]>
+ */
+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 '<pre>'.parent::dump($profile).'</pre>';
+    }
+
+    protected function formatTemplate(Twig_Profiler_Profile $profile, $prefix)
+    {
+        return sprintf('%s└ <span style="background-color: %s">%s</span>', $prefix, self::$colors['template'], $profile->getTemplate());
+    }
+
+    protected function formatNonTemplate(Twig_Profiler_Profile $profile, $prefix)
+    {
+        return sprintf('%s└ %s::%s(<span style="background-color: %s">%s</span>)', $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('<span style="color: %s">%.2fms/%.0f%%</span>', $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
@@ -0,0 +1,68 @@
+<?php
+
+/*
+ * This file is part of Twig.
+ *
+ * (c) 2015 Fabien Potencier
+ *
+ * For the full copyright and license information, please view the LICENSE
+ * file that was distributed with this source code.
+ */
+
+/**
+ * @author Fabien Potencier <[email protected]>
+ */
+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
@@ -0,0 +1,40 @@
+<?php
+
+/*
+ * This file is part of Twig.
+ *
+ * (c) 2015 Fabien Potencier
+ *
+ * For the full copyright and license information, please view the LICENSE
+ * file that was distributed with this source code.
+ */
+
+/**
+ * Represents a profile enter node.
+ *
+ * @author Fabien Potencier <[email protected]>
+ */
+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")
+        ;
+    }
+}