svn del causes even deactivated builds cause errors

[Steven R. Loomis <srl@…>]

1. Create a Build that's on a branch - all is OK
2. Deactivate the build
3. Delete the branch in svn

Now, 'timeline (including builds)' and 'show builds (including deactivate)' pages fail completely with an error: No such node branches/delbranch at revision XXXX. Even setting an upper bound on the deactivated build ( to stop before the revision with the delete) fails.

Only solution is to delete the build configuration.

[osimons]

Wonder why. We should look into the reason for this.

[osimons]

(And also check that it actually still happens - a lot of code has changed since 0.6b2...)

[osimons]

Haven't actually tried to recreate the issue myself, but I suspect that if you turn on Trac debug logging you will see an exception for respos.get_<something>(). This I believe is a problem in bitten.web_ui._has_permission that gets called like this various places: _has_permission(repos, path, req.perm)

The (default) repos, and the path - taken to be at latest repos revision. Which has no such node at that path. We should include revision in that call and function definition.

I've attached a patch that does this - could you try it please?

[osimons]

Add revision to repos permission check.

[osimons]

I have tried to recreate this, but I cannot replicate the issue using latest version from repository. Nothing I try and do will give me the kind of error you describe. Unless some fresh insights, I do presume that the issue has been fixed at some stage.

I still believe my patch is useful, and trying it I see no side effects myself. If anyone could please test it, I may just commit it now in time for 0.6b3.

PS! Most of the patch is just a more logical order of arguments - the actual rev changes is quite small...

[osimons]

Anyone want to test or comment on this patch? Include now for 0.6b3 or just leave it?

[fbrettschneider@…]

I can confirm the bug happens also here with todays SVN version of bitten (trac 0.12.1) without the patch attached to this ticket here. The error message tells me:

Trac Error
Event provider BuildController failed for filters "Builds": NoSuchNode: No node branches/BRANCH_xxxxx at revision 26821

You may want to see the other kinds of events from the Timeline or notify your Trac administrator about the error (detailed information was written to the log).

My question: Where is that logging stored?

[anonymous]

Replying to fbrettschneider@…:

My question: Where is that logging stored?

I guess I have to set something at Admin-->General-->Logging, right? Currently, there is the default Type=None, Log level=disabled, Log file=trac.log

[osimons]

Right. See ​trac:TracLogging

[fbrettschneider@…]

and the error logging (type=File, loglevel=ERROR, logfile=trac.log) is:

2010-12-09 11:05:45,206 Trac[web_ui] ERROR: Timeline event provider failed: 
Traceback (most recent call last):
  File "build\bdist.win32\egg\trac\timeline\web_ui.py", line 179, in process_request
    filters) or []:
  File "build\bdist.win32\egg\bitten\web_ui.py", line 657, in get_timeline_events
    if not _has_permission(repos, path, req.perm):
  File "build\bdist.win32\egg\bitten\web_ui.py", line 90, in _has_permission
    node = repos.get_node(path)
  File "build\bdist.win32\egg\trac\versioncontrol\cache.py", line 302, in get_node
    return self.repos.get_node(path, self.normalize_rev(rev))
  File "build\bdist.win32\egg\trac\versioncontrol\svn_fs.py", line 454, in get_node
    return SubversionNode(path, rev, self, self.pool)
  File "build\bdist.win32\egg\trac\versioncontrol\svn_fs.py", line 690, in __init__
    raise NoSuchNode(path, rev)
NoSuchNode: No node branches/xxxxx at revision 26821

[osimons]

Thanks! As suspected, node = repos.get_node(path) needs to be node = repos.get_node(path, rev) so that it don't lookup the path but the path at that previous revision as it may no longer exist.

So: The patch fixes it? Nothing in the log after applying patch and making new requests?

[fbrettschneider@…]

I need to apply the patch now. I hope I don't have probs with it. Stay tuned...

[anonymous]

I patched the source file web_ui.py and called

d:\svnRepos\bitten>python.exe setup.py install

and then yes, the file D:\bitnami-trac\python\Lib\site-packages\Bitten-0.7dev_r960-py2.5.egg\bitten\web_ui.py also contains the changes.

I shutdown Trac and restarted it but the error is still the same in the logging.

Do I need to reset the .db file to the state before the bug has happened und repeat the whole thing again? Or should the patch even fix it with a previously broken one?

[osimons]

No db files or other things needed for changing - this is purely a runtime issue.

However, the traceback cannot be the same - it can be almost the same, but if it does not contain node = repos.get_node(path, rev) the patched changes are not included. Could you paste the log again so I can look?

[anonymous]

I compared both loggings (old and new one) and they are identical, it does not contain your mentioned string. I installed the patch as described in my previous comment. What should I do do activate the patch?

[anonymous]

Replying to anonymous:

I compared both loggings (old and new one) and they are identical

apart from the timestamp :)

[osimons]

If anything, the log SHOULD contain these changed lines:

File "build\bdist.win32\egg\bitten\web_ui.py", line 657, in get_timeline_events
    if not _has_permission(req.perm, repos, path, rev):
  File "build\bdist.win32\egg\bitten\web_ui.py", line 90, in _has_permission
    node = repos.get_node(path, rev)

However, hopefully there should just be nothing in log as you no longer get the error...

You need to get the patch applied correctly. I don't know the Bitnami stack, so I don't know how they store their code or how it runs.

For 0.12, under 'About Trac' as TRAC_ADMIN user you should be able to see where Trac loads all the plugins - including Bitten. Make sure the modified code gets to the right place & version.

[fbrettschneider@…]

I remember, yesterday, for the first time I installed the .egg file I found in the d:\svnRepos\bitten\dist dir via webinterface (Admin-->General-->Plugins-->Install)

The patched one was installed today via command line call (I typed on command line prompt d:\svnRepos\bitten>python.exe setup.py install) and it is there in D:\bitnami-trac\python\Lib\site-packages\Bitten-0.7dev_r960-py2.5.egg\bitten\.

But the 'About Trac' page tells me it uses d:\trac\myproject\plugins\bitten-0.7dev_r960-py2.5.egg which is the old one, I checked the file modify time.

So it seems I have a double installation now. :(

How can I remove the one I installed with 'python.exe setup.py install'? Because now whenever I try to repeat the upload of the obviously new .egg file fom the dist dir via webinterface, it tells me Trac error 'Plugin Bitten-0.7dev_r960-py2.5.egg already installed'

[osimons]

Just rm either D:\bitnami-trac\python\Lib\site-packages\Bitten-0.7dev_r960-py2.5.egg or d:\trac\myproject\plugins\bitten-0.7dev_r960-py2.5.egg to let Trac pick up the other one.

Generally, I'd recommend using shared installs for plugin (ie. site-packages).

[anonymous]

Thanks for being patient! My learning curve is rampant today. :)

I removed by deleting the dirs and files, restarted the Trac stack, installed the new bitten .egg file via webinterface again and now the patch is active.

The described error is away, 'Timeline' and 'Build Status' menu work again. The trac.log stays empty.

Further seen effects, and I don't know if that is what you want to:

1. Now on Timeline I can click on a build link and it shows an error page ​https://172.20.x.x/myproject/build/releaseBranch/8 grumbling in red:

     Error: No such node
     No node branches/BRANCH_xxxxx at revision 26821
   

2. If I activate the build configuration of the deleted branch again, a click on menu item 'Build Status' displays the same error page as described in 1.

[fbrettschneider@…]

Replying to anonymous:

2. If I activate the build configuration of the deleted branch again, a click on menu item 'Build Status' displays the same error page as described in 1.

I mean menu item 'Build Status' works great without "Show deactivated configurations" but shows that error when trying with it

[osimons]

Thanks for testing. So, I'm on the right track here but something is still amiss. I'll see if I can figure out what. I think I know where to look based on your information.

One question: Is revision 26821 the latest revision in your repos? At what revision was your branch removed? I suspect 26821 is HEAD in your repos.

[anonymous]

26821 is the latest commit in the repository, and it's HEAD now. Yes, it's the commit of the branch removing.

[osimons]

Oh, and debug logging / tracebacks is always really useful when reporting...

I suspect the two use-cases will report different errors:

1. Viewing the newly reactivated Build Config frontpage will trigger error in line 608. Identified, but not quite sure how to handle it. What would be the correct approach to handle permission viewing for a config against a path that can no longer be found - so that we can't actually verify permissions? Hmm. I'll experiment a bit.

2. Clicking a build in Timeline will try to load the Build which will fail in line 378. This one I can fix, try to add this change to the patch:

   bitten/web_ui.py

   @@ -605 +605 @@
            repos = self.env.get_repository(authname=req.authname)
            assert repos, 'No "(default)" Repository: Add a repository or alias ' \
                          'named "(default)" to Trac.'
   -        _has_permission(req.perm, repos, config.path, raise_error=True)
   +        _has_permission(req.perm, repos, config.path, rev=build.rev, raise_error=True)
            chgset = repos.get_changeset(build.rev)
            data['build']['chgset_author'] = chgset.author
            data['build']['display_rev'] = repos.normalize_rev(build.rev)

[osimons]

Perhaps this is the right approach? Denying access to viewing config as we cannot check permissions?

bitten/web_ui.py

@@ -33 +33 @@
 from trac.web.chrome import INavigationContributor, ITemplateProvider, \
                             add_link, add_stylesheet, add_ctxtnav, \
                             prevnext_nav, add_script
-from trac.versioncontrol import NoSuchChangeset
+from trac.versioncontrol import NoSuchChangeset, NoSuchNode
 from trac.wiki import wiki_to_html, wiki_to_oneliner
 from bitten.api import ILogFormatter, IReportChartGenerator, IReportSummarizer
 from bitten.master import BuildMaster
@@ -375 +375 @@
         repos = self.env.get_repository(authname=req.authname)
         assert repos, 'No "(default)" Repository: Add a repository or alias ' \
                       'named "(default)" to Trac.'
-        _has_permission(req.perm, repos, config.path, raise_error=True)
+        try:
+            _has_permission(req.perm, repos, config.path, raise_error=True)
+        except NoSuchNode:
+            raise PermissionError("Permission checking against repository "
+                    "path %s failed as path does not exist." % config.path)
 
         data = {'title': 'Build Configuration "%s"' \
                           % config.label or config.name,
@@ -605 +609 @@
         repos = self.env.get_repository(authname=req.authname)
         assert repos, 'No "(default)" Repository: Add a repository or alias ' \
                       'named "(default)" to Trac.'
-        _has_permission(req.perm, repos, config.path, raise_error=True)
+        _has_permission(req.perm, repos, config.path, rev=build.rev, raise_error=True)
         chgset = repos.get_changeset(build.rev)
         data['build']['chgset_author'] = chgset.author
         data['build']['display_rev'] = repos.normalize_rev(build.rev)

[anonymous]

Replying to osimons:

Perhaps this is the right approach? Denying access to viewing config as we cannot check permissions?

...snip...

}}}

I tried this patch, and a click on the build link in 'Timeline' works now! No error anymore.

But no behaviour change in 'Build Status', though logging remains empty (with Logging configuration File,ERROR,trac.log)

[anonymous]

uhmm... and when changing the Log level to DEBUG, after a click on menu item 'Build Status' trac.log contains this:

2010-12-09 15:44:30,260 Trac[main] DEBUG: Dispatching <Request "GET '/build'">
2010-12-09 15:44:30,260 Trac[api] INFO: Synchronized '' repository in 0.00 seconds
2010-12-09 15:44:30,260 Trac[session] DEBUG: Retrieving session for ID 'falkb'
2010-12-09 15:44:30,276 Trac[main] WARNING: HTTPNotFound: 404 No such node (No node branches/BRANCH_xxxxx at revision 26821)
2010-12-09 15:44:30,276 Trac[chrome] DEBUG: Prepare chrome data for request

[osimons]

Instead of frontpage (/myproject/build), can you see if /myproject/build/<configname> works?

[anonymous]

Replying to osimons:

Instead of frontpage (/myproject/build), can you see if /myproject/build/<configname> works?

yep. Look here:

2010-12-09 15:50:25,232 Trac[main] DEBUG: Dispatching <Request "GET '/timeline'">
2010-12-09 15:50:25,247 Trac[api] INFO: Synchronized '' repository in 0.00 seconds
2010-12-09 15:50:25,247 Trac[session] DEBUG: Retrieving session for ID 'falkb'
2010-12-09 15:50:25,247 Trac[chrome] DEBUG: Prepare chrome data for request
2010-12-09 15:50:25,404 Trac[main] DEBUG: Dispatching <Request "GET '/chrome/common/css/timeline.css'">
2010-12-09 15:50:25,482 Trac[main] DEBUG: Dispatching <Request "GET '/chrome/common/js/timeline_multirepos.js'">
2010-12-09 15:50:25,545 Trac[main] DEBUG: Dispatching <Request "GET '/chrome/common/changeset.png'">
2010-12-09 15:50:25,592 Trac[main] DEBUG: Dispatching <Request "GET '/chrome/bitten/bitten_buildf.png'">
2010-12-09 15:50:25,638 Trac[main] DEBUG: Dispatching <Request "GET '/chrome/common/feed.png'">
2010-12-09 15:50:30,497 Trac[main] DEBUG: Dispatching <Request "GET '/build/releaseBranch/8'">
2010-12-09 15:50:30,497 Trac[api] INFO: Synchronized '' repository in 0.00 seconds
2010-12-09 15:50:30,497 Trac[session] DEBUG: Retrieving session for ID 'falkb'
2010-12-09 15:50:30,497 Trac[chrome] DEBUG: Prepare chrome data for request
2010-12-09 15:50:30,700 Trac[main] DEBUG: Dispatching <Request "GET '/chrome/bitten/tabset.js'">
2010-12-09 15:50:30,763 Trac[main] DEBUG: Dispatching <Request "GET '/chrome/bitten/failure.png'">
2010-12-09 15:50:35,436 Trac[main] DEBUG: Dispatching <Request "GET '/build/releaseBranch'">
2010-12-09 15:50:35,436 Trac[api] INFO: Synchronized '' repository in 0.00 seconds
2010-12-09 15:50:35,436 Trac[session] DEBUG: Retrieving session for ID 'falkb'
2010-12-09 15:50:35,436 Trac[main] WARNING: HTTPForbidden: 403 Forbidden (Permission checking against repository path branches/BRANCH_xxxxx failed as path does not exist. privileges are required to perform this operation)
2010-12-09 15:50:35,436 Trac[chrome] DEBUG: Prepare chrome data for request

[osimons]

Ok, then the final change may be adding this on top of all the others:

bitten/web_ui.py

@@ -219 +219 @@
 
         configs = []
         for config in BuildConfig.select(self.env, include_inactive=show_all):
-            if not _has_permission(req.perm, repos, config.path):
+            try:
+                if not _has_permission(req.perm, repos, config.path):
+                    continue
+            except NoSuchNode:
+                # FIXME: Should warn that config points to non-existing path
                 continue
 
             description = config.description

[osimons]

Actually, can just finish this by also adding a warning. Try this instead:

bitten/web_ui.py

@@ -32 +32 @@
 from trac.web import IRequestHandler, IRequestFilter, HTTPNotFound
 from trac.web.chrome import INavigationContributor, ITemplateProvider, \
                             add_link, add_stylesheet, add_ctxtnav, \
-                            prevnext_nav, add_script
-from trac.versioncontrol import NoSuchChangeset
+                            prevnext_nav, add_script, add_warning
+from trac.versioncontrol import NoSuchChangeset, NoSuchNode
 from trac.wiki import wiki_to_html, wiki_to_oneliner
 from bitten.api import ILogFormatter, IReportChartGenerator, IReportSummarizer
 from bitten.master import BuildMaster
@@ -219 +219 @@
 
         configs = []
         for config in BuildConfig.select(self.env, include_inactive=show_all):
-            if not _has_permission(req.perm, repos, config.path):
+            try:
+                if not _has_permission(req.perm, repos, config.path):
+                    continue
+            except NoSuchNode:
+                add_warning(req, "Configuration %s points to non-existing "
+                        "path %s. Configuration skipped." % (
+                                                    config.name, config.path))
                 continue
 
             description = config.description

(also notice the additional import of add_warning at the top.)

[osimons]

New patch including all the tested changes. Should fix most things I hope...

[osimons]

I've attached attachment:t606-has_permission_at_rev-r960.diff​ as a summary of all needed changes (discovered so far, at least).

[anonymous]

Replying to osimons:

Actually, can just finish this by also adding a warning. Try this instead:

...snip...

great, that works now even on front page 'Build Status', although I haven't taken the latest two .diff files from you. See the following attachment.

But - one thing remains, I've found out that already known error also appears when clicking on 'In Progress Builds' :-P

[osimons]

Same treatment, another location. Gaaah...

bitten/web_ui.py

@@ -315 +315 @@
 
         configs = []
         for config in BuildConfig.select(self.env, include_inactive=False):
-            if not _has_permission(req.perm, repos, config.path):
+            try:
+                if not _has_permission(req.perm, repos, config.path):
+                    continue
+            except NoSuchNode:
+                add_warning(req, "Configuration %s points to non-existing "
+                        "path %s. Configuration skipped." % (
+                                                    config.name, config.path))
                 continue
 

[anonymous]

Yeah! Now it shows that page well and additionally warns there too with "Warning: Configuration releaseBranch points to non-existing path branches/BRANCH_xxxxx. Configuration skipped."

Another place is here: 'Timeline' --> 'Build of ... ' --> 'that branch link on the right hand side of Configuration:'. Then you'll get to ​https://172.20.x.x/myproject/build/releaseBranch and an error message appears, also told in the debug logging:

2010-12-09 16:53:06,319 Trac[main] WARNING: HTTPForbidden: 403 Forbidden (Permission checking against repository path branches/BRANCH_xxxxx failed as path does not exist. privileges are required to perform this operation)

CU, falkb P.S.: finish for today, I'll be back tomorrow

[osimons]

Thanks for testing! And, you are right. Raising a PermissionError leaves the user with a slightly cryptic message seeing permission errors add more information (that we can't provide here). I suppose just raising a straight TracError is a better alternative:

bitten/web_ui.py

@@ -384 +390 @@
         try:
             _has_permission(req.perm, repos, config.path, raise_error=True)
         except NoSuchNode:
-            raise PermissionError("Permission checking against repository "
+            raise TracError("Permission checking against repository "
                     "path %s failed as path does not exist." % config.path)
 
         data = {'title': 'Build Configuration "%s"' \

[osimons]

Final patch v3 :-) Adds use of config.max_rev.

[osimons]

attachment:t606-has_permission_at_rev-r960.2.diff​ adds use of config.max_rev to follow the 'last' revision marker if set on config via admin.

Seems this issue is specific to 0.12.x, and that would explain why I can't recreate it when I tested with 0.11... Got it now, better test some more myself ;-)

[osimons]

So, here is one detail that also makes all the builds appear again when max_rev is set for configuration via admin:

bitten/queue.py

@@ -49 +49 @@
     if not db:
         db = env.get_db_cnx()
     try:
-        node = repos.get_node(config.path)
+        node = repos.get_node(config.path, config.max_rev)
     except Exception, e:
         env.log.warn('Error accessing path %r for configuration %r',
                     config.path, config.name, exc_info=True)

Without this patch, no builds are displayed in listing and builds will only be accessible by direct url link.

[osimons]

Thanks! Committed in [962] (trunk) and [963] (0.6-stable).

[anonymous]

Patch tested and works smoothly here.

[fbrettschneider@…]

Replying to anonymous:

Patch tested and works smoothly here.

that was me

[anonymous]

Note that a very similar (the same?) bug happens with Git repositories (using the ​GitPlugin). Unfortunately for Git repositories it does not suffice to catch NoSuchNode on repos.get_node, as GitNode happily creates a node for an invalid revision and skips any sanity checks if path is '/'.

Later repo.normalize_rev dies with a NoSuchChangeset exception, breaking the timeline.

This may be considered a bug in the ​GitPlugin, and ​a ticket was just submitted for it.

[osimons]

The issue was closed against miletone 0.6, it would be wrong to change that now.

[David Kühling <dvdkhlng@…>]

Fix the same error from occuring on Git repositories for builds that reference Git revisions that are gone from the repository.

[David Kühling <dvdkhlng@…>]

Just attached a patch that fixes this bug from occuring with Git Plugin? here. Note that this patch was developed on top of the multi-repository patch from #765, so it might need some fuzz factor to apply on bitten trunk. Also looks like you'll need "-p4" to make it apply (that's a Trac-generated patch BTW).

[fbrettschneider@…]

Replying to David Kühling <dvdkhlng@…>:

Just attached a patch

You are wrong here, David. This one is closed. Open a new ticket for your patch.