Item13525: Store reads the same file repeatedly from disk

Investigating the most expensive calls in Foswiki-2.0.0 using nytprof shows that Foswiki::Store::Rcs::Handler::readFile() is called up to 18 times for the same file (PatterSkinNavigation) and overall 118 files when visiting System.WebHome. That's quite a lot. Disk io is THE major bottleneck unless you are using SSDs.

This is a low-hanging fruit to lower disk-io using below simple patch:

diff --git a/RCSStoreContrib/lib/Foswiki/Store/Rcs/Handler.pm b/RCSStoreContrib/lib/Foswiki/Store/Rcs/Handler.pm
index 4340f77..9c1bc1b 100644
--- a/RCSStoreContrib/lib/Foswiki/Store/Rcs/Handler.pm
+++ b/RCSStoreContrib/lib/Foswiki/Store/Rcs/Handler.pm
@@ -152,6 +152,7 @@ sub finish {
     undef $this->{web};
     undef $this->{topic};
     undef $this->{attachment};
+    undef $this->{cache};
 }
 
 # Used in subclasses for late initialisation during object creation
@@ -1113,6 +1114,9 @@ sub saveFile {
     close($fh)
       or throw Error::Simple(
         'Rcs::Handler: failed to close file ' . $name . ': ' . $! );
+
+    $this->{cache}{$name} = undef;
+
     return;
 }
 
@@ -1120,7 +1124,10 @@ sub saveFile {
 sub readFile {
     my ( $this, $name ) = @_;
     ASSERT($name) if DEBUG;
-    my $data;
+
+    my $data = $this->{cache}{$name};
+    return $data if defined $data;
+
     my $IN_FILE;
 
     # Note: no IO layer; we want to trap encoding errors
@@ -1130,6 +1137,9 @@ sub readFile {
         $data = <$IN_FILE>;
         close($IN_FILE);
     }
+
+    $this->{cache}{$name} = $data;
+
     return $data;
 }

As a side, note I found out that Foswiki::Store::Rcs::Handler::getRevision($version) ignores the $version parameter and always returns the top revision as stored in the .txt file.

-- MichaelDaum - 15 Jul 2015

Patch updated to invalidate it when saveFile is called.

-- MichaelDaum - 17 Jul 2015

Changed attribution to RCSStoreContrib. I'm not convinced this is Urgent - no details of what operation on what topic with what skin in order to benchmark

-- Main.CrawfordCurrie - 20 Jul 2015 - 06:52

Skin does not matter, topic is System.WebHome as mentioned above, operation is view.

-- MichaelDaum - 20 Jul 2015

After digging a bit into Kenneth's report Item13593, it seems that the MetaCache doesn't cache very much. I've got a patch pasted into that topic that seems to improve that cache by refusing to re-add the same topic into the cache.

I suspect that these two problems are related. By not taking advantage of the MetaCache, that will certainly cause extra topic reads. In addition it means parsing the topic meta again which is also quite expensive. Fixing the MetaCache is probably lower risk than adding another cache in the store.

-- GeorgeClark - 31 Jul 2015

The fix in Item13593 had very significant improvement. I think that this item could be closed as a duplicate. Please see if the MetaCache was effective in eliminating the extra I/O that this patch resolved.

-- GeorgeClark - 05 Aug 2015

I will have to re-profile again. Above patch may now indeed only have negligible value. Having less pressure on the disk - no matter how - is a good thing.

-- MichaelDaum - 06 Aug 2015

Downgrading prio until the issue has been re-analyzed again.

-- MichaelDaum - 10 Aug 2015

MetaCache needs a redesign. It is tied to search and seems to be quite a mess of a coding attempt. In addition some sort of caching goes on in Meta itself with topics being half-loaded within the object itself.

Rewriting MetaCache is most probably best scheduled for 2.3 and tracked by Item14940

-- MichaelDaum - 12 Oct 2020

Commenting is disabled while not logged in