Drush crashes after “command dispatch complete” [duplicate]

Question

I have a custom drush script. This script loads, changes and saves ~10000 drupal commerce products.

After that I get the message

Command dispatch complete [1140.43 sec, 663.25 МБ]                                                                                                                                                                                 [notice]
 Timer                Cum (sec)  Count  Avg (msec) 
 page                 1140.368   1      1140367.61 
 drupal_http_request  67.66      1032   65.562 
Peak memory usage was 784.48 МБ [1140.43 sec, 663.24 МБ]

And AFTER that script hangs and consumes more and more memory. Finally, after long time, script reaches 1.5 G memory limit and dies.

PHP Fatal error:  Allowed memory size of 1610612736 bytes exhausted (tried to allocate 80 bytes) in /var/www/vhosts/mysite.ru/htdocs/sites/all/modules/contrib/entity/includes/entity.wrapper.inc on line 302

Fatal error: Allowed memory size of 1610612736 bytes exhausted (tried to allocate 80 bytes) in /var/www/vhosts/mysite.ru/htdocs/sites/all/modules/contrib/entity/includes/entity.wrapper.inc on line 302

All products which were processed by the script are sucessfully changed.

The question: why drush script hangs when dispatch is complete and what it makes for such a long time when all products are processed? Is it sort of a post-processing?

Denis

Answer 1

Drush is running out of memory.

In the case of re/indexing search data via Search API, the item in that issue queue for this is Better memory usage on indexing.

To work around these sorts of issues, you can increase the amount of memory used by Drush, without touching the memory limit used by your Web server. See Configuring php.ini for details.

In my case, in my drush.ini, I increased it from:

• memory_limit = 256M

to:

• memory_limit = 512M

...and it solved my Search API (re)indexing problem.

Answer 2

If you see code inside drush.php file ...

function drush_main() {
  $return = '';
  // Start code coverage collection.
  if ($coverage_file = drush_get_option('drush-coverage', FALSE)) {
    drush_set_context('DRUSH_CODE_COVERAGE', $coverage_file);
    xdebug_start_code_coverage(XDEBUG_CC_UNUSED | XDEBUG_CC_DEAD_CODE);
    register_shutdown_function('drush_coverage_shutdown');
  }

  if ($file = drush_get_option('early', FALSE)) {
    require_once $file;
    $function = 'drush_early_' . basename($file, '.inc');
    if (function_exists($function)) {
      if ($return = $function()) {
        // If the function returns FALSE, we continue and attempt to bootstrap
        // as normal. Otherwise, we exit early with the returned output.
        if ($return === TRUE) {
          $return = '';
        }
        drush_bootstrap_finish();
        return $return;
      }
    }
  }

  // Process initial global options such as --debug.
  _drush_bootstrap_global_options();

  $return = '';
  drush_bootstrap_to_phase(DRUSH_BOOTSTRAP_DRUSH);
  if (!drush_get_error()) {
    // Do any necessary preprocessing operations on the command,
    // perhaps handling immediately.
    $command_handled = drush_preflight_command_dispatch();
    if (!$command_handled) {
      $return = _drush_bootstrap_and_dispatch();
    }
  }
  drush_bootstrap_finish();

  // After this point the drush_shutdown function will run,
  // exiting with the correct exit code.
  return $return;
}

Seems like everything goes smooth till

$return = _drush_bootstrap_and_dispatch();

where it logs

drush_log(dt('Peak memory usage was !peak', array('!peak' => drush_format_size(memory_get_peak_usage()))), 'memory');

So, A good starting point for you to debug is analyse below functions with log statements

  drush_bootstrap_finish();
  drush_shutdown(); // In includes/bootstrap.inc

Answer 3

I figured out why my script hangs after "Command dispatch complete".

The matter is that I have installed the "Search API" module. This module has

function search_api_track_item_change($type, array $item_ids)

method. In this method it calls search_api_index_specific_items_delayed function, and in this function it registers shutdown function _search_api_index_queued_items.

drupal_register_shutdown_function('_search_api_index_queued_items');

_search_api_index_queued_items function calls search_api_index_specific_items and finally in this function search api loads into memory all changed products! (~10000)

function search_api_index_specific_items(SearchApiIndex $index, array $ids) {
    $items = $index->loadItems($ids);
    // Clone items because data alterations may alter them.
    $cloned_items = array();
    foreach ($items as $id => $item) {
    $cloned_items[$id] = clone $item;
    }
    $indexed = $items ? $index->index($cloned_items) : array();
    ...

And it happens not just one time, but several times for every index of my drupal installation.

Of cause I have not enough memory for 10000 products, so script dies.

My solution: I just disabled "Index items immediately" option in my search api indexes.