subversion-users mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Chris Capon <ttab...@gmail.com>
Subject Re: Unexpected HTTP status 400 'Bad request'.
Date Sat, 12 Dec 2015 05:30:10 GMT
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.


Mime
View raw message