Details
-
Bug
-
Status: Closed
-
Major
-
Resolution: Fixed
-
2.0.0-RC3
-
None
Description
The code that triggered queued up commands and ran them in the background queue. What the stack trace shows is that we have encountered a hollow entity while the InteractionService attempts to commit the transaction (as it winds down the interaction stack to 0). The transition to hollow only happens on commit, so it means that there was another commit already.
I captured a stack traces to see where the entity was being transitioned to hollow:
"quartzScheduler_Worker-8@21526" prio=5 tid=0x9f nid=NA runnable java.lang.Thread.State: RUNNABLE at org.apache.isis.persistence.jdo.datanucleus.entities.DnOidStoreAndRecoverHelper.storeOid(DnOidStoreAndRecoverHelper.java:49) at org.apache.isis.persistence.jdo.datanucleus.entities.DnStateManagerForIsis.lambda$disconnect$0(DnStateManagerForIsis.java:129) at org.apache.isis.persistence.jdo.datanucleus.entities.DnStateManagerForIsis$$Lambda$3581.1775298992.accept(Unknown Source:-1) at java.util.Optional.ifPresent(Optional.java:183) at org.apache.isis.persistence.jdo.datanucleus.entities.DnStateManagerForIsis.disconnect(DnStateManagerForIsis.java:129) at org.datanucleus.state.LifeCycleState.changeState(LifeCycleState.java:117) at org.datanucleus.api.jdo.state.PersistentDeleted.transitionCommit(PersistentDeleted.java:66) at org.datanucleus.state.StateManagerImpl.postCommit(StateManagerImpl.java:1223) at org.datanucleus.ExecutionContextImpl.postCommit(ExecutionContextImpl.java:4385) at org.datanucleus.ExecutionContextImpl.transactionCommitted(ExecutionContextImpl.java:745) at org.datanucleus.transaction.TransactionImpl.internalPostCommit(TransactionImpl.java:574) at org.datanucleus.transaction.TransactionImpl.commit(TransactionImpl.java:355) at org.datanucleus.api.jdo.JDOTransaction.commit(JDOTransaction.java:94) at org.apache.isis.persistence.jdo.spring.integration.JdoTransactionManager.doCommit(JdoTransactionManager.java:443) at org.springframework.transaction.support.AbstractPlatformTransactionManager.processCommit(AbstractPlatformTransactionManager.java:743) at org.springframework.transaction.support.AbstractPlatformTransactionManager.commit(AbstractPlatformTransactionManager.java:711) at org.apache.isis.core.runtimeservices.transaction.TransactionServiceSpring.callTransactional(TransactionServiceSpring.java:115) at org.apache.isis.applib.services.xactn.TransactionalProcessor.callTransactional(TransactionalProcessor.java:71) at org.apache.isis.applib.services.xactn.TransactionalProcessor.runTransactional(TransactionalProcessor.java:82) at org.apache.isis.extensions.commandlog.applib.job.RunBackgroundCommandsJob.lambda$execute$4(RunBackgroundCommandsJob.java:107) at org.apache.isis.extensions.commandlog.applib.job.RunBackgroundCommandsJob$$Lambda$4549.469978661.run(Unknown Source:-1) at org.apache.isis.commons.functional.ThrowingRunnable.lambda$toCallable$0(ThrowingRunnable.java:41) at org.apache.isis.commons.functional.ThrowingRunnable$$Lambda$3543.1911045472.call(Unknown Source:-1) at org.apache.isis.core.runtimeservices.session.InteractionServiceDefault.callInternal(InteractionServiceDefault.java:328) at org.apache.isis.core.runtimeservices.session.InteractionServiceDefault.call(InteractionServiceDefault.java:269) at org.apache.isis.applib.services.iactnlayer.InteractionService.lambda$callAndCatch$0(InteractionService.java:152) at org.apache.isis.applib.services.iactnlayer.InteractionService$$Lambda$3241.4502127.call(Unknown Source:-1) at org.apache.isis.commons.functional.Try.call(Try.java:58) at org.apache.isis.applib.services.iactnlayer.InteractionService.callAndCatch(InteractionService.java:152) at org.apache.isis.applib.services.iactnlayer.InteractionService.runAndCatch(InteractionService.java:163) at org.apache.isis.extensions.commandlog.applib.job.RunBackgroundCommandsJob.lambda$execute$9(RunBackgroundCommandsJob.java:106) at org.apache.isis.extensions.commandlog.applib.job.RunBackgroundCommandsJob$$Lambda$3396.1208611345.accept(Unknown Source:-1) at java.util.Optional.ifPresent(Optional.java:183) at org.apache.isis.extensions.commandlog.applib.job.RunBackgroundCommandsJob.execute(RunBackgroundCommandsJob.java:104) at org.quartz.core.JobRunShell.run(JobRunShell.java:202) at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:573) - locked <0xa335> (a java.lang.Object)
and I compared to the original stacktrace yielding the error:
java.lang.NullPointerException: target is marked non-null but is null at org.apache.isis.commons.internal.reflection._Reflect.invokeMethodOn(_Reflect.java:571) ~[isis-commons-2.0.0-SNAPSHOT.jar:2.0.0-SNAPSHOT] at org.apache.isis.core.metamodel.commons.CanonicalInvoker.invoke(CanonicalInvoker.java:76) ~[isis-core-metamodel-2.0.0-SNAPSHOT.jar:2.0.0-SNAPSHOT] at org.apache.isis.core.metamodel.object.MmInvokeUtils.invokeNoArg(MmInvokeUtils.java:108) ~[isis-core-metamodel-2.0.0-SNAPSHOT.jar:2.0.0-SNAPSHOT] at org.apache.isis.core.metamodel.facets.properties.accessor.PropertyAccessorFacetViaAccessor.getProperty(PropertyAccessorFacetViaAccessor.java:65) ~[isis-core-metamodel-2.0.0-SNAPSHOT.jar:2.0.0-SNAPSHOT] at org.apache.isis.core.metamodel.specloader.specimpl.OneToOneAssociationDefault.get(OneToOneAssociationDefault.java:155) ~[isis-core-metamodel-2.0.0-SNAPSHOT.jar:2.0.0-SNAPSHOT] at org.apache.isis.core.metamodel.services.objectlifecycle.PropertyChangeRecord.getPropertyValue(PropertyChangeRecord.java:138) ~[isis-core-metamodel-2.0.0-SNAPSHOT.jar:2.0.0-SNAPSHOT] at org.apache.isis.core.metamodel.services.objectlifecycle.PropertyChangeRecord.withPostValueSetToCurrent(PropertyChangeRecord.java:95) ~[isis-core-metamodel-2.0.0-SNAPSHOT.jar:2.0.0-SNAPSHOT] at org.apache.isis.persistence.commons.integration.changetracking.EntityChangeTrackerDefault.lambda$capturePostValuesAndDrain$0(EntityChangeTrackerDefault.java:164) ~[isis-persistence-commons-2.0.0-SNAPSHOT.jar:2.0.0-SNAPSHOT] at java.util.stream.ReferencePipeline$11$1.accept(ReferencePipeline.java:441) ~[?:?] at java.util.Iterator.forEachRemaining(Iterator.java:133) ~[?:?] at java.util.Spliterators$IteratorSpliterator.forEachRemaining(Spliterators.java:1801) ~[?:?] at java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:484) ~[?:?] at java.util.stream.AbstractPipeline.wrapAndCopyInto(AbstractPipeline.java:474) ~[?:?] at java.util.stream.ReduceOps$ReduceOp.evaluateSequential(ReduceOps.java:913) ~[?:?] at java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:234) ~[?:?] at java.util.stream.ReferencePipeline.collect(ReferencePipeline.java:578) ~[?:?] at org.apache.isis.persistence.commons.integration.changetracking.EntityChangeTrackerDefault.capturePostValuesAndDrain(EntityChangeTrackerDefault.java:168) ~[isis-persistence-commons-2.0.0-SNAPSHOT.jar:2.0.0-SNAPSHOT] at org.apache.isis.commons.functional.ThrowingSupplier.get(ThrowingSupplier.java:61) ~[isis-commons-2.0.0-SNAPSHOT.jar:2.0.0-SNAPSHOT] at org.apache.isis.commons.functional.ThrowingSupplier.get(ThrowingSupplier.java:49) ~[isis-commons-2.0.0-SNAPSHOT.jar:2.0.0-SNAPSHOT] at org.apache.isis.commons.internal.base._Lazy_ThreadSafe.get(_Lazy_ThreadSafe.java:66) ~[isis-commons-2.0.0-SNAPSHOT.jar:2.0.0-SNAPSHOT] at org.apache.isis.persistence.commons.integration.changetracking.EntityChangeTrackerDefault.snapshotPropertyChangeRecords(EntityChangeTrackerDefault.java:149) ~[isis-persistence-commons-2.0.0-SNAPSHOT.jar:2.0.0-SNAPSHOT] at org.apache.isis.persistence.commons.integration.changetracking.EntityChangeTrackerDefault.getPropertyChanges(EntityChangeTrackerDefault.java:294) ~[isis-persistence-commons-2.0.0-SNAPSHOT.jar:2.0.0-SNAPSHOT] at org.apache.isis.core.runtimeservices.publish.EntityPropertyChangePublisherDefault.publishChangedProperties(EntityPropertyChangePublisherDefault.java:95) ~[isis-core-runtimeservices-2.0.0-SNAPSHOT.jar:2.0.0-SNAPSHOT] at org.apache.isis.persistence.commons.integration.changetracking.EntityChangeTrackerDefault.doPublish(EntityChangeTrackerDefault.java:260) ~[isis-persistence-commons-2.0.0-SNAPSHOT.jar:2.0.0-SNAPSHOT] at org.apache.isis.persistence.commons.integration.changetracking.EntityChangeTrackerDefault.onTransactionCompleting(EntityChangeTrackerDefault.java:250) ~[isis-persistence-commons-2.0.0-SNAPSHOT.jar:2.0.0-SNAPSHOT] at org.apache.isis.persistence.commons.integration.changetracking.EntityChangeTrackerDefault$TransactionSubscriber.onTransactionCompleting(EntityChangeTrackerDefault.java:236) ~[isis-persistence-commons-2.0.0-SNAPSHOT.jar:2.0.0-SNAPSHOT] at jdk.internal.reflect.GeneratedMethodAccessor179.invoke(Unknown Source) ~[?:?] at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?] at java.lang.reflect.Method.invoke(Method.java:566) ~[?:?] at org.springframework.context.event.ApplicationListenerMethodAdapter.doInvoke(ApplicationListenerMethodAdapter.java:344) ~[spring-context-5.3.30.jar:5.3.30] at org.springframework.context.event.ApplicationListenerMethodAdapter.processEvent(ApplicationListenerMethodAdapter.java:229) ~[spring-context-5.3.30.jar:5.3.30] at org.springframework.context.event.ApplicationListenerMethodAdapter.onApplicationEvent(ApplicationListenerMethodAdapter.java:166) ~[spring-context-5.3.30.jar:5.3.30] at org.springframework.context.event.SimpleApplicationEventMulticaster.doInvokeListener(SimpleApplicationEventMulticaster.java:178) ~[spring-context-5.3.30.jar:5.3.30] at org.springframework.context.event.SimpleApplicationEventMulticaster.invokeListener(SimpleApplicationEventMulticaster.java:171) ~[spring-context-5.3.30.jar:5.3.30] at org.springframework.context.event.SimpleApplicationEventMulticaster.multicastEvent(SimpleApplicationEventMulticaster.java:145) ~[spring-context-5.3.30.jar:5.3.30] at org.springframework.context.support.AbstractApplicationContext.publishEvent(AbstractApplicationContext.java:421) ~[spring-context-5.3.30.jar:5.3.30] at org.springframework.context.support.AbstractApplicationContext.publishEvent(AbstractApplicationContext.java:391) ~[spring-context-5.3.30.jar:5.3.30] at org.apache.isis.core.runtimeservices.eventbus.EventBusServiceSpring.post(EventBusServiceSpring.java:43) ~[isis-core-runtimeservices-2.0.0-SNAPSHOT.jar:2.0.0-SNAPSHOT] at org.apache.isis.core.runtime.events.TransactionEventEmitter.beforeCompletion(TransactionEventEmitter.java:48) ~[isis-core-runtime-2.0.0-SNAPSHOT.jar:2.0.0-SNAPSHOT] at org.springframework.transaction.support.TransactionSynchronizationUtils.triggerBeforeCompletion(TransactionSynchronizationUtils.java:108) ~[spring-tx-5.3.30.jar:5.3.30] at org.springframework.transaction.support.AbstractPlatformTransactionManager.triggerBeforeCompletion(AbstractPlatformTransactionManager.java:926) ~[spring-tx-5.3.30.jar:5.3.30] at org.springframework.transaction.support.AbstractPlatformTransactionManager.processCommit(AbstractPlatformTransactionManager.java:728) ~[spring-tx-5.3.30.jar:5.3.30] at org.springframework.transaction.support.AbstractPlatformTransactionManager.commit(AbstractPlatformTransactionManager.java:711) ~[spring-tx-5.3.30.jar:5.3.30] at org.apache.isis.core.interaction.integration.InteractionAwareTransactionalBoundaryHandler.lambda$newTransactionOrParticipateInExisting$1(InteractionAwareTransactionalBoundaryHandler.java:135) ~[isis-core-interaction-2.0.0-SNAPSHOT.jar:2.0.0-SNAPSHOT] at org.apache.isis.core.interaction.integration.InteractionAwareTransactionalBoundaryHandler$OnCloseHandle.lambda$runOnCloseTasks$1(InteractionAwareTransactionalBoundaryHandler.java:160) ~[isis-core-interaction-2.0.0-SNAPSHOT.jar:2.0.0-SNAPSHOT] at java.util.ArrayList.forEach(ArrayList.java:1541) ~[?:?] at org.apache.isis.core.interaction.integration.InteractionAwareTransactionalBoundaryHandler$OnCloseHandle.runOnCloseTasks(InteractionAwareTransactionalBoundaryHandler.java:157) ~[isis-core-interaction-2.0.0-SNAPSHOT.jar:2.0.0-SNAPSHOT] at java.util.Optional.ifPresent(Optional.java:183) ~[?:?] at org.apache.isis.core.interaction.integration.InteractionAwareTransactionalBoundaryHandler.onClose(InteractionAwareTransactionalBoundaryHandler.java:98) ~[isis-core-interaction-2.0.0-SNAPSHOT.jar:2.0.0-SNAPSHOT] at org.apache.isis.core.runtimeservices.session.InteractionServiceDefault.preInteractionClosed(InteractionServiceDefault.java:392) ~[isis-core-runtimeservices-2.0.0-SNAPSHOT.jar:2.0.0-SNAPSHOT] at org.apache.isis.core.runtimeservices.session.InteractionServiceDefault.closeInteractionLayerStackDownToStackSize(InteractionServiceDefault.java:418) ~[isis-core-runtimeservices-2.0.0-SNAPSHOT.jar:2.0.0-SNAPSHOT] at org.apache.isis.core.runtimeservices.session.InteractionServiceDefault.call(InteractionServiceDefault.java:271) ~[isis-core-runtimeservices-2.0.0-SNAPSHOT.jar:2.0.0-SNAPSHOT] at org.apache.isis.applib.services.iactnlayer.InteractionService.lambda$callAndCatch$0(InteractionService.java:152) ~[isis-applib-2.0.0-SNAPSHOT.jar:2.0.0-SNAPSHOT] at org.apache.isis.commons.functional.Try.call(Try.java:58) ~[isis-commons-2.0.0-SNAPSHOT.jar:2.0.0-SNAPSHOT] at org.apache.isis.applib.services.iactnlayer.InteractionService.callAndCatch(InteractionService.java:152) ~[isis-applib-2.0.0-SNAPSHOT.jar:2.0.0-SNAPSHOT] at org.apache.isis.applib.services.iactnlayer.InteractionService.runAndCatch(InteractionService.java:163) ~[isis-applib-2.0.0-SNAPSHOT.jar:2.0.0-SNAPSHOT] at org.apache.isis.extensions.commandlog.applib.job.RunBackgroundCommandsJob.lambda$execute$9(RunBackgroundCommandsJob.java:106) ~[isis-extensions-commandlog-applib-2.0.0-SNAPSHOT.jar:2.0.0-SNAPSHOT] at java.util.Optional.ifPresent(Optional.java:183) ~[?:?] at org.apache.isis.extensions.commandlog.applib.job.RunBackgroundCommandsJob.execute(RunBackgroundCommandsJob.java:104) ~[isis-extensions-commandlog-applib-2.0.0-SNAPSHOT.jar:2.0.0-SNAPSHOT] at org.quartz.core.JobRunShell.run(JobRunShell.java:202) ~[quartz-2.3.2.jar:?] at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:573) ~[quartz-2.3.2.jar:?]
The former comes from TransactionService committing, the latter from InteractionService also committing, but on entities already hollow.
Looking at RunBackgroundCommandsJob, we see that the InteractionService calls TransactionService within:
So the fix is I think is simply not to bother with call to transactionService ... each call to interactionService is already going to be in a separate transaction, I think.