Stream: ibm
Topic: performance
guokun zhang (Dec 09 2020 at 11:07):
Dear IBM team,
We are running ibm fhir server + postgresql database (version: 13.0) from docker-compose file.
We noticed that posting fhir transaction bundles through Rest Api to both 4.5.1 and 4.5.2 is running much slower than the previous versions (<=4.5.0) .
We did some benchmark using the same setup in server.xml and fhir-server-conifg.json. Digesting fhir bundles is now about 4 times slower. So is it because of the change in database schema? Is there anything we can try to speed it up?
Robin Arnold (Dec 09 2020 at 14:38):
Hi, the main schema change was introduced in 4.5.0 (to improve ingestion performance). Are you monitoring the database? Have you configured any form of Application Performance Management (NewRelic, for example) which can help pinpoint where most of the time is being spent. Have you configured any search parameter filters to reduce the number of parameters we store? Do your resources contain PHI or are they test data? If there's no PHI involved, you could enable tracing in the server.xml and share the output - that would help us to see where most of the time is being spent.
Robin Arnold (Dec 09 2020 at 14:48):
Are you using client-asserted identifiers or using ids generated by the server (e.g. POST)?
Digamber Kalivemula (Dec 09 2020 at 19:45):
We are currently running 4.5.2.We are unable to post a bundle having 20k resources.We are facing below error while trying to post the bundle.
0000005a com.ibm.fhir.server.resources.FHIRResource E Commit global transaction failed. See server log for details
com.ibm.fhir.persistence.jdbc.exception.FHIRPersistenceDataAccessException: Commit global transaction failed. See server log for details [probeId=a-2c-0-1-3ea7a13d-c204-4abd-b597-e9b3568cf226]
at com.ibm.fhir.persistence.jdbc.connection.FHIRUserTransactionAdapter.end(FHIRUserTransactionAdapter.java:119)
at com.ibm.fhir.persistence.helper.FHIRTransactionHelper.commit(FHIRTransactionHelper.java:43)
at com.ibm.fhir.server.util.FHIRRestHelper.processBundleEntries(FHIRRestHelper.java:1520)
at com.ibm.fhir.server.util.FHIRRestHelper.doBundle(FHIRRestHelper.java:1078)
at com.ibm.fhir.server.resources.Batch.bundle(Batch.java:77)
at com.ibm.fhir.server.resources.Batch$Proxy$_$$_WeldClientProxy.bundle(Unknown Source)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at com.ibm.ws.jaxrs20.cdi.component.JaxRsFactoryImplicitBeanCDICustomizer.serviceInvoke(JaxRsFactoryImplicitBeanCDICustomizer.java:339)
at com.ibm.ws.jaxrs20.server.LibertyJaxRsServerFactoryBean.performInvocation(LibertyJaxRsServerFactoryBean.java:641)
at com.ibm.ws.jaxrs20.server.LibertyJaxRsInvoker.performInvocation(LibertyJaxRsInvoker.java:160)
at org.apache.cxf.service.invoker.AbstractInvoker.invoke(AbstractInvoker.java:96)
at com.ibm.ws.jaxrs20.server.LibertyJaxRsInvoker.invoke(LibertyJaxRsInvoker.java:273)
at org.apache.cxf.jaxrs.JAXRSInvoker.invoke(JAXRSInvoker.java:210)
at com.ibm.ws.jaxrs20.server.LibertyJaxRsInvoker.invoke(LibertyJaxRsInvoker.java:444)
at org.apache.cxf.jaxrs.JAXRSInvoker.invoke(JAXRSInvoker.java:112)
at org.apache.cxf.interceptor.ServiceInvokerInterceptor$1.run(ServiceInvokerInterceptor.java:61)
at org.apache.cxf.interceptor.ServiceInvokerInterceptor.handleMessage(ServiceInvokerInterceptor.java:99)
at org.apache.cxf.phase.PhaseInterceptorChain.doIntercept(PhaseInterceptorChain.java:318)
at org.apache.cxf.transport.ChainInitiationObserver.onMessage(ChainInitiationObserver.java:123)
at org.apache.cxf.transport.http.AbstractHTTPDestination.invoke(AbstractHTTPDestination.java:273)
at com.ibm.ws.jaxrs20.endpoint.AbstractJaxRsWebEndpoint.invoke(AbstractJaxRsWebEndpoint.java:136)
at com.ibm.websphere.jaxrs.server.IBMRestServlet.handleRequest(IBMRestServlet.java:146)
at com.ibm.websphere.jaxrs.server.IBMRestServlet.doPost(IBMRestServlet.java:104)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:706)
at com.ibm.websphere.jaxrs.server.IBMRestServlet.service(IBMRestServlet.java:96)
at com.ibm.ws.webcontainer.servlet.ServletWrapper.service(ServletWrapper.java:1230)
at com.ibm.ws.webcontainer.servlet.ServletWrapper.handleRequest(ServletWrapper.java:729)
at com.ibm.ws.webcontainer.servlet.ServletWrapper.handleRequest(ServletWrapper.java:426)
at com.ibm.ws.webcontainer.filter.WebAppFilterChain.invokeTarget(WebAppFilterChain.java:182)
at com.ibm.ws.webcontainer.filter.WebAppFilterChain.doFilter(WebAppFilterChain.java:93)
at com.ibm.fhir.server.filter.rest.FHIRRestServletFilter.doFilter(FHIRRestServletFilter.java:139)
at javax.servlet.http.HttpFilter.doFilter(HttpFilter.java:127)
at com.ibm.ws.webcontainer.filter.FilterInstanceWrapper.doFilter(FilterInstanceWrapper.java:201)
at com.ibm.ws.webcontainer.filter.WebAppFilterChain.doFilter(WebAppFilterChain.java:90)
at com.ibm.fhir.server.filter.rest.FHIRRestAuthorizationServletFilter.doFilter(FHIRRestAuthorizationServletFilter.java:86)
at com.ibm.ws.webcontainer.filter.FilterInstanceWrapper.doFilter(FilterInstanceWrapper.java:201)
at com.ibm.ws.webcontainer.filter.WebAppFilterChain.doFilter(WebAppFilterChain.java:90)
at com.ibm.ws.webcontainer.filter.WebAppFilterManager.doFilter(WebAppFilterManager.java:1001)
at com.ibm.ws.webcontainer.filter.WebAppFilterManager.invokeFilters(WebAppFilterManager.java:1139)
at com.ibm.ws.webcontainer.webapp.WebApp.handleRequest(WebApp.java:5037)
at com.ibm.ws.webcontainer.osgi.DynamicVirtualHost$2.handleRequest(DynamicVirtualHost.java:314)
at com.ibm.ws.webcontainer.WebContainer.handleRequest(WebContainer.java:1005)
at com.ibm.ws.webcontainer.osgi.DynamicVirtualHost$2.run(DynamicVirtualHost.java:279)
at com.ibm.ws.http.dispatcher.internal.channel.HttpDispatcherLink$TaskWrapper.run(HttpDispatcherLink.java:1134)
at com.ibm.ws.http.dispatcher.internal.channel.HttpDispatcherLink.wrapHandlerAndExecute(HttpDispatcherLink.java:415)
at com.ibm.ws.http.dispatcher.internal.channel.HttpDispatcherLink.ready(HttpDispatcherLink.java:374)
at com.ibm.ws.http.channel.internal.inbound.HttpInboundLink.handleDiscrimination(HttpInboundLink.java:577)
at com.ibm.ws.http.channel.internal.inbound.HttpInboundLink.handleNewRequest(HttpInboundLink.java:511)
at com.ibm.ws.http.channel.internal.inbound.HttpInboundLink.processRequest(HttpInboundLink.java:359)
at com.ibm.ws.http.channel.internal.inbound.HttpInboundLink.ready(HttpInboundLink.java:326)
at com.ibm.ws.channel.ssl.internal.SSLConnectionLink.determineNextChannel(SSLConnectionLink.java:1100)
at com.ibm.ws.channel.ssl.internal.SSLConnectionLink.readyInboundPostHandshake(SSLConnectionLink.java:757)
at com.ibm.ws.channel.ssl.internal.SSLConnectionLink$MyHandshakeCompletedCallback.complete(SSLConnectionLink.java:427)
at com.ibm.ws.channel.ssl.internal.SSLUtils.handleHandshake(SSLUtils.java:953)
at com.ibm.ws.channel.ssl.internal.SSLHandshakeIOCallback.complete(SSLHandshakeIOCallback.java:85)
at com.ibm.ws.tcpchannel.internal.WorkQueueManager.requestComplete(WorkQueueManager.java:504)
at com.ibm.ws.tcpchannel.internal.WorkQueueManager.attemptIO(WorkQueueManager.java:574)
at com.ibm.ws.tcpchannel.internal.WorkQueueManager.workerRun(WorkQueueManager.java:958)
at com.ibm.ws.tcpchannel.internal.WorkQueueManager$Worker.run(WorkQueueManager.java:1047)
at com.ibm.ws.threading.internal.ExecutorServiceImpl$RunnableWrapper.run(ExecutorServiceImpl.java:239)
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:823)
0000005a com.ibm.fhir.server.filter.rest.FHIRRestServletFilter I Completed request[43.361 secs]: tenantId:[] dsId:[default] user:[fhiruser] method:[POST] uri:[***] status:[500]
Robin Arnold (Dec 09 2020 at 20:10):
Can you provide more context from the server messages.log? It's interesting that it's the commit that's failing...all the hard work has been done at this point. Were there any errors reported in the database logs around the time of this request?
Lee Surprenant (Dec 09 2020 at 20:14):
@Digamber Kalivemula are you working with @guokun zhang ?
if not, please don't hijack this thread which is about a reported slowdown in ingestion performance in 4.5.1/4.5.2
Lee Surprenant (Dec 09 2020 at 20:15):
lets use https://chat.fhir.org/#narrow/stream/212434-ibm/topic/FHIR.20DB.20issues for that one
Last updated: Apr 12 2022 at 19:14 UTC
