hapifhir / hapi-fhir-jpaserver-starter

Apache License 2.0
394 stars 1.05k forks source link

strange problem(s) using existing MySQL 5.7 database #317

Closed jschneid-nmdp closed 7 months ago

jschneid-nmdp commented 2 years ago

I've been running into problems using hapi-fhir-jpaserver-starter with a MySQL 5.7 database.

The MySQL 5.7 database I'm using is populated with data, and has been used with another hapi-fhir server (based on hapi-fhir-jpaserver-uhnfhirtest). The database schema has been migrated to hapi-fhir 5.6.0 using the hapi-fhir-cli tool.

Steps to reproduce the problem(s) are:

  1. Clone the hapi-fhir-jpaserver-starter repo.
  2. Create a local branch based on the image/v5.6.0 tag.
  3. Build an executable JAR, using the "boot" profile (e.g. mvn -P boot clean package).
  4. Start a server, using the MySQL 5.7 database (e.g. java -Xmx4096m '-Dspring.datasource.url=jdbc:mysql://localhost:3306/fhir_r4?useSSL=false' -Dspring.datasource.username=myuser -Dspring.datasource.password=secret -Dspring.datasource.driverClassName=com.mysql.cj.jdbc.Driver -Dspring.jpa.properties.hibernate.dialect=org.hibernate.dialect.MySQL57Dialect -jar target/ROOT.war)

During startup the server prints multiple stack traces saying things like this:

2022-02-20 23:47:31.555 [main] WARN o.h.t.s.i.ExceptionHandlerLoggedImpl [ExceptionHandlerLoggedImpl.java:27] GenerationTarget encountered exception accepting command : Error executing DDL "alter table trm_valueset_concept add constraint FK_TRM_VALUESET_PID foreign key (valueset_pid) references trm_valueset (pid)" via JDBC Statement org.hibernate.tool.schema.spi.CommandAcceptanceException: Error executing DDL "alter table trm_valueset_concept add constraint FK_TRM_VALUESET_PID foreign key (valueset_pid) references trm_valueset (pid)" via JDBC Statement

I've tried using configuration settings such as spring.jpa.hibernate.ddl-auto=none to disable the DDL commands, with no effect.

In spite of the stack traces, the server is able to start up. However, it doesn't quite work correctly. For example, it's able to successfully process a Patient?_id=1 search, but fails to successfully process a Patient/1 request. E.g.

curl --silent --request GET --url 'http://localhost:8080/fhir/Patient?_id=1' --header 'accept: application/fhir+json' (returns a Bundle containing a single Patient resource)

curl --silent --request GET --url 'http://localhost:8080/fhir/Patient/1' --header 'accept: application/fhir+json' (returns an OperationOutcome saying, "Resource Patient/1 is not known")

My other hapi-fhir server (based on hapi-fhir-jpaserver-uhnfhirtest) is able to successfully process these same requests, so I'm pretty sure the problem does not reside in the (MySQL 5.7) database.

jschneid-nmdp commented 2 years ago

Today I found that setting the Hibernate property hibernate.hbm2ddl.auto=validate prevents the server from printing the "Error executing DDL" stack traces. E.g.:

java -Xmx4096m '-Dspring.datasource.url=jdbc:mysql://localhost:3306/fhir_r4?useSSL=false' -Dspring.datasource.username=myuser -Dspring.datasource.password=secret -Dspring.datasource.driverClassName=com.mysql.cj.jdbc.Driver -Dspring.jpa.properties.hibernate.dialect=org.hibernate.dialect.MySQL57Dialect -Dspring.jpa.properties.hibernate.hbm2ddl.auto=validate -jar target/ROOT.war

However, the Patient/1 request still fails (returns OperationOutcome saying "Resource Patient/1 is not known").

jschneid-nmdp commented 2 years ago

This issue is related to MySQL identifier case sensitivity (e.g. for table names) being linked to the case sensitivity of the underlying operating system. See also:

https://dev.mysql.com/doc/refman/5.7/en/identifier-case-sensitivity.html

The MySQL server I've been using runs in a (Linux) docker container. Rebuilding the MySQL server, setting the system variable lower_case_table_names=1 and then reloading the data, resolved the problem with the Patient/1 request.

There was an additional complication. The FHIR server initially wouldn't start, with flyway complaining about the absence of a schema history table.

Error starting ApplicationContext. To display the conditions report re-run your application with 'debug' enabled.
2022-03-01 10:39:23.972 [main] ERROR o.s.boot.SpringApplication [SpringApplication.java:843] Application run failed
org.springframework.context.ApplicationContextException: Unable to start web server; nested exception is org.springframework.boot.web.server.WebServerException: Unable to start embedded Tomcat
...
Caused by: org.flywaydb.core.api.FlywayException: Found non-empty schema(s) `fhir_r4` but no schema history table. Use baseline() or set baselineOnMigrate to true to initialize the schema history table.
    at org.flywaydb.core.Flyway$1.execute(Flyway.java:186)

This error was strange, because I had already used the v5.6.0 hapi-fhir-cli tool to run hapi-fhir-cli migrate-database on the fhir_r4 database.

To get past the flyway error, I set spring.flyway.baseline-on-migrate=true when starting the FHIR server. After doing this, during server startup flyway created a flyway_schema_history table, which also seemed strange, because the hapi-fhir-cli had already created a fly_hfj_migration table.

java -Xmx4096m '-Dspring.datasource.url=jdbc:mysql://localhost:3306/fhir_r4?useSSL=false' -Dspring.datasource.username=myuser -Dspring.datasource.password=secret -Dspring.datasource.driverClassName=com.mysql.cj.jdbc.Driver -Dspring.jpa.properties.hibernate.dialect=org.hibernate.dialect.MySQL57Dialect -Dspring.jpa.properties.hibernate.hbm2ddl.auto=validate -Dspring.flyway.baseline-on-migrate=true -jar target/ROOT.war
jschneid-nmdp commented 2 years ago

Another slightly strange part of this story is, only the hapi-fhir-jpaserver-starter FHIR server was affected by the MySQL lower_case_table_names=1 setting. The other FHIR server based on hapi-fhir-jpaserver-uhnfhirtest was not affected by that setting.

github-actions[bot] commented 7 months ago

This issue is stale because it has been open 730 days with no activity. Remove stale label or comment or this will be closed in 5 days.

github-actions[bot] commented 7 months ago

This issue was closed because it has been stalled for 5 days with no activity.