Re: svn+ssh long-lived daemon

Mark Phippard <markphip_at_gmail.com> writes:

> I should have added that the part that I would question here is the value
> and importance of the cache. Which is the root of this. I just do not see
> it. I guess you (Philip) do else you would not be looking into this. The
> majority of our users, as my educated guess only, are probably using Apache
> server with prefork MPM.

Apache prefork typically has low performance because the maximum number
of processes is high and that limits the size of the FSFS cache. Use a
threaded MPM, reduce the number of processes and increase the cache size
to get better performance.

I can use my local mirror of Subversion to demonstrate the effect of the
FSFS cache. I setup localhost svn+ssh and svn-with-SASL access, both
require authentication and both do encryption.

Running 'svnbench null-log' on trunk takes:

          svn+ssh: 4.3s
   cold cache svn: 4.4s
    hot cache svn: 2.0s

Cold cache is the first run after starting the daemon, hot is subsequent
runs. Runtime is completely dominated by CPU used by svnserve for both
svn+ssh and svn.

Using strace I see the systems calls to read the revision files are
absent when the cache is hot (although log still has to read all the
revprop files):

First run cold:

% time seconds usecs/call calls errors syscall
------ ----------- ----------- --------- --------- ----------------
 37.25 0.001078 0 652061 read
 23.01 0.000666 0 334700 2 open
 21.56 0.000624 0 581838 lseek
 14.41 0.000417 0 334699 close

Subsequent runs hot:

% time seconds usecs/call calls errors syscall
------ ----------- ----------- --------- --------- ----------------
 50.31 0.000404 0 106149 read
 25.65 0.000206 0 106136 2 open
 13.33 0.000107 0 106135 close
 10.71 0.000086 0 106124 fstat

Running 'svnbench null-blame' on configure.ac takes:

          svn+ssh: 0.37s
   cold cache svn: 0.39s
    hot cache svn: 0.13s

and strace shows reduced system calls, cold:

% time seconds usecs/call calls errors syscall
------ ----------- ----------- --------- --------- ----------------
 28.57 0.000020 0 14793 2 open
 28.57 0.000020 0 21931 lseek
 18.57 0.000013 0 14792 close
 17.14 0.000012 0 46660 read

hot:

% time seconds usecs/call calls errors syscall
------ ----------- ----------- --------- --------- ----------------
  0.00 0.000000 0 2319 read
  0.00 0.000000 0 1880 write
  0.00 0.000000 0 2305 2 open
  0.00 0.000000 0 2304 close

These examples show a reduction in the CPU on the server by a factor of
two or three, which translates into faster responses for the client and
the ability of the server to handle more clients simultaneously.

-- 
Philip Martin
WANdisco