[svn.haxx.se] · SVN Dev · SVN Users · SVN Org · TSVN Dev · TSVN Users · Subclipse Dev · Subclipse Users · this month's index

Re: "400 Bad Request" on commit with 1.7 client to 1.7 server

From: Gustavo Chaves <gustavo_at_cpqd.com.br>
Date: Sun, 4 Dec 2011 09:16:33 -0800 (PST)

I straced the httpd daemon to try to get any hint. The last syscalls
before the error are these:

17748 read(18, "POST /admin/!svn/me HTTP/1.1\r\nUs"..., 8000) = 441
17748 stat("/l/home1/svn/admin/htdocs/admin/!svn/me", 0x7fffce99c130)
= -1 ENOENT (No such file or directory)
17748 lstat("/l", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
17748 lstat("/l/home1", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
17748 lstat("/l/home1/svn", {st_mode=S_IFDIR|0775, st_size=4096, ...})
= 0
17748 lstat("/l/home1/svn/admin", {st_mode=S_IFDIR|0755,
st_size=4096, ...}) = 0
17748 lstat("/l/home1/svn/admin/htdocs", {st_mode=S_IFDIR|0775,
st_size=4096, ...}) = 0
17748 lstat("/l/home1/svn/admin/htdocs/admin", 0x7fffce99c130) = -1
ENOENT (No such file or directory)
17748 write(9, "[Sun Dec 04 14:58:00 2011] [debu"..., 207) = 207
17748 semop(5996545, 0x2b526524e160, 1) = 0
17748 semop(5996545, 0x2b526524e16c, 1) = 0
17748 semop(5996545, 0x2b526524e160, 1) = 0
17748 semop(5996545, 0x2b526524e16c, 1) = 0
17748 write(9, "[Sun Dec 04 14:58:00 2011] [debu"..., 133) = 133
17748 write(9, "[Sun Dec 04 14:58:00 2011] [debu"..., 158) = 158
17748 open("/l/home1/svn/admin/admin/db/current", O_RDONLY) = 20
17748 fcntl(20, F_GETFD) = 0
17748 fcntl(20, F_SETFD, FD_CLOEXEC) = 0
17748 read(20, "1\n", 4096) = 2
17748 close(20) = 0
17748 writev(18, [{"HTTP/1.1 400 Bad Request\r\nDate: "..., 226}, {"<!
DOCTYPE HTML PUBLIC \"-//IETF//"..., 226}], 2) = 452

I suppose the initial lstats are from httpd trying first to see if the
URL points to a file and only after failing that it realizes that the
path /admin is a specific Location. Anyway, the last open finds the
correct file in the repository and reads it. I can't see anything to
justify the error message in the last line.

This is a solitary repository configured with a SVNPath directive.
Since I have other repositories under a parent path I tried to perform
commits to one of them and got another error message:

  $ svn info | grep URL
  URL: http://svn2.cpqd.com.br/svn/xpto/trunk
  $ svn ci -mx
  svn: E175002: Commit failed (details follow):
  svn: E175002: Server sent unexpected return value (500 Internal
Server Error) in response to POST request for '/svn/xpto/!svn/me'

This time the following line appeared in the error.log:

  [Sun Dec 04 15:05:37 2011] [info] [client 192.168.100.37] Access
granted: 'gustavo' POST xpto:
  [Sun Dec 04 15:05:37 2011] [error] [client 192.168.100.37]
(20014)Internal error: Can't open file '/l/home1/svn/admin/repos/svn/
format': No such file or directory

Here there's something strange. The repository is in /l/home1/svn/
admin/repos/xpto but the path shown in the log message substitutes
'repos/svn' for 'repos/xpto'.

The apache configuration is this:

  <Location /svn>
    DAV svn
    SVNParentPath /l/home1/svn/admin/repos
    SVNListParentPath on
    AuthzSVNAccessFile /l/home1/svn/admin/admin/conf/authz.txt
  </Location>

Stracing this commit show the following:

17757 read(18, "POST /svn/xpto/!svn/me HTTP/1.1\r"..., 8000) = 444
17757 stat("/l/home1/svn/admin/htdocs/svn/xpto/!svn/me",
0x7fffce99c150) = -1 ENOENT (No such file or directory)
17757 lstat("/l", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
17757 lstat("/l/home1", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
17757 lstat("/l/home1/svn", {st_mode=S_IFDIR|0775, st_size=4096, ...})
= 0
17757 lstat("/l/home1/svn/admin", {st_mode=S_IFDIR|0755,
st_size=4096, ...}) = 0
17757 lstat("/l/home1/svn/admin/htdocs", {st_mode=S_IFDIR|0775,
st_size=4096, ...}) = 0
17757 lstat("/l/home1/svn/admin/htdocs/svn", 0x7fffce99c150) = -1
ENOENT (No such file or directory)
17757 write(9, "[Sun Dec 04 14:54:18 2011] [debu"..., 207) = 207
17757 semop(5996545, 0x2b526524e160, 1) = 0
17757 semop(5996545, 0x2b526524e16c, 1) = 0
17757 semop(5996545, 0x2b526524e160, 1) = 0
17757 semop(5996545, 0x2b526524e16c, 1) = 0
17757 write(9, "[Sun Dec 04 14:54:18 2011] [debu"..., 133) = 133
17757 write(9, "[Sun Dec 04 14:54:18 2011] [debu"..., 168) = 168
17757 write(9, "[Sun Dec 04 14:54:18 2011] [info"..., 95) = 95
17757 open("/l/home1/svn/admin/repos/svn/format", O_RDONLY) = -1
ENOENT (No such file or directory)
17757 write(9, "[Sun Dec 04 14:54:18 2011] [erro"..., 163) = 163
17757 writev(18, [{"HTTP/1.1 500 Internal Server Err"..., 236}, {"<!
DOCTYPE HTML PUBLIC \"-//IETF//"..., 539}], 2) = 775

It tries to open "/l/home1/svn/admin/repos/svn/format" instead of "/l/
home1/svn/admin/repos/xpto/format", but I don't understand why.

Again, I can browse the repositories, checkout, update and ls them. I
just can't commit anything to them.

I feel I'm missing something trivial, but I cannot spot it. Help! :-)

--
Gustavo.
Received on 2011-12-04 20:44:37 CET

This is an archived mail posted to the Subversion Users mailing list.

This site is subject to the Apache Privacy Policy and the Apache Public Forum Archive Policy.