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
Comment From: 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?
Comment From: dietzsch
will try to test the snapshot version. Thank you for your quick feedback.
Comment From: 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.
Comment From: 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.
Comment From: 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.
Comment From: 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.
Comment From: 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)
Comment From: shakuzen
That looks like a different exception, right? Perhaps there is a different issue.
Comment From: jonatan-ivanov
To me this seems like a different issue too, probably this: https://github.com/micrometer-metrics/micrometer/issues/3792
Comment From: dietzsch
Hi @jonatan-ivanov, yes its different then original. Regarding micrometer-metrics/micrometer/issues/3792 , that one was fixed with https://github.com/spring-projects/spring-security/issues/13133 and is included in the snapshot of Spring Security, with which I have tested.
Comment From: 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)