Failure acquiring datasource

alexey1607 commented 1 year ago

Hi, Failure acquiring datasource

DB: postgresql12 fhir-server: 5.1.1 running in kubernetes, helm chart

After install, test the install with:

curl -u "fhirserver:change-password" http://localhost:9080/fhir-server/api/v4/Patient

<OperationOutcome xmlns="http://hl7.org/fhir">
<id value="c0-a8-f7-49-b39289ee-74dd-494a-b74e-de25e40cd6bd"/>
<issue>
<severity value="fatal"/>
<code value="exception"/>
<details>
<text value="FHIRPersistenceDBConnectException: Failure acquiring datasource"/>
</details>
</issue>
</OperationOutcome>

logs


{"type":"liberty_message","host":"lfh-fhir-server-759b4d74f6-l7bq5","ibm_userDir":"\/opt\/ol\/wlp\/usr\/","ibm_serverName":"defaultServer","message":"Received request: tenantId:[default] dsId:[default] user:[fhiruser] method:[GET] uri:[http:\/\/localhost:9080\/fhir-server\/api\/v4\/Patient]","ibm_threadId":"00000037","ibm_datetime":"2023-05-16T08:00:57.918+0000","module":"org.linuxforhealth.fhir.server.filter.rest.FHIRRestServletFilter","level":"INFO","ibm_sequence":"1684224057918_00000000000A4","ext_appName":"fhir-server-webapp","ext_thread":"Default Executor-thread-5"}
{"type":"liberty_message","host":"lfh-fhir-server-759b4d74f6-l7bq5","ibm_userDir":"\/opt\/ol\/wlp\/usr\/","ibm_serverName":"defaultServer","message":"Failure acquiring connection for datasource: jdbc\/fhir_default_default [probeId=c0-a8-f7-49-13095014-280e-4813-955f-84b4c36b1110]","ibm_threadId":"00000037","ibm_datetime":"2023-05-16T08:00:57.925+0000","module":"org.linuxforhealth.fhir.persistence.jdbc.dao.impl.FHIRDbDAOImpl","level":"SEVERE","ibm_sequence":"1684224057925_00000000000A5","ibm_exceptionName":"javax.naming.NameNotFoundException","ibm_stackTrace":"javax.naming.NameNotFoundException: jdbc\/fhir_default_default\n\tat com.ibm.ws.jndi.internal.ContextNode.lookup(ContextNode.java:217)\n\tat com.ibm.ws.jndi.internal.WSContext.lookup(WSContext.java:308)\n\tat com.ibm.ws.jndi.WSContextBase.lookup(WSContextBase.java:61)\n\tat org.apache.aries.jndi.DelegateContext.lookup(DelegateContext.java:149)\n\tat java.naming\/javax.naming.InitialContext.lookup(InitialContext.java:409)\n\tat org.linuxforhealth.fhir.persistence.jdbc.connection.FHIRDbTenantDatasourceConnectionStrategy.getConnection(FHIRDbTenantDatasourceConnectionStrategy.java:149)\n\tat org.linuxforhealth.fhir.persistence.jdbc.impl.FHIRPersistenceJDBCImpl.openConnection(FHIRPersistenceJDBCImpl.java:2369)\n\tat org.linuxforhealth.fhir.persistence.jdbc.impl.FHIRPersistenceJDBCImpl.search(FHIRPersistenceJDBCImpl.java:878)\n\tat org.linuxforhealth.fhir.server.util.FHIRRestHelper.doSearch(FHIRRestHelper.java:1405)\n\tat org.linuxforhealth.fhir.server.util.FHIRRestHelper.doSearch(FHIRRestHelper.java:1355)\n\tat org.linuxforhealth.fhir.server.resources.Search.doSearch(Search.java:72)\n\tat org.linuxforhealth.fhir.server.resources.Search.searchGet(Search.java:49)\n\tat org.linuxforhealth.fhir.server.resources.Search$Proxy$_$$_WeldClientProxy.searchGet(Unknown Source)\n\tat java.base\/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)\n\tat java.base\/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)\n\tat java.base\/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)\n\tat java.base\/java.lang.reflect.Method.invoke(Method.java:566)\n\tat com.ibm.ws.jaxrs20.cdi.component.JaxRsFactoryImplicitBeanCDICustomizer.serviceInvoke(JaxRsFactoryImplicitBeanCDICustomizer.java:350)\n\tat com.ibm.ws.jaxrs20.server.LibertyJaxRsServerFactoryBean.performInvocation(LibertyJaxRsServerFactoryBean.java:641)\n\tat com.ibm.ws.jaxrs20.server.LibertyJaxRsInvoker.performInvocation(LibertyJaxRsInvoker.java:160)\n\tat org.apache.cxf.service.invoker.AbstractInvoker.invoke(AbstractInvoker.java:101)\n\tat com.ibm.ws.jaxrs20.server.LibertyJaxRsInvoker.invoke(LibertyJaxRsInvoker.java:273)\n\tat org.apache.cxf.jaxrs.JAXRSInvoker.invoke(JAXRSInvoker.java:213)\n\tat com.ibm.ws.jaxrs20.server.LibertyJaxRsInvoker.invoke(LibertyJaxRsInvoker.java:444)\n\tat org.apache.cxf.jaxrs.JAXRSInvoker.invoke(JAXRSInvoker.java:112)\n\tat org.apache.cxf.interceptor.ServiceInvokerInterceptor$1.run(ServiceInvokerInterceptor.java:59)\n\tat org.apache.cxf.interceptor.ServiceInvokerInterceptor.handleMessage(ServiceInvokerInterceptor.java:96)\n\tat org.apache.cxf.phase.PhaseInterceptorChain.doIntercept(PhaseInterceptorChain.java:308)\n\tat org.apache.cxf.transport.ChainInitiationObserver.onMessage(ChainInitiationObserver.java:123)\n\tat org.apache.cxf.transport.http.AbstractHTTPDestination.invoke(AbstractHTTPDestination.java:277)\n\tat com.ibm.ws.jaxrs20.endpoint.AbstractJaxRsWebEndpoint.invoke(AbstractJaxRsWebEndpoint.java:137)\n\tat com.ibm.websphere.jaxrs.server.IBMRestServlet.handleRequest(IBMRestServlet.java:146)\n\tat com.ibm.websphere.jaxrs.server.IBMRestServlet.doGet(IBMRestServlet.java:112)\n\tat javax.servlet.http.HttpServlet.service(HttpServlet.java:686)\n\tat com.ibm.websphere.jaxrs.server.IBMRestServlet.service(IBMRestServlet.java:96)\n\tat com.ibm.ws.webcontainer.servlet.ServletWrapper.service(ServletWrapper.java:1258)\n\tat com.ibm.ws.webcontainer.servlet.ServletWrapper.handleRequest(ServletWrapper.java:746)\n\tat com.ibm.ws.webcontainer.servlet.ServletWrapper.handleRequest(ServletWrapper.java:443)\n\tat com.ibm.ws.webcontainer.filter.WebAppFilterChain.invokeTarget(WebAppFilterChain.java:193)\n\tat com.ibm.ws.webcontainer.filter.WebAppFilterChain.doFilter(WebAppFilterChain.java:98)\n\tat org.linuxforhealth.fhir.server.filter.rest.FHIRRestServletFilter.doFilter(FHIRRestServletFilter.java:177)\n\tat javax.servlet.http.HttpFilter.doFilter(HttpFilter.java:127)\n\tat com.ibm.ws.webcontainer.filter.FilterInstanceWrapper.doFilter(FilterInstanceWrapper.java:201)\n\tat com.ibm.ws.webcontainer.filter.WebAppFilterChain.doFilter(WebAppFilterChain.java:91)\n\tat com.ibm.ws.security.jaspi.JaspiServletFilter.doFilter(JaspiServletFilter.java:56)\n\tat com.ibm.ws.webcontainer.filter.FilterInstanceWrapper.doFilter(FilterInstanceWrapper.java:201)\n\tat com.ibm.ws.webcontainer.filter.WebAppFilterChain.doFilter(WebAppFilterChain.java:91)\n\tat com.ibm.ws.webcontainer.filter.WebAppFilterManager.doFilter(WebAppFilterManager.java:1002)\n\tat com.ibm.ws.webcontainer.filter.WebAppFilterManager.invokeFilters(WebAppFilterManager.java:1140)\n\tat com.ibm.ws.webcontainer.filter.WebAppFilterManager.invokeFilters(WebAppFilterManager.java:1011)\n\tat com.ibm.ws.webcontainer.servlet.CacheServletWrapper.handleRequest(CacheServletWrapper.java:75)\n\tat com.ibm.ws.webcontainer40.servlet.CacheServletWrapper40.handleRequest(CacheServletWrapper40.java:85)\n\tat com.ibm.ws.webcontainer.WebContainer.handleRequest(WebContainer.java:938)\n\tat com.ibm.ws.webcontainer.osgi.DynamicVirtualHost$2.run(DynamicVirtualHost.java:281)\n\tat com.ibm.ws.http.dispatcher.internal.channel.HttpDispatcherLink$TaskWrapper.run(HttpDispatcherLink.java:1246)\n\tat com.ibm.ws.http.dispatcher.internal.channel.HttpDispatcherLink.wrapHandlerAndExecute(HttpDispatcherLink.java:468)\n\tat com.ibm.ws.http.dispatcher.internal.channel.HttpDispatcherLink.ready(HttpDispatcherLink.java:427)\n\tat com.ibm.ws.http.channel.internal.inbound.HttpInboundLink.handleDiscrimination(HttpInboundLink.java:567)\n\tat com.ibm.ws.http.channel.internal.inbound.HttpInboundLink.handleNewRequest(HttpInboundLink.java:501)\n\tat com.ibm.ws.http.channel.internal.inbound.HttpInboundLink.processRequest(HttpInboundLink.java:361)\n\tat com.ibm.ws.http.channel.internal.inbound.HttpInboundLink.ready(HttpInboundLink.java:328)\n\tat com.ibm.ws.tcpchannel.internal.NewConnectionInitialReadCallback.sendToDiscriminators(NewConnectionInitialReadCallback.java:167)\n\tat com.ibm.ws.tcpchannel.internal.NewConnectionInitialReadCallback.complete(NewConnectionInitialReadCallback.java:75)\n\tat com.ibm.ws.tcpchannel.internal.WorkQueueManager.requestComplete(WorkQueueManager.java:514)\n\tat com.ibm.ws.tcpchannel.internal.WorkQueueManager.attemptIO(WorkQueueManager.java:584)\n\tat com.ibm.ws.tcpchannel.internal.WorkQueueManager.workerRun(WorkQueueManager.java:968)\n\tat com.ibm.ws.tcpchannel.internal.WorkQueueManager$Worker.run(WorkQueueManager.java:1057)\n\tat com.ibm.ws.threading.internal.ExecutorServiceImpl$RunnableWrapper.run(ExecutorServiceImpl.java:245)\n\tat java.base\/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)\n\tat java.base\/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)\n\tat java.base\/java.lang.Thread.run(Thread.java:839)\n","ext_appName":"fhir-server-webapp","ext_thread":"Default Executor-thread-5"}
{"type":"liberty_message","host":"lfh-fhir-server-759b4d74f6-l7bq5","ibm_userDir":"\/opt\/ol\/wlp\/usr\/","ibm_serverName":"defaultServer","message":"Transaction failed - afterCompletion(status = STATUS_ROLLEDBACK)","ibm_threadId":"00000037","ibm_datetime":"2023-05-16T08:00:57.927+0000","module":"org.linuxforhealth.fhir.persistence.jdbc.impl.CacheTransactionSync","level":"INFO","ibm_sequence":"1684224057927_00000000000A6","ext_appName":"fhir-server-webapp","ext_thread":"Default Executor-thread-5"}
{"type":"liberty_message","host":"lfh-fhir-server-759b4d74f6-l7bq5","ibm_userDir":"\/opt\/ol\/wlp\/usr\/","ibm_serverName":"defaultServer","message":"Failure acquiring datasource","ibm_threadId":"00000037","ibm_datetime":"2023-05-16T08:00:57.927+0000","module":"org.linuxforhealth.fhir.server.resources.FHIRResource","level":"SEVERE","ibm_sequence":"1684224057927_00000000000A7","ibm_exceptionName":"org.linuxforhealth.fhir.persistence.jdbc.exception.FHIRPersistenceDBConnectException","ibm_stackTrace":"org.linuxforhealth.fhir.persistence.jdbc.exception.FHIRPersistenceDBConnectException: Failure acquiring datasource  [probeId=c0-a8-f7-49-13095014-280e-4813-955f-84b4c36b1110]\n\tat org.linuxforhealth.fhir.persistence.jdbc.connection.FHIRDbTenantDatasourceConnectionStrategy.getConnection(FHIRDbTenantDatasourceConnectionStrategy.java:154)\n\tat org.linuxforhealth.fhir.persistence.jdbc.impl.FHIRPersistenceJDBCImpl.openConnection(FHIRPersistenceJDBCImpl.java:2369)\n\tat org.linuxforhealth.fhir.persistence.jdbc.impl.FHIRPersistenceJDBCImpl.search(FHIRPersistenceJDBCImpl.java:878)\n\tat org.linuxforhealth.fhir.server.util.FHIRRestHelper.doSearch(FHIRRestHelper.java:1405)\n\tat org.linuxforhealth.fhir.server.util.FHIRRestHelper.doSearch(FHIRRestHelper.java:1355)\n\tat org.linuxforhealth.fhir.server.resources.Search.doSearch(Search.java:72)\n\tat org.linuxforhealth.fhir.server.resources.Search.searchGet(Search.java:49)\n\tat org.linuxforhealth.fhir.server.resources.Search$Proxy$_$$_WeldClientProxy.searchGet(Unknown Source)\n\tat java.base\/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)\n\tat java.base\/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)\n\tat java.base\/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)\n\tat java.base\/java.lang.reflect.Method.invoke(Method.java:566)\n\tat com.ibm.ws.jaxrs20.cdi.component.JaxRsFactoryImplicitBeanCDICustomizer.serviceInvoke(JaxRsFactoryImplicitBeanCDICustomizer.java:350)\n\tat com.ibm.ws.jaxrs20.server.LibertyJaxRsServerFactoryBean.performInvocation(LibertyJaxRsServerFactoryBean.java:641)\n\tat com.ibm.ws.jaxrs20.server.LibertyJaxRsInvoker.performInvocation(LibertyJaxRsInvoker.java:160)\n\tat org.apache.cxf.service.invoker.AbstractInvoker.invoke(AbstractInvoker.java:101)\n\tat com.ibm.ws.jaxrs20.server.LibertyJaxRsInvoker.invoke(LibertyJaxRsInvoker.java:273)\n\tat org.apache.cxf.jaxrs.JAXRSInvoker.invoke(JAXRSInvoker.java:213)\n\tat com.ibm.ws.jaxrs20.server.LibertyJaxRsInvoker.invoke(LibertyJaxRsInvoker.java:444)\n\tat org.apache.cxf.jaxrs.JAXRSInvoker.invoke(JAXRSInvoker.java:112)\n\tat org.apache.cxf.interceptor.ServiceInvokerInterceptor$1.run(ServiceInvokerInterceptor.java:59)\n\tat org.apache.cxf.interceptor.ServiceInvokerInterceptor.handleMessage(ServiceInvokerInterceptor.java:96)\n\tat org.apache.cxf.phase.PhaseInterceptorChain.doIntercept(PhaseInterceptorChain.java:308)\n\tat org.apache.cxf.transport.ChainInitiationObserver.onMessage(ChainInitiationObserver.java:123)\n\tat org.apache.cxf.transport.http.AbstractHTTPDestination.invoke(AbstractHTTPDestination.java:277)\n\tat com.ibm.ws.jaxrs20.endpoint.AbstractJaxRsWebEndpoint.invoke(AbstractJaxRsWebEndpoint.java:137)\n\tat com.ibm.websphere.jaxrs.server.IBMRestServlet.handleRequest(IBMRestServlet.java:146)\n\tat com.ibm.websphere.jaxrs.server.IBMRestServlet.doGet(IBMRestServlet.java:112)\n\tat javax.servlet.http.HttpServlet.service(HttpServlet.java:686)\n\tat com.ibm.websphere.jaxrs.server.IBMRestServlet.service(IBMRestServlet.java:96)\n\tat com.ibm.ws.webcontainer.servlet.ServletWrapper.service(ServletWrapper.java:1258)\n\tat com.ibm.ws.webcontainer.servlet.ServletWrapper.handleRequest(ServletWrapper.java:746)\n\tat com.ibm.ws.webcontainer.servlet.ServletWrapper.handleRequest(ServletWrapper.java:443)\n\tat com.ibm.ws.webcontainer.filter.WebAppFilterChain.invokeTarget(WebAppFilterChain.java:193)\n\tat com.ibm.ws.webcontainer.filter.WebAppFilterChain.doFilter(WebAppFilterChain.java:98)\n\tat org.linuxforhealth.fhir.server.filter.rest.FHIRRestServletFilter.doFilter(FHIRRestServletFilter.java:177)\n\tat javax.servlet.http.HttpFilter.doFilter(HttpFilter.java:127)\n\tat com.ibm.ws.webcontainer.filter.FilterInstanceWrapper.doFilter(FilterInstanceWrapper.java:201)\n\tat com.ibm.ws.webcontainer.filter.WebAppFilterChain.doFilter(WebAppFilterChain.java:91)\n\tat com.ibm.ws.security.jaspi.JaspiServletFilter.doFilter(JaspiServletFilter.java:56)\n\tat com.ibm.ws.webcontainer.filter.FilterInstanceWrapper.doFilter(FilterInstanceWrapper.java:201)\n\tat com.ibm.ws.webcontainer.filter.WebAppFilterChain.doFilter(WebAppFilterChain.java:91)\n\tat com.ibm.ws.webcontainer.filter.WebAppFilterManager.doFilter(WebAppFilterManager.java:1002)\n\tat com.ibm.ws.webcontainer.filter.WebAppFilterManager.invokeFilters(WebAppFilterManager.java:1140)\n\tat com.ibm.ws.webcontainer.filter.WebAppFilterManager.invokeFilters(WebAppFilterManager.java:1011)\n\tat com.ibm.ws.webcontainer.servlet.CacheServletWrapper.handleRequest(CacheServletWrapper.java:75)\n\tat com.ibm.ws.webcontainer40.servlet.CacheServletWrapper40.handleRequest(CacheServletWrapper40.java:85)\n\tat com.ibm.ws.webcontainer.WebContainer.handleRequest(WebContainer.java:938)\n\tat com.ibm.ws.webcontainer.osgi.DynamicVirtualHost$2.run(DynamicVirtualHost.java:281)\n\tat com.ibm.ws.http.dispatcher.internal.channel.HttpDispatcherLink$TaskWrapper.run(HttpDispatcherLink.java:1246)\n\tat com.ibm.ws.http.dispatcher.internal.channel.HttpDispatcherLink.wrapHandlerAndExecute(HttpDispatcherLink.java:468)\n\tat com.ibm.ws.http.dispatcher.internal.channel.HttpDispatcherLink.ready(HttpDispatcherLink.java:427)\n\tat com.ibm.ws.http.channel.internal.inbound.HttpInboundLink.handleDiscrimination(HttpInboundLink.java:567)\n\tat com.ibm.ws.http.channel.internal.inbound.HttpInboundLink.handleNewRequest(HttpInboundLink.java:501)\n\tat com.ibm.ws.http.channel.internal.inbound.HttpInboundLink.processRequest(HttpInboundLink.java:361)\n\tat com.ibm.ws.http.channel.internal.inbound.HttpInboundLink.ready(HttpInboundLink.java:328)\n\tat com.ibm.ws.tcpchannel.internal.NewConnectionInitialReadCallback.sendToDiscriminators(NewConnectionInitialReadCallback.java:167)\n\tat com.ibm.ws.tcpchannel.internal.NewConnectionInitialReadCallback.complete(NewConnectionInitialReadCallback.java:75)\n\tat com.ibm.ws.tcpchannel.internal.WorkQueueManager.requestComplete(WorkQueueManager.java:514)\n\tat com.ibm.ws.tcpchannel.internal.WorkQueueManager.attemptIO(WorkQueueManager.java:584)\n\tat com.ibm.ws.tcpchannel.internal.WorkQueueManager.workerRun(WorkQueueManager.java:968)\n\tat com.ibm.ws.tcpchannel.internal.WorkQueueManager$Worker.run(WorkQueueManager.java:1057)\n\tat com.ibm.ws.threading.internal.ExecutorServiceImpl$RunnableWrapper.run(ExecutorServiceImpl.java:245)\n\tat java.base\/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)\n\tat java.base\/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)\n\tat java.base\/java.lang.Thread.run(Thread.java:839)\n","ext_appName":"fhir-server-webapp","ext_thread":"Default Executor-thread-5"}
{"type":"liberty_message","host":"lfh-fhir-server-759b4d74f6-l7bq5","ibm_userDir":"\/opt\/ol\/wlp\/usr\/","ibm_serverName":"defaultServer","message":"Completed request[0.012636161 secs]: tenantId:[default] dsId:[default] user:[fhiruser] method:[GET] uri:[http:\/\/localhost:9080\/fhir-server\/api\/v4\/Patient] status:[500]","ibm_threadId":"00000037","ibm_datetime":"2023-05-16T08:00:57.931+0000","module":"org.linuxforhealth.fhir.server.filter.rest.FHIRRestServletFilter","level":"INFO","ibm_sequence":"1684224057931_00000000000A8","ext_appName":"fhir-server-webapp","ext_thread":"Default Executor-thread-5"}

from another pod in k8s the connection to database passes, i used psql client

alexey1607 commented 1 year ago

the problem was in istio

lmsurpre commented 1 year ago

@alexey1607 thanks for the update. can we close this one as "invalid" in that case?

alexey1607 commented 1 year ago

@lmsurpre you can close. But I have new problem,

I have a postgres cluster and there is a connection puller (pgbouncer) in front of it.

New error

org.postgresql.util.PSQLException: ERROR: prepared statement "S_1" already exists

how do I pass this a connection string? jdbc:postgresql://pgdb-01:6544,pgdb-02:6544/lfh?ApplicationName=lfh&prepareThreshold=0&reWriteBatchedInserts=true&targetServerType=master

or this

jdbc:postgresql://pgdb-vip:6544/lfh?ApplicationName=lfh&prepareThreshold=0

What config should I edit? /opt/ol/wlp/usr/servers/defaultServer/configDropins/overrides/datasources.xml or /opt/ol/wlp/usr/servers/defaultServer/config/default/fhir-server-config.json

I can't find a description of this in the documentation.

thank you!

lmsurpre commented 1 year ago

The docs for this are at https://linuxforhealth.github.io/FHIR/guides/FHIRServerUsersGuide/#331-the-jdbc-persistence-layer

fhir-server-config.json only has a few persistence fields...the most important of which is the jndiName for the datasource. so all the connection info is in datasources.xml

LinuxForHealth / FHIR

Failure acquiring datasource #4220