MassIndexer Locking

Manoj D · **Joined:** Tue Sep 28, 2010 5:14 am **Posts:** 25

Hi,

I am using hibernate search and when trying to do indexing on 360 records with massindexer, I find batch been terminated in between leaving indexes in inconsistent state. The same code was working when there were around 55 records for indexing. Basically, index files are created but are not committed.

Also, while indexing I see this error pretty often.
[quote]Terminating batch work! Index might end up in inconsistent state.
Terminating batch work! Index might end up in inconsistent state.
INFO | jvm 1 | 2011/04/13 10:32:14 | [GC 15057K->13191K(32576K), 0.0011870 secs]
INFO | jvm 1 | 2011/04/13 10:32:14 | InterruptedException in com.dao.IndexerDAO:indexRecord() >>
INFO | jvm 1 | 2011/04/13 10:32:14 | org.hibernate.search.SearchException: Unable to open IndexWriter
INFO | jvm 1 | 2011/04/13 10:32:14 | at org.hibernate.search.backend.Workspace.getIndexWriter(Workspace.java:159)
INFO | jvm 1 | 2011/04/13 10:32:14 | at org.hibernate.search.backend.impl.batchlucene.DirectoryProviderWorkspace.doWorkInSync(DirectoryProviderWorkspace.java:95)
INFO | jvm 1 | 2011/04/13 10:32:14 | at org.hibernate.search.backend.impl.batchlucene.LuceneBatchBackend$SyncBatchPerDirectoryWorkProcessor.addWorkToDpProcessor(LuceneBatchBackend.java:139)
INFO | jvm 1 | 2011/04/13 10:32:14 | at org.hibernate.search.backend.impl.lucene.DpSelectionVisitor$PurgeAllSelectionDelegate.addAsPayLoadsToQueue(DpSelectionVisitor.java:120)
INFO | jvm 1 | 2011/04/13 10:32:14 | at org.hibernate.search.backend.impl.batchlucene.LuceneBatchBackend.sendWorkToShards(LuceneBatchBackend.java:119)
INFO | jvm 1 | 2011/04/13 10:32:14 | at org.hibernate.search.backend.impl.batchlucene.LuceneBatchBackend.doWorkInSync(LuceneBatchBackend.java:80)
INFO | jvm 1 | 2011/04/13 10:32:14 | at org.hibernate.search.batchindexing.BatchCoordinator.beforeBatch(BatchCoordinator.java:145)
INFO | jvm 1 | 2011/04/13 10:32:14 | at org.hibernate.search.batchindexing.BatchCoordinator.run(BatchCoordinator.java:94)
INFO | jvm 1 | 2011/04/13 10:32:14 | at org.hibernate.search.impl.MassIndexerImpl.startAndWait(MassIndexerImpl.java:182)
INFO | jvm 1 | 2011/04/13 10:32:14 | at com.dao.IndexerDAO.indexRecord(IndexerDAO.java:39)
INFO | jvm 1 | 2011/04/13 10:32:14 | at com..service.impl.IndexerServiceImpl.indexRecord(IndexerServiceImpl.java:16)
INFO | jvm 1 | 2011/04/13 10:32:14 | at com.esearch.tpSearchForm.IndexerForm.onSubmit(IndexerForm.java:32)
INFO | jvm 1 | 2011/04/13 10:32:14 | at org.springframework.web.servlet.mvc.SimpleFormController.processFormSubmission(SimpleFormController.java:267)
INFO | jvm 1 | 2011/04/13 10:32:14 | at org.springframework.web.servlet.mvc.AbstractFormController.handleInvalidSubmit(AbstractFormController.java:671)
INFO | jvm 1 | 2011/04/13 10:32:14 | at org.springframework.web.servlet.mvc.AbstractFormController.handleRequestInternal(AbstractFormController.java:272)
INFO | jvm 1 | 2011/04/13 10:32:14 | at org.springframework.web.servlet.mvc.AbstractController.handleRequest(AbstractController.java:153)
INFO | jvm 1 | 2011/04/13 10:32:14 | at org.springframework.web.servlet.mvc.SimpleControllerHandlerAdapter.handle(SimpleControllerHandlerAdapter.java:48)
INFO | jvm 1 | 2011/04/13 10:32:14 | at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:875)
INFO | jvm 1 | 2011/04/13 10:32:14 | at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:809)
INFO | jvm 1 | 2011/04/13 10:32:14 | at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:523)

Could you please pin point where I am going wrong. I have been struggling with this but couldnt find a solution. Reading through forum, I found that the poolsize, connection size might be a issue so I incresed them to 50 but still no luck.

Code:

log.info(CLASS_NAME+":indexRecord()>> START");
      FullTextSession ftSession = SessionUtil.getFullTextSessionInstance();
      
      ftSession.getTransaction().begin();
      try {
         
         ftSession.createIndexer(Employee.class)
         .batchSizeToLoadObjects(50)
         .cacheMode(CacheMode.NORMAL)
         .threadsForSubsequentFetching(1)
         .threadsToLoadObjects(5)
         .startAndWait();
         
         
         log.info(CLASS_NAME+":indexRecord()>>  Committing indexes ");
         ftSession.getTransaction().commit();  
         log.info(CLASS_NAME+":indexRecord()>>  Indexes committed. ");
         
      } catch (Exception e) {
         log.error("InterruptedException in "+CLASS_NAME+":indexRecord() >>", e);
      } finally{
         ftSession.clear();
      }

Hibernate.configuration

Code:

<session-factory>

         <property name="hibernate.connection.driver_class">oracle.jdbc.driver.OracleDriver</property>
         
         <property name="hibernate.connection.url">@@dbconnurl@@</property>
         <property name="hibernate.connection.username">@@dbusername@@</property>
         <property name="hibernate.connection.password">@@dbpassword@@</property>
         <property name="hibernate.connection.pool_size">50</property>
         <property name="hibernate.connection.provider_class">org.hibernate.connection.C3P0ConnectionProvider</property>
         <property name="hibernate.c3p0.acquire_increment">1</property> 
         <property name="hibernate.c3p0.idle_test_period">100</property>
         <property name="hibernate.c3p0.max_size">50</property> 
         <property name="hibernate.c3p0.max_statements">5</property>
         <property name="hibernate.c3p0.min_size">5</property> 
         <property name="hibernate.c3p0.timeout">1800</property> 

         <!-- Enable Hibernate's automatic session context management --> 
          <!-- property name="current_session_context_class">thread</property -->        
          <!-- Disable the second-level cache  -->        
          <!-- property name="cache.provider_class">org.hibernate.cache.NoCacheProvider</property -->
         <property name="show_sql">true</property>
         <property name="dialect">org.hibernate.dialect.Oracle10gDialect</property>
         <property name="hibernate.hbm2ddl.auto">update</property>
         
            

         <!-- Hibernate search configuration  -->
         <property name="hibernate.search.default.directory_provider">org.hibernate.search.store.FSDirectoryProvider</property>
         <property name="hibernate.search.default.indexName">TPS_Index</property>
         <property name="hibernate.search.default.indexBase">@@indexBase@@</property>
         <!-- property name="hibernate.search.default.locking_strategy">none</property -->
         <property name="hibernate.search.default.batch.merge_factor">10</property>
         <property name="hibernate.search.default.batch.max_buffered_docs">10</property>

          <!-- Mapping files -->
         <mapping resource="employee.hbm.xml"/>
         <mapping resource="emp_languages.hbm.xml"/>
         <mapping resource="emp_education.hbm.xml"/>
         <mapping resource="emp_bus_skills.hbm.xml"/>
         <mapping resource="emp_prev_emp.hbm.xml"/>
         <mapping resource="emp_work_pref.hbm.xml"/>
         <mapping resource="emp_tech_skills.hbm.xml"/>
         <mapping resource="emp_mobility_pref.hbm.xml"/>
         <mapping resource="emp_role_pref.hbm.xml"/>
         <mapping resource="emp_visa.hbm.xml"/>
         <mapping resource="emp_priwork.hbm.xml"/>
         <mapping resource="emp_prev_job_details.hbm.xml"/>
         <mapping resource="user.hbm.xml"/>
         <mapping resource="role_protected_fields.hbm.xml"/>
         <mapping resource="roles.hbm.xml"/>
         <mapping resource="lookup_data.hbm.xml"/>
         <mapping resource="user_audit_log.hbm.xml"/>
         
   </session-factory>

sanne.grinovero · **Posted:** Wed Apr 13, 2011 9:13 am

hi,
which version of Search is this?
and could you check that
1) there are no normal indexing operations going on at the same time
2) the index is not still locked by a previously failed run, or another instance running.

Usually if it's unable to open the IndexWriter it's because it's locked (and that doesn't necessarily you have to force unlock it, some other thread might be using it)

Manoj D · **Joined:** Tue Sep 28, 2010 5:14 am **Posts:** 25

Hi Sanne,

I am using following jar

1. Hibernate search 3.2.0.Final
2. hibernate-core-3.5.1-Final
3. hibernate-commons-annotations-3.2.0.Final
4. hibernate-c3p0-3.3.2.GA

1) there are no normal indexing operations going on at the same time Since I am running only one batch job, there isnt any other indexing.

2) the index is not still locked by a previously failed run, or another instance running.
I ensured that all locked indexes created in previous run are deleted before I run the next batch.

However, when I change the massindexer's thread and batch parameter for 360 records, it worked fine. Here is that code

Code:

ftSession.createIndexer(TP_Employee.class)
         .batchSizeToLoadObjects(5)
         .cacheMode(CacheMode.NORMAL)
         .threadsForSubsequentFetching(1)
         .threadsToLoadObjects(1)
         .startAndWait();

However this will be of no use when I get around 40K - 60K records.

Is there any relationship between the threads fo root entity, child entity and batch load ?

sanne.grinovero · **Posted:** Wed Apr 13, 2011 6:56 pm

Hi,
I'm puzzled by this error, nobody reported anything similar.
I see you're starting a transaction, but I didn't see a transaction manager in the configuration; what are you using? Is it possible the transaction times out?
As it seems to be started by a form submission, it might make sense for Spring to have set some timeout for the request being processed and killing the thread.

Quote:

org.hibernate.search.backend.Workspace.getIndexWriter(Workspace.java:159)

This is Lucene related, an IOException is being thrown we need to understand why. That's why I was suspecting a locking timeout, as alternatives I can think of disk/filesystem corruption but seem unlikely.
Would you be able to set a breakpoint at that point and figure out what's happening? Alternatively I'd need you to forge a test to reproduce this and send it to us.

Also if you can try with hibernate-core 3.6.3, hibernate-search 3.4.0.CR2, Lucene 3.1.0 (latest) the error-messages might be more helpful.

Manoj D · **Joined:** Tue Sep 28, 2010 5:14 am **Posts:** 25

Hi,

Unfortuantely, this happening in production env so I can't debug that. When I run this on local build with same configuration I works fine. However, I will try to simulate this with some test case and try with latest core and search jars.

--Manoj

sanne.grinovero · **Posted:** Thu Apr 14, 2011 1:15 pm

thank you a testcase would help to understand this.
So it's failing in production only? Did it ever work in production, did you try the 360 records in the same environment and same machines?