hapifhir / hapi-fhir

🔥 HAPI FHIR - Java API for HL7 FHIR Clients and Servers
http://hapifhir.io
Apache License 2.0
2k stars 1.31k forks source link

Null partition ID for Subscription with multi-tenancy and MDM, STORAGE_PARTITION_IDENTIFY_READ never called #3498

Open ricardofago opened 2 years ago

ricardofago commented 2 years ago

Hi everyone!

I've been experimenting with the latest HAPI FHIR releases to test the update process and it seems to crash due to to something in the recent Subscription and MDM changes. From my limited debugging, it gets to https://github.com/hapifhir/hapi-fhir/blob/b0020a296fa6b0e0f62dce1cd63b43c94cec1b88/hapi-fhir-jpaserver-base/src/main/java/ca/uhn/fhir/jpa/partition/RequestPartitionHelperSvc.java#L114 (default tenant) properly for some initial system calls (SearchParameter, Subscription), registers the partition interceptor and the identification strategy for multi-tenancy, but then it seems to crash at another Subscription related call during the MDM stuff without ever calling the STORAGE_PARTITION_IDENTIFY_READ pointcut in https://github.com/hapifhir/hapi-fhir/blob/b0020a296fa6b0e0f62dce1cd63b43c94cec1b88/hapi-fhir-jpaserver-base/src/main/java/ca/uhn/fhir/jpa/partition/RequestPartitionHelperSvc.java#L127, even if I hardcode the tenant ID. This actually prevents the JPA server from starting, but only happens if mdm_enabled: true.

This can be reproduced in v5.7.0 (and previous recent releases) using the JPA server with the standard settings plus enabling multi-tenancy and MDM. It not familiar with the internals of the MDM code but I'm guessing there's something preventing the Subscription request from falling back to the default tenant ID. Around the first exception I have:

2022-03-28 18:51:02.859 [main] INFO  o.s.web.servlet.DispatcherServlet [FrameworkServlet.java:525] Initializing Servlet 'dispatcherServlet'
2022-03-28 18:51:03.282 [main] INFO  ca.uhn.fhir.jpa.mdm.config.MdmLoader [MdmLoader.java:54] MDM provider registered
2022-03-28 18:51:14.499 [main] ERROR o.s.web.servlet.DispatcherServlet [FrameworkServlet.java:534] Context initialization failed
ca.uhn.fhir.rest.server.exceptions.InternalErrorException: HAPI-1319: No interceptor provided a value for pointcut: STORAGE_PARTITION_IDENTIFY_READ
    at ca.uhn.fhir.jpa.partition.RequestPartitionHelperSvc.validateRequestPartitionNotNull(RequestPartitionHelperSvc.java:381)
    at ca.uhn.fhir.jpa.partition.RequestPartitionHelperSvc.determineReadPartitionForRequest(RequestPartitionHelperSvc.java:130)
    at ca.uhn.fhir.jpa.partition.IRequestPartitionHelperSvc.determineReadPartitionForRequestForRead(IRequestPartitionHelperSvc.java:43)
    at ca.uhn.fhir.jpa.dao.BaseHapiFhirResourceDao.readEntity(BaseHapiFhirResourceDao.java:1295)
    at ca.uhn.fhir.jpa.dao.BaseHapiFhirResourceDao.readEntity(BaseHapiFhirResourceDao.java:1281)
    at ca.uhn.fhir.jpa.dao.BaseHapiFhirResourceDao.doRead(BaseHapiFhirResourceDao.java:1238)
    at ca.uhn.fhir.jpa.dao.BaseHapiFhirResourceDao.lambda$read$13(BaseHapiFhirResourceDao.java:1224)
    at org.springframework.transaction.support.TransactionTemplate.execute(TransactionTemplate.java:140)
    at ca.uhn.fhir.jpa.dao.tx.HapiTransactionService.doExecuteCallback(HapiTransactionService.java:150)
    at ca.uhn.fhir.jpa.dao.tx.HapiTransactionService.execute(HapiTransactionService.java:84)
    at ca.uhn.fhir.jpa.dao.tx.HapiTransactionService.execute(HapiTransactionService.java:76)
    at ca.uhn.fhir.jpa.dao.BaseHapiFhirResourceDao.read(BaseHapiFhirResourceDao.java:1224)
    at ca.uhn.fhir.jpa.dao.BaseHapiFhirResourceDao.read(BaseHapiFhirResourceDao.java:1216)
    at ca.uhn.fhir.jpa.dao.BaseHapiFhirResourceDao.read(BaseHapiFhirResourceDao.java:1211)
    at ca.uhn.fhir.jpa.dao.BaseHapiFhirResourceDao$$FastClassBySpringCGLIB$$5578fb67.invoke(<generated>)
    at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:218)
    at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:783)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163)
    at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:753)
    at org.springframework.dao.support.PersistenceExceptionTranslationInterceptor.invoke(PersistenceExceptionTranslationInterceptor.java:137)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
    at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:753)
    at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:698)
    at ca.uhn.fhir.jpa.dao.r4.FhirResourceDaoSubscriptionR4$$EnhancerBySpringCGLIB$$b7dfcbc1.read(<generated>)
    at ca.uhn.fhir.jpa.mdm.config.MdmSubscriptionLoader.updateIfNotPresent(MdmSubscriptionLoader.java:93)
    at ca.uhn.fhir.jpa.mdm.config.MdmSubscriptionLoader.daoUpdateMdmSubscriptions(MdmSubscriptionLoader.java:87)
    at ca.uhn.fhir.jpa.mdm.config.MdmLoader.updateSubscriptions(MdmLoader.java:56)
    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
    at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.base/java.lang.reflect.Method.invoke(Method.java:566)
    at org.springframework.context.event.ApplicationListenerMethodAdapter.doInvoke(ApplicationListenerMethodAdapter.java:344)
    at org.springframework.context.event.ApplicationListenerMethodAdapter.processEvent(ApplicationListenerMethodAdapter.java:229)
    at org.springframework.context.event.ApplicationListenerMethodAdapter.onApplicationEvent(ApplicationListenerMethodAdapter.java:166)
    at org.springframework.context.event.SimpleApplicationEventMulticaster.doInvokeListener(SimpleApplicationEventMulticaster.java:176)
    at org.springframework.context.event.SimpleApplicationEventMulticaster.invokeListener(SimpleApplicationEventMulticaster.java:169)
    at org.springframework.context.event.SimpleApplicationEventMulticaster.multicastEvent(SimpleApplicationEventMulticaster.java:143)
    at org.springframework.context.support.AbstractApplicationContext.publishEvent(AbstractApplicationContext.java:421)
    at org.springframework.context.support.AbstractApplicationContext.publishEvent(AbstractApplicationContext.java:427)
    at org.springframework.context.support.AbstractApplicationContext.publishEvent(AbstractApplicationContext.java:378)
    at org.springframework.context.support.AbstractApplicationContext.finishRefresh(AbstractApplicationContext.java:938)
    at org.springframework.context.support.AbstractApplicationContext.refresh(AbstractApplicationContext.java:586)
    at org.springframework.web.servlet.FrameworkServlet.configureAndRefreshWebApplicationContext(FrameworkServlet.java:702)
    at org.springframework.web.servlet.FrameworkServlet.initWebApplicationContext(FrameworkServlet.java:578)
    at org.springframework.web.servlet.FrameworkServlet.initServletBean(FrameworkServlet.java:530)
    at org.springframework.web.servlet.HttpServletBean.init(HttpServletBean.java:170)
    at javax.servlet.GenericServlet.init(GenericServlet.java:203)
    at org.apache.catalina.core.StandardWrapper.initServlet(StandardWrapper.java:1164)
    at org.apache.catalina.core.StandardWrapper.load(StandardWrapper.java:1013)
    at org.springframework.boot.web.embedded.tomcat.TomcatEmbeddedContext.load(TomcatEmbeddedContext.java:82)
    at java.base/java.util.stream.ForEachOps$ForEachOp$OfRef.accept(ForEachOps.java:183)
    at java.base/java.util.ArrayList$ArrayListSpliterator.forEachRemaining(ArrayList.java:1655)
    at java.base/java.util.stream.ReferencePipeline$Head.forEach(ReferencePipeline.java:658)
    at java.base/java.util.stream.ReferencePipeline$7$1.accept(ReferencePipeline.java:274)
    at java.base/java.util.TreeMap$ValueSpliterator.forEachRemaining(TreeMap.java:2890)
    at java.base/java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:484)
    at java.base/java.util.stream.AbstractPipeline.wrapAndCopyInto(AbstractPipeline.java:474)
    at java.base/java.util.stream.ForEachOps$ForEachOp.evaluateSequential(ForEachOps.java:150)
    at java.base/java.util.stream.ForEachOps$ForEachOp$OfRef.evaluateSequential(ForEachOps.java:173)
    at java.base/java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:234)
    at java.base/java.util.stream.ReferencePipeline.forEach(ReferencePipeline.java:497)
    at org.springframework.boot.web.embedded.tomcat.TomcatEmbeddedContext.lambda$deferredLoadOnStartup$0(TomcatEmbeddedContext.java:65)
    at org.springframework.boot.web.embedded.tomcat.TomcatEmbeddedContext.doWithThreadContextClassLoader(TomcatEmbeddedContext.java:106)
    at org.springframework.boot.web.embedded.tomcat.TomcatEmbeddedContext.deferredLoadOnStartup(TomcatEmbeddedContext.java:64)
    at org.springframework.boot.web.embedded.tomcat.TomcatWebServer.performDeferredLoadOnStartup(TomcatWebServer.java:305)
    at org.springframework.boot.web.embedded.tomcat.TomcatWebServer.start(TomcatWebServer.java:216)
    at org.springframework.boot.web.servlet.context.WebServerStartStopLifecycle.start(WebServerStartStopLifecycle.java:43)
    at org.springframework.context.support.DefaultLifecycleProcessor.doStart(DefaultLifecycleProcessor.java:178)
    at org.springframework.context.support.DefaultLifecycleProcessor.access$200(DefaultLifecycleProcessor.java:54)
    at org.springframework.context.support.DefaultLifecycleProcessor$LifecycleGroup.start(DefaultLifecycleProcessor.java:356)
    at java.base/java.lang.Iterable.forEach(Iterable.java:75)
    at org.springframework.context.support.DefaultLifecycleProcessor.startBeans(DefaultLifecycleProcessor.java:155)
    at org.springframework.context.support.DefaultLifecycleProcessor.onRefresh(DefaultLifecycleProcessor.java:123)
    at org.springframework.context.support.AbstractApplicationContext.finishRefresh(AbstractApplicationContext.java:935)
    at org.springframework.context.support.AbstractApplicationContext.refresh(AbstractApplicationContext.java:586)
    at org.springframework.boot.web.servlet.context.ServletWebServerApplicationContext.refresh(ServletWebServerApplicationContext.java:145)
    at org.springframework.boot.SpringApplication.refresh(SpringApplication.java:730)
    at org.springframework.boot.SpringApplication.refreshContext(SpringApplication.java:412)
    at org.springframework.boot.SpringApplication.run(SpringApplication.java:302)
    at org.springframework.boot.SpringApplication.run(SpringApplication.java:1301)
    at org.springframework.boot.SpringApplication.run(SpringApplication.java:1290)
    at ca.uhn.fhir.jpa.starter.Application.main(Application.java:32)
2022-03-28 18:51:14.500 [main] ERROR o.a.c.c.C.[Tomcat].[localhost].[/] [DirectJDKLog.java:175] Servlet.init() for servlet [dispatcherServlet] threw exception

Perhaps, more specifically:

at ca.uhn.fhir.jpa.dao.r4.FhirResourceDaoSubscriptionR4$$EnhancerBySpringCGLIB$$b7dfcbc1.read(<generated>)
    at ca.uhn.fhir.jpa.mdm.config.MdmSubscriptionLoader.updateIfNotPresent(MdmSubscriptionLoader.java:93)
    at ca.uhn.fhir.jpa.mdm.config.MdmSubscriptionLoader.daoUpdateMdmSubscriptions(MdmSubscriptionLoader.java:87)
    at ca.uhn.fhir.jpa.mdm.config.MdmLoader.updateSubscriptions(MdmLoader.java:56)
    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
    at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.base/java.lang.reflect.Method.invoke(Method.java:566)

Does it make sense to have those issues while starting a fresh install using the in-memory H2 database? Here's the environment:

Thank you very much!

tadgh commented 2 years ago

Heya @ricardofago , no you should not have those errors at boot time with a fresh database. I'll see if I can replicate this. If you could make bulleted replication steps (and let me know which branch you're on for hapi-fhir-jpaserver-starter) that would be helpful.

ricardofago commented 2 years ago

Hi @tadgh, I've been out of the loop for a while but it should be easy to replicate. I was trying a new setup, so something like that:

import ca.uhn.fhir.i18n.Msg; import ca.uhn.fhir.interceptor.api.Hook; import ca.uhn.fhir.interceptor.api.Interceptor; import ca.uhn.fhir.interceptor.api.Pointcut; import ca.uhn.fhir.interceptor.model.RequestPartitionId; import ca.uhn.fhir.rest.api.server.RequestDetails; import ca.uhn.fhir.rest.server.exceptions.InternalErrorException; import ca.uhn.fhir.rest.server.tenant.ITenantIdentificationStrategy; import org.hl7.fhir.dstu2016may.model.Enumerations;

import javax.annotation.Nonnull;

import java.util.Arrays; import java.util.List;

import static org.apache.commons.lang3.StringUtils.isBlank;

/**

}

```java
package custom.package;

import ca.uhn.fhir.i18n.HapiLocalizer;
import ca.uhn.fhir.rest.api.server.RequestDetails;
import ca.uhn.fhir.rest.server.RestfulServer;
import ca.uhn.fhir.rest.server.exceptions.InvalidRequestException;
import ca.uhn.fhir.rest.server.tenant.ITenantIdentificationStrategy;
import ca.uhn.fhir.rest.server.tenant.UrlBaseTenantIdentificationStrategy;
import ca.uhn.fhir.util.UrlPathTokenizer;
import org.apache.commons.lang3.Validate;
import org.h2.util.StringUtils;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

import static org.apache.commons.lang3.StringUtils.defaultIfBlank;

/**
 * This class is a tenant identification strategy which assumes that a custom
 * HTTP header <tt>X-HAPI-Tenant</tt> will be present in the actual request.
 * Otherwise, the tenant is assumed to be the default one.
 * <p>The goal is to enable a tenancy environment which relies on additional
 * middleware infrastructure to keep the standard FHIR interaction flow.</p>
 */
public class HeaderTenantIdentificationStrategy implements ITenantIdentificationStrategy {

    private static final Logger ourLog = LoggerFactory.getLogger(HeaderTenantIdentificationStrategy.class);

    @Override
    public void extractTenant(UrlPathTokenizer theUrlPathTokenizer, RequestDetails theRequestDetails) {
        String tenantId = theRequestDetails.getHeader("X-HAPI-Tenant");
        if (StringUtils.isNullOrEmpty(tenantId)) {
            tenantId = "DEFAULT";
            ourLog.debug("X-HAPI-Tenant not present in request, assuming DEFAULT");
        } else {
            ourLog.debug("X-HAPI-Tenant present in request, tenant ID = {}", tenantId);
        }
        theRequestDetails.setTenantId(tenantId);
    }

    @Override
    public String massageServerBaseUrl(String theFhirServerBase, RequestDetails theRequestDetails) {
        return theFhirServerBase;
    }

}
tadgh commented 2 years ago

Thanks Ricardo, I'll have a look at this the moment i get back from vacation