[hibernate-issues] [Hibernate-JIRA] Commented: (HSEARCH-841) after deleting an entity lucene index updating fails due to NullPointerException

Hardy Ferentschik (JIRA) noreply at atlassian.com
Wed Aug 10 08:57:02 EDT 2011


    [ http://opensource.atlassian.com/projects/hibernate/browse/HSEARCH-841?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=43211#comment-43211 ] 

Hardy Ferentschik commented on HSEARCH-841:
-------------------------------------------

I think your scenario is too simple (incomplete)
{code}
org.hibernate.Session s = ...;
s.get(ClassA.class, ida);
ClassB value = s.get(ClassB.class, idb);
s.delete(value);
{code}
I tried to create a test case based on these steps and it works fine -
https://github.com/hferentschik/hibernate-search/commit/28b0a5eeb5ec0b06a443c095a327d239b30a07c6

Obviously these are very simple entities. Maybe you can help to extend this test. How do your annotated
entities look like and what exactly happens within the transaction? Feel free to use my test setup
as a starting ground. 

> after deleting an entity lucene index updating fails due to NullPointerException
> --------------------------------------------------------------------------------
>
>                 Key: HSEARCH-841
>                 URL: http://opensource.atlassian.com/projects/hibernate/browse/HSEARCH-841
>             Project: Hibernate Search
>          Issue Type: Bug
>          Components: engine
>    Affects Versions: 3.4.0.Final
>         Environment: Hibernate 3.4.0 (on MySQL 5.1.54, but any database is affected AFAIK)
>            Reporter: Bogdan Butnaru
>            Priority: Critical
>             Fix For: 3.4.1, 4.0.0.Alpha1
>
>
> When entities are deleted, I noticed an exception with a rather large stack trace (below), which appears to be caused by the fact that Lucene is told to remove from the index a document with a null id.
> After (quite) a bit of digging, I believe the source is the top of this stack trace:
> {noformat}
> DocumentBuilderIndexedEntity<T>.getId(Object) line: 662	
> WorkPlan$PerClassWork<T>.extractProperId(Work<T>) line: 233	
> WorkPlan$PerClassWork<T>.addWork(Work<T>) line: 205	
> WorkPlan.addWork(Work<T>) line: 79	
> WorkQueue.add(Work) line: 73	
> BatchedQueueingProcessor.add(Work, WorkQueue) line: 115	
> PostTransactionWorkQueueSynchronization.add(Work) line: 70	
> TransactionalWorker.performWork(Work<?>, TransactionContext) line: 81	
> FullTextIndexEventListener.processWork(T, Serializable, WorkType, AbstractEvent, boolean) line: 215	
> FullTextIndexEventListener.processCollectionEvent(AbstractCollectionEvent) line: 262	
> FullTextIndexEventListener.onPostRemoveCollection(PostCollectionRemoveEvent) line: 227	
> CollectionRemoveAction.postRemove() line: 146	
> CollectionRemoveAction.execute() line: 119	
> ActionQueue.execute(Executable) line: 273	
> ActionQueue.executeActions(List) line: 265	
> ActionQueue.executeActions() line: 186	
> EJB3FlushEventListener(AbstractFlushingEventListener).performExecutions(EventSource) line: 321	
> EJB3FlushEventListener(DefaultFlushEventListener).onFlush(FlushEvent) line: 51	
> SessionImpl.flush() line: 1216	
> SessionImpl.managedFlush() line: 383	
> JDBCTransaction.commit() line: 133
> TransactionImpl.commit() line: 76
> [only application-specific lines below here, omitted]
> {noformat}
> Specifically, _org.hibernate.search.engine.DocumentBuilderIndexedEntity.getId(Object)_ does:
> {code}
> Object unproxiedEntity = HibernateHelper.unproxy( entity );
> return (Serializable) ReflectionHelper.getMemberValue( unproxiedEntity, idGetter );
> {code}
> As far as I can tell, _unproxy(entity)_ will return an entity with a null id if called during postRemove; the returned result is null, although the debugger says that entity.id actually contains the correct (non-null, pre-deletion) value.
> _org.hibernate.search.engine.WorkPlan.PerClassWork.extractProperId(Work<T>)_, right below the top of the stack, does:
> {code}
> if ( entity == null || documentBuilder.requiresProvidedId() ||
> 	( work.isIdentifierWasRolledBack() && documentBuilder.isIdMatchingJpaId() )) {
> 		return work.getId();
> } else {
> 	return documentBuilder.getId( entity );
> }
> {code}
> This condition fails and goes into the "else" block, which is unfortunate, because work.getId() actually contains the correct value. 
> The error doesn't occur right away: org.hibernate.search.engine.WorkPlan.PerClassWork.addWork(Work<T>) (a bit below the top of the stack) calls "entityById.put( id, entityWork );", with id=null due to the above.
> A while later the following happens (the bottom two items are the same as the stack trace above):
> {noformat}
> DocumentBuilderIndexedEntity<T>.addWorkToQueue(Class<T>, T, Serializable, boolean, boolean, boolean, List<LuceneWork>) line: 355	
> WorkPlan$PerEntityWork<T>.enqueueLuceneWork(Class<T>, Serializable, AbstractDocumentBuilder<T>, List<LuceneWork>) line: 449	
> WorkPlan$PerClassWork<T>.enqueueLuceneWork(List<LuceneWork>) line: 250	
> WorkPlan.getPlannedLuceneWork() line: 150	
> WorkQueue.prepareWorkPlan() line: 134	
> BatchedQueueingProcessor.prepareWorks(WorkQueue) line: 124	
> PostTransactionWorkQueueSynchronization.beforeCompletion() line: 89	
> EventSourceTransactionContext$DelegateToSynchronizationOnBeforeTx.doBeforeTransactionCompletion(SessionImplementor) line: 172	
> ActionQueue$BeforeTransactionCompletionProcessQueue.beforeTransactionCompletion() line: 543	
> ActionQueue.beforeTransactionCompletion() line: 216	
> SessionImpl.beforeTransactionCompletion(Transaction) line: 571	
> JDBCContext.beforeTransactionCompletion(Transaction) line: 250	
> JDBCTransaction.commit() line: 138	
> TransactionImpl.commit() line: 76	
> {noformat}
> The entry at the top belongs to 
> {code}
> public void addWorkToQueue(Class<T> entityClass, T entity, Serializable id, boolean delete, boolean add, boolean batch, List<LuceneWork> queue) {
> 	String idInString = objectToString( idBridge, idKeywordName, id );
> 	if ( delete ) {
> 		queue.add( new DeleteLuceneWork( id, idInString, entityClass ) );
> 	}
> 	if ( add ) {
> 		queue.add( createAddWork( entityClass, entity, id, idInString, HibernateStatelessInitializer.INSTANCE, batch ) );
> 	}
> }
> {code}
> The argument delete is true and id is null (it's the value of _WorkPlan$PerClassWork<T>.enqueueLuceneWork(List<LuceneWork>_) gets it from the documentBuilder.getId(entity) call mentioned above). A little while later the actual exception is triggered:
> {noformat}
> java.lang.NullPointerException
> 	at org.apache.lucene.index.Term.compareTo(Term.java:115)
> 	at org.apache.lucene.index.TermInfosReader.getIndexOffset(TermInfosReader.java:189)
> 	at org.apache.lucene.index.TermInfosReader.get(TermInfosReader.java:268)
> 	at org.apache.lucene.index.TermInfosReader.get(TermInfosReader.java:208)
> 	at org.apache.lucene.index.SegmentTermDocs.seek(SegmentTermDocs.java:57)
> 	at org.apache.lucene.index.BufferedDeletes.applyDeletes(BufferedDeletes.java:312)
> 	at org.apache.lucene.index.BufferedDeletes.applyDeletes(BufferedDeletes.java:289)
> 	at org.apache.lucene.index.BufferedDeletes.applyDeletes(BufferedDeletes.java:191)
> 	at org.apache.lucene.index.IndexWriter.doFlush(IndexWriter.java:3358)
> 	at org.apache.lucene.index.IndexWriter.flush(IndexWriter.java:3296)
> 	at org.apache.lucene.index.IndexWriter.closeInternal(IndexWriter.java:1836)
> 	at org.apache.lucene.index.IndexWriter.close(IndexWriter.java:1800)
> 	at org.apache.lucene.index.IndexWriter.close(IndexWriter.java:1764)
> 	at org.hibernate.search.backend.Workspace.closeIndexWriter(Workspace.java:244)
> 	at org.hibernate.search.backend.impl.lucene.PerDPQueueProcessor.run(PerDPQueueProcessor.java:113)
> 	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441)
> 	at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
> 	at java.util.concurrent.FutureTask.run(FutureTask.java:138)
> 	at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
> 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
> 	at java.lang.Thread.run(Thread.java:662)
> ERROR o.h.s.e.i.LogErrorHandler - Exception occurred java.lang.NullPointerException
> Primary Failure:
> 	Entity com.dragg.server.model.Walk  Id null  Work Type  org.hibernate.search.backend.DeleteLuceneWork
> Subsequent failures:
> 	Entity com.dragg.server.model.Walk  Id null  Work Type  org.hibernate.search.backend.AddLuceneWork
> 	Entity com.dragg.server.model.Walk  Id 5552  Work Type  org.hibernate.search.backend.DeleteLuceneWork
> java.lang.NullPointerException
> 	at org.apache.lucene.index.Term.compareTo(Term.java:115)
> 	at org.apache.lucene.index.TermInfosReader.getIndexOffset(TermInfosReader.java:189)
> 	at org.apache.lucene.index.TermInfosReader.get(TermInfosReader.java:268)
> 	at org.apache.lucene.index.TermInfosReader.get(TermInfosReader.java:208)
> 	at org.apache.lucene.index.SegmentTermDocs.seek(SegmentTermDocs.java:57)
> 	at org.apache.lucene.index.BufferedDeletes.applyDeletes(BufferedDeletes.java:312)
> 	at org.apache.lucene.index.BufferedDeletes.applyDeletes(BufferedDeletes.java:289)
> 	at org.apache.lucene.index.BufferedDeletes.applyDeletes(BufferedDeletes.java:191)
> 	at org.apache.lucene.index.IndexWriter.doFlush(IndexWriter.java:3358)
> 	at org.apache.lucene.index.IndexWriter.flush(IndexWriter.java:3296)
> 	at org.apache.lucene.index.IndexWriter.closeInternal(IndexWriter.java:1836)
> 	at org.apache.lucene.index.IndexWriter.close(IndexWriter.java:1800)
> 	at org.apache.lucene.index.IndexWriter.close(IndexWriter.java:1764)
> 	at org.hibernate.search.backend.Workspace.closeIndexWriter(Workspace.java:244)
> 	at org.hibernate.search.backend.impl.lucene.PerDPQueueProcessor.run(PerDPQueueProcessor.java:113)
> 	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441)
> 	at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
> 	at java.util.concurrent.FutureTask.run(FutureTask.java:138)
> 	at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
> 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
> 	at java.lang.Thread.run(Thread.java:662)
> {noformat}
> _org.apache.lucene.index.Term.compareTo_ fails because this.id is null, having received its value a bit earlier from the null document id above. (Technically, I think this also a bug in lucene; surrounding code, for example Term.equals, does test for null, so either Term.compareTo should do it, or the Term should have been checked for null quite a while earlier. Anyway, the results would have been the same, except for easier debugging.)

--
This message is automatically generated by JIRA.
For more information on JIRA, see: http://www.atlassian.com/software/jira

        


More information about the hibernate-issues mailing list