Unexpected HTTP status 400 'Bad request'.

[Chris Capon]

Hi.
We are running a Subversion server using Apache2 2.4.17-3, modDAV, and
Subversion 1.9.2-3+b1 (the latest Testing release) under Debian
GNU/Linux. We use HTTPS for security along with client certificates.
This server has been running for many years with the same configuration.

A week or so ago, when trying to commit to ONE of the repositories on
this server, from a long-time client Windows machine running TortoiseSVN
1.9.2, Build 26806, the commit failed with the error:

Unexpected HTTP status 400 'Bad request' on .... {one of the files}

Since then, we have not been able to commit anything to that
repository. On a commit with about 6 files, it seems to fail on
different files periodically. It isn't always the same file name in the
error message.

The thing is, we can still do commits to other repositories on the same
server and folder tree without this error happening and even from the
same Windows machine. So I don't think the communications themselves
are the problem. There is no hardware firewall between the client and
the server.

To diagnose the problem, I tried to check out the repository on the
subversion server itself to a local folder (hoping to eliminate the
network as the problem). When I execute:

svn checkout https://server/svn/repository/dev/trunk --username
myself dev

the checkout begins to download files then will randomly stop after
about 10 files with this error:

svn: E175013: Access to 'filename' forbidden.

Repeating the experiment will cause it to fail at different files
seemingly randomly. Trying to 'svn cleanup' and 'svn update' the
partially checked out folder will give the same error after bringing
down a few more files.

I have made sure permissions are set correctly for the Apache user in
the folder with the subversion repository.

None of the log files under /var/log/apache2 seem to catch or record
anything about the errors, nor is there anything in the subversion.log
file in the same folder. I am not sure how to capture the cause of the
error on the server side.

Can anyone help me diagnose this problem?

Thanks.

[David Chapman]

Have you verified that the repository on the server is not corrupt?
Perhaps the disk has a bad sector on the drive, and only that repository
is affected. Or maybe the hard drive itself is failing, and the other
repositories have simply been "lucky" so far.

# svnadmin verify /path/to/repository/root

--
David Chapman dcch...@acm.org
Chapman Consulting -- San Jose, CA
Software Development Done Right.
www.chapman-consulting-sj.com

[Chris Capon]

On 2015-12-07 20:48, David Chapman wrote:
>
> Have you verified that the repository on the server is not corrupt?
> Perhaps the disk has a bad sector on the drive, and only that
> repository is affected. Or maybe the hard drive itself is failing,
> and the other repositories have simply been "lucky" so far.
>
> # svnadmin verify /path/to/repository/root
>

I ran the svnadmin command and the admin tool verified all the revisions
and reported no errors. The same problem still persists. I can only get
part way through a checkout before it fails.

By the way, if I change the local svn checkout on the server to a file
reference rather than going through apache2 and https then the checkout
completes with no problems. So,

svn checkout https://localhost/svn/repository/dev/trunk --username
myself dev

fails part way through after 5 to 10 files, where

svn checkout file:///root/subversion/root/repository/dev/trunk
--username myself dev

checks out the entire repository without errors.

[Eric Johnson]

Is it feasible to dump and load the repository in question?

You could re-load it, and see if the repository still has problems.

On the other hand, if the load fails at a specific revision, that might give you more of a clue about what is going wrong.

Eric.

[Yves Martin]

 Hello​

Is your repository served read-write by other services like svnserve or eventually through SSH in addition to Apache HTTPS access ?

If so you have to check your repository file permissions: owner, group and modes (for instance g+w or g+s...)

I guess your repository has been created long ago with a previous version of Subversion.

What is your repository format version ? Are some revisions packed ? Use svnadmin info.

Maybe you should use "svnadmin upgrade" to get some new features properly enabled with Subversion 1.9,

or even use dump/load procedure (or svnsync) to get your repository ready (and optimized) for Subversion 1.9.

Regards

-- 

Yves Martin

[Bert Huijben]

Usually you wouldn’t get ‘bad request’ errors from httpd unless Subversion sends a bad request. Server side errors as disk io are usually reported by other error codes, such as 500.

 

Most bad cases of status 400 are caused by firewall and antivirus products that somehow alter requests in unexpected ways. Another ‘expected’ case of this error is when Subversion sends too many headers to the server; we see this in some commits of subtrees with hundreds of locks. The investigation for this error code should start in the server log.

 

Except for that too much header data, the Subversion client should never generate a request that the server thinks is ‘bad’. That is what it tells with status 400.

 

But as noted before: more details should be in the server log (and often in the response body itself… but if there was usable data there Subversion should have noted that)

 

                Bert

[Yves Martin]

 Hello,

In my Apache2 configuration, I have added "LimitRequestBody 0" and "LimitXMLRequestBody 0" to avoid such troubles with a 12-year-old-really-large repository...

Hope this helps

Regards

-- 

Yves Martin

[Bert Huijben]

These are both about bodies… The headers causing that lock problem are not part of the body.

 

There is probably another configuration knob for them.

 

                Bert

 

From: Yves Martin [mailto:ymart...@gmail.com]
Sent: dinsdag 8 december 2015 12:10
To: Subversion <us...@subversion.apache.org>
Subject: Re: Unexpected HTTP status 400 'Bad request'.

 

 Hello,

[Yves Martin]

Right. I also saw I have "LimitRequestFieldSize 60000" set.

Is it possible for you to open a clear HTTP virtual host so that to inspect Subversion client traffic and understand what may be wrong ?

-- 

Yves Martin

[Chris Capon]

Hi Eric.

I did this:

    svnadmin dump /root/subversion/root/repository > repository.dump
    svnadmin create /root/subversion/root/tmprepo
    chown -R www-data:www-data /root/subversion/root/tmprepo
    svnadmin load /root/subversion/root/tmprepo < repository.dump

After this, I attempted a checkout on the server to a local folder:

    svn checkout https://localhost/svn/tmprepo/dev/trunk --username myself dev

It got further, perhaps 30 or 35 files before:

    svn: E175002: Unexpected HTTP status 400 'Bad request' on '/svn/tmprepo/!svn/rvr/1931/dev/trunk/code/app/Attributes/Attr.cs'

Thanks.

On 2015-12-08 03:04, Eric Johnson wrote:

[Chris Capon]

On 2015-12-08 05:06, Yves Martin wrote:
> Hello​
>
> Is your repository served read-write by other services like svnserve
> or eventually through SSH in addition to Apache HTTPS access ?

I'm sorry. I don't understand what this asks. Permissions are
controlled by a .apache_auth and .apache_htpasswd file (in addition to
client certificates). The .apache_auth file has the folder defined as
'rw' for my user id.

>
> If so you have to check your repository file permissions: owner, group
> and modes (for instance g+w or g+s...)

All the file level permissions are set to rwxr-xr-x (755) and both owner
and group are www-data, the user id under which the Apache2 service runs.

>
> I guess your repository has been created long ago with a previous
> version of Subversion.
> What is your repository format version ? Are some revisions packed ?
> Use svnadmin info.

Repository Format: 5
Compatible With Version: 1.9.0
Repository Capability: mergeinfo
Filesystem Type: fsfs
Filesystem Format: 7
FSFS Sharded: yes
FSFS Shard Size: 1000
FSFS Shards Packed: 0/3
FSFS Logical Addressing: no
Configuration File: /root/subversion/root/repository/db/fsfs.conf

>
> Maybe you should use "svnadmin upgrade" to get some new features
> properly enabled with Subversion 1.9,

After running
svn upgrade /root/subversion/root/repository

The response was "Upgrade completed." But an svn checkout gives the
same error:

svn: E175002: Unexpected HTTP status 4000 'Bad request' on
'/svn/repository/!svn/rvr/1903/dev...'

Again, at a random file about 5 or 6 files in.

> or even use dump/load procedure (or svnsync) to get your repository
> ready (and optimized) for Subversion 1.9.

We tried this in a previous e-mail (see for details).

>
> Regards
> --
> Yves Martin
Thanks.

[Bert Huijben]

Are you using some kind of (caching) proxy server when you connect to the server?

You are focusing your search to a disk problem (probably caused by hints on this list), while you are trying to determine what causes a 'bad HTTP request' error.

Bad requests on these urls may be caused by sending bad header values... I've seen those before when using nginx as proxy with a too strict caching policy.

Bert

[Chris Capon]

Hi Bert.
The only log I know of is under /var/log/apache2/subversion.log, and when I issue a checkout, I get only two lines in it:

[08/Dec/2015:09:24:53  -500] myself get-inherited-props /dev/trunk r3066
[08/Dec/2015:09:24:53  -500] myself checkout-or-export /dev/trunk r3066

If the error were caused by a firewall or antivirus software, would it still make sense that the checkout begins and gets several files in before failing?  Also, to try and eliminate that possibility, I've been performing the checkout tests on the subversion server machine.

[Chris Capon]

p.s. The server is around 8 years old and has been maintained and
regularly updated, pinned to the Testing release of Debian.

On 2015-12-08 05:06, Yves Martin wrote:
>

[Chris Capon]

I Added both these lines to the <Location> section of the Apache2
configuration file. When I do an svn checkout locally, I get the same
error occurring.

[Yves Martin]

 Hello,

Really your issue is strange.
​I propose you test your local checkout with HTTP protocol, with a tcpdump network traffic collection, maybe it is possible to find clues "on the wire".

-- 

Yves Martin

[Bert Huijben]

This is just the Subversion operational log generated by mod_dav_svn. The interesting things would be in the apache access and/or error logs.

(Depending on the configuration of your apache these could be the same logfile)

 

The operational log just shows successful Subversion operations, so that doesn’t tell us much why a request failed.

 

                Bert

[Stefan Sperling]

On Tue, Dec 08, 2015 at 04:28:21PM +0100, Bert Huijben wrote:
> This is just the Subversion operational log generated by mod_dav_svn. The interesting things would be in the apache access and/or error logs.

Hi Chris,

please try raising HTTPD's LogLevel to "Debug" or higher.
See http://httpd.apache.org/docs/2.4/mod/core.html#loglevel

Perhaps that will shed more light on the problem.

[Chris Capon]

On 2015-12-08 09:09, Bert Huijben wrote:
> Are you using some kind of (caching) proxy server when you connect to
> the server? You are focusing your search to a disk problem (probably
> caused by hints on this list), while you are trying to determine what
> causes a 'bad HTTP request' error. Bad requests on these urls may be
> caused by sending bad header values... I've seen those before when
> using nginx as proxy with a too strict caching policy. Bert

No proxy server. As I say, to eliminate the possibility, I'm even
connecting from a terminal on the subversion server and trying it from
there. Going through apache2, it fails, going directly through file
access succeeds.

But the confusing thing is that the error doesn't happen with the
initial connection, it happens part way through after several files have
transferred successfully. And it seems inconsistent. It doesn't always
fail on the same file.

What I don't know is how to diagnose the communications through apache
and to the subversion server. No error messages appear in any of the
apache2 logs nor the subversion log. So where is the error happening?

[Philip Martin]

Chris Capon <tta...@gmail.com> writes:

> What I don't know is how to diagnose the communications through apache
> and to the subversion server. No error messages appear in any of the
> apache2 logs nor the subversion log. So where is the error happening?

You should see the 400 in the apache logs at the very least, if apache
is not logging anything then you need to change LogLevel. The
Subversion regression tests generate a 400 and the apache log shows:

::1 - - [09/Dec/2015:09:44:28 +0000] "DELETE /svn-test-work/repositories/lock_tests-61/!svn/txr/2-2/A HTTP/1.1" 400 301 Length:-

[Wed Dec 09 09:29:40.749939 2015] [core:info] [pid 13733:tid 139669165561600] [client ::1:45002] AH00561: Request header exceeds LimitRequestFieldSize: If
[Wed Dec 09 09:29:40.749942 2015] [core:info] [pid 13733:tid 139669165561600] [client ::1:45002] AH00567: request failed: error reading the headers

There are various ways to trace the communication:
http://subversion.apache.org/docs/community-guide/debugging.html#net-trace
but these may not be useful if you are using https://. If you can
reproduce the problem for http:// it would be helpful.

If you can only use https:// one possibility is to use socat as an
http<->https relay:

socat -v TCP6-LISTEN:9630,reuseaddr,fork OPENSSL:localhost:443,verify=0

Then use http:// to socat and have socat use https to apache:

svn ls http://localhost:9603/...


--
Philip Martin
WANdisco

[Yves Martin]

Thanks Philip. Great tips.

Just a remark: port to use in svn ls command is 9630 (instead of 9603)

-- 

Yves Martin

[Chris Capon]

On 2015-12-08 11:16, Stefan Sperling wrote:

please try raising HTTPD's LogLevel to "Debug" or higher. See http://httpd.apache.org/docs/2.4/mod/core.html#loglevel Perhaps that will shed more light on the problem.

Hi All.
I appreciate the time you guys are taking to help me.  Thank you.

Here is the output of the Apache2 error.log after setting the level to DEBUG and re-running the test.




Here is the output from a shell prompt on the Subversion server:

myself@myserver:~/Folder$ svn checkout https://myserver/svn/repository/dev/trunk --username myself dev
Passphrase for '/home/myself/Folder/myself.p12': ***************

A    dev/code
A    dev/code/provider
A    dev/code/provider/Investor
A    dev/code/provider/Investor/Properties
A    dev/code/provider/Plugin
A    dev/code/provider/Plugin/Properties
A    dev/code/provider/Client
A    dev/code/provider/Client/Properties
A    dev/code/provider/ClientInstitutional
A    dev/code/provider/Client/Price-wrapper.xml
A    dev/code/provider/Client/Account.xsd
A    dev/code/provider/Client/History-sample.xml
A    dev/code/provider/ClientInstitutional/migrate.xml
svn: E175002: Unexpected HTTP status 400 'Bad request' on '/svn/repository/!svn/rvr/3062/dev/trunk/code/provider/Investor/Investor.cs'
myself@myserver:~/Folder$




Most of the Apache2 error.log on the server is filled with GET requests (2,198 of them).  Each of the GET requests is made up of 4 lines that look like this:


[Fri Dec 11 17:40:07.405190 2015] [authz_core:debug] [pid 9390] mod_authz_core.c(809): [client 127.0.0.1:46222] AH01626: authorization result of Require valid-user : denied (no authenticated user yet)
[Fri Dec 11 17:40:07.405199 2015] [authz_core:debug] [pid 9390] mod_authz_core.c(809): [client 127.0.0.1:46222] AH01626: authorization result of <RequireAny>: denied (no authenticated user yet)
[Fri Dec 11 17:40:07.405490 2015] [authz_svn:debug] [pid 9390] mod_authz_svn.c(450): [client 127.0.0.1:46222] Path to authz file is /root/subversion/.apache-auth
[Fri Dec 11 17:40:07.405502 2015] [authz_svn:info] [pid 9390] [client 127.0.0.1:46222] Access granted: 'myself' GET repository:/dev


The first few requests are OPTIONS and PROPFIND, the rest are all GET requests.  Here are the first few (imagine each being made up of the 4 lines above):


... OPTIONS repository:/dev/trunk
... OPTIONS repository:/dev/trunk
... OPTIONS repository:/dev/trunk
... PROPFIND repository:/dev/trunk
... OPTIONS repository:/dev/trunk
... REPORT repository:/dev/trunk
... GET repository:/dev
... GET repository:/
... REPORT repository:
... GET repository:/dev/trunk
... GET repository:/dev/trunk/code
... GET repository:/dev/trunk/code/provider
... GET repository:/dev/trunk/code/provider/Investor
... GET repository:/dev/trunk/code/provider/Investor/Investor.cs
... GET repository:/dev/trunk/code/provider/Investor/provider.Investor.csproj
... GET repository:/dev/trunk/code/provider/Investor/migrate.xml
... GET repository:/dev/trunk/code/provider/Investor/transform.xml
... GET repository:/dev/trunk/code/provider/Investor/data.cs
... GET repository:/dev/trunk/code/provider/Investor/data.xml
... GET repository:/dev/trunk/code/provider/Investor/Properties
... GET repository:/dev/trunk/code/provider/Investor/Properties/AssemblyInfo.cs
... (continues on for 2,198 requests)



After removing all the GET requests, here is what remains in the Apache2 error.log file:

[Fri Dec 11 17:40:02.071015 2015] [ssl:info] [pid 9390] [client 127.0.0.1:46222] AH01964: Connection to child 0 established (server my.server.org:443)
[Fri Dec 11 17:40:02.071400 2015] [ssl:debug] [pid 9390] ssl_engine_kernel.c(1940): [client 127.0.0.1:46222] AH02044: No matching SSL virtual host for servername myserver found (using default/first virtual host)
[Fri Dec 11 17:40:07.368155 2015] [ssl:debug] [pid 9390] ssl_engine_kernel.c(1397): [client 127.0.0.1:46222] AH02275: Certificate Verification, depth 1, CRL checking mode: none [subject: CN=CertificateAuthority,OU=Development,O=MyCompany,L=MyTown,ST=MyState,C=CA / issuer: CN=CertificateAuthority,OU=Development,O=MyCompany,L=MyTown,ST=MyState,C=CA / serial: D8F3B73A249AB90D / notbefore: Dec  7 04:48:38 2011 GMT / notafter: Dec  4 04:48:38 2021 GMT]
[Fri Dec 11 17:40:07.368283 2015] [ssl:debug] [pid 9390] ssl_engine_kernel.c(1397): [client 127.0.0.1:46222] AH02275: Certificate Verification, depth 0, CRL checking mode: none [subject: CN=myself,OU=Development,O=MyCompany,ST=MyState,C=CA / issuer: CN=CertificateAuthority,OU=Development,O=MyCompany,L=MyTown,ST=MyState,C=CA / serial: 100124 / notbefore: Dec  7 04:53:34 2011 GMT / notafter: Dec  4 04:53:34 2021 GMT]
[Fri Dec 11 17:40:07.368923 2015] [ssl:debug] [pid 9390] ssl_engine_kernel.c(1860): [client 127.0.0.1:46222] AH02041: Protocol: TLSv1.2, Cipher: ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)
[Fri Dec 11 17:40:07.369230 2015] [ssl:debug] [pid 9390] ssl_engine_kernel.c(245): [client 127.0.0.1:46222] AH02034: Initial (No.1) HTTPS request received for child 0 (server my.server.org:443)
[Fri Dec 11 17:40:07.369363 2015] [authz_svn:debug] [pid 9390] mod_authz_svn.c(450): [client 127.0.0.1:46222] Path to authz file is /root/subversion/.apache-auth
[Fri Dec 11 17:40:07.369528 2015] [authz_core:debug] [pid 9390] mod_authz_core.c(809): [client 127.0.0.1:46222] AH01626: authorization result of Require valid-user : denied (no authenticated user yet)
[Fri Dec 11 17:40:07.369539 2015] [authz_core:debug] [pid 9390] mod_authz_core.c(809): [client 127.0.0.1:46222] AH01626: authorization result of <RequireAny>: denied (no authenticated user yet)
[Fri Dec 11 17:40:07.390500 2015] [ssl:debug] [pid 9390] ssl_engine_kernel.c(245): [client 127.0.0.1:46222] AH02034: Subsequent (No.2) HTTPS request received for child 0 (server my.server.org:443)
[Fri Dec 11 17:40:07.393411 2015] [deflate:debug] [pid 9390] mod_deflate.c(853): [client 127.0.0.1:46222] AH01384: Zlib: Compressed 190 to 129 : URL /svn/repository/dev/trunk
[Fri Dec 11 17:40:07.393917 2015] [ssl:debug] [pid 9390] ssl_engine_kernel.c(245): [client 127.0.0.1:46222] AH02034: Subsequent (No.3) HTTPS request received for child 0 (server my.server.org:443)
[Fri Dec 11 17:40:07.394409 2015] [deflate:debug] [pid 9390] mod_deflate.c(853): [client 127.0.0.1:46222] AH01384: Zlib: Compressed 97 to 78 : URL /svn/repository/dev/trunk
[Fri Dec 11 17:40:07.394691 2015] [ssl:debug] [pid 9390] ssl_engine_kernel.c(245): [client 127.0.0.1:46222] AH02034: Subsequent (No.4) HTTPS request received for child 0 (server my.server.org:443)
[Fri Dec 11 17:40:07.395170 2015] [deflate:debug] [pid 9390] mod_deflate.c(853): [client 127.0.0.1:46222] AH01384: Zlib: Compressed 190 to 129 : URL /svn/repository/dev/trunk
[Fri Dec 11 17:40:07.395536 2015] [ssl:debug] [pid 9390] ssl_engine_kernel.c(245): [client 127.0.0.1:46222] AH02034: Subsequent (No.5) HTTPS request received for child 0 (server my.server.org:443)
[Fri Dec 11 17:40:07.403352 2015] [ssl:debug] [pid 9390] ssl_engine_kernel.c(245): [client 127.0.0.1:46222] AH02034: Subsequent (No.6) HTTPS request received for child 0 (server my.server.org:443)
[Fri Dec 11 17:40:07.404040 2015] [deflate:debug] [pid 9390] mod_deflate.c(853): [client 127.0.0.1:46222] AH01384: Zlib: Compressed 190 to 129 : URL /svn/repository/dev/trunk
[Fri Dec 11 17:40:07.404672 2015] [ssl:debug] [pid 9390] ssl_engine_kernel.c(245): [client 127.0.0.1:46222] AH02034: Subsequent (No.7) HTTPS request received for child 0 (server my.server.org:443)
[Fri Dec 11 17:40:07.405938 2015] [deflate:debug] [pid 9390] mod_deflate.c(853): [client 127.0.0.1:46222] AH01384: Zlib: Compressed 124 to 103 : URL /svn/repository/!svn/rvr/3066/dev/trunk
[Fri Dec 11 17:40:07.406577 2015] [ssl:debug] [pid 9390] ssl_engine_kernel.c(245): [client 127.0.0.1:46222] AH02034: Subsequent (No.8) HTTPS request received for child 0 (server my.server.org:443)
[Fri Dec 11 17:40:07.635617 2015] [ssl:info] [pid 9394] [client 127.0.0.1:46224] AH01964: Connection to child 4 established (server my.server.org:443)
[Fri Dec 11 17:40:07.635662 2015] [ssl:info] [pid 9393] [client 127.0.0.1:46226] AH01964: Connection to child 3 established (server my.server.org:443)
[Fri Dec 11 17:40:07.635759 2015] [ssl:info] [pid 9409] [client 127.0.0.1:46228] AH01964: Connection to child 5 established (server my.server.org:443)
[Fri Dec 11 17:40:07.635926 2015] [ssl:debug] [pid 9394] ssl_engine_kernel.c(1940): [client 127.0.0.1:46224] AH02044: No matching SSL virtual host for servername myserver found (using default/first virtual host)
[Fri Dec 11 17:40:07.635968 2015] [ssl:debug] [pid 9393] ssl_engine_kernel.c(1940): [client 127.0.0.1:46226] AH02044: No matching SSL virtual host for servername myserver found (using default/first virtual host)
[Fri Dec 11 17:40:07.635972 2015] [ssl:debug] [pid 9409] ssl_engine_kernel.c(1940): [client 127.0.0.1:46228] AH02044: No matching SSL virtual host for servername myserver found (using default/first virtual host)
[Fri Dec 11 17:40:07.655133 2015] [ssl:debug] [pid 9394] ssl_engine_kernel.c(1397): [client 127.0.0.1:46224] AH02275: Certificate Verification, depth 1, CRL checking mode: none [subject: CN=CertificateAuthority,OU=Development,O=MyCompany,L=MyTown,ST=MyState,C=CA / issuer: CN=CertificateAuthority,OU=Development,O=MyCompany,L=MyTown,ST=MyState,C=CA / serial: D8F3B73A249AB90D / notbefore: Dec  7 04:48:38 2011 GMT / notafter: Dec  4 04:48:38 2021 GMT]
[Fri Dec 11 17:40:07.655187 2015] [ssl:debug] [pid 9409] ssl_engine_kernel.c(1397): [client 127.0.0.1:46228] AH02275: Certificate Verification, depth 1, CRL checking mode: none [subject: CN=CertificateAuthority,OU=Development,O=MyCompany,L=MyTown,ST=MyState,C=CA / issuer: CN=CertificateAuthority,OU=Development,O=MyCompany,L=MyTown,ST=MyState,C=CA / serial: D8F3B73A249AB90D / notbefore: Dec  7 04:48:38 2011 GMT / notafter: Dec  4 04:48:38 2021 GMT]
[Fri Dec 11 17:40:07.655205 2015] [ssl:debug] [pid 9393] ssl_engine_kernel.c(1397): [client 127.0.0.1:46226] AH02275: Certificate Verification, depth 1, CRL checking mode: none [subject: CN=CertificateAuthority,OU=Development,O=MyCompany,L=MyTown,ST=MyState,C=CA / issuer: CN=CertificateAuthority,OU=Development,O=MyCompany,L=MyTown,ST=MyState,C=CA / serial: D8F3B73A249AB90D / notbefore: Dec  7 04:48:38 2011 GMT / notafter: Dec  4 04:48:38 2021 GMT]
[Fri Dec 11 17:40:07.655219 2015] [ssl:debug] [pid 9394] ssl_engine_kernel.c(1397): [client 127.0.0.1:46224] AH02275: Certificate Verification, depth 0, CRL checking mode: none [subject: CN=myself,OU=Development,O=MyCompany,ST=MyState,C=CA / issuer: CN=CertificateAuthority,OU=Development,O=MyCompany,L=MyTown,ST=MyState,C=CA / serial: 100124 / notbefore: Dec  7 04:53:34 2011 GMT / notafter: Dec  4 04:53:34 2021 GMT]
[Fri Dec 11 17:40:07.655306 2015] [ssl:debug] [pid 9409] ssl_engine_kernel.c(1397): [client 127.0.0.1:46228] AH02275: Certificate Verification, depth 0, CRL checking mode: none [subject: CN=myself,OU=Development,O=MyCompany,ST=MyState,C=CA / issuer: CN=CertificateAuthority,OU=Development,O=MyCompany,L=MyTown,ST=MyState,C=CA / serial: 100124 / notbefore: Dec  7 04:53:34 2011 GMT / notafter: Dec  4 04:53:34 2021 GMT]
[Fri Dec 11 17:40:07.655329 2015] [ssl:debug] [pid 9393] ssl_engine_kernel.c(1397): [client 127.0.0.1:46226] AH02275: Certificate Verification, depth 0, CRL checking mode: none [subject: CN=myself,OU=Development,O=MyCompany,ST=MyState,C=CA / issuer: CN=CertificateAuthority,OU=Development,O=MyCompany,L=MyTown,ST=MyState,C=CA / serial: 100124 / notbefore: Dec  7 04:53:34 2011 GMT / notafter: Dec  4 04:53:34 2021 GMT]
[Fri Dec 11 17:40:07.655807 2015] [ssl:debug] [pid 9394] ssl_engine_kernel.c(1860): [client 127.0.0.1:46224] AH02041: Protocol: TLSv1.2, Cipher: ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)
[Fri Dec 11 17:40:07.655992 2015] [ssl:debug] [pid 9394] ssl_engine_kernel.c(245): [client 127.0.0.1:46224] AH02034: Initial (No.1) HTTPS request received for child 4 (server my.server.org:443)
[Fri Dec 11 17:40:07.656001 2015] [ssl:debug] [pid 9409] ssl_engine_kernel.c(1860): [client 127.0.0.1:46228] AH02041: Protocol: TLSv1.2, Cipher: ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)
[Fri Dec 11 17:40:07.656095 2015] [ssl:debug] [pid 9393] ssl_engine_kernel.c(1860): [client 127.0.0.1:46226] AH02041: Protocol: TLSv1.2, Cipher: ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)
[Fri Dec 11 17:40:07.656270 2015] [ssl:debug] [pid 9409] ssl_engine_kernel.c(245): [client 127.0.0.1:46228] AH02034: Initial (No.1) HTTPS request received for child 5 (server my.server.org:443)
[Fri Dec 11 17:40:07.657170 2015] [ssl:debug] [pid 9393] ssl_engine_kernel.c(245): [client 127.0.0.1:46226] AH02034: Initial (No.1) HTTPS request received for child 3 (server my.server.org:443)
[Fri Dec 11 17:40:07.659118 2015] [deflate:debug] [pid 9394] mod_deflate.c(853): [client 127.0.0.1:46224] AH01384: Zlib: Compressed 1212 to 451 : URL /svn/repository/!svn/rvr/1729/dev/trunk/code/provider/Client/Price-wrapper.xml
[Fri Dec 11 17:40:07.659482 2015] [ssl:debug] [pid 9394] ssl_engine_kernel.c(245): [client 127.0.0.1:46224] AH02034: Subsequent (No.2) HTTPS request received for child 4 (server my.server.org:443)
[Fri Dec 11 17:40:07.660781 2015] [deflate:debug] [pid 9394] mod_deflate.c(853): [client 127.0.0.1:46224] AH01384: Zlib: Compressed 3937 to 907 : URL /svn/repository/!svn/rvr/1710/dev/trunk/code/provider/Client/Account.xsd
[Fri Dec 11 17:40:07.660922 2015] [ssl:debug] [pid 9394] ssl_engine_kernel.c(245): [client 127.0.0.1:46224] AH02034: Subsequent (No.3) HTTPS request received for child 4 (server my.server.org:443)
[Fri Dec 11 17:40:07.745767 2015] [deflate:debug] [pid 9394] mod_deflate.c(853): [client 127.0.0.1:46224] AH01384: Zlib: Compressed 4167011 to 103774 : URL /svn/repository/!svn/rvr/1710/dev/trunk/code/provider/Client/History-sample.xml
[Fri Dec 11 17:40:07.746614 2015] [ssl:debug] [pid 9394] ssl_engine_kernel.c(245): [client 127.0.0.1:46224] AH02034: Subsequent (No.4) HTTPS request received for child 4 (server my.server.org:443)
[Fri Dec 11 17:40:07.748365 2015] [deflate:debug] [pid 9394] mod_deflate.c(853): [client 127.0.0.1:46224] AH01384: Zlib: Compressed 331 to 202 : URL /svn/repository/!svn/rvr/3042/dev/trunk/code/provider/ClientInstitutional/migrate.xml
[Fri Dec 11 17:40:08.131029 2015] [ssl:debug] [pid 9409] ssl_engine_io.c(1007): [client 127.0.0.1:46228] AH02001: Connection closed to child 5 with standard shutdown (server my.server.org:443)
[Fri Dec 11 17:40:08.147313 2015] [ssl:info] [pid 9394] (70014)End of file found: [client 127.0.0.1:46224] AH01991: SSL input filter read failed.
[Fri Dec 11 17:40:08.147401 2015] [ssl:debug] [pid 9394] ssl_engine_io.c(1007): [client 127.0.0.1:46224] AH02001: Connection closed to child 4 with standard shutdown (server my.server.org:443)
[Fri Dec 11 17:40:08.437594 2015] [ssl:debug] [pid 9393] ssl_engine_io.c(1007): [client 127.0.0.1:46226] AH02001: Connection closed to child 3 with standard shutdown (server my.server.org:443)
[Fri Dec 11 17:40:10.974588 2015] [ssl:info] [pid 9390] (32)Broken pipe: [client 127.0.0.1:46222] AH01993: SSL output filter write failed.
[Fri Dec 11 17:40:10.974735 2015] [dav:error] [pid 9390] [client 127.0.0.1:46222] Provider encountered an error while streaming a REPORT response.  [500, #0]
[Fri Dec 11 17:40:10.974743 2015] [dav:error] [pid 9390] [client 127.0.0.1:46222] A failure occurred while driving the update report editor  [500, #32]
[Fri Dec 11 17:40:10.974747 2015] [dav:error] [pid 9390] [client 127.0.0.1:46222] Broken pipe  [500, #32]
[Fri Dec 11 17:40:10.974756 2015] [deflate:debug] [pid 9390] mod_deflate.c(853): [client 127.0.0.1:46222] AH01384: Zlib: Compressed 1358663 to 138938 : URL /svn/repository/!svn/me


The log file ends just like that - part way through a message.  The rest of the path never gets added to the error.log file.

Does any of this explain what is going wrong or do I need to debug Subversion itself?

Thanks.