Repository resync command failed

[Dan <trac@…>]

I get the folowing error from a resync:

Resyncing repository history...
Command failed: columns rev, path, change_type are not unique

Platform is Windows XP x64, Python 2.4.3, pysqlite 2.3.2, Subversion 1.4.0.

The repository verifies OK according to svnadmin.

This is just on one of many repositories. All the rest were OK. This is the only one that fails. I'm not very familiar with SQLite, but I'm assuming there is a chance that this could be due to corruption of the database?

[Dan <trac@…>]

Additionally ... Trying to initialize a new Trac environment with the existing Subversion repository produces the following:

 Indexing repository
Failed to initialize environment. columns rev, path, change_type are not unique
Traceback (most recent call last):
  File "C:\Program Files (x86)\Python24\Lib\site-packages\trac\scripts\admin.py", line 629, in do_initenv
    repos.sync()
  File "C:\Program Files (x86)\Python24\Lib\site-packages\trac\versioncontrol\cache.py", line 107, in sync
    (str(current_rev), path, kind, action,
  File "C:\Program Files (x86)\Python24\Lib\site-packages\trac\db\util.py", line 47, in execute
    return self.cursor.execute(sql_escape_percent(sql), args)
  File "C:\Program Files (x86)\Python24\Lib\site-packages\trac\db\sqlite_backend.py", line 56, in execute
    args or [])
  File "C:\Program Files (x86)\Python24\Lib\site-packages\trac\db\sqlite_backend.py", line 48, in _rollback_on_error
    return function(self, *args, **kwargs)
IntegrityError: columns rev, path, change_type are not unique

[cboos]

Can you svn log -v -rXXX that revision? (and copy thhe result here)

[tjb@…]

I reported a similar problem (#3513) with a postgres backend.
It seemed to be caused by a copy from outside the subversion subtree that your trac environment is rooted at to inside it.

[cboos]

Replying to tjb@cea.com.au:

I reported a similar problem (#3513) with a postgres backend.
It seemed to be caused by a copy from outside the subversion subtree that your trac environment is rooted at to inside it.

Sorry about that, but #3513 got unnoticed. In general, don't hesitate to "revive" a ticket by adding a reminder comment on it, if there has been no reaction from the TracTeam like not assignement to a Milestone.

Ok, so probably this is the same issue and the not unique in this ticket would be due to multiple NULL values (I can't think about another possibility right now).

We should probably remove the key constraint and use an index instead. That would introduce a schema change however, so I'm raising a bit the severity of the issue to get some feedback from the others.

• the pros for doing that for 0.10 would be that we already tell everybody to upgrade the schema, and that's more or less expected for a major upgrade; post-poning it do 0.10.1 would mean that users would have to upgrade again at that time.
• the cons is that the change is coming a bit late...

[cboos]

Replace the primary key constraint by a (non-unique) index on the node_change table

[cboos]

Dan, tjb, can you please test the following patch? attachment:node_change_upgrade-r3787.patch

[trac@…]

Well ... it doesn't crash now, but maybe things aren't quite correct yet.

As the sync() function is running along, the same file name was being processed twice in a row. The one that draws the erorr is /XXX/trunk/vhdl/video_lineup/mpp_proc/Xprimary_pkg.vhd. See below for the Subversion log information. (Note: Some names have been changed to protect the innocent, so to speak.)

------------------------------------------------------------------------
r401 | xxxxxx | 2006-06-26 12:00:07 -0500 (Mon, 26 Jun 2006) | 1 line
Changed paths:
   M /XXX/trunk/vhdl/libs/basic_pkg.vhd
   D /XXX/trunk/vhdl/video_lineup/Xprimary_proc
   A /XXX/trunk/vhdl/video_lineup/mpp_proc (from /XXX/trunk/vhdl/video_lineup/Xprimary_proc:394)
   D /XXX/trunk/vhdl/video_lineup/mpp_proc/Xprimary_pkg.vhd
   A /XXX/trunk/vhdl/video_lineup/mpp_proc/Xprimary_proc (from /XXX/trunk/vhdl/video_lineup/Xprimary_proc:394)
   D /XXX/trunk/vhdl/video_lineup/mpp_proc/Xprimary_proc/Xprimary_pkg.vhd
   D /XXX/trunk/vhdl/video_lineup/mpp_proc/Xprimary_proc/YxZmatrix.vhd
   D /XXX/trunk/vhdl/video_lineup/mpp_proc/YxZmatrix.vhd
   A /XXX/trunk/vhdl/video_lineup/mpp_proc/rtl (from /XXX/trunk/vhdl/video_lineup/Xprimary_proc/rtl:400)
   M /XXX/trunk/vhdl/video_lineup/mpp_proc/rtl/YxZmatrix.vhd
   A /XXX/trunk/vhdl/video_lineup/mpp_proc/sim (from /XXX/trunk/vhdl/video_lineup/Xprimary_proc/sim:400)
   A /XXX/trunk/vhdl/video_lineup/mpp_proc/tb (from /XXX/trunk/vhdl/video_lineup/Xprimary_proc/tb:400)

renamed directory.
------------------------------------------------------------------------

Interestingly, Trac's changeset page shows two of the files (of course, including the one listed above) being deleted ... twice. That is, the same line appears for each of those two files twice. Like this:

XXX/trunk/vhdl/libs/basic_pkg.vhd  (modified)  (1 diff)
XXX/trunk/vhdl/video_lineup/Xprimary_proc/Xprimary_pkg.vhd (deleted)
XXX/trunk/vhdl/video_lineup/Xprimary_proc/Xprimary_pkg.vhd (deleted)
XXX/trunk/vhdl/video_lineup/Xprimary_proc/YxZmatrix.vhd (deleted)
XXX/trunk/vhdl/video_lineup/Xprimary_proc/YxZmatrix.vhd (deleted)
XXX/trunk/vhdl/video_lineup/mpp_proc (copied) (copied from XXX/trunk/vhdl/video_lineup/Xprimary_proc)
XXX/trunk/vhdl/video_lineup/mpp_proc/Xprimary_proc (moved) (moved from XXX/trunk/vhdl/video_lineup/Xprimary_proc)
XXX/trunk/vhdl/video_lineup/mpp_proc/rtl (copied) (copied from XXX/trunk/vhdl/video_lineup/Xprimary_proc/rtl)
XXX/trunk/vhdl/video_lineup/mpp_proc/rtl/YxZmatrix.vhd (modified) (2 diffs)
XXX/trunk/vhdl/video_lineup/mpp_proc/sim (copied) (copied from XXX/trunk/vhdl/video_lineup/Xprimary_proc/sim)
XXX/trunk/vhdl/video_lineup/mpp_proc/tb (copied) (copied from XXX/trunk/vhdl/video_lineup/Xprimary_proc/tb) 

So ... maybe it's not quite properly understanding what's going on with that changeset.

[cboos]

Okay. Debriefing ;)

At first, I really wondered how you managed to get there, but I think this is what happened:

$ cd trunk/vhdl/video_lineup
$ svn rm Xprimary_proc/Xprimary_pkg.vhd
$ svn rm Xprimary_proc/YxZmatrix.vhd
$ svn cp Xprimary_proc mpp_proc
$ svn mv Xprimary_proc mpp_proc # !!!
$ svn commit -m "Now that's a fancy rename which will certainly blow up Trac"
Indeed (r401)

I would have expected a warning for the svn mv, but no, Subversion (1.2.3 in my test) was perfectly ok with that!

Why the double delete appears in Trac is also clear: we happen to take into account the base_path information for the delete, which usually happens to be ok. Not in this case; we should have used the path key (information which was so far discarded as we thought it was redundant with change.path; obviously it's not).

To summarize, this issue has probably nothing to do with #3513 and needs a different patch than the one I initially proposed.

Here's a quick attempt (completely untested, it's late ;)

Index: svn_fs.py
===================================================================
--- svn_fs.py	(revision 3788)
+++ svn_fs.py	(working copy)
@@ -648,12 +648,12 @@
         copies, deletions = {}, {}
         changes = []
         revroots = {}
-        for path, change in editor.changes.items():
+        for key_path, change in editor.changes.items():
             #assert path == change.path or change.base_path
             
             # Filtering on `path`
-            if not (_is_path_within_scope(self.scope, path) and \
-                    self.authz.has_permission(path)):
+            if not (_is_path_within_scope(self.scope, key_path) and \
+                    self.authz.has_permission(key_path)):
                 continue
 
             path = change.path
@@ -669,7 +669,7 @@
             if not path:                # deletion
                 if base_path:
                     action = Changeset.DELETE
-                    deletions[base_path] = idx
+                    deletions[key_path] = idx
                 elif self.scope:        # root property change
                     action = Changeset.EDIT
                 else:                   # deletion outside of scope, ignore

tjb, you should probably re-open #3513 and follow-up there with the results of the test for the previously posted patch (and also provide us with the svn log details, which are quite crucial for understanding what happens, as you can see from the above).

[trac@…]

Made a quick attempt to test, but it bombed in a similar fashion as before. (But .. may have typed something wrong.) I'm out of time right now, as well.

[cboos]

I believe this issue should be fixed by r3794, which is the same as the above patch, modulo the removal of leading '/' in base_paths, when performing rename detection.

I've not been able to recreate a changeset that would have the same sequence of change events as the one described above. I'll retry later by taking exactly the same names...

[trac@…]

Well, added a print line to cache.py:

                    print current_rev, path, kind, action

And this to svn_fs.py just after the variable assignments:

            print "Debug: ", key_path, path, base_path, base_rev

I see the following at changeset 401:

Debug:  XXX/trunk/vhdl/video_lineup/mpp_proc/sim XXX/trunk/vhdl/video_lineup/mpp_proc/sim /XXX/trunk/vhdl/video_lineup/Xprimary_proc/sim 400
Debug:  XXX/trunk/vhdl/video_lineup/mpp_proc XXX/trunk/vhdl/video_lineup/mpp_proc /XXX/trunk/vhdl/video_lineup/Xprimary_proc 394
Debug:  XXX/trunk/vhdl/video_lineup/mpp_proc/rtl XXX/trunk/vhdl/video_lineup/mpp_proc/rtl /XXX/trunk/vhdl/video_lineup/Xprimary_proc/rtl 400
Debug:  XXX/trunk/vhdl/video_lineup/mpp_proc/YxZmatrix.vhd None /XXX/trunk/vhdl/video_lineup/Xprimary_proc/YxZmatrix.vhd 394
Debug:  XXX/trunk/vhdl/video_lineup/Xprimary_proc None /XXX/trunk/vhdl/video_lineup/Xprimary_proc 400
Debug:  XXX/trunk/vhdl/video_lineup/mpp_proc/Xprimary_proc/Xprimary_pkg.vhd None /XXX/trunk/vhdl/video_lineup/Xprimary_proc/Xprimary_pkg.vhd 394
Debug:  XXX/trunk/vhdl/video_lineup/mpp_proc/Xprimary_proc/YxZmatrix.vhd None /XXX/trunk/vhdl/video_lineup/Xprimary_proc/YxZmatrix.vhd 394
Debug:  XXX/trunk/vhdl/video_lineup/mpp_proc/tb XXX/trunk/vhdl/video_lineup/mpp_proc/tb /XXX/trunk/vhdl/video_lineup/Xprimary_proc/tb 400
Debug:  XXX/trunk/vhdl/libs/basic_pkg.vhd XXX/trunk/vhdl/libs/basic_pkg.vhd /XXX/trunk/vhdl/libs/basic_pkg.vhd 400
Debug:  XXX/trunk/vhdl/video_lineup/mpp_proc/Xprimary_pkg.vhd None /XXX/trunk/vhdl/video_lineup/Xprimary_proc/Xprimary_pkg.vhd 394
Debug:  XXX/trunk/vhdl/video_lineup/mpp_proc/rtl/YxZmatrix.vhd XXX/trunk/vhdl/video_lineup/mpp_proc/rtl/YxZmatrix.vhd /XXX/trunk/vhdl/video_lineup/Xprimary_proc/rtl/YxZmatrix.vhd 400
Debug:  XXX/trunk/vhdl/video_lineup/mpp_proc/Xprimary_proc XXX/trunk/vhdl/video_lineup/mpp_proc/Xprimary_proc /XXX/trunk/vhdl/video_lineup/Xprimary_proc 394
401 XXX/trunk/vhdl/libs/basic_pkg.vhd F E
401 XXX/trunk/vhdl/video_lineup/Xprimary_proc/Xprimary_pkg.vhd F D
401 XXX/trunk/vhdl/video_lineup/Xprimary_proc/Xprimary_pkg.vhd F D
Failed to initialize environment. columns rev, path, change_type are not unique
Traceback (most recent call last):
  File "C:\Program Files\Python24\Lib\site-packages\trac\scripts\admin.py", line 629, in do_initenv
    repos.sync()
  File "c:\Program Files\Python24\lib\site-packages\trac\versioncontrol\cache.py", line 108, in sync
    (str(current_rev), path, kind, action,
  File "C:\Program Files\Python24\Lib\site-packages\trac\db\util.py", line 47, in execute
    return self.cursor.execute(sql_escape_percent(sql), args)
  File "C:\Program Files\Python24\Lib\site-packages\trac\db\sqlite_backend.py", line 44, in execute
    args or [])
  File "C:\Program Files\Python24\Lib\site-packages\trac\db\sqlite_backend.py", line 36, in _rollback_on_error
    return function(self, *args, **kwargs)
IntegrityError: columns rev, path, change_type are not unique

That seems like the same behavior as before the fix.

[cboos]

Yeah, sorry, I was about to commit r3795... It would really have been better with a test case...

Can you try again please?

[trac@…]

Seems to initialize fine now. However, viewing the changeset results in the following:

No node XXX/trunk/vhdl/video_lineup/mpp_proc/Xprimary_pkg.vhd at revision 394

[trac@…]

P.S. At 394, I guess the file is in Xprimary_proc, not mpp_proc

[cboos]

Grrr. Should have taken a different approach for r3795.

What about this?

Index: svn_fs.py
===================================================================
--- svn_fs.py	(revision 3795)
+++ svn_fs.py	(working copy)
@@ -666,9 +666,8 @@
             # Determine the action
             if not path:                # deletion
                 if base_path:
-                    base_path = '/'+key_path
                     action = Changeset.DELETE
-                    deletions[base_path] = idx
+                    deletions[key_path] = idx
                 elif self.scope:        # root property change
                     action = Changeset.EDIT
                 else:                   # deletion outside of scope, ignore
@@ -695,7 +694,7 @@
                     base_path, base_rev = cbase_path, cbase_rev
 
             kind = _kindmap[change.item_kind]
-            path = _path_within_scope(self.scope, _from_svn(path or base_path))
+            path = _path_within_scope(self.scope, _from_svn(path or key_path))
             base_path = _path_within_scope(self.scope, _from_svn(base_path))
             changes.append([path, kind, action, base_path, base_rev])
             idx += 1
@@ -703,6 +702,7 @@
         moves = []
         for k,v in copies.items():
             if k in deletions:
+                k = k.lstrip('/')
                 changes[v][2] = Changeset.MOVE
                 moves.append(deletions[k])
         offset = 0

[trac@…]

Initializes and reports the following files in the changeset:

XXX/trunk/vhdl/libs/basic_pkg.vhd  (modified)  (1 diff)
XXX/trunk/vhdl/video_lineup/Xprimary_proc (deleted)
XXX/trunk/vhdl/video_lineup/mpp_proc (copied) (copied from XXX/trunk/vhdl/video_lineup/Xprimary_proc REV=379)
XXX/trunk/vhdl/video_lineup/Xprimary_proc/Xprimary_pkg.vhd (deleted)
XXX/trunk/vhdl/video_lineup/mpp_proc/Xprimary_proc (copied) (copied from XXX/trunk/vhdl/video_lineup/Xprimary_proc REV=379)
XXX/trunk/vhdl/video_lineup/Xprimary_proc/Xprimary_pkg.vhd (deleted)
XXX/trunk/vhdl/video_lineup/Xprimary_proc/YxZmatrix.vhd (deleted)
XXX/trunk/vhdl/video_lineup/Xprimary_proc/YxZmatrix.vhd (deleted)
XXX/trunk/vhdl/video_lineup/mpp_proc/rtl (copied) (copied from XXX/trunk/vhdl/video_lineup/Xprimary_proc/rtl REV=400)
XXX/trunk/vhdl/video_lineup/mpp_proc/rtl/YxZmatrix.vhd (modified) (2 diffs)
XXX/trunk/vhdl/video_lineup/mpp_proc/sim (copied) (copied from XXX/trunk/vhdl/video_lineup/Xprimary_proc/sim REV=399)
XXX/trunk/vhdl/video_lineup/mpp_proc/tb (copied) (copied from XXX/trunk/vhdl/video_lineup/Xprimary_proc/tb REV=399)

(Tried to paste HTML, but was viewed as spam)

Hmm ...

Some files continue to show up twice, and are linked to 379.

And aren't the copied file revisions 394 and 400, rather than the ones given in the links (379, 400, 399)?

But I thought the other revisions were just 400 and 394. (?)

[cboos]

Replying to trac@digidescorp.com:

Initializes and reports the following files in the changeset:

Good!

Some files continue to show up twice, and are linked to 379.

Well, I could further improve on that, but I'm a bit hesitant for the place where we should check for those duplicated deletes.If I do it in the get_changes() method itself, the UI wouldn't need to be changed, but we would loose some information from what SVN provides. I think I'll do that anyway, as this information doesn't look that interesting and wasn't missed so far...

And aren't the copied file revisions 394 and 400, rather than the ones given in the links (379, 400, 399)? But I thought the other revisions were just 400 and 394. (?)

We try to provide interesting changesets, i.e. those corresponding to the last change that happened on that particular entry.

[trac@…]

Replying to cboos:

But I thought the other revisions were just 400 and 394. (?)

We try to provide interesting changesets, i.e. those corresponding to the last change that happened on that particular entry.

Fair enough! Thanks so much for your efforts.

[cboos]

So I've taken a different approach. Please upgrade to r3796, which reverts the last changes, then try the following patch:

Index: svn_fs.py
===================================================================
--- svn_fs.py	(revision 3796)
+++ svn_fs.py	(working copy)
@@ -649,7 +649,6 @@
         changes = []
         revroots = {}
         for path, change in editor.changes.items():
-            #assert path == change.path or change.base_path
             
             # Filtering on `path`
             if not (_is_path_within_scope(self.scope, path) and \
@@ -668,6 +667,8 @@
             # Determine the action
             if not path:                # deletion
                 if base_path:
+                    if base_path in deletions:
+                        continue # duplicates on base_path are possible (#3778)
                     action = Changeset.DELETE
                     deletions[base_path] = idx
                 elif self.scope:        # root property change

[cboos]

Correctly fixed by r3797. I finally managed to add a test case demonstrating that the above fix works. The problem is that the order in which entries are seen in the changeset matters. When I reused the names given by Dan, I managed to get a changeset demonstrating the double deletion issue:

$ svn log -r19 -v file:///C:/Workspace/local/svn/trac-vc
------------------------------------------------------------------------
r19 | cboos | 2006-09-27 12:41:27 +0200 (Wed, 27 Sep 2006) | 1 line
Changed paths:
   D /trunk/Xprimary_proc
   A /trunk/mpp_proc (from /trunk/Xprimary_proc:18)
   D /trunk/mpp_proc/Xprimary_pkg.vhd
   A /trunk/mpp_proc/Xprimary_proc (from /trunk/Xprimary_proc:18)
   D /trunk/mpp_proc/Xprimary_proc/Xprimary_pkg.vhd

Fancy copy+rename resulting in double delete.

Previous attempts (using a, b, c for the folder names, etc.) didn't succeed.

[trac@…]

Great!

So ... The more I get to know this changeset, the more I can't believe what's happening there. However, Trac's current changeset display with the files from r3797 looks very good to me. I can finally understand what happened!

Thanks again for you tenacity.

[anonymous]

I have a setup running 0.10.3 which is now completely stuck and unusable... Any suggestions would be welcome, like:
* a patch for 0.10.3
* an (easy) upgrade path (I tried the latest snapshot and its dependencies - only to get another error)
* svn commands to reload the tree without the double inserts

I'll take anything to get me out of this mess!

[mgood]

Replying to anonymous:

I have a setup running 0.10.3 which is now completely stuck and unusable...

Does your repository have the same instance of a copy+rename described here, or is it a different case of a duplicate key? If you're using MySQL you're likely experience the problems described in either #3676 or #4378.

[anonymous]

I guess it is a copy and rename issue, not exactly sure how it happened. more than likely it was a end-user error
I'm using the sqllite backend.

File "/usr/lib64/python2.4/site-packages/trac/db/sqlite_backend.py", line 48, in _rollback_on_error

return function(self, *args, **kwargs)

IntegrityError?: columns rev, path, change_type are not unique

[antoine@…]

Does anyone have a suggestion?

Anything please.

[cboos]

Without knowing the specifics of your problem, I'm afraid we can't help. Look at comment:6 for an example of what kind of data we'd need to understand the issue.

[anonymous]

ok - but how do I extract this info?

[anonymous]

can anyone tell me how to extract this info that you need?

[anonymous]

I even tried 0.10.4 snapshot, svn checkout. Also used the postgres backend instead of sqlite.

All fail with the same error.

[cboos]

Ok, here are the steps:

• enable debug level logging (see TracLogging)
• do a resync, keep note of the last revision number correctly cached, say X
• do a svn log -v -r(X+1) with (X+1) replaced by the actual number, of course. That would be the revision that can't be synced.

You should then be able to copy here the relevant information (like the original reporter did in comment:6).

[anonymous]

I can't believe this. Just did a resync with the current svn snapshot version and all is good! I should probably have tried that earlier!

[cboos]

Just out of curiosity... the svn snapshot of 0.10-stable, i.e. 0.10.4dev?

[anonymous]

http://trac.edgewall.org/wiki/TracOnGentoo http://trac.edgewall.org/attachment/wiki/TracOnGentoo/trac-svn-2.tar

Note: it may have nothing to do with which version I used. I could attempt to downgrade and resync, but now that everything works I am reluctant to do anything that might break something.

[cboos]

(this was originally fixed for 0.10, see comment:19)

[trac@…]

It's unclear to me what needs to be done exactly to fix this problem. In our case we have the following SVN check-in:

Changed paths:
   A /clients/scripps/trunk/fgs/test (from /sandbox/ravasthi/trunk/basic_wicket_project/test:5140)

When I run resync using [5249], I get the following in my log:

2007-04-21 21:06:12,244 Trac[cache] INFO: Trying to sync revision [5141]
2007-04-21 21:06:12,276 Trac[cache] DEBUG: Caching node change in [5141]: (None, 'dir', 'edit', None, -1)

And the following on my trac-admin:

Resyncing repository history...
 [48Command failed: ERROR:  null value in column "path" violates not-null constraint

Here's the table definition in PostgreSQL:

trac_scripps=> \d node_change
   Table "public.node_change"
   Column    | Type | Modifiers
-------------+------+-----------
 rev         | text | not null
 path        | text | not null
 node_type   | text |
 change_type | text | not null
 base_path   | text |
 base_rev    | text |
Indexes:
    "node_change_pk" PRIMARY KEY, btree (rev, path, change_type)
    "node_change_rev_idx" btree (rev)

[cboos]

Looks like it's a bug with scoped repositories. What's your actual scope, so that I can try to reproduce the problem?

[cboos]

(if this is indeed a bug, I'll create a new ticket for it)

[trac@…]

The trac project is scoped to /clients/scripps/. While /sandbox is directly off of svn root.

[anonymous]

Replying to trac@55minutes.com:

The trac project is scoped to /clients/scripps/. While /sandbox is directly off of svn root.

repository_dir = /var/svn/repos/55minutes/clients/scripps/

[cboos]

There was indeed a bug with scoped repositories, which I was able to trigger with a move/copy from outside of the scope to the inside, followed by a delete operation. Fixed in [5312-5313].