fromJune 2014
Article:

Different, Not Difficult

A Year Learning D8 the Hard Way
0

As AppNeta’s developer evangelist, I work with customers in five different programming languages to monitor application performance. Drupal is just one part of one language, but I’ll always have a soft spot for it because it’s where I learned to program. When I get a chance, I like to keep my skills sharp by contributing to the community-maintained TraceView integration module. Last spring, I decided to port it and learn Drupal 8 the hard way.

Like most Drupal developers, I’d never tried writing Symfony code or using Composer to manage packages. Before attempting it, I decided to research both Symfony in its own right and how it is being leveraged to rewrite Drupal. Thankfully, there were many rich tutorials on “the basics” even then, and, after a relatively painless porting process, I had the module running with a skeletal Symfony bundle inside it.

Initially, I relied on the same strategy as the Drupal 7 version of the TraceView module, which monitors hook execution time by installing two additional modules: an “early” module with a very low weight and a “late” module with a very high weight. As each hook was removed from core, I moved its implementations from the modules into the bundle and tagged that event with listeners at maximum and minimum priority.

/**
 * Implements EventSubscriberInterface::getSubscribedEvents().
 */
static function getSubscribedEvents() {
  // Register before and after listeners for the primary kernel events.
  $events[KernelEvents::REQUEST][] = array('beforeRequest', 255);
  $events[KernelEvents::REQUEST][] = array('afterRequest', -255);
  $events[KernelEvents::VIEW][] = array('beforeView', 255);
  $events[KernelEvents::VIEW][] = array('afterView', -255);
  $events[KernelEvents::CONTROLLER][] = array('beforeController', 255);
  $events[KernelEvents::CONTROLLER][] = array('afterController', -255);
  $events[KernelEvents::RESPONSE][] = array('beforeResponse', 255);
  $events[KernelEvents::RESPONSE][] = array('afterResponse', -255);
  $events[KernelEvents::TERMINATE][] = array('beforeTerminate', 255);
  $events[KernelEvents::TERMINATE][] = array('afterTerminate', -255);
  // Exceptions are handled differently.
  $events[KernelEvents::EXCEPTION][] = array('onException', -255);
  return $events;
}

That mostly worked, but TraceView tracks calls by logging entry and exit events, and I was generating many entries with no matching exit. The shift away from Drupal’s familiar hooks to Symfony’s event listeners had caught me off guard: unlike Drupal hooks, which always run to completion, Symfony event listeners can call stopPropagation at any time to “consume” the event and prevent lower-priority listeners from responding!

My initial workaround was to turn the low-priority `view` listener into a high-priority listener on `response`, the event immediately afterwards. While error-prone, it was consistent enough to serve as an alpha. We kept this version running as our booth demo at DrupalCon Portland, much to the surprise of everyone who stopped by. I even got to meet the team from SensioLabs, who gave me some tips about how to improve the codebase.

When I came back to the module late that summer, I rewrote it to better account for Drupal's new architecture. Rather than just adding listeners to interesting kernel events, I used dependency injection (via traceview.services.yml) to replace the default Symfony event dispatcher with a subclass that wrapped the dispatch() method in TraceView API calls. This allowed for intercepting arbitrary events without having to know about them in advance, a significant improvement over my initial KernelEventSubscriber.

class TraceviewContainerAwareEventDispatcher extends ContainerAwareEventDispatcher
{
 
  /**
   * {@inheritDoc}
   *
   * Lazily loads listeners for this event from the dependency injection
   * container.
   *
   * @throws \InvalidArgumentException if the service is not defined
   */
  public function dispatch($eventName, Event $event = null)
  {
 
    // Check whether this is a kernel request or response.
    $is_request = ($eventName === "kernel.request");
    $is_response = ($eventName === "kernel.response");
 
    // On the start of a request, start a request layer.
    if ($is_request) {
      oboe_log(($event->getRequestType() === HttpKernelInterface::MASTER_REQUEST) ? 'HttpKernel.master_request' : 'HttpKernel.sub_request', "entry", array(), TRUE);
    }

    // Create a profile if the event has any listeners.
    if ($this->hasListeners($eventName)) {
      oboe_log("profile_entry", array('ProfileName' => $eventName), TRUE);
    }

    // Dispatch the event as normal.
    $ret = parent::dispatch($eventName, $event);

    // Capture controller/action information.
    if ($eventName === "kernel.controller") {
      $event_controller = $ret->getController();

      // Handle the closure case, as per LegacyControllerSubscriber.
      if (is_callable($event_controller) && is_object($event_controller)) {
        $router_item = $event->getRequest()->attributes->get('drupal_menu_item');
        $controller = $router_item['page_callback'];
        $action = (isset($router_item['page_arguments'][0])) ? $router_item['page_arguments'][0] : NULL;
        // Default to the object-based case.
      } else {
        $controller = $event_controller[0];
        $action = $event_controller[1];
      }
      // Report the C/A pair.
      oboe_log('info', array("Controller" => (is_object($controller)) ? get_class($controller) : $controller, "Action" => (is_object($action)) ? get_class($action) : $action));
    }
 
    // End the profile if the event has any listeners.
    if ($this->hasListeners($eventName)) {
      oboe_log("profile_exit", array('ProfileName' => $eventName));
    }
 
    // On the end of a response, stop the request layer.
    if ($is_response) {
      oboe_log(($event->getRequestType() === HttpKernelInterface::MASTER_REQUEST) ? 'HttpKernel.master_request' : 'HttpKernel.sub_request', "exit", array());
    }
 
    return $ret;
  }
}

While I was at DrupalCon Portland, multiple developers asked whether TraceView could be extended to monitor Twig performance. Since then, Twig was finalized as Drupal 8’s templating system, so I decided to give it my best shot. But since Twig isn’t based on HTTPKernel and doesn’t use kernel events, I couldn’t reuse my EventDispatcher subclass.

Instead, my first Twig instrumentation target was the TwigEnvironment class, which is a Drupalized wrapper around Twig that gets registered as the `twig` service. I created a TraceviewTwigEnvironment class with appropriate monitoring inserted into its render() and display() methods.

Unfortunately, this didn’t work. After some investigation, I realized that unlike the EventDispatcher, Twig isn’t registered in core.services.yml. Instead, it gets registered in CoreServiceProvider so that it can be used during installation, meaning that I had to add a ServiceProvider of my own containing a CompilerPass that did the same thing.

Even this provided inconsistent results though; in some cases templates were being called directly rather than through the environment’s helper functions. The best approach was to override the display() and render() methods of the templates themselves – effectively what I'd done for TwigEnvironment, but at a deeper level.

abstract class TraceviewTwigTemplate extends TwigTemplate {
  /**
   * {@inheritdoc}
   */
  public function display(array $context, array $blocks = array())
  {
    oboe_log("profile_entry", array('ProfileName' => $this->getTemplateName()), TRUE);
    $this->displayWithErrorHandling($this->env->mergeGlobals($context), $blocks);
    oboe_log("profile_exit", array('ProfileName' => $this->getTemplateName()));
  }
}

I updated to more recent alphas a few times that fall, but the next major adjustment came in early 2014. Another project had me revisiting the Symfony bundle that I had split off from the Drupal 8 module almost a year ago. After I made it available on Packagist, I decided to take code reuse in the other direction.
Unfortunately, the only way for a module to provide a Symfony bundle’s classes is to include them with the module, so I began by copying over the shiny new Symfony code. It was a welcome surprise to see that the only immediate adjustment I needed to make was namespace-related!
However, progress had indeed marched on.
By this point, I had refactored the TraceView bundle to reuse the Symfony web toolbar’s controller/action reporting code. This worked in Drupal, but it yielded less than satisfactory results because so many controllers are actually proxies. In fact, an HtmlPageController can be a proxy for something like an HtmlFormController, which itself is a proxy for a specific form! Unfortunately, filtering these cases to provide more human-friendly strings proved to be a tedious task.

/**
 * Parse a Symfony controller into a TraceView-reportable format.
 */
public function parseController($request, $controller) {
  $parsed = array('Controller' => NULL, 'Action' => NULL);

  // We use the same logic as the Symfony debug toolbar to parse out controller/action.
  if (is_array($controller)) {
    $parsed['Controller'] = $controller[0];
    $parsed['Action'] = $controller[1];
  } elseif ($controller instanceof \Closure) {
    $r = new \ReflectionFunction($controller);
    $parsed['Controller'] = $r->getName();
    $parsed['Action'] = NULL;
  } elseif (is_string($controller)) {
    // Controller::action strings
    if (strpos($controller, '::') !== FALSE) {
    $ca = explode("::", $controller);
    $parsed['Controller'] = $ca[0];
    $parsed['Action'] = $ca[1];
    // Any other string
  } else {
    $parsed['Controller'] = $controller;
  }

  // Proxy controller for a full HTML page. Re-parse the underlying controller.
  if (is_a($parsed['Controller'], 'Drupal\Core\Controller\HtmlPageController')) {
    return $this->parseController($request, $request->attributes->get("_content"));
  }

  // Proxy controller for an HTML form. Use the matching form
  // (e.g., 'Drupal\system\Form\ModulesListForm') as the action.
  if (is_a($parsed['Controller'], 'Drupal\Core\Controller\HtmlFormController')) {
    $parsed['Action'] = $request->attributes->get("_form");
  }

  // Proxy class for an HTML entity form. Use the matching entity form
  // (e.g., 'node.edit') as the action.
  if (is_a($parsed['Controller'], 'Drupal\Core\Entity\HtmlEntityFormController')) {
    $parsed['Action'] = $request->attributes->get("_entity_form");
  }
 
  // Proxy class for a View. Use the matching View ID and display ID.
  if ($parsed['Controller'] === 'Drupal\views\Routing\ViewPageController') {
    $parsed['Controller'] = 'ViewPageController::'.$request->attributes->get('view_id');
    $parsed['Action'] = $request->attributes->get('display_id');
  }

  return $parsed;
}

I’ve spent a decent amount of time diving into the guts of Drupal 8 over the past year, and I’ve learned more about it than I ever expected to. Even so, I wouldn’t say I feel comfortable using it, and my guess is that many Drupal developers will face a rough start given how many Drupalisms have been axed. On balance, this is probably good, but there’s a whole new set of concepts to internalize. Drupal 8 may be more logical and consistent than Drupal 7, but it’s downright sprawling in comparison.

On the other hand, Symfony developers shouldn’t expect to have a head start; Drupal 8 is not particularly Symfonic. Some Symfony standards, like bundles and routing, are just different enough to not apply here, and even the reused parts have a thick layer of Drupal on top. Your development will necessarily take place inside Drupal modules – and it’s not even possible to track their dependencies because they aren’t visible to Composer.

But is it a problem if neither set of developers feels at home in Drupal 8? Anyone writing Drupal code has already stuck around past the “learning cliff,” and it’s not clear that Drupal 8 being different has any relationship with it being hard. It’s reasonable to worry about where you’ll be by Day 30 – just don’t forget to wonder about what you’ll be building on Day 365.

Image: ©iStockphoto.com/emesilva

Advertisement

From our blog

Entity Storage, the Drupal 8 Way

In Drupal 7 the Field API introduced the concept of swappable field storage.

The Drupal 6 to 8 Upgrade Challenge - Part 2

Having concluded the readiness assessment, we turn next to migrating the content and configuration. In reality, there’s little chance that we would migrate anything but the blogs from our old site. For the sake of giving Migrate in Core a workout with real conditions, however, we’re going to upgrade with core’s Migrate Drupal module rather than rebuilding.

The Drupal 6 to 8 Upgrade Challenge - Part 1

Nathaniel Catchpole , the Drupal 8 release maintainer and Tag1 Senior Performance Engineer, suggested that Drupal shops everywhere could support the

DrupalCon Austin

The entertainment industry is not for the faint of heart.

Drupal Watchdog Joins the Linux New Media Family
Drupal Watchdog 6.01 is the first issue published by Linux New Media.

Drupal Watchdog 6.01 is the first issue published by Linux New Media. Come see the Drupal Watchdog team at DrupalCon 2016!

Drupal Watchdog was founded in 2011 by Tag1 Consulting as a resource for the Drupal community to share news and information. Now in its sixth year, Drupal Watchdog is ready to expand to meet the needs of this growing community.

Drupal Watchdog will now be published by Linux New Media, aptly described as the Pulse of Open Source.

Welcome to DrupalCon Barcelona - The Director's Cut

For all you schedule-challenged CEOs – and ADHD coders – this Abbreviated Official Director’s Cut is just what the doctor ordered.

Welcome to DrupalCon - The Barcelona Edition

Did we have fun in Barcelona?
OMG, yes!

Did we eat all the tapas on the menu and wash them down with pitchers of sangria?
Yes indeed!

Recursive Closures and How to Get Rid of Them

This came up while manipulating taxonomy children and their children recursively, so it’s as not far from Drupal as you’d think.