Using Axon 4.0.2 with a postgres database in a spring boot 2.0.6.RELEASE application (using the spring-boot-starter-jpa auto-selected postgres hibernate dialect) we experience the following exception when a saga is loaded from the JPASagaStore after a deadline is triggered:
org.axonframework.messaging.ExecutionException: Failed to send a DeadlineMessage for scope [SagaScopeDescriptor for type [JobResultSaga] and identifier [3cf8b126-a13f-419f-9917-62c0f6783023]] at org.axonframework.deadline.quartz.DeadlineJob.lambda$executeScheduledDeadline$2(DeadlineJob.java:146) ~[axon-messaging-4.0.2.jar!/:4.0.2] at java.base/java.util.stream.ForEachOps$ForEachOp$OfRef.accept(Unknown Source) ~[na:na] at java.base/java.util.stream.ReferencePipeline$2$1.accept(Unknown Source) ~[na:na] at java.base/java.util.ArrayList$ArrayListSpliterator.forEachRemaining(Unknown Source) ~[na:na] at java.base/java.util.stream.AbstractPipeline.copyInto(Unknown Source) ~[na:na] at java.base/java.util.stream.AbstractPipeline.wrapAndCopyInto(Unknown Source) ~[na:na] at java.base/java.util.stream.ForEachOps$ForEachOp.evaluateSequential(Unknown Source) ~[na:na] at java.base/java.util.stream.ForEachOps$ForEachOp$OfRef.evaluateSequential(Unknown Source) ~[na:na] at java.base/java.util.stream.AbstractPipeline.evaluate(Unknown Source) ~[na:na] at java.base/java.util.stream.ReferencePipeline.forEach(Unknown Source) ~[na:na] at org.axonframework.deadline.quartz.DeadlineJob.executeScheduledDeadline(DeadlineJob.java:138) ~[axon-messaging-4.0.2.jar!/:4.0.2] at org.axonframework.deadline.quartz.DeadlineJob.lambda$execute$0(DeadlineJob.java:116) ~[axon-messaging-4.0.2.jar!/:4.0.2] at org.axonframework.messaging.DefaultInterceptorChain.proceed(DefaultInterceptorChain.java:57) ~[axon-messaging-4.0.2.jar!/:4.0.2] at org.axonframework.messaging.unitofwork.DefaultUnitOfWork.executeWithResult(DefaultUnitOfWork.java:74) ~[axon-messaging-4.0.2.jar!/:4.0.2] at org.axonframework.messaging.unitofwork.UnitOfWork.executeWithResult(UnitOfWork.java:328) ~[axon-messaging-4.0.2.jar!/:4.0.2] at org.axonframework.deadline.quartz.DeadlineJob.execute(DeadlineJob.java:121) ~[axon-messaging-4.0.2.jar!/:4.0.2] at org.quartz.core.JobRunShell.run(JobRunShell.java:202) ~[quartz-2.3.0.jar!/:na] at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:573) ~[quartz-2.3.0.jar!/:na] Caused by: javax.persistence.PersistenceException: org.hibernate.HibernateException: Unable to access lob stream at org.hibernate.internal.ExceptionConverterImpl.convert(ExceptionConverterImpl.java:149) ~[hibernate-core-5.2.17.Final.jar!/:5.2.17.Final] at org.hibernate.internal.ExceptionConverterImpl.convert(ExceptionConverterImpl.java:157) ~[hibernate-core-5.2.17.Final.jar!/:5.2.17.Final] at org.hibernate.query.internal.AbstractProducedQuery.list(AbstractProducedQuery.java:1423) ~[hibernate-core-5.2.17.Final.jar!/:5.2.17.Final] at org.hibernate.query.Query.getResultList(Query.java:146) ~[hibernate-core-5.2.17.Final.jar!/:5.2.17.Final] at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:na] at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(Unknown Source) ~[na:na] at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source) ~[na:na] at java.base/java.lang.reflect.Method.invoke(Unknown Source) ~[na:na] at org.springframework.orm.jpa.SharedEntityManagerCreator$DeferredQueryInvocationHandler.invoke(SharedEntityManagerCreator.java:380) ~[spring-orm-5.0.10.RELEASE.jar!/:5.0.10.RELEASE] at com.sun.proxy.$Proxy173.getResultList(Unknown Source) ~[na:na] at org.axonframework.modelling.saga.repository.jpa.JpaSagaStore.loadSaga(JpaSagaStore.java:155) ~[axon-modelling-4.0.2.jar!/:4.0.2] at org.axonframework.modelling.saga.repository.AnnotatedSagaRepository.doLoadSaga(AnnotatedSagaRepository.java:229) ~[axon-modelling-4.0.2.jar!/:4.0.2] at org.axonframework.modelling.saga.repository.AnnotatedSagaRepository.lambda$doLoad$1(AnnotatedSagaRepository.java:111) ~[axon-modelling-4.0.2.jar!/:4.0.2] at java.base/java.util.concurrent.ConcurrentHashMap.computeIfAbsent(Unknown Source) ~[na:na] at org.axonframework.modelling.saga.repository.AnnotatedSagaRepository.doLoad(AnnotatedSagaRepository.java:110) ~[axon-modelling-4.0.2.jar!/:4.0.2] at org.axonframework.modelling.saga.repository.AnnotatedSagaRepository.doLoad(AnnotatedSagaRepository.java:56) ~[axon-modelling-4.0.2.jar!/:4.0.2] at org.axonframework.modelling.saga.repository.LockingSagaRepository.load(LockingSagaRepository.java:64) ~[axon-modelling-4.0.2.jar!/:4.0.2] at org.axonframework.modelling.saga.AbstractSagaManager.send(AbstractSagaManager.java:206) ~[axon-modelling-4.0.2.jar!/:4.0.2] at org.axonframework.deadline.quartz.DeadlineJob.lambda$executeScheduledDeadline$2(DeadlineJob.java:140) ~[axon-messaging-4.0.2.jar!/:4.0.2] ... 17 common frames omitted Caused by: org.hibernate.HibernateException: Unable to access lob stream at org.hibernate.type.descriptor.java.PrimitiveByteArrayTypeDescriptor.wrap(PrimitiveByteArrayTypeDescriptor.java:123) ~[hibernate-core-5.2.17.Final.jar!/:5.2.17.Final] at org.hibernate.type.descriptor.java.PrimitiveByteArrayTypeDescriptor.wrap(PrimitiveByteArrayTypeDescriptor.java:26) ~[hibernate-core-5.2.17.Final.jar!/:5.2.17.Final] at org.hibernate.type.descriptor.sql.BlobTypeDescriptor$1.doExtract(BlobTypeDescriptor.java:48) ~[hibernate-core-5.2.17.Final.jar!/:5.2.17.Final] at org.hibernate.type.descriptor.sql.BasicExtractor.extract(BasicExtractor.java:47) ~[hibernate-core-5.2.17.Final.jar!/:5.2.17.Final] at org.hibernate.type.AbstractStandardBasicType.nullSafeGet(AbstractStandardBasicType.java:261) ~[hibernate-core-5.2.17.Final.jar!/:5.2.17.Final] at org.hibernate.type.AbstractStandardBasicType.nullSafeGet(AbstractStandardBasicType.java:257) ~[hibernate-core-5.2.17.Final.jar!/:5.2.17.Final] at org.hibernate.type.AbstractStandardBasicType.nullSafeGet(AbstractStandardBasicType.java:247) ~[hibernate-core-5.2.17.Final.jar!/:5.2.17.Final] at org.hibernate.loader.hql.QueryLoader.getResultRow(QueryLoader.java:453) ~[hibernate-core-5.2.17.Final.jar!/:5.2.17.Final] at org.hibernate.loader.hql.QueryLoader.getResultColumnOrRow(QueryLoader.java:436) ~[hibernate-core-5.2.17.Final.jar!/:5.2.17.Final] at org.hibernate.loader.Loader.getRowFromResultSet(Loader.java:761) ~[hibernate-core-5.2.17.Final.jar!/:5.2.17.Final] at org.hibernate.loader.Loader.processResultSet(Loader.java:991) ~[hibernate-core-5.2.17.Final.jar!/:5.2.17.Final] at org.hibernate.loader.Loader.doQuery(Loader.java:949) ~[hibernate-core-5.2.17.Final.jar!/:5.2.17.Final] at org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:341) ~[hibernate-core-5.2.17.Final.jar!/:5.2.17.Final] at org.hibernate.loader.Loader.doList(Loader.java:2692) ~[hibernate-core-5.2.17.Final.jar!/:5.2.17.Final] at org.hibernate.loader.Loader.doList(Loader.java:2675) ~[hibernate-core-5.2.17.Final.jar!/:5.2.17.Final] at org.hibernate.loader.Loader.listIgnoreQueryCache(Loader.java:2507) ~[hibernate-core-5.2.17.Final.jar!/:5.2.17.Final] at org.hibernate.loader.Loader.list(Loader.java:2502) ~[hibernate-core-5.2.17.Final.jar!/:5.2.17.Final] at org.hibernate.loader.hql.QueryLoader.list(QueryLoader.java:502) ~[hibernate-core-5.2.17.Final.jar!/:5.2.17.Final] at org.hibernate.hql.internal.ast.QueryTranslatorImpl.list(QueryTranslatorImpl.java:392) ~[hibernate-core-5.2.17.Final.jar!/:5.2.17.Final] at org.hibernate.engine.query.spi.HQLQueryPlan.performList(HQLQueryPlan.java:216) ~[hibernate-core-5.2.17.Final.jar!/:5.2.17.Final] at org.hibernate.internal.SessionImpl.list(SessionImpl.java:1490) ~[hibernate-core-5.2.17.Final.jar!/:5.2.17.Final] at org.hibernate.query.internal.AbstractProducedQuery.doList(AbstractProducedQuery.java:1445) ~[hibernate-core-5.2.17.Final.jar!/:5.2.17.Final] at org.hibernate.query.internal.AbstractProducedQuery.list(AbstractProducedQuery.java:1414) ~[hibernate-core-5.2.17.Final.jar!/:5.2.17.Final] ... 33 common frames omitted Caused by: org.postgresql.util.PSQLException: Large Objects may not be used in auto-commit mode. at org.postgresql.largeobject.LargeObjectManager.open(LargeObjectManager.java:254) ~[postgresql-42.2.5.jar!/:42.2.5] at org.postgresql.largeobject.LargeObjectManager.open(LargeObjectManager.java:240) ~[postgresql-42.2.5.jar!/:42.2.5] at org.postgresql.jdbc.AbstractBlobClob.getLo(AbstractBlobClob.java:272) ~[postgresql-42.2.5.jar!/:42.2.5] at org.postgresql.jdbc.AbstractBlobClob.getBinaryStream(AbstractBlobClob.java:116) ~[postgresql-42.2.5.jar!/:42.2.5] at org.hibernate.type.descriptor.java.PrimitiveByteArrayTypeDescriptor.wrap(PrimitiveByteArrayTypeDescriptor.java:120) ~[hibernate-core-5.2.17.Final.jar!/:5.2.17.Final] ... 55 common frames omitted
I have read on issues with LargeObjects and Axon but they are mosly concerning the EventStore and most of the time the problem was a missing transaction manager configuration. We have (from our point of view) properly configured our transaction manager for axon.
From what I see from the code and logging, it does seem that there is no transaction bound to the UnitOfWork for handling the DeadlineMessage that is subsequently reading the saga from the saga store. This should not be a problem in the first place for other DBMS. But for postgres when using @Lob this is a problem, since LOBs are stored in a separate table and reading involves two database access operations by hibernate that need to be executed within a transaction.
Did we miss a configuration to setup transactions for the deadline framework or is the read-access to the saga store designed intentionally without a transaction (which would be perfectly understandable).
Best Regards,
Jakob
PS.: If this turns out to be a bug, I will of course file an issue with additional information in the AxonFramework github repo bit I did’nt want to file a bug in the first place because I’m not sure if we’re on the right track with our guess.
