When Using Liquibase with "quarkus.liquibase.clean-at-start=true" a RuntimeException Is Thrown in Quarkus 3.10.0

[gcw-it]

Describe the bug

At App startup an exception is thrown and the program exits, when using Liquibase with quarkus.liquibase.clean-at-start=true set.
This happens at least with Postgresql and H2.
The issue didn't occur before Quarkus 3.10.0
The problem happens for a local as well as an in-container build.

For Postgres, the following error is logged:

INFO  [liq.command] (main) Logging exception.
ERROR: Exception Details
ERROR: Exception Primary Class:  PSQLException
ERROR: Exception Primary Reason:  ERROR: relation "public.databasechangeloglock" does not exist
  Position: 8
ERROR: Exception Primary Source:  PostgreSQL 16.2 (Debian 16.2-1.pgdg120+2)
INFO  [liq.command] (main) Command execution complete
2024-05-11 18:11:33,653 ERROR [io.qua.run.Application] (main) Failed to start application (with profile [prod]):

and the following exception is thrown:

java.lang.RuntimeException: Failed to start quarkus
	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)
Caused by: java.lang.IllegalStateException: Error starting Liquibase
	at io.quarkus.liquibase.runtime.LiquibaseRecorder.doStartActions(LiquibaseRecorder.java:90)
	at io.quarkus.deployment.steps.LiquibaseProcessor$startLiquibase1744275855.deploy_0(Unknown Source)
	at io.quarkus.deployment.steps.LiquibaseProcessor$startLiquibase1744275855.deploy(Unknown Source)
	... 7 more
Caused by: liquibase.exception.DatabaseException: liquibase.exception.CommandExecutionException: liquibase.exception.LockException: liquibase.exception.DatabaseException: 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
  Position: 8
	at liquibase.Liquibase.dropAll(Liquibase.java:1028)
	at liquibase.Liquibase.dropAll(Liquibase.java:1009)
	at liquibase.Liquibase.dropAll(Liquibase.java:994)
	at io.quarkus.liquibase.runtime.LiquibaseRecorder.doStartActions(LiquibaseRecorder.java:71)
	... 9 more
Caused by: liquibase.exception.CommandExecutionException: liquibase.exception.LockException: liquibase.exception.DatabaseException: 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
  Position: 8
	at liquibase.command.CommandScope.execute(CommandScope.java:257)
	at liquibase.Liquibase.dropAll(Liquibase.java:1026)
	... 12 more
Caused by: liquibase.exception.LockException: liquibase.exception.DatabaseException: 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
  Position: 8
	at liquibase.lockservice.StandardLockService.releaseLock(StandardLockService.java:407)
	at liquibase.command.core.DropAllCommandStep.run(DropAllCommandStep.java:120)
	at liquibase.command.CommandScope.execute(CommandScope.java:219)
	... 13 more
Caused by: liquibase.exception.DatabaseException: 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
  Position: 8
	at liquibase.executor.jvm.ChangelogJdbcMdcListener.query(ChangelogJdbcMdcListener.java:62)
	at liquibase.lockservice.StandardLockService.releaseLock(StandardLockService.java:372)
	... 15 more
Caused by: 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
  Position: 8
	at liquibase.executor.jvm.JdbcExecutor.execute(JdbcExecutor.java:101)
	at liquibase.executor.jvm.JdbcExecutor.update(JdbcExecutor.java:337)
	at liquibase.executor.jvm.JdbcExecutor.update(JdbcExecutor.java:305)
	at liquibase.lockservice.StandardLockService.lambda$releaseLock$6(StandardLockService.java:372)
	at liquibase.executor.jvm.ChangelogJdbcMdcListener.lambda$query$1(ChangelogJdbcMdcListener.java:55)
	at liquibase.Scope.child(Scope.java:199)
	at liquibase.Scope.child(Scope.java:175)
	at liquibase.executor.jvm.ChangelogJdbcMdcListener.query(ChangelogJdbcMdcListener.java:55)
	... 16 more
Caused by: org.postgresql.util.PSQLException: ERROR: relation "public.databasechangeloglock" does not exist
  Position: 8
	at org.postgresql.core.v3.QueryExecutorImpl.receiveErrorResponse(QueryExecutorImpl.java:2725)
	at org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:2412)
	at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:371)
	at org.postgresql.jdbc.PgStatement.executeInternal(PgStatement.java:502)
	at org.postgresql.jdbc.PgStatement.execute(PgStatement.java:419)
	at org.postgresql.jdbc.PgStatement.executeWithFlags(PgStatement.java:341)
	at org.postgresql.jdbc.PgStatement.executeCachedSql(PgStatement.java:326)
	at org.postgresql.jdbc.PgStatement.executeWithFlags(PgStatement.java:302)
	at org.postgresql.jdbc.PgStatement.executeUpdate(PgStatement.java:275)
	at io.agroal.pool.wrapper.StatementWrapper.executeUpdate(StatementWrapper.java:120)
	at liquibase.executor.jvm.JdbcExecutor$1UpdateStatementCallback.doInStatement(JdbcExecutor.java:328)
	at liquibase.executor.jvm.JdbcExecutor.execute(JdbcExecutor.java:80)
	... 23 more

For H2 the log contains:

INFO  [liq.command] (main) Logging exception.
ERROR: Exception Details
ERROR: Exception Primary Class:  JdbcSQLSyntaxErrorException
ERROR: Exception Primary Reason:  Tabelle "DATABASECHANGELOGLOCK" nicht gefunden (diese Datenbank ist leer)
Table "DATABASECHANGELOGLOCK" not found (this database is empty); SQL statement:
UPDATE PUBLIC.DATABASECHANGELOGLOCK SET LOCKED = FALSE, LOCKEDBY = NULL, LOCKGRANTED = NULL WHERE ID = 1 [42104-224]
ERROR: Exception Primary Source:  H2 2.2.224 (2023-09-17)
2024-05-11 17:43:26,697 INFO  [liq.command] (main) Command execution complete
2024-05-11 17:43:26,727 ERROR [io.qua.run.Application] (main) Failed to start application (with profile [prod]):

and the exception is:

java.lang.RuntimeException: Failed to start quarkus
	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)
Caused by: java.lang.IllegalStateException: Error starting Liquibase
	at io.quarkus.liquibase.runtime.LiquibaseRecorder.doStartActions(LiquibaseRecorder.java:90)
	at io.quarkus.deployment.steps.LiquibaseProcessor$startLiquibase1744275855.deploy_0(Unknown Source)
	at io.quarkus.deployment.steps.LiquibaseProcessor$startLiquibase1744275855.deploy(Unknown Source)
	... 7 more
Caused by: liquibase.exception.DatabaseException: liquibase.exception.CommandExecutionException: liquibase.exception.LockException: liquibase.exception.DatabaseException: liquibase.exception.DatabaseException: Error executing SQL UPDATE PUBLIC.DATABASECHANGELOGLOCK SET LOCKED = FALSE, LOCKEDBY = NULL, LOCKGRANTED = NULL WHERE ID = 1: Tabelle "DATABASECHANGELOGLOCK" nicht gefunden (diese Datenbank ist leer)
Table "DATABASECHANGELOGLOCK" not found (this database is empty); SQL statement:
UPDATE PUBLIC.DATABASECHANGELOGLOCK SET LOCKED = FALSE, LOCKEDBY = NULL, LOCKGRANTED = NULL WHERE ID = 1 [42104-224]
	at liquibase.Liquibase.dropAll(Liquibase.java:1028)
	at liquibase.Liquibase.dropAll(Liquibase.java:1009)
	at liquibase.Liquibase.dropAll(Liquibase.java:994)
	at io.quarkus.liquibase.runtime.LiquibaseRecorder.doStartActions(LiquibaseRecorder.java:71)
	... 9 more
Caused by: liquibase.exception.CommandExecutionException: liquibase.exception.LockException: liquibase.exception.DatabaseException: liquibase.exception.DatabaseException: Error executing SQL UPDATE PUBLIC.DATABASECHANGELOGLOCK SET LOCKED = FALSE, LOCKEDBY = NULL, LOCKGRANTED = NULL WHERE ID = 1: Tabelle "DATABASECHANGELOGLOCK" nicht gefunden (diese Datenbank ist leer)
Table "DATABASECHANGELOGLOCK" not found (this database is empty); SQL statement:
UPDATE PUBLIC.DATABASECHANGELOGLOCK SET LOCKED = FALSE, LOCKEDBY = NULL, LOCKGRANTED = NULL WHERE ID = 1 [42104-224]
	at liquibase.command.CommandScope.execute(CommandScope.java:257)
	at liquibase.Liquibase.dropAll(Liquibase.java:1026)
	... 12 more
Caused by: liquibase.exception.LockException: liquibase.exception.DatabaseException: liquibase.exception.DatabaseException: Error executing SQL UPDATE PUBLIC.DATABASECHANGELOGLOCK SET LOCKED = FALSE, LOCKEDBY = NULL, LOCKGRANTED = NULL WHERE ID = 1: Tabelle "DATABASECHANGELOGLOCK" nicht gefunden (diese Datenbank ist leer)
Table "DATABASECHANGELOGLOCK" not found (this database is empty); SQL statement:
UPDATE PUBLIC.DATABASECHANGELOGLOCK SET LOCKED = FALSE, LOCKEDBY = NULL, LOCKGRANTED = NULL WHERE ID = 1 [42104-224]
	at liquibase.lockservice.StandardLockService.releaseLock(StandardLockService.java:407)
	at liquibase.command.core.DropAllCommandStep.run(DropAllCommandStep.java:120)
	at liquibase.command.CommandScope.execute(CommandScope.java:219)
	... 13 more
Caused by: liquibase.exception.DatabaseException: liquibase.exception.DatabaseException: Error executing SQL UPDATE PUBLIC.DATABASECHANGELOGLOCK SET LOCKED = FALSE, LOCKEDBY = NULL, LOCKGRANTED = NULL WHERE ID = 1: Tabelle "DATABASECHANGELOGLOCK" nicht gefunden (diese Datenbank ist leer)
Table "DATABASECHANGELOGLOCK" not found (this database is empty); SQL statement:
UPDATE PUBLIC.DATABASECHANGELOGLOCK SET LOCKED = FALSE, LOCKEDBY = NULL, LOCKGRANTED = NULL WHERE ID = 1 [42104-224]
	at liquibase.executor.jvm.ChangelogJdbcMdcListener.query(ChangelogJdbcMdcListener.java:62)
	at liquibase.lockservice.StandardLockService.releaseLock(StandardLockService.java:372)
	... 15 more
Caused by: liquibase.exception.DatabaseException: Error executing SQL UPDATE PUBLIC.DATABASECHANGELOGLOCK SET LOCKED = FALSE, LOCKEDBY = NULL, LOCKGRANTED = NULL WHERE ID = 1: Tabelle "DATABASECHANGELOGLOCK" nicht gefunden (diese Datenbank ist leer)
Table "DATABASECHANGELOGLOCK" not found (this database is empty); SQL statement:
UPDATE PUBLIC.DATABASECHANGELOGLOCK SET LOCKED = FALSE, LOCKEDBY = NULL, LOCKGRANTED = NULL WHERE ID = 1 [42104-224]
	at liquibase.executor.jvm.JdbcExecutor.execute(JdbcExecutor.java:101)
	at liquibase.executor.jvm.JdbcExecutor.update(JdbcExecutor.java:337)
	at liquibase.executor.jvm.JdbcExecutor.update(JdbcExecutor.java:305)
	at liquibase.lockservice.StandardLockService.lambda$releaseLock$6(StandardLockService.java:372)
	at liquibase.executor.jvm.ChangelogJdbcMdcListener.lambda$query$1(ChangelogJdbcMdcListener.java:55)
	at liquibase.Scope.child(Scope.java:199)
	at liquibase.Scope.child(Scope.java:175)
	at liquibase.executor.jvm.ChangelogJdbcMdcListener.query(ChangelogJdbcMdcListener.java:55)
	... 16 more
Caused by: org.h2.jdbc.JdbcSQLSyntaxErrorException: Tabelle "DATABASECHANGELOGLOCK" nicht gefunden (diese Datenbank ist leer)
Table "DATABASECHANGELOGLOCK" not found (this database is empty); SQL statement:
UPDATE PUBLIC.DATABASECHANGELOGLOCK SET LOCKED = FALSE, LOCKEDBY = NULL, LOCKGRANTED = NULL WHERE ID = 1 [42104-224]
	at org.h2.message.DbException.getJdbcSQLException(DbException.java:514)
	at org.h2.message.DbException.getJdbcSQLException(DbException.java:489)
	at org.h2.message.DbException.get(DbException.java:223)
	at org.h2.message.DbException.get(DbException.java:199)
	at org.h2.command.Parser.getTableOrViewNotFoundDbException(Parser.java:8051)
	at org.h2.command.Parser.getTableOrViewNotFoundDbException(Parser.java:8045)
	at org.h2.command.Parser.getTableOrViewNotFoundDbException(Parser.java:8029)
	at org.h2.command.Parser.readTableOrView(Parser.java:8024)
	at org.h2.command.Parser.readTableOrView(Parser.java:7990)
	at org.h2.command.Parser.readSimpleTableFilter(Parser.java:1094)
	at org.h2.command.Parser.parseUpdate(Parser.java:1018)
	at org.h2.command.Parser.parsePrepared(Parser.java:765)
	at org.h2.command.Parser.parse(Parser.java:592)
	at org.h2.command.Parser.parse(Parser.java:564)
	at org.h2.command.Parser.prepareCommand(Parser.java:483)
	at org.h2.engine.SessionLocal.prepareLocal(SessionLocal.java:639)
	at org.h2.server.TcpServerThread.process(TcpServerThread.java:289)
	at org.h2.server.TcpServerThread.run(TcpServerThread.java:191)
	at java.base/java.lang.Thread.run(Thread.java:1570)

	at org.h2.engine.SessionRemote.readException(SessionRemote.java:650)
	at org.h2.engine.SessionRemote.done(SessionRemote.java:619)
	at org.h2.command.CommandRemote.prepare(CommandRemote.java:78)
	at org.h2.command.CommandRemote.<init>(CommandRemote.java:50)
	at org.h2.engine.SessionRemote.prepareCommand(SessionRemote.java:487)
	at org.h2.jdbc.JdbcConnection.prepareCommand(JdbcConnection.java:1166)
	at org.h2.jdbc.JdbcStatement.executeUpdateInternal(JdbcStatement.java:190)
	at org.h2.jdbc.JdbcStatement.executeUpdate(JdbcStatement.java:147)
	at io.agroal.pool.wrapper.StatementWrapper.executeUpdate(StatementWrapper.java:120)
	at liquibase.executor.jvm.JdbcExecutor$1UpdateStatementCallback.doInStatement(JdbcExecutor.java:328)
	at liquibase.executor.jvm.JdbcExecutor.execute(JdbcExecutor.java:80)
	... 23 more

Expected behavior

The DB is migrated and the app successfully started.

Actual behavior

An Exception is thrown, the DB isn't migrated and the application exits.

How to Reproduce?

To reproduce the error with Postgresql:

1. Use the liquibase-quickstart from the quarkus-quickstarts repo.
2. Change <artifactId>quarkus-jdbc-h2</artifactId> to <artifactId>quarkus-jdbc-postgresql</artifactId> in pom.xml.
3. Change the data source to %prod.quarkus.datasource.db-kind=postgresql and the url to %prod.quarkus.datasource.jdbc.url=jdbc:postgresql://localhost:5432/test in application.properties.
4. Run a DB-instance e.g.: docker run -d --rm --name=test-db -p 0.0.0.0:5432:5432 -e POSTGRES_USER=sa -e POSTGRES_PASSWORD=sa -e POSTGRES_DB=test postgres:16.2
5. Compile the app: mvn clean package -Dnative -DskipTests.
6. Run: ./target/liquibase-quickstart-1.0.0-SNAPSHOT-runner.

You can use similar steps to reproduce the error with H2.

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

[quarkus-bot]

/cc @Karm (mandrel), @andrejpetras (liquibase), @galderz (mandrel), @geoand (liquibase), @gsmet (liquibase), @zakkak (mandrel)

[galderz]

I've replicated the error locally. It fails with 3.10.0 but works fine with 3.9.5.

[galderz]

3.9.5:

2024-05-15 07:01:56,349 INFO  [liq.database] (main) Successfully deleted all supported object types in schema test.public.
2024-05-15 07:01:56,351 FINE  [liq.configuration] (main) No configuration value for liquibase.sql.showSqlWarnings found
2024-05-15 07:01:56,351 FINE  [liq.configuration] (main) Configuration liquibase.sql.showSqlWarnings is using the default value of true
2024-05-15 07:01:56,352 WARNING [liq.lockservice] (main) Failed to release change log lock
All objects dropped from sa@jdbc:postgresql://localhost:5432/test
2024-05-15 07:01:56,353 INFO  [liq.command] (main) Command execution complete
2024-05-15 07:01:56,353 FINE  [liq.servicelocator] (main) Loaded liquibase.lockservice.LockService instance liquibase.lockservice.LockServiceImpl
2024-05-15 07:01:56,353 FINE  [liq.servicelocator] (main) Loaded liquibase.lockservice.LockService instance liquibase.lockservice.MockLockService
2024-05-15 07:01:56,353 FINE  [liq.servicelocator] (main) Loaded liquibase.lockservice.LockService instance liquibase.lockservice.OfflineLockService
2024-05-15 07:01:56,353 FINE  [liq.servicelocator] (main) Loaded liquibase.lockservice.LockService instance liquibase.lockservice.StandardLockService
2024-05-15 07:01:56,354 FINE  [liq.executor] (main) Create Database Lock Table
2024-05-15 07:01:56,355 FINE  [liq.configuration] (main) No configuration value for liquibase.liquibaseTablespaceName aka liquibase.databaseChangeLogTablespaceName aka liquibase.liquibaseTableSpaceName found
2024-05-15 07:01:56,355 FINE  [liq.configuration] (main) No configuration value for liquibase.fileEncoding found
2024-05-15 07:01:56,355 FINE  [liq.configuration] (main) Configuration liquibase.fileEncoding is using the default value of UTF-8
2024-05-15 07:01:56,355 FINE  [liq.executor] (main) CREATE TABLE public.databasechangeloglock (ID INTEGER NOT NULL, LOCKED BOOLEAN NOT NULL, LOCKGRANTED TIMESTAMP WITHOUT TIME ZONE, LOCKEDBY VARCHAR(255), CONSTRAINT databasechangeloglock_pkey PRIMARY KEY (ID))

3.10.0:

2024-05-15 07:02:09,135 INFO  [liq.database] (main) Successfully deleted all supported object types in schema test.public.
2024-05-15 07:02:09,135 FINE  [liq.executor] (main) Release Database Lock
2024-05-15 07:02:09,135 FINE  [org.pos.jdb.PgConnection] (main) Rollback requested but no transaction in progress
2024-05-15 07:02:09,136 FINE  [liq.configuration] (main) No configuration value for liquibase.sql.showSqlWarnings found
2024-05-15 07:02:09,136 FINE  [liq.configuration] (main) Configuration liquibase.sql.showSqlWarnings is using the default value of true
2024-05-15 07:02:09,136 WARNING [liq.lockservice] (main) Failed to release change log lock
2024-05-15 07:02:09,137 INFO  [liq.command] (main) Logging exception.
ERROR: Exception Details
ERROR: Exception Primary Class:  PSQLException
ERROR: Exception Primary Reason:  ERROR: relation "public.databasechangeloglock" does not exist
  Position: 8
ERROR: Exception Primary Source:  PostgreSQL 16.2 (Debian 16.2-1.pgdg120+2)
2024-05-15 07:02:09,137 INFO  [liq.command] (main) Command execution complete

[galderz]

This looks like an issue related to task to create the database lock table not firing, or an ordering issue, where releasing database lock is executing before the create database lock table. Looking at what was fixed in 3.10.0 https://github.com/quarkusio/quarkus/milestone/325?closed=1, nothing stands out immediately as a culprit for this issue.