D8: Building for Twig Performance

(This article does not represent the current state of Drupal 8 development.)

There's been a lot of excitement over Drupal 8's switch to Twig, a modern templating engine written in object oriented PHP code, but the process of making the switch happen has been an adventure on its own. The plan to adopt Twig required abandoning PHPTemplate completely, which is a mammoth undertaking requiring converting every Drupal 8 core template and theme function to a Twig equivalent. Even with a feature freeze extension and a structured development plan, it still took a five day sprint to squeak past the deadline.

TraceView tracks calls into Twig templates, even if they're nested or called multiple times per page, and it presents the data more elegantly than the equivalent backtrace.

But even though Twig is locked in for Drupal 8, that's only the beginning of its story. Almost every contrib module touching the theme layer will require a rewrite, not to mention any custom development. Twig's syntax is relatively easy to learn, but getting a grip on its performance characteristics will be harder. Templating engines are notoriously tricky to comprehend because the separation between view and logic means that they perform a lot of work "behind the scenes," and even a seemingly simple tag might perform much more work than anticipated.

In Twig's architecture, though, tags aren't that simple. Since Twig templates are a domain-specific language rather than a hybrid of HTML and PHP like PHPTemplate, they can't be executed directly. Instead, Twig converts templates into executable PHP code. Developers can alter this process to add new functions and tags to their templates, or even change their basic syntax. It's even possible to extend Twig's mechanism for converting templates into PHP code with custom node visitors, allowing developers to exert even finer-grained control over the generated PHP. The upshot of all this extensibility is that a template's functionality and performance might vary greatly depending on what was done to convert it to PHP.

The way that Twig is deployed can also affect performance. Because compiled Twig templates are cached to disk, they can run into the same performance problems faced by the dependency injection container. And even after converting a template to PHP code, Twig provides a way to modify its behavior. The version of Twig used in Drupal 8 includes a PHP extension written in C that can optionally replace calls to Twig_Template::getAttribute(). This one weird trick could result in an almost 15% performance improvement on complex Twig templates just by replacing that hard-to-optimize PHP function with a faster C equivalent. However, the default Drupal configuration doesn't make use of it, or even hint that it's available.

Given this complexity, it's not surprising that during my time at DrupalCon Portland I had multiple developers ask whether AppNeta TraceView could provide insight into Twig performance. The Drupal.org entry on Twig debugging is nearly empty, but the Twig hackers I've spoken to have used a highly iteractive approach combined with a traditional profiler or debugger. This is effective, but it's not efficient, and the overhead and interpretability challenges cut right into how much work can be accomplished in a sprint.

Luckily, in my previous blog post on collecting data about kernel events, I rewrote the TraceView module to better account for Drupal's newly Symfonic architecture. Rather than just adding listeners to interesting events, I used Symfony's dependency injection to replace the default Symfony event dispatcher with a subclass containing the necessary TraceView API calls. This allowed for intercepting arbitrary events without having to know about them in advance... and after all, isn't that exactly the property you want to have for a templating engine's monitoring system?

My first Twig instrumentation target was the TwigEnvironment class, which is a Drupalized wrapper around Twig that gets registered as the twig service. Since swapping out the class used for a service is simple, I created a TraceviewTwigEnvironment class with appropriate calls inserted into render() and display(). Unfortunately, this didn't work. When I used TraceView to investigate why Twig layers weren't showing up, I realized that templates were being called directly via twig.engine (54) in Twig_Template->render(Array), completely bypassing the environment's helper functions.

My next step was to try overriding the display() and render() methods of the templates themselves; effectively, just what I'd done for TwigEnvironment, but at a deeper level. However, this required a different approach as the base template is an argument provided to the twig service rather than a service in its own right. Replacing only one argument isn't possible via YAML, so I instead assigned my modified base template class within PHP code in the TraceView module:

<?php 
 public function build(ContainerBuilder $container) {
   if (!$container->hasDefinition('twig')) {
     return;
   }
   $twig = $container->getDefinition('twig');
   // Retrives the second argument, which is an array containing configuration.
   $twig_config = $twig->getArgument(1);
   $twig_config['base_template_class'] = 'Drupal\traceview\Template\TraceviewTwigTemplate';
   $twig->replaceArgument(1, $twig_config);
   return;
 }
?> 

This approach worked beautifully, and I was able to turn my attention to comparing the rendering process in Drupal 7 and Drupal 8 sites:

TraceView segments the time spent in the default Tracker view on this Drupal 7 site. The highlighted span is a section of the ‘render' profile, which took about 140ms total.

In the Drupal 8 version of the Tracker view, the same ‘render' span (in white) is much smaller, taking just 10ms. However, that doesn't include Twig's templating time (in green) which takes place outside of Views (in brown).

Even at a glance it's clear that the adoption of Twig has brought huge changes to Drupal's request flow. But these traces also reveal that Twig is just one component of a larger theming process: While monitoring template time is important, a holistic picture of theme performance will still require insight into data retrieval and construction of renderable arrays. With that insight in mind, in my next article I'll be using this enhanced Twig support to investigate Views in more detail, including both its interaction with Twig and the dependency-injected Drupal 8 rewrite more generally.