Description
Repository consistency check:
....
11:44:48 default: checked 1461347 bundles.
11:44:48 Checked 1461347 nodes in 72260 ms.
11:44:48 0 problems found
mysql> SELECT COUNT FROM DEFAULT_BUNDLE;
----------
COUNT |
----------
1461347 |
----------
1 row in set (0.98 sec)
Checking index consistency starts taking minutes instead of seconds for every 10% after having completed 50%:
10.09.2013 11:49:45 INFO [org.apache.jackrabbit.core.query.lucene.ConsistencyCheck.checkIndexConsistency():281] progress: 10%
10.09.2013 11:49:46 INFO [org.apache.jackrabbit.core.query.lucene.ConsistencyCheck.checkIndexConsistency():281] progress: 20%
10.09.2013 11:49:48 INFO [org.apache.jackrabbit.core.query.lucene.ConsistencyCheck.checkIndexConsistency():281] progress: 30%
10.09.2013 11:49:48 INFO [org.apache.jackrabbit.core.query.lucene.ConsistencyCheck.checkIndexConsistency():281] progress: 40%
10.09.2013 11:49:51 INFO [org.apache.jackrabbit.core.query.lucene.ConsistencyCheck.checkIndexConsistency():281] progress: 50%
10.09.2013 11:53:02 INFO [org.apache.jackrabbit.core.query.lucene.ConsistencyCheck.checkIndexConsistency():313] progress: 60%
10.09.2013 11:55:01 INFO [org.apache.jackrabbit.core.query.lucene.ConsistencyCheck.checkIndexConsistency():313] progress: 70%
10.09.2013 11:57:06 INFO [org.apache.jackrabbit.core.query.lucene.ConsistencyCheck.checkIndexConsistency():313] progress: 80%
10.09.2013 11:58:57 INFO [org.apache.jackrabbit.core.query.lucene.ConsistencyCheck.checkIndexConsistency():313] progress: 90%
10.09.2013 12:01:13 INFO [org.apache.jackrabbit.core.query.lucene.ConsistencyCheck.checkIndexConsistency():313] progress: 100%
Then it logs the INFO message "[org.apache.jackrabbit.core.query.lucene.ConsistencyCheck.doubleCheckErrors():231] False positive: Node <UUID> no longer exists." 730432 times, with every single UUID being unique.
And then it continues logging the INFO message "[org.apache.jackrabbit.core.query.lucene.ConsistencyCheck.doubleCheckErrors():231] False positive: Node <UUID> has unknown parent: <UUID>" 730531 times for 730531 unique nodes and169309 unique parents.
This was performed on an single node cluster (i.e. Clustering enabled, but consisting of only this single node), so no concurrent changes to the data could have happened. The problem is reproducable.