SpringBoot More details logged in case of ApplicationFailedEvent

Hi, team!

I’ve made a trivial mistake in my application.yml file (a duplicate entry) and the app silently hanged in the air with the following message:

“Application failed to start with classpath: …“

That was everything. I traced the message to ClasspathLoggingApplicationListener and down to this code:


@Override
public void onApplicationEvent(ApplicationEvent event) {
    if (logger.isDebugEnabled()) {
        if (event instanceof ApplicationEnvironmentPreparedEvent) {
            logger.debug("Application started with classpath: " + getClasspath());
        }
        else if (event instanceof ApplicationFailedEvent) {
            logger.debug(
                    "Application failed to start with classpath: " + getClasspath());
        }
    }
}

I debugged and took the stack trace from the event - the reason became immediately apparent, there was an appropriate message within.

Question: Shouldn’t some more details be provided in case of ApplicationFailedEvent? Is the log level really debug?

Shall I try to provide some more details?

Thanks, L.

Comment From: snicoll

Shall I try to provide some more details?

Yes please. A sample that reproduces the mistake would be ideal.

Comment From: luchob

Thanks you Stéphane! The sample is here. It is almost empty and contains an application.yml with duplicated keys:

a:
  b:
    c: xyz

a:
  b:
    c: xyz

The only dependency is:

dependencies {
  compile('org.springframework.boot:spring-boot-starter-web')
}

Spring Boot 1.5.7.RELEASE.

Running the app hangs with this DEBUG message and no more info is provided:

14:38:52.823 [main] DEBUG org.springframework.boot.logging.ClasspathLoggingApplicationListener - Application failed to start with classpath: [some jars here...]

Removing the duplicate key solves the problem.

Hope this helps.

Comment From: snicoll

Thanks for the sample, that is very useful!

Comment From: wilkinsona

This is a duplicate of #10362 which has been fixed in 1.5.8 snapshots. Running the sample against those snapshots, the app no longer hangs and it outputs the following:

20:21:04.666 [main] ERROR org.springframework.boot.SpringApplication - Application startup failed
java.lang.IllegalStateException: Failed to load property source from location 'classpath:/application.yml'
    at org.springframework.boot.context.config.ConfigFileApplicationListener$Loader.loadIntoGroup(ConfigFileApplicationListener.java:476)
    at org.springframework.boot.context.config.ConfigFileApplicationListener$Loader.load(ConfigFileApplicationListener.java:465)
    at org.springframework.boot.context.config.ConfigFileApplicationListener$Loader.load(ConfigFileApplicationListener.java:386)
    at org.springframework.boot.context.config.ConfigFileApplicationListener.addPropertySources(ConfigFileApplicationListener.java:225)
    at org.springframework.boot.context.config.ConfigFileApplicationListener.postProcessEnvironment(ConfigFileApplicationListener.java:195)
    at org.springframework.boot.context.config.ConfigFileApplicationListener.onApplicationEnvironmentPreparedEvent(ConfigFileApplicationListener.java:182)
    at org.springframework.boot.context.config.ConfigFileApplicationListener.onApplicationEvent(ConfigFileApplicationListener.java:168)
    at org.springframework.context.event.SimpleApplicationEventMulticaster.doInvokeListener(SimpleApplicationEventMulticaster.java:172)
    at org.springframework.context.event.SimpleApplicationEventMulticaster.invokeListener(SimpleApplicationEventMulticaster.java:165)
    at org.springframework.context.event.SimpleApplicationEventMulticaster.multicastEvent(SimpleApplicationEventMulticaster.java:139)
    at org.springframework.context.event.SimpleApplicationEventMulticaster.multicastEvent(SimpleApplicationEventMulticaster.java:122)
    at org.springframework.boot.context.event.EventPublishingRunListener.environmentPrepared(EventPublishingRunListener.java:74)
    at org.springframework.boot.SpringApplicationRunListeners.environmentPrepared(SpringApplicationRunListeners.java:54)
    at org.springframework.boot.SpringApplication.prepareEnvironment(SpringApplication.java:325)
    at org.springframework.boot.SpringApplication.run(SpringApplication.java:296)
    at org.springframework.boot.SpringApplication.run(SpringApplication.java:1118)
    at org.springframework.boot.SpringApplication.run(SpringApplication.java:1107)
    at eu.balev.demo.Application.main(Application.java:11)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:498)
    at org.springframework.boot.loader.MainMethodRunner.run(MainMethodRunner.java:48)
    at org.springframework.boot.loader.Launcher.launch(Launcher.java:87)
    at org.springframework.boot.loader.Launcher.launch(Launcher.java:50)
    at org.springframework.boot.loader.JarLauncher.main(JarLauncher.java:51)
Caused by: org.yaml.snakeyaml.parser.ParserException: while parsing MappingNode
 in 'reader', line 1, column 1:
    a:
    ^
Duplicate key: a
 in 'reader', line 7, column 11:
    xyz
       ^

    at org.springframework.beans.factory.config.YamlProcessor$StrictMapAppenderConstructor.constructMapping(YamlProcessor.java:411)
    at org.yaml.snakeyaml.constructor.SafeConstructor$ConstructYamlMap.construct(SafeConstructor.java:489)
    at org.yaml.snakeyaml.constructor.BaseConstructor.constructObject(BaseConstructor.java:182)
    at org.yaml.snakeyaml.constructor.BaseConstructor.constructDocument(BaseConstructor.java:141)
    at org.yaml.snakeyaml.constructor.BaseConstructor.getData(BaseConstructor.java:108)
    at org.yaml.snakeyaml.Yaml$1.next(Yaml.java:471)
    at org.springframework.beans.factory.config.YamlProcessor.process(YamlProcessor.java:160)
    at org.springframework.beans.factory.config.YamlProcessor.process(YamlProcessor.java:138)
    at org.springframework.boot.env.YamlPropertySourceLoader$Processor.process(YamlPropertySourceLoader.java:101)
    at org.springframework.boot.env.YamlPropertySourceLoader.load(YamlPropertySourceLoader.java:58)
    at org.springframework.boot.env.PropertySourcesLoader.load(PropertySourcesLoader.java:127)
    at org.springframework.boot.context.config.ConfigFileApplicationListener$Loader.doLoadIntoGroup(ConfigFileApplicationListener.java:490)
    at org.springframework.boot.context.config.ConfigFileApplicationListener$Loader.loadIntoGroup(ConfigFileApplicationListener.java:473)
    ... 25 common frames omitted

Comment From: madorb

drats. this just cost me half a day - obviously i should have checked the issues rather than relying on google. it's a net-new app so I didn't realize sooner that it was due to a 1.5.7 regression as it wasn't something i previously had working with 1.5.6.

I accidentally had an invalid value in my application.yaml (as reported by 1.5.6): Caused by: while scanning for the next token found character '@' that cannot start any token. (Do not use @ for indentation) in 'reader', line 7, column 21: build-date: @project.build.date@

I'm curious as to when 1.5.8 is this planned on being released? from a user perspective this is a pretty painful regression issue - the application simply does not start, with zero indication as to why. i'd hate for other folks to lose so much time trying to suss it out...

Comment From: GeorgeBarbosa

I'm facing the same issue in org.springframework.boot:spring-boot-starter:2.6.7.

I can find the logs in stdout but they are not logged into my *.log files. Maybe this issue was introduced again?

Duplicated entry on the application.yml makes the application startup fail without any logs.

x: y: test x: y: test

Comment From: wilkinsona

@GeorgeBarbosa If logging to stdout is working and logging to a file is not, that sounds like a different problem. Please open a new issue with a minimal sample that reproduces the problem and we can take a look.