Quarkus: Flyway with "multiple datasources" does not migrate at start

Created on 18 May 2020  Â·  15Comments  Â·  Source: quarkusio/quarkus

Describe the bug
There are two datasources that should be be migrated on startup by Flyway, but the scripts are not executed. From the logs it can bee seen that the directories are recognized correctly by the Flyway extension, but not applied later. This has been working before (~1.3.x) and stopped working with current master source.

Example (database/mycompany)

Adding application migrations in path 'quarkus-quickstarts/hibernate-orm-quickstart-multi-tenancy/target/classes/database/mycompany/' using protocol 'file'
Database: jdbc:postgresql://localhost:5433/mycompany
Current version of schema "mycompany": null
Schema "mycompany" is up to date. No migration necessary.

Expected behavior
The scripts in "src/main/resources/database" should be used for migration on startup.

Actual behavior
The scripts in "src/main/resources/database" are not applied on startup.

To Reproduce
Steps to reproduce the behavior:

  1. Checkout Quickstart fork: https://github.com/michael-schnell/quarkus-quickstarts/
  2. Change into hibernate-orm-quickstart-multi-tenancy
  3. Execute "DATABASE Multitenancy" example as described in README.md
  4. Check the log output: The two datasource schemas "base" and "mycompany" are not applied

Configuration
See https://github.com/michael-schnell/quarkus-quickstarts/blob/master/hibernate-orm-quickstart-multi-tenancy/src/main/resources/application.properties

Log

2020-05-18 16:04:33,275 INFO  [io.qua.fly.FlywayProcessor] (build-61) Adding application migrations in path 'quarkus-quickstarts/hibernate-orm-quickstart-multi-tenancy/target/classes/db/migration/' using protocol 'file'
2020-05-18 16:04:33,277 INFO  [io.qua.fly.FlywayProcessor] (build-61) Adding application migrations in path 'quarkus-quickstarts/hibernate-orm-quickstart-multi-tenancy/target/classes/database/mycompany/' using protocol 'file'
2020-05-18 16:04:33,291 INFO  [io.qua.fly.FlywayProcessor] (build-61) Adding application migrations in path 'quarkus-quickstarts/hibernate-orm-quickstart-multi-tenancy/target/classes/database/base/' using protocol 'file'
2020-05-18 16:04:33,291 INFO  [io.qua.fly.FlywayProcessor] (build-61) Adding application migrations in path 'quarkus-quickstarts/hibernate-orm-quickstart-multi-tenancy/target/classes/db/migration/' using protocol 'file'
2020-05-18 16:04:36,831 INFO  [io.agr.pool] (Quarkus Main Thread) Datasource '<default>': Initial size smaller than min. Connections will be created when necessary
2020-05-18 16:04:36,835 INFO  [io.agr.pool] (Quarkus Main Thread) Datasource 'mycompany': Initial size smaller than min. Connections will be created when necessary
2020-05-18 16:04:36,840 INFO  [io.agr.pool] (Quarkus Main Thread) Datasource 'base': Initial size smaller than min. Connections will be created when necessary
2020-05-18 16:04:36,938 INFO  [org.fly.cor.int.lic.VersionPrinter] (Quarkus Main Thread) Flyway Community Edition 6.4.2 by Redgate
2020-05-18 16:04:37,092 INFO  [org.fly.cor.int.dat.DatabaseFactory] (Quarkus Main Thread) Database: jdbc:postgresql://localhost:5433/mycompany (PostgreSQL 12.2)
2020-05-18 16:04:37,123 INFO  [org.fly.cor.int.com.DbMigrate] (Quarkus Main Thread) Current version of schema "mycompany": null
2020-05-18 16:04:37,124 INFO  [org.fly.cor.int.com.DbMigrate] (Quarkus Main Thread) Schema "mycompany" is up to date. No migration necessary.
2020-05-18 16:04:37,140 INFO  [org.fly.cor.int.dat.DatabaseFactory] (Quarkus Main Thread) Database: jdbc:postgresql://localhost:5432/quarkus_test (PostgreSQL 12.2)
2020-05-18 16:04:37,153 INFO  [org.fly.cor.int.com.DbMigrate] (Quarkus Main Thread) Current version of schema "public": << Empty Schema >>
2020-05-18 16:04:37,153 INFO  [org.fly.cor.int.com.DbMigrate] (Quarkus Main Thread) Schema "public" is up to date. No migration necessary.
2020-05-18 16:04:37,685 INFO  [io.quarkus] (Quarkus Main Thread) hibernate-orm-quickstart-multi-tenancy 1.0-SNAPSHOT on JVM (powered by Quarkus 999-SNAPSHOT) started in 6.337s. Listening on: http://0.0.0.0:8080
2020-05-18 16:04:37,687 INFO  [io.quarkus] (Quarkus Main Thread) Profile database activated. Live Coding activated.
2020-05-18 16:04:37,688 INFO  [io.quarkus] (Quarkus Main Thread) Installed features: [agroal, cdi, flyway, hibernate-orm, jdbc-postgresql, mutiny, narayana-jta, resteasy, resteasy-jsonb]
^C2020-05-18 16:04:42,798 INFO  [io.quarkus] (Quarkus Main Thread) hibernate-orm-quickstart-multi-tenancy stopped in 0.029s

Environment (please complete the following information):

  • Linux quarkus-vm 4.15.0-20-generic #21-Ubuntu SMP Tue Apr 24 06:16:15 UTC 2018 x86_64 x86_64 x86_64 GNU/Linux
  • openjdk version "11.0.6" 2020-01-14
  • OpenJDK Runtime Environment GraalVM CE 20.0.0 (build 11.0.6+9-jvmci-20.0-b02)
  • OpenJDK 64-Bit Server VM GraalVM CE 20.0.0 (build 11.0.6+9-jvmci-20.0-b02, mixed mode, sharing)
  • Quarkus: Commit 87522320380e9f201a2f4c027f3e50bc1ffd6f06
  • apache-maven-3.6.2

Additional context
I'm currently preparing a quickstart for the new Hibernate multi-tenancy feature. This example was already working fine with 999-SNAPSHOT from source ~1.3.x, but it fails now with current Quarkus master source. The problem is actually not related to the new feature as it happens before anything from that code is executed. The problem is just the missing Flyway migration. It seems to be something that changed between ~1.3.x and the current master most likely in the Flyway extension.

kinbug

Most helpful comment

I'll take a look

All 15 comments

@barreiro @Sanne @geoand @gsmet Any idea?

Funny thing is, that in the integration test it's working with a very similar setup...

I'll take a look

I am using the absolute latest Quarkus from master, and I see

2020-05-18 17:52:39,102 INFO  [io.qua.fly.FlywayProcessor] (build-25) Adding application migrations in path '/home/gandrian/Desktop/quarkus-quickstarts/hibernate-orm-quickstart-multi-tenancy/target/classes/database/mycompany/' using protocol 'file'
2020-05-18 17:52:39,104 INFO  [io.qua.fly.FlywayProcessor] (build-25) Adding application migrations in path '/home/gandrian/Desktop/quarkus-quickstarts/hibernate-orm-quickstart-multi-tenancy/target/classes/database/base/' using protocol 'file'
2020-05-18 17:52:39,850 INFO  [io.agr.pool] (Quarkus Main Thread) Datasource '<default>': Initial size smaller than min. Connections will be created when necessary
2020-05-18 17:52:39,851 INFO  [io.agr.pool] (Quarkus Main Thread) Datasource 'mycompany': Initial size smaller than min. Connections will be created when necessary
2020-05-18 17:52:39,851 INFO  [io.agr.pool] (Quarkus Main Thread) Datasource 'base': Initial size smaller than min. Connections will be created when necessary
2020-05-18 17:52:39,879 INFO  [org.fly.cor.int.lic.VersionPrinter] (Quarkus Main Thread) Flyway Community Edition 6.4.2 by Redgate
2020-05-18 17:52:39,880 WARN  [org.fly.cor.int.sca.cla.ClassPathScanner] (Quarkus Main Thread) Unable to resolve location classpath:db/migration. Note this warning will become an error in Flyway 7.
2020-05-18 17:52:39,939 INFO  [org.fly.cor.int.dat.DatabaseFactory] (Quarkus Main Thread) Database: jdbc:postgresql://localhost:5433/mycompany (PostgreSQL 12.2)
2020-05-18 17:52:39,954 INFO  [org.fly.cor.int.com.DbMigrate] (Quarkus Main Thread) Current version of schema "public": << Empty Schema >>
2020-05-18 17:52:39,954 INFO  [org.fly.cor.int.com.DbMigrate] (Quarkus Main Thread) Schema "public" is up to date. No migration necessary.
2020-05-18 17:52:39,956 WARN  [org.fly.cor.int.sca.cla.ClassPathScanner] (Quarkus Main Thread) Unable to resolve location classpath:db/migration. Note this warning will become an error in Flyway 7.
2020-05-18 17:52:39,962 INFO  [org.fly.cor.int.dat.DatabaseFactory] (Quarkus Main Thread) Database: jdbc:postgresql://localhost:5432/quarkus_test (PostgreSQL 12.2)
2020-05-18 17:52:39,969 INFO  [org.fly.cor.int.com.DbMigrate] (Quarkus Main Thread) Current version of schema "public": << Empty Schema >>
2020-05-18 17:52:39,969 INFO  [org.fly.cor.int.com.DbMigrate] (Quarkus Main Thread) Schema "public" is up to date. No migration necessary.

Which suggests to me that it's working (I am not really a Flyway user so I might be missing something).
Are you seeing something else or am I missing something?

It says "Current version of schema "public": << Empty Schema >>" and " Schema "public" is up to date. No migration necessary." which means nothing is applied. If you look at the database it has the Flyway table, but no version - Should be "V1.0.0__create_fruits.sql" for both databases. Before it worked fine and both scripts were picked up on startup and there was a table "fruits" created by the scripts in both databases. Now there is no table created.

Should be something like:

INFO  [org.fly.cor.int.com.DbMigrate] (Quarkus Main Thread) Migrating schema "public" to version 1.0.0 - create fruits

Turns out that this problem is rather serious.

What I am seeing is that when multiple datasources are being used, dev-mode does not populate the named datasources of FlywayBuildTimeConfig.

Here is a screenshot from the debugger of the non-working dev-mode (notice the 0 in namedDataSources of flywayBuildConfig, the flywayRuntimeConfig however seems correct):

dev-mode

and here is the screenshot of the same point in the code for a prod-mode jar:

prod-mode

I could keep digging to try and figure out what the problem is, but I would appreciate some input from @stuartwdouglas and @dmlloyd

Same when using the 'database' profile that is required for the quickstart when using a database per tenant.

Example in native mode which also does not work:

./target/hibernate-orm-quickstart-multi-tenancy-1.0-SNAPSHOT-runner -Dquarkus.profile=database

In any case, if no one beats me to it, I'll continue debugging tomorrow

It's probably related to
https://github.com/quarkusio/quarkus/commit/86c18ff469b1fbb8b8d24daa7518932eba31fb26
,
although without this commit dev mode injection of beans does not work at
all, so you can't just revert it to check.

I think this is the same issue as
https://github.com/quarkusio/quarkus/issues/9296 .

I am going to investigate more, however this code is really complex so it
may take some time.

Stuart

On Tue, 19 May 2020 at 03:31, Georgios Andrianakis notifications@github.com
wrote:

In any case, if no one beats me to it, I'll continue debugging tomorrow

—
You are receiving this because you were mentioned.
Reply to this email directly, view it on GitHub
https://github.com/quarkusio/quarkus/issues/9415#issuecomment-630330191,
or unsubscribe
https://github.com/notifications/unsubscribe-auth/AACQG62XZVVDKEJUB7V7HXDRSFWIDANCNFSM4NEEOY2A
.

The issue is here:
https://github.com/quarkusio/quarkus/commit/86c18ff469b1fbb8b8d24daa7518932eba31fb26#diff-7fbde848a99a6f09343b25f15981ee40R618

Something to do with the converters, but I am still looking into it.

Stuart

On Tue, 19 May 2020 at 13:11, Stuart Douglas sdouglas@redhat.com wrote:

It's probably related to
https://github.com/quarkusio/quarkus/commit/86c18ff469b1fbb8b8d24daa7518932eba31fb26 ,
although without this commit dev mode injection of beans does not work at
all, so you can't just revert it to check.

I think this is the same issue as
https://github.com/quarkusio/quarkus/issues/9296 .

I am going to investigate more, however this code is really complex so it
may take some time.

Stuart

On Tue, 19 May 2020 at 03:31, Georgios Andrianakis <
[email protected]> wrote:

In any case, if no one beats me to it, I'll continue debugging tomorrow

—
You are receiving this because you were mentioned.
Reply to this email directly, view it on GitHub
https://github.com/quarkusio/quarkus/issues/9415#issuecomment-630330191,
or unsubscribe
https://github.com/notifications/unsubscribe-auth/AACQG62XZVVDKEJUB7V7HXDRSFWIDANCNFSM4NEEOY2A
.

I'll look as well

I think I have a fix https://github.com/quarkusio/quarkus/issues/9296

On Tue, 19 May 2020 at 15:31, Georgios Andrianakis notifications@github.com
wrote:

I'll look as well

—
You are receiving this because you were mentioned.
Reply to this email directly, view it on GitHub
https://github.com/quarkusio/quarkus/issues/9415#issuecomment-630590029,
or unsubscribe
https://github.com/notifications/unsubscribe-auth/AACQG623HQ6VBEXEWLYKI43RSIKSVANCNFSM4NEEOY2A
.

Cool, looking

I tested with the new quickstart project again and dev mode works now fine.

Unfortunately in native mode the profile is still not picked up (Flyway is not started for migartion).

Starting with ./mvnw quarkus:dev -Dquarkus.profile=database works:

2020-05-20 15:23:39,881 INFO  [io.qua.fly.FlywayProcessor] (build-34) Adding application migrations in path 'quarkus-quickstarts/hibernate-orm-quickstart-multi-tenancy/target/classes/db/migration/' using protocol 'file'
2020-05-20 15:23:39,903 INFO  [io.qua.fly.FlywayProcessor] (build-34) Adding application migrations in path 'quarkus-quickstarts/hibernate-orm-quickstart-multi-tenancy/target/classes/database/mycompany/' using protocol 'file'
2020-05-20 15:23:39,904 INFO  [io.qua.fly.FlywayProcessor] (build-34) Adding application migrations in path 'quarkus-quickstarts/hibernate-orm-quickstart-multi-tenancy/target/classes/database/base/' using protocol 'file'
2020-05-20 15:23:39,904 INFO  [io.qua.fly.FlywayProcessor] (build-34) Adding application migrations in path 'quarkus-quickstarts/hibernate-orm-quickstart-multi-tenancy/target/classes/db/migration/' using protocol 'file'
2020-05-20 15:23:42,652 INFO  [io.agr.pool] (Quarkus Main Thread) Datasource '<default>': Initial size smaller than min. Connections will be created when necessary
2020-05-20 15:23:42,656 INFO  [io.agr.pool] (Quarkus Main Thread) Datasource '<default>': Pool interceptors: []
2020-05-20 15:23:42,662 INFO  [io.agr.pool] (Quarkus Main Thread) Datasource 'mycompany': Initial size smaller than min. Connections will be created when necessary
2020-05-20 15:23:42,663 INFO  [io.agr.pool] (Quarkus Main Thread) Datasource 'mycompany': Pool interceptors: []
2020-05-20 15:23:42,666 INFO  [io.agr.pool] (Quarkus Main Thread) Datasource 'base': Initial size smaller than min. Connections will be created when necessary
2020-05-20 15:23:42,666 INFO  [io.agr.pool] (Quarkus Main Thread) Datasource 'base': Pool interceptors: []
2020-05-20 15:23:42,681 INFO  [org.fly.cor.int.lic.VersionPrinter] (Quarkus Main Thread) Flyway Community Edition 6.4.2 by Redgate
2020-05-20 15:23:42,868 INFO  [org.fly.cor.int.dat.DatabaseFactory] (Quarkus Main Thread) Database: jdbc:postgresql://localhost:5433/mycompany (PostgreSQL 12.2)
2020-05-20 15:23:42,917 INFO  [org.fly.cor.int.sch.JdbcTableSchemaHistory] (Quarkus Main Thread) Creating Schema History table "public"."flyway_schema_history" ...
2020-05-20 15:23:42,996 INFO  [org.fly.cor.int.com.DbMigrate] (Quarkus Main Thread) Current version of schema "public": << Empty Schema >>
2020-05-20 15:23:43,001 INFO  [org.fly.cor.int.com.DbMigrate] (Quarkus Main Thread) Migrating schema "public" to version 1.0.0 - create fruits
2020-05-20 15:23:43,005 INFO  [org.fly.cor.int.sql.DefaultSqlScriptExecutor] (Quarkus Main Thread) +--------+
| setval |
+--------+
| 3      |
+--------+

2020-05-20 15:23:43,023 INFO  [org.fly.cor.int.com.DbMigrate] (Quarkus Main Thread) Successfully applied 1 migration to schema "public" (execution time 00:00.043s)
2020-05-20 15:23:43,042 INFO  [org.fly.cor.int.dat.DatabaseFactory] (Quarkus Main Thread) Database: jdbc:postgresql://localhost:5432/quarkus_test (PostgreSQL 12.2)
2020-05-20 15:23:43,056 INFO  [org.fly.cor.int.sch.JdbcTableSchemaHistory] (Quarkus Main Thread) Creating Schema History table "public"."flyway_schema_history" ...
2020-05-20 15:23:43,108 INFO  [org.fly.cor.int.com.DbMigrate] (Quarkus Main Thread) Current version of schema "public": << Empty Schema >>
2020-05-20 15:23:43,111 INFO  [org.fly.cor.int.com.DbMigrate] (Quarkus Main Thread) Migrating schema "public" to version 1.0.0 - create fruits
2020-05-20 15:23:43,114 INFO  [org.fly.cor.int.sql.DefaultSqlScriptExecutor] (Quarkus Main Thread) +--------+
| setval |
+--------+
| 3      |
+--------+

2020-05-20 15:23:43,132 INFO  [org.fly.cor.int.com.DbMigrate] (Quarkus Main Thread) Successfully applied 1 migration to schema "public" (execution time 00:00.033s)
2020-05-20 15:23:43,642 INFO  [io.quarkus] (Quarkus Main Thread) hibernate-orm-quickstart-multi-tenancy 1.0-SNAPSHOT on JVM (powered by Quarkus 999-SNAPSHOT) started in 5.393s. Listening on: http://0.0.0.0:8080
2020-05-20 15:23:43,645 INFO  [io.quarkus] (Quarkus Main Thread) Profile database activated. Live Coding activated.
2020-05-20 15:23:43,645 INFO  [io.quarkus] (Quarkus Main Thread) Installed features: [agroal, cdi, flyway, hibernate-orm, jdbc-postgresql, mutiny, narayana-jta, resteasy, resteasy-jsonb]

Same in native mode with ./target/hibernate-orm-quickstart-multi-tenancy-1.0-SNAPSHOT-runner -Dquarkus.profile=database does not show any Flyway activity:

2020-05-20 15:28:19,661 INFO  [io.agr.pool] (main) Datasource '<default>': Initial size smaller than min. Connections will be created when necessary
2020-05-20 15:28:19,662 INFO  [io.agr.pool] (main) Datasource '<default>': Pool interceptors: []
2020-05-20 15:28:19,667 INFO  [io.quarkus] (main) hibernate-orm-quickstart-multi-tenancy 1.0-SNAPSHOT native (powered by Quarkus 999-SNAPSHOT) started in 0.022s. Listening on: http://0.0.0.0:8080
2020-05-20 15:28:19,667 INFO  [io.quarkus] (main) Profile database activated. 
2020-05-20 15:28:19,667 INFO  [io.quarkus] (main) Installed features: [agroal, cdi, flyway, hibernate-orm, jdbc-postgresql, mutiny, narayana-jta, resteasy, resteasy-jsonb]

It seems again to be related to the profile, as Flyway correctly shows up if no profile is used with ./target/hibernate-orm-quickstart-multi-tenancy-1.0-SNAPSHOT-runner:

2020-05-20 15:29:34,842 INFO  [io.agr.pool] (main) Datasource '<default>': Initial size smaller than min. Connections will be created when necessary
2020-05-20 15:29:34,843 INFO  [io.agr.pool] (main) Datasource '<default>': Pool interceptors: []
2020-05-20 15:29:34,843 INFO  [org.fly.cor.int.lic.VersionPrinter] (main) Flyway Community Edition 6.4.2 by Redgate
2020-05-20 15:29:34,849 INFO  [org.fly.cor.int.dat.DatabaseFactory] (main) Database: jdbc:postgresql://localhost:5432/quarkus_test (PostgreSQL 12.2)
2020-05-20 15:29:34,860 INFO  [org.fly.cor.int.dat.bas.Schema] (main) Creating schema "base" ...
2020-05-20 15:29:34,861 INFO  [org.fly.cor.int.dat.bas.Schema] (main) Creating schema "mycompany" ...
2020-05-20 15:29:34,863 INFO  [org.fly.cor.int.sch.JdbcTableSchemaHistory] (main) Creating Schema History table "base"."flyway_schema_history" ...
2020-05-20 15:29:34,900 INFO  [org.fly.cor.int.com.DbMigrate] (main) Current version of schema "base": null
2020-05-20 15:29:34,903 INFO  [org.fly.cor.int.com.DbMigrate] (main) Migrating schema "base" to version 1.0.0 - create fruits
2020-05-20 15:29:34,904 INFO  [org.fly.cor.int.sql.DefaultSqlScriptExecutor] (main) +--------+
| setval |
+--------+
| 3      |
+--------+

2020-05-20 15:29:34,907 INFO  [org.fly.cor.int.sql.DefaultSqlScriptExecutor] (main) +--------+
| setval |
+--------+
| 3      |
+--------+

2020-05-20 15:29:34,920 INFO  [org.fly.cor.int.com.DbMigrate] (main) Successfully applied 1 migration to schema "base" (execution time 00:00.021s)
2020-05-20 15:29:34,928 INFO  [io.quarkus] (main) hibernate-orm-quickstart-multi-tenancy 1.0-SNAPSHOT native (powered by Quarkus 999-SNAPSHOT) started in 0.103s. Listening on: http://0.0.0.0:8080
2020-05-20 15:29:34,928 INFO  [io.quarkus] (main) Profile prod activated. 
2020-05-20 15:29:34,928 INFO  [io.quarkus] (main) Installed features: [agroal, cdi, flyway, hibernate-orm, jdbc-postgresql, mutiny, narayana-jta, resteasy, resteasy-jsonb]

Seems as if the fix only was half the way.

@stuartwdouglas @geoand Any idea?

The fix was indeed only for dev-mode. Can you please open a new issue for the problem you are seeing in native?

OK

Was this page helpful?
0 / 5 - 0 ratings