FHIR Chat · Hidden exception when loading libraries · cql

Stream: cql

Topic: Hidden exception when loading libraries


view this post on Zulip Sean McIlvenna (May 18 2021 at 01:59):

So, I encountered a bit of an issue today... We're working on defining a new measure. Tried testing it against HAPI with cql_enabled. HAPI failed to load the library with the following stack trace:

ca.uhn.fhir.rest.server.exceptions.InternalErrorException: Failed to call access method: java.lang.IllegalArgumentException: Could not resolve primary library for Measure/NHSNBaseMeasure.
    at ca.uhn.fhir.rest.server.method.BaseMethodBinding.invokeServerMethod(BaseMethodBinding.java:258)
    at ca.uhn.fhir.rest.server.method.OperationMethodBinding.invokeServer(OperationMethodBinding.java:329)
    at ca.uhn.fhir.rest.server.method.BaseResourceReturningMethodBinding.doInvokeServer(BaseResourceReturningMethodBinding.java:272)
    at ca.uhn.fhir.rest.server.method.BaseResourceReturningMethodBinding.invokeServer(BaseResourceReturningMethodBinding.java:380)
    at ca.uhn.fhir.rest.server.method.OperationMethodBinding.invokeServer(OperationMethodBinding.java:304)
    at ca.uhn.fhir.rest.server.RestfulServer.handleRequest(RestfulServer.java:1084)
    at ca.uhn.fhir.rest.server.RestfulServer.doGet(RestfulServer.java:380)
    at ca.uhn.fhir.rest.server.RestfulServer.service(RestfulServer.java:1794)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:750)
    at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:791)
    at org.eclipse.jetty.servlet.ServletHandler$ChainEnd.doFilter(ServletHandler.java:1626)
    at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:201)
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119)
    at org.eclipse.jetty.servlet.FilterHolder.doFilter(FilterHolder.java:193)
    at org.eclipse.jetty.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1601)
    at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:548)
    at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:143)
    at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:602)
    at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127)
    at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:235)
    at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1624)
    at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:233)
    at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1435)
    at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:188)
    at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:501)
    at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1594)
    at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:186)
    at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1350)
    at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)
    at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127)
    at org.eclipse.jetty.server.Server.handle(Server.java:516)
    at org.eclipse.jetty.server.HttpChannel.lambda$handle$1(HttpChannel.java:388)
    at org.eclipse.jetty.server.HttpChannel.dispatch(HttpChannel.java:633)
    at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:380)
    at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:279)
    at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:311)
    at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:105)
    at org.eclipse.jetty.io.ChannelEndPoint$1.run(ChannelEndPoint.java:104)
    at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:882)
    at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:1036)
    at java.base/java.lang.Thread.run(Thread.java:830)
Caused by: java.lang.reflect.InvocationTargetException: null
    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:567)
    at ca.uhn.fhir.rest.server.method.BaseMethodBinding.invokeServerMethod(BaseMethodBinding.java:250)
    ... 40 common frames omitted
Caused by: java.lang.IllegalArgumentException: Could not resolve primary library for Measure/NHSNBaseMeasure.
    at ca.uhn.fhir.cql.r4.helper.LibraryHelper.resolvePrimaryLibrary(LibraryHelper.java:216)
    at ca.uhn.fhir.cql.r4.evaluation.MeasureEvaluationSeed.setup(MeasureEvaluationSeed.java:83)
    at ca.uhn.fhir.cql.r4.provider.MeasureOperationsProvider.evaluateMeasure(MeasureOperationsProvider.java:95)
    ... 45 common frames omitted
2021-05-17 18:55:48.440 [qtp2016067912-73] INFO  fhirtest.access [LoggingInterceptor.java:160] ERROR - GET http://localhost:8080/fhir/Measure/NHSNBaseMeasure/$evaluate-measure

I couldn't find anything wrong with it. I thought it was made an issue with the Library.url or the Library.id... But it wasn't.
As it turned out, there were some issues with references to definitions in the CQL. I had to debug HAPI in order to figure it out:

NHSNBaseMeasure-0.0.001 [21:4, 21:58] Could not resolve identifier COVID_19 (Tests for SARS_CoV_2 Antigen) in the current library.
NHSNBaseMeasure-0.0.001 [26:8, 26:27] Could not validate reference to expression COVID 19 CoV Tests because its definition contains errors.
NHSNBaseMeasure-0.0.001 [38:3, 38:36] Could not validate reference to expression Encounter with COVID19 CoV Tests because its definition contains errors.

I uncovered this exception by stepping through the logic until I hit PrivateCachingLibraryLoaderDecorator.load(), where it catches an exception and simply returns null without writing out any logs about the exception.
Are there plans to improve this so that loading libraries with CQL provides more guidance as-to what the issues are when loading?

view this post on Zulip JP (May 19 2021 at 16:10):

Hmm... Took a look at this and I'll have to think how to address it in a way that makes sense. The current logic assumes that some other component may be able to load the library from a different source (for example, an embedded FHIRHelpers vs one posted on the server) so that's why it ignores the error.

view this post on Zulip JP (May 19 2021 at 16:10):

But clearly if you get to the end of the chain and still weren't able to get a Library it'd be nice to see any errors along the way.


Last updated: Apr 12 2022 at 19:14 UTC