Possible "corrupted" Lucene index after stale reader exception.

[jamoore]

The following exception was thrown during a run of the JobHandleTest. We need to guarantee that when such an exception is thrown, that the related Event is re-indexed to prevent a stale index (e.g. a still present entry which has already been deleted.)

25547      [r_Worker-2] ERROR  rg.hibernate.transaction.JDBCTransaction  - exception calling user Synchronization
org.hibernate.search.SearchException: Unable to remove from Lucene index: class ome.model.meta.GroupExperimenterMap#250
	at org.hibernate.search.backend.impl.lucene.LuceneWorker.remove(LuceneWorker.java:109)
	at org.hibernate.search.backend.impl.lucene.LuceneWorker.performWork(LuceneWorker.java:80)
	at org.hibernate.search.backend.impl.lucene.LuceneWorker.performWork(LuceneWorker.java:46)
	at org.hibernate.search.backend.impl.lucene.LuceneBackendQueueProcessor.run(LuceneBackendQueueProcessor.java:98)
	at org.hibernate.search.backend.impl.BatchedQueueingProcessor.performWorks(BatchedQueueingProcessor.java:132)
	at org.hibernate.search.backend.impl.PostTransactionWorkQueueSynchronization.afterCompletion(PostTransactionWorkQueueSynchronization.java:50)
	at org.hibernate.transaction.JDBCTransaction.notifyLocalSynchsAfterTransactionCompletion(JDBCTransaction.java:243)
	at org.hibernate.transaction.JDBCTransaction.commit(JDBCTransaction.java:121)
	at ome.services.fulltext.FullTextIndexer.doWork(FullTextIndexer.java:99)
	at ome.services.util.Executor$Interceptor$1$1.doInHibernate(Executor.java:241)
	at org.springframework.orm.hibernate3.HibernateTemplate.execute(HibernateTemplate.java:373)
	at ome.services.util.Executor$Interceptor$1.doInTransaction(Executor.java:238)
	at org.springframework.transaction.support.TransactionTemplate.execute(TransactionTemplate.java:128)
	at ome.services.util.Executor$Interceptor.invoke(Executor.java:236)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:171)
	at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
	at $Proxy58.doWork(Unknown Source)
	at sun.reflect.GeneratedMethodAccessor166.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
	at java.lang.reflect.Method.invoke(Method.java:585)
	at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:301)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:182)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:149)
	at ome.security.basic.EventHandler.invoke(EventHandler.java:112)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:171)
	at org.springframework.orm.hibernate3.HibernateInterceptor.invoke(HibernateInterceptor.java:111)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:171)
	at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:106)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:171)
	at ome.tools.hibernate.ProxyCleanupFilter$Interceptor.invoke(ProxyCleanupFilter.java:169)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:171)
	at ome.services.util.ServiceHandler.invoke(ServiceHandler.java:92)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:171)
	at org.springframework.aop.interceptor.JamonPerformanceMonitorInterceptor.invokeUnderTrace(JamonPerformanceMonitorInterceptor.java:105)
	at org.springframework.aop.interceptor.AbstractTraceInterceptor.invoke(AbstractTraceInterceptor.java:110)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:171)
	at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
	at $Proxy58.doWork(Unknown Source)
	at ome.services.util.Executor.execute(Executor.java:169)
	at ome.services.fulltext.FullTextThread.doRun(FullTextThread.java:124)
	at ome.services.util.ExecutionThread.run(ExecutionThread.java:58)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
	at java.lang.reflect.Method.invoke(Method.java:585)
	at org.springframework.util.MethodInvoker.invoke(MethodInvoker.java:283)
	at org.springframework.scheduling.quartz.MethodInvokingJobDetailFactoryBean$MethodInvokingJob.executeInternal(MethodInvokingJobDetailFactoryBean.java:272)
	at org.springframework.scheduling.quartz.QuartzJobBean.execute(QuartzJobBean.java:86)
	at org.quartz.core.JobRunShell.run(JobRunShell.java:203)
	at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:520)
Caused by: org.apache.lucene.index.StaleReaderException: IndexReader out of date and no longer valid for delete, undelete, or setNorm operations
	at org.apache.lucene.index.IndexReader.acquireWriteLock(IndexReader.java:648)
	at org.apache.lucene.index.IndexReader.deleteDocument(IndexReader.java:672)
	at org.hibernate.search.backend.impl.lucene.LuceneWorker.remove(LuceneWorker.java:104)
	... 49 more

[jmoore]

This is being thrown at "transaction.commit()":

   public Object doWork(TransactionStatus status, Session session,
            ServiceFactory sf) {
        FullTextSession fullTextSession = Search.createFullTextSession(session);
        fullTextSession.setFlushMode(FlushMode.MANUAL);
        fullTextSession.setCacheMode(CacheMode.IGNORE);
        Transaction transaction = fullTextSession.beginTransaction();
        doIndexing(fullTextSession);
        transaction.commit();
        session.clear();
        return null;
    }

which is after doIndexing() which sets the new next-event to search. If the value set by doIndexing() is not also being rolled back when transaction.commit() throws the exception, then we are losing data.

I'll try to test this. If we are losing data, then I'll pull the exception checking up to the doWork() method.

[jmoore]

I'm fairly sure that this is happening within the transaction boundaries and so the configuration table won't get updated. Doesn't mean that this isn't an issue, just that data's not being lost. Downgrading and pushing.

Should also look at the other asynchronous issues with Lucene while doing this.

[jmoore]

With the move of the indexer to its own process (#1059) and the various transaction fixes this should now be safe. Closing for now.