New upgrade step to fix inconsistencies in UID index. by mauritsvanrees · Pull Request #901 · euphorie/Euphorie

mauritsvanrees · 2025-10-10T21:53:17Z

For https://github.com/syslabcom/scrum/issues/3987

I have run this on oshastag-oira-app1. Output:

2025-10-10 17:01:07,111 INFO    [waitress:449][MainThread] Serving on http://0.0.0.0:9001
2025-10-10 17:01:40,807 INFO    [.:106][waitress-3] Checking inconsistencies in UID index.
2025-10-10 17:01:43,594 INFO    [.:58][waitress-3] Number of _index uid keys:      198801, unique: 198801
2025-10-10 17:01:43,639 INFO    [.:62][waitress-3] Number of _index doc id values: 198801, unique: 198801
2025-10-10 17:01:52,004 INFO    [.:66][waitress-3] Number of _unindex doc id keys: 419339, unique: 419339
2025-10-10 17:01:52,087 INFO    [.:70][waitress-3] Number of _unindex uid values:  419339, unique: 245707
2025-10-10 17:01:52,273 ERROR   [.:87][waitress-3] The numbers of keys and values in the UID index are NOT consistent.
2025-10-10 17:01:52,275 INFO    [.:115][waitress-3] Checking _unindex items.
2025-10-10 17:01:55,911 INFO    [.:127][waitress-3] Found 100 paths to recreate so far.
2025-10-10 17:01:57,129 INFO    [.:127][waitress-3] Found 200 paths to recreate so far.
...
2025-10-10 18:06:53,030 INFO    [.:127][waitress-3] Found 220500 paths to recreate so far.
2025-10-10 18:06:53,561 INFO    [.:129][waitress-3] Done checking _unindex items.
2025-10-10 18:06:53,563 INFO    [.:134][waitress-3] We will recreate 220538 UIDs/UUIDs that are currently duplicate.
2025-10-10 18:06:53,564 INFO    [.:138][waitress-3] You might need to manually fix some links.
We have no way of knowing if a link should use resolveuid/old_uid or resolveuid/new_uid.
Perhaps we could query the relation catalog to see which relations an item has.
2025-10-10 18:06:58,601 INFO    [.:177][waitress-3] Created fresh UID for 1000/220538 paths so far.
...
2025-10-10 18:12:43,862 INFO    [.:177][waitress-3] Created fresh UID for 220000/220538 paths so far.
2025-10-10 18:12:44,503 INFO    [.:181][waitress-3] Created fresh UID for all 220538 paths.
2025-10-10 18:12:44,505 INFO    [.:184][waitress-3] Clearing UID index...
2025-10-10 18:12:44,506 INFO    [.:186][waitress-3] Reindexing UID index...
2025-10-10 18:22:43,638 INFO    [.:188][waitress-3] Done reindexing UID index.
2025-10-10 18:22:43,642 INFO    [.:189][waitress-3] Processing catalog queue...
...
2025-10-10 18:44:25,329 INFO    [.:191][waitress-3] Done processing catalog queue.
2025-10-10 18:44:25,330 INFO    [.:192][waitress-3] The UID index should be fine again. Checking...
2025-10-10 18:44:27,267 INFO    [.:58][waitress-3] Number of _index uid keys:      419339, unique: 419339
2025-10-10 18:44:27,370 INFO    [.:62][waitress-3] Number of _index doc id values: 419339, unique: 419339
2025-10-10 18:44:28,084 INFO    [.:66][waitress-3] Number of _unindex doc id keys: 419339, unique: 419339
2025-10-10 18:44:28,196 INFO    [.:70][waitress-3] Number of _unindex uid values:  419339, unique: 419339
2025-10-10 18:44:32,845 INFO    [.:92][waitress-3] The numbers of keys and values in the UID index are consistent.
2025-10-10 18:44:37,625 INFO    [.:101][waitress-3] No inconsistencies found in UID index.
2025-10-10 18:44:37,627 INFO    [.:197][waitress-3] Yes, the UID index is consistent. All done.
2025-10-10 18:44:37,634 INFO    [GenericSetup:1131][waitress-3] Ran upgrade step Fix UID index inconsistencies. for profile euphorie.deployment:default

This takes 1 hour 45 minutes... Maybe that can be improved.

Then browsing to teleworking like in this comment looks like this:

I tried inserting one of those, but nothing happened. I don't know why. Maybe it just took long? For another module it worked.

I undid the database changes, so we still have this site to test on.

We reindexed its value in the UID index, but this was cleared and rebuilt later, so seems useless. Also, this would update all catalog metadata, where we only need to update the UID column. So when we are done, explicitly update the UID catalog column. This should be faster.

That should make the check we use it for faster.

mauritsvanrees · 2025-10-24T11:53:04Z

@ale-rt This is ready now. Previously on the test site this took 1 hour and 45 minutes. Now it is down to 30 minutes. Main change for that, shaving off a full hour:

+        index_index_values = set(index._index.values())
         for docid, uid in index._unindex.items():
-            if docid not in index._index.values():
+            if docid not in index_index_values:

I mentioned above that I had trouble inserting some items, but I have discovered what caused that. This happens when the context is a survey that does not use training, and with the miller columns you select a training question. I am making a PR in osha.oira to make this clear.

ale-rt

Thanks Maurits, wonderful job as usual ❤️
I added some comments.

This also works when the Plone Site is within a Folder.

mauritsvanrees · 2025-10-24T17:13:58Z

I am doing intermediate commits now. You can disable it by setting environment variable EUPHORIE_DISABLE_INTERMEDIATE_COMMITS=1. Could potentially be used in other cases as well.

It does not seem to influence the total time, but it should make the chance and impact of ConflictErrors smaller.

The log is then this:

2025-10-24 18:23:19,961 INFO    [.:132][waitress-2] Checking inconsistencies in UID index.
...
2025-10-24 18:23:41,081 INFO    [.:164][waitress-2] We will recreate 220538 UIDs/UUIDs that are currently duplicate.
2025-10-24 18:24:13,911 INFO    [.:207][waitress-2] Created fresh UID for 10000/220538 paths so far.
2025-10-24 18:24:36,946 INFO    [.:207][waitress-2] Created fresh UID for 20000/220538 paths so far.
2025-10-24 18:24:57,120 INFO    [.:207][waitress-2] Created fresh UID for 30000/220538 paths so far.
2025-10-24 18:25:14,615 INFO    [.:207][waitress-2] Created fresh UID for 40000/220538 paths so far.
2025-10-24 18:25:31,700 INFO    [.:207][waitress-2] Created fresh UID for 50000/220538 paths so far.
2025-10-24 18:25:42,118 INFO    [.:124][waitress-2] Committed transaction: Created fresh UID for 50000/220538 paths so far.
...
2025-10-24 18:32:10,590 INFO    [.:124][waitress-2] Committed transaction: Created fresh UID for all 220538 paths.
2025-10-24 18:32:10,593 INFO    [.:218][waitress-2] Updating catalog metadata for UIDs.
2025-10-24 18:32:10,594 INFO    [.:219][waitress-2] This can take a long time...
...
2025-10-24 18:44:53,946 INFO    [ProgressHandler:73][waitress-2] 419300/419339 (99.99%) Estimated termination: 2025/10/24 18:44:54h
2025-10-24 18:44:53,996 INFO    [ProgressHandler:73][waitress-2] Process terminated. Duration: 721.08 seconds
2025-10-24 18:45:02,617 INFO    [.:124][waitress-2] Committed transaction: Updating catalog metadata for UIDs.
...
2025-10-24 18:45:02,620 INFO    [.:224][waitress-2] Clearing UID index...
2025-10-24 18:45:02,623 INFO    [.:228][waitress-2] Reindexing UID index...
...
2025-10-24 18:55:38,038 INFO    [ProgressHandler:73][waitress-2] 410000/419339 (97.77%) Estimated termination: 2025/10/24 18:55:52h
2025-10-24 18:55:38,115 INFO    [ProgressHandler:73][waitress-2] committing subtransaction
2025-10-24 18:55:53,639 INFO    [ProgressHandler:73][waitress-2] Process terminated. Duration: 642.99 seconds
2025-10-24 18:55:53,640 INFO    [.:235][waitress-2] Reindexed UID index.
2025-10-24 18:55:56,932 INFO    [.:124][waitress-2] Committed transaction: Reindexed UID index.
2025-10-24 18:55:56,933 INFO    [.:238][waitress-2] The UID index should be fine again. Checking...
2025-10-24 18:55:57,128 INFO    [.:66][waitress-2] Number of _index uid keys:      419339, unique: 419339
2025-10-24 18:55:57,232 INFO    [.:71][waitress-2] Number of _index doc id values: 419339, unique: 419339
2025-10-24 18:55:57,575 INFO    [.:76][waitress-2] Number of _unindex doc id keys: 419339, unique: 419339
2025-10-24 18:55:57,663 INFO    [.:81][waitress-2] Number of _unindex uid values:  419339, unique: 419339
2025-10-24 18:56:01,005 INFO    [.:104][waitress-2] The numbers of keys and values in the UID index are consistent.
2025-10-24 18:56:04,522 INFO    [.:113][waitress-2] No inconsistencies found in UID index.
2025-10-24 18:56:04,523 INFO    [.:243][waitress-2] Yes, the UID index is consistent. All done.

And the Undo tab shows this:

Starting with the second commit it says "Zope" instead of "admin", and the most recent commit note is empty, but I don't really mind.

Technically we could do some intermediate commits during the metadata update and the reindex of the UID index, to get rid of two ten-minute commits. But that would mean copy-pasting and editing code from plone.app.upgrade and Products.ZCatalog. And in case of a ConflictError in one of these two parts I think you would need to restart the metadata update or the reindex fully anyway, so it may not actually help.

New upgrade step to fix inconsistencies in UID index.

3745ec8

mauritsvanrees requested a review from ale-rt October 10, 2025 21:53

mauritsvanrees added 5 commits October 24, 2025 10:57

Fix UID index: make faster, and show better progress.

1f4f4fa

Make index_index_values a set.

7c3e37b

That should make the check we use it for faster.

Yes, using a set made this extremely fast.

b435fcf

Update comments.

c114415

ale-rt reviewed Oct 24, 2025

View reviewed changes

mauritsvanrees added 2 commits October 24, 2025 17:30

upgrade step: use getPhysicalRoot to get the 'app' object.

f577cc1

This also works when the Plone Site is within a Folder.

Make intermediate commits when fixing the UID index.

5f4f6f8

ale-rt approved these changes Oct 31, 2025

View reviewed changes

ale-rt merged commit e3acd06 into main Oct 31, 2025
3 checks passed

ale-rt deleted the maurits-uid-index-inconsistencies branch October 31, 2025 10:29

Navigation Menu

New upgrade step to fix inconsistencies in UID index. - #901

New upgrade step to fix inconsistencies in UID index.#901
ale-rt merged 8 commits into
mainfrom
maurits-uid-index-inconsistencies

mauritsvanrees commented Oct 10, 2025

Uh oh!

mauritsvanrees commented Oct 24, 2025

Uh oh!

ale-rt left a comment

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

mauritsvanrees commented Oct 24, 2025

Uh oh!

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

2 participants

Conversation

mauritsvanrees commented Oct 10, 2025

Uh oh!

mauritsvanrees commented Oct 24, 2025

Uh oh!

ale-rt left a comment

Choose a reason for hiding this comment

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

mauritsvanrees commented Oct 24, 2025

Uh oh!

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

2 participants