Hello!
I am encountering a really bizzare issue. I have my project set to use a Postgres database running in a local container. When I launch it on an empty database, as usual Studio suggests updating and running Liuquibase migrations. If I DENY - it works fine for the first time - the app launches, the tables are created and it is all functional.
However, if I accept the migrations, or if I launch the app with the database already set up - the problems begin. On launch, liquibase for some reason thinks it needs to create the changelogs table in the database, sees that it already exists (either created by studio migrations or by a previous app run on an empty base where this step successfully resolved) - and throws a fatal error.
This behaviour started randomly at some point and I can’t pinpoint what changes caused it.
Here are the error logs:
2025-07-04T13:16:44.486+03:00 INFO 10024 --- [ main] c.c.b.BotManagmentSystemApplication : No active profile set, falling back to 1 default profile: "default"
2025-07-04T13:16:46.084+03:00 INFO 10024 --- [ main] io.jmix.core.JmixModulesProcessor : Using Jmix modules: [io.jmix.core, io.jmix.security, io.jmix.flowui, io.jmix.securityflowui, io.jmix.data, io.jmix.datatools, io.jmix.datatoolsflowui, io.jmix.eclipselink, io.jmix.flowuidata, io.jmix.localfs, io.jmix.securitydata, com.company.botmanagmentsystem]
2025-07-04T13:16:47.036+03:00 INFO 10024 --- [ main] o.s.b.w.embedded.tomcat.TomcatWebServer : Tomcat initialized with port 8080 (http)
2025-07-04T13:16:47.053+03:00 INFO 10024 --- [ main] o.apache.catalina.core.StandardService : Starting service [Tomcat]
2025-07-04T13:16:47.053+03:00 INFO 10024 --- [ main] o.apache.catalina.core.StandardEngine : Starting Servlet engine: [Apache Tomcat/10.1.41]
2025-07-04T13:16:47.131+03:00 INFO 10024 --- [ main] o.a.c.c.C.[Tomcat].[localhost].[/] : Initializing Spring embedded WebApplicationContext
2025-07-04T13:16:47.132+03:00 INFO 10024 --- [ main] w.s.c.ServletWebServerApplicationContext : Root WebApplicationContext: initialization completed in 2469 ms
2025-07-04T13:16:47.407+03:00 INFO 10024 --- [ main] i.j.c.i.s.JmixModulesClasspathScanner : Classpath scan completed in 76 ms
2025-07-04T13:16:47.659+03:00 INFO 10024 --- [ main] io.jmix.core.impl.MetadataLoader : Metadata initialized in 104 ms
2025-07-04T13:16:51.694+03:00 INFO 10024 --- [ main] c.v.f.s.VaadinServletContextInitializer : Search for subclasses and classes with annotations took 3426 ms
2025-07-04T13:16:52.068+03:00 INFO 10024 --- [ main] c.v.b.d.startup.DevModeStartupListener : Starting dev-mode updaters in C:\Users\Sergei\IdeaProjects\BotManagmentSystem folder.
2025-07-04T13:16:52.107+03:00 INFO 10024 --- [ main] c.v.f.s.f.s.FullDependenciesScanner : Visited 173 classes. Took 26 ms.
2025-07-04T13:16:52.108+03:00 INFO 10024 --- [ main] c.v.f.s.frontend.BundleValidationUtil : Checking if a development mode bundle build is needed
2025-07-04T13:16:52.132+03:00 INFO 10024 --- [ main] c.v.f.s.frontend.BundleValidationUtil : Dependency react-router is missing from the bundle
2025-07-04T13:16:52.133+03:00 INFO 10024 --- [ main] c.v.f.s.frontend.BundleValidationUtil : A development mode bundle build is needed
2025-07-04T13:16:52.288+03:00 INFO 10024 --- [ main] com.zaxxer.hikari.HikariDataSource : HikariPool-1 - Starting...
2025-07-04T13:16:52.453+03:00 INFO 10024 --- [ main] com.zaxxer.hikari.pool.HikariPool : HikariPool-1 - Added connection org.postgresql.jdbc.PgConnection@a1cfd17
2025-07-04T13:16:52.455+03:00 INFO 10024 --- [ main] com.zaxxer.hikari.HikariDataSource : HikariPool-1 - Start completed.
2025-07-04T13:16:52.579+03:00 INFO 10024 --- [ main] liquibase.database : Set default schema name to public
2025-07-04T13:16:52.961+03:00 INFO 10024 --- [ main] liquibase.changelog : Creating database history table with name: public.databasechangelog
2025-07-04T13:16:52.986+03:00 INFO 10024 --- [ main] liquibase.command : Logging exception.
2025-07-04T13:16:52.986+03:00 INFO 10024 --- [ main] liquibase.ui : ERROR: Exception Details
2025-07-04T13:16:52.986+03:00 INFO 10024 --- [ main] liquibase.ui : ERROR: Exception Primary Class: PSQLException
2025-07-04T13:16:52.986+03:00 INFO 10024 --- [ main] liquibase.ui : ERROR: Exception Primary Reason: ERROR: relation "databasechangelog" already exists
2025-07-04T13:16:52.986+03:00 INFO 10024 --- [ main] liquibase.ui : ERROR: Exception Primary Source: PostgreSQL 17.4 (Debian 17.4-1.pgdg120+2)
2025-07-04T13:16:52.986+03:00 INFO 10024 --- [ main] liquibase.command : Command execution complete
2025-07-04T13:16:54.090+03:00 WARN 10024 --- [ main] ConfigServletWebServerApplicationContext : Exception encountered during context initialization - cancelling refresh attempt: org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'entityManagerFactory' defined in class path resource [io/jmix/autoconfigure/eclipselink/EclipselinkAutoConfiguration.class]: Failed to initialize dependency 'jmix_Liquibase' of LoadTimeWeaverAware bean 'entityManagerFactory': Error creating bean with name 'jmix_Liquibase' defined in class path resource [io/jmix/autoconfigure/data/JmixLiquibaseAutoConfiguration.class]: liquibase.exception.CommandExecutionException: liquibase.exception.ChangeLogParseException: liquibase.exception.SetupException: liquibase.exception.SetupException: liquibase.exception.DatabaseException: ERROR: relation "databasechangelog" already exists [Failed SQL: (0) CREATE TABLE public.databasechangelog (ID VARCHAR(255) NOT NULL, AUTHOR VARCHAR(255) NOT NULL, FILENAME VARCHAR(255) NOT NULL, DATEEXECUTED TIMESTAMP WITHOUT TIME ZONE NOT NULL, ORDEREXECUTED INTEGER NOT NULL, EXECTYPE VARCHAR(10) NOT NULL, MD5SUM VARCHAR(35), DESCRIPTION VARCHAR(255), COMMENTS VARCHAR(255), TAG VARCHAR(255), LIQUIBASE VARCHAR(20), CONTEXTS VARCHAR(255), LABELS VARCHAR(255), DEPLOYMENT_ID VARCHAR(10))]
2025-07-04T13:16:54.091+03:00 INFO 10024 --- [ main] com.zaxxer.hikari.HikariDataSource : HikariPool-1 - Shutdown initiated...
2025-07-04T13:16:54.093+03:00 INFO 10024 --- [ main] com.zaxxer.hikari.HikariDataSource : HikariPool-1 - Shutdown completed.
2025-07-04T13:16:54.096+03:00 INFO 10024 --- [ main] o.apache.catalina.core.StandardService : Stopping service [Tomcat]
2025-07-04T13:16:54.098+03:00 WARN 10024 --- [ main] o.a.c.loader.WebappClassLoaderBase : The web application [ROOT] appears to have started a thread named [JNA Cleaner] but has failed to stop it. This is very likely to create a memory leak. Stack trace of thread:
java.base/jdk.internal.misc.Unsafe.park(Native Method)
java.base/java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:269)
java.base/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:1852)
java.base/java.lang.ref.ReferenceQueue.await(ReferenceQueue.java:71)
java.base/java.lang.ref.ReferenceQueue.remove0(ReferenceQueue.java:143)
java.base/java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:218)
com.sun.jna.internal.Cleaner$CleanerThread.run(Cleaner.java:154)
I can’t share the entire app since it’s confidential. I would be happy to include any files of interest - but I don’t know where to start - I have tried some config options, but none worked, and now I am at a dead end, so I will be very grateful for any advice.
I have updated to Jmix 2.6.0 after the problems began, just to list it here, but I am pretty sure something in my code is causing the issue.