[hibernate-issues] [Hibernate-JIRA] Resolved: (HSEARCH-399) NPE in org.hibernate.search.backend.WorkQueue.clear()

NPE in org.hibernate.search.backend.WorkQueue.clear() ----------------------------------------------------- Key: HSEARCH-399 URL: http://opensource.atlassian.com/projects/hibernate/browse/HSEARCH-399 Project: Hibernate Search Issue Type: Bug Affects Versions: 3.1.1.GA Reporter: Dobes Vandermeer Assignee: Emmanuel Bernard Fix For: 3.2.0.CR1 Our server blew up, and we're seeing a continuous stream of: [#|2009-09-17T06:24:02.169-0700|SEVERE|sun-appserver9.1|books.db.search.SafeBatchedQueueingProcessor|_ThreadID=40;_Threa dName=httpSSLWorkerThread-8080-19;_RequestID=97e3df6c-2fc7-4f54-a47a-e77ba48d1a07;|RuntimeException during cancelWorks() java.lang.NullPointerException at org.hibernate.search.backend.WorkQueue.clear(WorkQueue.java:58) at org.hibernate.search.backend.impl.BatchedQueueingProcessor.cancelWorks(BatchedQueueingProcessor.java:180) at org.hibernate.search.backend.impl.PostTransactionWorkQueueSynchronization.afterCompletion(PostTransactionWorkQueueSynchronization.java:56) at com.sun.enterprise.distributedtx.J2EETransaction.commit(J2EETransaction.java:491) The method body for this is: public void clear() { queue.clear(); // <---- queue is null if (sealedQueue != null) sealedQueue.clear(); } It appears that queue may be set null by the setSealedQueue method above: public void setSealedQueue(List<LuceneWork> sealedQueue) { //invalidate the working queue for serializability queue = null; this.sealedQueue = sealedQueue; } The only change I've made recently that I thought could cause this was to change the search system to run in a separate thread. My hibernate search options are: <exclude-unlisted-classes>true</exclude-unlisted-classes> <properties> <property name="hibernate.dialect" value="org.hibernate.dialect.PostgreSQLDialect"/> <property name="hibernate.show_sql" value="false"/> <property name="hibernate.cache.provider_class" value="net.sf.ehcache.hibernate.EhCacheProvider"/> <property name="hibernate.cache.use_query_cache" value="true"/> <property name="hibernate.cache.use_second_level_cache" value="true"/> <property name="hibernate.bytecode.provider" value="javassist"/> <property name="hibernate.search.default.directory_provider" value="org.hibernate.search.store.FSDirectoryProvider"/> <property name="hibernate.search.default.indexBase" value="../search-indexes"/> <property name="hibernate.search.worker.scope" value="books.db.search.SafeWorkerImpl"/> <property name="hibernate.search.worker.backend" value="books.db.search.SafeBackendQueueProcessorFactory"/> <property name="hibernate.search.worker.execution" value="async"/> <!-- sync or async --> <property name="hibernate.search.worker.buffer_queue.max" value="5"/> <property name="hibernate.search.worker.thread_pool.size" value="5"/> </properties> Note that books.db.search.Safe* are classes I wrote that wrap the default implementation with an exception handler; sometimes RuntimeExceptions were thrown and glassfish would just silently eat them and fail, now they are noisily eaten and the transaction commits anyway. This was probably (to some degree) triggered by the exception logged just prior: [#|2009-09-17T06:23:56.498-0700|SEVERE|sun-appserver9.1|org.hibernate.event.def.AbstractFlushingEventListener|_ThreadID=40;_ThreadName=httpSSLWorkerThread-8080-19;_RequestID=97e3df6c-2fc7-4f54-a47a-e77ba48d1a07;|Could not synchronize database state with session org.hibernate.StaleObjectStateException: Row was updated or deleted by another transaction (or unsaved-value mapping was incorrect): [books.db.Business#5617057] at org.hibernate.persister.entity.AbstractEntityPersister.check(AbstractEntityPersister.java:1782) at org.hibernate.persister.entity.AbstractEntityPersister.update(AbstractEntityPersister.java:2425) at org.hibernate.persister.entity.AbstractEntityPersister.updateOrInsert(AbstractEntityPersister.java:2325) at org.hibernate.persister.entity.AbstractEntityPersister.update(AbstractEntityPersister.java:2625) at org.hibernate.action.EntityUpdateAction.execute(EntityUpdateAction.java:115) at org.hibernate.engine.ActionQueue.execute(ActionQueue.java:279) at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:263) at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:168) at org.hibernate.event.def.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:321) at org.hibernate.event.def.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:50) at org.hibernate.impl.SessionImpl.flush(SessionImpl.java:1028) at org.hibernate.impl.SessionImpl.managedFlush(SessionImpl.java:366) at org.hibernate.ejb.AbstractEntityManagerImpl$1.beforeCompletion(AbstractEntityManagerImpl.java:504) at com.sun.enterprise.distributedtx.J2EETransaction.commit(J2EETransaction.java:419) Figuring out under which conditions the queue became null but shouldn't have been might be nearly impossible at this point, although I'll watch out for repeats of this issue. The NPE itself might be easier to fix, if you just check for null before calling clear(). For now I'll try implementing a workaround in my safe subclass like this: @Override public void cancelWorks(WorkQueue workQueue) { try { super.cancelWorks(workQueue); } catch (RuntimeException e) { logger.error("RuntimeException during cancelWorks()", e); try { if(workQueue.getQueue() != null) workQueue.getQueue().clear(); else workQueue.getSealedQueue().clear(); } catch(org.hibernate.annotations.common.AssertionFailure t) { // sealedQueue was null too } } }