About the speakers

• Drupal development, consulting and training since 2007
• Based in Montreal, clients in Canada and USA
• Very involved with the Drupal community
• Specialties
  • Content migration
  • Design and responsive themes
  • Module dev: custom applications built on Drupal
  • Infrastructure, Multilingual content, Solr search UI
• Extensive Drupal training program

Outline

• Profiling methodology + philosophy
• Blackfire demo and discussion
• Case studies from our projects

Motivation

Why page loading time is SUPER IMPORTANT

• User experience
• Concurrency + scalability
  • "Throw more hardware at it"
• Financial implications
• Google's history

What profiling doesn't measure

• Browser rendering time (HTML, CSS)
• Network issues
• JavaScript run-time
• Asset fetching (imgs, fonts)

What profiling measures

• Time spent
• Resource usage: CPU, memory, DB, network, I/O
• Hooks into PHP engine, instruments each function call

Why it matters for Drupal

• Real Drupal sites can be heavy
  • Core is usually well-optimized, but not always
  • Contrib varies in quality, custom + legacy code more so
• Varnish isn't enough
• Working on slow sites makes us sad

Profiling gets results, fast

How to profile: M.A.F.I.A.

How to profile: Measure

• Figure out exactly what you care about (request, cookies)
• Variations, eg: pages, server env, disable modules…
• Use a profiler to analyze code

How to profile: Analyze

• Look for low hanging fruit, bottlenecks
  • cachable calculations, bad SQL, blocking requests, unnecessary loads…
• Look for signs of overall sluggishness
  • eg: swapping, Vagrant shared folders, server contention, missing opcache

How to profile: Fix

• Make a change
• Compare to baseline
  • In Drupal, static caching means removing "slow" code just pushes it to later in request

How to profile: Iterate

• Measure again
• Know when to stop profiling
  • Decide what's "fast enough"
• Log your runs, later it will be hard to remember all you've changed

How to profile: Applause

• I couldn't come up with a better "A"

Measurement tools

• Front-end: Chrome Developer Tools
• Benchmark: ApacheBench, JMeter
• Application Performance Monitoring: New Relic
• PHP Profiling: xhprof, Blackfire

Blackfire.io

• By SensioLabs, creators of Symfony and Twig
• Freemium, SaaS
• Great docs
• Started as a fork of xhprof
  • Simpler installation
  • Interactive callgraph, better UX
  • Supports comparisons
  • Actively maintained, support for PHP 7
  • No overhead, you can leave it on all the time

Case study: McGill U

McGill University listing of courses and programs.

Case study: McGill U

Let's profile a page with Blackfire!

The slow code

public function loadAcademicFacultyNodes($language, $key){
  foreach($this->faculties as $f){
    if ($f->nid && $f->code){
      if (!$language || $f->language === $language){
        $node = node_load($f->nid);
        if ($key && $f->$key){
          $return[$f->$key] = $node;
        } else {
          $return[] = $node;
        }
      }
    }
  }
  // ...
}

Iterate over faculties, load nodes one at a time.

A fix

public function loadAcademicFacultyNodes($language, $key){
  foreach($this->faculties as $f){
    if ($f->nid && $f->code){
      if (!$language || $f->language === $language){
        if ($key && $f->$key){
          $nids[$f->$key] = $f->nid;
        } else {
          $nids[] = $f->nid;
        }
      }
    }
  }

  $nodes = node_load_multiple($nids);
  // ...
}

Collect the nids, load all nodes at once.

Case study: McGill U

Saved about 25ms!

A real improvement in under an hour of total work, from profiling to committing a fix.

Installing Blackfire

Sign in with GitHub, then view the super-easy Blackfire Install Docs.

Blackfire features

• Comparison with baseline profile
• Command line profile trigger (for AJAX, cookies, POST requests, web services)
• Profiling command-line / drush commands
  • blackfire run drush.launcher cc all
• Sharing profiles publicly

Case study: Client X

The problem

Homepage is slow

Let's check it out in Chrome inspector's Network tab:

Profiling

Use Chrome's Copy as cURL:

Profiling

Give the results of Copy as cURL to Blackfire:

Profiling

Blackfire does its magic:

Analysis

function tq_home_preprocess_page(&$variables) {
  // ...
  $lang = locale_language_from_browser($languages);
  drupal_goto('<front>', $lang);
}

Moved it to a hook_init!

Case study: Client X

• Much better performance!
• We learned a lot about an unfamiliar codebase
• After a few more hours, implemented other dramatic improvements

Blackfire tips

Blackfire tips

• Aggregation (10 requests, averaged)
  • Disable aggregation to control for caching and side effects
• Blackfire doesn't keep function arguments

Blackfire tips

• xdebug
  • Turn off for profiling
  • Turn on for analysis
• profiling overhead
• Tradeoff: memory vs time
• SDK: enableProbe / disableProbe

Case study: evolvingweb.ca

Case study: evolvingweb.ca

We already upgraded our site to Drupal 8!

D8 is great, we love features like Views in core, CKEditor, Twig…

But it's slower than D7

Blog view

Really fast when cached!

No so fast after any node is edited, and D8 invalidates cache tags

Uncached requests

Aggregation makes it hard to profile uncached behavior.

So at the start of each request, pretend a node was edited:

class EwsiteSubscriber implements EventSubscriberInterface {
  public static function getSubscribedEvents() {
    $events[KernelEvents::REQUEST][] = ['killBlogCache'];
    return $events;
  }

  public function killBlogCache(GetResponseEvent $event) {
    $tags = ['node_list', 'node:239'];
    \Drupal::service("cache_tags.invalidator")->invalidateTags($tags);
  }
}

Profiling

Now let's see why it's so slow:

That's part of D8 core, and it's taking 117 ms!

Analysis

public function getVisibleBlocksPerRegion(array &$cacheable_metadata = []) {
  // ...
  foreach ($this->blockStorage->loadByProperties(array('theme' => $active_theme->getName())) as $block_id => $block) {
    $access = $block->access('view', NULL, TRUE);
    // ....
  }
}

To get a list of blocks, Drupal 8:

• Loads every single block in the current theme just to check access
• Checks access using visibility conditions—pretty complex!

Does this sound familiar?

node_access!

A fix

Built a module that determines block visibility in one DB query: github.com/vasi/block_access_records

We saved over 80 ms on every uncached request!

Blackfire Premium

• Environments (team)
• Data retention
• Assertions + Scenarios + CI + notifications
• Custom metrics
• Recommendations
• On-Premise version
• Talk to the guys in the Blackfire booth!

Calls to Action!

• Please fill in the feedback form for this session!
• Join us for Code Sprints
  • Friday, May 13 at the Convention Center
  • First-Time Sprinter Workshop - 9am-12pm in Room 271-273
  • Mentored Core Sprint - 9am-6pm in Room 275-277
  • General Sprints - 9am-6pm in Room 278-282

Calls to Action!

• Follow @dergachev and @djvasi on twitter!
• Go to the Blackfire booth
• Other resources:
  • block_access_records: github.com/vasi/block_access_records
  • Another Blackfire case study: evolvingweb.ca/blog/improving-drupal-speed-blackfire-io-part-1
  • Block visibility case study: evolvingweb.ca/blog/speed-up-drupal-8-block-rendering-blackfire-io
  • Our talk about our D8 upgrade 2016.midcamp.org/session/moving-our-company-site-drupal-8-break-ice

Drupal training program

• Public: Montreal, Ottawa, Toronto, DC Munich, NJ, NYC, Boston, Chiacgo
• Private: Health Canada, Parks Canada, Tourism Quebec, Trent U, McGill U, remote
• Enterprise teams, dev shops, remote

Visit us in Canada!

Just one more thing…