HAPI FHIR JPA Server Notes

Russell Bateman
June 2020

Project hapi-fhir-jpaserver-starter is a free and open-source FHIR server. HAPI means "HL7 application programming interface and is pronounced, "happy." HAPI exists in support of HL7 v2 (HAPI v2), and for HL7 v4 (HAPI FHIR).

Relevant links

Cloning the project from GitHub

Most of what follows is my experience in real time. I did this work in a separate rather than under my usual user area. This and setting up the project in IntelliJ IDEA took me maybe five minutes.

russ@gondolin ~/dev $ echo $JAVA_HOME
/home/russ/dev/jdk-11.0.2
russ@gondolin ~/dev $ mvn --version
Apache Maven 3.3.9
Maven home: /usr/share/maven
Java version: 11.0.2, vendor: Oracle Corporation
Java home: /home/russ/dev/jdk-11.0.2
Default locale: en_US, platform encoding: UTF-8
OS name: "linux", version: "4.13.0-36-generic", arch: "amd64", family: "unix"
russ@gondolin ~/dev $ git clone https://github.com/hapifhir/hapi-fhir-jpaserver-starter.git
Cloning into 'hapi-fhir-jpaserver-starter'...
remote: Enumerating objects: 145, done.
remote: Counting objects: 100% (145/145), done.
remote: Compressing objects: 100% (63/63), done.
remote: Total 1629 (delta 40), reused 108 (delta 22), pack-reused 1484
Receiving objects: 100% (1629/1629), 468.96 KiB | 0 bytes/s, done.
Resolving deltas: 100% (554/554), done.
Checking connectivity... done.
russ@gondolin ~/dev $ ll hapi-fhir-jpaserver-starter
total 12
drwxrwxr-x  3 russ russ 4096 Jul  3 06:50 .
drwxr-xr-x 16 russ russ 4096 Jul  3 06:49 ..
drwxrwxr-x  4 russ russ 4096 Jul  3 06:50 hapi-fhir-jpaserver-starter

This project is actively developed...

When I looked, the most recent modifications had come in the previous, few days. That was encouraging. It's not a cobweb site.

However, the project's stale README.md contains several misleading statements. One problem was a reference to a nonexistent property, server.base.

Another, and probably the most glaring, is its statement that it uses Apache Derby. This hasn't been true for some time. It uses
H2. It's a small matter, but something to look out for and a mise en garde against trusting too much of what you read. Documentation going stale is the bane of our profession.

Setting up the project in IntelliJ IDEA

At this point, I launched IntelliJ IDEA, chose File → Open..., then navigated to my new project and chose its pom.xml. Then, in IDEA, I set up File → Project Structure... thus:

    Project Settings
    Project
  1. Project name: hapi-fhir-jpaserver-starter
  2. Project SDK: 11
  3. Project language level: 8 - Lambdas, type annotations, etc.
  4. Project compiler output: out
  5. Modules
  6. Click the + sign and Module → Next.
  7. Type /home/russ/dev/hapi-fhir-jpaserver-starter.
  8. Ensure that Content root: and Module file location: are both /home/russ/dev/hapi-fhir-jpaserver-starter.
  9. Click Finish.
  10. Back in the Project Structure → Modules dialog, do this for the Sources tab:
    1. Set Language level: as above.
    2. Click .idea and then on the orange Excluded icon.
    3. Click target, if there, and then on the orange Excluded icon.
    4. If src is blue, click it, then click on the blue Sources icon.
    5. Expand src, expand main and test.
    6. Click on java under main and click the blue Sources icon.
    7. Click on resources under main and click the Resources icon.
    8. Click on java under test and click the green Tests icon.
    9. Click on resources under test (if there—it's not) and click the Test Resources icon (no need).
  11. Click on the Apply button to save your work.
  12.  
    Platform Settings
    SDKs
  13. You should have some good JDK installed; mine is 11.0.2

Ultimately, you should see something like this (click to enlarge):

What I show above is good medicine for a lot of open-source projects of this sort that you decide to do using IntelliJ IDEA. Often, projects are done in Eclipse with no other consideration and it can be difficult to translate from the project's set-up. This is the case of the IBM FHIR server which has gobs of code arranged paratactically that you have to grok in order to set it up to build in IDEA. I did this, it wasn't too hard, but I did scratch my head a bit over it. Ultimately, I did not show how because I do not plan to continue working with that code. Shame on me.

Demonstration of using the server

To run the server from the command line (it works very nicely), you will need to edit hapi-fhir-jpaserver-starter/src/main/resources/hapi.properties and change following lines. For my example, I'm going to use 7070 instead of 8080:

server_address=http://localhost:7070/hapi-fhir-jpaserver/fhir/
test.port=7070
# cors.allowed_origin=http://localhost:7070,https://localhost:7070,https://fhirtest.uhn.ca

Next, you must run the server using the slightly more complex command line than the first one given. Some versions of the README.md give this:

russ@gondolin ~/dev/hapi-fhir-jpaserver-starter $ mvn -Djetty.port=7070 jetty:run
WARNING: An illegal reflective access operation has occurred
WARNING: Illegal reflective access by com.google.inject.internal.cglib.core.$ReflectUtils$1 (file:/usr/share/maven/lib/guice.jar) to method java.lang.ClassLoader.defineClass(java.lang.String,byte[],int,int,java.security.ProtectionDomain)
WARNING: Please consider reporting this to the maintainers of com.google.inject.internal.cglib.core.$ReflectUtils$1
WARNING: Use --illegal-access=warn to enable warnings of further illegal reflective access operations
WARNING: All illegal access operations will be denied in a future release
[INFO] Scanning for projects...
[WARNING]
[WARNING] Some problems were encountered while building the effective model for ca.uhn.hapi.fhir:hapi-fhir-jpaserver-starter:war:5.0.2
[WARNING] 'build.plugins.plugin.(groupId:artifactId)' must be unique but found duplicate declaration of plugin org.apache.maven.plugins:maven-enforcer-plugin @ ca.uhn.hapi.fhir:hapi-fhir:5.0.2, /home/russ/.m2/repository/ca/uhn/hapi/fhir/hapi-fhir/5.0.2/hapi-fhir-5.0.2.pom, line 2020, column 12
[WARNING]
[WARNING] It is highly recommended to fix these problems because they threaten the stability of your build.
[WARNING]
[WARNING] For this reason, future Maven versions might no longer support building such malformed projects.
[WARNING]
[INFO]
[INFO] ------------------------------------------------------------------------
[INFO] Building HAPI FHIR JPA Server - Starter Project 5.0.2
[INFO] ------------------------------------------------------------------------
[INFO]
.
.
.
[INFO] Started ServerConnector@3809f4ec{HTTP/1.1,[http/1.1]}{0.0.0.0:7070}
[INFO] Started @14955ms
[INFO] Started Jetty Server
2020-06-30 13:38:57.156 [qtp1373172466-14] INFO  ca.uhn.fhir.context.FhirContext [FhirContext.java:180] Creating new FHIR context for FHIR version [R4]
2020-06-30 13:38:57.606 [qtp1373172466-21] INFO  fhirtest.access [LoggingInterceptor.java:175] Path[/fhir] Source[] Operation[metadata  ] UA[HAPI-FHIR/5.0.2 (FHIR Client; FHIR 4.0.1/R4; apache)] Params[] ResponseEncoding[JSON]
2020-06-30 13:38:57.688 [qtp1373172466-14] INFO  ca.uhn.fhir.to.Controller [Controller.java:175] Request(GET //localhost:7070/hapi-fhir-jpaserver/)@3fe4793e
^C[INFO] Stopped ServerConnector@3809f4ec{HTTP/1.1,[http/1.1]}{0.0.0.0:7070}
[INFO] node0 Stopped scavenging
[INFO] Closing Spring root WebApplicationContext
[INFO] Destroying Spring FrameworkServlet 'spring'
[INFO] Stopped o.e.j.m.p.JettyWebAppContext@10bf1ec9{/hapi-fhir-jpaserver,[file:///home/russ/dev/hapi-fhir-jpaserver-starter/src/main/webapp/, file:///home/russ/dev/hapi-fhir-jpaserver-starter/target/jetty_overlays/hapi-fhir-testpage-overlay-5_0_2_war/],UNAVAILABLE}{file:///home/russ/dev/hapi-fhir-jpaserver-starter/src/main/webapp/}
[INFO] Jetty server exiting.
[INFO] ------------------------------------------------------------------------
[INFO] BUILD SUCCESS
[INFO] ------------------------------------------------------------------------
[INFO] Total time: 55.059 s
[INFO] Finished at: 2020-06-30T13:39:32-06:00
[INFO] Final Memory: 102M/354M
[INFO] ------------------------------------------------------------------------

At this point, turn away from the command line to a browser. This is the server's capability statement. It's about 20,000 lines of XML.

And, I have already added a patient, from the browser I see this:

...or, with a tool such as Postman, but here I'm using </> RESTED, you can do a GET to see the patient.

To illustrate how I added that original patient, I'll add another:

Because I want to see more than one patient now (having two), I'll make the query parameters tell the server that I would like to see up to ten of them.

Intercepting execution in the server...

What interests me more than anything else is being able to intercept execution as it reaches the server and do something completely different from interacting with the H2 database. I plan instead to interact with a proprietary search engine. In support of this, I have been perusing the documentation on the matter of Interceptors, found at this URL.

Terminology

First, here's some terminolgy. I paraphrase a bit here.

Maybe I'll need to hook the DAOs. I don't know yet.

I have registered hook methods for seven server cutpoints and none is called. I have written about 7 hook methods, one for each of most of the server pointcuts.

From IntelliJ IDEA's project pane, I right click on ExampleServerR4IT.main() and Debug it. I have already added the lines highlighted below in order to force the JUnit test to reveal what port IDEA is really running the server on:

ExampleServerR4IT.java:
public class ExampleServerR4IT {
    ...
    private static String ourServerBase;  // my new static to reveal port we're running on
    ...
    @BeforeClass
    public static void beforeClass() throws Exception {
        ...
        ourServerBase = "http://localhost:" + ourPort + "/hapi-fhir-jpaserver/fhir/";
        ...
    }

    public static void main(String[] theArgs) throws Exception {
        ourPort = 7070;
        beforeClass();
        ourLog.info("Server base is: " + ourServerBase);
    }

...which I caused to be set in @BeforeClass in order to know what the URL to hit from Postman will be. I have breakpoints set inside every hook method.

The server launches in the (debug) console and, when it's up, I see:

2020-07-01 16:21:10.848 [main] INFO  c.u.f.jpa.starter.ExampleServerR4IT [ExampleServerR4IT.java:158] \
    Base URL is: http://localhost:7070/hapi-fhir-jpaserver/fhir/
2020-07-01 16:21:10.848 [main] INFO  c.u.f.jpa.starter.ExampleServerR4IT [ExampleServerR4IT.java:159] \
    Server base is: http://localhost:33945/hapi-fhir-jpaserver/fhir/

Then, using that URL (with the port number that will change each time I relaunch the debugger on the test), I get </> RESTED to POST in a few names which I can see when I do a GET http://localhost:33945/hapi-fhir-jpaserver/fhir/Patient?_limit=10

At no time is any of my breakpoints hit despite that I have, I think, reached and passed points like SERVER_INCOMING_REQUEST_PRE_PROCESSED, SERVER_INCOMING_REQUEST_POST_PROCESSED, SERVER_OUTGOING_RESPONSE, etc.

Is there something else, beyond mere annotations, that I need to do to get the rest of the (cloned and as yet unmodified) code to register my callbacks? I did try toggling the following booleans in hapi.properties to true:

fhirpath_interceptor.enabled=false
subscription.resthook.enabled=false
subscription.websocket.enabled=true

...to no avail.

Interceptor/Hook source code

I have created the following files on the path hapi-fhir-jpaserver-starter/src/main/java/com/windofkeltia/fhir/server. This package is inside the server code, parallel to hapi-fhir-jpaserver-starter/src/main/java/ca/uhn/fhir/jpa/starter. I assume, perhaps wrongly, that this code—by virtue of the @Hook annotation (the @Interceptor annotation is optional, so must not do anything), should build into the server.

I launch for debugging inside IDEA the main() method of ExampleServerR4IT.java, having doctored that method to give me the actual port number IntelliJ IDEA runs it on (we're no longer using the server we tried out on the command line). I have already shown that code above. Then, using </> RESTED, I try POSTing a new patient, GETing a patient, etc., but never are the breakpoints hit.

RequestCounterInterceptor.java:

This example comes directly from the documentation. The debugger I set at line 20 is never hit.

package com.windofkeltia.fhir.server;

import ca.uhn.fhir.interceptor.api.Hook;
import ca.uhn.fhir.interceptor.api.Interceptor;
import ca.uhn.fhir.interceptor.api.Pointcut;

import javax.servlet.http.HttpServletRequest;
import javax.servlet.http.HttpServletResponse;

@Interceptor
public class RequestCounterInterceptor
{
  private int requestCount;

  public int getRequestCount() { return requestCount; }

  @Hook( Pointcut.SERVER_INCOMING_REQUEST_PRE_PROCESSED )
  public boolean incomingRequestPreprocessed( HttpServletRequest request, HttpServletResponse response )
  {
    requestCount++;
    return true;
  }
}
Interceptors.java:

These are most if not all of the pointcuts I wish to investigate for my use. Of course, I never hit breakpoints I set on these lines.

package com.windofkeltia.fhir.server;

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.rest.api.server.RequestDetails;
import ca.uhn.fhir.rest.server.exceptions.BaseServerResponseException;

import javax.servlet.http.HttpServletRequest;
import javax.servlet.http.HttpServletResponse;
import java.io.IOException;

@Interceptor
public class Interceptors
{
  private int requestCount;
  private int responseCount;

  public int getRequestCount() { return requestCount; }
  public int getResponseCount() { return responseCount; }

  @Hook( Pointcut.SERVER_INCOMING_REQUEST_PRE_PROCESSED )
  public boolean incomingRequestPreprocessed( HttpServletRequest request, HttpServletResponse response )
  {
    requestCount++;
    return true;
  }

  @Hook( Pointcut.SERVER_INCOMING_REQUEST_POST_PROCESSED )
  public boolean incomingRequestPostprocessed( HttpServletRequest request, HttpServletResponse response )
  {
    requestCount++;
    return true;
  }

  @Hook( Pointcut.SERVER_INCOMING_REQUEST_PRE_HANDLED )
  public boolean incomingRequestPrehandled( HttpServletRequest request )
  {
    requestCount++;
    return true;
  }

  @Hook( Pointcut.SERVER_OUTGOING_RESPONSE )
  public boolean outgoingResponsePrepared( HttpServletResponse response )
  {
    responseCount++;
    return true;
  }

  @Hook( Pointcut.SERVER_PROCESSING_COMPLETED_NORMALLY )
  public boolean outgoingResponseSerialized( HttpServletResponse response )
  {
    responseCount++;
    return true;
  }

  @Hook( Pointcut.SERVER_PROCESSING_COMPLETED )
  public boolean outgoingResponseToClient( HttpServletResponse response )
  {
    responseCount++;
    return true;
  }

  @Hook( Pointcut.SERVER_HANDLE_EXCEPTION )
  public boolean handleException( RequestDetails details, BaseServerResponseException exception,
                                    HttpServletRequest request, HttpServletResponse response )
    throws IOException
  {
    response.setStatus( exception.getStatusCode() );
    response.setContentType( "text/plain" );
    response.getWriter().append( "Failed to process" );
    response.getWriter().close();
    return false;
  }
}

Lucene lock held by Hibernate...

Fairly quickly, I ran into this permanent Lucene lock mess. It's reported when you POST something new, but not when you perform a GET.

I'm guessing it began when I slammed down an instance of the server hard and dirty. It would have been inadvertant:

2020-07-03 10:13:31.402 [Hibernate Search sync consumer thread for index ca.uhn.fhir.jpa.model.entity.ResourceIndexedSearchParamString] \
        ERROR o.h.s.exception.impl.LogErrorHandler [LogErrorHandler.java:71] HSEARCH000058: Exception occurred org.apache.lucene.store.LockObtainFailedException: \
        Lock held by another program: /home/russ/dev/hapi-fhir-jpaserver-starter/target/lucenefiles/ca.uhn.fhir.jpa.model.entity.ResourceIndexedSearchParamString/write.lock
Primary Failure:
    Entity ca.uhn.fhir.jpa.model.entity.ResourceIndexedSearchParamString  Id 102  Work Type  org.hibernate.search.backend.AddLuceneWork
Subsequent failures:
    Entity ca.uhn.fhir.jpa.model.entity.ResourceIndexedSearchParamString  Id 103  Work Type  org.hibernate.search.backend.AddLuceneWork
    Entity ca.uhn.fhir.jpa.model.entity.ResourceIndexedSearchParamString  Id 104  Work Type  org.hibernate.search.backend.AddLuceneWork

org.apache.lucene.store.LockObtainFailedException: Lock held by another program: \
        /home/russ/dev/hapi-fhir-jpaserver-starter/target/lucenefiles/ca.uhn.fhir.jpa.model.entity.ResourceIndexedSearchParamString/write.lock
    at org.apache.lucene.store.NativeFSLockFactory.obtainFSLock(NativeFSLockFactory.java:118)
    at org.apache.lucene.store.FSLockFactory.obtainLock(FSLockFactory.java:41)
    at org.apache.lucene.store.BaseDirectory.obtainLock(BaseDirectory.java:45)
    at org.apache.lucene.index.IndexWriter.(IndexWriter.java:776)
    at org.hibernate.search.backend.impl.lucene.IndexWriterHolder.createNewIndexWriter(IndexWriterHolder.java:127)
    at org.hibernate.search.backend.impl.lucene.IndexWriterHolder.getIndexWriter(IndexWriterHolder.java:93)
    at org.hibernate.search.backend.impl.lucene.AbstractWorkspaceImpl.getIndexWriter(AbstractWorkspaceImpl.java:118)
    at org.hibernate.search.backend.impl.lucene.AbstractWorkspaceImpl.getIndexWriterDelegate(AbstractWorkspaceImpl.java:204)
    at org.hibernate.search.backend.impl.lucene.LuceneBackendQueueTask.applyUpdates(LuceneBackendQueueTask.java:82)
    at org.hibernate.search.backend.impl.lucene.LuceneBackendQueueTask.run(LuceneBackendQueueTask.java:47)
    at org.hibernate.search.backend.impl.lucene.SyncWorkProcessor$Consumer.applyChangesets(SyncWorkProcessor.java:167)
    at org.hibernate.search.backend.impl.lucene.SyncWorkProcessor$Consumer.run(SyncWorkProcessor.java:153)
    at java.base/java.lang.Thread.run(Thread.java:834)

I tried clearing it by rerunning the server and shutting it down cleanly. Ctrl-C appears to do this from the command line.

[INFO] Stopped ServerConnector@56178090{HTTP/1.1,[http/1.1]}{0.0.0.0:7070}
[INFO] node0 Stopped scavenging
[INFO] Closing Spring root WebApplicationContext
[INFO] Destroying Spring FrameworkServlet 'spring'
[INFO] Stopped o.e.j.m.p.JettyWebAppContext@10bf1ec9{/hapi-fhir-jpaserver,[file:///home/russ/dev/hapi-fhir-jpaserver-starter/src/main/webapp/, file:///home/russ/dev/hapi-fhir-jpaserver-starter/target/jetty_overlays/hapi-fhir-testpage-overlay-5_0_2_war/],UNAVAILABLE}{file:///home/russ/dev/hapi-fhir-jpaserver-starter/src/main/webapp/}
[INFO] Jetty server exiting.
[INFO] ------------------------------------------------------------------------
[INFO] BUILD SUCCESS
[INFO] ------------------------------------------------------------------------
[INFO] Total time: 32:26 min
[INFO] Finished at: 2020-07-03T10:45:34-06:00
[INFO] Final Memory: 104M/357M
[INFO] ------------------------------------------------------------------------

I probably screwed things up from IntelliJ IDEA; I should have thought about how best to bounce the server as I tried things out.

I tried bouncing IntelliJ IDEA. This has not helped.

I haven't yet tried bouncing my Linux host. Surely that will clear it?