I'm encountering an odd behavior when I use the search-index command. The index works fine up until there are about 1000 items left, reporting the remaining items to be indexed every 200 as per my site configuration. When it gets to 997 items remaining, however, it suddenly starts spamming the shell:
Remaining items to be indexed: 997 [ok]

I checked admin/settings/search and the site is listed as 100% indexed at this point, so I just ^C to stop it, but it's odd.

If I do a search-reindex, admin/settings/search reports the same number of items to index as the initial report from search-index, so I'm not sure what the disconnect is.

Comments

xjm’s picture

This seems to be tied to the realname module. Watchdog shows realname reporting its own indexing of realnames right around the time my drush search-index starts looping, 200 per batch four times and then 197 the last time. There are 997 active users on the site.

greg.1.anderson’s picture

Are you sure that drush is setting your base_url correctly for you? For example, drush will work just fine if you use --uri=default to identify your site, but some modules might prefer (or demand) that you instead use --uri=mydrupalsite.org. (This presumes that your site it http://mydrupalsite.org, and you store your settings file at sites/default/settings.php; adjust for your particular values).

Normally Drupal will always set your base_url correctly based on the info sent in the headers from the web browser, but drush simulates these headers, so you need to tell drush accurately what your site should be called.

xjm’s picture

Thanks for the suggestion. I tried adding the --uri to the command but the same issue occurred. I'm thinking that maybe realname does something that drush doesn't expect in its hook_update_index(), which looks like this:

function realname_update_index() {
  if (variable_get('realname_search_enable', FALSE)) {
    $start = variable_get('realname_last_index', -1) + 1;
    $limit = (int)variable_get('search_cron_limit', 100);
    $how_many = db_result(db_query("SELECT COUNT(uid) FROM {users} WHERE  status=1 AND uid>=%d", $start));
    $limit = min($limit, $how_many);
    if ($limit < 1) {
      return;
    }
    watchdog('RealName', 'Indexing up to !limit users, starting at !start',
      array('!start' => $start, '!limit' => $limit),
      WATCHDOG_NOTICE);
    $result = db_query_range("SELECT uid, name FROM {users} WHERE status=1 AND uid>=%d", $start, 0, $limit);
    while ($account = db_fetch_object($result)) {
      $index_text = realname_make_name($account);
      if (variable_get('realname_search_login', FALSE)) {
        $index_text .= ' '. $account->name;
      }
      search_index($account->uid, 'realname', $index_text);
      variable_set('realname_last_index', $account->uid);
    }
  }
}

I haven't figured out just what yet; as far as I can tell it looks like node_update_index does.

xjm’s picture

So looking inside drush, I think something is going wrong in _drush_core_search_status()? I will try some debugging.

xjm’s picture

The status case of realname's hook_search():

    case 'status':
      $start = variable_get('realname_last_index', -1) + 1;
      $total = db_result(db_query('SELECT COUNT(*) FROM {users} WHERE status=1'));
      $remaining = db_result(db_query("SELECT COUNT(*) FROM {users} WHERE status=1 AND uid>=%d", $start));
      return array('remaining' => $remaining, 'total' => $total);

This never returns less than the maximum for $remaining when called by drush--and $start never changes--thence the infinite loop. Trying to figure out why.

Edit: Realname is using variable_get() here. (node.module doesn't for its own case.) It seems to always return the default, despite that the variable contains the proper, non-default value when I print it in hook_update_index() in between, incrementing from 0 to the max over successive calls as one would expect. Is $conf somehow empty when _drush_core_search_status() runs? Very, very weird. I'd appreciate any advice as I don't really understand how drush bootstraps.

xjm’s picture

I've confirmed that this bug occurs on a fresh D6.19 test site on my local machine, with only realname, devel_generate, admin_menu, and search modules enabled. (Just to be safe, I tried the --uri option on this site as well, both with localhost and 127.0.0.1 as the uri.)

$conf isn't empty, but it does contain different values depending on whether it's called in hook_search() from _drush_core_search_status(), or hook_update_index() from _drush_core_search_index() (which also calls _drush_core_search_status(), mind).

It's not that it's returning the default; $conf['realname_last_index'] itself is somehow -1, and then suddenly the correct number, and then -1 again, and then the (new, higher) correct number. Meow?

agentrickard’s picture

Component: Code » PM (dl, en, up ...)
Priority: Minor » Normal

I just ran into this as well, using Advanced Help in Drupal 7 and the culprit seems to be a combination of:

a) Advanced Help search indexing is disabled.

b) drush_search_status() does not filter disabled search modules when generating its count.

c) advanced_help_search_status() does not return 0 if it is disabled.

d) _drush_core_search_index() tries, therefore, to iterate over records that are never returned, because it runs while $count > 0.

There are two possible fixes here:

1) Fix drush:

function _drush_core_search_status() {
  $remaining = 0;
  $total = 0;
  $active = variable_get('search_active_modules', array('node', 'user'));
  if (drush_drupal_major_version() >= 7) {
    foreach (module_implements('search_status') as $module) {
      if (!in_array($module, $active)) {
        return;
      }
      $status = module_invoke($module, 'search_status');
      $remaining += $status['remaining'];
      $total += $status['total'];
    }
  }

With a similar correction for D6.

2) File issues / clarify the documentation of hook_search_status() so that modules that are disabled always return 0.

Ref: http://api.drupal.org/api/drupal/modules--search--search.api.php/functio...

Given that Drupal core blindly returns a value here, I think drush has to fix the problem. (See http://api.drupal.org/api/drupal/modules--node--node.module/function/nod...)

brad.bulger’s picture

I think this may be the same issue I saw a while ago - http://drupal.org/node/652894#comment-2387494

It's because Drush is doing the indexing in subprocesses, and the Realname count is coming from a static variable read by the parent Drush process. So it never changes. (That's a rough summary - that initial report is pretty old, but as far as I can tell, it's still like that.)

agentrickard’s picture

Note also that user.module DOES NOT store data in {search_data} so is always fully indexed. User module simply runs SQL queries on the {user} table. (Which is bad.)

See #1101668: User module does not use Search APIs fully

seanburlington’s picture

Status: Active » Needs review
StatusFileSize
new566 bytes

The code at #7 seems to work for me

I've made this into a patch against branch pear-7.x-4.x

moshe weitzman’s picture

Hard to tell WTF is going on here. Do we need to 'return' out of that loop (#7) or continue (#10)? Would be great if someone reviewed this.

seanburlington’s picture

I tried it with return as posted in #7 - the search-index returned very quickly without finishing the index ...

Apologies - I forgot I'd made this change when I said I'd rolled the above code to a patch.

It looks like it ought to be a return
The loop says

for each module which has hook_search_status (if it's active) run hook search_status

It seems that module_implements() returns modules which implement a hook - even if they are inactive.

We want to ignore these - but not subsequent modules so continue seems correct to me

I don't understand the purpose of $total and $remaining here - they don't appear to be used - but don't do any harm.

darrick’s picture

I took a look at how the the core search module was calculating the remaining items and copied that. My issue was with hook_search_status in the advanced_help module as in #7.

moshe weitzman’s picture

Status: Needs review » Postponed (maintainer needs more info)

this works for d7 and d6?

darrick’s picture

@moshe weitzman

My patch in #13 fixes the loop in D7. If you look at the code for _drush_core_search_index() you'll see it only calls update_index for modules in the search_active_modules variable. So my patch only looks for remaining items to index for those same modules.

function _drush_core_search_index() {
  list($remaining, ) = _drush_core_search_status();
  register_shutdown_function('search_update_totals');
  while ($remaining > 0) {
    drush_log(dt('Remaining items to be indexed: ' . $remaining), 'ok');
    // Use drush_backend_invoke() to start subshell. Avoids out of memory issue.
    $eval = "register_shutdown_function('search_update_totals');";
    if (drush_drupal_major_version() >= 7) {
      foreach (variable_get('search_active_modules', array('node', 'user')) as $module) {
        $eval .= " module_invoke($module, 'update_index');";
      }
    }
    else {
      $eval .= " module_invoke_all('update_index');";
    }
    drush_backend_invoke('php-eval', array($eval));
    list($remaining, ) = _drush_core_search_status();
  }
}

I did try things out with realname in D6. realname is checking the status by looking at the realname_last_index variable. However, when processing the index in a loop the cached value is returned and not the value which is updated by the index function. If you ctrl-c then restart indexing drush will show the newly updated indexing value.

I also checked if there was a difference between modules being enabled or disabled and didn't find any troubles.

jonhattan’s picture

Component: PM (dl, en, up ...) » Core Commands
Status: Postponed (maintainer needs more info) » Active

Committed #13, that fixes the case for drupal 7.

@brad.bulger idea for preventing infinite loop is still needed. http://drupal.org/node/652894#comment-2387494

gcassie’s picture

agentrickard’s picture

That patch hasn't been applied to Drush 7.x.5.

agentrickard’s picture

StatusFileSize
new14.32 KB

Drush still ignores these settings.

jonhattan’s picture

Version: » All-versions-4.x-dev
Assigned: Unassigned » msonnabaum
Status: Active » Patch (to be ported)
msonnabaum’s picture

Status: Patch (to be ported) » Fixed

Backported #13. Will be in 4.6.

Status: Fixed » Closed (fixed)

Automatically closed -- issue fixed for 2 weeks with no activity.

kenorb’s picture

Version: All-versions-4.x-dev » 7.x-5.8
Status: Closed (fixed) » Needs work

Problem still exists in drush 7.x-5.8

Duplicates:
#985778: search-index does not process
#955736: drush search-index fails

kenorb’s picture

Status: Needs work » Closed (duplicate)
kenorb’s picture

Issue summary: View changes

Updated issue summary.