Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

When Using Liquibase in Native Mode a ServiceConfigurationError is Logged #40575

Closed
gcw-it opened this issue May 11, 2024 · 17 comments · Fixed by #41928 · May be fixed by #41414
Closed

When Using Liquibase in Native Mode a ServiceConfigurationError is Logged #40575

gcw-it opened this issue May 11, 2024 · 17 comments · Fixed by #41928 · May be fixed by #41414
Milestone

Comments

@gcw-it
Copy link
Contributor

gcw-it commented May 11, 2024

Describe the bug

When Using Liquibase in Native Mode a ServiceConfigurationError is Logged.
This happens at least with Postgresql and H2.
The issue occurs at least since Quarkus 3.8.2
The error occurs for a local as well as an in-container build.
There seem to be no negative consequences of this error, besides polluting the application log.

Expected behavior

No Error is logged.

Actual behavior

At Quarkus start the following error is logged:

INFO  [liq.servicelocator] (main) Cannot load service: java.util.ServiceConfigurationError: liquibase.command.CommandStep: Provider liquibase.command.core.StartH2CommandStep not found
	at [email protected]/java.util.ServiceLoader.fail(ServiceLoader.java:593)
	at [email protected]/java.util.ServiceLoader$LazyClassPathLookupIterator.nextProviderClass(ServiceLoader.java:1219)
	at [email protected]/java.util.ServiceLoader$LazyClassPathLookupIterator.hasNextService(ServiceLoader.java:1228)
	at [email protected]/java.util.ServiceLoader$LazyClassPathLookupIterator.hasNext(ServiceLoader.java:1273)
	at [email protected]/java.util.ServiceLoader$2.hasNext(ServiceLoader.java:1309)
	at [email protected]/java.util.ServiceLoader$3.hasNext(ServiceLoader.java:1393)
	at liquibase.servicelocator.StandardServiceLocator.findInstances(StandardServiceLocator.java:22)
	at liquibase.command.CommandFactory.findAllInstances(CommandFactory.java:244)
	at liquibase.command.CommandFactory.computePipelineForCommandDefinition(CommandFactory.java:71)
	at liquibase.command.CommandFactory.getCommandDefinition(CommandFactory.java:50)
	at liquibase.command.CommandScope.<init>(CommandScope.java:64)
	at liquibase.Liquibase.lambda$validate$25(Liquibase.java:1365)
	at liquibase.Scope.lambda$child$0(Scope.java:190)
	at liquibase.Scope.child(Scope.java:199)
	at liquibase.Scopefor child(Scope.java:189)
	at liquibase.Scope.child(Scope.java:168)
	at liquibase.Liquibase.runInScope(Liquibase.java:1436)
	at liquibase.Liquibase.validate(Liquibase.java:1364)
	at io.quarkus.liquibase.runtime.LiquibaseRecorder.doStartActions(LiquibaseRecorder.java:79)
	at io.quarkus.deployment.steps.LiquibaseProcessor$startLiquibase1744275855.deploy_0(Unknown Source)
	at io.quarkus.deployment.steps.LiquibaseProcessor$startLiquibase1744275855.deploy(Unknown Source)
	at io.quarkus.runner.ApplicationImpl.doStart(Unknown Source)
	at io.quarkus.runtime.Application.start(Application.java:101)
	at io.quarkus.runtime.ApplicationLifecycleManager.run(ApplicationLifecycleManager.java:111)
	at io.quarkus.runtime.Quarkus.run(Quarkus.java:71)
	at io.quarkus.runtime.Quarkus.run(Quarkus.java:44)
	at io.quarkus.runtime.Quarkus.run(Quarkus.java:124)
	at io.quarkus.runner.GeneratedMain.main(Unknown Source)

The error is exactly the same for Postgresql and H2.
It probably occurs for other databases as well.

How to Reproduce?

  1. Use the liquibase-quickstart from quarkus-quickstarters.
  2. Run a H2 instance with remote database creation enabled.
  3. Compile and run the app in native mode.

Output of uname -a or ver

Darwin 23.4.0 Darwin Kernel Version 23.4.0: Fri Mar 15 00:11:05 PDT 2024; root:xnu-10063.101.17~1/RELEASE_X86_64 x86_64

Output of java -version

java 21.0.3 2024-04-16 LTS Java(TM) SE Runtime Environment Oracle GraalVM 21.0.3+7.1 (build 21.0.3+7-LTS-jvmci-23.1-b37) Java HotSpot(TM) 64-Bit Server VM Oracle GraalVM 21.0.3+7.1 (build 21.0.3+7-LTS-jvmci-23.1-b37, mixed mode, sharing)

Mandrel or GraalVM version (if different from Java)

No response

Quarkus version or git rev

3.10.0

Build tool (ie. output of mvnw --version or gradlew --version)

Apache Maven 3.9.6 (bc0240f3c744dd6b6ec2920b3cd08dcc295161ae)

Additional information

No response

Copy link

quarkus-bot bot commented May 11, 2024

/cc @Karm (mandrel), @andrejpetras (liquibase), @galderz (mandrel), @geoand (liquibase), @gsmet (liquibase), @radcortez (config), @zakkak (mandrel,native-image)

@geoand
Copy link
Contributor

geoand commented May 13, 2024

cc @famod you looked into this last

@gsmet gsmet closed this as completed in 509ec82 May 20, 2024
gsmet added a commit that referenced this issue May 20, 2024
Fix issue with Liquibase and H2 database
gsmet pushed a commit to gsmet/quarkus that referenced this issue May 21, 2024
gsmet pushed a commit to gsmet/quarkus that referenced this issue May 21, 2024
@HerrDerb
Copy link
Contributor

Does this fix only the h2 issue? We too experience this with postgres

@geoand
Copy link
Contributor

geoand commented May 22, 2024

Right, this was closed by mistake.

@geoand geoand reopened this May 22, 2024
@geoand
Copy link
Contributor

geoand commented May 22, 2024

How does one reproduce this for postgres?

@HerrDerb
Copy link
Contributor

HerrDerb commented May 22, 2024

I'll try to provide a reproducer, my first guess is the same just with a postgres driver

@gcw-it
Copy link
Contributor Author

gcw-it commented May 22, 2024

You can use the steps outlined in issue 40574 under How to Reproduce? to replicate the error for postgres.

@HerrDerb
Copy link
Contributor

HerrDerb commented May 22, 2024

You can use the steps outlined in issue 40574 under How to Reproduce? to replicate the error for postgres.

Brilliant, thank you.
I can approve that we also use quarkus.liquibase.migrate-at-start=true
We seem NOT to set quarkus.liquibase.clean-at-start=true

@geoand
Copy link
Contributor

geoand commented May 22, 2024

I can confirm that I get:

liquibase.exception.DatabaseException: Error executing SQL UPDATE public.databasechangeloglock SET LOCKED = FALSE, LOCKEDBY = NULL, LOCKGRANTED = NULL WHERE ID = 1: ERROR: relation "public.databasechangeloglock" does not exist

when using Postgres, but I have no idea what that means.

@geoand
Copy link
Contributor

geoand commented May 22, 2024

Nevermind the comment above - I see why that happens in native tests.
So the real questions becomes why does

Cannot load service: java.util.ServiceConfigurationError: liquibase.command.CommandStep: Provider liquibase.command.core.StartH2CommandStep not found

show up in the logs

@HerrDerb
Copy link
Contributor

Yes, especially when you don't have an h2 dependency.

@geoand
Copy link
Contributor

geoand commented May 22, 2024

My best guess is that we should always do () -> true from

private static Predicate<String> commandStepPredicate(Capabilities capabilities) {
.

Do you want to try that out in your applications?

@gcw-it
Copy link
Contributor Author

gcw-it commented May 22, 2024

Brilliant, thank you. I can approve that we also use quarkus.liquibase.migrate-at-start=true We seem NOT to set quarkus.liquibase.clean-at-start=true

You're right. This setting is only required to reproduce the issue addressed in the linked topic.
In this context the setting is unnecessary.

gsmet pushed a commit to gsmet/quarkus that referenced this issue May 22, 2024
gsmet pushed a commit to gsmet/quarkus that referenced this issue May 22, 2024
gsmet pushed a commit to gsmet/quarkus that referenced this issue May 23, 2024
gsmet pushed a commit to gsmet/quarkus that referenced this issue May 23, 2024
gsmet pushed a commit to gsmet/quarkus that referenced this issue Jun 4, 2024
gsmet pushed a commit to gsmet/quarkus that referenced this issue Jun 4, 2024
@HerrDerb
Copy link
Contributor

My best guess is that we should always do () -> true from

private static Predicate<String> commandStepPredicate(Capabilities capabilities) {

.
Do you want to try that out in your applications?

Without having it tried yet, as far as I understand, I agree that this probably should not be filtered out as the class will be loaded by the service loader of liquibase: https://github.com/liquibase/liquibase/blob/master/liquibase-standard/src/main/resources/META-INF/services/liquibase.command.CommandStep#L31

@porschesstein
Copy link

I'm still experiencing this issue in Quarkus 3.11.2. I see that the fix mentioned above was applied to 3.11 branch:

https://github.com/quarkusio/quarkus/blob/3.11/extensions/liquibase/deployment/src/main/java/io/quarkus/liquibase/deployment/LiquibaseProcessor.java#L256

So I guess it is still not fixed. I'm using liquibase in combination with MongoDB dependencies and Kotlin:

implementation(enforcedPlatform("io.quarkus.platform:quarkus-bom:3.11.2"))
implementation("io.quarkus:quarkus-kotlin")
implementation("org.jetbrains.kotlin:kotlin-stdlib")
implementation("io.quarkus:quarkus-mongodb-panache")
implementation("io.quarkus:quarkus-liquibase-mongodb")

Here the stacktrace I get:

2024-06-19 11:33:08,911 INFO [liq.servicelocator] (main) Cannot load service: java.util.ServiceConfigurationError: liquibase.command.CommandStep: Provider liquibase.command.core.StartH2CommandStep not found
at [email protected]/java.util.ServiceLoader.fail(ServiceLoader.java:593)
at [email protected]/java.util.ServiceLoader$LazyClassPathLookupIterator.nextProviderClass(ServiceLoader.java:1219)
at [email protected]/java.util.ServiceLoader$LazyClassPathLookupIterator.hasNextService(ServiceLoader.java:1228)
at [email protected]/java.util.ServiceLoader$LazyClassPathLookupIterator.hasNext(ServiceLoader.java:1273)
at [email protected]/java.util.ServiceLoader$2.hasNext(ServiceLoader.java:1309)
at [email protected]/java.util.ServiceLoader$3.hasNext(ServiceLoader.java:1393)
at liquibase.servicelocator.StandardServiceLocator.findInstances(StandardServiceLocator.java:22)
at liquibase.command.CommandFactory.findAllInstances(CommandFactory.java:244)
at liquibase.command.CommandFactory.computePipelineForCommandDefinition(CommandFactory.java:71)
at liquibase.command.CommandFactory.getCommandDefinition(CommandFactory.java:50)
at liquibase.command.CommandScope.(CommandScope.java:64)
at liquibase.Liquibase.lambda$validate$25(Liquibase.java:1365)
at liquibase.Scope.lambda$child$0(Scope.java:190)
at liquibase.Scope.child(Scope.java:199)
at liquibase.Scope.child(Scope.java:189)
at liquibase.Scope.child(Scope.java:168)
at liquibase.Liquibase.runInScope(Liquibase.java:1436)
at liquibase.Liquibase.validate(Liquibase.java:1364)
at io.quarkus.liquibase.mongodb.runtime.LiquibaseMongodbRecorder.doStartActions(LiquibaseMongodbRecorder.java:63)
at io.quarkus.deployment.steps.LiquibaseMongodbProcessor$startLiquibase1767457900.deploy_0(Unknown Source)
at io.quarkus.deployment.steps.LiquibaseMongodbProcessor$startLiquibase1767457900.deploy(Unknown Source)
at io.quarkus.runner.ApplicationImpl.doStart(Unknown Source)
at io.quarkus.runtime.Application.start(Application.java:101)
at io.quarkus.runtime.ApplicationLifecycleManager.run(ApplicationLifecycleManager.java:111)
at io.quarkus.runtime.Quarkus.run(Quarkus.java:71)
at io.quarkus.runtime.Quarkus.run(Quarkus.java:44)
at io.quarkus.runtime.Quarkus.run(Quarkus.java:124)
at io.quarkus.runner.GeneratedMain.main(Unknown Source)

It seems to only log this error, but app itself works fine and liquibase migration is also applied correctly.

@khanh-tranvan
Copy link

khanh-tranvan commented Jun 22, 2024

Hello team, I am still facing this issue when running native image, it is still not fixed, could you guy update the current status for this issue and when the fix could be released? Many thanks

2024-06-22 10:12:39,768 INFO [liq.database] (main) Set default schema name to public
2024-06-22 10:12:39,786 INFO [liq.lockservice] (main) Successfully acquired change log lock
2024-06-22 10:12:39,788 INFO [liq.servicelocator] (main) Cannot load service: java.util.ServiceConfigurationError: liquibase.command.CommandStep: Provider liquibase.command.core.StartH2CommandStep not found
at [email protected]/java.util.ServiceLoader.fail(ServiceLoader.java:593)
at [email protected]/java.util.ServiceLoader$LazyClassPathLookupIterator.nextProviderClass(ServiceLoader.java:1219)
at [email protected]/java.util.ServiceLoader$LazyClassPathLookupIterator.hasNextService(ServiceLoader.java:1228)
at [email protected]/java.util.ServiceLoader$LazyClassPathLookupIterator.hasNext(ServiceLoader.java:1273)
at [email protected]/java.util.ServiceLoader$2.hasNext(ServiceLoader.java:1309)
at [email protected]/java.util.ServiceLoader$3.hasNext(ServiceLoader.java:1393)
at liquibase.servicelocator.StandardServiceLocator.findInstances(StandardServiceLocator.java:22)
at liquibase.command.CommandFactory.findAllInstances(CommandFactory.java:244)
at liquibase.command.CommandFactory.computePipelineForCommandDefinition(CommandFactory.java:71)
at liquibase.command.CommandFactory.getCommandDefinition(CommandFactory.java:50)
at liquibase.command.CommandScope.(CommandScope.java:64)
at liquibase.Liquibase.lambda$validate$25(Liquibase.java:1365)
at liquibase.Scope.lambda$child$0(Scope.java:190)
at liquibase.Scope.child(Scope.java:199)
at liquibase.Scope.child(Scope.java:189)
at liquibase.Scope.child(Scope.java:168)
at liquibase.Liquibase.runInScope(Liquibase.java:1436)
at liquibase.Liquibase.validate(Liquibase.java:1364)
at io.quarkus.liquibase.runtime.LiquibaseRecorder.doStartActions(LiquibaseRecorder.java:82)
at io.quarkus.deployment.steps.LiquibaseProcessor$startLiquibase1744275855.deploy_0(Unknown Source)
at io.quarkus.deployment.steps.LiquibaseProcessor$startLiquibase1744275855.deploy(Unknown Source)
at io.quarkus.runner.ApplicationImpl.doStart(Unknown Source)
at io.quarkus.runtime.Application.start(Application.java:101)
at io.quarkus.runtime.ApplicationLifecycleManager.run(ApplicationLifecycleManager.java:111)
at io.quarkus.runtime.Quarkus.run(Quarkus.java:71)
at io.quarkus.runtime.Quarkus.run(Quarkus.java:44)
at io.quarkus.runtime.Quarkus.run(Quarkus.java:124)
at io.quarkus.runner.GeneratedMain.main(Unknown Source)

2024-06-22 10:12:39,793 INFO [liq.command] (main) Logging exception.
ERROR: Exception Details
ERROR: Exception Primary Class: XSDLookUpException
ERROR: Exception Primary Reason: Unable to resolve xml entity http://www.liquibase.org/xml/ns/dbchangelog/dbchangelog-3.8.xsd. liquibase.secureParsing is set to 'true' which does not allow remote lookups. Check for spelling or capitalization errors and missing extensions such as liquibase-commercial in your XSD definition. Or, set it to 'false' to allow remote lookups of xsd files.

geoand added a commit to geoand/quarkus that referenced this issue Jun 25, 2024
@geoand
Copy link
Contributor

geoand commented Jun 25, 2024

Can someone try #41414 and see if it fixes their problem?

@quarkus-bot quarkus-bot bot added this to the 3.14 - main milestone Jul 25, 2024
holly-cummins pushed a commit to holly-cummins/quarkus that referenced this issue Jul 31, 2024
@gsmet gsmet modified the milestones: 3.14 - main, 3.13.1 Aug 1, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
7 participants