Bug #5606: SVN + ssh subdirectory failure - RhodeCode CE/EE - RhodeCode - issues

Actions

Copy link

Bug #5606

open

SVN + ssh subdirectory failure

Added by Luke Mauldin over 4 years ago. Updated over 4 years ago.

Status:

Resolved

Priority:

High

Assignee:

Daniel D

Category:

Target version:

Start date:

30.03.2020

Due date:

% Done:

Estimated time:

Sorting:

Commit Number:

Affected Version:

Description

Encountered a bug when using SVN + ssh.
Scenario:

Create a new SVN repository: teststructure
Checkout repository as HTTPS
mkdir and commit /trunk/foo
Add and commit file /trunk/foo/test.sql
Svn move /trunk/foo/test.sql to /trunk/foo/test_a.sql and commit
The above steps all work as expected
Checkout teststructure repository as svn+ssh
Svn move /trunk/foo/test_a.sql to /trunk/foo/test_b.sql and commit
this step fails with a permission error (see details below)

Other information: my user account mauldinl is a "super admin" in the tool and all HTTPS operations with SVN work as expected. svn+ssh operations work as expected in the root level of an SVN repository but write operations fail in subdirectories. All git SSH operations work as expected. I have restarted Rhodecode and ran steps to invalidate all cached keys in case it is a caching issue. Experienced the same issue with both file and Redis caching.

Version: Rhodecode 4.18.2
OS: RHEL 8

Debugging information:

❰mauldinl❙/tmp❱✔≻ svn co svn+ssh://rhodecode@XXXXX/playground/teststructure teststructure_ssh
2020-03-30 06:37:34.811 [99778] DEBUG [rhodecode.config.middleware] DEBUG MODE ON | req_id:00000000-0000-0000-0000-000000000000
2020-03-30 06:37:34.811 [99778] DEBUG [rhodecode.config.middleware] Using the following Mako template directories: ['rhodecode:templates'] | req_id:00000000-0000-0000-0000-000000000000
2020-03-30 06:37:34.812 [99778] DEBUG [rhodecode.config.middleware] Using the following pyramid.includes: [] | req_id:00000000-0000-0000-0000-000000000000
2020-03-30 06:37:34.844 [99778] INFO  [rhodecode.model] RhodeCode 4.18.2 initializing db for postgresql://rhodecode:XXXXX@127.0.0.1:5432/rhodecode | req_id:00000000-0000-0000-0000-000000000000
2020-03-30 06:37:34.846 [99778] INFO  [rhodecode.config.environment] Enabled VCS backends: ['svn', 'git'] | req_id:00000000-0000-0000-0000-000000000000
2020-03-30 06:37:34.849 [99778] DEBUG [rhodecode.config.middleware] Initializing main includeme from middleware.pyc | req_id:00000000-0000-0000-0000-000000000000
2020-03-30 06:37:34.874 [99778] DEBUG [rhodecode.lib.rc_cache] dogpile: found following cache regions: set(['cache_perms', 'cache_repo_longterm', 'sql_cache_short', 'cache_license', 'cache_repo']) | req_id:00000000-0000-0000-0000-000000000000
2020-03-30 06:37:34.877 [99778] DEBUG [rhodecode.lib.rc_cache] dogpile: registering a new region cache_perms[{'async_creation_runner': None, 'name': 'cache_perms', 'function_key_generator': <function wrapper at 0x7f4276711848>, 'region_invalidator': <dogpile.cache.region.DefaultInvalidationStrategy object at 0x7f42766fd290>, '_actual_backend': <rhodecode.lib.rc_cache.backends.RedisPickleBackend object at 0x7f42766fded0>, 'function_multi_key_generator': <function function_multi_key_generator at 0x7f4280c39de8>, '_lock_registry': <dogpile.util.nameregistry.NameRegistry object at 0x7f4281a39c50>, 'key_mangler': None, 'expiration_time': 300, '_user_defined_key_mangler': None, 'backend': <rhodecode.lib.rc_cache.backends.RedisPickleBackend object at 0x7f42766fded0>}] | req_id:00000000-0000-0000-0000-000000000000
2020-03-30 06:37:34.878 [99778] DEBUG [rhodecode.lib.rc_cache] dogpile: registering a new region cache_repo_longterm[{'async_creation_runner': None, 'name': 'cache_repo_longterm', 'function_key_generator': <function wrapper at 0x7f4276718668>, 'region_invalidator': <dogpile.cache.region.DefaultInvalidationStrategy object at 0x7f4281a39d50>, '_actual_backend': <rhodecode.lib.rc_cache.backends.LRUMemoryBackend object at 0x7f4281a39e50>, 'function_multi_key_generator': <function function_multi_key_generator at 0x7f4280c39de8>, '_lock_registry': <dogpile.util.nameregistry.NameRegistry object at 0x7f427671b0d0>, 'key_mangler': None, 'expiration_time': 2592000, '_user_defined_key_mangler': None, 'backend': <rhodecode.lib.rc_cache.backends.LRUMemoryBackend object at 0x7f4281a39e50>}] | req_id:00000000-0000-0000-0000-000000000000
2020-03-30 06:37:34.878 [99778] DEBUG [rhodecode.lib.rc_cache] dogpile: registering a new region sql_cache_short[{'async_creation_runner': None, 'name': 'sql_cache_short', 'function_key_generator': <function wrapper at 0x7f4276718758>, 'region_invalidator': <dogpile.cache.region.DefaultInvalidationStrategy object at 0x7f427671b190>, '_actual_backend': <rhodecode.lib.rc_cache.backends.LRUMemoryBackend object at 0x7f427671b1d0>, 'function_multi_key_generator': <function function_multi_key_generator at 0x7f4280c39de8>, '_lock_registry': <dogpile.util.nameregistry.NameRegistry object at 0x7f427671b290>, 'key_mangler': None, 'expiration_time': 30, '_user_defined_key_mangler': None, 'backend': <rhodecode.lib.rc_cache.backends.LRUMemoryBackend object at 0x7f427671b1d0>}] | req_id:00000000-0000-0000-0000-000000000000
2020-03-30 06:37:34.879 [99778] DEBUG [rhodecode.lib.rc_cache] dogpile: registering a new region cache_license[{'async_creation_runner': None, 'name': 'cache_license', 'function_key_generator': <function wrapper at 0x7f42767188c0>, 'region_invalidator': <dogpile.cache.region.DefaultInvalidationStrategy object at 0x7f427671b310>, '_actual_backend': <class 'rhodecode.lib.rc_cache.backends.FileNamespaceBackend'> `/home/rhodecode/.rccontrol/community-1/data/rc_cache_3`, 'function_multi_key_generator': <function function_multi_key_generator at 0x7f4280c39de8>, '_lock_registry': <dogpile.util.nameregistry.NameRegistry object at 0x7f427671b450>, 'key_mangler': None, 'expiration_time': 300, '_user_defined_key_mangler': None, 'backend': <class 'rhodecode.lib.rc_cache.backends.FileNamespaceBackend'> `/home/rhodecode/.rccontrol/community-1/data/rc_cache_3`}] | req_id:00000000-0000-0000-0000-000000000000
2020-03-30 06:37:34.880 [99778] DEBUG [rhodecode.lib.rc_cache] dogpile: registering a new region cache_repo[{'async_creation_runner': None, 'name': 'cache_repo', 'function_key_generator': <function wrapper at 0x7f42767189b0>, 'region_invalidator': <dogpile.cache.region.DefaultInvalidationStrategy object at 0x7f427671b4d0>, '_actual_backend': <rhodecode.lib.rc_cache.backends.RedisPickleBackend object at 0x7f427671b590>, 'function_multi_key_generator': <function function_multi_key_generator at 0x7f4280c39de8>, '_lock_registry': <dogpile.util.nameregistry.NameRegistry object at 0x7f427671b510>, 'key_mangler': None, 'expiration_time': 2592000, '_user_defined_key_mangler': None, 'backend': <rhodecode.lib.rc_cache.backends.RedisPickleBackend object at 0x7f427671b590>}] | req_id:00000000-0000-0000-0000-000000000000
2020-03-30 06:37:35.046 [99778] INFO  [celery.rhodecode.loader] Configuring celery based on `/home/rhodecode/.rccontrol/community-1/rhodecode.ini` file | req_id:00000000-0000-0000-0000-000000000000
2020-03-30 06:37:35.052 [99778] DEBUG [celery.rhodecode.loader] Got custom celery conf: {u'task_always_eager': False, u'broker_url': u'redis://localhost:6379/8', u'max_tasks_per_child': 100} | req_id:00000000-0000-0000-0000-000000000000
2020-03-30 06:37:35.052 [99778] INFO  [rhodecode.config.middleware] Pyramid app `pyramid_app_with_cleanup` created and configured in 0.24s | req_id:00000000-0000-0000-0000-000000000000
2020-03-30 06:37:35.057 [99778] DEBUG [rhodecode.apps.ssh_support.lib.backends] Mode: `auto` User: `mauldinl:5` Shell: `False` SSH Command: `"svnserve -t"` SCM_DETECTED: `svn` SCM Mode: `auto` SCM Repo: `None` | req_id:80516960-5025-4885-8e80-84dfefb2483e
2020-03-30 06:37:35.282 [99778] DEBUG [rhodecode.apps.ssh_support.lib.backends] Update key id:`2` fingerprint:`MD5:9e:12:51:5d:00:36:87:79:56:0f:6e:c0:52:1a:0b:8e` access time | req_id:80516960-5025-4885-8e80-84dfefb2483e
2020-03-30 06:37:35.282 [99778] DEBUG [rhodecode.apps.ssh_support.lib.backends] SSH Connection info {'client_port': '52644', 'client_ip': '138.254.18.237', 'server_ip': '138.254.135.35', 'server_port': '22'} | req_id:80516960-5025-4885-8e80-84dfefb2483e
2020-03-30 06:37:35.284 [99778] DEBUG [rhodecode.lib.auth] AuthUser: starting data propagation for new potential user | req_id:80516960-5025-4885-8e80-84dfefb2483e
2020-03-30 06:37:35.286 [99778] DEBUG [rhodecode.lib.auth] Trying Auth User lookup by USER ID: `5` | req_id:80516960-5025-4885-8e80-84dfefb2483e
2020-03-30 06:37:35.287 [99778] DEBUG [rhodecode.model.user] AuthUser: fill data execution based on: user_id:5 api_key:None username:None | req_id:80516960-5025-4885-8e80-84dfefb2483e
2020-03-30 06:37:35.287 [99778] DEBUG [rhodecode.model.user] AuthUser: filling found user:<User('id:5:mauldinl')> data | req_id:80516960-5025-4885-8e80-84dfefb2483e
2020-03-30 06:37:35.294 [99778] DEBUG [rhodecode.lib.auth] AuthUser: propagated user is now <AuthUser('id:5[mauldinl] ip:None auth:False')> | req_id:80516960-5025-4885-8e80-84dfefb2483e
2020-03-30 06:37:35.294 [99778] DEBUG [rhodecode.lib.auth] Computing PERMISSION tree for user <AuthUser('id:5[mauldinl] ip:None auth:False')> scope `None` with caching: True[TTL: 300s] | req_id:80516960-5025-4885-8e80-84dfefb2483e
2020-03-30 06:37:35.298 [99778] DEBUG [rhodecode.lib.auth] PERMISSION tree for user <AuthUser('id:5[mauldinl] ip:None auth:False')> computed in 0.0036s: [('repositories', 541), ('global', 2), ('repositories_groups', 18), ('repository_branches', 0), ('user_groups', 5)] | req_id:80516960-5025-4885-8e80-84dfefb2483e
2020-03-30 06:37:35.310 [99778] DEBUG [rhodecode.lib.auth] Computing PERMISSION tree for user <AuthUser('id:5[mauldinl] ip:None auth:False')> scope `OrderedDict([('repo_id', -1), ('user_group_id', -1), ('repo_group_id', -1), ('repo_name', None)])` with caching: True[TTL: 300s] | req_id:80516960-5025-4885-8e80-84dfefb2483e
2020-03-30 06:37:35.347 [99778] DEBUG [rhodecode.lib.auth] PERMISSION tree for user <AuthUser('id:5[mauldinl] ip:None auth:False')> computed in 0.0370s: [('repository_branches', 0), ('global', 2), ('repositories', 0), ('repositories_groups', 0), ('user_groups', 0)] | req_id:80516960-5025-4885-8e80-84dfefb2483e
2020-03-30 06:37:35.349 [99778] DEBUG [rhodecode.apps.ssh_support.lib.backends] VCS detected:`svn` mode: `auto` repo_name: None, branch_permission_checks:False | req_id:80516960-5025-4885-8e80-84dfefb2483e
2020-03-30 06:37:35.349 [99778] DEBUG [rhodecode.lib.hooks_daemon] Preparing HTTP callback daemon at `127.0.0.1:36369` and registering hook object | req_id:80516960-5025-4885-8e80-84dfefb2483e
2020-03-30 06:37:35.350 [99778] DEBUG [rhodecode.lib.hooks_daemon] Prepared a callback daemon: HttpHooksCallbackDaemon at url `127.0.0.1:36369` | req_id:80516960-5025-4885-8e80-84dfefb2483e
2020-03-30 06:37:35.350 [99778] DEBUG [rhodecode.lib.hooks_daemon] Running `HttpHooksCallbackDaemon` callback daemon | req_id:80516960-5025-4885-8e80-84dfefb2483e
2020-03-30 06:37:35.350 [99778] DEBUG [rhodecode.lib.hooks_daemon] Running event loop of callback daemon in background thread | req_id:80516960-5025-4885-8e80-84dfefb2483e
2020-03-30 06:37:35.350 [99778] DEBUG [rhodecode.apps.ssh_support.lib.backends.svn] Using svn binaries from path ~/.rccontrol/vcsserver-1/profile/bin/svnserve | req_id:80516960-5025-4885-8e80-84dfefb2483e
2020-03-30 06:37:35.350 [99778] DEBUG [rhodecode.apps.ssh_support.lib.backends.svn] Final CMD: ~/.rccontrol/vcsserver-1/profile/bin/svnserve -t --config-file /tmp/tmp3ldrQa -r /srv/rhodecode/repos/ | req_id:80516960-5025-4885-8e80-84dfefb2483e
svnserve: warning: cannot set LC_CTYPE locale
svnserve: warning: environment variable LANG is en_US.UTF-8
svnserve: warning: please check that your locale name is correct
2020-03-30 06:37:35.510 [99778] DEBUG [rhodecode.apps.ssh_support.lib.backends.base] permission for <User('id:5:mauldinl')> on playground/teststructure are: repository.admin | req_id:80516960-5025-4885-8e80-84dfefb2483e
2020-03-30 06:37:35.510 [99778] INFO  [rhodecode.apps.ssh_support.lib.backends.base] READ Permissions for User "<User('id:5:mauldinl')>" detected to repo "playground/teststructure"! | req_id:80516960-5025-4885-8e80-84dfefb2483e
A    teststructure_ssh/trunk
A    teststructure_ssh/trunk/bar
A    teststructure_ssh/trunk/bar/test_b2.sql
A    teststructure_ssh/trunk/bar/test_b3.sql
A    teststructure_ssh/trunk/bar/test_b5.sql
A    teststructure_ssh/trunk/bar/test_b7.sql
A    teststructure_ssh/trunk/foo
A    teststructure_ssh/trunk/foo/test_a.sql
Checked out revision 16.
❰mauldinl❙/tmp❱✔≻ cd teststructure_ssh/trunk/
❰mauldinl❙/tmp/teststructure_ssh/trunk❱✔≻ ls
bar/  foo/
❰mauldinl❙/tmp/teststructure_ssh/trunk❱✔≻ cd foo
❰mauldinl❙/tmp/teststructure_ssh/trunk/foo❱✔≻ ls
test_a.sql
❰mauldinl❙/tmp/teststructure_ssh/trunk/foo❱✔≻ svn mv test_a.sql test_b.sql
A         test_b.sql
D         test_a.sql
❰mauldinl❙/tmp/teststructure_ssh/trunk/foo❱✔≻ svn commit -m "Move file"
2020-03-30 06:38:07.291 [99839] DEBUG [rhodecode.config.middleware] DEBUG MODE ON | req_id:00000000-0000-0000-0000-000000000000
2020-03-30 06:38:07.292 [99839] DEBUG [rhodecode.config.middleware] Using the following Mako template directories: ['rhodecode:templates'] | req_id:00000000-0000-0000-0000-000000000000
2020-03-30 06:38:07.292 [99839] DEBUG [rhodecode.config.middleware] Using the following pyramid.includes: [] | req_id:00000000-0000-0000-0000-000000000000
2020-03-30 06:38:07.325 [99839] INFO  [rhodecode.model] RhodeCode 4.18.2 initializing db for postgresql://rhodecode:XXXXX@127.0.0.1:5432/rhodecode | req_id:00000000-0000-0000-0000-000000000000
2020-03-30 06:38:07.326 [99839] INFO  [rhodecode.config.environment] Enabled VCS backends: ['svn', 'git'] | req_id:00000000-0000-0000-0000-000000000000
2020-03-30 06:38:07.330 [99839] DEBUG [rhodecode.config.middleware] Initializing main includeme from middleware.pyc | req_id:00000000-0000-0000-0000-000000000000
2020-03-30 06:38:07.355 [99839] DEBUG [rhodecode.lib.rc_cache] dogpile: found following cache regions: set(['cache_perms', 'cache_repo_longterm', 'sql_cache_short', 'cache_license', 'cache_repo']) | req_id:00000000-0000-0000-0000-000000000000
2020-03-30 06:38:07.358 [99839] DEBUG [rhodecode.lib.rc_cache] dogpile: registering a new region cache_perms[{'async_creation_runner': None, 'name': 'cache_perms', 'function_key_generator': <function wrapper at 0x7f8fdae5d848>, 'region_invalidator': <dogpile.cache.region.DefaultInvalidationStrategy object at 0x7f8fdae49290>, '_actual_backend': <rhodecode.lib.rc_cache.backends.RedisPickleBackend object at 0x7f8fdae49ed0>, 'function_multi_key_generator': <function function_multi_key_generator at 0x7f8fe5385de8>, '_lock_registry': <dogpile.util.nameregistry.NameRegistry object at 0x7f8fe6185c50>, 'key_mangler': None, 'expiration_time': 300, '_user_defined_key_mangler': None, 'backend': <rhodecode.lib.rc_cache.backends.RedisPickleBackend object at 0x7f8fdae49ed0>}] | req_id:00000000-0000-0000-0000-000000000000
2020-03-30 06:38:07.359 [99839] DEBUG [rhodecode.lib.rc_cache] dogpile: registering a new region cache_repo_longterm[{'async_creation_runner': None, 'name': 'cache_repo_longterm', 'function_key_generator': <function wrapper at 0x7f8fdae64668>, 'region_invalidator': <dogpile.cache.region.DefaultInvalidationStrategy object at 0x7f8fe6185d50>, '_actual_backend': <rhodecode.lib.rc_cache.backends.LRUMemoryBackend object at 0x7f8fe6185e50>, 'function_multi_key_generator': <function function_multi_key_generator at 0x7f8fe5385de8>, '_lock_registry': <dogpile.util.nameregistry.NameRegistry object at 0x7f8fdae670d0>, 'key_mangler': None, 'expiration_time': 2592000, '_user_defined_key_mangler': None, 'backend': <rhodecode.lib.rc_cache.backends.LRUMemoryBackend object at 0x7f8fe6185e50>}] | req_id:00000000-0000-0000-0000-000000000000
2020-03-30 06:38:07.359 [99839] DEBUG [rhodecode.lib.rc_cache] dogpile: registering a new region sql_cache_short[{'async_creation_runner': None, 'name': 'sql_cache_short', 'function_key_generator': <function wrapper at 0x7f8fdae64758>, 'region_invalidator': <dogpile.cache.region.DefaultInvalidationStrategy object at 0x7f8fdae67190>, '_actual_backend': <rhodecode.lib.rc_cache.backends.LRUMemoryBackend object at 0x7f8fdae671d0>, 'function_multi_key_generator': <function function_multi_key_generator at 0x7f8fe5385de8>, '_lock_registry': <dogpile.util.nameregistry.NameRegistry object at 0x7f8fdae67290>, 'key_mangler': None, 'expiration_time': 30, '_user_defined_key_mangler': None, 'backend': <rhodecode.lib.rc_cache.backends.LRUMemoryBackend object at 0x7f8fdae671d0>}] | req_id:00000000-0000-0000-0000-000000000000
2020-03-30 06:38:07.360 [99839] DEBUG [rhodecode.lib.rc_cache] dogpile: registering a new region cache_license[{'async_creation_runner': None, 'name': 'cache_license', 'function_key_generator': <function wrapper at 0x7f8fdae648c0>, 'region_invalidator': <dogpile.cache.region.DefaultInvalidationStrategy object at 0x7f8fdae67310>, '_actual_backend': <class 'rhodecode.lib.rc_cache.backends.FileNamespaceBackend'> `/home/rhodecode/.rccontrol/community-1/data/rc_cache_3`, 'function_multi_key_generator': <function function_multi_key_generator at 0x7f8fe5385de8>, '_lock_registry': <dogpile.util.nameregistry.NameRegistry object at 0x7f8fdae67450>, 'key_mangler': None, 'expiration_time': 300, '_user_defined_key_mangler': None, 'backend': <class 'rhodecode.lib.rc_cache.backends.FileNamespaceBackend'> `/home/rhodecode/.rccontrol/community-1/data/rc_cache_3`}] | req_id:00000000-0000-0000-0000-000000000000
2020-03-30 06:38:07.361 [99839] DEBUG [rhodecode.lib.rc_cache] dogpile: registering a new region cache_repo[{'async_creation_runner': None, 'name': 'cache_repo', 'function_key_generator': <function wrapper at 0x7f8fdae649b0>, 'region_invalidator': <dogpile.cache.region.DefaultInvalidationStrategy object at 0x7f8fdae674d0>, '_actual_backend': <rhodecode.lib.rc_cache.backends.RedisPickleBackend object at 0x7f8fdae67590>, 'function_multi_key_generator': <function function_multi_key_generator at 0x7f8fe5385de8>, '_lock_registry': <dogpile.util.nameregistry.NameRegistry object at 0x7f8fdae67510>, 'key_mangler': None, 'expiration_time': 2592000, '_user_defined_key_mangler': None, 'backend': <rhodecode.lib.rc_cache.backends.RedisPickleBackend object at 0x7f8fdae67590>}] | req_id:00000000-0000-0000-0000-000000000000
2020-03-30 06:38:07.526 [99839] INFO  [celery.rhodecode.loader] Configuring celery based on `/home/rhodecode/.rccontrol/community-1/rhodecode.ini` file | req_id:00000000-0000-0000-0000-000000000000
2020-03-30 06:38:07.532 [99839] DEBUG [celery.rhodecode.loader] Got custom celery conf: {u'task_always_eager': False, u'broker_url': u'redis://localhost:6379/8', u'max_tasks_per_child': 100} | req_id:00000000-0000-0000-0000-000000000000
2020-03-30 06:38:07.532 [99839] INFO  [rhodecode.config.middleware] Pyramid app `pyramid_app_with_cleanup` created and configured in 0.24s | req_id:00000000-0000-0000-0000-000000000000
2020-03-30 06:38:07.537 [99839] DEBUG [rhodecode.apps.ssh_support.lib.backends] Mode: `auto` User: `mauldinl:5` Shell: `False` SSH Command: `"svnserve -t"` SCM_DETECTED: `svn` SCM Mode: `auto` SCM Repo: `None` | req_id:f2d3044f-0809-458c-9342-082d91e7c7ef
2020-03-30 06:38:07.758 [99839] DEBUG [rhodecode.apps.ssh_support.lib.backends] Update key id:`2` fingerprint:`MD5:9e:12:51:5d:00:36:87:79:56:0f:6e:c0:52:1a:0b:8e` access time | req_id:f2d3044f-0809-458c-9342-082d91e7c7ef
2020-03-30 06:38:07.758 [99839] DEBUG [rhodecode.apps.ssh_support.lib.backends] SSH Connection info {'client_port': '52644', 'client_ip': '138.254.18.237', 'server_ip': '138.254.135.35', 'server_port': '22'} | req_id:f2d3044f-0809-458c-9342-082d91e7c7ef
2020-03-30 06:38:07.760 [99839] DEBUG [rhodecode.lib.auth] AuthUser: starting data propagation for new potential user | req_id:f2d3044f-0809-458c-9342-082d91e7c7ef
2020-03-30 06:38:07.763 [99839] DEBUG [rhodecode.lib.auth] Trying Auth User lookup by USER ID: `5` | req_id:f2d3044f-0809-458c-9342-082d91e7c7ef
2020-03-30 06:38:07.763 [99839] DEBUG [rhodecode.model.user] AuthUser: fill data execution based on: user_id:5 api_key:None username:None | req_id:f2d3044f-0809-458c-9342-082d91e7c7ef
2020-03-30 06:38:07.763 [99839] DEBUG [rhodecode.model.user] AuthUser: filling found user:<User('id:5:mauldinl')> data | req_id:f2d3044f-0809-458c-9342-082d91e7c7ef
2020-03-30 06:38:07.770 [99839] DEBUG [rhodecode.lib.auth] AuthUser: propagated user is now <AuthUser('id:5[mauldinl] ip:None auth:False')> | req_id:f2d3044f-0809-458c-9342-082d91e7c7ef
2020-03-30 06:38:07.770 [99839] DEBUG [rhodecode.lib.auth] Computing PERMISSION tree for user <AuthUser('id:5[mauldinl] ip:None auth:False')> scope `None` with caching: True[TTL: 300s] | req_id:f2d3044f-0809-458c-9342-082d91e7c7ef
2020-03-30 06:38:07.774 [99839] DEBUG [rhodecode.lib.auth] PERMISSION tree for user <AuthUser('id:5[mauldinl] ip:None auth:False')> computed in 0.0034s: [('repositories', 541), ('global', 2), ('repositories_groups', 18), ('repository_branches', 0), ('user_groups', 5)] | req_id:f2d3044f-0809-458c-9342-082d91e7c7ef
2020-03-30 06:38:07.785 [99839] DEBUG [rhodecode.lib.auth] Computing PERMISSION tree for user <AuthUser('id:5[mauldinl] ip:None auth:False')> scope `OrderedDict([('repo_id', -1), ('user_group_id', -1), ('repo_group_id', -1), ('repo_name', None)])` with caching: True[TTL: 300s] | req_id:f2d3044f-0809-458c-9342-082d91e7c7ef
2020-03-30 06:38:07.786 [99839] DEBUG [rhodecode.lib.auth] PERMISSION tree for user <AuthUser('id:5[mauldinl] ip:None auth:False')> computed in 0.0004s: [('repositories', 0), ('global', 2), ('repository_branches', 0), ('repositories_groups', 0), ('user_groups', 0)] | req_id:f2d3044f-0809-458c-9342-082d91e7c7ef
2020-03-30 06:38:07.788 [99839] DEBUG [rhodecode.apps.ssh_support.lib.backends] VCS detected:`svn` mode: `auto` repo_name: None, branch_permission_checks:False | req_id:f2d3044f-0809-458c-9342-082d91e7c7ef
2020-03-30 06:38:07.788 [99839] DEBUG [rhodecode.lib.hooks_daemon] Preparing HTTP callback daemon at `127.0.0.1:56149` and registering hook object | req_id:f2d3044f-0809-458c-9342-082d91e7c7ef
2020-03-30 06:38:07.788 [99839] DEBUG [rhodecode.lib.hooks_daemon] Prepared a callback daemon: HttpHooksCallbackDaemon at url `127.0.0.1:56149` | req_id:f2d3044f-0809-458c-9342-082d91e7c7ef
2020-03-30 06:38:07.789 [99839] DEBUG [rhodecode.lib.hooks_daemon] Running `HttpHooksCallbackDaemon` callback daemon | req_id:f2d3044f-0809-458c-9342-082d91e7c7ef
2020-03-30 06:38:07.789 [99839] DEBUG [rhodecode.lib.hooks_daemon] Running event loop of callback daemon in background thread | req_id:f2d3044f-0809-458c-9342-082d91e7c7ef
2020-03-30 06:38:07.789 [99839] DEBUG [rhodecode.apps.ssh_support.lib.backends.svn] Using svn binaries from path ~/.rccontrol/vcsserver-1/profile/bin/svnserve | req_id:f2d3044f-0809-458c-9342-082d91e7c7ef
2020-03-30 06:38:07.789 [99839] DEBUG [rhodecode.apps.ssh_support.lib.backends.svn] Final CMD: ~/.rccontrol/vcsserver-1/profile/bin/svnserve -t --config-file /tmp/tmpz0gGYF -r /srv/rhodecode/repos/ | req_id:f2d3044f-0809-458c-9342-082d91e7c7ef
svnserve: warning: cannot set LC_CTYPE locale
svnserve: warning: environment variable LANG is en_US.UTF-8
svnserve: warning: please check that your locale name is correct
2020-03-30 06:38:07.969 [99839] DEBUG [rhodecode.apps.ssh_support.lib.backends.base] permission for <User('id:5:mauldinl')> on playground/teststructure/trunk/foo are: None | req_id:f2d3044f-0809-458c-9342-082d91e7c7ef
2020-03-30 06:38:07.969 [99839] ERROR [rhodecode.apps.ssh_support.lib.backends.base] user `<User('id:5:mauldinl')>` permissions to repo:playground/teststructure/trunk/foo are empty. Forbidding access. | req_id:f2d3044f-0809-458c-9342-082d91e7c7ef
2020-03-30 06:38:07.970 [99839] DEBUG [rhodecode.apps.ssh_support.lib.backends.base] Running cleanup with cache invalidation | req_id:f2d3044f-0809-458c-9342-082d91e7c7ef
2020-03-30 06:38:07.976 [99839] DEBUG [rhodecode.lib.hooks_daemon] Exiting `HttpHooksCallbackDaemon` callback daemon | req_id:f2d3044f-0809-458c-9342-082d91e7c7ef
2020-03-30 06:38:07.976 [99839] DEBUG [rhodecode.lib.hooks_daemon] Waiting for background thread to finish. | req_id:f2d3044f-0809-458c-9342-082d91e7c7ef
2020-03-30 06:38:07.983 [99839] DEBUG [rhodecode.lib.hooks_daemon] Background thread done. | req_id:f2d3044f-0809-458c-9342-082d91e7c7ef
svnserve: E210002: Network connection closed unexpectedly
svn: E170013: Commit failed (details follow):
svn: E170013: Unable to connect to a repository at URL 'svn+ssh://rhodecode@XXXXX/playground/teststructure/trunk/foo'
svn: E210002: Network connection closed unexpectedly

Actions

Copy link

Updated by Marcin Kuzminski [CTO] over 4 years ago

Assignee set to Daniel D

Actions

Copy link

Updated by Marcin Kuzminski [CTO] over 4 years ago

Priority changed from Normal to High

Confirmed, we'll do a fix asap.

note: probably we should do a bugfix release just for this...

Actions

Copy link

Updated by Luke Mauldin over 4 years ago

Thank you for investigation. Just curious, is this specific to our configuration or was this generally broken for SSH+SVN? If it is not specific to our environment, do very few customers use SSH+SVN?

Actions

Copy link

Updated by Marcin Kuzminski [CTO] over 4 years ago

Yes, unfortunately, this was broken for all users.

We're actually surprised this wasn't reported before.

We think that it's both:

SSH+SVN not commonly used (mostly migrating users came from Apache+mod_dav)
SVN+SSH support was added as the last supported combination as wasn't there from the beginning.

Actions

Copy link

Updated by Marcin Kuzminski [CTO] over 4 years ago

@Luke Mauldin in your organization case, do you only now started to test SSH+SVN ?

Actions

Copy link

Updated by Luke Mauldin over 4 years ago

We are new users of Rhodecode and recently setup SSH+SVN access and then ran into this bug.

Actions

Copy link

Updated by Luke Mauldin over 4 years ago

I have a related question about SSH access. Let me know if this needs to be filed in another bug report.
Scenario 1:
1.Clone a small git repo via https

Make a small change to a .txt file and commit git
Execute "git push" - takes about 1.5 seconds Perform the same steps above but clone the repo via ssh+git. The "git push" takes around 4.5 seconds.

Scenario 2:
Execute git remote show origin. The https repo takes about 300 milliseconds to respond while the ssh+git repo takes about 4.0 seconds to respond.

These tests are all performed over a high-bandwidth low latency LAN.

Why the drastic performance difference between git+https vs git+ssh? Is this due to a misconfiguration of our environment? Should I submit this as a seperate bug?

Actions

Copy link

Updated by Marcin Kuzminski [CTO] over 4 years ago

It's a known issue that currently the SSH backend has some overhead. (git remote show origin takes ~3s against our public https://code.rhodecode.com/appenlight)
The bootstrap of single operation takes long time for spawning a new worker to handle SSH+All DB connections, permissions checks etc.
It's mostly visible on small operations, a larger push, or clone should be more or less similar performance.

We're constantly improving the performance of that piece, and I hope we make it soon closer to the http performance.

Actions

Copy link

Updated by Luke Mauldin over 4 years ago

Thank you for the confirmation. When you say "soon", are you hopeful in maybe release 4.19 or is that a change that will most likely be 3-6+ months away?

Actions

Copy link

#10

Updated by Marcin Kuzminski [CTO] over 4 years ago

To be honest, this depends on the priority we put onto this, so far we've got 1 more customer we promised to work on this, but this hasn't been a top priority for them (there are other things)
Our EE customers have priority on those type of things, so if there's a strong push on this it could make it to 4.19

Actions

Copy link

#11

Updated by Redmine Integration over 4 years ago

Status changed from New to Resolved

Commit 5da17e74f2ad by Daniel Dourvaris daniel@rhodecode.com on default branch changed this issue.
https://code.rhodecode.com/rhodecode-enterprise-ce/changeset/5da17e74f2ad4eacc891bac2975e8b5b2076bf11

Actions

Copy link

#12

Updated by Luke Mauldin over 4 years ago

I applied the fix locally and it resolved my issue. Thank you very much. I do not know if this is related or not, but now when I do an svn commit via ssh+svn I get this text:

svn commit -m "Move file"
svnserve: warning: cannot set LC_CTYPE locale
svnserve: warning: environment variable LANG is en_US.UTF-8
svnserve: warning: please check that your locale name is correct
Deleting       trunk/foo/test_a.sql
Adding         trunk/foo/test_b.sql
Committing transaction...
Committed revision 17.

I do not know why I get the LANG type warnings. Here is the locale output for my local workstation:

LANG=en_US.UTF-8
LC_CTYPE="en_US.UTF-8"
LC_NUMERIC="en_US.UTF-8"
LC_TIME="en_US.UTF-8"
LC_COLLATE="en_US.UTF-8"
LC_MONETARY="en_US.UTF-8"
LC_MESSAGES="en_US.UTF-8"
LC_PAPER="en_US.UTF-8"
LC_NAME="en_US.UTF-8"
LC_ADDRESS="en_US.UTF-8"
LC_TELEPHONE="en_US.UTF-8"
LC_MEASUREMENT="en_US.UTF-8"
LC_IDENTIFICATION="en_US.UTF-8"
LC_ALL=

and for the server:

LANG=en_US.UTF-8
LC_CTYPE="en_US.UTF-8"
LC_NUMERIC="en_US.UTF-8"
LC_TIME="en_US.UTF-8"
LC_COLLATE="en_US.UTF-8"
LC_MONETARY="en_US.UTF-8"
LC_MESSAGES="en_US.UTF-8"
LC_PAPER="en_US.UTF-8"
LC_NAME="en_US.UTF-8"
LC_ADDRESS="en_US.UTF-8"
LC_TELEPHONE="en_US.UTF-8"
LC_MEASUREMENT="en_US.UTF-8"
LC_IDENTIFICATION="en_US.UTF-8"
LC_ALL=

Actions

Copy link

#13

Updated by Daniel D over 4 years ago

Regarding the locales, maybe this is related to this: https://docs.rhodecode.com/RhodeCode-Enterprise/known-issues/known-issues.html#fedora-23-ubuntu-18-04

Actions

Copy link

#14

Updated by Luke Mauldin over 4 years ago

I downloaded the locale package and added it both to the systemd startup script and the supervisor.ini file and rebooted the server and I still get the same locale errors on ssh+svn operations. Is there anything else I should try?

Actions

Copy link

#15

Updated by Daniel D over 4 years ago

Are you able to set LC_ALL also to en_US.UTF-8 ?

Actions

Copy link

#16

Updated by Luke Mauldin over 4 years ago

I added the line below to my systemd unit file and restarted the server and still get the error.

Error:

svnserve: warning: cannot set LC_CTYPE locale
svnserve: warning: environment variable LANG is en_US.UTF-8
svnserve: warning: please check that your locale name is correct

Line:

Environment="LC_ALL=en_US.UTF-8"

Actions

Copy link

#17

Updated by Daniel D over 4 years ago

RhodeCode is quite isolated from the system, please try to set it via supervisord.ini a rccontrol self-stop && rccontrol self-init is required after changes in there

Actions

Copy link

#18

Updated by Luke Mauldin over 4 years ago

I edited my supervisor.ini to include the following and restarted using the commands you provided and still received the same error:

[supervisord]
strip_ansi = true
minprocs = 200
environment = HOME=/home/rhodecode,LANG=en_US.UTF-8,LC_ALL=en_US.UTF-8,LOCALE_ARCHIVE=/home/rhodecode/locale-archive

Actions

Copy link

Also available in: Atom PDF

Project

General

Profile

RhodeCode CE/EE

Custom queries

Bug #5606

SVN + ssh subdirectory failure

Updated by Marcin Kuzminski [CTO] over 4 years ago

Updated by Marcin Kuzminski [CTO] over 4 years ago

Updated by Luke Mauldin over 4 years ago

Updated by Marcin Kuzminski [CTO] over 4 years ago

Updated by Marcin Kuzminski [CTO] over 4 years ago

Updated by Luke Mauldin over 4 years ago

Updated by Luke Mauldin over 4 years ago

Updated by Marcin Kuzminski [CTO] over 4 years ago

Updated by Luke Mauldin over 4 years ago

Updated by Marcin Kuzminski [CTO] over 4 years ago

Updated by Redmine Integration over 4 years ago

Updated by Luke Mauldin over 4 years ago

Updated by Daniel D over 4 years ago

Updated by Luke Mauldin over 4 years ago

Updated by Daniel D over 4 years ago

Updated by Luke Mauldin over 4 years ago

Updated by Daniel D over 4 years ago

Updated by Luke Mauldin over 4 years ago