Performance with case insensitive matching

Additional info, I'm using full word matching.
Maybe this page on Performance: drupal_substr is useful

Word matching has 2 calls to drupal_substr; "match any string" does not have calls to drupal_substr; My page times however do not significantly differ between the two settings, difference is <2%, so drupal_substr probably is not the main contributer to the problem here after all.

I added a counter for the number of matches, my test node has 823 matches in the node body (has no comments) and 44 unique matches. "All matches" takes 47 sec, "unique matches" takes 20 sec. A page with 0 matches generates in 2 sec. This looks like the number of matches, typically as a result of the size of the vocabulary and size of the node, has a big impact. This is consistent with users experience on the production site that large nodes and/or long threads tend to be particularly slow.

My test PC is a WinXP with a recent Xampp, PHP 5.2.5, a P4 2.8GHz with 2Gb mem. Note I've deliberately switched off all caching to make sure I'm seeing the bare effects of the code and I've deliberatly chosen a huge page to test with to exaggerate the problem.

On production I've limited the cache flush moments by moderating new terms using the unitag module. I moderate new tags once or twice a day. Still I'd like to keep the page timing spikes as low as possible. Only way to do this I think is to make Glossary scale as well as possible. This benefits anyone using Glossary obviously.

As for language aspects: I have a Dutch site and am using locale for translation, characters are plain latin, no difference really with English. Database is fully utf8-general-ci, pretty standard.

I know I'm using Glossary a little different than it was intended to but functionally it works great! It makes the site very dynamic with very little effort and users understand the concept as soon as they see it. It gives users often a much quicker and focussed access from the forum to the knowledge pages, much easier than using the search engine. Would probably also work nicely on drupal.org ;-)

I'm going to fiddle around a bit more, I'm slowly starting to understand how things work in glossary and drupal for that matter.

@nancyw: yes, I'm using "first match" on production, makes the most sense from a functional point on my site. Note "first match" means first match per piece of text i.e. if 5 comments each use the same term twice, each comment gets the first one highlighted by Glossary, there'll still be 5 links created by Glossary in the full thread (and this feels sensible as a user).

@kbahey: I'm using the exact same page and changing only glossary settings between measurements. Nr of queries (563) and time spent on queries (500 ms) is the same in both cases but total page generation times differ hugely.

@jscoble: I'm using MySQL 5.0.51a (most recent Xampp as a quick test setup)

I realised there's a complication. Case sensitive matching will naturally result in fewer matches, that's fine but exercises 2 aspects of the problem at the same time. So I need a table of 4 cases where I'm using first match / all matches as the volume aspect against case sensitive/insensitive:

my node/13355    | Case insensitive   | Case sensitive    |
Only first match | 20 sec / 44 hits   | 3.7 sec / 32 hits |
All matches      | 47 sec / 136 hits* | 3.8 sec / 91 hits |

*) note I've lost the 823 hits, I may need to repeat the measurement on a fresh restore, may have changed something testing yesterday, I've had the site collapse on a CPU limit of 120 sec when tripeling the node content.. ;-)

As a baseline a node without hits and very little content:

my node/10795    | Case insensitive  | Case sensitive    |
Only first match |  1.8 sec / 0 hits |  1.7 sec / 0 hits |
All matches      |  1.8 sec / 0 hits |  1.7 sec / 0 hits |

Filter out just case sensitive vs insensitive effects

Normalised       | Case insensitive    | Case sensitive    |
Only first match | 18.2 sec / 44 hits  | 2 sec / 32 hits   |
All matches      | 45.2 sec / 136 hits | 2.1 sec / 91 hits |

Normalised per hit  | Case insensitive | Case sensitive | Case sensitive vs insensitive
Only first match    | 0.41 sec/hit     | 0.06 sec/hit   | 15%
All matches         | 0.33 sec/hit     | 0.02 sec/hit   | 7%

Just checked, query cache is off on my test system. I tried to do all timings 3 or 4 times to get a feel for consistency and haven't seen 'cache effects' like the first attempt slower than the others. Now I'm reasonably sure we looking at just code effects. Thanks all for your comments :-)

About the 47 sec/823 hits, that was "match any substring", "case insensitive" and "all matches". Since match type "word", as used in all the measurements above, is more realistic and a more processing intensive case I'll forget about the 47 sec/823 case from now on. Still, good to understand where it went and saves me a database restore.

@Nancy, absolutely I'll test anything that might help :-)

This bit seems to me a good candidate as I feel it could be scaling consistent with the timings seen, would you agree?

  // Find match candidates.
  foreach ($terms as $i => $term) {
    foreach($term['synonyms'] as $synonym) {
      $offset=0;
      $first_match_found = false;
      while(($offset = $findfunc($text, $synonym, $offset)) !== false) {
        $match = drupal_substr($text, $offset, drupal_strlen($synonym));
        //only longer matches override shorter ones
        if (!isset($events[$offset]) || drupal_strlen($events[$offset]['match']) < drupal_strlen($match)) {
          // get synonym with case as in text
          $events[$offset] = array('type' => 'match', 'which' => $i, 'match' => $match);
          if (!$replaceall) {
            $first_match_found = true;
            break;
          }
        }
        $offset += drupal_strlen($synonym);
      }
      //TODO: remove this if we want different synonyms of the same term to be matched independently as 'first matches'
      if ($first_match_found && !$replaceall) {
        break;
      }
    }
  }

My vocabulary for Glossary holds 593 terms+aliasses so that's the outer 2 loops. The string being scanned (node text) is 51235 bytes long. I think there are really only a few functions that might be sensitive to differences in typecase and that are in the innermost loop: drupal_substr, $findfunc (expands to mb_stripos) and drupal_strlen.

[edit] counted nr of terms [/edit]

Sorry, you're right, the engine is MyISAM on all tables. Time spent in the database is 0.5 sec consistently on all test cases, I do not see how I can gain 15 odd seconds there. That said, there are 563 queries of which there are some 500 from _glossary_get_terms each at ~0.7 ms, totalling 350ms:

SELECT COUNT(n.nid) FROM term_node t JOIN node n USING (nid) WHERE t.tid=1018 AND n.status=0

It is "using index" says explain. No difference between case insensitive and case sensitive.

The innermost loop in the code above is executed 530735 times in this particular case, 593 terms times 895 pieces of text to be scanned. Also, it will explode with either component increasing. The only way that I see to improve this, read make this more scalable, is to flatten the loops out, untangeling them. Maybe that's what Nancy called prefetching the terms? I can imagine that reading the terms into variables first and then doing the inner loop scanning text would help to the extent that it would reduce the text scan loop to ~1 sec (now 18.2 sec). I could do this in another programming language easily but I'm not up to php very well yet. I'm looking forward to what Nancy can come up with.
[edit] my point is, if the loop is this much more efficient I pretty much don't care anymore about case sensitivity ;-) [/edit]

@jscoble: no problem, I appreciate your help

@nancyw: that's sad news.. Drupal will just have to wait, take care

I'll have a go at that bit of code myself, good learning experience

With utf8_substr function

my node/13355    | Case insensitive    | Case sensitive    |
Only first match | 21.2 sec / 44 hits  | 4.9 sec / 32 hits |
All matches      | 49.9 sec / 136 hits | 5.3 sec / 91 hits |

Baseline:
my node/10795    | Case insensitive  | Case sensitive    |
Only first match |  2.1 sec / 0 hits |  1.9 sec / 0 hits |
All matches      |  2.1 sec / 0 hits |  1.9 sec / 0 hits |

Normalised       | Case insensitive    | Case sensitive    |
Only first match | 19.1 sec / 44 hits  | 3.0 sec / 32 hits |
All matches      | 47.8 sec / 136 hits | 3.4 sec / 91 hits |

So utf8_substr appears to be slightly slower than drupal_substr. Also the baseline is slightly slower as a result of utf8_substr; I put back the original module and retested the old cases and can still reproduce the old timings.

I will test removing multi-byte support from PHP tomorrow.

Sorry to have to disappoint you Nancy but module #22 crashes on all the original testcases on the 120 sec CPU limit.. really. I've tried a smaller vocabulaty that produces just 1 match, with that vocab the module works properly and is about as fast as the original module.

I've noticed there's a new option "Abbr element" in the settings screen, we're not using the exact same version of the module, probably doesn't matter for this function. (For the record, mine is v 1.121.2.13, yours is v 1.121.2.14)

I'll now have a go at seeing the influence of disabeling mbstring in php (planned yesterday but I had some other unexpected obligations)

With "mbstring" switched off, the site reverts to findfunc = "strpos"; and then strange things happen:

my node/13355    | Case insensitive  | Case sensitive  |
Only first match | 64 sec / 4 hits   | 69 sec / 2 hits |
All matches      | 65 sec / 2 hits   | 69 sec / 6 hits |

Not only are these slower, typecase has no real influence on speed and without mbstring most of the terms are not found anymore in the text. Also notice that it finds less hits on setting "all matches" that "first match" when case insensitive is set, strange.

Mbstring on again in php.ini, stop/start apache, check in admin/logs/status and the old timings and nr of matches can be reproduced again with the same glossary module.

Ok, here's a thought. I'm running PHP 5; it uses stripos for case insensitive string searches and strpos for case sensitive; basically stripos is a strpos with both its arguments lowercased. This means we're lowercasing this long 50k textstring over and over again. By doing a strtolower once, would bring down case insensitive searches to case sensitive times and speed it up by a factor 5.

This code runs equally fast for case insensitive as case sensitive and produces the right nr of matches

   // make sure we only do lowercase once, case sensitive searching is faster than case insensitive
   $typecase = variable_get("glossary_case_$format", '1');
   if ($typecase == 0) {
      $searchtext = strtolower($text);
      } else {
      $searchtext = $text;
      }

  // Find match candidates.
  foreach ($terms as $i => $term) {
    foreach($term['synonyms'] as $synonym) {
      $offset=0;
      if ($typecase == 0) {
         $searchsynonym = strtolower($synonym);
         } else {
         $searchsynonym = $synonym;
      }

      $first_match_found = false;
//      while(($offset = $findfunc($text, $synonym, $offset)) !== false) {
      while(($offset = $findtagfunc($searchtext, $searchsynonym, $offset)) !== false) { // always search case sensitive
        $match = drupal_substr($text, $offset, drupal_strlen($synonym));
        //only longer matches override shorter ones
        if (!isset($events[$offset]) || drupal_strlen($events[$offset]['match']) < drupal_strlen($match)) {
          // get synonym with case as in text
          $events[$offset] = array('type' => 'match', 'which' => $i, 'match' => $match);
          if (!$replaceall) {
            $first_match_found = true;
            break;
          }
        }
        $offset += drupal_strlen($synonym);
      }
      //TODO: remove this if we want different synonyms of the same term to be matched independently as 'first matches'
      if ($first_match_found && !$replaceall) {
        break;
      }
    }
  }

Nancy, case sensitive works but case insensitive crashes:
Fatal error: Maximum execution time of 120 seconds exceeded in .....\glossary.module on line 404
That's with the comments around 381 removed. It executes 504 of the 563 SQL queries needed for the page.
Maybe something is still wrong with the removed loop from update #22, that also crashed. I do have some 50 odd synonyms in the vocab, maybe that's it?

Hi Nancy,

have a look and enjoy, module #32 works wonderful:

my node/13355    | Case insensitive   | Case sensitive    |
Only first match | 3.9 sec / 44 hits  | 3.9 sec / 32 hits |
All matches      | 4.7 sec / 136 hits | 4.0 sec / 91 hits |

Baseline:
my node/10795    | Case insensitive  | Case sensitive    |
Only first match |  1.9 sec / 0 hits |  1.9 sec / 0 hits |
All matches      |  1.9 sec / 0 hits |  1.9 sec / 0 hits |

This means that in a cache flush situation, not only are pages with glossary matches considerably faster but all pages without glossary matches are slightly faster as well. Also there'll much less variation in speed between pages which helps website consistency and user trust. And ofcourse, eventhough there's still a dependency on nr of terms and volume of text, it's impact is far less than before, unlikely to become a problem again any time soon.

I'm delighted with this result! and I think we should call this problem busted ;-)
the problem in #31 is for some other time, hopefully under clearer conditions.
Thank you for your patience and your time

Johan

PS maybe the performance degradation after a cache flush is now so small that the warning message is no longer necessary.

5-10 fold is in a worst case scenario but not bad at all, that's for sure. Funny thing is that once the problem is found it seems so obvious ;-)
I'll have the test system anyway for support of the prod site so it's no problem to test further. I suggest opening a new thread, If you forward link this one to it I'll pick it up. Are you after the /glossary page? any particular circumstances?