You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@httpd.apache.org by Bram Mertens <br...@anubex.com.INVALID> on 2021/03/23 14:15:09 UTC

RE: [users@httpd] How to troubleshoot/fix DAV errors during SVN checkout

> -----Original Message-----
> From: Yann Ylavic <yl...@gmail.com>
> Sent: Thursday, 14 January 2021 14:24
> To: users@httpd.apache.org
> Subject: Re: [users@httpd] How to troubleshoot/fix DAV errors during SVN
> checkout
> 
> On Thu, Jan 14, 2021 at 2:14 PM Yann Ylavic <yl...@gmail.com> wrote:
> >
> > You could use a "ProxyPass ... ttl=[timeout]" on the proxy with
> > [timeout] < KeepAliveTimeout on the backend (say the KeepAliveTimeout
> > on the backend's vhost is 5, try ttl=3 in the proxy's ProxyPass
> > directive).
> > By doing this, you avoid the case where the proxy is reusing a
> > connection that is being closed by the backend at the same time
> > (because its KeepAliveTimeout expires), the more connections the
> > greater the risk of this happening..
> >
> > But this is unlikely to fix the errors raised by the backend, because
> > those seem to happen on well established connections.
> > I may be missing something though, so this first step could help already..
> 
> As a first first-step and before fine tuning like described above though, I'd
> suggest completely disabling keepalive to see if it helps.
> So either "ProxyPass ... disablereuse=on" on the proxy or "KeepAlive off" on the
> backend.
> 
> Regards;
> Yann.

Sorry for the very late reply.
I'm unable to reproduce this often enough on our test server so I need to plan my tests in production carefully.

Adding ttl=3 with the default KeepAliveTimeout on the backend did not help.
I increased ttl to7 while increasing the KeepAliveTimeout on the backend to 10 but that too did not help.
Neither did disablereuse.

I then added the SVNInMemoryCacheSize section that we had on the old Debian server but that too does not resolve the problem.

Large checkouts (many thousands of files, 6+ GB total) fail consistently.
The checkout failed 3 times on my laptop (SVN clean followed by SVN up each time).
Checkouts in Jenkins which perform a clean SVN checkout every time fail every time.

What I noticed today is that even though the Jenkins SVN agent is reporting hundreds of files being checked out (lines starting with 'A   ' there is no activity logged in the web server logs. Neither on the proxy server nor the backend server.

For a checkout of 27655 files, 2.12 GB only the following lines are logged (192.168.14.195 is the client on which the Jenkins agent runs and performs the checkout):

Logs on the backend:
$ sudo tail -f /var/log/httpd/{access,error}_log|grep .14.195
192.168.14.195 - - [23/Mar/2021:14:45:22 +0100] "OPTIONS /customer/trunk HTTP/1.1" 401 381 "-" "SVN/1.10.0 SVNKit/1.10.1 (http://svnkit.com/) r10777"
192.168.14.195 - build [23/Mar/2021:14:45:22 +0100] "OPTIONS /customer/trunk HTTP/1.1" 200 186 "-" "SVN/1.10.0 SVNKit/1.10.1 (http://svnkit.com/) r10777"
192.168.14.195 - build [23/Mar/2021:14:45:22 +0100] "PROPFIND /customer/trunk HTTP/1.1" 207 682 "-" "SVN/1.10.0 SVNKit/1.10.1 (http://svnkit.com/) r10777"
192.168.14.195 - build [23/Mar/2021:14:45:22 +0100] "PROPFIND /customer/!svn/vcc/default HTTP/1.1" 207 396 "-" "SVN/1.10.0 SVNKit/1.10.1 (http://svnkit.com/) r10777"
192.168.14.195 - build [23/Mar/2021:14:45:22 +0100] "PROPFIND /customer/!svn/bln/273 HTTP/1.1" 207 451 "-" "SVN/1.10.0 SVNKit/1.10.1 (http://svnkit.com/) r10777"
192.168.14.195 - build [23/Mar/2021:14:45:22 +0100] "PROPFIND /customer/trunk HTTP/1.1" 207 682 "-" "SVN/1.10.0 SVNKit/1.10.1 (http://svnkit.com/) r10777"
192.168.14.195 - build [23/Mar/2021:14:45:22 +0100] "PROPFIND /customer/!svn/vcc/default HTTP/1.1" 207 410 "-" "SVN/1.10.0 SVNKit/1.10.1 (http://svnkit.com/) r10777"
192.168.14.195 - build [23/Mar/2021:14:45:22 +0100] "PROPFIND /customer/!svn/bc/273/trunk HTTP/1.1" 207 328 "-" "SVN/1.10.0 SVNKit/1.10.1 (http://svnkit.com/) r10777"
192.168.14.195 - build [23/Mar/2021:14:45:22 +0100] "PROPFIND /customer/!svn/bc/273/trunk HTTP/1.1" 207 328 "-" "SVN/1.10.0 SVNKit/1.10.1 (http://svnkit.com/) r10777"
192.168.14.195 - build [23/Mar/2021:14:45:25 +0100] "PROPFIND /customer/trunk HTTP/1.1" 207 682 "-" "SVN/1.10.0 SVNKit/1.10.1 (http://svnkit.com/) r10777"
192.168.14.195 - build [23/Mar/2021:14:45:25 +0100] "PROPFIND /customer/!svn/vcc/default HTTP/1.1" 207 410 "-" "SVN/1.10.0 SVNKit/1.10.1 (http://svnkit.com/) r10777"
192.168.14.195 - build [23/Mar/2021:14:45:25 +0100] "REPORT /customer/!svn/bc/273/trunk HTTP/1.1" 200 124 "-" "SVN/1.10.0 SVNKit/1.10.1 (http://svnkit.com/) r10777"
192.168.14.195 - build [23/Mar/2021:14:45:25 +0100] "PROPFIND /customer/trunk HTTP/1.1" 207 682 "-" "SVN/1.10.0 SVNKit/1.10.1 (http://svnkit.com/) r10777"

=> nothing logged for a long time

[Tue Mar 23 14:49:37.428573 2021] [dav:error] [pid 21083:tid 140486392063744] [client 192.168.14.195:0] Provider encountered an error while streaming a REPORT response.  [500, #0]
[Tue Mar 23 14:49:37.428615 2021] [dav:error] [pid 21083:tid 140486392063744] [client 192.168.14.195:0] A failure occurred while driving the update report editor  [500, #104]
[Tue Mar 23 14:49:37.428619 2021] [dav:error] [pid 21083:tid 140486392063744] [client 192.168.14.195:0] Error writing base64 data: Connection reset by peer  [500, #104]
192.168.14.195 - build [23/Mar/2021:14:45:25 +0100] "REPORT /customer/!svn/vcc/default HTTP/1.1" 200 226936481 "-" "SVN/1.10.0 SVNKit/1.10.1 (http://svnkit.com/) r10777"

Logs on the proxy:
192.168.14.195 - - [23/Mar/2021:14:45:22 +0100] "OPTIONS /customer/trunk HTTP/1.1" 401 381 "-" "SVN/1.10.0 SVNKit/1.10.1 (http://svnkit.com/) r10777"
192.168.14.195 - - [23/Mar/2021:14:45:22 +0100] "OPTIONS /customer/trunk HTTP/1.1" 200 186 "-" "SVN/1.10.0 SVNKit/1.10.1 (http://svnkit.com/) r10777"
192.168.14.195 - - [23/Mar/2021:14:45:22 +0100] "PROPFIND /customer/trunk HTTP/1.1" 207 682 "-" "SVN/1.10.0 SVNKit/1.10.1 (http://svnkit.com/) r10777"
192.168.14.195 - - [23/Mar/2021:14:45:22 +0100] "PROPFIND /customer/!svn/vcc/default HTTP/1.1" 207 396 "-" "SVN/1.10.0 SVNKit/1.10.1 (http://svnkit.com/) r10777"
192.168.14.195 - - [23/Mar/2021:14:45:22 +0100] "PROPFIND /customer/!svn/bln/273 HTTP/1.1" 207 451 "-" "SVN/1.10.0 SVNKit/1.10.1 (http://svnkit.com/) r10777"
192.168.14.195 - - [23/Mar/2021:14:45:22 +0100] "PROPFIND /customer/trunk HTTP/1.1" 207 682 "-" "SVN/1.10.0 SVNKit/1.10.1 (http://svnkit.com/) r10777"
192.168.14.195 - - [23/Mar/2021:14:45:22 +0100] "PROPFIND /customer/!svn/vcc/default HTTP/1.1" 207 410 "-" "SVN/1.10.0 SVNKit/1.10.1 (http://svnkit.com/) r10777"
192.168.14.195 - - [23/Mar/2021:14:45:22 +0100] "PROPFIND /customer/!svn/bc/273/trunk HTTP/1.1" 207 328 "-" "SVN/1.10.0 SVNKit/1.10.1 (http://svnkit.com/) r10777"
192.168.14.195 - - [23/Mar/2021:14:45:22 +0100] "PROPFIND /customer/!svn/bc/273/trunk HTTP/1.1" 207 328 "-" "SVN/1.10.0 SVNKit/1.10.1 (http://svnkit.com/) r10777"
192.168.14.195 - - [23/Mar/2021:14:45:25 +0100] "PROPFIND /customer/trunk HTTP/1.1" 207 682 "-" "SVN/1.10.0 SVNKit/1.10.1 (http://svnkit.com/) r10777"
192.168.14.195 - - [23/Mar/2021:14:45:25 +0100] "PROPFIND /customer/!svn/vcc/default HTTP/1.1" 207 410 "-" "SVN/1.10.0 SVNKit/1.10.1 (http://svnkit.com/) r10777"
192.168.14.195 - - [23/Mar/2021:14:45:25 +0100] "REPORT /customer/!svn/bc/273/trunk HTTP/1.1" 200 124 "-" "SVN/1.10.0 SVNKit/1.10.1 (http://svnkit.com/) r10777"
192.168.14.195 - - [23/Mar/2021:14:45:25 +0100] "PROPFIND /customer/trunk HTTP/1.1" 207 682 "-" "SVN/1.10.0 SVNKit/1.10.1 (http://svnkit.com/) r10777"
192.168.14.195 - - [23/Mar/2021:14:45:25 +0100] "REPORT /customer/!svn/vcc/default HTTP/1.1" 200 220094101 "-" "SVN/1.10.0 SVNKit/1.10.1 (http://svnkit.com/) r10777"

Some questions I have based on this:
1) Is it expected that none of those files that have been checked out are logged? When I perform a checkout of a subset of these with TortoiseSVN I see "GET" requests for each and every file.

2) The REPORT requests that fail are large (over 200MB if I convert the bytes correctly). Do I need to change the default configuration to allow these large requests?

3) The size of the REPORT request reported on the backend (226936481) is larger than what is reported on the proxy (220094101). Does this indicate that the connection between the proxy and backend was lost?

Thanks in advance

Bram

---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@httpd.apache.org
For additional commands, e-mail: users-help@httpd.apache.org