Bug #5540
openRhode Code 4.15.2 VCS Caching(?) behaviour
0%
Description
Hi everybody,
we just installed RhodeCode CE 4.15.2 on top of our existing SVN environment with existing repositories. Till today we access these SVN repos with Apache/mod_dav_svn and Tortoise SVN Client at Windows - Client side.
To make these repos available to RhodeCode, we soft - linked them to the RhodeCode data dir and did a "Remap and Rescan" in RhodeCode web admin, so the repos appear in RhodeCode.
But after a very short time of usage we came accross some strange behaviour of RhodeCode.
To track this down we created a SVN test repository (rhodecode_test) by using Linux cmdline "svnadmin create..." at the server. Then we did some standard tasks with Tortoise over Apache (create trunk/branches/tags folder structure, checkout, commit files / changes) as can be seen in the Tortoise screenshot:
Now we open the Repo in RhodeCode (with a SuperAdmin account) and do see ... nothing... no commits, no changelog, no history
When we hit Browsers "Refresh" 10-20 times somewhen we suddenly see the commits.
A few refreshs later they are gone and the repo seems to be empty (or an older state) again.
Somtimes a refresh leads to a "500 - Internal Server Error" with this in the community.log:
Traceback (most recent call last):
File "/opt/rhodecode/store/mcjhzq84p171b42cwjlszbz8611ir1b8-python2.7-pyramid-1.9.2/lib/python2.7/site-packages/pyramid/tweens.py", line 39, in excview_tween
response = handler(request)
File "/opt/rhodecode/store/mcjhzq84p171b42cwjlszbz8611ir1b8-python2.7-pyramid-1.9.2/lib/python2.7/site-packages/pyramid/router.py", line 156, in handle_request
view_name
File "/opt/rhodecode/store/mcjhzq84p171b42cwjlszbz8611ir1b8-python2.7-pyramid-1.9.2/lib/python2.7/site-packages/pyramid/view.py", line 642, in _call_view
response = view_callable(context, request)
File "/opt/rhodecode/store/mcjhzq84p171b42cwjlszbz8611ir1b8-python2.7-pyramid-1.9.2/lib/python2.7/site-packages/pyramid/viewderivers.py", line 390, in attr_view
return view(context, request)
File "/opt/rhodecode/store/mcjhzq84p171b42cwjlszbz8611ir1b8-python2.7-pyramid-1.9.2/lib/python2.7/site-packages/pyramid/viewderivers.py", line 368, in predicate_wrapper
return view(context, request)
File "/opt/rhodecode/store/mcjhzq84p171b42cwjlszbz8611ir1b8-python2.7-pyramid-1.9.2/lib/python2.7/site-packages/pyramid/viewderivers.py", line 462, in rendered_view
request, result, view_inst, context)
File "/opt/rhodecode/store/mcjhzq84p171b42cwjlszbz8611ir1b8-python2.7-pyramid-1.9.2/lib/python2.7/site-packages/pyramid/renderers.py", line 435, in render_view
return self.render_to_response(response, system, request=request)
File "/opt/rhodecode/store/mcjhzq84p171b42cwjlszbz8611ir1b8-python2.7-pyramid-1.9.2/lib/python2.7/site-packages/pyramid/renderers.py", line 458, in render_to_response
result = self.render(value, system_values, request=request)
File "/opt/rhodecode/store/mcjhzq84p171b42cwjlszbz8611ir1b8-python2.7-pyramid-1.9.2/lib/python2.7/site-packages/pyramid/renderers.py", line 454, in render
result = renderer(value, system_values)
File "/opt/rhodecode/store/jzd3fzw15kzc5k1f14spfjp4sm142h52-python2.7-pyramid-mako-1.0.2/lib/python2.7/site-packages/pyramid_mako/__init__.py", line 156, in __call__
reraise(MakoRenderingException(errtext), None, exc_info[2])
File "/opt/rhodecode/store/jzd3fzw15kzc5k1f14spfjp4sm142h52-python2.7-pyramid-mako-1.0.2/lib/python2.7/site-packages/pyramid_mako/__init__.py", line 148, in __call__
result = template.render_unicode(**system)
File "/opt/rhodecode/store/ida848f1ziml06glki8mawhi38h2k4fv-python2.7-mako-1.0.7/lib/python2.7/site-packages/mako/template.py", line 471, in render_unicode
as_unicode=True)
File "/opt/rhodecode/store/ida848f1ziml06glki8mawhi38h2k4fv-python2.7-mako-1.0.7/lib/python2.7/site-packages/mako/runtime.py", line 838, in _render
**_kwargs_for_callable(callable_, data))
File "/opt/rhodecode/store/ida848f1ziml06glki8mawhi38h2k4fv-python2.7-mako-1.0.7/lib/python2.7/site-packages/mako/runtime.py", line 873, in _render_context
_exec_template(inherit, lclcontext, args=args, kwargs=kwargs)
File "/opt/rhodecode/store/ida848f1ziml06glki8mawhi38h2k4fv-python2.7-mako-1.0.7/lib/python2.7/site-packages/mako/runtime.py", line 899, in _exec_template
callable_(context, *args, **kwargs)
File "_base_root_mako", line 98, in render_body
File "_base_base_mako", line 54, in render_body
File "_summary_summary_base_mako", line 62, in render_main
File "rhodecode_templates_summary_summary_mako", line 69, in render_main
File "_summary_components_mako", line 165, in render_summary_detail
File "/opt/rhodecode/store/rq6n4kdw9z8d44km9njnr5rxxyh01p4h-python2.7-zope.cachedescriptors-4.3.1/lib/python2.7/site-packages/zope/cachedescriptors/property.py", line 106, in __get__
value = func(inst)
File "/opt/rhodecode/store/8g71brmqhd8vrka0n6sk5k2icw2diwdd-python2.7-rhodecode-enterprise-ce-4.15.2/lib/python2.7/site-packages/rhodecode/lib/vcs/backends/svn/repository.py", line 103, in branches
return self._tags_or_branches('vcs_svn_branch')
File "/opt/rhodecode/store/8g71brmqhd8vrka0n6sk5k2icw2diwdd-python2.7-rhodecode-enterprise-ce-4.15.2/lib/python2.7/site-packages/rhodecode/lib/vcs/backends/svn/repository.py", line 133, in _tags_or_branches
tip = self.get_commit()
File "/opt/rhodecode/store/8g71brmqhd8vrka0n6sk5k2icw2diwdd-python2.7-rhodecode-enterprise-ce-4.15.2/lib/python2.7/site-packages/rhodecode/lib/vcs/backends/svn/repository.py", line 266, in get_commit
commit = SubversionCommit(repository=self, commit_id=commit_id)
File "/opt/rhodecode/store/8g71brmqhd8vrka0n6sk5k2icw2diwdd-python2.7-rhodecode-enterprise-ce-4.15.2/lib/python2.7/site-packages/rhodecode/lib/vcs/backends/svn/commit.py", line 51, in __init__
self.idx = self.repository._get_commit_idx(commit_id)
File "/opt/rhodecode/store/8g71brmqhd8vrka0n6sk5k2icw2diwdd-python2.7-rhodecode-enterprise-ce-4.15.2/lib/python2.7/site-packages/rhodecode/lib/vcs/backends/svn/repository.py", line 201, in _get_commit_idx
"Commit at index %s does not exist." % (commit_idx, ))
MakoRenderingException:
Traceback (most recent call last):
File "/opt/rhodecode/store/jzd3fzw15kzc5k1f14spfjp4sm142h52-python2.7-pyramid-mako-1.0.2/lib/python2.7/site-packages/pyramid_mako/__init__.py", line 148, in __call__
result = template.render_unicode(**system)
File "/opt/rhodecode/store/ida848f1ziml06glki8mawhi38h2k4fv-python2.7-mako-1.0.7/lib/python2.7/site-packages/mako/template.py", line 471, in render_unicode
as_unicode=True)
File "/opt/rhodecode/store/ida848f1ziml06glki8mawhi38h2k4fv-python2.7-mako-1.0.7/lib/python2.7/site-packages/mako/runtime.py", line 838, in _render
**_kwargs_for_callable(callable_, data))
File "/opt/rhodecode/store/ida848f1ziml06glki8mawhi38h2k4fv-python2.7-mako-1.0.7/lib/python2.7/site-packages/mako/runtime.py", line 873, in _render_context
_exec_template(inherit, lclcontext, args=args, kwargs=kwargs)
File "/opt/rhodecode/store/ida848f1ziml06glki8mawhi38h2k4fv-python2.7-mako-1.0.7/lib/python2.7/site-packages/mako/runtime.py", line 899, in _exec_template
callable_(context, *args, **kwargs)
File "/opt/rhodecode/store/8g71brmqhd8vrka0n6sk5k2icw2diwdd-python2.7-rhodecode-enterprise-ce-4.15.2/lib/python2.7/site-packages/rhodecode/templates/base/root.mako", line 143, in render_body
${next.body()}
File "/opt/rhodecode/store/8g71brmqhd8vrka0n6sk5k2icw2diwdd-python2.7-rhodecode-enterprise-ce-4.15.2/lib/python2.7/site-packages/rhodecode/templates/base/base.mako", line 32, in render_body
${next.main()}
File "/opt/rhodecode/store/8g71brmqhd8vrka0n6sk5k2icw2diwdd-python2.7-rhodecode-enterprise-ce-4.15.2/lib/python2.7/site-packages/rhodecode/templates/summary/summary_base.mako", line 28, in render_main
${next.main()}
File "/opt/rhodecode/store/8g71brmqhd8vrka0n6sk5k2icw2diwdd-python2.7-rhodecode-enterprise-ce-4.15.2/lib/python2.7/site-packages/rhodecode/templates/summary/summary.mako", line 26, in render_main
${components.summary_detail(breadcrumbs_links=self.breadcrumbs_links(), show_downloads=True)}
File "/opt/rhodecode/store/8g71brmqhd8vrka0n6sk5k2icw2diwdd-python2.7-rhodecode-enterprise-ce-4.15.2/lib/python2.7/site-packages/rhodecode/templates/summary/components.mako", line 95, in render_summary_detail
${refs_counters(
File "/opt/rhodecode/store/rq6n4kdw9z8d44km9njnr5rxxyh01p4h-python2.7-zope.cachedescriptors-4.3.1/lib/python2.7/site-packages/zope/cachedescriptors/property.py", line 106, in __get__
value = func(inst)
File "/opt/rhodecode/store/8g71brmqhd8vrka0n6sk5k2icw2diwdd-python2.7-rhodecode-enterprise-ce-4.15.2/lib/python2.7/site-packages/rhodecode/lib/vcs/backends/svn/repository.py", line 103, in branches
return self._tags_or_branches('vcs_svn_branch')
File "/opt/rhodecode/store/8g71brmqhd8vrka0n6sk5k2icw2diwdd-python2.7-rhodecode-enterprise-ce-4.15.2/lib/python2.7/site-packages/rhodecode/lib/vcs/backends/svn/repository.py", line 133, in _tags_or_branches
tip = self.get_commit()
File "/opt/rhodecode/store/8g71brmqhd8vrka0n6sk5k2icw2diwdd-python2.7-rhodecode-enterprise-ce-4.15.2/lib/python2.7/site-packages/rhodecode/lib/vcs/backends/svn/repository.py", line 266, in get_commit
commit = SubversionCommit(repository=self, commit_id=commit_id)
File "/opt/rhodecode/store/8g71brmqhd8vrka0n6sk5k2icw2diwdd-python2.7-rhodecode-enterprise-ce-4.15.2/lib/python2.7/site-packages/rhodecode/lib/vcs/backends/svn/commit.py", line 51, in __init__
self.idx = self.repository._get_commit_idx(commit_id)
File "/opt/rhodecode/store/8g71brmqhd8vrka0n6sk5k2icw2diwdd-python2.7-rhodecode-enterprise-ce-4.15.2/lib/python2.7/site-packages/rhodecode/lib/vcs/backends/svn/repository.py", line 201, in _get_commit_idx
"Commit at index %s does not exist." % (commit_idx, ))
CommitDoesNotExistError: Commit at index 7 does not exist.
Similar behaviour when we want to see the details of a commit. When we are able to see the Changelog and click on a commit, we can see its details. Hitting refresh again a few times lead to RhodeCodes "404 - not found" error page.
Could all this be some sort of caching problem?
Because in rhodecode.ini setting this:
## use cache version of scm repo everywhere
vcs_full_cache = true
to "false" seem to solve the problems, now all page refreshs in RhodeCode are/stay up-to-date immediatly.
But wouldn't this lead to performance issues esp. on bigger repos?
When "vcs_full_cache" is set to true and doing a "Invalidate repository cache" on the test repository also leads to a correct view - until new commits reach the repo which makes invalidating the cache neccessary again... but then the cache would be completely useless.
Another issue:
In one of our productive repos opening a specific commit leads reproduceable to RhodeCodes "500 Internal Server Error" page, this exception is in "community.log":
2019-02-22 11:22:36.843 ERROR [rhodecode.config.middleware] error occurred handling this request for path: /rhodecode/main/changeset/212301
Traceback (most recent call last):
File "/opt/rhodecode/store/mcjhzq84p171b42cwjlszbz8611ir1b8-python2.7-pyramid-1.9.2/lib/python2.7/site-packages/pyramid/tweens.py", line 39, in excview_tween
response = handler(request)
File "/opt/rhodecode/store/mcjhzq84p171b42cwjlszbz8611ir1b8-python2.7-pyramid-1.9.2/lib/python2.7/site-packages/pyramid/router.py", line 156, in handle_request
view_name
File "/opt/rhodecode/store/mcjhzq84p171b42cwjlszbz8611ir1b8-python2.7-pyramid-1.9.2/lib/python2.7/site-packages/pyramid/view.py", line 642, in _call_view
response = view_callable(context, request)
File "/opt/rhodecode/store/mcjhzq84p171b42cwjlszbz8611ir1b8-python2.7-pyramid-1.9.2/lib/python2.7/site-packages/pyramid/viewderivers.py", line 390, in attr_view
return view(context, request)
File "/opt/rhodecode/store/mcjhzq84p171b42cwjlszbz8611ir1b8-python2.7-pyramid-1.9.2/lib/python2.7/site-packages/pyramid/viewderivers.py", line 368, in predicate_wrapper
return view(context, request)
File "/opt/rhodecode/store/mcjhzq84p171b42cwjlszbz8611ir1b8-python2.7-pyramid-1.9.2/lib/python2.7/site-packages/pyramid/viewderivers.py", line 410, in viewresult_to_response
result = view(context, request)
File "/opt/rhodecode/store/mcjhzq84p171b42cwjlszbz8611ir1b8-python2.7-pyramid-1.9.2/lib/python2.7/site-packages/pyramid/viewderivers.py", line 138, in _class_view
response = getattr(inst, attr)()
File "/opt/rhodecode/store/8g71brmqhd8vrka0n6sk5k2icw2diwdd-python2.7-rhodecode-enterprise-ce-4.15.2/lib/python2.7/site-packages/rhodecode/lib/auth.py", line 2352, in local_wrapper
return wrapper(func, *args, **kwds)
File "/opt/rhodecode/store/8g71brmqhd8vrka0n6sk5k2icw2diwdd-python2.7-rhodecode-enterprise-ce-4.15.2/lib/python2.7/site-packages/rhodecode/lib/auth.py", line 1665, in __wrapper
return func(*fargs, **fkwargs)
File "/opt/rhodecode/store/8g71brmqhd8vrka0n6sk5k2icw2diwdd-python2.7-rhodecode-enterprise-ce-4.15.2/lib/python2.7/site-packages/rhodecode/lib/auth.py", line 2352, in local_wrapper
return wrapper(func, *args, **kwds)
File "/opt/rhodecode/store/8g71brmqhd8vrka0n6sk5k2icw2diwdd-python2.7-rhodecode-enterprise-ce-4.15.2/lib/python2.7/site-packages/rhodecode/lib/auth.py", line 1739, in __wrapper
return func(*fargs, **fkwargs)
File "/opt/rhodecode/store/8g71brmqhd8vrka0n6sk5k2icw2diwdd-python2.7-rhodecode-enterprise-ce-4.15.2/lib/python2.7/site-packages/rhodecode/apps/repository/views/repo_commits.py", line 273, in repo_commit_show
return self._commit(commit_id, method='show')
File "/opt/rhodecode/store/8g71brmqhd8vrka0n6sk5k2icw2diwdd-python2.7-rhodecode-enterprise-ce-4.15.2/lib/python2.7/site-packages/rhodecode/apps/repository/views/repo_commits.py", line 203, in _commit
diffset, _parsed, commit1.raw_id, commit2.raw_id)
File "/opt/rhodecode/store/8g71brmqhd8vrka0n6sk5k2icw2diwdd-python2.7-rhodecode-enterprise-ce-4.15.2/lib/python2.7/site-packages/rhodecode/apps/_base/__init__.py", line 307, in render_patchset_filtered
filtered_patchset, source_ref=source_ref, target_ref=target_ref)
File "/opt/rhodecode/store/8g71brmqhd8vrka0n6sk5k2icw2diwdd-python2.7-rhodecode-enterprise-ce-4.15.2/lib/python2.7/site-packages/rhodecode/lib/codeblocks.py", line 414, in render_patchset
filediff = self.render_patch(patch)
File "/opt/rhodecode/store/8g71brmqhd8vrka0n6sk5k2icw2diwdd-python2.7-rhodecode-enterprise-ce-4.15.2/lib/python2.7/site-packages/rhodecode/lib/codeblocks.py", line 531, in render_patch
hunkbit = self.parse_hunk(hunk, source_file, target_file)
File "/opt/rhodecode/store/8g71brmqhd8vrka0n6sk5k2icw2diwdd-python2.7-rhodecode-enterprise-ce-4.15.2/lib/python2.7/site-packages/rhodecode/lib/codeblocks.py", line 578, in parse_hunk
self.parse_lines(before, after, source_file, target_file, no_hl=no_hl))
File "/opt/rhodecode/store/8g71brmqhd8vrka0n6sk5k2icw2diwdd-python2.7-rhodecode-enterprise-ce-4.15.2/lib/python2.7/site-packages/rhodecode/lib/codeblocks.py", line 671, in parse_lines
original.content = render_tokenstream(o_tokens)
File "/opt/rhodecode/store/8g71brmqhd8vrka0n6sk5k2icw2diwdd-python2.7-rhodecode-enterprise-ce-4.15.2/lib/python2.7/site-packages/rhodecode/lib/codeblocks.py", line 164, in render_tokenstream
escaped_text = html_escape(token_text)
File "/opt/rhodecode/store/8g71brmqhd8vrka0n6sk5k2icw2diwdd-python2.7-rhodecode-enterprise-ce-4.15.2/lib/python2.7/site-packages/rhodecode/lib/helpers.py", line 126, in html_escape
return text.translate(html_escape_table)
TypeError: expected a string or other character buffer object
In this commit a sql text file and a Excel (xlsx) binary file was changed.
We were not able to reprocude this in the Test - Repo. In this we commited the same files from the mentioned commit in the productive repo and here the commit display is normal.
During all these tests we directly connect to RhodeCode Community on Port 10020 so there is no Apache Reverse (Caching) Proxy involved.
This is our RhodeCode installation:
# rccontrol status
RHODECODE CONTROL VERSION: 1.21.1
- NAME: community-1
- STATUS: RUNNING
logs:/root/.rccontrol/community-1/community.log
- VERSION: 4.15.2 Community
- VCS: vcsserver-1
- URL: http://0.0.0.0:10020
- CONFIG: /root/.rccontrol/community-1/rhodecode.ini
- NAME: vcsserver-1
- STATUS: RUNNING
logs:/root/.rccontrol/vcsserver-1/vcsserver.log
- VERSION: 4.15.2 VCSServer
- URL: http://127.0.0.1:10010
- CONFIG: /root/.rccontrol/vcsserver-1/vcsserver.ini
Thx in advance for any hint!
Markus
Files
Updated by Marcin Kuzminski [CTO] almost 6 years ago
Hi Markus,
The issue you're desribing looks like a problem with cache invalidation. This is indeed somehow related to vcs_full_cache setting. Normally how it works is that during the push rhodecode notifies it's caches that something changed and cache should be invalidated. This for SVN backend is handled by hooks inside SVN repositories. I suspect that maybe your repositories already have some hooks and RhodeCode doesn't override them preventing any data losses.
You could force install the hooks by going to such url:
http://you-server-address/REPO_NAME/settings/advanced/hooks
This should re-install RhodeCode SVN hooks for this particular repository.
Regarding the second issue, could you share the test repository with us so we can investigate this?
Best,
Updated by Markus Leitold almost 6 years ago
Hi Marcin,
now things become clear .... in our productive repo we indeed already have post- and pre-commit hooks (perl-written) which weren't overwritten by RhodeCodes "Remap and Rescan" and they have to stay and work beside RhodeCode. So it was very good they where not overwritten, so force - install RhodeCodes Hooks will not be a solution.
In the mentioned test repo we didn't have hooks, of course. After "Remap and Rescan" we noticed, that every SVN commit fails with an error like "Commit was blocked by pre-commit hook with no output (error 255)":
At this point we noticed for the first time the hooks which RhodeCode installed. After deleting them, commits work again but "Remap and Rescan" re-installed the RhodeCode hooks and commits failed again. So we delete the hooks again and installed a "dummy" pre- and post-commit hook which just do an "exit 0" to prevent RhodeCode from installing its own hooks, which don't work in our environment. We assumed we safely could do that, because we thought the RhodeCode hooks just where neccessary when our own hooks would be managed in RhodeCode, too.
All this now leads to two questions when RhodeCodes hooks are needed for the caching beahviour:
-> How could the RhodeCode hooks exists beside our own hooks?
-> Why do RhodeCode hooks errors out in our environment? They are written in python, arn't they? Python 2.7.13 is installed...
Ahh... and what about the secons issue, the reproducable "500 internal server error" while opening one specific commit in the productive repo? ("TypeError: expected a string or other character buffer object")
Updated by Markus Leitold almost 6 years ago
I just noticed the #! line in the RhodeCode hooks... this could be the cause that the hooks fail, this line is:
#!/root/.rccontrol/vcsserver-1/profile/bin/python
The commits are triggered by Apache, as the Windows Tortoise clients access the repos with "https://...." over Apaches mod_dav_svn.
Apache is running as non-root user, so of course Apache may not access "/root/...."... I track this down further...
Updated by Markus Leitold almost 6 years ago
Indeed .... wwwrun (the user which runs Apache) isn't (of course) allowed to run anything under /root ...
So to make RhodeCodes hooks work in this constellation one has to install it as "wwwrun", not "root". Then the hooks will work ... but what about the existing perl-written hooks?
Updated by Marcin Kuzminski [CTO] almost 6 years ago
Dear Markus -
Our hooks are a simple self-contained python script. I believe in the case of your perl custom SVN hooks, you could simply run our hook from within your perl scripts (maybe as a subprocess call?) The hooks use environment variables to read some data, just make sure the execution from Perl passed the environment into our script.
Why those hooks are required? They act as a trigger for:
- cache invalidation
- integrations triggering
- rcextensions calls
Potentially you don't need to have those hooks as all 3 are optional, and cache invalidation can be trigger via API call from your perl script, or even periodically every N minutes or so.
Updated by Markus Leitold almost 6 years ago
Hi Marcin,
thx for the explanations ... as we will use RhodeCode just for simple Code-Reviews and not for anything else the cache invalidation would be the only reason to use your hooks IMHO.
How could these be triggered from our own perl hooks? 1.) They aren't installed when our hooks are existing, 2.) the permission problem as describe above will remain 3.) if we simply copy/rename (from) your installed hooks then newer hook versions during RhodeCode updates will never be considered.
So I think the cache invalidation would best be done through API Calls, I'll try to figure out how this exactly works
Updated by Markus Leitold almost 6 years ago
OK, very simple... I managed to trigger the cache - invalidation by a curl - request in a post-commit hook in the test-repo ... now everything concerning caching seems to work now