Support Janino in a native image

[gdrouet]

When building a native image with Spring Boot Maven plugin, Logback configuration relying on Janino leads to an error.

For instance, if we add to the logback-spring.xml file the following if statement:

        <if condition='isDefined("ENV")'>
            <then>
                <appender-ref ref="CONSOLE_JSON"/>
            </then>
            <else>
                <appender-ref ref="CONSOLE_LOCAL"/>
            </else>
        </if>

Then running a native image lead to this error:

Logging system failed to initialize using configuration from 'null'
java.util.EmptyStackException
    at java.base@17.0.5/java.util.Stack.peek(Stack.java:101)
    at ch.qos.logback.core.model.processor.ModelInterpretationContext.peekModel(ModelInterpretationContext.java:84)
    at ch.qos.logback.core.model.processor.conditional.ElseModelHandler.handle(ElseModelHandler.java:45)
    at ch.qos.logback.core.model.processor.DefaultProcessor.secondPhaseTraverse(DefaultProcessor.java:241)
    at ch.qos.logback.core.model.processor.DefaultProcessor.secondPhaseTraverse(DefaultProcessor.java:253)
    at ch.qos.logback.core.model.processor.DefaultProcessor.secondPhaseTraverse(DefaultProcessor.java:253)
    at ch.qos.logback.core.model.processor.DefaultProcessor.secondPhaseTraverse(DefaultProcessor.java:253)
    at ch.qos.logback.core.model.processor.DefaultProcessor.traversalLoop(DefaultProcessor.java:90)
    at ch.qos.logback.core.model.processor.DefaultProcessor.process(DefaultProcessor.java:106)
    at ch.qos.logback.core.joran.GenericXMLConfigurator.processModel(GenericXMLConfigurator.java:200)
    at org.springframework.boot.logging.logback.SpringBootJoranConfigurator.processModel(SpringBootJoranConfigurator.java:122)
    at org.springframework.boot.logging.logback.SpringBootJoranConfigurator.configureUsingAotGeneratedArtifacts(SpringBootJoranConfigurator.java:115)
    at org.springframework.boot.logging.logback.LogbackLoggingSystem.initializeFromAotGeneratedArtifactsIfPossible(LogbackLoggingSystem.java:210)
    at org.springframework.boot.logging.logback.LogbackLoggingSystem.initialize(LogbackLoggingSystem.java:187)
    at org.springframework.boot.context.logging.LoggingApplicationListener.initializeSystem(LoggingApplicationListener.java:332)
    at org.springframework.boot.context.logging.LoggingApplicationListener.initialize(LoggingApplicationListener.java:298)
    at org.springframework.boot.context.logging.LoggingApplicationListener.onApplicationEnvironmentPreparedEvent(LoggingApplicationListener.java:246)
    at org.springframework.boot.context.logging.LoggingApplicationListener.onApplicationEvent(LoggingApplicationListener.java:223)
    at org.springframework.context.event.SimpleApplicationEventMulticaster.doInvokeListener(SimpleApplicationEventMulticaster.java:176)
    at org.springframework.context.event.SimpleApplicationEventMulticaster.invokeListener(SimpleApplicationEventMulticaster.java:169)
    at org.springframework.context.event.SimpleApplicationEventMulticaster.multicastEvent(SimpleApplicationEventMulticaster.java:143)
    at org.springframework.context.event.SimpleApplicationEventMulticaster.multicastEvent(SimpleApplicationEventMulticaster.java:131)
    at org.springframework.boot.context.event.EventPublishingRunListener.multicastInitialEvent(EventPublishingRunListener.java:136)
    at org.springframework.boot.context.event.EventPublishingRunListener.environmentPrepared(EventPublishingRunListener.java:81)
    at org.springframework.boot.SpringApplicationRunListeners.lambda$environmentPrepared$2(SpringApplicationRunListeners.java:64)
    at java.base@17.0.5/java.lang.Iterable.forEach(Iterable.java:75)
    at org.springframework.boot.SpringApplicationRunListeners.doWithListeners(SpringApplicationRunListeners.java:118)
    at org.springframework.boot.SpringApplicationRunListeners.doWithListeners(SpringApplicationRunListeners.java:112)
    at org.springframework.boot.SpringApplicationRunListeners.environmentPrepared(SpringApplicationRunListeners.java:63)
    at org.springframework.boot.SpringApplication.prepareEnvironment(SpringApplication.java:352)
    at org.springframework.boot.SpringApplication.run(SpringApplication.java:303)
    at org.springframework.boot.SpringApplication.run(SpringApplication.java:1302)
    at org.springframework.boot.SpringApplication.run(SpringApplication.java:1291)

Note that a fat-jar run with -Dspring.aot.enabled=true does not help to reproduce the issue.

It would be great to have such support for native image.

[wilkinsona]

https://stackoverflow.com/questions/75514151/spring-boot-native-image-does-not-print-logs-when-logback-is-configured-with-con contains another sample that exhibits slightly different faulty behaviour – this sample starts successfully but no logging output is produced.

[hpoettker]

In the example from the stackoverflow question, I also get the exception from the original post if no metadata is added to src/main/resources/META-INF/native-image.

[wilkinsona]

Unfortunately, supporting Janino is non-trivial. It relies on generating ch.qos.logback.core.joran.conditional.Condition implementations at runtime, something that Graal does not support. Spring Native hacked around this with a substitution. This option is not open to us. We do not use substitutions in Boot as the Graal team have been clear that they should not be used.

One option that we could explore is generating the Condition implementations at build time, including them in the native image and then reusing these pre-generated classes at runtime. This is what Framework does for CGLib-based proxies. This may not be possible without changes to Logback if the necessary hook points are not available.

[wilkinsona]

I've prototyped something in this branch. It's not a lot of code, but I'm not happy with AotIfModelHandler. It duplicates much of the logic in Logback's IfModelHandler which would be at risk of falling out of sync. I'd like to discuss our options with the rest of the team. My feeling is that we won't be able to do something here without some changes to Logback.

[hpoettker]

@wilkinsona Thanks for implementing #34315 so quickly! The sample application from the stackoverflow question now fails early and logs a meaningful exception. I've added it to the SO question.

[gdrouet]

Do you have any workaround to write an equivalent programmatically and have a chance to make it work with spring native?

[wilkinsona]

I'm afraid not. https://github.com/spring-projects/spring-boot/issues/25847 is tracking support for programmatic configuration of Logback.

[wilkinsona]

@ceki would you consider making some changes to IfModelHandler to make it more Graal-friendly? We'd like to be able to capture the class files that it creates so that they can be contributed to a GraalVM native image. Then, when the image is being executed, we'd like to be able to provide those classes to the handler rather than it compiling them again.

[ceki]

@wilkinsona Sure, I am open to changes. I have looked at your efforts to support logback with GraalVM which are quite impressive.

For your information, I have started to explore a path for supporting GraalVM which you might find interesting:

Note: experimental changes in 1.4.9 (commit bd11e72017941331f2c3ba5101429359aced5a47 not yet released)

• JoranConfigurator is invoked by reflection and no longer as a service.
• JoranConfigurator now supports the <serializeModel file="...."/> directive in logback.xml to dump/serialize the model it created into an ObjectOutputStream file with an .smo extension.
• SerializedModelConfigurator searches for serialized model files (.smo extension) and configures logback if a logback.smo or logback-test.smo file is found.
• SerializedModelConfigurator is invoked as a configurator service. This happens before JoranConfigurator is invoked via serialization.

Anyway, I am still experimenting and am not sure of the results, that is whether this will work with GraalVM without the need for an XML parser.

Coming back to your original question, I understand that the experimental approach outlined above is different than the question raised by Janino.

Update: the strategy outlined above is verified to work in a GraalVM native-image, at least in simple scenarios.

[ceki]

@wilkinsona As of commit c440e08b, logback supports loading a model configuration file without ever loading JoranConfigurator and without including java.xml in a native image. I have verified this to work with GraalVM.

[wilkinsona]

That sounds great. Thanks, @ceki. Are Logback snapshots published anywhere? I'd like to give the new serialisation support a try and see if we can rip out the stuff that I wrote.

[ceki]

@wilkinsona Logback snapshots are not published. You would need to check out from github source and build at your end using the JDK 11+ and Maven.

I will be documenting the procedure for using serialized model (SMO) files shortly. The only "tricky" part is to remember to add <serializeModel file="${aVariablePointingToADestinationFile}"/> directive in logback.xml.

Please note this is still work in progress. More testing is required before public release.

Just fixed a silly bug this morning (24th of June).

[drubio-tlnd]

Hey, did the use of scmo file allows to use the janino library with conditions ? I currently have a logback-spring.xml that looks like that:

<?xml version="1.0" encoding="UTF-8"?>
<configuration debug="false">

    <serializeModel file="src/main/resources/logback.scmo"/>

    <include resource="org/springframework/boot/logging/logback/defaults.xml"/>
    <include resource="org/springframework/boot/logging/logback/console-appender.xml"/>

    <property name="LOGGING_LEVEL" value="${LOGGING_LEVEL:-INFO}"/>
    <property name="CONSOLE_LOG_THRESHOLD" value="${CONSOLE_LOG_THRESHOLD:-INFO}"/>

    <springProfile name="!dev">
        <if condition='p("LOGGING_LAYOUT").toUpperCase().equals("TEXT")'>
            <then>
                <!-- use the default TEXT layout -->
            </then>
            <else>
                <appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender">
                    <filter class="ch.qos.logback.classic.filter.ThresholdFilter">
                        <level>${CONSOLE_LOG_THRESHOLD}</level>
                    </filter>
                </appender>
                <logger name="reactor.netty.http.server.AccessLog" level="INFO" additivity="false">
                    <appender-ref ref="CONSOLE"/>
                </logger>
            </else>
        </if>
    </springProfile>

    <root level="${LOGGING_LEVEL}">
        <appender-ref ref="CONSOLE"/>
    </root>

</configuration>

1- When not using scmo file, I keep having EmptyStackException when running the native executable (following gradle nativeCompile command).

2- While when using the scmo file, I have errors like:

InvalidClassException: Unauthorized deserialization attempt; org.springframework.boot.logging.logback.SpringProfileModel
InvalidClassException: Unauthorized deserialization attempt; ch.qos.logback.core.model.conditional.IfModel

This error comes from ch.qos.logback.classic.joran.SerializedModelConfigurator following instruction:

HardenedModelInputStream hmis = new HardenedModelInputStream(is);
Model model = (Model) hmis.readObject();

I cannot figure out if there is something wrong in my native configuration, or if it's related to ch.qos.logback.classic.net.server.HardenedModelInputStream.getWhitelist() method which does not contain these 2 classes

[syedyusufh]

@ceki could you please tell us the way to use logback + janino in a Spring Boot native image?

[guai]

would it work if logback supported condition in a simple predicate class instead of compiling expressions on the fly with janino?

[ceki]

@guai Sounds like a good idea. I encourage you to file an issue with the logback project.

[ceki]

@gdrouet FYI, logback-tyler already translates janono-expressions into Java. It seems to me that the output generated logbaclk-tyler is an auto-loadable Configurator and shoulfd be quite suitable for a GraalVM application.

Also, the next version of logback-tyler will support PropertiesConfigurator (new in logback 1,5,8) which allows setting logger levels from a properties file.