On Thu, Oct 1, 2015 at 12:57 PM, Terry Dooher
<Terry.Dooher_at_naturalmotion.com> wrote:
> I've recently configured svn usage logs with:
>
> LogFormat "%h %t %u (%{SVN-REPOS-NAME}e %{SVN-ACTION}e) %s (%I/%O in %Ts) %k \"%{User-Agent}i\"" svn
> CustomLog /var/log/svn/svn-usage.log svn env=SVN-ACTION
>
> mod_logio is enabled, so I'm getting values written to each of the above fields, but when testing with a full checkout of a ~420Mb repo (excluding pristine), I get variable results depending on the client. Sometimes the log entry appears within 4 seconds and reports ~1MB:
>
> 192.168.1.2 [01/Oct/2015:11:42:50 +0100] user (svn get-inherited-props /trunk r1084) 200 (543/292 in 0s) 4 "SVN/1.8.13 (x64-microsoft-windows) serf/1.3.8"
> 192.168.1.2 [01/Oct/2015:11:42:50 +0100] user (svn checkout-or-export /trunk r1084) 200 (726/11527999 in 11s) 5 "SVN/1.8.13 (x64-microsoft-windows) serf/1.3.8"
>
> Sometimes the log only reports the checkout, but with the correct size:
>
> 192.168.1.2 [01/Oct/2015:11:43:55 +0100] user (svn checkout-or-export /trunk r1084) 200 (729/665066747 in 171s) 3 "SVN/1.7.20 neon/0.29.6"
>
> The exact %I, %O and %T will vary a little with each test, but the log entry appears after the first ~5s/~10MB of a checkout that takes 3 minutes. The difference between the above two is that the first checkout is via command-line SVn (part of Tortoise), using Serf and the latter is via the OSX developer tools svn command line (Currently 1.7.20 and built against Neon).
>
> I've disabled compression both at SVNCompressionLevel and disabling mod_deflate. (The data sizes logged were much smaller previously, but the issue was still there).
>
> Is there a way I can ensure the log is only written after the full request has been serviced? The data over time will be really useful in gauging usage over time.
>
> Environment:
> * Debian Jessie/Apache 2.4.10
> * mod_dav_svn 1.8.14 Compiled from source. - Basic auth. No SSL.
> * Client: Windows 7 - Command line (From Tortoise SVN 1.8.13) / OSX Yosemite shell (1.7.20 from OSX Developer Tools)
>
> Config:
> <IfModule mod_dav_svn.c>
> SVNCompressionLevel 0
> SVNCacheTextDeltas On
> SVNCacheFullTexts On
> SVNCacheRevProps On
> SVNInMemoryCacheSize 262144
> </IfModule>
>
> Common repo config (Path and AuthName set per Location)
> AuthType Basic
> AuthUserFile xxx
> Require valid-user
> AuthzSVNAccessFile yyy
>
> Order allow,deny
> Allow from all
>
> # Common SVN.
> DAV svn
>
> # Misc:
> Options +FollowSymLinks +Indexes
> SVNIndexXSLT "/svnindex.xsl"
>
> Thanks,
>
> Terry.
I think this is because 1.8+serf uses "skelta style updates" instead
of "bulk updates". With skelta mode the client uses a separate HTTP
request for each resource that needs to be fetched (instead of pulling
the entire update through a massive http request/response). See here:
http://subversion.apache.org/docs/release-notes/1.8.html#neon-deleted
As explained there, you can configure the server to "prefer" bulk
update mode, if you wish. That might give you back the ability to
measure the checkouts as one huge HTTP response.
--
Johan
Received on 2015-10-01 14:33:42 CEST