You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@subversion.apache.org by Chris Capon <tt...@gmail.com> on 2015/12/07 23:56:17 UTC
Unexpected HTTP status 400 'Bad request'.
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.
Re: Unexpected HTTP status 400 'Bad request'.
Posted by Chris Capon <tt...@gmail.com>.
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:
> 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.
>
> On Mon, Dec 7, 2015 at 10:13 PM, Chris Capon <ttabyss@gmail.com
> <ma...@gmail.com>> wrote:
Re: Unexpected HTTP status 400 'Bad request'.
Posted by Chris Capon <tt...@gmail.com>.
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:
>
> I guess your repository has been created long ago with a previous
> version of Subversion.
>
Re: Unexpected HTTP status 400 'Bad request'.
Posted by Yves Martin <ym...@gmail.com>.
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
RE: Unexpected HTTP status 400 'Bad request'.
Posted by Bert Huijben <be...@qqmail.nl>.
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:ymartin1040@gmail.com]
Sent: dinsdag 8 december 2015 12:10
To: Subversion <us...@subversion.apache.org>
Subject: Re: Unexpected HTTP status 400 'Bad request'.
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
Re: Unexpected HTTP status 400 'Bad request'.
Posted by Chris Capon <tt...@gmail.com>.
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.
On 2015-12-08 06:09, Yves Martin wrote:
> 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
>
>
Re: Unexpected HTTP status 400 'Bad request'.
Posted by Yves Martin <ym...@gmail.com>.
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
Re: Unexpected HTTP status 400 'Bad request'.
Posted by Chris Capon <tt...@gmail.com>.
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.
Re: Unexpected HTTP status 400 'Bad request'.
Posted by Stefan Sperling <st...@elego.de>.
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.
RE: Unexpected HTTP status 400 'Bad request'.
Posted by Bert Huijben <be...@qqmail.nl>.
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
From: Chris Capon [mailto:ttabyss@gmail.com]
Sent: dinsdag 8 december 2015 15:29
To: users@subversion.apache.org
Subject: Re: Unexpected HTTP status 400 'Bad request'.
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.
On 2015-12-08 05:37, Bert Huijben wrote:
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
From: Yves Martin [ <ma...@gmail.com> mailto:ymartin1040@gmail.com]
Sent: dinsdag 8 december 2015 11:06
To: <ma...@subversion.apache.org> users@subversion.apache.org
Subject: Re: Unexpected HTTP status 400 'Bad request'.
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
Re: Unexpected HTTP status 400 'Bad request'.
Posted by Yves Martin <ym...@gmail.com>.
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
Re: Unexpected HTTP status 400 'Bad request'.
Posted by Chris Capon <tt...@gmail.com>.
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.
On 2015-12-08 05:37, Bert Huijben wrote:
>
> 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
>
> *From:*Yves Martin [mailto:ymartin1040@gmail.com]
> *Sent:* dinsdag 8 december 2015 11:06
> *To:* users@subversion.apache.org
> *Subject:* Re: Unexpected HTTP status 400 'Bad request'.
>
> 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
>
RE: Unexpected HTTP status 400 'Bad request'.
Posted by Bert Huijben <be...@qqmail.nl>.
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
From: Yves Martin [mailto:ymartin1040@gmail.com]
Sent: dinsdag 8 december 2015 11:06
To: users@subversion.apache.org
Subject: Re: Unexpected HTTP status 400 'Bad request'.
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
Re: Unexpected HTTP status 400 'Bad request'.
Posted by Yves Martin <ym...@gmail.com>.
Thanks Philip. Great tips.
Just a remark: port to use in svn ls command is 9630 (instead of 9603)
--
Yves Martin
Re: Unexpected HTTP status 400 'Bad request'.
Posted by Philip Martin <ph...@wandisco.com>.
Chris Capon <tt...@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
Re: Unexpected HTTP status 400 'Bad request'.
Posted by Chris Capon <tt...@gmail.com>.
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?
RE: Unexpected HTTP status 400 'Bad request'.
Posted by Bert Huijben <be...@qqmail.nl>.
> -----Original Message-----
> From: Chris Capon [mailto:ttabyss@gmail.com]
> Sent: dinsdag 8 december 2015 14:47
> To: users@subversion.apache.org
> Subject: Re: Unexpected HTTP status 400 'Bad request'.
>
> 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).
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
Re: Unexpected HTTP status 400 'Bad request'.
Posted by Chris Capon <tt...@gmail.com>.
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.
Re: Unexpected HTTP status 400 'Bad request'.
Posted by Yves Martin <ym...@gmail.com>.
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
Re: Unexpected HTTP status 400 'Bad request'.
Posted by Eric Johnson <er...@tibco.com>.
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.
On Mon, Dec 7, 2015 at 10:13 PM, Chris Capon <tt...@gmail.com> wrote:
> 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.
>
>
>
Re: Unexpected HTTP status 400 'Bad request'.
Posted by Chris Capon <tt...@gmail.com>.
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.
Re: Unexpected HTTP status 400 'Bad request'.
Posted by David Chapman <dc...@acm.org>.
On 12/7/2015 2:56 PM, Chris Capon wrote:
> 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.
>
>
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 dcchapman@acm.org
Chapman Consulting -- San Jose, CA
Software Development Done Right.
www.chapman-consulting-sj.com