JPA 2.5 issues - Large Objects may not be used in auto-commit mode.

2,351 views

Skip to first unread message

contac...@gmail.com

unread,

Jun 29, 2017, 4:31:51 PM6/29/17

to HAPI FHIR

Hi James,

We recently upgraded from 2.4 to 2.5 and we started seeing these messages in the logs. Most of the functionality works but the Batch and transaction operations fail. Out Backend is Postgress.

Any inputs will be helpful, I am wondering if it is DB config issue, please suggest

2017-06-29 16:24:37.189 [scheduledExecutorService-3] ERROR o.s.s.s.TaskUtils$LoggingErrorHandler [TaskUtils.java:95] Unexpected error occurred in scheduled task.

org.springframework.orm.jpa.JpaSystemException: org.hibernate.HibernateException: Unable to access lob stream; nested exception is javax.persistence.PersistenceException: org.hibernate.HibernateException: Unable to access lob stream

at org.springframework.orm.jpa.EntityManagerFactoryUtils.convertJpaAccessExceptionIfPossible(EntityManagerFactoryUtils.java:418)

at org.springframework.orm.jpa.AbstractEntityManagerFactoryBean.translateExceptionIfPossible(AbstractEntityManagerFactoryBean.java:492)

at org.springframework.dao.support.ChainedPersistenceExceptionTranslator.translateExceptionIfPossible(ChainedPersistenceExceptionTranslator.java:59)

at org.springframework.dao.support.DataAccessUtils.translateIfNecessary(DataAccessUtils.java:213)

at org.springframework.dao.support.PersistenceExceptionTranslationInterceptor.invoke(PersistenceExceptionTranslationInterceptor.java:147)

at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)

at org.springframework.data.jpa.repository.support.CrudMethodMetadataPostProcessor$CrudMethodMetadataPopulatingMethodInterceptor.invoke(CrudMethodMetadataPostProcessor.java:133)

at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)

at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:92)

at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)

at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:213)

at com.sun.proxy.$Proxy145.findWhereLastReturnedBefore(Unknown Source)

at ca.uhn.fhir.jpa.search.StaleSearchDeletingSvcImpl.pollForStaleSearchesAndDeleteThem(StaleSearchDeletingSvcImpl.java:100)

at ca.uhn.fhir.jpa.search.StaleSearchDeletingSvcImpl.schedulePollForStaleSearches(StaleSearchDeletingSvcImpl.java:120)

at sun.reflect.GeneratedMethodAccessor111.invoke(Unknown Source)

at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)

at java.lang.reflect.Method.invoke(Method.java:497)

at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:333)

at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:190)

at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:157)

at org.springframework.transaction.interceptor.TransactionInterceptor$1.proceedWithInvocation(TransactionInterceptor.java:99)

at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:281)

at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:96)

at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)

at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:213)

at com.sun.proxy.$Proxy183.schedulePollForStaleSearches(Unknown Source)

at sun.reflect.GeneratedMethodAccessor111.invoke(Unknown Source)

at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)

at java.lang.reflect.Method.invoke(Method.java:497)

at org.springframework.scheduling.support.ScheduledMethodRunnable.run(ScheduledMethodRunnable.java:65)

at org.springframework.scheduling.support.DelegatingErrorHandlingRunnable.run(DelegatingErrorHandlingRunnable.java:54)

at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)

at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)

at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)

at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)

at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)

at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)

at java.lang.Thread.run(Thread.java:745)

Caused by: javax.persistence.PersistenceException: org.hibernate.HibernateException: Unable to access lob stream

at org.hibernate.jpa.spi.AbstractEntityManagerImpl.convert(AbstractEntityManagerImpl.java:1692)

at org.hibernate.jpa.spi.AbstractEntityManagerImpl.convert(AbstractEntityManagerImpl.java:1602)

at org.hibernate.jpa.internal.QueryImpl.getResultList(QueryImpl.java:492)

at org.springframework.data.jpa.repository.query.JpaQueryExecution$CollectionExecution.doExecute(JpaQueryExecution.java:118)

at org.springframework.data.jpa.repository.query.JpaQueryExecution.execute(JpaQueryExecution.java:82)

at org.springframework.data.jpa.repository.query.AbstractJpaQuery.doExecute(AbstractJpaQuery.java:114)

at org.springframework.data.jpa.repository.query.AbstractJpaQuery.execute(AbstractJpaQuery.java:104)

at org.springframework.data.repository.core.support.RepositoryFactorySupport$QueryExecutorMethodInterceptor.doInvoke(RepositoryFactorySupport.java:482)

at org.springframework.data.repository.core.support.RepositoryFactorySupport$QueryExecutorMethodInterceptor.invoke(RepositoryFactorySupport.java:460)

at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)

at org.springframework.data.projection.DefaultMethodInvokingMethodInterceptor.invoke(DefaultMethodInvokingMethodInterceptor.java:61)

at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)

at org.springframework.transaction.interceptor.TransactionInterceptor$1.proceedWithInvocation(TransactionInterceptor.java:99)

at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:281)

at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:96)

at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)

at org.springframework.dao.support.PersistenceExceptionTranslationInterceptor.invoke(PersistenceExceptionTranslationInterceptor.java:136)

... 33 common frames omitted

Caused by: org.hibernate.HibernateException: Unable to access lob stream

at org.hibernate.type.descriptor.java.DataHelper.extractString(DataHelper.java:270)

at org.hibernate.type.descriptor.java.StringTypeDescriptor.wrap(StringTypeDescriptor.java:72)

at org.hibernate.type.descriptor.java.StringTypeDescriptor.wrap(StringTypeDescriptor.java:22)

at org.hibernate.type.descriptor.sql.ClobTypeDescriptor$1.doExtract(ClobTypeDescriptor.java:44)

at org.hibernate.type.descriptor.sql.BasicExtractor.extract(BasicExtractor.java:47)

at org.hibernate.type.AbstractStandardBasicType.nullSafeGet(AbstractStandardBasicType.java:238)

at org.hibernate.type.AbstractStandardBasicType.nullSafeGet(AbstractStandardBasicType.java:234)

at org.hibernate.type.AbstractStandardBasicType.nullSafeGet(AbstractStandardBasicType.java:224)

at org.hibernate.type.AbstractStandardBasicType.hydrate(AbstractStandardBasicType.java:300)

at org.hibernate.persister.entity.AbstractEntityPersister.hydrate(AbstractEntityPersister.java:2738)

at org.hibernate.loader.Loader.loadFromResultSet(Loader.java:1729)

at org.hibernate.loader.Loader.instanceNotYetLoaded(Loader.java:1655)

at org.hibernate.loader.Loader.getRow(Loader.java:1544)

at org.hibernate.loader.Loader.getRowFromResultSet(Loader.java:727)

at org.hibernate.loader.Loader.processResultSet(Loader.java:972)

at org.hibernate.loader.Loader.doQuery(Loader.java:930)

at org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:336)

at org.hibernate.loader.Loader.doList(Loader.java:2617)

at org.hibernate.loader.Loader.doList(Loader.java:2600)

at org.hibernate.loader.Loader.listIgnoreQueryCache(Loader.java:2429)

at org.hibernate.loader.Loader.list(Loader.java:2424)

at org.hibernate.loader.hql.QueryLoader.list(QueryLoader.java:501)

at org.hibernate.hql.internal.ast.QueryTranslatorImpl.list(QueryTranslatorImpl.java:371)

at org.hibernate.engine.query.spi.HQLQueryPlan.performList(HQLQueryPlan.java:216)

at org.hibernate.internal.SessionImpl.list(SessionImpl.java:1326)

at org.hibernate.internal.QueryImpl.list(QueryImpl.java:87)

at org.hibernate.jpa.internal.QueryImpl.list(QueryImpl.java:606)

at org.hibernate.jpa.internal.QueryImpl.getResultList(QueryImpl.java:483)

... 47 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:265)

at org.postgresql.largeobject.LargeObjectManager.open(LargeObjectManager.java:251)

at org.postgresql.jdbc.AbstractBlobClob.getLo(AbstractBlobClob.java:275)

at org.postgresql.jdbc.AbstractBlobClob.getBinaryStream(AbstractBlobClob.java:119)

at org.postgresql.jdbc.PgClob.getCharacterStream(PgClob.java:55)

at org.hibernate.type.descriptor.java.DataHelper.extractString(DataHelper.java:263)

... 74 common frames omitted

Thanks

James Agnew

unread,

Jun 30, 2017, 8:45:52 AM6/30/17

to Kuchi Ravi, HAPI FHIR

Hi Ravi,

That stack trace is a problem, but it wouldn't be the cause of transactions failing. That stack trace is actually related to a scheduled task for cleaning up stale searches not working. I'm committing a fix now.

If you are still experiencing transaction failures, can you check your logs for the stack trace on that failure?

Cheers,

James

--
You received this message because you are subscribed to the Google Groups "HAPI FHIR" group.
To unsubscribe from this group and stop receiving emails from it, send an email to hapi-fhir+unsubscribe@googlegroups.com.
To post to this group, send email to hapi...@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/hapi-fhir/920a494e-82bd-4ba2-bee3-edfe3e0bfd75%40googlegroups.com.
For more options, visit https://groups.google.com/d/optout.

contac...@gmail.com

unread,

Jun 30, 2017, 9:04:06 AM6/30/17

to HAPI FHIR, contac...@gmail.com

Thanks James,

Here is the Batch requesting I am trying to post:

{

"resourceType": "Bundle",

"id": "bundle-transaction",

"type": "batch",

"entry": [

{

"request": {

"method": "GET",

"url": "Encounter?subject.identifier=5000038123"

}

]

}

and here is the logs that I get :

2017-06-30 08:57:33.495 [http-nio-8585-exec-3] INFO c.u.f.j.dao.dstu3.FhirSystemDaoDstu3 [FhirSystemDaoDstu3.java:107] Beginning batch with 1 resources

2017-06-30 08:57:33.496 [http-nio-8585-exec-3] INFO c.u.f.j.dao.dstu3.FhirSystemDaoDstu3 [FhirSystemDaoDstu3.java:302] Beginning Batch sub-request with 1 resources

2017-06-30 08:57:33.496 [http-nio-8585-exec-3] INFO c.u.f.j.dao.dstu3.FhirSystemDaoDstu3 [FhirSystemDaoDstu3.java:355] Processed 0 non-GET entries out of 1

2017-06-30 08:57:33.499 [http-nio-8585-exec-3] INFO ca.uhn.fhir.jpa.dao.SearchBuilder [SearchBuilder.java:2025] Initial query result returned in 2ms for query 4d64bbdb-0ca5-4c65-85ca-3964c57011c4

2017-06-30 08:57:33.499 [http-nio-8585-exec-3] INFO ca.uhn.fhir.jpa.dao.SearchBuilder [SearchBuilder.java:2029] Query found 107 matches in 2ms for query 4d64bbdb-0ca5-4c65-85ca-3964c57011c4

2017-06-30 08:57:33.657 [http-nio-8585-exec-3] ERROR c.u.f.j.dao.dstu3.FhirSystemDaoDstu3 [FhirSystemDaoDstu3.java:153] Failure during BATCH sub transaction processing

java.lang.NullPointerException: The validated object is null

at org.apache.commons.lang3.Validate.notNull(Validate.java:225)

at org.apache.commons.lang3.Validate.notNull(Validate.java:206)

at ca.uhn.fhir.jpa.search.DatabaseBackedPagingProvider.storeResultList(DatabaseBackedPagingProvider.java:80)

at org.hl7.fhir.dstu3.hapi.rest.server.Dstu3BundleFactory.initializeBundleFromBundleProvider(Dstu3BundleFactory.java:338)

at ca.uhn.fhir.rest.method.BaseResourceReturningMethodBinding.doInvokeServer(BaseResourceReturningMethodBinding.java:393)

at ca.uhn.fhir.jpa.dao.dstu3.FhirSystemDaoDstu3.doTransaction(FhirSystemDaoDstu3.java:619)

at ca.uhn.fhir.jpa.dao.dstu3.FhirSystemDaoDstu3.transaction(FhirSystemDaoDstu3.java:280)

at ca.uhn.fhir.jpa.dao.dstu3.FhirSystemDaoDstu3.access$000(FhirSystemDaoDstu3.java:100)

at ca.uhn.fhir.jpa.dao.dstu3.FhirSystemDaoDstu3$1.doInTransaction(FhirSystemDaoDstu3.java:131)

at ca.uhn.fhir.jpa.dao.dstu3.FhirSystemDaoDstu3$1.doInTransaction(FhirSystemDaoDstu3.java:124)

at org.springframework.transaction.support.TransactionTemplate.execute(TransactionTemplate.java:133)

at ca.uhn.fhir.jpa.dao.dstu3.FhirSystemDaoDstu3.batch(FhirSystemDaoDstu3.java:138)

at ca.uhn.fhir.jpa.dao.dstu3.FhirSystemDaoDstu3.doTransaction(FhirSystemDaoDstu3.java:290)

at ca.uhn.fhir.jpa.dao.dstu3.FhirSystemDaoDstu3.transaction(FhirSystemDaoDstu3.java:280)

at ca.uhn.fhir.jpa.dao.dstu3.FhirSystemDaoDstu3.transaction(FhirSystemDaoDstu3.java:274)

at ca.uhn.fhir.jpa.dao.dstu3.FhirSystemDaoDstu3.transaction(FhirSystemDaoDstu3.java:100)

at sun.reflect.GeneratedMethodAccessor267.invoke(Unknown Source)