Added a Twig profiler #13428

Merged
merged 2 commits into from Jan 25, 2015

Conversation

Projects
None yet
@fabpot
Member

fabpot commented Jan 16, 2015

Q A
Bug fix? no
New feature? yes
BC breaks? no
Deprecations? yes
Tests pass? yes
Fixed tickets #6914
License MIT
Doc PR n/a

This PR integrates the new Twig 1.18 Profiler (see twigphp/Twig#1597) into Symfony (replace the current TimedTwigEngine) and adds a new Twig panel.

The timers are now available for all rendered templates (TimedTwigEngine was only able to get information from a few of them -- mainly the first template only).

The Twig panel gives you a lot of information about the execution of the templates, including a call graph.

image

image

image

image

image

@fabpot fabpot referenced this pull request in twigphp/Twig Jan 16, 2015

Merged

added a profiler #1597

@wimleers

This comment has been minimized.

Show comment
Hide comment
@wimleers

wimleers Jan 16, 2015

Very much looking forward to having this in Drupal 8! (Via https://www.drupal.org/project/webprofiler .)

Very much looking forward to having this in Drupal 8! (Via https://www.drupal.org/project/webprofiler .)

+ /**
+ * {@inheritdoc}
+ */
+ public function collect(Request $request, Response $response, \Exception $exception = null)

This comment has been minimized.

@stof

stof Jan 16, 2015

Member

shouldn't this use lateCollect to take into account templates rendered later (in a streamed response for instance) ?

@stof

stof Jan 16, 2015

Member

shouldn't this use lateCollect to take into account templates rendered later (in a streamed response for instance) ?

This comment has been minimized.

@fabpot

fabpot Jan 16, 2015

Member

I went back and forth on this one, but the current version is probably fine with the late data collector.

@fabpot

fabpot Jan 16, 2015

Member

I went back and forth on this one, but the current version is probably fine with the late data collector.

This comment has been minimized.

@fabpot

fabpot Jan 16, 2015

Member

done

@stof stof referenced this pull request in Elao/WebProfilerExtraBundle Jan 16, 2015

Closed

Conflict with Symfony core collectors #50

+ <argument type="service" id="debug.stopwatch" on-invalid="ignore" />
+ </service>
+
+ <service id="twig.profile" class="Twig_Profiler_Profile" />

This comment has been minimized.

@stof

stof Jan 16, 2015

Member

this service is only meant to be accessed by twig.extension.profiler and data_collector.twig. It does not need to be retrieved dynamically. Right ? If yes, it could be marked private

@stof

stof Jan 16, 2015

Member

this service is only meant to be accessed by twig.extension.profiler and data_collector.twig. It does not need to be retrieved dynamically. Right ? If yes, it could be marked private

This comment has been minimized.

@fabpot

fabpot Jan 16, 2015

Member

I made public because you might want to get the profile from a CLI tool or something else. It is available through the data collector, but exposing it directly seems like a better idea.

@fabpot

fabpot Jan 16, 2015

Member

I made public because you might want to get the profile from a CLI tool or something else. It is available through the data collector, but exposing it directly seems like a better idea.

This comment has been minimized.

@stof

stof Jan 16, 2015

Member

fine with me (making it private would not allow inlining it anyway, as it is referenced twice)

@stof

stof Jan 16, 2015

Member

fine with me (making it private would not allow inlining it anyway, as it is referenced twice)

+ {% set time = collector.templatecount|length ? '%0.0f ms'|format(collector.time) : 'n/a' %}
+ {% set icon %}
+ <img height="28" alt="Twig" src="data:image/png;base64,iVBORw0KGgoAAAANSUhEUgAAABUAAAAcCAYAAACOGPReAAAACXBIWXMAAAsTAAALEwEAmpwYAAAAbElEQVRIx2NgGAXUBowMDAwMaWlp/6ll4KxZsxhZYJy0tDRqGMjAwMDAwEQL77OgCxSXlJBsSG9PDwqfJi6lj/fRvTJ4XYocUTBXE4q8oRtRRBnKwsw8RFw6fA0lKkd1dnYOIpfCCthRMIIAAI0IFu9Hxh7ZAAAAAElFTkSuQmCC" />
+ <span>{{ time }}</span>

This comment has been minimized.

@stof

stof Jan 16, 2015

Member

you should add class="sf-toolbar-status" so that the time gets hidden on smaller screens (smartphones for instance)

@stof

stof Jan 16, 2015

Member

you should add class="sf-toolbar-status" so that the time gets hidden on smaller screens (smartphones for instance)

This comment has been minimized.

@stof

stof Jan 16, 2015

Member

you should add class="sf-toolbar-status" so that the time gets hidden on smaller screens (smartphones for instance)

@stof

stof Jan 16, 2015

Member

you should add class="sf-toolbar-status" so that the time gets hidden on smaller screens (smartphones for instance)

+{% extends '@WebProfiler/Profiler/layout.html.twig' %}
+
+{% block toolbar %}
+ {% set time = collector.templatecount|length ? '%0.0f ms'|format(collector.time) : 'n/a' %}

This comment has been minimized.

@stof

stof Jan 16, 2015

Member

why using |length on an integer ? It is confusing

@stof

stof Jan 16, 2015

Member

why using |length on an integer ? It is confusing

+{% block toolbar %}
+ {% set time = collector.templatecount|length ? '%0.0f ms'|format(collector.time) : 'n/a' %}
+ {% set icon %}
+ <img height="28" alt="Twig" src="data:image/png;base64,iVBORw0KGgoAAAANSUhEUgAAABUAAAAcCAYAAACOGPReAAAACXBIWXMAAAsTAAALEwEAmpwYAAAAbElEQVRIx2NgGAXUBowMDAwMaWlp/6ll4KxZsxhZYJy0tDRqGMjAwMDAwEQL77OgCxSXlJBsSG9PDwqfJi6lj/fRvTJ4XYocUTBXE4q8oRtRRBnKwsw8RFw6fA0lKkd1dnYOIpfCCthRMIIAAI0IFu9Hxh7ZAAAAAElFTkSuQmCC" />

This comment has been minimized.

@stof

stof Jan 16, 2015

Member

this will need to be converted to SVG when merging #13298 /cc @sgrodzicki

@stof

stof Jan 16, 2015

Member

this will need to be converted to SVG when merging #13298 /cc @sgrodzicki

+ </tr>
+ <tr>
+ <th>Block Calls</th>
+ <td><pre>{{ collector.blockcount }}</pre></td>

This comment has been minimized.

@stof

stof Jan 16, 2015

Member

do we really need a <pre> tag to render an integer ?

@stof

stof Jan 16, 2015

Member

do we really need a <pre> tag to render an integer ?

+ <table>
+ <tr>
+ <th scope="col" style="width: 25%">Template Name</th>
+ <th scope="col" style="width: 75%">Render Count</th>

This comment has been minimized.

@stof

stof Jan 16, 2015

Member

should we really force this ratio ? The name of the template is likely to be much longer than the number of calls (unless you render the same template billion times)

@stof

stof Jan 16, 2015

Member

should we really force this ratio ? The name of the template is likely to be much longer than the number of calls (unless you render the same template billion times)

@stof

This comment has been minimized.

Show comment
Hide comment
@stof

stof Jan 16, 2015

Member

the composer.json of the TwigBridge needs to be updated to Twig ~1.18

Member

stof commented Jan 16, 2015

the composer.json of the TwigBridge needs to be updated to Twig ~1.18

@@ -63,13 +63,12 @@ public function process(ContainerBuilder $container)
$container->getDefinition('twig.extension.code')->replaceArgument(0, $container->getParameter('templating.helper.code.file_link_format'));
}
+ if ($container->getParameter('kernel.debug') && $container->has('debug.stopwatch')) {

This comment has been minimized.

@stof

stof Jan 16, 2015

Member

should it really be tied to the presence of debug.stopwatch (which is optional in the service definition already) ? this would prevent getting the Twig profiling data when you don't have the Stopwatch

@stof

stof Jan 16, 2015

Member

should it really be tied to the presence of debug.stopwatch (which is optional in the service definition already) ? this would prevent getting the Twig profiling data when you don't have the Stopwatch

@@ -71,6 +71,18 @@
<argument type="service" id="templating.locator" />
</service>
+ <service id="twig.extension.profiler" class="Symfony\Bridge\Twig\Extension\ProfilerExtension" public="false">
+ <argument type="service" id="twig.profile" />
+ <argument type="service" id="debug.stopwatch" on-invalid="ignore" />

This comment has been minimized.

@stof

stof Jan 16, 2015

Member

on-invalid="ignore" is invalid because the argument is mandatory in the class

@stof

stof Jan 16, 2015

Member

on-invalid="ignore" is invalid because the argument is mandatory in the class

@hhamon

This comment has been minimized.

Show comment
Hide comment
@hhamon

hhamon Jan 16, 2015

Contributor

Oh yeah! This feature is very welcomed! Really nice to have.

Contributor

hhamon commented Jan 16, 2015

Oh yeah! This feature is very welcomed! Really nice to have.

@fabpot fabpot added the TwigBundle label Jan 16, 2015

+ {
+ $this->getProfile();
+
+ return $this->computed['templates'];

This comment has been minimized.

@jderusse

jderusse Jan 16, 2015

Contributor

IMO, it's weird to call a getter before reading a property wich seem to not be related to the previous call
What's about

public function getComputedData($key)
{
    if (null === $this->computed ) {
        $this->computed = $this->computeData($this->getProfile());
    }

    return $this->computed[$key];
}
@jderusse

jderusse Jan 16, 2015

Contributor

IMO, it's weird to call a getter before reading a property wich seem to not be related to the previous call
What's about

public function getComputedData($key)
{
    if (null === $this->computed ) {
        $this->computed = $this->computeData($this->getProfile());
    }

    return $this->computed[$key];
}
@emmanuelballery

This comment has been minimized.

Show comment
Hide comment
@emmanuelballery

emmanuelballery Jan 16, 2015

👍 ! Really great !

👍 ! Really great !

@Haehnchen

This comment has been minimized.

Show comment
Hide comment
@Haehnchen

Haehnchen Jan 16, 2015

Contributor

quick idea: would be nice to dump template context vars also. allows me to provide ide completion.

Contributor

Haehnchen commented Jan 16, 2015

quick idea: would be nice to dump template context vars also. allows me to provide ide completion.

@aitboudad

This comment has been minimized.

Show comment
Hide comment
@aitboudad

aitboudad Jan 18, 2015

Contributor

👍

Contributor

aitboudad commented Jan 18, 2015

👍

fabpot added a commit to twigphp/Twig that referenced this pull request Jan 20, 2015

feature #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

@fabpot fabpot merged commit daad64f into symfony:2.7 Jan 25, 2015

1 of 2 checks passed

continuous-integration/travis-ci The Travis CI build is in progress
Details
fabbot.io Your code looks good.
Details

fabpot added a commit that referenced this pull request Jan 25, 2015

feature #13428 Added a Twig profiler (fabpot)
This PR was merged into the 2.7 branch.

Discussion
----------

Added a Twig profiler

| Q             | A
| ------------- | ---
| Bug fix?      | no
| New feature?  | yes
| BC breaks?    | no
| Deprecations? | yes
| Tests pass?   | yes
| Fixed tickets | #6914
| License       | MIT
| Doc PR        | n/a

This PR integrates the new Twig 1.18 Profiler (see twigphp/Twig#1597) into Symfony (replace the current TimedTwigEngine) and adds  a new Twig panel.

The timers are now available for all rendered templates (TimedTwigEngine was only able to get information from a few of them -- mainly the first template only).

The Twig panel gives you a lot of information about the execution of the templates, including a call graph.

![image](https://cloud.githubusercontent.com/assets/47313/5773885/fdf6756e-9d67-11e4-8dce-5ec20b07eca9.png)

![image](https://cloud.githubusercontent.com/assets/47313/5773892/0ae24d5c-9d68-11e4-9cbe-767bc31c9152.png)

![image](https://cloud.githubusercontent.com/assets/47313/5773897/13c0b6b6-9d68-11e4-95a1-b9188aca9651.png)

![image](https://cloud.githubusercontent.com/assets/47313/5773902/1c5498d8-9d68-11e4-975e-9822385fb836.png)

![image](https://cloud.githubusercontent.com/assets/47313/5773917/4eba00ba-9d68-11e4-8114-0a2d05eae5ea.png)

Commits
-------

daad64f added a Twig panel to the WebProfiler
ef0c967 integrated the Twig profiler
@rande

This comment has been minimized.

Show comment
Hide comment
@rande

rande Jan 25, 2015

Contributor

very nice!

Contributor

rande commented Jan 25, 2015

very nice!

fabpot added a commit that referenced this pull request Jan 25, 2015

minor #13520 [twig] Fix getComputedData in new twig profiler (jeremy-…
…derusse)

This PR was merged into the 2.7 branch.

Discussion
----------

[twig] Fix getComputedData in new twig profiler

| Q             | A
| ------------- | ---
| Bug fix?      | yes
| New feature?  | no
| BC breaks?    | no
| Deprecations? | no
| Tests pass?   | should be
| Fixed tickets | NA
| License       | MIT
| Doc PR        | NA

Add a small fix to #13428

Commits
-------

e8ca06a Fix getComputedData
@ikhsan017

This comment has been minimized.

Show comment
Hide comment
@ikhsan017

ikhsan017 Jan 26, 2015

great one!

but how to enable it in the silex web profiler?

great one!

but how to enable it in the silex web profiler?

@fabpot fabpot deleted the fabpot:twig-profiler branch Feb 12, 2015

+ $this->computed = $this->computeData($this->getProfile());
+ }
+
+ return $this->computed['index'];

This comment has been minimized.

@nike-17

nike-17 Feb 12, 2015

should be $this->computed[$index];

@nike-17

nike-17 Feb 12, 2015

should be $this->computed[$index];

This comment has been minimized.

@jderusse

jderusse Feb 12, 2015

Contributor

@nike-17 Fixed by #13520

@jderusse

jderusse Feb 12, 2015

Contributor

@nike-17 Fixed by #13520

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment