[ 
https://issues.apache.org/jira/browse/CAUSEWAY-3654?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17795041#comment-17795041
 ] 

Daniel Keir Haywood commented on CAUSEWAY-3654:
-----------------------------------------------

So, confirmed that not calling the TransactionService fixes the issue.  

However, that code ought not to fail, and looking at where the responsibilities 
reside, seems that the InteractionService is responsible for interacting with 
the EntityPropertyChanges service whereas really that should be the 
TransactionService.  (The actual responsibilities reside in the intermediate 
InteractionAwareTransactionBoundaryHandler).

I believe that those responsibilities ought to move, which would allow the 
RunBackgroundCommandsJob code to work as written.  (The use of 
TransactionService is still redundant, so should be removed still, but it ought 
to be valid code).

 

> Audit Trail can result in NPE, causing xactn to rollback, in some 
> circumstances
> -------------------------------------------------------------------------------
>
>                 Key: CAUSEWAY-3654
>                 URL: https://issues.apache.org/jira/browse/CAUSEWAY-3654
>             Project: Causeway
>          Issue Type: Bug
>          Components: Ext Sec AuditTrail
>    Affects Versions: 2.0.0-RC3
>            Reporter: Daniel Keir Haywood
>            Assignee: Daniel Keir Haywood
>            Priority: Major
>             Fix For: 2.0.0-RC4
>
>         Attachments: image-2023-12-08-18-12-43-554.png
>
>
> 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:
> {code:java}
> "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)
>  {code}
> and I compared to the original stacktrace yielding the error:
> {code:java}
> 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:?]
>  {code}
> 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:
> !image-2023-12-08-18-12-43-554.png|width=1178,height=623!
>  
> 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.



--
This message was sent by Atlassian Jira
(v8.20.10#820010)

Reply via email to