jdbc-observations / datasource-micrometer

Micrometer Observation API instrumentation and Spring Boot 3 Auto-Configuration for JDBC APIs
Apache License 2.0
50 stars 8 forks source link

NullPointerException when connection is not possible #40

Closed ZIRAKrezovic closed 3 days ago

ZIRAKrezovic commented 3 weeks ago

When connection to database is not possible for whatever reason, spring-boot will record a NullPointerException rather than the real cause when using datasource-micrometer

Caused by: org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'liquibase' defined in class path resource [org/springframework/boot/autoconfigure/liquibase/LiquibaseAutoConfiguration$LiquibaseConfiguration.class]: Failed to perform getConnection
        at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.initializeBean(AbstractAutowireCapableBeanFactory.java:1788)
        at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:600)
        at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:522)
        at org.springframework.beans.factory.support.AbstractBeanFactory.lambda$doGetBean$0(AbstractBeanFactory.java:337)
        at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:234)
        at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:335)
        at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:200)
        at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:313)
        ... 17 common frames omitted
Caused by: net.ttddyy.dsproxy.DataSourceProxyException: Failed to perform getConnection
        at net.ttddyy.dsproxy.support.ProxyDataSource.getConnectionProxy(ProxyDataSource.java:88)
        at net.ttddyy.dsproxy.support.ProxyDataSource.getConnection(ProxyDataSource.java:73)
        at liquibase.integration.spring.SpringLiquibase.afterPropertiesSet(SpringLiquibase.java:283)
        at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.invokeInitMethods(AbstractAutowireCapableBeanFactory.java:1835)
        at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.initializeBean(AbstractAutowireCapableBeanFactory.java:1784)
        ... 24 common frames omitted
Caused by: java.lang.NullPointerException: Cannot invoke "net.ttddyy.dsproxy.ConnectionInfo.getConnectionId()" because "connectionInfo" is null
        at net.ttddyy.observation.tracing.DataSourceObservationListener.handleGetConnectionAfter(DataSourceObservationListener.java:262)
        at net.ttddyy.observation.tracing.DataSourceObservationListener.afterMethod(DataSourceObservationListener.java:207)
        at net.ttddyy.dsproxy.listener.CompositeMethodListener.afterMethod(CompositeMethodListener.java:25)
        at net.ttddyy.dsproxy.proxy.ProxyLogicSupport.proceedMethodExecution(ProxyLogicSupport.java:114)
        at net.ttddyy.dsproxy.support.ProxyDataSource.getConnectionProxy(ProxyDataSource.java:83)

If I remove the dependency, I see what the root cause is (connection failed, databsae down, etc)

ttddyy commented 3 days ago

@ZIRAKrezovic Thanks for the report. I fixed the issue and released v1.0.4. Please try it.

luispflamminger commented 2 days ago

Hi @ttddyy,

first of all, thanks for the great work.

I think this change introduced issues for us. We have the following integration test class

@SpringBootTest
@AutoConfigureMockMvc
class MyIT {

    @MockBean
    JwtDecoder jwtDecoder;

    @MockBean(name = "servicePointRepositoryImpl")
    ServicePointRepository servicePointRepository;

    @MockBean
    SpdbServicePointExportLogRepository spdbServicePointExportLogRepository;

    @Autowired
    private MockMvc mockMvc;

    // some tests
}

As you can see, we're mocking the JPA repository as we don't want to test real DB access here. With v1.0.3 this was running fine, but with v1.0.4 we're getting the following

[ERROR] com.example.MyIT.test_patch_invalidPropertiesForMegaResource_respondsBadRequest -- Time elapsed: 0.008 s <<< ERROR!
java.lang.IllegalStateException: Failed to load ApplicationContext for [WebMergedContextConfiguration@37c45154 testClass = com.example.MyIT, locations = [], classes = [com.telekom.dtit.clm.OpenApiGeneratorApplication], contextInitializerClasses = [], activeProfiles = [], propertySourceDescriptors = [], propertySourceProperties = ["org.springframework.boot.test.context.SpringBootTestContextBootstrapper=true"], contextCustomizers = [[ImportsContextCustomizer@55300b93 key = [org.springframework.boot.test.autoconfigure.web.servlet.MockMvcWebDriverAutoConfiguration, org.springframework.boot.test.autoconfigure.web.servlet.MockMvcAutoConfiguration, org.springframework.boot.autoconfigure.security.oauth2.client.servlet.OAuth2ClientAutoConfiguration, org.springframework.boot.autoconfigure.security.servlet.SecurityAutoConfiguration, org.springframework.boot.autoconfigure.security.servlet.SecurityFilterAutoConfiguration, org.springframework.boot.autoconfigure.security.servlet.UserDetailsServiceAutoConfiguration, org.springframework.boot.autoconfigure.security.oauth2.resource.servlet.OAuth2ResourceServerAutoConfiguration, org.springframework.boot.test.autoconfigure.web.servlet.MockMvcSecurityConfiguration, org.springframework.boot.test.autoconfigure.web.servlet.MockMvcWebClientAutoConfiguration, org.springframework.boot.test.autoconfigure.web.reactive.WebTestClientAutoConfiguration]], org.springframework.boot.test.context.filter.ExcludeFilterContextCustomizer@35636217, org.springframework.boot.test.json.DuplicateJsonObjectContextCustomizerFactory$DuplicateJsonObjectContextCustomizer@36dfbdaf, org.springframework.boot.test.mock.mockito.MockitoContextCustomizer@3550e3e1, org.springframework.boot.test.web.client.TestRestTemplateContextCustomizer@4992613f, org.springframework.boot.test.autoconfigure.actuate.observability.ObservabilityContextCustomizerFactory$DisableObservabilityContextCustomizer@1f, org.springframework.boot.test.autoconfigure.properties.PropertyMappingContextCustomizer@4b3fa0b3, org.springframework.boot.test.autoconfigure.web.servlet.WebDriverContextCustomizer@3f672204, org.springframework.boot.test.context.SpringBootTestAnnotation@a71a7ddd], resourceBasePath = "src/main/webapp", contextLoader = org.springframework.boot.test.context.SpringBootContextLoader, parent = null]
        at org.springframework.test.context.cache.DefaultCacheAwareContextLoaderDelegate.loadContext(DefaultCacheAwareContextLoaderDelegate.java:180)
        at org.springframework.test.context.support.DefaultTestContext.getApplicationContext(DefaultTestContext.java:130)
        at org.springframework.test.context.web.ServletTestExecutionListener.setUpRequestContextIfNecessary(ServletTestExecutionListener.java:191)
        at org.springframework.test.context.web.ServletTestExecutionListener.prepareTestInstance(ServletTestExecutionListener.java:130)
        at org.springframework.test.context.TestContextManager.prepareTestInstance(TestContextManager.java:260)
        at org.springframework.test.context.junit.jupiter.SpringExtension.postProcessTestInstance(SpringExtension.java:163)
        at java.base/java.util.stream.ReferencePipeline$3$1.accept(ReferencePipeline.java:197)
        at java.base/java.util.stream.ReferencePipeline$2$1.accept(ReferencePipeline.java:179)
        at java.base/java.util.ArrayList$ArrayListSpliterator.forEachRemaining(ArrayList.java:1625)
        at java.base/java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:509)
        at java.base/java.util.stream.AbstractPipeline.wrapAndCopyInto(AbstractPipeline.java:499)
        at java.base/java.util.stream.StreamSpliterators$WrappingSpliterator.forEachRemaining(StreamSpliterators.java:310)
        at java.base/java.util.stream.Streams$ConcatSpliterator.forEachRemaining(Streams.java:735)
        at java.base/java.util.stream.Streams$ConcatSpliterator.forEachRemaining(Streams.java:734)
        at java.base/java.util.stream.ReferencePipeline$Head.forEach(ReferencePipeline.java:762)
        at java.base/java.util.Optional.orElseGet(Optional.java:364)
        at java.base/java.util.ArrayList.forEach(ArrayList.java:1511)
        at java.base/java.util.ArrayList.forEach(ArrayList.java:1511)
Caused by: org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'entityManagerFactory' defined in class path resource [org/springframework/boot/autoconfigure/orm/jpa/HibernateJpaConfiguration.class]: Failed to instantiate [org.springframework.orm.jpa.LocalContainerEntityManagerFactoryBean]: Factory method 'entityManagerFactory' threw exception with message: Failed to perform getConnection
        at org.springframework.beans.factory.support.ConstructorResolver.instantiate(ConstructorResolver.java:648)
        at org.springframework.beans.factory.support.ConstructorResolver.instantiateUsingFactoryMethod(ConstructorResolver.java:636)
        at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.instantiateUsingFactoryMethod(AbstractAutowireCapableBeanFactory.java:1337)
        at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBeanInstance(AbstractAutowireCapableBeanFactory.java:1167)
        at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:562)
        at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:522)
        at org.springframework.beans.factory.support.AbstractBeanFactory.lambda$doGetBean$0(AbstractBeanFactory.java:337)
        at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:234)
        at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:335)
        at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:205)
        at org.springframework.context.support.AbstractApplicationContext.finishBeanFactoryInitialization(AbstractApplicationContext.java:952)
        at org.springframework.context.support.AbstractApplicationContext.refresh(AbstractApplicationContext.java:624)
        at org.springframework.boot.SpringApplication.refresh(SpringApplication.java:754)
        at org.springframework.boot.SpringApplication.refreshContext(SpringApplication.java:456)
        at org.springframework.boot.SpringApplication.run(SpringApplication.java:335)
        at org.springframework.boot.test.context.SpringBootContextLoader.lambda$loadContext$3(SpringBootContextLoader.java:137)
        at org.springframework.util.function.ThrowingSupplier.get(ThrowingSupplier.java:58)
        at org.springframework.util.function.ThrowingSupplier.get(ThrowingSupplier.java:46)
        at org.springframework.boot.SpringApplication.withHook(SpringApplication.java:1463)
        at org.springframework.boot.test.context.SpringBootContextLoader$ContextLoaderHook.run(SpringBootContextLoader.java:553)
        at org.springframework.boot.test.context.SpringBootContextLoader.loadContext(SpringBootContextLoader.java:137)
        at org.springframework.boot.test.context.SpringBootContextLoader.loadContext(SpringBootContextLoader.java:108)
        at org.springframework.test.context.cache.DefaultCacheAwareContextLoaderDelegate.loadContextInternal(DefaultCacheAwareContextLoaderDelegate.java:225)
        at org.springframework.test.context.cache.DefaultCacheAwareContextLoaderDelegate.loadContext(DefaultCacheAwareContextLoaderDelegate.java:152)
        ... 17 more
Caused by: org.springframework.beans.BeanInstantiationException: Failed to instantiate [org.springframework.orm.jpa.LocalContainerEntityManagerFactoryBean]: Factory method 'entityManagerFactory' threw exception with message: Failed to perform getConnection
        at org.springframework.beans.factory.support.SimpleInstantiationStrategy.instantiate(SimpleInstantiationStrategy.java:177)
        at org.springframework.beans.factory.support.ConstructorResolver.instantiate(ConstructorResolver.java:644)
        ... 40 more
Caused by: net.ttddyy.dsproxy.DataSourceProxyException: Failed to perform getConnection
        at net.ttddyy.dsproxy.support.ProxyDataSource.getConnectionProxy(ProxyDataSource.java:88)
        at net.ttddyy.dsproxy.support.ProxyDataSource.getConnection(ProxyDataSource.java:73)
        at org.springframework.jdbc.datasource.DataSourceUtils.fetchConnection(DataSourceUtils.java:160)
        at org.springframework.jdbc.datasource.DataSourceUtils.doGetConnection(DataSourceUtils.java:118)
        at org.springframework.jdbc.datasource.DataSourceUtils.getConnection(DataSourceUtils.java:81)
        at org.springframework.jdbc.core.JdbcTemplate.execute(JdbcTemplate.java:342)
        at org.springframework.boot.jdbc.EmbeddedDatabaseConnection.isEmbedded(EmbeddedDatabaseConnection.java:168)
        at org.springframework.boot.autoconfigure.orm.jpa.HibernateDefaultDdlAutoProvider.getDefaultDdlAuto(HibernateDefaultDdlAutoProvider.java:42)
        at org.springframework.boot.autoconfigure.orm.jpa.HibernateJpaConfiguration.lambda$getVendorProperties$1(HibernateJpaConfiguration.java:142)
        at org.springframework.boot.autoconfigure.orm.jpa.HibernateSettings.getDdlAuto(HibernateSettings.java:41)
        at org.springframework.boot.autoconfigure.orm.jpa.HibernateProperties.determineDdlAuto(HibernateProperties.java:118)
        at org.springframework.boot.autoconfigure.orm.jpa.HibernateProperties.getAdditionalProperties(HibernateProperties.java:87)
        at org.springframework.boot.autoconfigure.orm.jpa.HibernateProperties.determineHibernateProperties(HibernateProperties.java:80)
        at org.springframework.boot.autoconfigure.orm.jpa.HibernateJpaConfiguration.getVendorProperties(HibernateJpaConfiguration.java:143)
        at org.springframework.boot.autoconfigure.orm.jpa.JpaBaseConfiguration.entityManagerFactory(JpaBaseConfiguration.java:134)
        at java.base/java.lang.reflect.Method.invoke(Method.java:568)
        at org.springframework.beans.factory.support.SimpleInstantiationStrategy.instantiate(SimpleInstantiationStrategy.java:140)
        ... 41 more
Caused by: java.lang.NullPointerException: Cannot invoke "javax.sql.DataSource.isWrapperFor(java.lang.Class)" because "dataSource" is null
        at net.ttddyy.observation.tracing.HikariJdbcObservationFilter.map(HikariJdbcObservationFilter.java:51)
        at io.micrometer.observation.SimpleObservation.stop(SimpleObservation.java:185)
        at net.ttddyy.observation.tracing.DataSourceObservationListener.stopObservation(DataSourceObservationListener.java:314)
        at net.ttddyy.observation.tracing.DataSourceObservationListener.handleGetConnectionAfter(DataSourceObservationListener.java:257)
        at net.ttddyy.observation.tracing.DataSourceObservationListener.afterMethod(DataSourceObservationListener.java:207)
        at net.ttddyy.dsproxy.listener.CompositeMethodListener.afterMethod(CompositeMethodListener.java:25)
        at net.ttddyy.dsproxy.proxy.ProxyLogicSupport.proceedMethodExecution(ProxyLogicSupport.java:114)
        at net.ttddyy.dsproxy.support.ProxyDataSource.getConnectionProxy(ProxyDataSource.java:83)
        ... 57 more

I've fiddled around with adding some DataSource related mocks, but can't really get it to work. I guess this simple use case might affect more users. Can you perhaps think of a fix for an upcoming version, that doesn't require us to change our stubbing configuration?

Thanks in advance!

BR Luis