Devmode, Liquibase: Changelog file is found twice if located in another Maven module

[famod]

Describe the bug
Application startup fails in Devmode if I try to auto-migrate with a changelog file that comes from another Maven module because Liquibase finds it two times on the classpath (once in the jar and once from the module target).

Expected behavior
No failure. In Devmode, the one from target should be used, IMHO.

Actual behavior

ERROR: Failed to start application
java.lang.IllegalStateException: liquibase.exception.ChangeLogParseException: Error Reading Migration File: Found 2 files that match db/changeLog.xml
        at io.quarkus.liquibase.runtime.LiquibaseRecorder.doStartActions(LiquibaseRecorder.java:69)
        at io.quarkus.deployment.steps.LiquibaseProcessor$createBeansAndStartActions2123523327.deploy_0(LiquibaseProcessor$createBeansAndStartActions2123523327.zig:76)
        at io.quarkus.deployment.steps.LiquibaseProcessor$createBeansAndStartActions2123523327.deploy(LiquibaseProcessor$createBeansAndStartActions2123523327.zig:36)
        at io.quarkus.runner.ApplicationImpl.doStart(ApplicationImpl.zig:356)
        at io.quarkus.runtime.Application.start(Application.java:90)
        at io.quarkus.runtime.ApplicationLifecycleManager.run(ApplicationLifecycleManager.java:90)
        at io.quarkus.runtime.Quarkus.run(Quarkus.java:61)
        at io.quarkus.runtime.Quarkus.run(Quarkus.java:38)
        at io.quarkus.runtime.Quarkus.run(Quarkus.java:106)
        at io.quarkus.runner.GeneratedMain.main(GeneratedMain.zig:29)
        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:566)
        at io.quarkus.runner.bootstrap.StartupActionImpl$3.run(StartupActionImpl.java:144)
        at java.base/java.lang.Thread.run(Thread.java:834)
Caused by: liquibase.exception.ChangeLogParseException: Error Reading Migration File: Found 2 files that match db/changeLog.xml
        at liquibase.parser.core.xml.XMLChangeLogSAXParser.parseToNode(XMLChangeLogSAXParser.java:118)
        at liquibase.parser.core.xml.AbstractChangeLogParser.parse(AbstractChangeLogParser.java:15)
        at liquibase.Liquibase.getDatabaseChangeLog(Liquibase.java:217)
        at liquibase.Liquibase.validate(Liquibase.java:1559)
        at io.quarkus.liquibase.runtime.LiquibaseRecorder.doStartActions(LiquibaseRecorder.java:60)
        ... 15 more
Caused by: java.io.IOException: Found 2 files that match db/changeLog.xml
        at liquibase.util.StreamUtil.singleInputStream(StreamUtil.java:206)
        at liquibase.parser.core.xml.XMLChangeLogSAXParser.parseToNode(XMLChangeLogSAXParser.java:71)
        ... 19 more

To Reproduce
Steps to reproduce the behavior:

1. Clone https://github.com/famod/quarkus-liquibase-dup
   (this is just the official quickstart split into two modules and without h2 tcp, which caused problems on my machine)
2. Passes: mvn clean install (includes a test)
3. Passes: java -jar app/target/liquibase-dup-app-1.0-SNAPSHOT-runner.jar
4. Fails: mvn quarkus:dev -f app (or without -f from within app )

Configuration

quarkus.datasource.db-kind=h2
quarkus.datasource.username=sa
quarkus.datasource.password=sa
quarkus.datasource.jdbc.url=jdbc:h2:mem:test_quarkus;DB_CLOSE_DELAY=-1
quarkus.liquibase.migrate-at-start=true

Screenshots
n/a

Environment (please complete the following information):

• Output of uname -a or ver:

  MINGW64_NT-10.0-18363 XXX 3.1.4-340.x86_64 2020-05-19 12:55 UTC x86_64 Msys
  

• Output of java -version:

  openjdk version "11.0.6" 2020-01-14
  OpenJDK Runtime Environment AdoptOpenJDK (build 11.0.6+10)
  OpenJDK 64-Bit Server VM AdoptOpenJDK (build 11.0.6+10, mixed mode)
  

• GraalVM version (if different from Java): n/a
• Quarkus version or git rev: 1.4.2.Final, 1.5.2.Final, 1.6.0.CR1
• Build tool (ie. output of mvnw --version or gradlew --version): Apache Maven 3.6.3

Additional context
There have been two fixes before, but both adressed Gradle:

• Liquibase in dev mode detects duplicate changeLog file #8400
• Liquibase still detects multiple changelogs despite upgrade to 1.4.1 #8984

[quarkusbot]

/cc @quarkusio/devtools

[famod]

cc @tkalmar @harthorst (team members)

[geoand]

This seems like the gift that keeps on giving...

[geoand]

I'll take a look tomorrow if no one else does before then

[famod]

For this case there is a German saying that would go something like: After the bug is before the bug. 😄

Might be a stupid idea, but I am wondering whether devmode should (in general) try to filter out resources from jars in case they are "mappable" to target paths.

[geoand]

Not sure TBH, I need to look into this and see what is causing it.
Ideally dev mode should behave exactly the same as prod jar mode.

[famod]

This is the clash from our internal project (obfuscated):

file:/C:/Develop/some-project/middleware/_develop-2/some-project-middleware/user/core/target/classes/db/changeLog-user.xml
jar:file:/C:/Develop/some-project/middleware/_develop-2/maven/repo/com/some_company/some_project/middleware/middleware-user-core/0.1.0-SNAPSHOT/middleware-user-core-0.1.0-SNAPSHOT.jar!/db/changeLog-user.xml

[geoand]

Thanks

[famod]

And this is where both are found: https://github.com/liquibase/liquibase/blob/v3.8.9/liquibase-core/src/main/java/liquibase/util/StreamUtil.java#L186

[famod]

I forgot to mention that we are using a custom @Observes StartupEvent bean that uses io.quarkus.liquibase.LiquibaseFactory but then executes each found changelog file in a separate Liquibase run (because we need separate databaseChangeLogTableNames).

In this context we already use a liquibase.resource.ClassLoaderResourceAccessor to find the files upfront and since we just use the TCCL, we also get duplicates in devmode. As we are are only interested in the file names (not the full paths) we mitigate this problem by using a Set.
But for the actual Liquibase execution we cannot work around the problem since we can neither pass in our ClassLoaderResourceAccessor (which could use a custom "filtering" CL) nor can we pass in fully resolved file paths.

So in case your solution is based on a special "filtering" CL via ClassLoaderResourceAccessor, it would come in handy for use if we could somehow reuse this loader, ideally via io.quarkus.liquibase.runtime.LiquibaseConfig.

[geoand]

What I describe next is basically for @aloubyansky.

This problem occurs because the Quarkus Runtime Classloader loads the resource from the path (as the changelog module seems to be an additional application archive), then delegates to its parent (Quarkus Base Runtime Classloader) which in turn picks up the resource from the jar because it's not the classpath.

So the question is: Should sibling (yet dependency) module's the jar not be added to dev jar's classpath in this case (as it's a module that is discovered by bootstrap), or should bootstrap not pick up this module at all? I am assuming the first option is correct...

[famod]

Could this duplication also explain the CCE I am seeing here?
https://quarkusio.zulipchat.com/#narrow/stream/187030-users/topic/ClassCastException.20in.20dev.20mode.20but.20not.20with.20runner-jar
Or is this just about resources (not java sources)?

[geoand]

Not sure about that one, haven't checked. But my guess would be that it's unrelated

[aloubyansky]

@geoand are you saying the local module appears on the cp as a jar and as a classes dir?

[geoand]

Yes exactly. As a jar it's on the classpath of the dev jar (coming from m2) - this is what I assume should be removed.

[aloubyansky]

Yes. Is there a reproducer?

[geoand]

Yup, it's mentioned in the description of the issue: https://github.com/famod/quarkus-liquibase-dup

[aloubyansky]

Ok, thanks. Just to clarify, were you going to fix it @geoand ? Or do you want me to take care of that?

[geoand]

I'll look at it in morning and let you know if I need help.

[aloubyansky]

I'd like to get #9919 in first though to avoid rebasing it again.

[geoand]

Sure thing