Issue running latest version with SVN?

Hello, I’ve been using Rhodecode for a while and I’m installing it to a new server with the latest version and SVN repositories commits are just not working. I use nginx as a front proxy to SSL all connections.

I set up debug to true on the rhodecode layer and it’s happening a problem while commiting:

Error: Commit failed (details follow):  
Error: Commit blocked by pre-commit hook (exit code 255) with no output.  
Error: This error was generated by a custom hook script on the Subversion server.  
Error: Please contact your server administrator for help with resolving this issue.  

I looked for the logs and found the hook is trying to access a URL in the svn which doesn’t seem to exhist (returns 404). I’m using the same apache/svn configurations I’m using in the other server which works.

Here is the log:

2019-12-20 13:43:06.971 [7285] DEBUG [rhodecode.authentication.base] AUTH_CACHE_TTL for plugin `egg:rhodecode-enterprise-ce#rhodecode` active: True (TTL: 30) | req_id:8983ea38-9c18-4388-8f06-cbfdb09df693
2019-12-20 13:43:06.971 [7285] DEBUG [rhodecode.lib.rc_cache.utils] Using already configured region: cache_user_auth.2 | req_id:8983ea38-9c18-4388-8f06-cbfdb09df693
2019-12-20 13:43:06.971 [7285] DEBUG [rhodecode.authentication.base] Authentication for plugin `egg:rhodecode-enterprise-ce#rhodecode` completed in 0.000s, expiration time of fetched cache 30.0s. | req_id:8983ea38-9c18-4388-8f06-cbfdb09$
2019-12-20 13:43:06.971 [7285] DEBUG [rhodecode.authentication.base] PLUGIN USER DATA: {'user_group_sync': False, 'email': u'matheus@arquis.com.br', 'active_from_extern': True, 'active': True, 'extern_name': 2L, 'groups': [], 'extern_ty$
2019-12-20 13:43:06.971 [7285] DEBUG [rhodecode.authentication.base] Plugin returned proper authentication data | req_id:8983ea38-9c18-4388-8f06-cbfdb09df693
2019-12-20 13:43:06.971 [7285] INFO  [rhodecode.lib.middleware.simplevcs] MAIN-AUTH successful for user `matheus` from rhodecode plugin | req_id:8983ea38-9c18-4388-8f06-cbfdb09df693
2019-12-20 13:43:06.972 [7285] DEBUG [rhodecode.lib.auth] AuthUser: starting data propagation for new potential user | req_id:8983ea38-9c18-4388-8f06-cbfdb09df693
2019-12-20 13:43:06.973 [7285] DEBUG [rhodecode.lib.auth] Trying Auth User lookup by USER ID: `2` | req_id:8983ea38-9c18-4388-8f06-cbfdb09df693
2019-12-20 13:43:06.973 [7285] DEBUG [rhodecode.model.user] AuthUser: fill data execution based on: user_id:2 api_key:None username:None | req_id:8983ea38-9c18-4388-8f06-cbfdb09df693
2019-12-20 13:43:06.973 [7285] DEBUG [rhodecode.model.user] AuthUser: filling found user:<User('id:2:matheus')> data | req_id:8983ea38-9c18-4388-8f06-cbfdb09df693
2019-12-20 13:43:06.977 [7285] DEBUG [rhodecode.lib.auth] AuthUser: propagated user is now <AuthUser('id:2[matheus] ip:None auth:False')> | req_id:8983ea38-9c18-4388-8f06-cbfdb09df693
2019-12-20 13:43:06.977 [7285] DEBUG [rhodecode.lib.middleware.simplevcs] AUTH_CACHE_TTL for permissions `rhodecode` active: True (TTL: 30) | req_id:8983ea38-9c18-4388-8f06-cbfdb09df693
2019-12-20 13:43:06.977 [7285] DEBUG [rhodecode.lib.rc_cache.utils] Using already configured region: cache_user_auth.2 | req_id:8983ea38-9c18-4388-8f06-cbfdb09df693
2019-12-20 13:43:06.977 [7285] DEBUG [rhodecode.lib.middleware.simplevcs] Running plugin `rhodecode` permissions check | req_id:8983ea38-9c18-4388-8f06-cbfdb09df693
2019-12-20 13:43:06.977 [7285] DEBUG [rhodecode.lib.middleware.simplevcs] Permissions for plugin `rhodecode` completed in 0.000s, expiration time of fetched cache 30.0s. | req_id:8983ea38-9c18-4388-8f06-cbfdb09df693
2019-12-20 13:43:06.981 [7285] DEBUG [rhodecode.lib.auth] Computing PERMISSION tree for user <AuthUser('id:2[matheus] ip:None auth:False')> scope `OrderedDict([('repo_id', 1L), ('user_group_id', -1), ('repo_group_id', -1), ('repo_name',$
2019-12-20 13:43:06.981 [7285] DEBUG [rhodecode.lib.rc_cache.utils] Using already configured region: cache_user_auth.2 | req_id:8983ea38-9c18-4388-8f06-cbfdb09df693
2019-12-20 13:43:06.981 [7285] DEBUG [rhodecode.lib.auth] PERMISSION tree for user <AuthUser('id:2[matheus] ip:None auth:False')> computed in 0.000s: [('user_groups', 0), ('repositories_groups', 0), ('repository_branches', 0), ('reposit$
2019-12-20 13:43:06.983 [7285] DEBUG [rhodecode.lib.base] Checking locking on repository "ttest" | req_id:8983ea38-9c18-4388-8f06-cbfdb09df693
2019-12-20 13:43:06.985 [7285] DEBUG [rhodecode.model.db] Repository <Repository('1:ttest')> do not have locking enabled | req_id:8983ea38-9c18-4388-8f06-cbfdb09df693
2019-12-20 13:43:06.985 [7285] DEBUG [rhodecode.model.db] FINAL locking values make_lock:None,locked:False,locked_by:[None, None, None] | req_id:8983ea38-9c18-4388-8f06-cbfdb09df693
2019-12-20 13:43:06.990 [7285] DEBUG [rhodecode.lib.middleware.simplevcs] Repository path is /var/repos/ttest | req_id:8983ea38-9c18-4388-8f06-cbfdb09df693
2019-12-20 13:43:06.990 [7285] INFO  [rhodecode.lib.middleware.simplevcs] push action on svn repo "ttest" by "matheus" from 192.168.0.158 SVN/1.12.2 (x64-microsoft-windows) serf/1.3.9 TortoiseSVN-1.12.2.28653 | req_id:8983ea38-9c18-4388$
2019-12-20 13:43:06.990 [7285] DEBUG [rhodecode.lib.hooks_daemon] Prepared a callback daemon: DummyHooksCallbackDaemon at url `` | req_id:8983ea38-9c18-4388-8f06-cbfdb09df693
2019-12-20 13:43:06.990 [7285] DEBUG [rhodecode.lib.middleware.simplevcs] HOOKS extras is {'locked_by': [None, None, None], 'config': '/root/.rccontrol/community-1/rhodecode.ini', 'hooks_uri': '', 'action': 'push', 'hooks_module': 'rhod$
2019-12-20 13:43:06.990 [7285] DEBUG [rhodecode.lib.hooks_daemon] Running dummy hooks callback daemon | req_id:8983ea38-9c18-4388-8f06-cbfdb09df693
2019-12-20 13:43:06.990 [7285] DEBUG [rhodecode.lib.middleware.simplesvn] Handling: DELETE method via `http://127.0.0.1:8090/ttest/!svn/txn/0-9` | req_id:8983ea38-9c18-4388-8f06-cbfdb09df693
2019-12-20 13:43:06.990 [7285] DEBUG [rhodecode.lib.middleware.simplesvn] Calling SVN PROXY at `http://127.0.0.1:8090/ttest/!svn/txn/0-9`, using method:DELETE. Stream: False | req_id:8983ea38-9c18-4388-8f06-cbfdb09df693
2019-12-20 13:43:06.992 [7285] DEBUG [rhodecode.lib.middleware.simplesvn] Got SVN response:<Response [404]> with text:`
<!DOCTYPE HTML PUBLIC "-//IETF//DTD HTML 2.0//EN">
<html><head>
<title>404 Not Found</title>
</head><body>
<h1>Not Found</h1>
<p>The requested URL /ttest/!svn/txn/0-9 was not found on this server.</p>
</body></html>
` | req_id:8983ea38-9c18-4388-8f06-cbfdb09df693
2019-12-20 13:43:06.992 [7285] INFO  [rhodecode.lib.middleware.request_wrapper] IP: 192.168.0.158 DELETE Request to /ttest/!svn/txn/0-9 time: 0.076s [SVN/1.12.2 (x64-microsoft-windows) serf/1.3.9 TortoiseSVN-1.12.2.28653] | req_id:8983e$
2019-12-20 13:43:06.992 [7285] DEBUG [rhodecode.config.middleware] sa pool status: Pool size: 5  Connections in pool: 1 Current Overflow: -4 Current Checked out connections: 0 | req_id:00000000-0000-0000-0000-000000000000
2019-12-20 13:43:06.992 [7285] DEBUG [rhodecode.config.middleware] Request processing finalized | req_id:00000000-0000-0000-0000-000000000000
2019-12-20 13:43:06.996 [7285] DEBUG [rhodecode.model.db] cache objects marked as invalid for cache args repo_cache:1 | req_id:00000000-0000-0000-0000-000000000000
2019-12-20 13:43:07.004 [7285] DEBUG [rhodecode.lib.utils] settings ui from db@repo[<Repository('1:ttest')>]: [hooks] changegroup.repo_size=python:vcsserver.hooks.repo_size,[hooks] preoutgoing.pre_pull=python:vcsserver.hooks.pre_pull,[h$
2019-12-20 13:43:07.005 [7285] DEBUG [rhodecode.lib.vcs.backends] Creating instance of svn repository from /var/repos/ttest | req_id:00000000-0000-0000-0000-000000000000
2019-12-20 13:43:07.005 [7285] DEBUG [rhodecode.lib.vcs.client_http] RepoMaker call on /var/repos/ttest | req_id:00000000-0000-0000-0000-000000000000
2019-12-20 13:43:07.005 [7285] DEBUG [rhodecode.lib.vcs.client_http] Calling http://127.0.0.1:10010/svn@is_path_valid_repository with args:('/var/repos/ttest',). wire_context: a5a9d9e5-652f-4014-8fe4-28006704559c | req_id:00000000-0000-$
2019-12-20 13:43:07.008 [7285] DEBUG [rhodecode.lib.vcs.client_http] Calling http://127.0.0.1:10010/svn@lookup with args:(None,). wire_context: a5a9d9e5-652f-4014-8fe4-28006704559c | req_id:00000000-0000-0000-0000-000000000000
2019-12-20 13:43:07.010 [7285] DEBUG [rhodecode.lib.vcs.client_http] Calling http://127.0.0.1:10010/svn@is_empty with args:(). wire_context: a5a9d9e5-652f-4014-8fe4-28006704559c | req_id:00000000-0000-0000-0000-000000000000
2019-12-20 13:43:07.019 [7285] DEBUG [rhodecode.model.db] Skipping update_commit_cache for repo:`ttest` commit already with latest changes | req_id:00000000-0000-0000-0000-000000000000
2019-12-20 13:43:07.019 [7285] DEBUG [rhodecode.lib.hooks_daemon] Exiting dummy hooks callback daemon | req_id:00000000-0000-0000-0000-000000000000

Hope someone who’s been through this could help. Thank you.

This looks like a problem with SVN hook, can you check one repo in advanced section there’s a hook option check that also allows to fix it.