Item13593: Foswiki 2.0 is 350% slower doing query SEARCH compared to 1.1.9.

I have a query search that goes though a set of 1200 topics

It is a FORMAT that iterates 42 times

Each time is makes a SEARCH looking for topics with some criteria incl comparing a date field with an interval.

In Foswiki 1.1.9 this takes 17 seconds on my test machine.

On the same machine the 2.0 spends 61 seconds doing exactly the same thing

It is already a major issue on my 1.1.9 that this page takes 17 seconds to load so imagine 61 seconds. I actually had to increase the default Apache timeout.

-- KennethLavrsen - 31 Jul 2015

Would be nice to have some reproducible example. I'm wondering myself about the search, so if you could provide some generated example topic data-set + the slow search command would be nice.

It is hard to generate 1000 topic which are used in the search? Some lorem Ipsum type data and such.

-- JozefMojzis - 31 Jul 2015

Here is what you need.

You need 1200 topics with a form. In this form you need a text field. And in this text field you need some value. In my example I just run now 220 of the records have the same value (a project name).

I have boiled the test case down to making a page with this search repeated 90 times. All my topics are called HwSR######

I cannot zip up my 1200 topics because the content is pretty confidential. But you script wizards can probably create 1200 files with same info except the topic name in a few minutes.

%SEARCH{  "Release = 'RLJ Cosmos 1' "  type="query"  topic="HwSR*" format=""  footer="$nhits"  nonoise="on" }%

I just tested 1.1.9 vs 2.0 (git checkout)

• 1.1.9 = 14 seconds
• 2.0 master = 86 seconds

That is 6 times slower. My previous measurement was with a more advanced SEARCH pattern that find less topics per search (typically 0-10 hits) and that was actually faster.

40 searches on 2.0 takes 39 seconds. 40/90 is pretty close to 39/86 so the time is proportional to number of searches. Approx 1 second per search

-- Main.KennethLavrsen - 31 Jul 2015 - 15:42

Here are NYTProf results of 1.1.9 and 2.0 to compare and analyse

• nytprof20.tgz: NYTProf run on 2.0

• nytprof119.tgz: NYTProf from 1.1.9

The following patch might help. The unit tests still pass, and there are a lot of cache hits, so it's got to be worth something ... hopefully.

diff --git a/core/lib/Foswiki/MetaCache.pm b/core/lib/Foswiki/MetaCache.pm
index b72ed7a..152c2c4 100644
--- a/core/lib/Foswiki/MetaCache.pm
+++ b/core/lib/Foswiki/MetaCache.pm
@@ -144,6 +144,14 @@ sub removeMeta {
 sub addMeta {
     my ( $this, $web, $topic, $meta ) = @_;
 
+    my $user = $this->current_user();
+
+    # If the cache is already populated, return it, don't add it again
+    if ( $this->hasCached($web, $topic) ) {
+        print STDERR "Cache hit for $web.$topic for $user\n";
+        return $this->{cache}->{$user}{$web}{$topic}->{tom}; 
+    }
+
     if ( not defined($meta) ) {
         $meta = Foswiki::Meta->load( $this->{session}, $web, $topic );
     }
@@ -160,8 +168,6 @@ sub addMeta {
         return;
     }
 
-    my $user = $this->current_user();
-
     unless ( $this->{cache}->{$user}{$web} ) {
         $this->{cache}->{$user}{$web} = {};
     }

-- GeorgeClark - 31 Jul 2015

I suspect that this issue is the same underlying problem to Item13525.

-- GeorgeClark - 31 Jul 2015

The patch that George just posted above shall from this moment be known to the world as "George's Miracle Patch".

I tried it and the search is now exactly the same speed as 1.1.9. That was it!!

-- KennethLavrsen - 03 Aug 2015

Commenting is disabled while not logged in