Blackfire on Blackfire: Twig loops and escaping

By Romain Neutron, on Oct 22, 2015

The first principle we obey at Blackfire is to use our own product on a daily basis. As developers we are de-facto beta testers and reviewers of our own work.

Recently, I’ve been working on optimizing Twig and I’d like to share my findings about loops and escaping.

As you might know, Blackfire is built with PHP and uses Twig as its template engine. In the early days of Blackfire, we had some issues about memory consumption and intense CPU usage when displaying a profile graph page.

The graph view needs a lot of data, some are dynamically created by the browser based on a JSON file while some others are rendered server-side by Twig.

Here’s what we were doing:

{% extends "layout.html.twig" %}

{% block body_container %}
    <table>
    {% for key, call in graph.nodes %}
        {{ block('functioncall') }}
    {% endfor %}
    </table>
{% endblock %}

{% block functioncall %}
    {% spaceless %}
        <tr>
            <td title="{{ call.nodeId }}">
                <a href="#call={{ call.nodeId }}">{{ call.nodeId }}</a>
            </td>
            {% for dimension, data in graph.dimensions %}
                <td class="focus-{{ dimension }}">
                    <div class="hidden val-focus-{{ dimension }} val-self">
                        {{ call.exclusive_percentage[dimension]|abs }}
                    </div>
                    <div class="progress" data-dimension="{{ dimension }}" data-call-name="{{ call.nodeId }}">
                        <div class="progress-bar progress-bar-danger"
                             style="width: {{ call.exclusive_percentage[dimension]|abs }}%;">
                        </div>
                        <div class="progress-bar progress-bar-warning"
                             style="width: {{ call.inclusive_percentage[dimension]|abs }}%;">
                        </div>
                    </div>
                </td>
                <td class="hidden focus-{{ dimension }}">
                    <div class="val-focus-{{ dimension }} val-incl">
                        {{ call.inclusive_percentage[dimension]|abs }}
                    </div>
                </td>
            {% endfor %}
        </tr>
    {% endspaceless %}
{% endblock functioncall %}

Notice anything special? Personally, I’ve already seen such code and I’m okay with it. However, passing this template to Twig results in the following graph:

Twig

Observations

Some observations about this graph first:

  • The whole page takes 260ms to render;
  • We spend nearly 80ms in the functioncall Twig block, more than 30ms exclusively, for 275 calls;
  • twig_escape_filter consumes more than 30ms and is called nearly 15,000 times;
  • twig_template_get_attributes is called 15700 times using up to 7ms (and we are using the Twig C PHP extension);
  • The spaceless twig tag implies a preg_replace call that cost 5ms.

Improving the performance

In our case, we are absolutely confident about the data we manipulate. All of them have been prepared server side and none of them can contain user data. This eliminates XSS injection vulnerabilities that twig_escape_filter is used for.
twig_template_get_attributes is called many times, but if you read carefully, the same attribute is fetched multiple times from the call variable.

First, let’s avoid that on the data we’re sure by using the Twig autoescape tag. Then, let’s cache twig_template_get_attributes calls by setting a variable within the loop. Finally, let’s remove the spaceless tag from the loop and let’s use it at higher level.

 
 {% block body_container %}
+    {% spaceless %}
     <table>
     {% for key, call in graph.nodes %}
         {{ block('functioncall') }}
     {% endfor %}
     </table>
+    {% endspaceless %}
 {% endblock %}

 {% block functioncall %}
-    {% spaceless %}
+    {% set nodeId = call.nodeId %}
     <tr>
+        {% autoescape false %}
-        <td title="{{ call.nodeId }}">
-            <a href="#call={{ call.nodeId }}">{{ call.nodeId }}</a>
+        <td title="{{ nodeId }}">
+            <a href="#call={{ nodeId }}">{{ nodeId }}</a>
         </td>
         {% for dimension, data in graph.dimensions %}
+            {% set inclusive_dim = call.inclusive_percentage[dimension]|abs %} 
+            {% set exclusive_dim = call.exclusive_percentage[dimension]|abs %}
             <td class="focus-{{ dimension }}">
                 <div class="hidden val-focus-{{ dimension }} val-self">
-                    {{ call.exclusive_percentage[dimension]|abs }}
+                    {{ exclusive_dim }}
                 </div>
-                <div class="progress" data-dimension="{{ dimension }}" data-call-name="{{ call.nodeId }}">
+                <div class="progress" data-dimension="{{ dimension }}" data-call-name="{{ nodeId }}">
                     <div class="progress-bar progress-bar-danger"
-                         style="width: {{ call.exclusive_percentage[dimension]|abs }}%;">
+                         style="width: {{ exclusive_dim }}%;">
                     </div>
                     <div class="progress-bar progress-bar-warning"
-                         style="width: {{ call.inclusive_percentage[dimension]|abs }}%;">
+                         style="width: {{ inclusive_dim }}%;">
                     </div>
                 </div>
             </td>
-                    {{ call.inclusive_percentage[dimension]|abs }}
+                    {{ inclusive_dim }}
                 </div>
             </td>
         {% endfor %}
+        {% endautoescape %}
     </tr>
-    {% endspaceless %}
 {% endblock functioncall %}

Comparison

Twig comparison

We saved 53ms for the page rendering:

  • twig_escape_filter has now disappeared and that saves 33ms;
  • twig_template_get_attributes is now less than 5ms;
  • preg_replace is now called once instead of 255 times and is not noticeable anymore;
  • The functioncall block is now faster but use more than 1MB of memory by storing more variables;
  • The page now takes 206ms to be rendered.

That’s quite an improvement!

Being an expert in a language or framework does not mean you control everything that happen at runtime. Blackfire is definitely my new glasses that help me spot what’s important to tweak before delivering it in production.

Enjoy these glasses, it’s free 🙂

Romain Neutron

Romain is a developer at Blackfire.io. He started programming years ago while he was studying physics. He loved it so much he stopped his studies to be a programmer and contributed to various open source projects. He joined SensioLabs in 2014 to work on Blackfire and discovered a new love in application performance.