NullPointerException in io.micrometer.common.KeyValues

[dietzsch]

Hello,

we have a set of Java Spring Boot applications, that we updated today to version 3.0.7. For monitoring the applications we have added dependency "io.micrometer:micrometer-registry-prometheus" to get the additional prometheus actuator. For all the Spring Boot apps that are running on the Webflux stack - use Netty - we see from time to time the following error in the logs:

2023-05-19 13:03:32 ERROR org.springframework.web.server.adapter.HttpWebHandlerAdapter [2cbc5a29-377] Error [java.lang.NullPointerException: Cannot invoke "java.lang.Comparable.compareTo(Object)" because "[]" is null] for HTTP GET "/actuator/prometheus", but ServerHttpResponse already committed (200 OK)
2023-05-19 13:03:32 ERROR reactor.core.publisher.Operators Operator called default onErrorDropped
java.lang.NullPointerException: Cannot invoke "java.lang.Comparable.compareTo(Object)" because "[]" is null
at java.base/java.util.ComparableTimSort.countRunAndMakeAscending(Unknown Source)
Suppressed: reactor.core.publisher.FluxOnAssembly$OnAssemblyException:
Error has been observed at the following site(s):
*__checkpoint ⇢ AuthorizationWebFilter [DefaultWebFilterChain]
*__checkpoint ⇢ ExceptionTranslationWebFilter [DefaultWebFilterChain]
*__checkpoint ⇢ LogoutWebFilter [DefaultWebFilterChain]
*__checkpoint ⇢ ServerRequestCacheWebFilter [DefaultWebFilterChain]
*__checkpoint ⇢ SecurityContextServerWebExchangeWebFilter [DefaultWebFilterChain]
*__checkpoint ⇢ AuthenticationWebFilter [DefaultWebFilterChain]
*__checkpoint ⇢ ReactorContextWebFilter [DefaultWebFilterChain]
*__checkpoint ⇢ HttpHeaderWriterWebFilter [DefaultWebFilterChain]
Original Stack Trace:
at java.base/java.util.ComparableTimSort.countRunAndMakeAscending(Unknown Source)
at java.base/java.util.ComparableTimSort.sort(Unknown Source)
at java.base/java.util.Arrays.sort(Unknown Source)
at io.micrometer.common.KeyValues.(KeyValues.java:47)
at io.micrometer.common.KeyValues.of(KeyValues.java:267)
at io.micrometer.observation.Observation$Context.getLowCardinalityKeyValues(Observation.java:1094)
at io.micrometer.core.instrument.observation.DefaultMeterObservationHandler.createTags(DefaultMeterObservationHandler.java:87)
at io.micrometer.core.instrument.observation.DefaultMeterObservationHandler.onStart(DefaultMeterObservationHandler.java:52)
at io.micrometer.observation.ObservationHandler$FirstMatchingCompositeObservationHandler.onStart(ObservationHandler.java:149)
at io.micrometer.observation.SimpleObservation.notifyOnObservationStarted(SimpleObservation.java:232)
at io.micrometer.observation.SimpleObservation.start(SimpleObservation.java:167)
at org.springframework.security.web.server.ObservationWebFilterChainDecorator$AroundWebFilterObservation$SimpleAroundWebFilterObservation$ObservationReference.stop(ObservationWebFilterChainDecorator.java:407)
at org.springframework.security.web.server.ObservationWebFilterChainDecorator$AroundWebFilterObservation$SimpleAroundWebFilterObservation.stop(ObservationWebFilterChainDecorator.java:290)

I have create a sample project and opened already issue 3849 with Micrometer. In this issue it was recommended to create a further issue with Spring Security for further analysis.

best regards,
Alex

[jzheaux]

@dietzsch, recently a concurrency issue was found in ObservationWebFilterChainDecorator. Can you please try 6.0.4-SNAPSHOT and tell me if that addresses the issue?

[dietzsch]

will try to test the snapshot version. Thank you for your quick feedback.

[spring-projects-issues]

If you would like us to look at this issue, please provide the requested information. If the information is not provided within the next 7 days this issue will be closed.

[dietzsch]

sorry for the delay, was busy with other topics this week, so that I had no time yet, but will test the new snapshot version.

[dietzsch]

I have updated one of the apps to the new Spring Security Core 6.0.4-SNAPSHOT version and deployed it. I will run it for the next days to see if we see the NPE again.

[dietzsch]

short update, the new version of the app is running since two days and we haven't seen the exception since then in the logs. So far it seems that the issue was fixed. Will continue running the app and update the ticket later this week.

[dietzsch]

After nearly one week the app has logged for the first time again the exception:

2023-06-10 01:55:06 ERROR reactor.core.publisher.Operators Operator called default onErrorDropped
java.lang.IllegalArgumentException: Context does not have an entry for key [class io.micrometer.core.instrument.Timer$Sample]
at io.micrometer.observation.Observation$Context.getRequired(Observation.java:946)
at io.micrometer.core.instrument.observation.DefaultMeterObservationHandler.onStop(DefaultMeterObservationHandler.java:65)
at io.micrometer.observation.ObservationHandler$FirstMatchingCompositeObservationHandler.onStop(ObservationHandler.java:197)
at io.micrometer.observation.SimpleObservation.lambda$notifyOnObservationStopped$0(SimpleObservation.java:286)
at java.base/java.util.ArrayDeque$DescendingIterator.forEachRemaining(Unknown Source)
at io.micrometer.observation.SimpleObservation.notifyOnObservationStopped(SimpleObservation.java:286)
at io.micrometer.observation.SimpleObservation.stop(SimpleObservation.java:194)
at org.springframework.security.web.server.ObservationWebFilterChainDecorator$AroundWebFilterObservation$SimpleAroundWebFilterObservation$ObservationReference.stop(ObservationWebFilterChainDecorator.java:407)
at org.springframework.security.web.server.ObservationWebFilterChainDecorator$AroundWebFilterObservation$SimpleAroundWebFilterObservation.stop(ObservationWebFilterChainDecorator.java:290)
at reactor.core.publisher.FluxPeekFuseable$PeekFuseableConditionalSubscriber.cancel(FluxPeekFuseable.java:445)
at reactor.core.publisher.MonoPeekTerminal$MonoTerminalPeekSubscriber.cancel(MonoPeekTerminal.java:144)
at reactor.core.publisher.FluxContextWrite$ContextWriteSubscriber.cancel(FluxContextWrite.java:141)
at reactor.core.publisher.FluxOnAssembly$OnAssemblySubscriber.cancel(FluxOnAssembly.java:654)
at reactor.core.publisher.MonoFlatMap$FlatMapMain.cancel(MonoFlatMap.java:207)
at reactor.core.publisher.FluxOnAssembly$OnAssemblySubscriber.cancel(FluxOnAssembly.java:654)
at reactor.core.publisher.MonoFlatMap$FlatMapMain.cancel(MonoFlatMap.java:207)
at reactor.core.publisher.FluxOnAssembly$OnAssemblySubscriber.cancel(FluxOnAssembly.java:654)
at reactor.core.publisher.FluxDoOnEach$DoOnEachSubscriber.cancel(FluxDoOnEach.java:113)
at reactor.core.publisher.FluxPeekFuseable$PeekConditionalSubscriber.cancel(FluxPeekFuseable.java:798)
at reactor.core.publisher.FluxContextWrite$ContextWriteSubscriber.cancel(FluxContextWrite.java:141)
at reactor.core.publisher.FluxOnAssembly$OnAssemblySubscriber.cancel(FluxOnAssembly.java:654)
at reactor.core.publisher.Operators$MultiSubscriptionSubscriber.drainLoop(Operators.java:2399)
at reactor.core.publisher.Operators$MultiSubscriptionSubscriber.drain(Operators.java:2367)
at reactor.core.publisher.Operators$MultiSubscriptionSubscriber.cancel(Operators.java:2179)
at reactor.core.publisher.Operators$MultiSubscriptionSubscriber.drainLoop(Operators.java:2399)
at reactor.core.publisher.Operators$MultiSubscriptionSubscriber.drain(Operators.java:2367)
at reactor.core.publisher.Operators$MultiSubscriptionSubscriber.cancel(Operators.java:2179)
at reactor.core.publisher.Operators$MultiSubscriptionSubscriber.drainLoop(Operators.java:2399)
at reactor.core.publisher.Operators$MultiSubscriptionSubscriber.drain(Operators.java:2367)
at reactor.core.publisher.Operators$MultiSubscriptionSubscriber.cancel(Operators.java:2179)
at reactor.core.publisher.MonoPeekTerminal$MonoTerminalPeekSubscriber.cancel(MonoPeekTerminal.java:144)
at reactor.core.publisher.Operators$MultiSubscriptionSubscriber.drainLoop(Operators.java:2399)
at reactor.core.publisher.Operators$MultiSubscriptionSubscriber.drain(Operators.java:2367)
at reactor.core.publisher.Operators$MultiSubscriptionSubscriber.cancel(Operators.java:2179)
at reactor.core.publisher.MonoIgnoreThen$ThenIgnoreMain.cancel(MonoIgnoreThen.java:143)
at reactor.core.publisher.MonoPeekTerminal$MonoTerminalPeekSubscriber.cancel(MonoPeekTerminal.java:144)
at reactor.core.publisher.MonoPeekTerminal$MonoTerminalPeekSubscriber.cancel(MonoPeekTerminal.java:144)
at reactor.core.publisher.Operators.terminate(Operators.java:1277)
at reactor.netty.channel.ChannelOperations.terminate(ChannelOperations.java:481)
at io.netty.util.concurrent.AbstractEventExecutor.runTask(AbstractEventExecutor.java:174)
at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:167)
at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:470)
at io.netty.channel.epoll.EpollEventLoop.run(EpollEventLoop.java:403)
at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:997)
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(Unknown Source)

[shakuzen]

That looks like a different exception, right? Perhaps there is a different issue.

[jonatan-ivanov]

To me this seems like a different issue too, probably this: micrometer-metrics/micrometer#3792

[dietzsch]

Hi @jonatan-ivanov, yes its different then original. Regarding micrometer-metrics/micrometer/issues/3792 , that one was fixed with #13133 and is included in the snapshot of Spring Security, with which I have tested.

[Abkallel]

Hello,

I still have the same error described at the began even I am using :

• Spring Boot 3.0.8
• Spring security 6.0.4
• micrometer 1.10.8
  java.lang.NullPointerException: Cannot invoke "java.lang.Comparable.compareTo(Object)" because "a[runHi]" is null at java.base/java.util.ComparableTimSort.countRunAndMakeAscending(ComparableTimSort.java:325) at java.base/java.util.ComparableTimSort.sort(ComparableTimSort.java:188) at java.base/java.util.Arrays.sort(Arrays.java:1041) at io.micrometer.common.KeyValues.<init>(KeyValues.java:47) at io.micrometer.common.KeyValues.of(KeyValues.java:268) at io.micrometer.observation.Observation$Context.getLowCardinalityKeyValues(Observation.java:1106)