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

MigrationException: Error executing command. Cause: null #220

Closed
szj-coder opened this issue May 21, 2022 · 12 comments
Closed

MigrationException: Error executing command. Cause: null #220

szj-coder opened this issue May 21, 2022 · 12 comments
Assignees
Labels
Milestone

Comments

@szj-coder
Copy link

szj-coder commented May 21, 2022

Hi,
I'm using mybatis-migration:3.3.9 for data migration and I'm getting a strange exception, only when I deploy in Amazon cloud environment, I can't locate the exception based on the exception stack information.

org.apache.ibatis.migration.MigrationException: Error executing command.  Cause: null
	at org.apache.ibatis.migration.operations.PendingOperation.operate(PendingOperation.java:95)
	at org.apache.ibatis.migration.operations.PendingOperation.operate(PendingOperation.java:40)
	...

Please consider cleaning up the following code in PendingOperation.java and DownOperation.java and UpOperation.java

while (e instanceof MigrationException) {
   e = e.getCause();
}

Thanks

@harawata
Copy link
Member

Hello @szj-coder ,

Please provide more information so that we can reproduce the exception.

  • DB version, driver version
  • migration scripts
  • configuration
  • the steps/commands to reproduce the problem
  • what do you mean by 'deploy in Amazon cloud environment'

@szj-coder
Copy link
Author

szj-coder commented May 21, 2022

Hello @harawata ,
I am still troubleshooting the cause of the problem, my service is spring-boot architecture, deployed on cloud environment via docker container, before we can execute scripts normally in Ali cloud or company k8s or my local environment, only recently we have this exception when deployed on aws cloud, I will consider syncing the information here after locating the problem.

The exception is currently considered to be between PendingOperation.java:45 and PendingOperation.java:55 because the log of getConnection() can be seen and there is no WARNING: Running pending migrations out of order can create unexpected results. log for line PendingOperation.java:55

database.driverClass: com.mysql.cj.jdbc.Driver
database.url: jdbc:mysql://xxxxxx.amazonaws.com.cn:3306/xxx?useUnicode=true&characterEncoding=utf8&autoReconnect=true&allowMultiQueries=true&zeroDateTimeBehavior=convertToNull&serverTimezone=Asia/Shanghai

I'm very sorry, I can't provide other information, in the process of troubleshooting the problem, I found that there are contradictions between the logs here and the exceptions in try, and I think there is room for optimization

@harawata
Copy link
Member

I honestly do not understand what you are doing. :D
You are not executing migrate pending command from within the spring-boot app, are you?

Anyway, please let us know if you find more info for us to work with.

@szj-coder
Copy link
Author

szj-coder commented May 23, 2022

I modified the exception logic, and the following code was cleaned up

while (e instanceof MigrationException) {
   e = e.getCause();
}

Exception Stack:

org.apache.ibatis.migration.MigrationException: Error executing command.  Cause: org.apache.ibatis.migration.MigrationException: Change log doesn't exist, no migrations applied.  Try running 'up' instead.
	at com.xxx.migration.CustomPendingOperation.operate(CustomPendingOperation.java:81)
	at com.xxx.migration.CustomPendingOperation.operate(CustomPendingOperation.java:29)
	...
Caused by: org.apache.ibatis.migration.MigrationException: Change log doesn't exist, no migrations applied.  Try running 'up' instead.
	at com.xxx.migration.CustomPendingOperation.operate(CustomPendingOperation.java:39)
	... 13 more

The reason for the exception is tablename case mismatch

@harawata
Copy link
Member

harawata commented Jun 4, 2022

Could you post the entire stack trace, please?

@szj-coder
Copy link
Author

@harawata Take a look at the exception thrown here,you can simulate the change log table does not exist to view stack information

if (!changelogExists(con, option)) {
throw new MigrationException("Change log doesn't exist, no migrations applied. Try running 'up' instead.");
}

Error message will be erased here

while (e instanceof MigrationException) {
e = e.getCause();
}

@harawata
Copy link
Member

harawata commented Jun 7, 2022

@szj-coder
Stack trace shows the call stack that causes the exception and that is the information I would like to see.
If it's difficult, please provide the exact steps to reproduce the problem including some migration scripts, DB version etc..
So far, there is not enough information for us to reproduce the problem you are experiencing on our end.

@szj-coder
Copy link
Author

@harawata
Oh, I just feel that the exception information here is not friendly, it is not a serious bug, it can be asserted that MigrationException can understand what I mean. If you think it's trivial or something else, I can close this question.

Stack trace is here
#220 (comment)

Here is the stack trace after my modification
#220 (comment)

@harawata
Copy link
Member

harawata commented Jun 8, 2022

I agree that the information is not good enough and it should be fixed, but we need to reproduce the problem first (reproducing the problem is always the first step).
And to reproduce the problem, we need one of the following.

  • The 'full' stack trace. Please do not pick lines. Partial stack traces are not useful to developers very much. This may provide the information about 'where this exception is originally thrown' and that might be enough for me to reproduce the problem.
  • The exact steps to reproduce the problem.

@szj-coder
Copy link
Author

Since my code uses the lowercase changelog table name to create, and org.apache.ibatis.migration.operations.DatabaseOperation#changelogExists uses the uppercase CHANGELOG table name verification, and the mysql database sets the table name case sensitive

com.xxx.pip.migration.mysql.MultiMigrationSetup#doIt

    public void doIt(DataSource dataSource, String profile) throws Exception {
        String migrationPath = new StringBuilder("META-INF/migrations/").append(profile).append("/scripts/").toString();
        Enumeration<URL> paths = DefaultMigrationSetup.class.getClassLoader().getResources(migrationPath);
        ComplexMigrationLoader migrationLoader = new ComplexMigrationLoader(migrationPath, paths);
        migrationLoader.init();

        DataSourceConnectionProvider dataSourceConnectionProvider = new DataSourceConnectionProvider(dataSource);

        // changelog table is Exists?
        if (!checkChangelogExists(dataSourceConnectionProvider)) {
            createChangelogTable(dataSourceConnectionProvider);
        }

        ByteArrayOutputStream byteArrayOutputStream = new ByteArrayOutputStream();
        PrintStream printStream = new PrintStream(byteArrayOutputStream);
        logger.info("Migrating **Pending** SQL scripts");

        DatabaseOperationOption databaseOperationOption = new DatabaseOperationOption();
        databaseOperationOption.setSendFullScript(false);
        databaseOperationOption.setThrowWarning(false);
        databaseOperationOption.setAutoCommit(false);
        databaseOperationOption.setChangelogTable("changelog");

        new PendingOperation().operate(dataSourceConnectionProvider, migrationLoader, databaseOperationOption, printStream);
        new UpOperation().operate(dataSourceConnectionProvider, migrationLoader, databaseOperationOption, printStream);
        logger.info(new String(byteArrayOutputStream.toByteArray()));
        printStream.close();
    }

Stack trace:

org.apache.ibatis.migration.MigrationException: Error executing command.  Cause: null
	at org.apache.ibatis.migration.operations.PendingOperation.operate(PendingOperation.java:95) ~[mybatis-migrations-3.3.9.jar:3.3.9]
	at org.apache.ibatis.migration.operations.PendingOperation.operate(PendingOperation.java:40) ~[mybatis-migrations-3.3.9.jar:3.3.9]
	at com.xxx.pip.migration.mysql.MultiMigrationSetup.doIt(MultiMigrationSetup.java:70) ~[pip-migration-mybatis-5.1.1-20220601.084806-12.jar:na]
	at com.xxx.pip.migration.mysql.MultiMigrationSetup.execute(MultiMigrationSetup.java:38) ~[pip-migration-mybatis-5.1.1-20220601.084806-12.jar:na]
	at com.xxx.pip.migration.MybatisMigration.execute(MybatisMigration.java:49) ~[pip-migration-mybatis-5.1.1-20220601.084806-12.jar:na]
	at com.xxx.pip.migration.MigrationCostTime.migration(MigrationCostTime.kt:10) ~[pip-migration-base-5.1.1-20220601.082504-32.jar:na]
	at java.util.ArrayList.forEach(ArrayList.java:1259) ~[na:1.8.0_332]
	at com.xxx.pip.migration.MigrationApplicationRunListener.execute(MigrationApplicationRunListener.java:49) ~[pip-migration-spring-boot-starter-5.1.1-20220601.084843-11.jar:na]
	at com.xxx.lite.context.TenantProvider$DefaultTenantEventListener.onAddEvent(TenantProvider.java:496) ~[lite-base-1.7.0-20220526.051837-35.jar:na]
	at com.xxx.lite.context.TenantProvider.lambda$null$3(TenantProvider.java:270) ~[lite-base-1.7.0-20220526.051837-35.jar:na]
	at com.xxx.lite.util.DelayedLooper.loop(DelayedLooper.java:59) [lite-base-1.7.0-20220526.051837-35.jar:na]
	at com.xxx.lite.util.DelayedLooper.loop(DelayedLooper.java:49) [lite-base-1.7.0-20220526.051837-35.jar:na]
	at com.xxx.lite.util.DelayedLooper.loopOnException(DelayedLooper.java:104) [lite-base-1.7.0-20220526.051837-35.jar:na]
	at com.xxx.lite.context.TenantProvider.lambda$null$5(TenantProvider.java:262) ~[lite-base-1.7.0-20220526.051837-35.jar:na]
	at com.xxx.lite.context.TenantProvider.lambda$execFor$2(TenantProvider.java:149) ~[lite-base-1.7.0-20220526.051837-35.jar:na]
	at com.xxx.lite.context.TenantProvider.getWith(TenantProvider.java:187) ~[lite-base-1.7.0-20220526.051837-35.jar:na]
	at com.xxx.lite.context.TenantProvider.execFor(TenantProvider.java:148) ~[lite-base-1.7.0-20220526.051837-35.jar:na]
	at com.xxx.lite.context.TenantProvider.execFor(TenantProvider.java:135) ~[lite-base-1.7.0-20220526.051837-35.jar:na]
	at com.xxx.lite.context.TenantProvider.lambda$callbackWithRetry$6(TenantProvider.java:287) ~[lite-base-1.7.0-20220526.051837-35.jar:na]
	at com.xxx.lite.context.TenantProvider.lambda$null$9(TenantProvider.java:297) ~[lite-base-1.7.0-20220526.051837-35.jar:na]
	at java.lang.Thread.run(Thread.java:750) ~[na:1.8.0_332]

Hope this information can help you

@harawata
Copy link
Member

harawata commented Jun 9, 2022

Thanks for the info, @szj-coder !
I'll try to reproduce it when I find some spare time.

@harawata harawata self-assigned this Jun 12, 2022
@harawata harawata added the bug label Jun 12, 2022
@harawata harawata added this to the 3.3.11 milestone Jun 12, 2022
@harawata
Copy link
Member

@szj-coder ,

This should be fixed in the latest 3.3.11-SNAPSHOT.
Thank you for taking the time to report!

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

No branches or pull requests

2 participants