Resync: Endless Loop

[Prasand J. <cyrano423@…>]

I encountered an endless loop when trying to resync trac when the number of revisions in the database is higher than the number of revisions in Subversion.

The steps to reproduce:

svnadmin dump <repos> -r 0:89 | gzip > dumpfile.gz

Remove rename the repository folder. Create a new repository in the previous location of the old one, load the dumped range, then resync:

gunzip -c dumpfile.gz | svnadmin load <repos>
trac-admin <trac-env> resync

This is no longer an issue for me. The problem goes away upon killing the process and running it again. Since the first process reset the revision table, the second encounters an empty revision table and runs as it should.

I let the first process run for half an hour. Curiously I looked to see what the error output would be prior to running the resync. It was as expected:

Traceback (most recent call last):
  File "/home/user/packages/lib/python2.3/site-packages/trac/web/main.py", line 406, in dispatch_request
    dispatcher.dispatch(req)
  File "/home/user/packages/lib/python2.3/site-packages/trac/web/main.py", line 173, in dispatch
    for handler in self.handlers:
  File "/home/user/packages/lib/python2.3/site-packages/trac/core.py", line 55, in extensions
    return filter(None, [component.compmgr[cls] for cls in extensions])
  File "/home/user/packages/lib/python2.3/site-packages/trac/core.py", line 179, in __getitem__
    component = cls(self)
  File "/home/user/packages/lib/python2.3/site-packages/trac/core.py", line 98, in maybe_init
    init(self)
  File "/home/user/packages/lib/python2.3/site-packages/TracRevtreePlugin-0.4.7.2dev_r2110-py2.3.egg/revtree/web_ui.py", line 220, in __init__
    youngest = int(tracrepos.get_youngest_rev())
  File "/home/user/packages/lib/python2.3/site-packages/trac/versioncontrol/cache.py", line 213, in get_youngest_rev
    self.sync()
  File "/home/user/packages/lib/python2.3/site-packages/trac/versioncontrol/cache.py", line 100, in sync
    self.youngest = self.repos.normalize_rev(self.youngest)
  File "/home/user/packages/lib/python2.3/site-packages/trac/versioncontrol/svn_fs.py", line 312, in normalize_rev
    raise NoSuchChangeset(rev)
NoSuchChangeset: No changeset 91 in the repository

[Christian Boos]

Good catch.

[Christian Boos]

As your traceback suggests, you saw the above error in the web browser, before you attempted to do the resync, then the attempt to resync made the problem go away, right?

If not, then were you using the latest of 0.10-stable, or some other revision?

The fix I'd like to do here is to raise a more explicit error message, indicating that a resync is needed, as what happens in your scenario (dump/load) is similar to changing the repository_dir, but first I'd like to be sure I understood correctly what happened for you.

[Prasand J. <cyrano423@…>]

Yes that is correct @ seeing the error before the resync. Curiosity struck me at that moment, lol. However, the problem went away only after pkilling the looped process. Fifteen minutes into the loop, prior to killing it I ran ps amux to see how much ram and cpu was being used (to see if it was indeed idle). I let it run for 15 additional minutes, then killed it.

Due to me killing it … I checked my database tables to see if I screwed anything by doing so (since I forcefully interrupted the looped resync and I didn't know exactly where the operation stopped, and wanted to double check that my necessary data was there before doing anything). Upon doing so, I noticed that the revision table count was @ zero. So I ran the resync again, because I assumed that it wouldn't encounter the problem a second time (with the table now being empty and all) … and monitored the database to see what would happen. The items were recounted as the resync functioned normally (due to the table being reset by the previous resync attempt that looped).

The version that I'm using is the one you addressed in #5067 … which is *goes check* r5163 (0.10-stable).

[Prasand J. <cyrano423@…>]

Follow up of previous comment:

My curiosity was actually "would the timeline still display the latter revisions removed, or would it display the correct number?" Wondering if a resync was needed at all. Then when it errored I thought "yeah, can't get away without a resync afterall" (though I would've resynced it anyway). Then proceeded to resync, which looped.

I am a developer but not a python developer so I like looking at the logic of what's going on in trac by anally / actively monitoring the changes. As it gives perspective / appreciation to the thought process involved. A verbose mode for some of the command-line functions would be nice. *hint, hint*, lol. ;-)

Though I guess that's moot if you know python. It's the Trac project which has convinced me to start coding in python. After initially encountering and using it, I started noticing things such as google adopting python as well. I'll more than likely pick it up heavily after I'm done with my current project. Or maybe during for that matter, as I'd like to have Trac more integrated with the site I'm currently working on.

[Christian Boos]

A verbose mode for some of the command-line functions would be nice. *hint, hint*

If you were using r5163 for the trac-admin tool, you should have indeed seen some progress information (incrementing rev counter: [XYZ]).

I wonder how the first resync could have looped, as the first thing it is supposed to do is to clear the cache tables, then commit, then proceed with a sync()…

This actually worked as expected when I reproduced the dump/load/resync operations you described.

So the reason of the loop is not yet clear for me, it might be related to your setup and the plugins you're using. If possible, could you redo the resync at DEBUG level logging? (see TracLogging).

[Prasand J. <cyrano423@…>]

Ironically, I have to undo a revision again (as I just committed a sensitive file to svn), and something told me to check this before doing so. I'll enable debug logging, and try to reproduce my steps.

[Prasand J. <cyrano423@…>]

I attempted several times but was not able to reproduce it. I guess the issue is invalid. Maybe dreamhost was just having troubles at the time, as this morning I was able to successfully duplicate it.

Though on the verbosity:

user@server:~/trac$ trac-admin tracenv/ resync
Resyncing repository history... 
91 revisions cached. Done.
user@server:~/trac$ pkill -9 trac.fcgi

That was all I received. I was thinking something more so along the lines of svnadmin load or make`s verbosity. Or better yet, the debug data echoed on screen (aka Caching node change in [89]: … etc). Though it's not imperative or anything, was just something that came to mind that I jokingly stated at that moment. I'll attempt a few more times (trying different things during peak hours), and if I'm able to reproduce it I'll reopen this ticket or something if you've already closed it by then.

[Prasand J. <cyrano423@…>]

Attempted again during peak hours, with no success.