Skip to content

Reactive observation without parent fails with NullPointerException during completion #5082

@cweissbon

Description

@cweissbon

With version 4.5.5 of spring-data-mongodb the following change has been introduced in the MongoObservationCommandListener:

070f613#diff-64079f8c368e716ffb92044fe472f98a1ecc3ca32b0a56be4e21d0a3719f82b7R194

The line 194 leads to a NPE thrown by the ConcurrentHashMap because the parent observation (and therefore the value of the hashmap .putcall) seems to be null in some cases:

requestContext.put(ObservationThreadLocalAccessor.KEY, observation.getContext().getParentObservation());

The parent observation is explicitly marked as nullable in the micrometer observation implementation:

https://github.com/micrometer-metrics/micrometer/blob/101596568aba22d754dbc7db9f4b3805af1d617a/micrometer-observation/src/main/java/io/micrometer/observation/Observation.java#L964

I noticed that this happens regularly when the MongoDB hello command gets executed, which is e.g. the case when my application starts up.

Spring Boot Version 3.5.7
Kotlin with JVM21

Fix would be probably to wrap a null check around this?

I have configured the MongoDB tracing like this:

@Bean
fun mongoMetricsSynchronousContextProvider(registry: ObservationRegistry): MongoClientSettingsBuilderCustomizer {
    return MongoClientSettingsBuilderCustomizer { clientSettingsBuilder: MongoClientSettings.Builder ->
        clientSettingsBuilder.contextProvider(ContextProviderFactory.create(registry))
            .addCommandListener(MongoObservationCommandListener(registry))
    }
}

Stacktrace:

Exception thrown raising command succeeded event to listener org.springframework.data.mongodb.observability.MongoObservationCommandListener@6534fa9e

java.lang.NullPointerException: null
	at java.base/java.util.concurrent.ConcurrentHashMap.putVal(ConcurrentHashMap.java:1011)
	at java.base/java.util.concurrent.ConcurrentHashMap.put(ConcurrentHashMap.java:1006)
	at org.springframework.data.mongodb.observability.MapRequestContext.put(MapRequestContext.java:61)
	at org.springframework.data.mongodb.observability.MongoObservationCommandListener.stopObservation(MongoObservationCommandListener.java:194)
	at org.springframework.data.mongodb.observability.MongoObservationCommandListener.commandSucceeded(MongoObservationCommandListener.java:140)
	at com.mongodb.internal.connection.ProtocolHelper.sendCommandSucceededEvent(ProtocolHelper.java:311)
	at com.mongodb.internal.connection.LoggingCommandEventSender.sendSucceededEvent(LoggingCommandEventSender.java:181)
	at com.mongodb.internal.connection.LoggingCommandEventSender.sendSucceededEvent(LoggingCommandEventSender.java:151)
	at com.mongodb.internal.connection.InternalStreamConnection.lambda$sendCommandMessageAsync$9(InternalStreamConnection.java:628)
	at com.mongodb.internal.connection.InternalStreamConnection$MessageHeaderCallback$MessageCallback.onResult(InternalStreamConnection.java:941)
	at com.mongodb.internal.connection.InternalStreamConnection$MessageHeaderCallback$MessageCallback.onResult(InternalStreamConnection.java:904)
	at com.mongodb.internal.connection.InternalStreamConnection$2.completed(InternalStreamConnection.java:738)
	at com.mongodb.internal.connection.InternalStreamConnection$2.completed(InternalStreamConnection.java:735)
	at com.mongodb.internal.connection.netty.NettyStream.readAsync(NettyStream.java:334)
	at com.mongodb.internal.connection.netty.NettyStream.readAsync(NettyStream.java:278)
	at com.mongodb.internal.connection.InternalStreamConnection.readAsync(InternalStreamConnection.java:735)
	at com.mongodb.internal.connection.InternalStreamConnection.access$500(InternalStreamConnection.java:103)
	at com.mongodb.internal.connection.InternalStreamConnection$MessageHeaderCallback.onResult(InternalStreamConnection.java:893)
	at com.mongodb.internal.connection.InternalStreamConnection$MessageHeaderCallback.onResult(InternalStreamConnection.java:875)
	at com.mongodb.internal.connection.InternalStreamConnection$2.completed(InternalStreamConnection.java:738)
	at com.mongodb.internal.connection.InternalStreamConnection$2.completed(InternalStreamConnection.java:735)
	at com.mongodb.internal.connection.netty.NettyStream.readAsync(NettyStream.java:334)
	at com.mongodb.internal.connection.netty.NettyStream.handleReadResponse(NettyStream.java:361)
	at com.mongodb.internal.connection.netty.NettyStream.access$900(NettyStream.java:115)
	at com.mongodb.internal.connection.netty.NettyStream$InboundBufferHandler.channelRead0(NettyStream.java:437)
	at com.mongodb.internal.connection.netty.NettyStream$InboundBufferHandler.channelRead0(NettyStream.java:434)
	at io.netty.channel.SimpleChannelInboundHandler.channelRead(SimpleChannelInboundHandler.java:99)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:444)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:420)
	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:412)
	at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1357)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:440)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:420)
	at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:868)
	at io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:166)
	at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:796)
	at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:732)
	at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:658)
	at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:562)
	at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:998)
	at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
	at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
	at java.base/java.lang.Thread.run(Thread.java:1583)

Metadata

Metadata

Assignees

Labels

type: regressionA regression from a previous release

Type

No type

Projects

No projects

Relationships

None yet

Development

No branches or pull requests

Issue actions