SVN Commit fails, hard to debug
Closed, InvalidPublic
Actions

Assigned To

None

Authored By

	foven
	Dec 7 2015, 7:31 PM

Description

After creating a new svn repository hosted by Phabricator, commit attempts fail with the following error message:

svn: E165001: Commit blocked by pre-commit hook (exit code 255) with no output.

This has proven very difficult to debug. Apparently it often signifies issues such as incorrect permissions or attempts at using programs that aren't available in the environment in which svn hooks are run. I have also seen where users ran into issues with SELinux as well as other miscellaneous issues, such as syntax errors in the offending hook script.

It doesn't seem as though there should be anything wrong with the contents of the hook script, seeing as it is provided by Phabricator and probably works for most users. The permissions and ownership are set by Phabricator as well and the directories look like this:

sudo ls -la /var/repo/SVN/
total 16
drwxr-xr-x. 6 phd phd   80 Dec  4 14:28 .
drwxr-xr-x. 7 phd phd   70 Dec  4 14:38 ..
drwxr-xr-x. 2 phd phd   72 Dec  4 14:28 conf
drwxr-sr-x. 6 phd phd 4096 Dec  4 14:42 db
-r--r--r--. 1 phd phd    2 Dec  4 14:28 format
drwxr-xr-x. 3 phd phd 4096 Dec  4 14:28 hooks
drwxr-xr-x. 2 phd phd   39 Dec  4 14:28 locks
-rw-r--r--. 1 phd phd  246 Dec  4 14:28 README.txt

sudo ls -la /var/repo/SVN/hooks/
total 44
drwxr-xr-x. 3 phd phd 4096 Dec  4 14:28 .
drwxr-xr-x. 6 phd phd   80 Dec  4 14:28 ..
-rwxr-xr-x. 1 phd phd 2062 Dec  4 14:28 post-commit.tmpl
-rwxr-xr-x. 1 phd phd 1638 Dec  4 14:28 post-lock.tmpl
-rwxr-xr-x. 1 phd phd 2289 Dec  4 14:28 post-revprop-change.tmpl
-rwxr-xr-x. 1 phd phd 1567 Dec  4 14:28 post-unlock.tmpl
-rwxr-xr-x. 1 phd phd  123 Dec  4 16:48 pre-commit
drwxr-xr-x. 2 phd phd   19 Dec  4 14:28 pre-commit-phabricator.d
-rwxr-xr-x. 1 phd phd 3426 Dec  4 14:28 pre-commit.tmpl
-rwxr-xr-x. 1 phd phd 2434 Dec  4 14:28 pre-lock.tmpl
-rwxr-xr-x. 1 phd phd 2786 Dec  4 14:28 pre-revprop-change.tmpl
-rwxr-xr-x. 1 phd phd 2122 Dec  4 14:28 pre-unlock.tmpl
-rwxr-xr-x. 1 phd phd 3163 Dec  4 14:28 start-commit.tmpl

I am not using SELinux, it is disabled.

Other repository functions seem to be working. I can checkout code with no issues. If I create a git repository hosted by Phabricator I can commit to that as well, although there may be so many differences between the two that this is completely irrelevant.

For testing purposes, I disabled the Phabricator daemons and used a much simpler hook script, which looks like this:

#!/bin/sh

echo "testing" >&2

exit 1

In this context, running this command:

svn mkdir svn+ssh://vcs@phabricator.example.com/diffusion/SVN/TestFolder -m "Test commit hooks"

yields this output:

svn: E165001: Commit blocked by pre-commit hook (exit code 255) with no output.

It may be interesting to know that this command actually results in the script running successfully:

sudo svn mkdir file:///var/repo/SVN/TestFolder -m "Test commit hooks"
svn: E165001: Commit blocked by pre-commit hook (exit code 1) with output:
testing

If I enable the daemons and try the same, the simple hook script used for testing is overwritten and I get the following results:

svn mkdir svn+ssh://vcs@phabricator.example.com/diffusion/SVN/TestFolder -m "Test commit hooks"
svn: E165001: Commit blocked by pre-commit hook (exit code 255) with no output.

sudo svn mkdir file:///var/repo/SVN/TestFolder -m "Test commit hooks"
svn: E165001: Commit blocked by pre-commit hook (exit code 255) with output:
[2015-12-07 13:09:01] EXCEPTION: (Exception) No such user "root"! at [<phabricator>/scripts/repository/commit_hook.php:108]
arcanist(head=master, ref.master=4a680c762b2e), phabricator(head=master, ref.master=ef820ed1ee29), phutil(head=master, ref.master=a8143ced646d)

For what it's worth, at least one other user seems to have run into this same issue: https://secure.phabricator.com/Q180

I have also asked for help on stackoverflow and the svn mailing list:

http://stackoverflow.com/questions/33789148/svn-e165001-commit-blocked-by-pre-commit-hook-exit-code-255-with-no-output
http://svn.haxx.se/users/archive-2015-12/0003.shtml

Please let me know if there is information I can provide that may be useful. I've been trying to solve this for a while now and tried many things, but it's hard to predict what information may help and what is just useless.

Related Objects

Mentioned In: T10941: Subversion fails to execute pre-commit hook if CWD isn't readable
T10839: SVN ERROR 255 pre-commit hook

Event Timeline

foven created this task.Dec 7 2015, 7:31 PM

foven raised the priority of this task from to Needs Triage.

foven updated the task description. (Show Details)

foven changed the edit policy from "All Users" to "Custom Policy".

foven added a project: Bug Report.

foven added a subscriber: foven.

foven updated the task description. (Show Details)Dec 7 2015, 7:36 PM

Can you give us more details on your system so we can try to reproduce? OS / PHP / Webserver / SVN / etc

Sure.

OS: Fedora 22, kernel 4.2.5-201.fc22.x86_64
PHP: 5.6.15
Webserver: Apache 2.4.17
svnserve: 1.8.13
mysql: Ver 15.1 Distrib 10.0.21-MariaDB, for Linux (x86_64) using readline 5.1

Are there any more details that might be useful?

Are there any more details that might be useful?

Can you give us root SSH access to a server on the public internet where this issue is reproducible?

Can you give us root SSH access to a server on the public internet where this issue is reproducible?

I'm sure that would be really useful, but I doubt I will be allowed to do that. I'll look into it though.

If I could provide a virtual machine image of some sort that shows the issue, would that be useful? It might be more feasible for me to do something like that.

If I could provide a virtual machine image of some sort that shows the issue, would that be useful?

Yes.

Or, let me clarify: if you give us a running VM in EC2 with root credentials, that's useful.

If you give us some image only that we need to load into our own virtualization, that's not useful. It doesn't save us much time over doing everything in EC2 ourselves.

To reproduce this issue, I'd follow these steps:

Launch a new Fedora 22 host in EC2.
Install Phabricator.
Set up Subversion + Diffusion.
Push to it.

I think it is very likely that the push would work at the end of this, meaning that I'd wasted a lot of time.

If you follow these steps instead, you'll either narrow down the problem to an environmental issue (if your second host works fine) or end up with a valid repro we don't need to waste time building.

(If your time is valuable, we're happy to shoulder the entire burden of building a reproduction case and fish around for environmental problems at our consulting rate; see Consulting.)

I've never used EC2 and I'm not entirely sure what's involved with it. There are a few things I'd like to try before doing this, one being a reinstall on the local server. If that doesn't work, I will look into EC2.

Thanks for the information.

chad added projects: Diffusion, Subversion.Dec 12 2015, 5:06 PM

Just an update:

I have reinstalled on both Fedora 22 and Fedora 23 with the same issue. If I'm doing something wrong (which there is a good chance of), I seem to be doing it every time. Else it could be that there is some issue. Or it could be something in the environment outside of the Phabricator installation.

I'll start looking into EC2.

Any additional help is appreciated.

epriestley edited projects, added Bug Report (Needs Information); removed Bug Report.Jan 2 2016, 12:18 AM

I am still trying to find a solution to this, but until I do I am considering hosting the SVN repository outside of Phabricator.

If I later wanted to change this repository to be hosted by Phabricator, is this possible? Or would I have to create a new repository in Diffusion?

Other than that, it seems that the main losses from not hosting the repository within Phabricator would be related to pre-commit functionality and repository access control? Is there anything else that would be missing?

Hopefully I didn't miss any documentation. The only links I found that discuss this are these:

http://stackoverflow.com/questions/30555952/phabricator-advantage-disadvantage-of-hosted-repository
https://secure.phabricator.com/T4482

I have the same issue with SVN+SSH, but not with GIT+SSH. I used strace. This is the part where it breaks - looks like it breaks after the chdir call (in the middle of the snippet):

1277  open("/var/repo/MDM/db/transactions/1196-xx.txn/node.1-563.0", O_RDONLY|O_CLOEXEC) = 3
1277  read(3, "id: 1-563.0.t1196-xx\ntype: file\npred: 1-563.0.r837/98\ncount: 7\ntext: -1 0 160 4289 f6219db61daf8f1dcbeae644277d6d2c f59bd4dde8d96245f84bc1d70c0fbfd87691ee82 1196-xx/_2\ncpath: /wiki/description.wiki\ncopyroot: 0 /\n\n", 409
6) = 209
1277  read(3, "", 4096)                 = 0
1277  read(3, "", 4096)                 = 0
1277  read(3, "", 4096)                 = 0
1277  read(3, "", 4096)                 = 0
1277  read(3, "", 4096)                 = 0
1277  read(3, "", 4096)                 = 0
1277  read(3, "", 4096)                 = 0
1277  read(3, "", 4096)                 = 0
1277  close(3)                          = 0
1277  stat("/var/repo/MDM/hooks/pre-commit", {st_mode=S_IFREG|0755, st_size=118, ...}) = 0
1277  open("/dev/null", O_RDONLY|O_CLOEXEC) = 3
1277  open("/dev/null", O_WRONLY|O_CLOEXEC) = 4
1277  dup(3)                            = 5
1277  fcntl(5, F_GETFD)                 = 0
1277  fcntl(5, F_SETFD, 0)              = 0
1277  dup(4)                            = 6
1277  fcntl(6, F_GETFD)                 = 0
1277  fcntl(6, F_SETFD, 0)              = 0
1277  pipe([7, 8])                      = 0
1277  fcntl(7, F_GETFD)                 = 0
1277  fcntl(7, F_SETFD, FD_CLOEXEC)     = 0
1277  clone(child_stack=0, flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD, child_tidptr=0x7f0c0dfa9a50) = 1278
1277  close(5 <unfinished ...>
1278  set_robust_list(0x7f0c0dfa9a60, 24) = 0
1277  <... close resumed> )             = 0
1277  close(6)                          = 0
1277  close(8)                          = 0
1278  dup3(2, 1, 0 <unfinished ...>
1277  read(7,  <unfinished ...>
1278  <... dup3 resumed> )              = 1
1278  close(7)                          = 0
1278  close(4)                          = 0
1278  close(3)                          = 0
1278  dup2(5, 0)                        = 0
1278  close(5)                          = 0
1278  dup2(6, 1)                        = 1
1278  close(6)                          = 0
1278  dup2(8, 2)                        = 2
1278  close(8)                          = 0
1278  rt_sigaction(SIGCHLD, {SIG_DFL, [], SA_RESTORER|SA_INTERRUPT, 0x7f0c0b70d100}, {SIG_DFL, [], 0}, 8) = 0
1278  chdir(".")                        = -1 EACCES (Permission denied)
1278  exit_group(-1)                    = ?
1278  +++ exited with 255 +++
1277  <... read resumed> "", 16384)     = 0
1277  --- SIGCHLD {si_signo=SIGCHLD, si_code=CLD_EXITED, si_pid=1278, si_status=255, si_utime=0, si_stime=0} ---
1277  wait4(1278, [{WIFEXITED(s) && WEXITSTATUS(s) == 255}], WSTOPPED, NULL) = 1278
1277  close(7)                          = 0
1277  close(4)                          = 0
1277  openat(AT_FDCWD, "/var/repo/MDM/db/transactions/1196-xx.txn", O_RDONLY|O_NONBLOCK|O_DIRECTORY|O_CLOEXEC) = 4
1277  brk(0)                            = 0x7f0c0e529000
1277  brk(0x7f0c0e550000)               = 0x7f0c0e550000
1277  getdents(4, /* 10 entries */, 32768) = 320
1277  lstat("/var/repo/MDM/db/transactions/1196-xx.txn/.", {st_mode=S_IFDIR|S_ISGID|0755, st_size=4096, ...}) = 0
1277  lstat("/var/repo/MDM/db/transactions/1196-xx.txn/..", {st_mode=S_IFDIR|S_ISGID|0755, st_size=24, ...}) = 0
1277  lstat("/var/repo/MDM/db/transactions/1196-xx.txn/node.0.0", {st_mode=S_IFREG|0644, st_size=94, ...}) = 0
1277  lstat("/var/repo/MDM/db/transactions/1196-xx.txn/changes", {st_mode=S_IFREG|0644, st_size=60, ...}) = 0
1277  lstat("/var/repo/MDM/db/transactions/1196-xx.txn/next-ids", {st_mode=S_IFREG|0644, st_size=4, ...}) = 0
1277  lstat("/var/repo/MDM/db/transactions/1196-xx.txn/props", {st_mode=S_IFREG|0644, st_size=147, ...}) = 0
1277  lstat("/var/repo/MDM/db/transactions/1196-xx.txn/node.4-1.0", {st_mode=S_IFREG|0644, st_size=97, ...}) = 0
1277  lstat("/var/repo/MDM/db/transactions/1196-xx.txn/node.0.0.children", {st_mode=S_IFREG|0644, st_size=176, ...}) = 0
1277  lstat("/var/repo/MDM/db/transactions/1196-xx.txn/node.1-563.0", {st_mode=S_IFREG|0644, st_size=209, ...}) = 0
1277  lstat("/var/repo/MDM/db/transactions/1196-xx.txn/node.4-1.0.children", {st_mode=S_IFREG|0644, st_size=620, ...}) = 0
1277  getdents(4, /* 0 entries */, 32768) = 0
1277  brk(0)                            = 0x7f0c0e550000
1277  brk(0)                            = 0x7f0c0e550000
1277  brk(0x7f0c0e548000)               = 0x7f0c0e548000
1277  brk(0)                            = 0x7f0c0e548000
1277  close(4)                          = 0
1277  unlink("/var/repo/MDM/db/transactions/1196-xx.txn/node.0.0") = 0
1277  unlink("/var/repo/MDM/db/transactions/1196-xx.txn/props") = 0
1277  unlink("/var/repo/MDM/db/transactions/1196-xx.txn/node.4-1.0") = 0
1277  unlink("/var/repo/MDM/db/transactions/1196-xx.txn/changes") = 0
1277  unlink("/var/repo/MDM/db/transactions/1196-xx.txn/node.0.0.children") = 0
1277  unlink("/var/repo/MDM/db/transactions/1196-xx.txn/node.4-1.0.children") = 0
1277  unlink("/var/repo/MDM/db/transactions/1196-xx.txn/next-ids") = 0
1277  unlink("/var/repo/MDM/db/transactions/1196-xx.txn/node.1-563.0") = 0
1277  rmdir("/var/repo/MDM/db/transactions/1196-xx.txn") = 0
1277  unlink("/var/repo/MDM/db/txn-protorevs/1196-xx.rev") = 0
1277  unlink("/var/repo/MDM/db/txn-protorevs/1196-xx.rev-lock") = 0
1277  write(1, "( failure ( ( 165001 65:Commit blocked by pre-commit hook (exit code 255) with no output. 0: 0 ) ) ) ", 101) = 101
1277  close(3)                          = 0

Here are my settings that are supposed to be involved in this (as I understand) for SVN+SSH to work:

CentOS 7
- SELinux in Permissive mode
daemon user / phd.daemon: phd
- /etc/passwd settings: phd:x:1002:1002::/var/repo:/sbin/nologin
- /etc/shadow settings: phd:!!:16820:0:99999:7:::
vcs user / ssh user: phabricator
- - /etc/passwd settings: phabricator:x:1001:1001::/home/phabricator:/bin/sh
  - /etc/shadow settings: phabricator:NP:16814:0:99999:7:::
- this user is set in /usr/libexec/phabricator-ssh-hook.sh and in /etc/ssh/sshd_config_phabricator
sudo settings: phabricator ALL=(phd) SETENV: NOPASSWD: /usr/bin/git-upload-pack, /usr/bin/git-receive-pack, /usr/bin/svnserve
permissions for /var/repo/MDM: drwxr-xr-x. 6 phd phd

This has been open for several months without forward progress.

Feel free to file a new task if you discover more information which will allow us to reproduce the issue.

(An strace log is not helpful in reproducing the issue -- see Contributing Bug Reports for a detailed description of exactly what we need to move forward on resolving issues.)

• leonardo.furio mentioned this in T10839: SVN ERROR 255 pre-commit hook.Apr 20 2016, 12:43 PM

epriestley mentioned this in T10941: Subversion fails to execute pre-commit hook if CWD isn't readable.May 9 2016, 11:50 PM

SVN Commit fails, hard to debugClosed, InvalidPublicActions

Description

Related Objects

Event Timeline

SVN Commit fails, hard to debug
Closed, InvalidPublic
Actions