jtds and HAPI 3.4.0 possible bug/incompatibility

[logan....@bestpractice.org.nz]

Hi.

I am in the process of upgrading from HAPI JPA server 2.4 to 3.4. We had configured JPA server 2.4 to work with the jtds jdbc driver to talk to SQL server (Express Edition version 14.0.1000.169) however after upgrading this no longer works.

A little bit of background, I am working with a dataset of 10,000+ PractitionerRole resources (and associated references), the performance of the JPA server for 2.4 is unable to keep up with this amount of data when searching to return all PractitionerRole Resources, taking from 20 seconds (configured to use maximum page size of 1000) to 50 seconds (default maximum page size).

I have successfully got 3.4 running using the Microsoft jdbc driver however this performs worse than jtds (fastest I have been able to get is 1 minute)

My setup is based off the hapi-fhir-jpaserver-example project using DSTU3 with the following modifications

pom.xml

<dependency>

<groupId>org.apache.commons</groupId>

   <artifactId>commons-dbcp2</artifactId>

</dependency>        

<dependency>

<groupId>net.sourceforge.jtds</groupId>

   <artifactId>jtds</artifactId>

   <version>1.3.1</version>            

</dependency>

FhirServerConfig.java

@Bean(destroyMethod = "close")

public DataSource dataSource() {

String dbConnectionString = System.getenv("DB_ConnectionString"); //jdbc:jtds:sqlserver://localhost/Directory

    String dbUsername = System.getenv("DB_Username");

   String dbPassword = System.getenv("DB_Password");

BasicDataSource retVal = new BasicDataSource();

   retVal.setDriver(new Driver());

   retVal.setUrl(dbConnectionString);

   retVal.setUsername(dbUsername);

   retVal.setPassword(dbPassword);

   retVal.setValidationQuery("SELECT 1");

   return retVal;

}

@Override

@Bean()

public LocalContainerEntityManagerFactoryBean entityManagerFactory() {

LocalContainerEntityManagerFactoryBean retVal = super.entityManagerFactory();

    retVal.setPersistenceUnitName("HAPI_PU");

    retVal.setDataSource(dataSource());       

    retVal.setJpaProperties(jpaProperties());

    return retVal;

}

private Properties jpaProperties() {

Properties extraProperties = new Properties();

    extraProperties.put("hibernate.default_schema", "fhir");

    extraProperties.put("hibernate.dialect", SQLServer2012Dialect.class.getName());

    extraProperties.put("hibernate.format_sql", "true");

    extraProperties.put("hibernate.show_sql", "false");

    extraProperties.put("hibernate.hbm2ddl.auto", "update");

    extraProperties.put("hibernate.jdbc.batch_size", "20");

    extraProperties.put("hibernate.cache.use_query_cache", "false");

    extraProperties.put("hibernate.cache.use_second_level_cache", "false");

    extraProperties.put("hibernate.cache.use_structured_entries", "false");

    extraProperties.put("hibernate.cache.use_minimal_puts", "false");

    extraProperties.put("hibernate.search.model_mapping", LuceneSearchMappingFactory.class.getName());

    extraProperties.put("hibernate.search.default.directory_provider", "filesystem");

    extraProperties.put("hibernate.search.default.indexBase", "target/lucenefiles");

    extraProperties.put("hibernate.search.lucene_version", "LUCENE_CURRENT");

    // extraProperties.put("hibernate.search.default.worker.execution", "async");

return extraProperties;

}

With a clean database I get the following error when trying to access the PractitionerRole resource. 

  

2018-07-31 08:59:29.943 [qtp927159199-16] INFO  c.u.f.j.s.SearchCoordinatorSvcImpl [SearchCoordinatorSvcImpl.java:351] Search initial phase completed in 8ms
2018-07-31 08:59:29.985 [search_coord_1] INFO  o.h.e.j.b.internal.AbstractBatchImpl [AbstractBatchImpl.java:193] HHH000010: On release of batch it still contained JDBC statements
2018-07-31 08:59:29.987 [search_coord_1] ERROR c.u.f.j.s.SearchCoordinatorSvcImpl [SearchCoordinatorSvcImpl.java:542] Failed during search loading after 44ms
java.lang.AbstractMethodError: null
        at net.sourceforge.jtds.jdbc.JtdsPreparedStatement.setCharacterStream(JtdsPreparedStatement.java:1274)
        at org.apache.commons.dbcp2.DelegatingPreparedStatement.setCharacterStream(DelegatingPreparedStatement.java:383)
        at org.apache.commons.dbcp2.DelegatingPreparedStatement.setCharacterStream(DelegatingPreparedStatement.java:383)
        at org.hibernate.type.descriptor.sql.ClobTypeDescriptor$4$1.doBind(ClobTypeDescriptor.java:129)
        at org.hibernate.type.descriptor.sql.BasicBinder.bind(BasicBinder.java:74)
        at org.hibernate.type.AbstractStandardBasicType.nullSafeSet(AbstractStandardBasicType.java:280)
        at org.hibernate.type.AbstractStandardBasicType.nullSafeSet(AbstractStandardBasicType.java:275)
        at org.hibernate.type.AbstractSingleColumnStandardBasicType.nullSafeSet(AbstractSingleColumnStandardBasicType.java:39)
        at org.hibernate.persister.entity.AbstractEntityPersister.dehydrate(AbstractEntityPersister.java:2715)
        at org.hibernate.persister.entity.AbstractEntityPersister.insert(AbstractEntityPersister.java:3009)
        at org.hibernate.persister.entity.AbstractEntityPersister.insert(AbstractEntityPersister.java:3533)
        at org.hibernate.action.internal.EntityInsertAction.execute(EntityInsertAction.java:89)
        at org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:600)
        at org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:474)
        at org.hibernate.event.internal.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:337)
        at org.hibernate.event.internal.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:39)
        at org.hibernate.internal.SessionImpl.doFlush(SessionImpl.java:1436)
        at org.hibernate.internal.SessionImpl.managedFlush(SessionImpl.java:493)
        at org.hibernate.internal.SessionImpl.flushBeforeTransactionCompletion(SessionImpl.java:3206)
        at org.hibernate.internal.SessionImpl.beforeTransactionCompletion(SessionImpl.java:2412)
        at org.hibernate.engine.jdbc.internal.JdbcCoordinatorImpl.beforeTransactionCompletion(JdbcCoordinatorImpl.java:473)
        at org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl.beforeCompletionCallback(JdbcResourceLocalTransactionCoordinatorImpl.java:156)
        at org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl.access$100(JdbcResourceLocalTransactionCoordinatorImpl.java:38)
        at org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl$TransactionDriverControlImpl.commit(JdbcResourceLocalTransactionCoordinatorImpl.java:231)
        at org.hibernate.engine.transaction.internal.TransactionImpl.commit(TransactionImpl.java:68)
        at org.springframework.orm.jpa.JpaTransactionManager.doCommit(JpaTransactionManager.java:536)
        at org.springframework.transaction.support.AbstractPlatformTransactionManager.processCommit(AbstractPlatformTransactionManager.java:742)
        at org.springframework.transaction.support.AbstractPlatformTransactionManager.commit(AbstractPlatformTransactionManager.java:710)
        at org.springframework.transaction.support.TransactionTemplate.execute(TransactionTemplate.java:152)
        at ca.uhn.fhir.jpa.search.SearchCoordinatorSvcImpl$SearchTask.saveSearch(SearchCoordinatorSvcImpl.java:679)
        at ca.uhn.fhir.jpa.search.SearchCoordinatorSvcImpl$SearchTask.call(SearchCoordinatorSvcImpl.java:512)
        at ca.uhn.fhir.jpa.search.SearchCoordinatorSvcImpl$SearchTask.call(SearchCoordinatorSvcImpl.java:454)
        at java.util.concurrent.FutureTask.run(FutureTask.java:266)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
        at java.lang.Thread.run(Thread.java:748)
2018-07-31 08:59:30.001 [search_coord_1] INFO  o.h.e.j.b.internal.AbstractBatchImpl [AbstractBatchImpl.java:193] HHH000010: On release of batch it still contained JDBC statements
2018-07-31 08:59:30.007 [qtp927159199-16] ERROR c.u.f.r.s.i.ExceptionHandlingInterceptor [ExceptionHandlingInterceptor.java:134] Failure during REST processing
ca.uhn.fhir.rest.server.exceptions.InternalErrorException: null
        at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
        at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
        at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
        at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
        at ca.uhn.fhir.rest.server.exceptions.BaseServerResponseException.newInstance(BaseServerResponseException.java:301)
        at ca.uhn.fhir.jpa.search.SearchCoordinatorSvcImpl.verifySearchHasntFailedOrThrowInternalErrorException(SearchCoordinatorSvcImpl.java:437)
        at ca.uhn.fhir.jpa.search.PersistedJpaSearchFirstPageBundleProvider.size(PersistedJpaSearchFirstPageBundleProvider.java:84)
        at ca.uhn.fhir.rest.server.method.BaseResourceReturningMethodBinding.doInvokeServer(BaseResourceReturningMethodBinding.java:315)
        at ca.uhn.fhir.rest.server.method.BaseResourceReturningMethodBinding.invokeServer(BaseResourceReturningMethodBinding.java:371)
        at ca.uhn.fhir.rest.server.RestfulServer.handleRequest(RestfulServer.java:921)
        at ca.uhn.fhir.rest.server.RestfulServer.doGet(RestfulServer.java:335)
        at ca.uhn.fhir.rest.server.RestfulServer.service(RestfulServer.java:1494)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:790)
        at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:860)
        at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1650)
        at org.eclipse.jetty.websocket.server.WebSocketUpgradeFilter.doFilter(WebSocketUpgradeFilter.java:206)
        at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1637)
        at org.ebaysf.web.cors.CORSFilter.handleNonCORS(CORSFilter.java:437)
        at org.ebaysf.web.cors.CORSFilter.doFilter(CORSFilter.java:172)
        at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1629)
        at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:533)
        at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:143)
        at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:548)
        at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:132)
        at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:190)
        at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1595)
        at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:188)
        at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1253)
        at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:168)
        at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:473)
        at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1564)
        at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:166)
        at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1155)
        at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)
        at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:219)
        at org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.java:126)
        at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:132)
        at org.eclipse.jetty.server.Server.handle(Server.java:530)
        at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:347)
        at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:256)
        at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:279)
        at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:102)
        at org.eclipse.jetty.io.ChannelEndPoint$2.run(ChannelEndPoint.java:124)
        at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:247)
        at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.produce(EatWhatYouKill.java:140)
        at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:708)
        at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:626)
        at java.lang.Thread.run(Thread.java:748) 

[James Agnew]

Given that it's JTDS that's throwing an AbstractMethodError, it sounds mostly like a bug in JTDS to me. I did find this page that shows the same error and claims that a solution was verified, although I don't have access to see what the solution was: https://access.redhat.com/solutions/1582163

Is JTDS still an active project that could be asked about this?

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+...@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/a65380c1-6809-4b9c-a6cc-04e9d6bcbf7e%40googlegroups.com.
For more options, visit https://groups.google.com/d/optout.

[logan....@bestpractice.org.nz]

Hi. Thanks for the response.

I also found that redhat solution and am also unable to view the answer

Looking at the jtds repo the most recent change was 2016, the most recent release on Maven was 2013, so the project looks fairly dead.

Thanks,

Logan.

[James Agnew]

Ahh that's unfortunate.

I wonder if it doesn't make more sense to focus on what's making the MS driver so much slower in that case.

Are you in a position to try it with the latest 3.5.0 snapshot builds? There are a number of performance enhancements in the upcoming release. Also, can you take a thread dump or two to see where it seems to be spending most of its time while loading?

Cheers,

James

To view this discussion on the web visit https://groups.google.com/d/msgid/hapi-fhir/a219589c-51a7-4ba2-bb2f-21e4122aa20d%40googlegroups.com.

[logan....@bestpractice.org.nz]

Hi.

I will look at generating a thread dump tomorrow.

I have tested using the 3.5.0 snapshot build, I tried with an existing database and a new database both result in the following error when fetching PractitionerRole data

The table referred to in the error has been created and populated with data in my [fhir] schema

2018-07-31 16:11:33.349 [qtp1607458416-15] WARN  o.h.e.jdbc.spi.SqlExceptionHelper [SqlExceptionHelper.java:129] SQL Error: 208, SQLState: S0002
2018-07-31 16:11:33.350 [qtp1607458416-15] ERROR o.h.e.jdbc.spi.SqlExceptionHelper [SqlExceptionHelper.java:131] Invalid object name 'HFJ_RES_VER'.
2018-07-31 16:11:33.353 [search_coord_2] INFO  c.u.f.j.s.SearchCoordinatorSvcImpl [SearchCoordinatorSvcImpl.java:528] Completed search for 143 resources in 44ms
2018-07-31 16:11:33.360 [qtp1607458416-15] ERROR c.u.f.r.s.i.ExceptionHandlingInterceptor [ExceptionHandlingInterceptor.java:154] Failure during REST processing: org.springframework.dao.InvalidDataAccessResourceUsageException: could not extract ResultSet; SQL [n/a]; nested exception is org.hibernate.exception.SQLGrammarException: could not extract ResultSet
org.springframework.dao.InvalidDataAccessResourceUsageException: could not extract ResultSet; SQL [n/a]; nested exception is org.hibernate.exception.SQLGrammarException: could not extract ResultSet
        at org.springframework.orm.jpa.vendor.HibernateJpaDialect.convertHibernateAccessException(HibernateJpaDialect.java:242)
        at ca.uhn.fhir.jpa.config.HapiFhirHibernateJpaDialect.convertHibernateAccessException(HapiFhirHibernateJpaDialect.java:59)
        at org.springframework.orm.jpa.vendor.HibernateJpaDialect.translateExceptionIfPossible(HibernateJpaDialect.java:225)
        at org.springframework.orm.jpa.AbstractEntityManagerFactoryBean.translateExceptionIfPossible(AbstractEntityManagerFactoryBean.java:527)
        at org.springframework.dao.support.ChainedPersistenceExceptionTranslator.translateExceptionIfPossible(ChainedPersistenceExceptionTranslator.java:61)
        at org.springframework.dao.support.DataAccessUtils.translateIfNecessary(DataAccessUtils.java:242)
        at org.springframework.dao.support.PersistenceExceptionTranslationInterceptor.invoke(PersistenceExceptionTranslationInterceptor.java:153)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:185)
        at org.springframework.data.jpa.repository.support.CrudMethodMetadataPostProcessor$CrudMethodMetadataPopulatingMethodInterceptor.invoke(CrudMethodMetadataPostProcessor.java:135)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:185)
        at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:92)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:185)
        at org.springframework.data.repository.core.support.SurroundingTransactionDetectorMethodInterceptor.invoke(SurroundingTransactionDetectorMethodInterceptor.java:61)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:185)
        at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:212)
        at com.sun.proxy.$Proxy148.findByResourceIds(Unknown Source)
        at ca.uhn.fhir.jpa.dao.SearchBuilder.doLoadPids(SearchBuilder.java:1597)
        at ca.uhn.fhir.jpa.dao.SearchBuilder.loadResourcesByPid(SearchBuilder.java:1706)
        at ca.uhn.fhir.jpa.search.PersistedJpaBundleProvider.toResourceList(PersistedJpaBundleProvider.java:282)
        at ca.uhn.fhir.jpa.search.PersistedJpaSearchFirstPageBundleProvider$1.doInTransaction(PersistedJpaSearchFirstPageBundleProvider.java:69)
        at ca.uhn.fhir.jpa.search.PersistedJpaSearchFirstPageBundleProvider$1.doInTransaction(PersistedJpaSearchFirstPageBundleProvider.java:66)
        at org.springframework.transaction.support.TransactionTemplate.execute(TransactionTemplate.java:140)
        at ca.uhn.fhir.jpa.search.PersistedJpaSearchFirstPageBundleProvider.getResources(PersistedJpaSearchFirstPageBundleProvider.java:66)
        at ca.uhn.fhir.rest.server.method.BaseResourceReturningMethodBinding.createBundleFromBundleProvider(BaseResourceReturningMethodBinding.java:156)
        at ca.uhn.fhir.rest.server.method.BaseResourceReturningMethodBinding.doInvokeServer(BaseResourceReturningMethodBinding.java:334)
        at ca.uhn.fhir.rest.server.method.BaseResourceReturningMethodBinding.invokeServer(BaseResourceReturningMethodBinding.java:379)
        at ca.uhn.fhir.rest.server.RestfulServer.handleRequest(RestfulServer.java:920)
        at ca.uhn.fhir.rest.server.RestfulServer.doGet(RestfulServer.java:331)
        at ca.uhn.fhir.rest.server.RestfulServer.service(RestfulServer.java:1488)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:790)
        at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:865)
        at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1655)
        at org.eclipse.jetty.websocket.server.WebSocketUpgradeFilter.doFilter(WebSocketUpgradeFilter.java:215)
        at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1642)

        at org.ebaysf.web.cors.CORSFilter.handleNonCORS(CORSFilter.java:437)
        at org.ebaysf.web.cors.CORSFilter.doFilter(CORSFilter.java:172)

        at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1634)
        at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:533)
        at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:146)

        at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:548)
        at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:132)

        at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:257)
        at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1595)
        at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:255)
        at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1253)
        at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:203)

        at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:473)
        at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1564)

        at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:201)
        at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1155)
        at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:144)

        at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:219)
        at org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.java:126)
        at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:132)

        at org.eclipse.jetty.server.Server.handle(Server.java:531)
        at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:352)
        at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:260)
        at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:281)
        at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:102)
        at org.eclipse.jetty.io.ChannelEndPoint$2.run(ChannelEndPoint.java:118)
        at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.runTask(EatWhatYouKill.java:333)
        at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:310)
        at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:168)
        at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:126)
        at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:366)
        at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:760)
        at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:678)
        at java.lang.Thread.run(Thread.java:748)
Caused by: org.hibernate.exception.SQLGrammarException: could not extract ResultSet
        at org.hibernate.exception.internal.SQLStateConversionDelegate.convert(SQLStateConversionDelegate.java:106)
        at org.hibernate.exception.internal.StandardSQLExceptionConverter.convert(StandardSQLExceptionConverter.java:42)
        at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:111)
        at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:97)
        at org.hibernate.engine.jdbc.internal.ResultSetReturnImpl.extract(ResultSetReturnImpl.java:69)
        at org.hibernate.loader.Loader.getResultSet(Loader.java:2167)
        at org.hibernate.loader.Loader.executeQueryStatement(Loader.java:1930)
        at org.hibernate.loader.Loader.executeQueryStatement(Loader.java:1892)
        at org.hibernate.loader.Loader.doQuery(Loader.java:937)
        at org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:340)
        at org.hibernate.loader.Loader.doList(Loader.java:2689)
        at org.hibernate.loader.Loader.doList(Loader.java:2672)
        at org.hibernate.loader.Loader.listIgnoreQueryCache(Loader.java:2506)
        at org.hibernate.loader.Loader.list(Loader.java:2501)
        at org.hibernate.loader.hql.QueryLoader.list(QueryLoader.java:504)
        at org.hibernate.hql.internal.ast.QueryTranslatorImpl.list(QueryTranslatorImpl.java:395)
        at org.hibernate.engine.query.spi.HQLQueryPlan.performList(HQLQueryPlan.java:221)
        at org.hibernate.internal.SessionImpl.list(SessionImpl.java:1508)
        at org.hibernate.query.internal.AbstractProducedQuery.doList(AbstractProducedQuery.java:1538)
        at org.hibernate.query.internal.AbstractProducedQuery.list(AbstractProducedQuery.java:1506)
        at org.hibernate.query.Query.getResultList(Query.java:146)
        at org.springframework.data.jpa.repository.query.JpaQueryExecution$CollectionExecution.doExecute(JpaQueryExecution.java:129)
        at org.springframework.data.jpa.repository.query.JpaQueryExecution.execute(JpaQueryExecution.java:91)
        at org.springframework.data.jpa.repository.query.AbstractJpaQuery.doExecute(AbstractJpaQuery.java:136)
        at org.springframework.data.jpa.repository.query.AbstractJpaQuery.execute(AbstractJpaQuery.java:125)
        at org.springframework.data.repository.core.support.RepositoryFactorySupport$QueryExecutorMethodInterceptor.doInvoke(RepositoryFactorySupport.java:590)
        at org.springframework.data.repository.core.support.RepositoryFactorySupport$QueryExecutorMethodInterceptor.invoke(RepositoryFactorySupport.java:578)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:185)
        at org.springframework.data.projection.DefaultMethodInvokingMethodInterceptor.invoke(DefaultMethodInvokingMethodInterceptor.java:59)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:185)
        at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:294)
        at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:98)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:185)
        at org.springframework.dao.support.PersistenceExceptionTranslationInterceptor.invoke(PersistenceExceptionTranslationInterceptor.java:139)
        ... 61 common frames omitted
Caused by: com.microsoft.sqlserver.jdbc.SQLServerException: Invalid object name 'HFJ_RES_VER'.
        at com.microsoft.sqlserver.jdbc.SQLServerException.makeFromDatabaseError(SQLServerException.java:259)
        at com.microsoft.sqlserver.jdbc.SQLServerStatement.getNextResult(SQLServerStatement.java:1547)
        at com.microsoft.sqlserver.jdbc.SQLServerPreparedStatement.doExecutePreparedStatement(SQLServerPreparedStatement.java:548)
        at com.microsoft.sqlserver.jdbc.SQLServerPreparedStatement$PrepStmtExecCmd.doExecute(SQLServerPreparedStatement.java:479)
        at com.microsoft.sqlserver.jdbc.TDSCommand.execute(IOBuffer.java:7344)
        at com.microsoft.sqlserver.jdbc.SQLServerConnection.executeCommand(SQLServerConnection.java:2713)
        at com.microsoft.sqlserver.jdbc.SQLServerStatement.executeCommand(SQLServerStatement.java:224)
        at com.microsoft.sqlserver.jdbc.SQLServerStatement.executeStatement(SQLServerStatement.java:204)
        at com.microsoft.sqlserver.jdbc.SQLServerPreparedStatement.executeQuery(SQLServerPreparedStatement.java:401)
        at org.apache.commons.dbcp2.DelegatingPreparedStatement.executeQuery(DelegatingPreparedStatement.java:83)
        at org.apache.commons.dbcp2.DelegatingPreparedStatement.executeQuery(DelegatingPreparedStatement.java:83)
        at org.hibernate.engine.jdbc.internal.ResultSetReturnImpl.extract(ResultSetReturnImpl.java:60)
        ... 90 common frames omitted

[James Agnew]

Whoa, that's weird.

The fact that it can't find "HFJ_RES_VER" (which is a table in the HAPI FHIR schema) suggests that maybe it didn't successfully create its own schema? Do you see that table in the DB if you attach using a database tool?

If yes, does this error happen anytime you try to do anything, or is there something specific that triggers it?

Cheers,

James

To view this discussion on the web visit https://groups.google.com/d/msgid/hapi-fhir/ced9e17c-b8ab-4681-963a-9f801b272a85%40googlegroups.com.

[logan....@bestpractice.org.nz]

Running the following results in this error:

http://localhost:8080/hapi-fhir-jpaserver/fhir/PractitionerRole

http://localhost:8080/hapi-fhir-jpaserver/fhir/Practitioner

http://localhost:8080/hapi-fhir-jpaserver/fhir/Endpoint

http://localhost:8080/hapi-fhir-jpaserver/fhir/Organization
http://localhost:8080/hapi-fhir-jpaserver/fhir/HealthcareService

The following requests don't error and return results:

http://localhost:8080/hapi-fhir-jpaserver/fhir/PractitionerRole/<id>
http://localhost:8080/hapi-fhir-jpaserver/fhir/Practitioner/<id>

http://localhost:8080/hapi-fhir-jpaserver/fhir/Endpoint/<id>

http://localhost:8080/hapi-fhir-jpaserver/fhir/Organization/<id>

http://localhost:8080/hapi-fhir-jpaserver/fhir/HealthcareService/<id>

Also using the Hl7.Fhir.Rest.FhirClient.Update() method for each of the above resource types doesn't error.

I have not tried other resource types.

See the screenshot below of the table existing and populated with data in the database.

Thanks,

Logan.

[logan....@bestpractice.org.nz]

Hi.

Here is a link to the a pastebin of the thread dump generated using VisualVm for version 3.4 of Hapi-Fhir using mssql-jdbc. If this isn't what you are after please provide more detailed instructions as I am not all that familiar with Java.

https://pastebin.com/AXg6TW7R 

Thanks,

Logan.

[logan....@bestpractice.org.nz]

Hi.

I have done some testing using Postgres on Hapi Fhir 3.4 and am seeing similar timings as with MSSQL (1 minute to load 10000+ PractitionerRole resources)

I have also tried Postgres with 3.5.0-SNAPSHOT and I don't get the same database error I was receiving with MSSQL. The performance is significantly better than Hapi Fhir 3.4,  22 seconds for 10000 results at a maximum page size of 1000, 28 seconds for 10000 results at a maximum page size of 50.

These timings still seem slow for the amount of data I am dealing with, is this the expected level of performance of Hapi Fhir?

I noticed in the change log for 3.5:

JPA server loading logic has been improved to enhance performance when loading a large number of results in a page, or when loading multiple search results with tags. Thanks to Frank Tao for the pull request!

In data that I am working with, every resource has a tag so that we can implement tenant specific data, could this be the cause of the poor performance? 

If this is the case do you have any suggestions for how to implement multi-tenancy with better performance?

Thanks,

Logan.

[Yohannes Tecle]

Hi All

I am also new to fhir, I am trying to build a JPA server from scratch, what else can I reuse into my code in addition to the POM file and the FhirServerConfig.java ?

Any direction/ references to build JPA server from scratch would be greatly appreciated. I have seen these sample JPA-FHIR projects, but I do not quite understand how they work.  Thank you.  

[James Agnew]

This starter project is the recommended way to get started:

https://github.com/hapifhir/hapi-fhir-jpaserver-starter

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+...@googlegroups.com.

To view this discussion on the web visit https://groups.google.com/d/msgid/hapi-fhir/242ab2a6-50e7-42d0-92e0-42d54e7d2444%40googlegroups.com.