search

micronaut-projects / micronaut-aot

Experimental Ahead-of-time optimizations for Micronaut
Apache License 2.0
17 stars 5 forks source link

Json Formatter in logback.xml breaks Micronaut building #311

Closed eratolekov closed 2 months ago

eratolekov commented 2 months ago

Expected Behavior

./gradlew build builds Micronaut app.

Actual Behaviour

./gradlew build generates exception:`

$ ./gradlew build

> Task :prepareJitOptimizations FAILED
10:03:08,321 |-INFO in ch.qos.logback.classic.LoggerContext[default] - This is logback-classic version 1.5.3
10:03:08,323 |-INFO in ch.qos.logback.classic.util.ContextInitializer@7a35b0f5 - No custom configurators were discovered as a service.
10:03:08,323 |-INFO in ch.qos.logback.classic.util.ContextInitializer@7a35b0f5 - Trying to configure with ch.qos.logback.classic.joran.SerializedModelConfigurator
10:03:08,325 |-INFO in ch.qos.logback.classic.util.ContextInitializer@7a35b0f5 - Constructed configurator of type class ch.qos.logback.classic.joran.SerializedModelConfigurator
10:03:08,326 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could NOT find resource [logback-test.scmo]
10:03:08,326 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could NOT find resource [logback.scmo]
10:03:08,336 |-INFO in ch.qos.logback.classic.util.ContextInitializer@7a35b0f5 - ch.qos.logback.classic.joran.SerializedModelConfigurator.configure() call lasted 2 milliseconds. ExecutionStatus=INVOKE_NEXT_IF_ANY
10:03:08,336 |-INFO in ch.qos.logback.classic.util.ContextInitializer@7a35b0f5 - Trying to configure with ch.qos.logback.classic.util.DefaultJoranConfigurator
10:03:08,337 |-INFO in ch.qos.logback.classic.util.ContextInitializer@7a35b0f5 - Constructed configurator of type class ch.qos.logback.classic.util.DefaultJoranConfigurator
10:03:08,337 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could NOT find resource [logback-test.xml]
10:03:08,340 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Found resource [logback.xml] at [jar:file:/C:/Users/et/IdeaProjects/temp/testmn3/build/libs/demo-0.1.jar!/logback.xml]
10:03:08,348 |-INFO in ch.qos.logback.core.joran.spi.ConfigurationWatchList@5e2c3d18 - URL [jar:file:/C:/Users/et/IdeaProjects/temp/testmn3/build/libs/demo-0.1.jar!/logback.xml] is not of type file
10:03:08,486 |-WARN in ch.qos.logback.core.model.processor.AppenderModelHandler - Appender named [STDOUT] not referenced. Skipping further processing.
10:03:08,486 |-INFO in ch.qos.logback.core.model.processor.AppenderModelHandler - Processing appender named [json]
10:03:08,486 |-INFO in ch.qos.logback.core.model.processor.AppenderModelHandler - About to instantiate appender of type [ch.qos.logback.core.ConsoleAppender]
10:03:08,665 |-INFO in ch.qos.logback.classic.model.processor.RootLoggerModelHandler - Setting level of ROOT logger to INFO
10:03:08,665 |-INFO in ch.qos.logback.core.model.processor.AppenderRefModelHandler - Attaching appender named [json] to Logger[ROOT]
10:03:08,666 |-INFO in ch.qos.logback.core.model.processor.DefaultProcessor@2cb4893b - End of configuration.
10:03:08,666 |-INFO in ch.qos.logback.classic.joran.JoranConfigurator@cc43f62 - Registering current configuration as safe fallback point
10:03:08,666 |-INFO in ch.qos.logback.classic.util.ContextInitializer@7a35b0f5 - ch.qos.logback.classic.util.DefaultJoranConfigurator.configure() call lasted 330 milliseconds. ExecutionStatus=DO_NOT_INVOKE_NEXT_IF_ANY

{"timestamp":"2024-08-20T10:03:09.004+0500","level":"INFO","thread":"main","logger":"io.micronaut.aot.MicronautAotOptimizer","message":"Analysis will be performed with active environments: []","context":"default"}
java.lang.RuntimeException: java.lang.reflect.InvocationTargetException
    at io.micronaut.aot.cli.Main.executeInIsolatedLoader(Main.java:113)
    at io.micronaut.aot.cli.Main.run(Main.java:87)
    at picocli.CommandLine.executeUserObject(CommandLine.java:2026)
    at picocli.CommandLine.access$1500(CommandLine.java:148)
    at picocli.CommandLine$RunLast.executeUserObjectOfLastSubcommandWithSameParent(CommandLine.java:2461)
    at picocli.CommandLine$RunLast.handle(CommandLine.java:2453)
    at picocli.CommandLine$RunLast.handle(CommandLine.java:2415)
    at picocli.CommandLine$AbstractParseResultHandler.execute(CommandLine.java:2273)
    at picocli.CommandLine$RunLast.execute(CommandLine.java:2417)
    at picocli.CommandLine.execute(CommandLine.java:2170)
    at io.micronaut.aot.cli.Main.execute(Main.java:134)
    at io.micronaut.aot.cli.Main.main(Main.java:138)
Caused by: java.lang.reflect.InvocationTargetException
    at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:118)
    at java.base/java.lang.reflect.Method.invoke(Method.java:580)
    at io.micronaut.aot.cli.Main.executeInIsolatedLoader(Main.java:107)
    ... 11 more
Caused by: java.lang.RuntimeException: Unable to convert typeclass java.nio.charset.Charset
    at io.micronaut.aot.std.sourcegen.Logback14GeneratorHelper$1.maybeGenerateAddOrSet(Logback14GeneratorHelper.java:289)
    at io.micronaut.aot.std.sourcegen.Logback14GeneratorHelper$1.generateSetterCode(Logback14GeneratorHelper.java:260)
    at io.micronaut.aot.std.sourcegen.Logback14GeneratorHelper$1.visitImplicit(Logback14GeneratorHelper.java:222)
    at io.micronaut.aot.std.sourcegen.Logback14GeneratorHelper$ModelVisitor.previsit(Logback14GeneratorHelper.java:367)
    at io.micronaut.aot.std.sourcegen.Logback14GeneratorHelper$ModelVisitor.visit(Logback14GeneratorHelper.java:354)
    at io.micronaut.aot.std.sourcegen.Logback14GeneratorHelper$ModelVisitor.lambda$visit$0(Logback14GeneratorHelper.java:355)
    at java.base/java.util.ArrayList.forEach(ArrayList.java:1596)
    at io.micronaut.aot.std.sourcegen.Logback14GeneratorHelper$ModelVisitor.visit(Logback14GeneratorHelper.java:355)
    at io.micronaut.aot.std.sourcegen.Logback14GeneratorHelper$ModelVisitor.lambda$visit$0(Logback14GeneratorHelper.java:355)
    at java.base/java.util.ArrayList.forEach(ArrayList.java:1596)
    at io.micronaut.aot.std.sourcegen.Logback14GeneratorHelper$ModelVisitor.visit(Logback14GeneratorHelper.java:355)
    at io.micronaut.aot.std.sourcegen.Logback14GeneratorHelper$ModelVisitor.lambda$visit$0(Logback14GeneratorHelper.java:355)
    at java.base/java.util.ArrayList.forEach(ArrayList.java:1596)
    at io.micronaut.aot.std.sourcegen.Logback14GeneratorHelper$ModelVisitor.visit(Logback14GeneratorHelper.java:355)
    at io.micronaut.aot.std.sourcegen.Logback14GeneratorHelper$ModelVisitor.visit(Logback14GeneratorHelper.java:350)
    at io.micronaut.aot.std.sourcegen.Logback14GeneratorHelper.configureMethod(Logback14GeneratorHelper.java:337)
    at io.micronaut.aot.std.sourcegen.LogbackConfigurationSourceGenerator.generate(LogbackConfigurationSourceGenerator.java:59)
    at io.micronaut.aot.core.codegen.AbstractSingleClassFileGenerator.generate(AbstractSingleClassFileGenerator.java:35)
    at io.micronaut.aot.std.sourcegen.LogbackConfigurationSourceGenerator.generate(LogbackConfigurationSourceGenerator.java:85)
    at io.micronaut.aot.core.codegen.ApplicationContextConfigurerGenerator.generate(ApplicationContextConfigurerGenerator.java:66)
    at io.micronaut.aot.MicronautAotOptimizer$Runner.execute(MicronautAotOptimizer.java:343)
    at io.micronaut.aot.MicronautAotOptimizer.execute(MicronautAotOptimizer.java:202)
    at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:103)
    ... 13 more

FAILURE: Build failed with an exception.

Steps To Reproduce

  1. Create new app using Micronaut Launch at https://micronaut.io/launch with Java 21, Kotlin, Gradle, Spock.
  2. Add json formatter dependencies to build.gradle
  3. Add json formatter settings to logback.xml
  4. Try to build: ./gradlew build

build.gradle

...
dependencies {
    ...
    runtimeOnly("ch.qos.logback.contrib:logback-jackson:0.1.5")
    runtimeOnly("ch.qos.logback.contrib:logback-json-classic:0.1.5")
    ...
}
...

logback.xml

<configuration>

    <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
        <!-- encoders are assigned the type
             ch.qos.logback.classic.encoder.PatternLayoutEncoder by default -->
        <encoder>
            <pattern>%cyan(%d{HH:mm:ss.SSS}) %gray([%thread]) %highlight(%-5level) %magenta(%logger{36}) - %msg%n</pattern>
        </encoder>
    </appender>

    <appender name="json" class="ch.qos.logback.core.ConsoleAppender">
        <encoder class="ch.qos.logback.core.encoder.LayoutWrappingEncoder">
            <charset>utf-8</charset>
            <layout class="ch.qos.logback.contrib.json.classic.JsonLayout">
                <jsonFormatter class="ch.qos.logback.contrib.jackson.JacksonJsonFormatter">
                    <prettyPrint>false</prettyPrint>
                </jsonFormatter>
                <timestampFormat>yyyy-MM-dd'T'HH:mm:ss.SSSZZZZZ</timestampFormat>
                <appendLineSeparator>true</appendLineSeparator>
                <includeContextName>true</includeContextName>
                <includeMDC>true</includeMDC>
            </layout>
        </encoder>
    </appender>

    <root level="info">
        <appender-ref ref="json"/>
    </root>
</configuration>

The root cause is <charset>utf-8</charset> . If this string is absent the build is succesful.

Environment Information

Windows 11 23H2 OpenJDK Runtime Environment Temurin-21.0.2+13 (build 21.0.2+13-LTS)

Example Application

https://github.com/eratolekov/micronaut-json-logback-bug

Version

4.5.1

yawkat commented 2 months ago

You can try disabling micronaut-aot or specifically the logging config aot for now.

eratolekov commented 2 months ago

You can try disabling micronaut-aot or specifically the logging config aot for now.

Yes, as workaround I can set replaceLogbackXml = false in build.gradle.

altro3 commented 2 months ago

I received the same error in my project and have already fixed it. The problem is in the appender encoder. If the encoding is specified, it tries to call the method Charset.valueOf("UTF-8"), but must be Charset.forName("UTF-8").

Fixed here: https://github.com/micronaut-projects/micronaut-aot/pull/313