spring-projects / spring-boot

Spring Boot
https://spring.io/projects/spring-boot
Apache License 2.0
74.57k stars 40.55k forks source link

Spring Boot 3.3.0 Native debug=true in application.properties No effect #40930

Closed syedyusufh closed 3 months ago

syedyusufh commented 3 months ago

I need to debug my Spring Boot v3.3.0 native application built using mvn package -P <native-profile> as it is failing to load application properties from AWS parameter store which was otherwise working fine till Spring Boot v3.2.5

So, have addeddebug=true in application.properties and expected to see additional information on the config failure reported via org.springframework.boot.diagnostics.LoggingFailureAnalysisReporter, but no effect

Debug logs from org.springframework.boot.diagnostics.LoggingFailureAnalysisReporter aren't available for the native image.

wilkinsona commented 3 months ago

Without knowing what's happening when you start the application, it's not clear if LoggingFailureAnalysisReporter will have been called. For that to happen, an exception for which failure analysis is performed successfully would have to be thrown when the application is started.

If you would like us to spend some more time investigating, please spend some time providing a complete yet minimal sample that reproduces the problem. You can share it with us by pushing it to a separate repository on GitHub or by zipping it up and attaching it to this issue.

syedyusufh commented 3 months ago

Thanks for the quick revert @wilkinsona

I am referring to the below class which is reporting the startup failure related to config location citing AWS parameterstore. Inorder to see the actual root cause, I need to have the debug logging enabled for my native image. Have tried with debug=true in application.properties which does not have any effect. Please correct if I'm wrong. Thanks

public final class LoggingFailureAnalysisReporter implements FailureAnalysisReporter {

    private static final Log logger = LogFactory.getLog(LoggingFailureAnalysisReporter.class);

    @Override
    public void report(FailureAnalysis failureAnalysis) {
        if (logger.isDebugEnabled()) {
            logger.debug("Application failed to start due to an exception", failureAnalysis.getCause());
        }
        if (logger.isErrorEnabled()) {
            logger.error(buildMessage(failureAnalysis));
        }
    }

    private String buildMessage(FailureAnalysis failureAnalysis) {
        StringBuilder builder = new StringBuilder();
        builder.append(String.format("%n%n"));
        builder.append(String.format("***************************%n"));
        builder.append(String.format("APPLICATION FAILED TO START%n"));
        builder.append(String.format("***************************%n%n"));
        builder.append(String.format("Description:%n%n"));
        builder.append(String.format("%s%n", failureAnalysis.getDescription()));
        if (StringUtils.hasText(failureAnalysis.getAction())) {
            builder.append(String.format("%nAction:%n%n"));
            builder.append(String.format("%s%n", failureAnalysis.getAction()));
        }
        return builder.toString();
    }
wilkinsona commented 3 months ago

I am referring to the below class which is reporting the startup failure related to config location citing AWS parameterstore.

As I said above, without knowing what the failure is, I don't know if it will have been analyzed. Please provide the requested sample. We can then investigate further.

syedyusufh commented 3 months ago

Please check the below sample application with the mentioned startup failure logs. Need to enable debug logs as to see the actual root cause. Thanks

Sample Application

20:12:07.297 [restartedMain] ERROR org.springframework.boot.diagnostics.LoggingFailureAnalysisReporter -- 

***************************
APPLICATION FAILED TO START
***************************

Description:

Config data location 'aws-parameterstore:/config/config-failure-debug_dev/' does not exist

Action:

Check that the value 'aws-parameterstore:/config/config-failure-debug_dev/' at class path resource [application.properties] - 4:23 is correct, or prefix it with 'optional:'
@Override
public void report(FailureAnalysis failureAnalysis) {
    if (logger.isDebugEnabled()) {
        logger.debug("Application failed to start due to an exception", failureAnalysis.getCause());
    }
philwebb commented 3 months ago

This is quite similar to #32120.

The problem we have here is that we can't load the application.properties file so we throw an exception. That exception prevents us from using the debug: true property in the file.

I'm not sure that there is much we can do to improve the situation unfortunately.

philwebb commented 3 months ago

@syedyusufh

I think your best option for now is to temporarily add a logback.xml file to src/main/resources. Something like this:

<?xml version="1.0" encoding="UTF-8"?>
<configuration>
    <include resource="org/springframework/boot/logging/logback/defaults.xml"/>
    <include resource="org/springframework/boot/logging/logback/console-appender.xml" />
    <root level="INFO">
        <appender-ref ref="CONSOLE" />
    </root>
    <logger name="org.springframework.boot" level="TRACE"/>
</configuration>

With your sample that gives:


org.springframework.boot.context.config.ConfigDataLocationNotFoundException: Config data location 'aws-parameterstore:/config/config-failure-debug_dev/' cannot be found
    at org.springframework.boot.context.config.ConfigDataEnvironment.checkMandatoryLocations(ConfigDataEnvironment.java:386)
    at org.springframework.boot.context.config.ConfigDataEnvironment.applyToEnvironment(ConfigDataEnvironment.java:329)
    at org.springframework.boot.context.config.ConfigDataEnvironment.processAndApply(ConfigDataEnvironment.java:235)
    at org.springframework.boot.context.config.ConfigDataEnvironmentPostProcessor.postProcessEnvironment(ConfigDataEnvironmentPostProcessor.java:96)
    at org.springframework.boot.context.config.ConfigDataEnvironmentPostProcessor.postProcessEnvironment(ConfigDataEnvironmentPostProcessor.java:89)
    at org.springframework.boot.env.EnvironmentPostProcessorApplicationListener.onApplicationEnvironmentPreparedEvent(EnvironmentPostProcessorApplicationListener.java:109)
    at org.springframework.boot.env.EnvironmentPostProcessorApplicationListener.onApplicationEvent(EnvironmentPostProcessorApplicationListener.java:94)
    at org.springframework.context.event.SimpleApplicationEventMulticaster.doInvokeListener(SimpleApplicationEventMulticaster.java:185)
    at org.springframework.context.event.SimpleApplicationEventMulticaster.invokeListener(SimpleApplicationEventMulticaster.java:178)
    at org.springframework.context.event.SimpleApplicationEventMulticaster.multicastEvent(SimpleApplicationEventMulticaster.java:156)
    at org.springframework.context.event.SimpleApplicationEventMulticaster.multicastEvent(SimpleApplicationEventMulticaster.java:138)
    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/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:370)
    at org.springframework.boot.SpringApplication.run(SpringApplication.java:330)
    at org.springframework.boot.SpringApplication.run(SpringApplication.java:1363)
    at org.springframework.boot.SpringApplication.run(SpringApplication.java:1352)
    at com.sample.ConfigFailureDebugApplication.main(ConfigFailureDebugApplication.java:10)
    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77)
    at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.base/java.lang.reflect.Method.invoke(Method.java:568)
    at org.springframework.boot.devtools.restart.RestartLauncher.run(RestartLauncher.java:50)

I'm guessing your real application has a different error because it has something that can parse the aws-parameterstore: import.

philwebb commented 3 months ago

Perhaps native image creation is also complicating the issue. I found the exception was thrown on the JVM.

I'm going to close this one for now since I don't think we can improve the log output directly and it seems like the underlying issue might be in the library supporting aws-parameterstore: imports.

syedyusufh commented 3 months ago

Thanks @philwebb , yes I get the root cause now on a JVM ONLY

However, my native image still does NOT output the root cause. The same application used to start fine while on Spring Boot v3.2.5, we are seeing this problem ONLY after the upgrade to Spring Boot v3.3.0

For us to attribute the problem to Spring Boot or the underlying AWS library, need to know the root cause :(

Could you please consider logging the root cause (or just the cause message) as well by default in LoggingFailureAnalysisReporter? Thanks.

wilkinsona commented 3 months ago

@syedyusufh I don't think we can consider making any changes as you haven't yet provided what we need to reproduce the problem. Unfortunately, your sample does not reproduce it as AOT processing fails due to the problem in application.properties so we can't observe a difference between behaviour on the JVM and in a native image. If you want us to spend any more time on this, please provide a sample that accurately reproduces the behavior that you have described.