search

ehrbase / fhir-bridge

FHIR Bridge acts as a broker between an HL7 FHIR client and an openEHR server.
32 stars 20 forks source link

Unexpected 422 Error in happy path tests of ObservationLab #152

Closed af-pwo closed 3 years ago

af-pwo commented 3 years ago

Test Case/s To Reproduce Issue

tests/robot/OBSERVATION/01_create.robot/.. 39 Create Observation Lab - CRP 40 Create Observation Lab - Billirubin 41 Create Observation Lab - Ferritin 43 Create Observation Lab - Gamma Glutamyl Transferase 44 Create Observation Lab - Lactate 45 Create Observation Lab - Leukocytes 46 Create Observation Lab - Lymphocytes 48 Create Observation Lab - Hemoglobin 51 Create Observation Lab - Creatinine 53 Create Observation Lab - Procalcitonin 54 Create Observation Lab - Interleukin 6 55 Create Observation Lab - Natriuretic Peptide.b Prohormoe N-Terminal 58 Create Observation Lab - Platelets 59 Create Observation Lab - Antithrombin

These test cases are using the associated example.json from src/test/resources/Observation.

robot command to execute related test case(s) in your terminal/console

You HAVE to be in the folder tests/

execute: robot -i observation-lab -d results/ -L TRACE robot NOTE: This will execute all observation-lab tagged test cases. Some of the executed test cases will fail with a 500 error. The test cases that result in a 500 http error are part of another issue https://github.com/ehrbase/fhir-bridge/issues/153

Expected Result

http 200

Actual Result

422 None diagnostics': 'untersuchterAnalyt is required in FHIR Observation', severity': 'error'

Stacktrace

STACKTRACE IS THE SAME FOR ALL RESOURCES ONLY MessageId AND ExchangeId DIFFER

2021-01-22 13:22:06.043 INFO 34714 --- [nio-8888-exec-1] o.e.f.c.p.ResourceProfileValidator : Observation resource validated 2021-01-22 13:22:07.447 ERROR 34714 --- [nio-8888-exec-1] o.a.c.p.e.DefaultErrorHandler : Failed delivery for (MessageId: FABE5E743B2D30C-0000000000000000 on ExchangeId: FABE5E743B2D30C-0000000000000000). Exhausted after delivery attempt: 1 caught: ca.uhn.fhir.rest.server.exceptions.UnprocessableEntityException: untersuchterAnalyt is required in FHIR Observation. Processed by failure processor: FatalFallbackErrorHandler[Channel[DelegateSync[org.ehrbase.fhirbridge.camel.processor.DefaultExceptionHandler@29ceefb3]]]

Message History (complete message history is disabled)

RouteId ProcessorId Processor Elapsed (ms) [route5 ] [route5 ] [from[fhir-create-observation://fhirConsumer?fhirContext=%23fhirContext] ] [ 1453]

Stacktrace

ca.uhn.fhir.rest.server.exceptions.UnprocessableEntityException: untersuchterAnalyt is required in FHIR Observation at org.ehrbase.fhirbridge.ehr.converter.ObservationLabCompositionConverter.mapToLaboranalyt(ObservationLabCompositionConverter.java:468) ~[classes!/:na] at org.ehrbase.fhirbridge.ehr.converter.ObservationLabCompositionConverter.toComposition(ObservationLabCompositionConverter.java:181) ~[classes!/:na] at org.ehrbase.fhirbridge.ehr.converter.ObservationLabCompositionConverter.toComposition(ObservationLabCompositionConverter.java:57) ~[classes!/:na] at org.ehrbase.fhirbridge.camel.component.ehr.composition.CompositionProducer.mergeCompositionEntity(CompositionProducer.java:43) ~[classes!/:na] at org.ehrbase.fhirbridge.camel.component.ehr.composition.CompositionProducer.process(CompositionProducer.java:27) ~[classes!/:na] at org.apache.camel.support.AsyncProcessorConverterHelper$ProcessorToAsyncProcessorBridge.process(AsyncProcessorConverterHelper.java:66) ~[camel-support-3.7.0.jar!/:3.7.0] at org.apache.camel.processor.SendProcessor.process(SendProcessor.java:169) ~[camel-core-processor-3.7.0.jar!/:3.7.0] at org.apache.camel.processor.errorhandler.RedeliveryErrorHandler$RedeliveryTask.doRun(RedeliveryErrorHandler.java:714) ~[camel-core-processor-3.7.0.jar!/:3.7.0] at org.apache.camel.processor.errorhandler.RedeliveryErrorHandler$RedeliveryTask.run(RedeliveryErrorHandler.java:623) ~[camel-core-processor-3.7.0.jar!/:3.7.0] at org.apache.camel.impl.engine.DefaultReactiveExecutor$Worker.schedule(DefaultReactiveExecutor.java:148) ~[camel-base-engine-3.7.0.jar!/:3.7.0] at org.apache.camel.impl.engine.DefaultReactiveExecutor.scheduleMain(DefaultReactiveExecutor.java:60) ~[camel-base-engine-3.7.0.jar!/:3.7.0] at org.apache.camel.processor.Pipeline.process(Pipeline.java:147) ~[camel-core-processor-3.7.0.jar!/:3.7.0] at org.apache.camel.impl.engine.CamelInternalProcessor.process(CamelInternalProcessor.java:312) ~[camel-base-engine-3.7.0.jar!/:3.7.0] at org.apache.camel.impl.engine.DefaultAsyncProcessorAwaitManager.process(DefaultAsyncProcessorAwaitManager.java:83) ~[camel-base-engine-3.7.0.jar!/:3.7.0] at org.apache.camel.support.AsyncProcessorSupport.process(AsyncProcessorSupport.java:41) ~[camel-support-3.7.0.jar!/:3.7.0] at org.openehealth.ipf.platform.camel.ihe.fhir.core.intercept.consumer.ConsumerAuditInterceptor.process(ConsumerAuditInterceptor.java:60) ~[ipf-platform-camel-ihe-fhir-core-4.0.0.jar!/:na] at org.openehealth.ipf.platform.camel.ihe.fhir.core.FhirConsumer.runRoute(FhirConsumer.java:192) ~[ipf-platform-camel-ihe-fhir-core-4.0.0.jar!/:na] at org.openehealth.ipf.platform.camel.ihe.fhir.core.FhirConsumer.handleInRoute(FhirConsumer.java:165) ~[ipf-platform-camel-ihe-fhir-core-4.0.0.jar!/:na] at org.openehealth.ipf.platform.camel.ihe.fhir.core.FhirConsumer.handleAction(FhirConsumer.java:137) ~[ipf-platform-camel-ihe-fhir-core-4.0.0.jar!/:na] at org.openehealth.ipf.commons.ihe.fhir.AbstractPlainProvider.requestAction(AbstractPlainProvider.java:170) ~[ipf-commons-ihe-fhir-core-4.0.0.jar!/:na] at org.ehrbase.fhirbridge.fhir.observation.CreateObservationProvider.create(CreateObservationProvider.java:20) ~[classes!/:na] at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:na] at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:64) ~[na:na] at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:na] at java.base/java.lang.reflect.Method.invoke(Method.java:564) ~[na:na] at ca.uhn.fhir.rest.server.method.BaseMethodBinding.invokeServerMethod(BaseMethodBinding.java:245) ~[hapi-fhir-server-5.2.0.jar!/:na] at ca.uhn.fhir.rest.server.method.BaseOutcomeReturningMethodBinding.invokeServer(BaseOutcomeReturningMethodBinding.java:154) ~[hapi-fhir-server-5.2.0.jar!/:na] at ca.uhn.fhir.rest.server.method.CreateMethodBinding.invokeServer(CreateMethodBinding.java:41) ~[hapi-fhir-server-5.2.0.jar!/:na] at ca.uhn.fhir.rest.server.RestfulServer.handleRequest(RestfulServer.java:1052) ~[hapi-fhir-server-5.2.0.jar!/:na] at ca.uhn.fhir.rest.server.RestfulServer.doPost(RestfulServer.java:377) ~[hapi-fhir-server-5.2.0.jar!/:na] at ca.uhn.fhir.rest.server.RestfulServer.service(RestfulServer.java:1749) ~[hapi-fhir-server-5.2.0.jar!/:na] at javax.servlet.http.HttpServlet.service(HttpServlet.java:733) ~[tomcat-embed-core-9.0.41.jar!/:4.0.FR] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:231) ~[tomcat-embed-core-9.0.41.jar!/:9.0.41] at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-9.0.41.jar!/:9.0.41] at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:53) ~[tomcat-embed-websocket-9.0.41.jar!/:9.0.41] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) ~[tomcat-embed-core-9.0.41.jar!/:9.0.41] at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-9.0.41.jar!/:9.0.41] at org.springframework.web.filter.CorsFilter.doFilterInternal(CorsFilter.java:91) ~[spring-web-5.3.2.jar!/:5.3.2] at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119) ~[spring-web-5.3.2.jar!/:5.3.2] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) ~[tomcat-embed-core-9.0.41.jar!/:9.0.41] at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-9.0.41.jar!/:9.0.41] at org.springframework.web.filter.RequestContextFilter.doFilterInternal(RequestContextFilter.java:100) ~[spring-web-5.3.2.jar!/:5.3.2] at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119) ~[spring-web-5.3.2.jar!/:5.3.2] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) ~[tomcat-embed-core-9.0.41.jar!/:9.0.41] at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-9.0.41.jar!/:9.0.41] at org.springframework.web.filter.FormContentFilter.doFilterInternal(FormContentFilter.java:93) ~[spring-web-5.3.2.jar!/:5.3.2] at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119) ~[spring-web-5.3.2.jar!/:5.3.2] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) ~[tomcat-embed-core-9.0.41.jar!/:9.0.41] at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-9.0.41.jar!/:9.0.41] at org.springframework.boot.actuate.metrics.web.servlet.WebMvcMetricsFilter.doFilterInternal(WebMvcMetricsFilter.java:93) ~[spring-boot-actuator-2.4.1.jar!/:2.4.1] at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119) ~[spring-web-5.3.2.jar!/:5.3.2] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) ~[tomcat-embed-core-9.0.41.jar!/:9.0.41] at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-9.0.41.jar!/:9.0.41] at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:201) ~[spring-web-5.3.2.jar!/:5.3.2] at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119) ~[spring-web-5.3.2.jar!/:5.3.2] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) ~[tomcat-embed-core-9.0.41.jar!/:9.0.41] at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-9.0.41.jar!/:9.0.41] at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:202) ~[tomcat-embed-core-9.0.41.jar!/:9.0.41] at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:97) ~[tomcat-embed-core-9.0.41.jar!/:9.0.41] at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:542) ~[tomcat-embed-core-9.0.41.jar!/:9.0.41] at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:143) ~[tomcat-embed-core-9.0.41.jar!/:9.0.41] at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:92) ~[tomcat-embed-core-9.0.41.jar!/:9.0.41] at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:78) ~[tomcat-embed-core-9.0.41.jar!/:9.0.41] at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:343) ~[tomcat-embed-core-9.0.41.jar!/:9.0.41] at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:374) ~[tomcat-embed-core-9.0.41.jar!/:9.0.41] at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:65) ~[tomcat-embed-core-9.0.41.jar!/:9.0.41] at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:888) ~[tomcat-embed-core-9.0.41.jar!/:9.0.41] at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1597) ~[tomcat-embed-core-9.0.41.jar!/:9.0.41] at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49) ~[tomcat-embed-core-9.0.41.jar!/:9.0.41] at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130) ~[na:na] at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:630) ~[na:na] at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61) ~[tomcat-embed-core-9.0.41.jar!/:9.0.41] at java.base/java.lang.Thread.run(Thread.java:832) ~[na:na]

2021-01-22 13:22:07.628 WARN 34714 --- [nio-8888-exec-1] c.u.f.r.s.i.ExceptionHandlingInterceptor : Failure during REST processing: ca.uhn.fhir.rest.server.exceptions.UnprocessableEntityException: untersuchterAnalyt is required in FHIR Observation

ppazos commented 3 years ago

@af-pwo the error from the log comes from this code:

            if (fhirObservation.getCode().getCoding().get(0).getSystem().equals("http://loinc.org")) {
                String code = fhirObservation.getCode().getCoding().get(0).getCode();
                untersuchterAnalyt = untersuchterAnalytLOINCDefiningcodeMap.get(code);
            }

Because the untersuchterAnalyt is NULL.

That could happen because:

  1. this condition is false: fhirObservation.getCode().getCoding().get(0).getSystem().equals("http://loinc.org")
  2. or the 'code' used is not in this enum https://github.com/ehrbase/fhir-bridge/blob/2ce1c5ed7d55eb35985d286e65379f6b98f7c4f6/src/main/java/org/ehrbase/fhirbridge/ehr/opt/geccolaborbefundcomposition/definition/UntersuchterAnalytDefiningcode.java

Can you attach the JSON used? Thanks.

af-pwo commented 3 years ago

@ppazos

https://github.com/ehrbase/fhir-bridge/blob/develop/src/test/resources/Observation/create-observation-lab-CRP.json

https://github.com/ehrbase/fhir-bridge/blob/develop/src/test/resources/Observation/create-observation-lab-bilirubin.json

https://github.com/ehrbase/fhir-bridge/blob/develop/src/test/resources/Observation/create-observation-lab-ferritin.json

https://github.com/ehrbase/fhir-bridge/blob/develop/src/test/resources/Observation/create-observation-lab-gamma-glutamyl-transferase.json

https://github.com/ehrbase/fhir-bridge/blob/develop/src/test/resources/Observation/create-observation-lab-lactate.json

https://github.com/ehrbase/fhir-bridge/blob/develop/src/test/resources/Observation/create-observation-lab-leukocytes.json

https://github.com/ehrbase/fhir-bridge/blob/develop/src/test/resources/Observation/create-observation-lab-lymphocytes.json

https://github.com/ehrbase/fhir-bridge/blob/develop/src/test/resources/Observation/create-observation-lab-hemoglobin.json

https://github.com/ehrbase/fhir-bridge/blob/develop/src/test/resources/Observation/create-observation-lab-creatinine.json

https://github.com/ehrbase/fhir-bridge/blob/develop/src/test/resources/Observation/create-observation-lab-procalcitonin.json

https://github.com/ehrbase/fhir-bridge/blob/develop/src/test/resources/Observation/create-observation-lab-interleukin-6.json

https://github.com/ehrbase/fhir-bridge/blob/develop/src/test/resources/Observation/create-observation-lab-natriuretic-peptide.b-prohormone-n-terminal.json

https://github.com/ehrbase/fhir-bridge/blob/develop/src/test/resources/Observation/create-observation-lab-antithrombin.json

https://github.com/ehrbase/fhir-bridge/blob/develop/src/test/resources/Observation/create-observation-lab-platelets.json

ppazos commented 3 years ago

@birgerhaarbrandt I found the source of this error "untersuchterAnalyt is required in FHIR Observation'" and started to fix it on this PR https://github.com/ehrbase/fhir-bridge/pull/196/files#diff-1dc4f5dc96b5e84dbd2305ba28c6459a4432f5effe891aa60c7838f68f095b36R116

The issue is there is a enum class that doesn't contain the codes used in the FHIR examples we have for testing, and that enum (UntersuchterAnalytDefiningcode.java) is generated by the SDK from an OPT. For this to work, all possible lab study codes should be in the OPT, which is not the way to model it. IMO the OPT shouldn't have code constraints inside the archetype/OPT.

The OPT is GECCO_Laborbefund. If you check this node at0024, there is a list of hardcoded LOINC codes there https://github.com/ehrbase/fhir-bridge/blob/develop/src/main/resources/opt/GECCO_Laborbefund.opt#L1914

IMO this is a modeling issue, not a mapping error.

SevKohler commented 3 years ago

@ppazos since you fixed it via the PR can we close this ?

ppazos commented 3 years ago

@SevKohler reading my last comment, this should be fixed in the OPT, my PR was a temporal thing, since the code is autogenerated. Were the codes in the OPT updated?

SevKohler commented 3 years ago

i just communicated that to them, since no one did that as it seems ... We now have to wait for the fix i already started an branch.

ppazos commented 3 years ago

@SevKohler I would not do any coding for this one until the template is updated and the classes can be regenerated using that one, then update the mapping accordingly and check if there are any errors. With the right codes in the OPT this shouldn't be a problem any more.

SevKohler commented 3 years ago

fixed by #355 Nevertheless a new bug appeared in the search, this is due to current bridge changes. Initial create error is fixed.

SevKohler commented 3 years ago

@subigre will fix this search

subigre commented 3 years ago

Search tests cases are enabled

Command:

robot -i search -d results/ -L TRACE robot

Output:

004 Search Heart Rate Results :: 1. *CREATE* new EHR record           | PASS |
------------------------------------------------------------------------------
Robot.OBSERVATION.02 Search                                           | PASS |
4 tests, 4 passed, 0 failed
==============================================================================
Robot.OBSERVATION                                                     | PASS |
4 tests, 4 passed, 0 failed
==============================================================================
Robot :: _Copyright (c) 2020/2021 Wladislaw Wagner (Vitasystems Gm... | PASS |
4 tests, 4 passed, 0 failed
==============================================================================
Output:  D:\Projets\ehrbase\dev\fhir-bridge\tests\results\output.xml
Log:     D:\Projets\ehrbase\dev\fhir-bridge\tests\results\log.html
Report:  D:\Projets\ehrbase\dev\fhir-bridge\tests\results\report.html