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

[Dobes Vandermeer (JIRA)]

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


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
        	}
        }
    }




-- 
This message is automatically generated by JIRA.
-
If you think it was sent incorrectly contact one of the administrators: http://opensource.atlassian.com/projects/hibernate/secure/Administrators.jspa
-
For more information on JIRA, see: http://www.atlassian.com/software/jira