Issues with the logger cast

Environment

MacOSX

Liquibase Version:
4.1.0

Liquibase Integration & Version: <Pick one: CLI, maven, gradle, spring boot, servlet, etc.>
org.liquibase:liquibase-core:4.1.0
org.liquibase.ext:liquibase-hibernate5:4.1.0

Liquibase Extension(s) & Version:

Database Vendor & Version:

Operating System Type & Version:
MacOSX Catalina
10.15.6

Description

Trying to implement a gradle task for the diffChangeLog liquibase's command line command.

My dependencies:

    implementation("org.liquibase:liquibase-core:4.1.0")
    implementation("org.liquibase.ext:liquibase-hibernate5:4.1.0")
    runtimeOnly("com.mattbertolini:liquibase-slf4j:4.0.0")

The task

tasks.register<JavaExec>("liquibaseDiffChangelog") {
    description = "Runs Liquidbase diff between schema and current changeSet"
    group = "liquibase"
    classpath = sourceSets["main"].runtimeClasspath + configurations["liquidbase"]
    main = "liquibase.integration.commandline.Main"

    args("--changeLogFile=" + project.projectDir.toString() + "/src/main/resources/changelog-changesets.xml")
    args("--referenceUrl=hibernate:spring:**redacted**?dialect=org.hibernate.dialect.MySQL57Dialect")
    args("--username=sa")
    args("--password=sa")
    args("--url=jdbc:mysql://localhost:3306/**redacted**?useSSL=false&nullNamePatternMatchesAll=true")
    args("--driver=com.mysql.cj.jdbc.Driver")
    args("diffChangeLog")
}

it gives me

▶ ./gradlew liquibaseDiffChangelog

> Task :liquibaseDiffChangelog FAILED
16:38:12,437 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could NOT find resource [logback-test.xml]
16:38:12,438 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could NOT find resource [logback.groovy]
16:38:12,439 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Found resource [logback.xml] at [file:/**redacted**/build/resources/main/logback.xml]
16:38:12,553 |-INFO in ch.qos.logback.classic.joran.action.LoggerContextListenerAction - Adding LoggerContextListener of type [ch.qos.logback.classic.jul.LevelChangePropagator] to the object stack
16:38:12,554 |-INFO in ch.qos.logback.classic.jul.LevelChangePropagator@7c7b252e - Propagating DEBUG level on Logger[ROOT] onto the JUL framework
16:38:12,554 |-INFO in ch.qos.logback.classic.joran.action.LoggerContextListenerAction - Starting LoggerContextListener
16:38:12,556 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.core.ConsoleAppender]
16:38:12,558 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [STDOUT]
16:38:12,563 |-INFO in ch.qos.logback.core.joran.action.NestedComplexPropertyIA - Assuming default type [ch.qos.logback.classic.encoder.PatternLayoutEncoder] for [encoder] property
16:38:12,817 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.classic.AsyncAppender]
16:38:12,819 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [ASYNC]
16:38:12,819 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [STDOUT] to ch.qos.logback.classic.AsyncAppender[ASYNC]
16:38:12,819 |-INFO in ch.qos.logback.classic.AsyncAppender[ASYNC] - Attaching appender named [STDOUT] to AsyncAppender.
16:38:12,819 |-INFO in ch.qos.logback.classic.AsyncAppender[ASYNC] - Setting discardingThreshold to 51
16:38:12,820 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [liquibase] to INFO
16:38:12,821 |-INFO in ch.qos.logback.classic.jul.LevelChangePropagator@7c7b252e - Propagating INFO level on Logger[liquibase] onto the JUL framework
16:38:12,821 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [com.fieldlens] to DEBUG
16:38:12,821 |-INFO in ch.qos.logback.classic.jul.LevelChangePropagator@7c7b252e - Propagating DEBUG level on Logger[com.fieldlens] onto the JUL framework
16:38:12,821 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [com.wework.costmanagement] to INFO
16:38:12,821 |-INFO in ch.qos.logback.classic.jul.LevelChangePropagator@7c7b252e - Propagating INFO level on Logger[com.wework.costmanagement] onto the JUL framework
16:38:12,821 |-INFO in ch.qos.logback.classic.joran.action.RootLoggerAction - Setting level of ROOT logger to INFO
16:38:12,821 |-INFO in ch.qos.logback.classic.jul.LevelChangePropagator@7c7b252e - Propagating INFO level on Logger[ROOT] onto the JUL framework
16:38:12,821 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [ASYNC] to Logger[ROOT]
16:38:12,821 |-INFO in ch.qos.logback.classic.joran.action.ConfigurationAction - End of configuration.
16:38:12,822 |-INFO in ch.qos.logback.classic.joran.JoranConfigurator@64e7619d - Registering current configuration as safe fallback point
Unexpected error running Liquibase: class com.mattbertolini.liquibase.logging.slf4j.Slf4jLogService cannot be cast to class liquibase.logging.core.JavaLogService (com.mattbertolini.liquibase.logging.slf4j.Slf4jLogService and liquibase.logging.core.JavaLogService are in unnamed module of loader 'app')
For more information, please use the --logLevel flag
2020-10-13 16:38:12.850 [main   ] ERROR l.integration.commandline.Main$1 - Unexpected error running Liquibase: class com.mattbertolini.liquibase.logging.slf4j.Slf4jLogService cannot be cast to class liquibase.logging.core.JavaLogService (com.mattbertolini.liquibase.logging.slf4j.Slf4jLogService and liquibase.logging.core.JavaLogService are in unnamed module of loader 'app')
java.lang.ClassCastException: class com.mattbertolini.liquibase.logging.slf4j.Slf4jLogService cannot be cast to class liquibase.logging.core.JavaLogService (com.mattbertolini.liquibase.logging.slf4j.Slf4jLogService and liquibase.logging.core.JavaLogService are in unnamed module of loader 'app')
        at liquibase.integration.commandline.Main$1.run(Main.java:276)
        at liquibase.integration.commandline.Main$1.run(Main.java:193)
        at liquibase.Scope.child(Scope.java:169)
        at liquibase.Scope.child(Scope.java:145)
        at liquibase.integration.commandline.Main.run(Main.java:193)
        at liquibase.integration.commandline.Main.main(Main.java:156)

Any recommendations?

Steps To Reproduce

List the steps to reproduce the behavior.

Please be precise and ensure private information is redacted
Include things like
- Files used - sql scripts, changelog file(s), property file(s), config files, POM Files
- Exact commands used - CLI, maven, gradle, spring boot, servlet, etc.

Actual Behavior

A clear and concise description of what happens in the software before this pull request.

Include console output if relevant
Include log files if available.

Expected/Desired Behavior

A clear and concise description of what happens in the software after this pull request.

Screenshots (if appropriate)

If applicable, add screenshots to help explain your problem.

Additional Context

I've submitted the issue here - mattbertolini/liquibase-slf4j#11

Reply from mattbertolini

Thanks for the info! Sadly I did encounter this in my testing. It seems the the Liquibase CLI is expecting the default LogService implementation (the default being JavaLogService) to be returned in all cases. Here's the area of the code where that happens:

liquibase/liquibase-core/src/main/java/liquibase/integration/commandline/Main.java

Lines 272 to 277 in ef986f4

    
           java.util.logging.Logger rootLogger = java.util.logging.Logger.getLogger(""); 
        
           java.util.logging.Logger liquibaseLogger = java.util.logging.Logger.getLogger("liquibase"); 
        
           liquibaseLogger.setParent(rootLogger); 
        
           final JavaLogService logService = (JavaLogService) Scope.getCurrentScope().get(Scope.Attr.logService, LogService.class); 
        
           logService.setParent(liquibaseLogger);

I'm not sure if that is a bug on their part or a deliberate design decision. Based on the code around it, it looks deliberate. I guess they are expecting people to use standard out and the default Java logger does that just fine.

I would suggest opening an issue with Liquibase on this. There's no workaround I can do from my side. They will need to stop casting to a concrete type. If Liquibase doesn't or won't fix this, another way of avoiding the problem is to not use this library but rather bridge java.util.logging to SLF4J. I hope this information helps. Let me know if you have any other questions.

Hi @PavelSusloparov Thanks for bringing this issue to our attention. We will add it to the list of issues that we are processing.

@molivasdat hello, I'm looking at the code, and seems It'll be ok to use an interface instead of casting to implementation and seems setting parent to the logService from the current scope is not required at this part of the code.

Could you assign me to this task, I'm in the testing stage now and I believe I would make a PR today?

Hi @EEM86 Thanks for helping. I have assigned you this issue.

This was changed at some point. In 4.15.0, the code is correctly handling different Logger implementation.

Closing this as "stale"

	java.util.logging.Logger rootLogger = java.util.logging.Logger.getLogger("");
	java.util.logging.Logger liquibaseLogger = java.util.logging.Logger.getLogger("liquibase");
	liquibaseLogger.setParent(rootLogger);

	final JavaLogService logService = (JavaLogService) Scope.getCurrentScope().get(Scope.Attr.logService, LogService.class);
	logService.setParent(liquibaseLogger);