Spring-boot: Spring Boot 2 no logging exception message when use Apache Commons BeanUtils

[alanbear]

When I use Apache Commons BeanUtils with Spring Boot 2, I can't catch exception stacktrace message.

I also try other version, only 2.X have this problem.

build.gradle

buildscript {
    ext {
        springBootVersion = '2.0.0.RELEASE'
//      springBootVersion = '1.5.10.RELEASE'
//      springBootVersion = '2.0.1.BUILD-SNAPSHOT'
    }
    repositories {
        mavenCentral()
        maven {
            url 'https://repo.spring.io/libs-snapshot'
        }
    }
    dependencies {
        classpath("org.springframework.boot:spring-boot-gradle-plugin:${springBootVersion}")
    }
}

apply plugin: 'java'
apply plugin: 'eclipse'
apply plugin: 'org.springframework.boot'
apply plugin: 'io.spring.dependency-management'

group = 'com.example'
version = '0.0.1-SNAPSHOT'
sourceCompatibility = 1.8

repositories {
    mavenCentral()
    maven {
        url 'https://repo.spring.io/libs-snapshot'
    }
}


dependencies {
    compile('org.springframework.boot:spring-boot-starter')
    compile group: 'commons-beanutils', name: 'commons-beanutils', version: '1.9.3'

    testCompile('org.springframework.boot:spring-boot-starter-test')
}

DemoApplication.java

@SpringBootApplication
public class DemoApplication {

    public static void main(String[] args) {
        SpringApplication.run(DemoApplication.class, args);
    }

    @Bean
    public CommandLineRunner run() {
        return (args) -> {
            throw new Exception("test");
        };
    }
}

Console

2018-03-13 11:03:05.166  INFO 22690 --- [           main] com.example.demo.DemoApplication         : No active profile set, falling back to default profiles: default
2018-03-13 11:03:05.267  INFO 22690 --- [           main] s.c.a.AnnotationConfigApplicationContext : Refreshing org.springframework.context.annotation.AnnotationConfigApplicationContext@22f59fa: startup date [Tue Mar 13 11:03:05 CST 2018]; root of context hierarchy
2018-03-13 11:03:06.089  INFO 22690 --- [           main] o.s.j.e.a.AnnotationMBeanExporter        : Registering beans for JMX exposure on startup
2018-03-13 11:03:06.103  INFO 22690 --- [           main] com.example.demo.DemoApplication         : Started DemoApplication in 1.67 seconds (JVM running for 3.222)
Disconnected from the target VM, address: '127.0.0.1:63647', transport: 'socket'

Process finished with exit code 1

[wilkinsona]

There are a few things going on here.

In 2.0, SpringApplication ends up using a org.apache.commons.logging.impl.Jdk14Logger for its logging which means that the logging isn't routed into Logback as it should be. In 1.5, SpringApplication ends up using an org.apache.commons.logging.impl.SLF4JLog that is provided by SLF4J and routes logging into Logback. This change has two causes.

Firstly, commons-logging isn't on the classpath in 1.5 but it is in 2.0. This happens because we have removed the dependency management for commons-beanutils that excluded commons-logging. The problem can be avoided when using Boot 2.0 by excluding commons-logging:commons-logging:

compile('commons-beanutils:commons-beanutils:1.9.3') {
    exclude group: 'commons-logging', module: 'commons-logging'
}

However, that's not the full picture as the problem doesn't occur with 1.5 even when Commons Logging is on the classpath. In 1.5, Commons Logging's LogFactory finds the META-INF/services/org.apache.commons.logging.LogFactory file in jcl-over-slf4j and org.apache.commons.logging.impl.SLF4JLogFactory is used. In 2.0, we use Spring Framework's spring-jcl instead of jcl-over-slf4j. spring-jcl does not contain a META-INF/services/org.apache.commons.logging.LogFactory so Commons Logging falls back to its default factory and creates a org.apache.commons.logging.impl.Jdk14Logger.

I've opened SPR-16585 to see if spring-jcl can be improved. In the meantime, please exclude commons-logging:commons-logging as described above.

[alanbear]

Thank you for your help

[erezwncare]

Seems like spring-jcl are not going to fix it... I also had my share of hidden Exception with this, as the following exception would not have been printed without the exclusion of the commons or adding a custom ApplicationRunListener :

2018-12-07 14:11:23.614 ERROR 79921 --- [           main] o.s.boot.SpringApplication               : Application run failed

java.lang.IllegalStateException: No CacheResolver specified, and no unique bean of type CacheManager found. Mark one as primary (or give it the name 'cacheManager') or declare a specific CacheManager to use, that serves as the default one.
    at org.springframework.cache.interceptor.CacheAspectSupport.afterSingletonsInstantiated(CacheAspectSupport.java:194) ~[spring-context-5.0.6.RELEASE.jar:5.0.6.RELEASE]
    at org.springframework.beans.factory.support.DefaultListableBeanFactory.preInstantiateSingletons(DefaultListableBeanFactory.java:777) ~[spring-beans-5.0.6.RELEASE.jar:5.0.6.RELEASE]
    at org.springframework.context.support.AbstractApplicationContext.finishBeanFactoryInitialization(AbstractApplicationContext.java:869) ~[spring-context-5.0.6.RELEASE.jar:5.0.6.RELEASE]
    at org.springframework.context.support.AbstractApplicationContext.refresh(AbstractApplicationContext.java:550) ~[spring-context-5.0.6.RELEASE.jar:5.0.6.RELEASE]
    at org.springframework.boot.web.servlet.context.ServletWebServerApplicationContext.refresh(ServletWebServerApplicationContext.java:140) ~[spring-boot-2.0.2.RELEASE.jar:2.0.2.RELEASE]
    at org.springframework.boot.SpringApplication.refresh(SpringApplication.java:759) [spring-boot-2.0.2.RELEASE.jar:2.0.2.RELEASE]
    at org.springframework.boot.SpringApplication.refreshContext(SpringApplication.java:395) [spring-boot-2.0.2.RELEASE.jar:2.0.2.RELEASE]
    at org.springframework.boot.SpringApplication.run(SpringApplication.java:327) [spring-boot-2.0.2.RELEASE.jar:2.0.2.RELEASE]

Maybe something can be done on spring boot side ?