jkiddo
commented
2 years ago Can you provide a docker-compose setup that exposes the error?
Closed chgl closed 2 years ago
jkiddo
commented
2 years ago Can you provide a docker-compose setup that exposes the error?
chgl
commented
2 years ago Sure! Thank you for your time!
services:
hapi-fhir-jpaserver:
image: docker.io/hapiproject/hapi:v5.7.0
environment:
SPRING_DATASOURCE_URL: "jdbc:postgresql://postgres-db:5432/hapi"
SPRING_DATASOURCE_USERNAME: "postgres"
SPRING_DATASOURCE_PASSWORD: "postgres"
SPRING_DATASOURCE_DRIVERCLASSNAME: "org.postgresql.Driver"
SPRING_JPA_PROPERTIES_HIBERNATE_DIALECT: "org.hibernate.dialect.PostgreSQL10Dialect"
SPRING_JPA_DATABASE_PLATFORM: "org.hibernate.dialect.PostgreSQLDialect"
postgres-db:
image: docker.io/postgres:14.2
environment:
POSTGRES_DB: hapi
POSTGRES_PASSWORD: postgresSave as docker-compose.yaml and run docker compose -f docker-compose.yaml up.
Slightly off-topic, but I'm thinking once this is solved, we could add integration/e2e tests to the CI pipeline running the container with multiple different database backends.
jkiddo
commented
2 years ago The dialect is not picked up:
2022-04-06 23:20:01.482 [main] INFO org.hibernate.dialect.Dialect [Dialect.java:175] HHH000400: Using dialect: ca.uhn.fhir.jpa.model.dialect.HapiFhirH2Dialect
It is picked up when I run it directly from Intellij .... dont know why yet it fails. Also you should change the dialect to ca.uhn.fhir.jpa.model.dialect.HapiFhirPostgres94Dialect
jkiddo
commented
2 years ago services:
hapi-fhir-jpaserver:
image: docker.io/hapiproject/hapi:v5.7.0
environment:
SPRING_APPLICATION_JSON: '{
"spring.datasource.url" : "jdbc:postgresql://postgres-db:5432/hapi",
"spring.datasource.driverClassName" : "org.postgresql.Driver",
"spring.datasource.username" : "postgres",
"spring.datasource.password" : "postgres",
"spring.jpa.properties.hibernate.dialect" : "ca.uhn.fhir.jpa.model.dialect.HapiFhirPostgres94Dialect"
}'
postgres-db:
image: docker.io/postgres:14.2
environment:
POSTGRES_DB: hapi
POSTGRES_PASSWORD: postgresAbove works - don't ask why
chgl
commented
2 years ago Brilliant, thank you so much @jkiddo ! I narrowed it down to spring.jpa.properties.hibernate.dialect, which does work as an env var when using lowercase and dots while SPRING_JPA_PROPERTIES_HIBERNATE_DIALECT no longer works.
I'm trying to update the Helm chart to the latest release, v5.7.0, but when starting the container I get the following warning/error:
which is caused by
The container has the following env vars set, which correspond to the settings in the application.yaml:
I'm not sure if this relates to either https://github.com/hapifhir/hapi-fhir/issues/3012 and/or https://github.com/hapifhir/hapi-fhir/issues/3118 requiring upstream fixing, or if it's just some missing config option (possibly related: https://github.com/hapifhir/hapi-fhir/issues/3404)
Complete Stacktrace
```log . ____ _ __ _ _ /\\ / ___'_ __ _ _(_)_ __ __ _ \ \ \ \ ( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \ \\/ ___)| |_)| | | | | || (_| | ) ) ) ) ' |____| .__|_| |_|_| |_\__, | / / / / =========|_|==============|___/=/_/_/_/ :: Spring Boot :: (v2.6.2) 2022-04-06 23:19:40.225 [main] INFO ca.uhn.fhir.jpa.starter.Application [StartupInfoLogger.java:55] Starting Application using Java 17.0.2 on hapi-fhir-hapi-fhir-jpaserver-5cc6bbf448-5d822 with PID 1 (/app/main.war started by nonroot in /app) 2022-04-06 23:19:40.230 [main] INFO ca.uhn.fhir.jpa.starter.Application [SpringApplication.java:635] No active profile set, falling back to default profiles: default 2022-04-06 23:19:42.647 [main] INFO o.s.d.r.c.RepositoryConfigurationDelegate [RepositoryConfigurationDelegate.java:132] Bootstrapping Spring Data JPA repositories in DEFAULT mode. 2022-04-06 23:19:43.347 [main] INFO o.s.d.r.c.RepositoryConfigurationDelegate [RepositoryConfigurationDelegate.java:201] Finished Spring Data repository scanning in 685 ms. Found 51 JPA repository interfaces. 2022-04-06 23:19:46.482 [main] INFO ca.uhn.fhir.util.VersionUtil [VersionUtil.java:84] HAPI FHIR version 5.7.0 - Rev 0f1a306b58 2022-04-06 23:19:46.505 [main] INFO ca.uhn.fhir.context.FhirContext [FhirContext.java:208] Creating new FHIR context for FHIR version [R4] 2022-04-06 23:19:47.357 [main] INFO o.s.c.s.PostProcessorRegistrationDelegate$BeanPostProcessorChecker [PostProcessorRegistrationDelegate.java:376] Bean 'fhirContextR4' of type [ca.uhn.fhir.context.FhirContext] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying) 2022-04-06 23:19:47.360 [main] INFO o.s.c.s.PostProcessorRegistrationDelegate$BeanPostProcessorChecker [PostProcessorRegistrationDelegate.java:376] Bean 'myDaoRegistry' of type [ca.uhn.fhir.jpa.api.dao.DaoRegistry] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying) 2022-04-06 23:19:47.374 [main] INFO o.s.c.s.PostProcessorRegistrationDelegate$BeanPostProcessorChecker [PostProcessorRegistrationDelegate.java:376] Bean 'org.springframework.boot.autoconfigure.jdbc.DataSourceConfiguration$Hikari' of type [org.springframework.boot.autoconfigure.jdbc.DataSourceConfiguration$Hikari] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying) 2022-04-06 23:19:47.420 [main] INFO o.s.c.s.PostProcessorRegistrationDelegate$BeanPostProcessorChecker [PostProcessorRegistrationDelegate.java:376] Bean 'org.springframework.boot.autoconfigure.flyway.FlywayAutoConfiguration' of type [org.springframework.boot.autoconfigure.flyway.FlywayAutoConfiguration] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying) 2022-04-06 23:19:47.423 [main] INFO o.s.c.s.PostProcessorRegistrationDelegate$BeanPostProcessorChecker [PostProcessorRegistrationDelegate.java:376] Bean 'stringOrNumberMigrationVersionConverter' of type [org.springframework.boot.autoconfigure.flyway.FlywayAutoConfiguration$StringOrNumberToMigrationVersionConverter] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying) 2022-04-06 23:19:47.469 [main] INFO o.s.c.s.PostProcessorRegistrationDelegate$BeanPostProcessorChecker [PostProcessorRegistrationDelegate.java:376] Bean 'spring.datasource-org.springframework.boot.autoconfigure.jdbc.DataSourceProperties' of type [org.springframework.boot.autoconfigure.jdbc.DataSourceProperties] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying) 2022-04-06 23:19:47.528 [main] INFO o.s.c.s.PostProcessorRegistrationDelegate$BeanPostProcessorChecker [PostProcessorRegistrationDelegate.java:376] Bean 'dataSource' of type [com.zaxxer.hikari.HikariDataSource] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying) 2022-04-06 23:19:47.567 [main] INFO o.s.c.s.PostProcessorRegistrationDelegate$BeanPostProcessorChecker [PostProcessorRegistrationDelegate.java:376] Bean 'org.springframework.batch.core.configuration.annotation.SimpleBatchConfiguration' of type [org.springframework.batch.core.configuration.annotation.SimpleBatchConfiguration] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying) 2022-04-06 23:19:47.576 [main] INFO o.s.c.s.PostProcessorRegistrationDelegate$BeanPostProcessorChecker [PostProcessorRegistrationDelegate.java:376] Bean 'jobLauncher' of type [jdk.proxy2.$Proxy83] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying) 2022-04-06 23:19:47.656 [main] INFO o.s.c.s.PostProcessorRegistrationDelegate$BeanPostProcessorChecker [PostProcessorRegistrationDelegate.java:376] Bean 'appProperties' of type [ca.uhn.fhir.jpa.starter.AppProperties$$EnhancerBySpringCGLIB$$da4cd388] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying) 2022-04-06 23:19:47.662 [main] INFO o.s.c.s.PostProcessorRegistrationDelegate$BeanPostProcessorChecker [PostProcessorRegistrationDelegate.java:376] Bean 'fhirServerConfigR4' of type [ca.uhn.fhir.jpa.starter.FhirServerConfigR4$$EnhancerBySpringCGLIB$$c979184a] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying) 2022-04-06 23:19:48.864 [main] INFO o.s.b.w.e.tomcat.TomcatWebServer [TomcatWebServer.java:108] Tomcat initialized with port(s): 8080 (http) 2022-04-06 23:19:48.893 [main] INFO o.a.coyote.http11.Http11NioProtocol [DirectJDKLog.java:173] Initializing ProtocolHandler ["http-nio-8080"] 2022-04-06 23:19:48.895 [main] INFO o.a.catalina.core.StandardService [DirectJDKLog.java:173] Starting service [Tomcat] 2022-04-06 23:19:48.896 [main] INFO o.a.catalina.core.StandardEngine [DirectJDKLog.java:173] Starting Servlet engine: [Apache Tomcat/9.0.56] 2022-04-06 23:19:56.128 [main] INFO o.a.c.c.C.[Tomcat].[localhost].[/] [DirectJDKLog.java:173] Initializing Spring embedded WebApplicationContext 2022-04-06 23:19:56.129 [main] INFO o.s.b.w.s.c.ServletWebServerApplicationContext [ServletWebServerApplicationContext.java:290] Root WebApplicationContext: initialization completed in 15736 ms 2022-04-06 23:19:56.271 [main] INFO c.u.f.j.s.FhirServerConfigCommon [FhirServerConfigCommon.java:39] Server configured to allow contains searches 2022-04-06 23:19:56.272 [main] INFO c.u.f.j.s.FhirServerConfigCommon [FhirServerConfigCommon.java:40] Server configured to deny multiple deletes 2022-04-06 23:19:56.273 [main] INFO c.u.f.j.s.FhirServerConfigCommon [FhirServerConfigCommon.java:41] Server configured to deny external references 2022-04-06 23:19:56.273 [main] INFO c.u.f.j.s.FhirServerConfigCommon [FhirServerConfigCommon.java:42] Server configured to disable delete expunges 2022-04-06 23:19:56.274 [main] INFO c.u.f.j.s.FhirServerConfigCommon [FhirServerConfigCommon.java:43] Server configured to enable expunges 2022-04-06 23:19:56.275 [main] INFO c.u.f.j.s.FhirServerConfigCommon [FhirServerConfigCommon.java:44] Server configured to allow overriding default search params 2022-04-06 23:19:56.276 [main] INFO c.u.f.j.s.FhirServerConfigCommon [FhirServerConfigCommon.java:45] Server configured to disable auto-creating placeholder references 2022-04-06 23:19:56.415 [main] INFO c.u.f.j.s.FhirServerConfigCommon [FhirServerConfigCommon.java:95] Server configured to have a maximum fetch size of 'unlimited' 2022-04-06 23:19:56.416 [main] INFO c.u.f.j.s.FhirServerConfigCommon [FhirServerConfigCommon.java:99] Server configured to cache search results for 60000 milliseconds 2022-04-06 23:19:58.070 [main] INFO c.u.f.j.s.BaseSchedulerServiceImpl [BaseSchedulerServiceImpl.java:123] Creating Local Scheduler 2022-04-06 23:19:58.193 [main] INFO org.quartz.impl.StdSchedulerFactory [StdSchedulerFactory.java:1220] Using default implementation for ThreadExecutor 2022-04-06 23:19:58.248 [main] INFO o.quartz.core.SchedulerSignalerImpl [SchedulerSignalerImpl.java:61] Initialized Scheduler Signaller of type: class org.quartz.core.SchedulerSignalerImpl 2022-04-06 23:19:58.249 [main] INFO org.quartz.core.QuartzScheduler [QuartzScheduler.java:229] Quartz Scheduler v.2.3.2 created. 2022-04-06 23:19:58.252 [main] INFO org.quartz.simpl.RAMJobStore [RAMJobStore.java:155] RAMJobStore initialized. 2022-04-06 23:19:58.254 [main] INFO org.quartz.core.QuartzScheduler [QuartzScheduler.java:294] Scheduler meta-data: Quartz Scheduler (v2.3.2) 'hapi-fhir-jpa-scheduler' with instanceId 'NON_CLUSTERED' Scheduler class: 'org.quartz.core.QuartzScheduler' - running locally. NOT STARTED. Currently in standby mode. Number of jobs executed: 0 Using thread pool 'org.quartz.simpl.SimpleThreadPool' - with 4 threads. Using job-store 'org.quartz.simpl.RAMJobStore' - which does not support persistence. and is not clustered. 2022-04-06 23:19:58.255 [main] INFO org.quartz.impl.StdSchedulerFactory [StdSchedulerFactory.java:1374] Quartz scheduler 'hapi-fhir-jpa-scheduler' initialized from an externally provided properties instance. 2022-04-06 23:19:58.256 [main] INFO org.quartz.impl.StdSchedulerFactory [StdSchedulerFactory.java:1378] Quartz scheduler version: 2.3.2 2022-04-06 23:19:58.257 [main] INFO org.quartz.core.QuartzScheduler [QuartzScheduler.java:2293] JobFactory set to: ca.uhn.fhir.jpa.sched.AutowiringSpringBeanJobFactory@14dc3f89 2022-04-06 23:19:58.257 [main] INFO org.quartz.core.QuartzScheduler [QuartzScheduler.java:585] Scheduler hapi-fhir-jpa-scheduler_$_NON_CLUSTERED paused. 2022-04-06 23:19:58.258 [main] INFO c.u.f.j.s.BaseSchedulerServiceImpl [BaseSchedulerServiceImpl.java:120] Creating Clustered Scheduler 2022-04-06 23:19:58.261 [main] INFO org.quartz.impl.StdSchedulerFactory [StdSchedulerFactory.java:1220] Using default implementation for ThreadExecutor 2022-04-06 23:19:58.294 [main] INFO o.quartz.core.SchedulerSignalerImpl [SchedulerSignalerImpl.java:61] Initialized Scheduler Signaller of type: class org.quartz.core.SchedulerSignalerImpl 2022-04-06 23:19:58.295 [main] INFO org.quartz.core.QuartzScheduler [QuartzScheduler.java:229] Quartz Scheduler v.2.3.2 created. 2022-04-06 23:19:58.296 [main] INFO org.quartz.simpl.RAMJobStore [RAMJobStore.java:155] RAMJobStore initialized. 2022-04-06 23:19:58.296 [main] INFO org.quartz.core.QuartzScheduler [QuartzScheduler.java:294] Scheduler meta-data: Quartz Scheduler (v2.3.2) 'hapi-fhir-jpa-scheduler' with instanceId 'NON_CLUSTERED' Scheduler class: 'org.quartz.core.QuartzScheduler' - running locally. NOT STARTED. Currently in standby mode. Number of jobs executed: 0 Using thread pool 'org.quartz.simpl.SimpleThreadPool' - with 4 threads. Using job-store 'org.quartz.simpl.RAMJobStore' - which does not support persistence. and is not clustered. 2022-04-06 23:19:58.297 [main] INFO org.quartz.impl.StdSchedulerFactory [StdSchedulerFactory.java:1374] Quartz scheduler 'hapi-fhir-jpa-scheduler' initialized from an externally provided properties instance. 2022-04-06 23:19:58.297 [main] INFO org.quartz.impl.StdSchedulerFactory [StdSchedulerFactory.java:1378] Quartz scheduler version: 2.3.2 2022-04-06 23:19:58.298 [main] INFO org.quartz.core.QuartzScheduler [QuartzScheduler.java:2293] JobFactory set to: ca.uhn.fhir.jpa.sched.AutowiringSpringBeanJobFactory@14dc3f89 2022-04-06 23:19:58.298 [main] INFO org.quartz.core.QuartzScheduler [QuartzScheduler.java:585] Scheduler hapi-fhir-jpa-scheduler_$_NON_CLUSTERED paused. 2022-04-06 23:19:58.801 [main] INFO com.zaxxer.hikari.HikariDataSource [HikariDataSource.java:95] HikariPool-1 - Starting... 2022-04-06 23:19:59.204 [main] INFO com.zaxxer.hikari.HikariDataSource [HikariDataSource.java:107] HikariPool-1 - Start completed. 2022-04-06 23:19:59.284 [main] INFO o.f.c.i.license.VersionPrinter [Slf4jLog.java:37] Flyway Community Edition 8.4.1 by Redgate 2022-04-06 23:19:59.299 [main] INFO o.f.c.i.d.base.BaseDatabaseType [Slf4jLog.java:37] Database: jdbc:postgresql://hapi-fhir-postgresql:5432/fhir (PostgreSQL 11.13) 2022-04-06 23:19:59.451 [main] INFO o.f.core.internal.command.DbValidate [Slf4jLog.java:37] Successfully validated 1 migration (execution time 00:00.035s) 2022-04-06 23:19:59.506 [main] INFO o.f.core.internal.command.DbMigrate [Slf4jLog.java:37] Current version of schema "public": 1 2022-04-06 23:19:59.507 [main] INFO o.f.core.internal.command.DbMigrate [Slf4jLog.java:37] Schema "public" is up to date. No migration necessary. 2022-04-06 23:19:59.985 [main] INFO o.h.jpa.internal.util.LogHelper [LogHelper.java:31] HHH000204: Processing PersistenceUnitInfo [name: HAPI_PU] 2022-04-06 23:20:00.268 [main] INFO org.hibernate.Version [Version.java:44] HHH000412: Hibernate ORM core version 5.6.2.Final 2022-04-06 23:20:00.749 [main] INFO o.h.annotations.common.Version [JavaReflectionManager.java:56] HCANN000001: Hibernate Commons Annotations {5.1.2.Final} 2022-04-06 23:20:01.482 [main] INFO org.hibernate.dialect.Dialect [Dialect.java:175] HHH000400: Using dialect: ca.uhn.fhir.jpa.model.dialect.HapiFhirH2Dialect 2022-04-06 23:20:03.482 [main] INFO o.h.validator.internal.util.Version [Version.java:21] HV000001: Hibernate Validator 6.1.5.Final 2022-04-06 23:20:04.352 [main] INFO o.h.s.m.o.b.i.HibernateSearchIntegrator [HibernateSearchIntegrator.java:65] HSEARCH000034: Hibernate Search version 6.0.3.Final 2022-04-06 23:20:07.093 [main] WARN o.h.t.s.i.ExceptionHandlerLoggedImpl [ExceptionHandlerLoggedImpl.java:27] GenerationTarget encountered exception accepting command : Error executing DDL "create table hfj_binary_storage_blob (blob_id varchar(200) not null, blob_data blob not null, content_type varchar(100) not null, blob_hash varchar(128), published_date timestamp not null, resource_id varchar(100) not null, blob_size integer, primary key (blob_id))" via JDBC Statement org.hibernate.tool.schema.spi.CommandAcceptanceException: Error executing DDL "create table hfj_binary_storage_blob (blob_id varchar(200) not null, blob_data blob not null, content_type varchar(100) not null, blob_hash varchar(128), published_date timestamp not null, resource_id varchar(100) not null, blob_size integer, primary key (blob_id))" via JDBC Statement at org.hibernate.tool.schema.internal.exec.GenerationTargetToDatabase.accept(GenerationTargetToDatabase.java:67) at org.hibernate.tool.schema.internal.AbstractSchemaMigrator.applySqlString(AbstractSchemaMigrator.java:581) at org.hibernate.tool.schema.internal.AbstractSchemaMigrator.applySqlStrings(AbstractSchemaMigrator.java:526) at org.hibernate.tool.schema.internal.AbstractSchemaMigrator.createTable(AbstractSchemaMigrator.java:293) at org.hibernate.tool.schema.internal.GroupedSchemaMigratorImpl.performTablesMigration(GroupedSchemaMigratorImpl.java:74) at org.hibernate.tool.schema.internal.AbstractSchemaMigrator.performMigration(AbstractSchemaMigrator.java:220) at org.hibernate.tool.schema.internal.AbstractSchemaMigrator.doMigration(AbstractSchemaMigrator.java:123) at org.hibernate.tool.schema.spi.SchemaManagementToolCoordinator.performDatabaseAction(SchemaManagementToolCoordinator.java:192) at org.hibernate.tool.schema.spi.SchemaManagementToolCoordinator.process(SchemaManagementToolCoordinator.java:81) at org.hibernate.internal.SessionFactoryImpl.