Hibernate Search 3.3.0 Final: Massindexer taking a long time to index

Hi I have the following class. User view is materialized view in oracle.

  public class UserView {
        @DocumentId
        private Integer           id;

        @Fields({ @Field(index = Index.TOKENIZED, store = Store.YES),
                @Field(name = "username_sort", index = Index.UN_TOKENIZED, store = Store.NO) })
        @Boost(value = 2.5f)
        private String            username;

        @Fields({ @Field(index = Index.TOKENIZED, store = Store.YES),
                @Field(name = "email_sort", index = Index.UN_TOKENIZED, store = Store.NO) })
        @Boost(value = 2)
        private String            email;

        @Fields({ @Field(index = Index.TOKENIZED, store = Store.YES),
                @Field(name = "firstname_sort", index = Index.UN_TOKENIZED, store = Store.NO)    })
        @Boost(value = 1.5f)
        private String            firstname;

        @Fields({ @Field(index = Index.TOKENIZED, store = Store.YES),
                @Field(name = "lastname_sort", index = Index.UN_TOKENIZED, store = Store.NO) })
        @Boost(value = 1.5f)
        private String            lastname;

        @Field(index = Index.NO_NORMS)
        @DateBridge(resolution = Resolution.MILLISECOND)
        private Timestamp         createDate;

        @IndexedEmbedded(depth = 1, prefix = "createBy_")
        private UserView          createdBy;

        @Field(index = Index.TOKENIZED)
        @DateBridge(resolution = Resolution.MILLISECOND)
        private Timestamp         modifyDate;

        @IndexedEmbedded(depth = 1, prefix = "modifyBy_")
        private UserView          modifiedBy;
    }

Than I have the Data access object for mass indexing as follow.

private static class BatchProcessUserReindex implements HibernateCallback<Future<?>> {
        private final Logger LOG = LoggerFactory.getLogger(this.getClass());

        private final int    batchSize;
        private final int    fetchSize;

        public BatchProcessUserReindex(final int batchSize, final int fetchSize) {
            super();
            this.batchSize = batchSize;
            this.fetchSize = fetchSize;
        }

        @Override
        public Future<?> doInHibernate(final Session session) {
            final Integer threadsToLoadObject = (this.fetchSize / this.batchSize);
            final Integer threadsForFetch = (this.batchSize/threadsToLoadObject) * threadsToLoadObject;
            final FullTextSession fullTextSession = Search.getFullTextSession(session);
            final Future<?> batchProcesses = fullTextSession.createIndexer(UserView.class)
                    .batchSizeToLoadObjects(this.batchSize)
                    .threadsForSubsequentFetching(threadsForFetch)
                    .threadsToLoadObjects(threadsToLoadObject)
                    .start();
            batchProcesses.get(); // block all incoming request. 
            if (this.LOG.isDebugEnabled()) {
                final Statistics stat = fullTextSession.getSearchFactory().getStatistics();
                this.LOG.debug("batch size {}", this.batchSize);
                this.LOG.debug("threads for fetch {}", threadsForFetch);
                this.LOG.debug("threads to load object {}", threadsToLoadObject);
                this.LOG.debug("average loading execution time: {}", stat.getObjectLoadingExecutionAvgTime());
                this.LOG.debug("maximum loading time: {}", stat.getObjectLoadingExecutionMaxTime());
                this.LOG.debug("total time to load object: {}", stat.getObjectLoadingTotalTime());
                this.LOG.debug("total object loaded: {}", stat.getObjectsLoadedCount());
                this.LOG.debug("average search time: {}", stat.getSearchQueryExecutionAvgTime());
                this.LOG.debug("maximum search time: {}", stat.getSearchQueryExecutionMaxTime());
                this.LOG.debug("total time to search object: {}", stat.getSearchQueryTotalTime());
                this.LOG.debug("total object search: {}", stat.getSearchQueryExecutionCount());
                this.LOG.debug("query with slowest search: {}", stat.getSearchQueryExecutionMaxTimeQueryString());
            }
            return batchProcesses;
        }
    }

I have batch size as 25 and fetch size as 200. So my transaction setting for batching.

@Transactional(propagation = Propagation.REQUIRES_NEW,
            isolation = Isolation.READ_COMMITTED)

Here are my properties setting.

hibernate.search.User.directory_provider=filesystem-master
hibernate.search.User.optimizer.operation_limit.max=500
hibernate.search.User.optimizer.transaction_limit.max=50
hibernate.search.User.locking_strategy=native
hibernate.search.User.indexwriter.batch.merge_factor=32
hibernate.search.User.indexwriter.batch.ram_buffer_size=64
hibernate.search.User.indexwriter.batch.max_merge_docs=2147483647
hibernate.search.User.indexwriter.batch.max_buffered_docs=64
hibernate.search.User.exclusive_index_use=true
hibernate.search.User.refresh=7200
hibernate.search.User.buffer_size_on_copy=64
hibernate.search.generate_statistics=true

So I start indexing and it ends up taking more than 7 minutes and no result (and I only have 20 user in the system)?????

What is wrong? Why does it take so long.

Here is the trace log file.

2011-03-13 08:35:49,664 INFO  [org.hibernate.search.Version][main][] Hibernate Search 3.4.0.Alpha1
2011-03-13 08:35:50,685 DEBUG [org.hibernate.search.impl.ConfigContext][main][] Using default similarity implementation: org.apache.lucene.search.DefaultSimilarity
2011-03-13 08:35:50,743 TRACE [org.hibernate.search.backend.configuration.MaskedProperty][main][] found a match for key: [hibernate.search.User.directory_provider] value: filesystem-master
2011-03-13 08:35:50,743 TRACE [org.hibernate.search.backend.configuration.MaskedProperty][main][] found a match for key: [User.directory_provider] value: filesystem-master
2011-03-13 08:35:50,764 TRACE [org.hibernate.search.backend.configuration.MaskedProperty][main][] found a match for key: [hibernate.search.default.sourceBase] value: searchIndexCopy
2011-03-13 08:35:50,764 TRACE [org.hibernate.search.backend.configuration.MaskedProperty][main][] found a match for key: [default.sourceBase] value: sear开发者_StackOverflow中文版chIndexCopy
2011-03-13 08:35:50,764 TRACE [org.hibernate.search.store.DirectoryProviderHelper][main][] Guess source directory from sourceBase searchIndexCopy and source <null>
2011-03-13 08:35:50,764 WARN  [org.hibernate.search.store.DirectoryProviderHelper][main][] Index directory not found, creating: '/searchIndexCopy'
2011-03-13 08:35:50,765 WARN  [org.hibernate.search.store.DirectoryProviderHelper][main][] Index directory not found, creating: '/searchIndexCopy\User'
2011-03-13 08:35:50,766 DEBUG [org.hibernate.search.store.DirectoryProviderHelper][main][] Got directory from root + relative
2011-03-13 08:35:50,767 DEBUG [org.hibernate.search.store.FSMasterDirectoryProvider][main][] Source directory: searchIndexCopy\User
2011-03-13 08:35:50,767 TRACE [org.hibernate.search.backend.configuration.MaskedProperty][main][] found a match for key: [hibernate.search.default.indexBase] value: searchIndex
2011-03-13 08:35:50,767 TRACE [org.hibernate.search.backend.configuration.MaskedProperty][main][] found a match for key: [default.indexBase] value: searchIndex
2011-03-13 08:35:50,767 WARN  [org.hibernate.search.store.DirectoryProviderHelper][main][] Index directory not found, creating: '/searchIndex'
2011-03-13 08:35:50,768 WARN  [org.hibernate.search.store.DirectoryProviderHelper][main][] Index directory not found, creating: '/searchIndex\User'
2011-03-13 08:35:50,769 DEBUG [org.hibernate.search.store.FSMasterDirectoryProvider][main][] Index directory: searchIndex\User
2011-03-13 08:35:50,770 TRACE [org.hibernate.search.backend.configuration.MaskedProperty][main][] found a match for key: [hibernate.search.User.locking_strategy] value: native
2011-03-13 08:35:50,770 TRACE [org.hibernate.search.backend.configuration.MaskedProperty][main][] found a match for key: [User.locking_strategy] value: native
2011-03-13 08:35:50,793 DEBUG [org.hibernate.search.store.DirectoryProviderHelper][main][] Initialize index: '/searchIndex\User'
2011-03-13 08:35:50,986 TRACE [org.hibernate.search.backend.configuration.MaskedProperty][main][] found a match for key: [hibernate.search.User.buffer_size_on_copy] value: 64
2011-03-13 08:35:50,986 TRACE [org.hibernate.search.backend.configuration.MaskedProperty][main][] found a match for key: [User.buffer_size_on_copy] value: 64
2011-03-13 08:35:50,986 TRACE [org.hibernate.search.backend.configuration.MaskedProperty][main][] found a match for key: [hibernate.search.User.exclusive_index_use] value: true
2011-03-13 08:35:50,986 TRACE [org.hibernate.search.backend.configuration.MaskedProperty][main][] found a match for key: [User.exclusive_index_use] value: true
2011-03-13 08:35:50,988 TRACE [org.hibernate.search.backend.configuration.MaskedProperty][main][] found a match for key: [hibernate.search.User.optimizer.transaction_limit.max] value: 50
2011-03-13 08:35:50,988 TRACE [org.hibernate.search.backend.configuration.MaskedProperty][main][] found a match for key: [User.optimizer.transaction_limit.max] value: 50
2011-03-13 08:35:50,989 TRACE [org.hibernate.search.backend.configuration.MaskedProperty][main][] found a match for key: [hibernate.search.User.optimizer.transaction_limit.max] value: 50
2011-03-13 08:35:50,989 TRACE [org.hibernate.search.backend.configuration.MaskedProperty][main][] found a match for key: [User.optimizer.transaction_limit.max] value: 50
2011-03-13 08:35:51,010 TRACE [org.hibernate.search.backend.configuration.MaskedProperty][main][] found a match for key: [hibernate.search.User.indexwriter.batch.max_buffered_docs] value: 64
2011-03-13 08:35:51,010 TRACE [org.hibernate.search.backend.configuration.MaskedProperty][main][] found a match for key: [User.indexwriter.batch.max_buffered_docs] value: 64
2011-03-13 08:35:51,010 TRACE [org.hibernate.search.backend.configuration.MaskedProperty][main][] found a match for key: [indexwriter.batch.max_buffered_docs] value: 64
2011-03-13 08:35:51,011 TRACE [org.hibernate.search.backend.configuration.MaskedProperty][main][] found a match for key: [batch.max_buffered_docs] value: 64
2011-03-13 08:35:51,011 DEBUG [org.hibernate.search.backend.LuceneIndexingParameters][main][] Set index writer parameter batch.max_buffered_docs to value : 64
2011-03-13 08:35:51,011 TRACE [org.hibernate.search.backend.configuration.MaskedProperty][main][] found a match for key: [hibernate.search.User.indexwriter.batch.max_merge_docs] value: 2147483647
2011-03-13 08:35:51,011 TRACE [org.hibernate.search.backend.configuration.MaskedProperty][main][] found a match for key: [User.indexwriter.batch.max_merge_docs] value: 2147483647
2011-03-13 08:35:51,011 TRACE [org.hibernate.search.backend.configuration.MaskedProperty][main][] found a match for key: [indexwriter.batch.max_merge_docs] value: 2147483647
2011-03-13 08:35:51,011 TRACE [org.hibernate.search.backend.configuration.MaskedProperty][main][] found a match for key: [batch.max_merge_docs] value: 2147483647
2011-03-13 08:35:51,011 DEBUG [org.hibernate.search.backend.LuceneIndexingParameters][main][] Set index writer parameter batch.max_merge_docs to value : 2147483647
2011-03-13 08:35:51,011 TRACE [org.hibernate.search.backend.configuration.MaskedProperty][main][] found a match for key: [hibernate.search.User.indexwriter.batch.merge_factor] value: 32
2011-03-13 08:35:51,011 TRACE [org.hibernate.search.backend.configuration.MaskedProperty][main][] found a match for key: [User.indexwriter.batch.merge_factor] value: 32
2011-03-13 08:35:51,011 TRACE [org.hibernate.search.backend.configuration.MaskedProperty][main][] found a match for key: [indexwriter.batch.merge_factor] value: 32
2011-03-13 08:35:51,011 TRACE [org.hibernate.search.backend.configuration.MaskedProperty][main][] found a match for key: [batch.merge_factor] value: 32
2011-03-13 08:35:51,011 DEBUG [org.hibernate.search.backend.LuceneIndexingParameters][main][] Set index writer parameter batch.merge_factor to value : 32
2011-03-13 08:35:51,012 TRACE [org.hibernate.search.backend.configuration.MaskedProperty][main][] found a match for key: [hibernate.search.User.indexwriter.batch.ram_buffer_size] value: 64
2011-03-13 08:35:51,012 TRACE [org.hibernate.search.backend.configuration.MaskedProperty][main][] found a match for key: [User.indexwriter.batch.ram_buffer_size] value: 64
2011-03-13 08:35:51,012 TRACE [org.hibernate.search.backend.configuration.MaskedProperty][main][] found a match for key: [indexwriter.batch.ram_buffer_size] value: 64
2011-03-13 08:35:51,012 TRACE [org.hibernate.search.backend.configuration.MaskedProperty][main][] found a match for key: [batch.ram_buffer_size] value: 64
2011-03-13 08:35:51,012 DEBUG [org.hibernate.search.backend.LuceneIndexingParameters][main][] Set index writer parameter batch.ram_buffer_size to value : 64
2011-03-13 08:35:51,154 TRACE [org.hibernate.search.engine.AbstractDocumentBuilder][main][] depth reached, ignoring createBy_createBy_
2011-03-13 08:35:51,154 TRACE [org.hibernate.search.engine.AbstractDocumentBuilder][main][] depth reached, ignoring createBy_modifyBy_
2011-03-13 08:35:51,162 TRACE [org.hibernate.search.engine.AbstractDocumentBuilder][main][] depth reached, ignoring modifyBy_createBy_
2011-03-13 08:35:51,162 TRACE [org.hibernate.search.engine.AbstractDocumentBuilder][main][] depth reached, ignoring modifyBy_modifyBy_
2011-03-13 08:35:51,186 DEBUG [org.hibernate.search.engine.DocumentBuilderIndexedEntity][main][] Field selection in projections is set to true for entity com.domain.UserView.
2011-03-13 08:35:51,190 DEBUG [org.hibernate.search.store.FSMasterDirectoryProvider][main][] Source directory for '/searchIndex\User' will be initialized
2011-03-13 08:35:51,217 DEBUG [org.hibernate.search.store.FSMasterDirectoryProvider][main][] Current directory: 1
2011-03-13 08:35:51,229 TRACE [org.hibernate.search.backend.configuration.MaskedProperty][main][] found a match for key: [hibernate.search.User.refresh] value: 7200
2011-03-13 08:35:51,229 TRACE [org.hibernate.search.backend.configuration.MaskedProperty][main][] found a match for key: [User.refresh] value: 7200
2011-03-13 08:35:51,230 DEBUG [org.hibernate.search.store.DirectoryProviderHelper][main][] Refresh period: 7200 seconds
2011-03-13 08:35:51,314 DEBUG [org.hibernate.search.event.FullTextIndexEventListener][main][] Hibernate Search event listeners deactivated
2011-03-13 08:35:51,315 DEBUG [org.hibernate.search.event.FullTextIndexEventListener][main][] Hibernate Search dirty checks enabled
2011-03-13 08:35:51,315 DEBUG [org.hibernate.search.event.FullTextIndexEventListener][main][] Hibernate Search event listeners deactivated
2011-03-13 08:35:51,315 DEBUG [org.hibernate.search.event.FullTextIndexEventListener][main][] Hibernate Search dirty checks enabled
2011-03-13 08:35:51,315 DEBUG [org.hibernate.search.event.FullTextIndexEventListener][main][] Hibernate Search event listeners deactivated
2011-03-13 08:35:51,315 DEBUG [org.hibernate.search.event.FullTextIndexEventListener][main][] Hibernate Search dirty checks enabled
2011-03-13 08:35:51,315 DEBUG [org.hibernate.search.event.FullTextIndexEventListener][main][] Hibernate Search event listeners deactivated
2011-03-13 08:35:51,315 DEBUG [org.hibernate.search.event.FullTextIndexEventListener][main][] Hibernate Search dirty checks enabled
2011-03-13 08:35:51,315 DEBUG [org.hibernate.search.event.FullTextIndexEventListener][main][] Hibernate Search event listeners deactivated
2011-03-13 08:35:51,315 DEBUG [org.hibernate.search.event.FullTextIndexEventListener][main][] Hibernate Search dirty checks enabled
2011-03-13 08:35:51,315 DEBUG [org.hibernate.search.event.FullTextIndexEventListener][main][] Hibernate Search event listeners deactivated
2011-03-13 08:35:51,316 DEBUG [org.hibernate.search.event.FullTextIndexEventListener][main][] Hibernate Search dirty checks enabled
2011-03-13 08:35:51,316 DEBUG [org.hibernate.search.event.FullTextIndexEventListener][main][] Hibernate Search event listeners deactivated
2011-03-13 08:35:51,316 DEBUG [org.hibernate.search.event.FullTextIndexEventListener][main][] Hibernate Search dirty checks enabled
2011-03-13 08:35:52,825 TRACE [org.hibernate.search.spi.internals.PolymorphicIndexHierarchy][main][] Targeted indexed classes for [class com.domain.UserView]: [class com.domain.UserView]
2011-03-13 08:35:52,826 DEBUG [org.hibernate.search.impl.MassIndexerImpl][main][] Targets for indexing job: [class com.domain.UserView]
2011-03-13 08:35:52,846 TRACE [org.hibernate.search.backend.configuration.MaskedProperty][main][] found a match for key: [hibernate.search.batchbackend.concurrent_writers] value: 4
2011-03-13 08:35:52,848 TRACE [org.hibernate.search.spi.internals.PolymorphicIndexHierarchy][main][] Targeted indexed classes for [class com.domain.UserView]: [class com.domain.UserView]
2011-03-13 08:35:52,856 TRACE [org.hibernate.search.backend.Workspace][main][] IndexWriter opened
2011-03-13 08:35:52,856 TRACE [org.hibernate.search.backend.impl.lucene.works.PurgeAllWorkDelegate][main][] purgeAll Lucene index using IndexWriter for type: class com.domain.UserView
2011-03-13 08:35:52,867 TRACE [org.hibernate.search.backend.impl.lucene.works.OptimizeWorkDelegate][main][] optimize Lucene index: class com.domain.UserView
2011-03-13 08:35:52,887 TRACE [org.hibernate.search.batchindexing.OptionallyWrapInJTATransaction][Hibernate Search: collectionsloader-1][] TransactionFactory does not require a TransactionManager: don't wrap in a JTA transaction
2011-03-13 08:35:52,897 TRACE [org.hibernate.search.batchindexing.IdentifierConsumerEntityProducer][Hibernate Search: BatchIndexingWorkspace-1][] created
2011-03-13 08:35:52,901 TRACE [org.hibernate.search.batchindexing.OptionallyWrapInJTATransaction][Hibernate Search: collectionsloader-24][] TransactionFactory does not require a TransactionManager: don't wrap in a JTA transaction
2011-03-13 08:35:52,909 TRACE [org.hibernate.search.batchindexing.OptionallyWrapInJTATransaction][Hibernate Search: entityloader-1][] TransactionFactory does not require a TransactionManager: don't wrap in a JTA transaction
2011-03-13 08:35:52,901 TRACE [org.hibernate.search.batchindexing.OptionallyWrapInJTATransaction][Hibernate Search: collectionsloader-20][] TransactionFactory does not require a TransactionManager: don't wrap in a JTA transaction
2011-03-13 08:35:52,901 TRACE [org.hibernate.search.batchindexing.OptionallyWrapInJTATransaction][Hibernate Search: collectionsloader-16][] TransactionFactory does not require a TransactionManager: don't wrap in a JTA transaction
2011-03-13 08:35:52,892 TRACE [org.hibernate.search.batchindexing.OptionallyWrapInJTATransaction][Hibernate Search: collectionsloader-3][] TransactionFactory does not require a TransactionManager: don't wrap in a JTA transaction
2011-03-13 08:35:52,901 TRACE [org.hibernate.search.batchindexing.OptionallyWrapInJTATransaction][Hibernate Search: collectionsloader-12][] TransactionFactory does not require a TransactionManager: don't wrap in a JTA transaction
2011-03-13 08:35:52,901 TRACE [org.hibernate.search.batchindexing.OptionallyWrapInJTATransaction][Hibernate Search: collectionsloader-8][] TransactionFactory does not require a TransactionManager: don't wrap in a JTA transaction
2011-03-13 08:35:52,900 TRACE [org.hibernate.search.batchindexing.OptionallyWrapInJTATransaction][Hibernate Search: collectionsloader-4][] TransactionFactory does not require a TransactionManager: don't wrap in a JTA transaction
2011-03-13 08:35:52,896 TRACE [org.hibernate.search.batchindexing.OptionallyWrapInJTATransaction][Hibernate Search: collectionsloader-23][] TransactionFactory does not require a TransactionManager: don't wrap in a JTA transaction
2011-03-13 08:35:52,895 TRACE [org.hibernate.search.batchindexing.OptionallyWrapInJTATransaction][Hibernate Search: collectionsloader-21][] TransactionFactory does not require a TransactionManager: don't wrap in a JTA transaction
2011-03-13 08:35:52,895 TRACE [org.hibernate.search.batchindexing.OptionallyWrapInJTATransaction][Hibernate Search: collectionsloader-19][] TransactionFactory does not require a TransactionManager: don't wrap in a JTA transaction
2011-03-13 08:35:52,894 TRACE [org.hibernate.search.batchindexing.OptionallyWrapInJTATransaction][Hibernate Search: collectionsloader-17][] TransactionFactory does not require a TransactionManager: don't wrap in a JTA transaction
2011-03-13 08:35:52,894 TRACE [org.hibernate.search.batchindexing.OptionallyWrapInJTATransaction][Hibernate Search: collectionsloader-15][] TransactionFactory does not require a TransactionManager: don't wrap in a JTA transaction
2011-03-13 08:35:52,894 TRACE [org.hibernate.search.batchindexing.OptionallyWrapInJTATransaction][Hibernate Search: collectionsloader-13][] TransactionFactory does not require a TransactionManager: don't wrap in a JTA transaction
2011-03-13 08:35:52,893 TRACE [org.hibernate.search.batchindexing.OptionallyWrapInJTATransaction][Hibernate Search: collectionsloader-11][] TransactionFactory does not require a TransactionManager: don't wrap in a JTA transaction
2011-03-13 08:35:52,893 TRACE [org.hibernate.search.batchindexing.OptionallyWrapInJTATransaction][Hibernate Search: collectionsloader-9][] TransactionFactory does not require a TransactionManager: don't wrap in a JTA transaction
2011-03-13 08:35:52,893 TRACE [org.hibernate.search.batchindexing.OptionallyWrapInJTATransaction][Hibernate Search: collectionsloader-7][] TransactionFactory does not require a TransactionManager: don't wrap in a JTA transaction
2011-03-13 08:35:52,892 TRACE [org.hibernate.search.batchindexing.OptionallyWrapInJTATransaction][Hibernate Search: collectionsloader-5][] TransactionFactory does not require a TransactionManager: don't wrap in a JTA transaction
2011-03-13 08:35:52,906 TRACE [org.hibernate.search.batchindexing.OptionallyWrapInJTATransaction][Hibernate Search: collectionsloader-6][] TransactionFactory does not require a TransactionManager: don't wrap in a JTA transaction
2011-03-13 08:35:52,906 TRACE [org.hibernate.search.batchindexing.OptionallyWrapInJTATransaction][Hibernate Search: collectionsloader-10][] TransactionFactory does not require a TransactionManager: don't wrap in a JTA transaction
2011-03-13 08:35:52,906 TRACE [org.hibernate.search.batchindexing.OptionallyWrapInJTATransaction][Hibernate Search: collectionsloader-14][] TransactionFactory does not require a TransactionManager: don't wrap in a JTA transaction
2011-03-13 08:35:52,906 TRACE [org.hibernate.search.batchindexing.OptionallyWrapInJTATransaction][Hibernate Search: collectionsloader-18][] TransactionFactory does not require a TransactionManager: don't wrap in a JTA transaction
2011-03-13 08:35:52,905 TRACE [org.hibernate.search.batchindexing.OptionallyWrapInJTATransaction][Hibernate Search: collectionsloader-22][] TransactionFactory does not require a TransactionManager: don't wrap in a JTA transaction
2011-03-13 08:35:52,905 TRACE [org.hibernate.search.batchindexing.OptionallyWrapInJTATransaction][Hibernate Search: collectionsloader-2][] TransactionFactory does not require a TransactionManager: don't wrap in a JTA transaction
2011-03-13 08:35:52,911 TRACE [org.hibernate.search.batchindexing.IdentifierConsumerEntityProducer][Hibernate Search: entityloader-1][] started
2011-03-13 08:35:52,907 TRACE [org.hibernate.search.batchindexing.IdentifierConsumerEntityProducer][Hibernate Search: BatchIndexingWorkspace-1][] created
2011-03-13 08:35:53,001 TRACE [org.hibernate.search.batchindexing.IdentifierConsumerEntityProducer][Hibernate Search: BatchIndexingWorkspace-1][] created
2011-03-13 08:35:53,004 TRACE [org.hibernate.search.batchindexing.IdentifierConsumerEntityProducer][Hibernate Search: BatchIndexingWorkspace-1][] created
2011-03-13 08:35:53,005 TRACE [org.hibernate.search.batchindexing.IdentifierConsumerEntityProducer][Hibernate Search: BatchIndexingWorkspace-1][] created
2011-03-13 08:35:53,005 TRACE [org.hibernate.search.batchindexing.IdentifierConsumerEntityProducer][Hibernate Search: BatchIndexingWorkspace-1][] created
2011-03-13 08:35:53,005 TRACE [org.hibernate.search.batchindexing.IdentifierConsumerEntityProducer][Hibernate Search: BatchIndexingWorkspace-1][] created
2011-03-13 08:35:53,005 TRACE [org.hibernate.search.batchindexing.IdentifierConsumerEntityProducer][Hibernate Search: BatchIndexingWorkspace-1][] created
2011-03-13 08:35:53,008 TRACE [org.hibernate.search.batchindexing.IdentifierProducer][Hibernate Search: BatchIndexingWorkspace-1][] created
2011-03-13 08:35:53,018 TRACE [org.hibernate.search.batchindexing.OptionallyWrapInJTATransaction][Hibernate Search: entityloader-2][] TransactionFactory does not require a TransactionManager: don't wrap in a JTA transaction
2011-03-13 08:35:53,031 TRACE [org.hibernate.search.batchindexing.IdentifierConsumerEntityProducer][Hibernate Search: entityloader-2][] started
2011-03-13 08:35:53,031 TRACE [org.hibernate.search.batchindexing.OptionallyWrapInJTATransaction][Hibernate Search: entityloader-6][] TransactionFactory does not require a TransactionManager: don't wrap in a JTA transaction
2011-03-13 08:35:53,031 TRACE [org.hibernate.search.batchindexing.IdentifierConsumerEntityProducer][Hibernate Search: entityloader-6][] started
2011-03-13 08:35:53,032 TRACE [org.hibernate.search.batchindexing.OptionallyWrapInJTATransaction][Hibernate Search: entityloader-8][] TransactionFactory does not require a TransactionManager: don't wrap in a JTA transaction
2011-03-13 08:35:53,034 TRACE [org.hibernate.search.batchindexing.IdentifierConsumerEntityProducer][Hibernate Search: entityloader-8][] started
2011-03-13 08:35:53,034 TRACE [org.hibernate.search.batchindexing.OptionallyWrapInJTATransaction][Hibernate Search: entityloader-3][] TransactionFactory does not require a TransactionManager: don't wrap in a JTA transaction
2011-03-13 08:35:53,037 TRACE [org.hibernate.search.batchindexing.IdentifierConsumerEntityProducer][Hibernate Search: entityloader-3][] started
2011-03-13 08:35:53,033 TRACE [org.hibernate.search.batchindexing.OptionallyWrapInJTATransaction][Hibernate Search: entityloader-5][] TransactionFactory does not require a TransactionManager: don't wrap in a JTA transaction
2011-03-13 08:35:53,033 TRACE [org.hibernate.search.batchindexing.OptionallyWrapInJTATransaction][Hibernate Search: entityloader-4][] TransactionFactory does not require a TransactionManager: don't wrap in a JTA transaction
2011-03-13 08:35:53,038 TRACE [org.hibernate.search.batchindexing.IdentifierConsumerEntityProducer][Hibernate Search: entityloader-4][] started
2011-03-13 08:35:53,033 TRACE [org.hibernate.search.batchindexing.OptionallyWrapInJTATransaction][Hibernate Search: entityloader-7][] TransactionFactory does not require a TransactionManager: don't wrap in a JTA transaction
2011-03-13 08:35:53,038 TRACE [org.hibernate.search.batchindexing.IdentifierConsumerEntityProducer][Hibernate Search: entityloader-7][] started
2011-03-13 08:35:53,033 TRACE [org.hibernate.search.batchindexing.OptionallyWrapInJTATransaction][Hibernate Search: identifierloader-1][] TransactionFactory does not require a TransactionManager: don't wrap in a JTA transaction
2011-03-13 08:35:53,038 TRACE [org.hibernate.search.batchindexing.IdentifierProducer][Hibernate Search: identifierloader-1][] started
2011-03-13 08:35:53,037 TRACE [org.hibernate.search.batchindexing.IdentifierConsumerEntityProducer][Hibernate Search: entityloader-5][] started

Found out the problem.

http://opensource.atlassian.com/projects/hibernate/browse/HSEARCH-598

pool size was too low (so i raised max active of basic data source to about 50 connections). This prevents it from hanging.