index rebuilding hangs...

[ds-crcpress]

I'm trying to get my alfresco installation running again.  Due to a small mishap I need to rebuild the indexes (set config property to FULL).  But after 100% completion, it just hangs.  So I enabled debug logging, and here is where it stops.

09:16:31,494 DEBUG [repo.transaction.AlfrescoTransactionSupport] Fetched resource:
   key: MethodStatsorg.alfresco.repo.transaction.TransactionResourceInterceptor@1df95673
   resource: {public abstract org.alfresco.service.cmr.repository.ChildAssociationRef org.alfresco.service.cmr.repository.NodeService.getPrimaryParent(org.alfresco.service.cmr.repository.NodeRef) throws org.alfresco.service.cmr.repository.InvalidNodeRefException=org.alfresco.util.resource.MethodResourceManager$MethodStatistics@5f19756f, public abstract org.alfresco.service.namespace.QName org.alfresco.service.cmr.repository.NodeService.getType(org.alfresco.service.cmr.repository.NodeRef) throws org.alfresco.service.cmr.repository.InvalidNodeRefException=org.alfresco.util.resource.MethodResourceManager$MethodStatistics@b75a852, public abstract org.alfresco.service.cmr.repository.NodeRef org.alfresco.service.cmr.repository.NodeService.getRootNode(org.alfresco.service.cmr.repository.StoreRef) throws org.alfresco.service.cmr.repository.InvalidStoreRefException=org.alfresco.util.resource.MethodResourceManager$MethodStatistics@3ebc478a, public abstract org.alfresco.service.cmr.repository.NodeRef$Status org.alfresco.service.cmr.repository.NodeService.getNodeStatus(org.alfresco.service.cmr.repository.NodeRef)=org.alfresco.util.resource.MethodResourceManager$MethodStatistics@4c1129c, public abstract java.util.Set org.alfresco.service.cmr.repository.NodeService.getAspects(org.alfresco.service.cmr.repository.NodeRef) throws org.alfresco.service.cmr.repository.InvalidNodeRefException=org.alfresco.util.resource.MethodResourceManager$MethodStatistics@2f7e4adb, public abstract java.util.Map org.alfresco.service.cmr.repository.NodeService.getProperties(org.alfresco.service.cmr.repository.NodeRef) throws org.alfresco.service.cmr.repository.InvalidNodeRefException=org.alfresco.util.resource.MethodResourceManager$MethodStatistics@76351d99, public abstract java.util.List org.alfresco.service.cmr.repository.NodeService.getPaths(org.alfresco.service.cmr.repository.NodeRef,boolean) throws org.alfresco.service.cmr.repository.InvalidNodeRefException=org.alfresco.util.resource.MethodResourceManager$MethodStatistics@44995874, public abstract java.io.Serializable org.alfresco.service.cmr.repository.NodeService.getProperty(org.alfresco.service.cmr.repository.NodeRef,org.alfresco.service.namespace.QName) throws org.alfresco.service.cmr.repository.InvalidNodeRefException=org.alfresco.util.resource.MethodResourceManager$MethodStatistics@c648839, public abstract java.util.List org.alfresco.service.cmr.repository.NodeService.getParentAssocs(org.alfresco.service.cmr.repository.NodeRef) throws org.alfresco.service.cmr.repository.InvalidNodeRefException=org.alfresco.util.resource.MethodResourceManager$MethodStatistics@5dd47d76}
09:16:31,495 DEBUG [lucene.analysis.MLTokenDuplicator] Locale en using ALL_ONLY is []
09:16:31,495 DEBUG [lucene.analysis.MLTokenDuplicator] Locale en using ALL_ONLY is []
09:16:31,495 DEBUG [lucene.analysis.MLTokenDuplicator] Locale en using ALL_ONLY is []
09:16:31,495 DEBUG [lucene.analysis.MLTokenDuplicator] Locale en using ALL_ONLY is []
09:16:31,496 DEBUG [lucene.index.ReferenceCountingReadOnlyIndexReaderFactory$ReferenceCountingReadOnlyIndexReader] main: Reader MainReader closing        … org.alfresco.repo.search.impl.lucene.index.ReferenceCountingReadOnlyIndexReaderFactory$ReferenceCountingReadOnlyIndexReader@78ec8432
09:16:31,496 DEBUG [lucene.index.ReferenceCountingReadOnlyIndexReaderFactory$ReferenceCountingReadOnlyIndexReader] main: Reader MainReader - decrement - ref count is 0        … org.alfresco.repo.search.impl.lucene.index.ReferenceCountingReadOnlyIndexReaderFactory$ReferenceCountingReadOnlyIndexReader@78ec8432
09:16:31,496 DEBUG [lucene.index.ReferenceCountingReadOnlyIndexReaderFactory$ReferenceCountingReadOnlyIndexReader] main: Reader MainReader still open …. ref = 0 invalidForReuse = false        … org.alfresco.repo.search.impl.lucene.index.ReferenceCountingReadOnlyIndexReaderFactory$ReferenceCountingReadOnlyIndexReader@78ec8432
09:16:31,580 DEBUG [lucene.index.IndexInfo] Waiting for READ lock  - main
09:16:31,580 DEBUG [lucene.index.IndexInfo] …GOT READ LOCK  - main -  in 5.867E-4 ms
09:16:31,580 DEBUG [lucene.index.IndexInfo] RELEASED READ LOCK  - main
09:16:31,580 DEBUG [lucene.index.IndexInfo] Waiting for WRITE lock  - main
09:16:31,580 DEBUG [lucene.index.IndexInfo] …GOT WRITE LOCK  - main -  in 7.822E-4 ms
09:16:31,580 DEBUG [lucene.index.IndexInfo] Start Index c8caed9b-0962-11dd-8d19-ef1ef5a87815 state = PREPARED
09:16:31,580 DEBUG [lucene.index.IndexInfo]
Entry List
1         Name=8f3428bd-1d42-11dd-a92d-c5da260934ad Type=INDEX Status=COMMITTED Docs=29 Deletions=0
2         Name=62910d5b-070f-11dd-9d8d-418630c1fd6d Type=INDEX Status=COMMITTED Docs=12 Deletions=0
3         Name=c8caed9b-0962-11dd-8d19-ef1ef5a87815 Type=DELTA Status=PREPARING Docs=0 Deletions=0

09:16:31,582 DEBUG [lucene.index.IndexInfo] End Index c8caed9b-0962-11dd-8d19-ef1ef5a87815 state = PREPARED
09:16:31,582 DEBUG [lucene.index.IndexInfo]
Entry List
1         Name=8f3428bd-1d42-11dd-a92d-c5da260934ad Type=INDEX Status=COMMITTED Docs=29 Deletions=0
2         Name=62910d5b-070f-11dd-9d8d-418630c1fd6d Type=INDEX Status=COMMITTED Docs=12 Deletions=0
3         Name=c8caed9b-0962-11dd-8d19-ef1ef5a87815 Type=DELTA Status=PREPARED Docs=0 Deletions=0

09:16:31,582 DEBUG [lucene.index.IndexInfo] Waiting for READ lock  - main
09:16:31,582 DEBUG [lucene.index.IndexInfo] …GOT READ LOCK  - main -  in 4.19E-4 ms
09:16:31,582 DEBUG [lucene.index.IndexInfo] RELEASED WRITE LOCK  - main
09:16:31,582 DEBUG [lucene.index.IndexInfo] RELEASED READ LOCK  - main
09:16:31,582 DEBUG [lucene.index.IndexInfo] Waiting for READ lock  - main
09:16:31,582 DEBUG [lucene.index.IndexInfo] …GOT READ LOCK  - main -  in 3.912E-4 ms
09:16:31,582 DEBUG [lucene.index.IndexInfo] RELEASED READ LOCK  - main
09:16:31,582 DEBUG [lucene.index.IndexInfo] Waiting for WRITE lock  - main
09:16:31,582 DEBUG [lucene.index.IndexInfo] …GOT WRITE LOCK  - main -  in 4.749E-4 ms
09:16:31,582 DEBUG [lucene.index.IndexInfo] Start Index c95468ef-0962-11dd-8d19-ef1ef5a87815 state = PREPARING
09:16:31,582 DEBUG [lucene.index.IndexInfo]
Entry List
1         Name=1cc73c68-1b9c-11dd-aece-a908fac44278 Type=INDEX Status=COMMITTED Docs=29685 Deletions=0
2         Name=0214d0ed-08c9-11dd-9d8d-418630c1fd6d Type=INDEX Status=COMMITTED Docs=28654 Deletions=0
3         Name=ead0bd81-08c9-11dd-9d8d-418630c1fd6d Type=INDEX Status=COMMITTED Docs=1518 Deletions=0
4         Name=74825f55-08ca-11dd-9d8d-418630c1fd6d Type=INDEX Status=COMMITTED Docs=768 Deletions=0
5         Name=aa6f1a09-0959-11dd-a74d-9b8ae99db4c2 Type=INDEX Status=COMMITTED Docs=612 Deletions=0
6         Name=ada3df40-0959-11dd-a74d-9b8ae99db4c2 Type=DELTA Status=COMMITTED Docs=3 Deletions=2
7         Name=c95468ef-0962-11dd-8d19-ef1ef5a87815 Type=DELTA Status=ACTIVE Docs=0 Deletions=0

09:16:31,582 DEBUG [lucene.index.IndexInfo] End Index c95468ef-0962-11dd-8d19-ef1ef5a87815 state = PREPARING
09:16:31,582 DEBUG [lucene.index.IndexInfo]
Entry List
1         Name=1cc73c68-1b9c-11dd-aece-a908fac44278 Type=INDEX Status=COMMITTED Docs=29685 Deletions=0
2         Name=0214d0ed-08c9-11dd-9d8d-418630c1fd6d Type=INDEX Status=COMMITTED Docs=28654 Deletions=0
3         Name=ead0bd81-08c9-11dd-9d8d-418630c1fd6d Type=INDEX Status=COMMITTED Docs=1518 Deletions=0
4         Name=74825f55-08ca-11dd-9d8d-418630c1fd6d Type=INDEX Status=COMMITTED Docs=768 Deletions=0
5         Name=aa6f1a09-0959-11dd-a74d-9b8ae99db4c2 Type=INDEX Status=COMMITTED Docs=612 Deletions=0
6         Name=ada3df40-0959-11dd-a74d-9b8ae99db4c2 Type=DELTA Status=COMMITTED Docs=3 Deletions=2
7         Name=c95468ef-0962-11dd-8d19-ef1ef5a87815 Type=DELTA Status=PREPARING Docs=0 Deletions=0

09:16:31,582 DEBUG [lucene.index.IndexInfo] Waiting for READ lock  - main
09:16:31,582 DEBUG [lucene.index.IndexInfo] …GOT READ LOCK  - main -  in 3.911E-4 ms
09:16:31,582 DEBUG [lucene.index.IndexInfo] RELEASED WRITE LOCK  - main
09:16:31,583 DEBUG [lucene.index.IndexInfo] RELEASED READ LOCK  - main
09:16:31,583 DEBUG [lucene.index.IndexInfo] Waiting for READ lock  - main
09:16:31,583 DEBUG [lucene.index.IndexInfo] …GOT READ LOCK  - main -  in 3.632E-4 ms
09:16:31,583 DEBUG [lucene.index.IndexInfo] RELEASED READ LOCK  - main
09:16:31,583 DEBUG [lucene.index.IndexInfo] Waiting for WRITE lock  - main
09:16:31,583 DEBUG [lucene.index.IndexInfo] …GOT WRITE LOCK  - main -  in 4.749E-4 ms
09:16:31,583 DEBUG [lucene.index.ReferenceCountingReadOnlyIndexReaderFactory$ReferenceCountingReadOnlyIndexReader] main: Reader 1cc73c68-1b9c-11dd-aece-a908fac44278 - increment - ref count is 1        … org.alfresco.repo.search.impl.lucene.index.ReferenceCountingReadOnlyIndexReaderFactory$ReferenceCountingReadOnlyIndexReader@57177d79
09:16:31,583 DEBUG [lucene.index.ReferenceCountingReadOnlyIndexReaderFactory$ReferenceCountingReadOnlyIndexReader] main: Reader 0214d0ed-08c9-11dd-9d8d-418630c1fd6d - increment - ref count is 1        … org.alfresco.repo.search.impl.lucene.index.ReferenceCountingReadOnlyIndexReaderFactory$ReferenceCountingReadOnlyIndexReader@472ebf9a
09:16:31,584 DEBUG [lucene.index.ReferenceCountingReadOnlyIndexReaderFactory$ReferenceCountingReadOnlyIndexReader] main: Reader ead0bd81-08c9-11dd-9d8d-418630c1fd6d - increment - ref count is 1        … org.alfresco.repo.search.impl.lucene.index.ReferenceCountingReadOnlyIndexReaderFactory$ReferenceCountingReadOnlyIndexReader@4e253bf8
09:16:31,584 DEBUG [lucene.index.ReferenceCountingReadOnlyIndexReaderFactory$ReferenceCountingReadOnlyIndexReader] main: Reader 74825f55-08ca-11dd-9d8d-418630c1fd6d - increment - ref count is 1        … org.alfresco.repo.search.impl.lucene.index.ReferenceCountingReadOnlyIndexReaderFactory$ReferenceCountingReadOnlyIndexReader@50e0de15
09:16:31,584 DEBUG [lucene.index.ReferenceCountingReadOnlyIndexReaderFactory$ReferenceCountingReadOnlyIndexReader] main: Reader aa6f1a09-0959-11dd-a74d-9b8ae99db4c2 - increment - ref count is 1        … org.alfresco.repo.search.impl.lucene.index.ReferenceCountingReadOnlyIndexReaderFactory$ReferenceCountingReadOnlyIndexReader@5b145e2e
09:16:31,584 DEBUG [lucene.index.ReferenceCountingReadOnlyIndexReaderFactory$ReferenceCountingReadOnlyIndexReader] main: Reader ada3df40-0959-11dd-a74d-9b8ae99db4c2 - increment - ref count is 1        … org.alfresco.repo.search.impl.lucene.index.ReferenceCountingReadOnlyIndexReaderFactory$ReferenceCountingReadOnlyIndexReader@16334cb9
09:16:31,587 DEBUG [lucene.index.IndexInfo] There are 2 deletions for ada3df40-0959-11dd-a74d-9b8ae99db4c2
09:16:31,587 DEBUG [impl.lucene.FilterIndexReaderByStringId] Applying deletions FOR ada3df40-0959-11dd-a74d-9b8ae99db4c2 (the index ito which these are applied is the previous one …)
09:16:31,607 DEBUG [lucene.index.ReferenceCountingReadOnlyIndexReaderFactory] Replacing ref counting reader for MainReader
09:16:31,607 DEBUG [lucene.index.ReferenceCountingReadOnlyIndexReaderFactory] Created ref counting reader for MainReader org.alfresco.repo.search.impl.lucene.index.ReferenceCountingReadOnlyIndexReaderFactory$ReferenceCountingReadOnlyIndexReader@35f23c3a
09:16:31,607 DEBUG [lucene.index.IndexInfo] Waiting for READ lock  - main
09:16:31,607 DEBUG [lucene.index.IndexInfo] …GOT READ LOCK  - main -  in 3.911E-4 ms
09:16:31,607 DEBUG [lucene.index.IndexInfo] RELEASED WRITE LOCK  - main
09:16:31,607 DEBUG [lucene.index.ReferenceCountingReadOnlyIndexReaderFactory$ReferenceCountingReadOnlyIndexReader] main: Reader MainReader - increment - ref count is 1        … org.alfresco.repo.search.impl.lucene.index.ReferenceCountingReadOnlyIndexReaderFactory$ReferenceCountingReadOnlyIndexReader@35f23c3a
09:16:31,607 DEBUG [lucene.index.IndexInfo] Main index reader references = 1
09:16:31,607 DEBUG [lucene.index.IndexInfo] RELEASED READ LOCK  - main
09:16:31,608 DEBUG [lucene.index.IndexInfo] Waiting for READ lock  - main
09:16:31,608 DEBUG [lucene.index.IndexInfo] …GOT READ LOCK  - main -  in 3.911E-4 ms
09:16:31,608 DEBUG [lucene.index.IndexInfo] RELEASED READ LOCK  - main
‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍

Anybody? Any idea?  Do I just need to remain patient–ie, does this just take a really long time to complete?

Thanks,

David

[ds-crcpress]

Got tired of waiting, so I stopped the server and here is the additional log that occurs:

11:43:43,111 DEBUG [alfresco.util.VmShutdownListener] VM shutdown detected by listener IndexRecovery
11:43:43,111 DEBUG [alfresco.util.VmShutdownListener] VM shutdown detected by listener org.alfresco.repo.content.cleanup.ContentStoreCleaner
‍‍‍‍

[ds-crcpress]

Problem resolved… just had to be patient. 

[sangireddi]

can you share your solution with us?