Poor Man's XHProf profiling of Drupal 8 Migrations and Drush commands

On a recent project, there was a Migration run that took a very long time, and I couldn't pinpoint why; there were multiple migrations, and none of the others took very long at all (usually processing at least hundreds if not thousands of nodes per minute). In Drupal 7, if you enabled the XHProf module, then you'd get a checkbox on the configuration page that would turn on profiling for all page requests and Drush commands.

In Drupal 8, the XHProf module was completely rewritten, and as a side effect, the Drush/CLI profiling functionality is not yet present (see: Profile drush/CLI with XHProf in Drupal 8).

Since I don't have the time right now to help figure out how to get things working through the official XHProf module, I decided to use a 'poor man's profiling' method to profile a Migration run:

  1. Find the Migrate module's drush command file (migrate_tools.drush.inc).
  2. Inject the appropriate xhprof functions in the right places to set up and save a profiling run.
  3. Run the drush mi [migration-name] command.
  4. Profit!

In my case, since I was using Drupal VM and it's default XHProf configuration, I had to add the following PHP:

<?php
/**
 * @param string $migration_names
 */
function drush_migrate_tools_migrate_import($migration_names = '') {
 
// Enable XHProf profiling for CPU and Memory usage.
 
xhprof_enable(XHPROF_FLAGS_CPU + XHPROF_FLAGS_MEMORY);

  ...
migrate drush command code here ...

 
// Disable XHProf, save the run into the configured directory.
 
$xhprof_data = xhprof_disable();
 
$XHPROF_ROOT = "/usr/share/php";
  include_once
$XHPROF_ROOT . "/xhprof_lib/utils/xhprof_lib.php";
  include_once
$XHPROF_ROOT . "/xhprof_lib/utils/xhprof_runs.php";
 
$xhprof_runs = new XHProfRuns_Default();
 
$run_id = $xhprof_runs->save_run($xhprof_data, "xhprof_testing");
}
?>

The $XHPROF_ROOT should point to the directory where you have XHProf installed.

After doing this, and running drush mi [migration-name], I looked at the Drupal VM XHProf runs page (configured by default at http://xhprof.[drupal-vm-name]/), and noticed the new run (the one at the top—the second one in this screenshot was from a run I did while viewing the site in the browser):

XHProf Drupal VM Dashboard page screenshot

See more on the PHP.net XHProf documentation pages, most notably the XHProf example with optional GUI example.

Comments

Hi there!

My xhprof-kit has a handy perf.php now, which I use when I need this kind of setup:

If you put xhprof-kit into the root of the site installation, you can do:

./xhprof-kit/setup.sh

Then in the code:

require_once DRUPAL_ROOT . "/xhprof-kit/perf.php";
$run = new \XhprofKit\XhprofKitRun();
// do your things
unset($run);

It will write the data to /tmp/perf.log, which is very handy when testing various things.

It also gives a direct link to /xhprof-kit.php, which is needed if you don't run Drupal VM as it proxies all commands through to the main script. (and works with D8's advanced protection)

Thanks,
Fabian

Drush has built-in xhprof integration. See the options declared here.. Its poorly advertised for you. Sorry about that.

I'd love to know what was slowing down the migration in your case.

I'd love to know what was slowing down the migration in your case.

I'm still working on that :(