AnsweredAssumed Answered

Index Recovery (FULL) Hangs

Question asked by scegliau on May 31, 2010
Latest reply on Mar 21, 2012 by lynnders
Hi all,

I'm trying to rebuild indexes on  Alfresco Community 3.3.0 (2765) schema 4009.
Everything goes well till 90%: after that the application hangs and nothing else is written to the log file.

12:00:18,314  DEBUG [java.sql.PreparedStatement] {pstm-100481} Parameters: [5]
12:00:18,314  DEBUG [java.sql.PreparedStatement] {pstm-100481} Types: [java.lang.Long]
12:00:18,314  DEBUG [java.sql.ResultSet] {rset-100482} ResultSet
12:00:18,314  DEBUG [java.sql.ResultSet] {rset-100482} Header: [id, version, uri]
12:00:18,314  DEBUG [java.sql.ResultSet] {rset-100482} Result: [5, 0, http://www.alfresco.org/model/versionstore/2.0]
12:00:21,933  INFO  [node.index.FullIndexRecoveryComponent]    10 % complete.
12:00:24,040  INFO  [node.index.FullIndexRecoveryComponent]    20 % complete.
12:00:26,091  INFO  [node.index.FullIndexRecoveryComponent]    30 % complete.
12:00:27,668  INFO  [node.index.FullIndexRecoveryComponent]    40 % complete.
12:00:29,649  INFO  [node.index.FullIndexRecoveryComponent]    50 % complete.
12:00:31,229  INFO  [node.index.FullIndexRecoveryComponent]    60 % complete.
12:00:33,066  INFO  [node.index.FullIndexRecoveryComponent]    70 % complete.
12:00:34,800  INFO  [node.index.FullIndexRecoveryComponent]    80 % complete.
12:00:36,618  INFO  [node.index.FullIndexRecoveryComponent]    90 % complete.

Monitoring java process with jvisualvm I can see that there is a very slow heap usage and one CPU (we have 8 cores) is used costantly.
Making a thread dump I can see that there is one indexthread runnable:

"indexTrackerThread10" daemon prio=10 tid=0x00002aab48c51800 nid=0x6ec5 runnable [0x0000000045d42000]
   java.lang.Thread.State: RUNNABLE
   at java.lang.String.intern(Native Method)
   at org.apache.lucene.index.Term.<init>(Term.java:50)
   at org.apache.lucene.index.Term.<init>(Term.java:36)
   at org.alfresco.repo.search.impl.lucene.AbstractLuceneIndexerImpl.deleteReference(AbstractLuceneIndexerImpl.java:204)
   at org.alfresco.repo.search.impl.lucene.AbstractLuceneIndexerImpl.deleteImpl(AbstractLuceneIndexerImpl.java:600)
   at org.alfresco.repo.search.impl.lucene.AbstractLuceneIndexerImpl.flushPending(AbstractLuceneIndexerImpl.java:785)
   at org.alfresco.repo.search.impl.lucene.ADMLuceneIndexerImpl.doPrepare(ADMLuceneIndexerImpl.java:1665)
   at org.alfresco.repo.search.impl.lucene.AbstractLuceneIndexerImpl.prepare(AbstractLuceneIndexerImpl.java:466)
   at org.alfresco.repo.search.impl.lucene.AbstractLuceneIndexerAndSearcherFactory.prepare(AbstractLuceneIndexerAndSearcherFactory.java:804)
   at org.alfresco.repo.transaction.AlfrescoTransactionSupport$TransactionSynchronizationImpl.beforeCommit(AlfrescoTransactionSupport.java:689)
   at org.springframework.transaction.support.TransactionSynchronizationUtils.triggerBeforeCommit(TransactionSynchronizationUtils.java:95)
   at org.springframework.transaction.support.AbstractPlatformTransactionManager.triggerBeforeCommit(AbstractPlatformTransactionManager.java:927)
   at org.springframework.transaction.support.AbstractPlatformTransactionManager.processCommit(AbstractPlatformTransactionManager.java:737)
   at org.springframework.transaction.support.AbstractPlatformTransactionManager.commit(AbstractPlatformTransactionManager.java:723)
   at org.springframework.transaction.interceptor.TransactionAspectSupport.commitTransactionAfterReturning(TransactionAspectSupport.java:394)
   at org.alfresco.util.transaction.SpringAwareUserTransaction.commit(SpringAwareUserTransaction.java:472)
   - locked <0x00002aaacd631940> (a org.alfresco.util.transaction.SpringAwareUserTransaction)
   at org.alfresco.repo.transaction.RetryingTransactionHelper.doInTransaction(RetryingTransactionHelper.java:343)
   at org.alfresco.repo.node.index.AbstractReindexComponent$ReindexWorkerRunnable.run(AbstractReindexComponent.java:874)
   at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
   at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
   at java.lang.Thread.run(Thread.java:619)

and all the others are in TIME_WAITED, like this one:

"indexTrackerThread11" daemon prio=10 tid=0x00002aab49209000 nid=0x6ed1 in Object.wait() [0x0000000045e43000]
   java.lang.Thread.State: TIMED_WAITING (on object monitor)
   at java.lang.Object.wait(Native Method)
   - waiting on <0x00002aaacd6357f0> (a org.alfresco.repo.node.index.AbstractReindexComponent$ReindexWorkerRunnable)
   at org.alfresco.repo.node.index.AbstractReindexComponent$ReindexWorkerRunnable.waitForHeadOfQueue(AbstractReindexComponent.java:825)
   - locked <0x00002aaacd6357f0> (a org.alfresco.repo.node.index.AbstractReindexComponent$ReindexWorkerRunnable)
   at org.alfresco.repo.node.index.AbstractReindexComponent$ReindexWorkerRunnable.handleQueue(AbstractReindexComponent.java:987)
   at org.alfresco.repo.node.index.AbstractReindexComponent$ReindexWorkerRunnable.afterCommit(AbstractReindexComponent.java:956)
   at org.alfresco.repo.transaction.AlfrescoTransactionSupport$TransactionSynchronizationImpl.afterCompletion(AlfrescoTransactionSupport.java:808)
   at org.springframework.transaction.support.TransactionSynchronizationUtils.invokeAfterCompletion(TransactionSynchronizationUtils.java:168)
   at org.springframework.transaction.support.AbstractPlatformTransactionManager.invokeAfterCompletion(AbstractPlatformTransactionManager.java:996)
   at org.springframework.transaction.support.AbstractPlatformTransactionManager.triggerAfterCompletion(AbstractPlatformTransactionManager.java:971)
   at org.springframework.transaction.support.AbstractPlatformTransactionManager.processCommit(AbstractPlatformTransactionManager.java:799)
   at org.springframework.transaction.support.AbstractPlatformTransactionManager.commit(AbstractPlatformTransactionManager.java:723)
   at org.springframework.transaction.interceptor.TransactionAspectSupport.commitTransactionAfterReturning(TransactionAspectSupport.java:394)
   at org.alfresco.util.transaction.SpringAwareUserTransaction.commit(SpringAwareUserTransaction.java:472)
   - locked <0x00002aaacd635940> (a org.alfresco.util.transaction.SpringAwareUserTransaction)
   at org.alfresco.repo.transaction.RetryingTransactionHelper.doInTransaction(RetryingTransactionHelper.java:343)
   at org.alfresco.repo.node.index.AbstractReindexComponent$ReindexWorkerRunnable.run(AbstractReindexComponent.java:874)
   at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
   at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
   at java.lang.Thread.run(Thread.java:619)

Please, can someone help ?
If you need all the trhead dump, off course, I can upload it.
Thanks in advance

Outcomes