4.25 does not execute changesets

General Discussion
1

I am upgrading my java process that executes liquibase 3x to 4.25 and changed to use CommandScope.
I use my process to run software upgrades for oracle and pg. LB is a real workhorse and very reliable. We’ve been using it to process our software upgrades for many years.
I am currently running on jdk 8 and the open source liquibase.

My problem is that I cannot seem to figure out why the sql in the changesets and inserts into databasechangelog are not getting executed.
I can see from the log that the changesets are getting picked up and the resulting message in the log says they are executed correctly.
There are no errors. I am using the same driver, url, user, password and connection as before.

Here’s the relevant parts of my code in case someone can see what I am missing or have suggestions.

// changelog and logger for example
File fileChangeLog = new File(“/path/changelogs/changelog.xml”);
OutputStream lbLogger = Files.newOutputStream(Paths.get(“logs” + java.io.File.separator + “CommandScopeLogs.log”));
// set up my jdbc connection
Connection myConnection = null;
try {
myConnection = DriverManager.getConnection(
dbUrl, dbUpgradeUser,
dbUpgradePwd);
} catch (SQLException e) {
e.printStackTrace();
throw e;
}

// instantiate liquibase database
liquibase.database.Database lbDatabase = null;
try {

lbDatabase = DatabaseFactory.getInstance().findCorrectDatabaseImplementation(new JdbcConnection(myConnection));
lbDatabase.setDefaultSchemaName(defaultSchema);
lbDatabase.setLiquibaseCatalogName(liquibaseCatalogName);
lbDatabase.setLiquibaseSchemaName((String) liquibaseSchemaName);
lbDatabase.setAutoCommit(true);

} catch (DatabaseException ae) {
logger.debug(“Error in trying to create database object for changelog: " + changeLog + " message: " + ae.getMessage());
throw ae;
}
// set up resource accessor and search patch
ClassLoader classLoader = getClass().getClassLoader();
liquibase.resource.ResourceAccessor clOpener = new liquibase.resource.SearchPathResourceAccessor(
new liquibase.resource.DirectoryResourceAccessor(java.nio.file.Paths.get(”/path/changelogs"),
new liquibase.resource.ClassLoaderResourceAccessor(classLoader) );

// set up map for scope
final java.util.Map<String, Object> config = new java.util.HashMap<>();
config.put(liquibase.Scope.Attr.database.name(), dbliquibase);
config.put(liquibase.Scope.Attr.resourceAccessor.name(), clOpener);
try {
liquibase.Scope.child(config, () → {
liquibase.command.CommandScope updateCommand = new liquibase.command.CommandScope(liquibase.command.core.UpdateSqlCommandStep.COMMAND_NAME);
updateCommand.addArgumentValue(liquibase.command.core.helpers.DbUrlConnectionCommandStep.DATABASE_ARG, dbliquibase);
updateCommand.addArgumentValue(liquibase.command.core.UpdateCommandStep.CHANGELOG_FILE_ARG, fileChangeLog.getName());

    updateCommand.setOutput(lbLogger );
    liquibase.command.CommandResults result = updateCommand.execute(); 
    if (result.getResults() != null) {
        java.util.Set set2 = result.getResults().entrySet();
        java.util.Iterator i2 = set2.iterator();
        while (i2.hasNext()) {
            java.util.Map.Entry param = (java.util.Map.Entry) i2.next();
            logger.debug("Results Entry set " + param.getKey() + " value " + param.getValue());
        }
    }
    

});

} catch( liquibase.command.CommandFailedException af ){
logger.error("ERROR executing command failed execution liquibase " + af.getMessage());
logger.debug("Error executing command failed execution liquibase " + af.getStackTrace());
}
catch (liquibase.exception.CommandExecutionException ae) {
logger.error("ERROR executing command execution liquibase " + ae.getMessage());
logger.debug("Error executing command execution liquibase " + ae.getStackTrace());
} catch (Exception ee) {
logger.error("ERROR executing liquibase " + ee.getMessage());
logger.debug("Error executing liquibase " + ee.getStackTrace());
}

I saw that a new 4.25.1 was pushed so I pulled that, had to change the database command

updateCommand.addArgumentValue(liquibase.command.core.helpers.DbUrlConnectionArgumentsCommandStep.DATABASE_ARG, dbliquibase);

but I get exception : Unable to find CommandStep provider for class liquibase.command.core.helpers.DbUrlConnectionArgumentsCommandStep

My changelog changelog.xml looks like the following and I just updated the schema location to pull the latest based on another discussion.
I reverted to the previous and got the same result.

<?xml version="1.0" encoding="UTF-8" standalone="no"?> 

<include file="somescript.sql"  relativeToChangelogFile="true"/>

My sql file somescript.sql is like the following, I simplified for the example but the sql can include insert statements and any operation (create table, add index, add columns, add comments, update, create or replace views and dbprocs).

–liquibase formatted sql
–changeset myauthor:somescript.sql splitStatements:true stripComments:false logicalFilePath:sql/somescript.sql
update sometable set somecolumn = ‘XX’;

The end result in liquibase.command.CommandResults is the following:

Results Entry set defaultChangeExecListener value liquibase.changelog.visitor.DefaultChangeExecListener@12591ac8
Results Entry set statusCode value 0
Results Entry set updateReport value UpdateReportParameters(changelogArgValue=changelog.xml, jdbcUrl=jdbc:postgresql://xxx:5432/mypgdb, commandTitle=Update Sql, databaseInfo=DatabaseInfo(databaseType=PostgreSQL, version=13.13 (Ubuntu 13.13-1.pgdg20.04+1)), runtimeInfo=RuntimeInfo(systemUsername=mhockett, hostname=xxx, os=Mac OS X, interfaceType=null, startTime=null), operationInfo=OperationInfo(command=null, operationOutcome=success, operationOutcomeErrorMsg=null), customData=CustomData(customDataFile=null, fileContents=null), changesetInfo=ChangesetInfo(changesetCount=1, changesetInfoList=[IndividualChangesetInfo(index=1, changesetAuthor=myauthor, changesetId=somescript.sql , changelogFile=somescript.sql, comment=, changesetOutcome=EXECUTED, errorMsg=null, labels=, contexts=, attributes=, generatedSql=[update sometable set somecolumn = ‘XX’;]), date=Sun Dec 17 11:39:25 EST 2023)

My lbLogger shows the sql statements for all changesets, including the sql to lock and unlock databasechangelog, and to insert into databasechangelog.

I ran the debugger and the code in the AbstractJdbcDatabase
Scope.getCurrentScope().getSingleton(ExecutorService.class).getExecutor(“jdbc”, this).execute(statement, sqlVisitors);
gets reached, but does not seem to actually execute the JDBC statement. The sqlVisitors is null, is that correct? The statement shows the sql for the changeset.

Right after that code is reached there is a commit and that code is reached.

I confirmed by showing all sql statements in my database log that the statements in the changesets are never executed.

The slf4j logger shows success for each changeset

2023-12-17 11:39:28,961 INFO liquibase.changelog.ChangeSet [main] ChangeSet somescript.sql::somescript.sql::myauthor ran successfully in 16ms
2023-12-17 11:39:28,961 DEBUG liquibase.changelog.ChangeSet [main] Database after execute in ChangeSet auto commit mode= false support ddl in trans: true
2023-12-17 11:39:28,963 DEBUG liquibase.executor.jvm.ChangelogJdbcMdcListener [main] Changelog query completed.
2023-12-17 11:39:28,970 INFO liquibase.command.core.UpdateSqlCommandStep [main] Update command completed successfully.
2023-12-17 11:39:28,977 DEBUG liquibase.executor.jvm.ChangelogJdbcMdcListener [main] Changelog query completed.
2023-12-17 11:39:28,980 INFO liquibase.lockservice.StandardLockService [main] Successfully released change log lock
liquibase.command.CommandResults

Yet in the end, the entries are not in the databasechangelog table and the database changes were not done.
I even used sql_trace for my oracle and the changesets and databasechangelog insert is not reported, and for Postgres I altered the database to show all sql in the logs and the same result.

Hopefully I just missed something very obvious.
Thank you ahead for your help and hope you all have great holiday!

2

I prepared demo , simple java to execute the process using the new CommandScope and liquibase.update to show the difference.
I am not sure how to upload but it may help someone see what is happening.

3

I ran comparison between the old liquibase.update and the scopeCommand
on left is the liquibase.update and right scope command.
The scope command never calls l.e.j.JdbcExecutor$ExecuteStatementCallback that executes the staement

image
image1451×480 118 KB

4

I uploaded my demo to github

hope my example helps debug the issue or someone can spot what I need to do differently.
I could only test on Oracle and PG.

thanks

5

i got it, my lack of understanding of scope.
I created separate class with the database and resource acc objects and run update command within that

 
public class DbLiqLiquibase    {
    private liquibase.UpdateSummaryEnum showSummary;
    private liquibase.UpdateSummaryOutputEnum showSummaryOutput;
    protected liquibase.database.Database database;
    private liquibase.changelog.DatabaseChangeLog databaseChangeLog;
    private String changeLogFile;
    private final liquibase.resource.ResourceAccessor resourceAccessor;
    private static final Logger logger = (Logger) LoggerFactory.getLogger(DbLiqLiquibase.class);


    public DbLiqLiquibase(String changeLogFile, liquibase.resource.ResourceAccessor resourceAccessor,
                          liquibase.database.Database lbDatabase ) throws liquibase.exception.LiquibaseException {

        this.changeLogFile = changeLogFile ;
        this.resourceAccessor = resourceAccessor;
        this.database = lbDatabase;
    }

    private void myScope(liquibase.Scope.ScopedRunner scopedRunner) throws liquibase.exception.LiquibaseException {
        java.util.Map<String, Object> scopeObjects = new java.util.HashMap<>();
        scopeObjects.put(liquibase.Scope.Attr.database.name(), database);
        scopeObjects.put(liquibase.Scope.Attr.resourceAccessor.name(), resourceAccessor );
        logger.debug("Set up scope");
        try {
            liquibase.Scope.child(scopeObjects, scopedRunner);
        } catch (Exception e) {
            if (e instanceof liquibase.exception.LiquibaseException) {
                throw (liquibase.exception.LiquibaseException) e;
            } else {
                throw new liquibase.exception.LiquibaseException(e);
            }
        }
    }

    public void myUpdate(String changeLogFile,  java.io.OutputStream lbLogger, Database lbDatabase, String contexts) throws liquibase.exception.LiquibaseException {
         
        myScope(() -> {
            liquibase.command.CommandScope updateCommand = new liquibase.command.CommandScope(liquibase.command.core.UpdateCommandStep.COMMAND_NAME);
            updateCommand.addArgumentValue(liquibase.command.core.helpers.DbUrlConnectionArgumentsCommandStep.DATABASE_ARG, database);
            updateCommand.addArgumentValue(liquibase.command.core.UpdateToTagCommandStep.CHANGELOG_FILE_ARG, changeLogFile);
            updateCommand.addArgumentValue(liquibase.command.core.UpdateToTagCommandStep.CONTEXTS_ARG, contexts != null ? contexts.toString() : null);
            updateCommand.addArgumentValue(liquibase.command.core.helpers.ShowSummaryArgument.SHOW_SUMMARY , showSummary);
            updateCommand.addArgumentValue(liquibase.command.core.helpers.ShowSummaryArgument.SHOW_SUMMARY_OUTPUT, showSummaryOutput);
            updateCommand.setOutput(lbLogger);
            updateCommand.execute();
        });
    }
}

then execute in process with try / catch

 try {
            DbLiqLiquibase newLiquibase = new DbLiqLiquibase(fileChangeLog.getName(), clOpener, dbliquibase );
            newLiquibase.myUpdate(fileChangeLog.getName(), lbLogger, dbliquibase, finalContextValue );
        }
        catch (Exception ee) {
            logger.error("Error executing liquibase " + ee.getMessage());
            ee.printStackTrace();
        }