Micrometer: Lots of 'ConcurrentModificationException: null' since upgrading to 1.5.3

Created on 31 Jul 2020 · 8Comments · Source: micrometer-metrics/micrometer

Since upgrading micrometer to 1.5.3, we're seeing load of these exceptions in our logs with warning message Error while discarding collection, stopping.
This has already been mentioned in
https://github.com/micrometer-metrics/micrometer/issues/2140#issuecomment-663004911 but figured I'd create a separate ticket for it.

Environment:

Java 11
Spring Boot 2.3
Micrometer 1.5.3
Using statsd

java.util.ConcurrentModificationException: null
    at java.base/java.util.ArrayList$Itr.checkForComodification(ArrayList.java:1042)
    at java.base/java.util.ArrayList$Itr.next(ArrayList.java:996)
    at io.micrometer.shaded.reactor.core.publisher.Operators.onDiscardMultiple(Operators.java:565)
    at io.micrometer.shaded.reactor.core.publisher.FluxBufferPredicate$BufferPredicateSubscriber.cancel(FluxBufferPredicate.java:174)
    at io.micrometer.shaded.reactor.core.publisher.FluxMap$MapSubscriber.cancel(FluxMap.java:160)
    at io.micrometer.shaded.reactor.core.publisher.FluxOnBackpressureLatest$LatestSubscriber.cancel(FluxOnBackpressureLatest.java:99)
    at io.micrometer.shaded.reactor.core.publisher.FluxMap$MapSubscriber.cancel(FluxMap.java:160)
    at io.micrometer.shaded.reactor.core.publisher.Operators.terminate(Operators.java:1222)
    at io.micrometer.shaded.reactor.netty.channel.MonoSendMany$SendManyInner.operationComplete(MonoSendMany.java:264)
    at io.micrometer.shaded.reactor.netty.channel.MonoSendMany$SendManyInner.operationComplete(MonoSendMany.java:114)
    at io.micrometer.shaded.io.netty.util.concurrent.DefaultPromise.notifyListener0(DefaultPromise.java:577)
    at io.micrometer.shaded.io.netty.util.concurrent.DefaultPromise.notifyListenersNow(DefaultPromise.java:551)
    at io.micrometer.shaded.io.netty.util.concurrent.DefaultPromise.notifyListeners(DefaultPromise.java:490)
    at io.micrometer.shaded.io.netty.util.concurrent.DefaultPromise.setValue0(DefaultPromise.java:615)
    at io.micrometer.shaded.io.netty.util.concurrent.DefaultPromise.setSuccess0(DefaultPromise.java:604)
    at io.micrometer.shaded.io.netty.util.concurrent.DefaultPromise.trySuccess(DefaultPromise.java:104)
    at io.micrometer.shaded.io.netty.channel.DefaultChannelPromise.trySuccess(DefaultChannelPromise.java:84)
    at io.micrometer.shaded.io.netty.channel.AbstractChannel$CloseFuture.setClosed(AbstractChannel.java:1158)
    at io.micrometer.shaded.io.netty.channel.AbstractChannel$AbstractUnsafe.doClose0(AbstractChannel.java:760)
    at io.micrometer.shaded.io.netty.channel.AbstractChannel$AbstractUnsafe.close(AbstractChannel.java:736)
    at io.micrometer.shaded.io.netty.channel.AbstractChannel$AbstractUnsafe.close(AbstractChannel.java:607)
    at io.micrometer.shaded.io.netty.channel.DefaultChannelPipeline$HeadContext.close(DefaultChannelPipeline.java:1352)
    at io.micrometer.shaded.io.netty.channel.AbstractChannelHandlerContext.invokeClose(AbstractChannelHandlerContext.java:622)
    at io.micrometer.shaded.io.netty.channel.AbstractChannelHandlerContext.close(AbstractChannelHandlerContext.java:606)
    at io.micrometer.shaded.io.netty.channel.AbstractChannelHandlerContext.close(AbstractChannelHandlerContext.java:472)
    at io.micrometer.shaded.io.netty.channel.DefaultChannelPipeline.close(DefaultChannelPipeline.java:957)
    at io.micrometer.shaded.io.netty.channel.AbstractChannel.close(AbstractChannel.java:232)
    at io.micrometer.shaded.reactor.netty.DisposableChannel.dispose(DisposableChannel.java:76)
    at io.micrometer.shaded.reactor.netty.channel.ChannelOperations.dispose(ChannelOperations.java:168)
    at io.micrometer.shaded.reactor.core.Disposables.set(Disposables.java:421)
    at io.micrometer.shaded.reactor.core.Disposables$SwapDisposable.update(Disposables.java:317)
    at io.micrometer.statsd.StatsdMeterRegistry.lambda$retryReplaceClient$12(StatsdMeterRegistry.java:273)
    at io.micrometer.shaded.reactor.core.publisher.LambdaMonoSubscriber.onNext(LambdaMonoSubscriber.java:168)
    at io.micrometer.shaded.reactor.core.publisher.SerializedSubscriber.onNext(SerializedSubscriber.java:99)
    at io.micrometer.shaded.reactor.core.publisher.FluxRetryWhen$RetryWhenMainSubscriber.onNext(FluxRetryWhen.java:162)
    at io.micrometer.shaded.reactor.core.publisher.MonoCreate$DefaultMonoSink.success(MonoCreate.java:156)
    at io.micrometer.shaded.reactor.netty.resources.NewConnectionProvider$NewConnectionObserver.onStateChange(NewConnectionProvider.java:199)
    at io.micrometer.shaded.reactor.netty.channel.ChannelOperationsHandler.channelActive(ChannelOperationsHandler.java:65)
    at io.micrometer.shaded.io.netty.channel.AbstractChannelHandlerContext.invokeChannelActive(AbstractChannelHandlerContext.java:230)
    at io.micrometer.shaded.io.netty.channel.AbstractChannelHandlerContext.invokeChannelActive(AbstractChannelHandlerContext.java:216)
    at io.micrometer.shaded.io.netty.channel.AbstractChannelHandlerContext.fireChannelActive(AbstractChannelHandlerContext.java:209)
    at io.micrometer.shaded.io.netty.channel.DefaultChannelPipeline$HeadContext.channelActive(DefaultChannelPipeline.java:1398)
    at io.micrometer.shaded.io.netty.channel.AbstractChannelHandlerContext.invokeChannelActive(AbstractChannelHandlerContext.java:230)
    at io.micrometer.shaded.io.netty.channel.AbstractChannelHandlerContext.invokeChannelActive(AbstractChannelHandlerContext.java:216)
    at io.micrometer.shaded.io.netty.channel.DefaultChannelPipeline.fireChannelActive(DefaultChannelPipeline.java:895)
    at io.micrometer.shaded.io.netty.channel.nio.AbstractNioChannel$AbstractNioUnsafe.fulfillConnectPromise(AbstractNioChannel.java:305)
    at io.micrometer.shaded.io.netty.channel.nio.AbstractNioChannel$AbstractNioUnsafe.connect(AbstractNioChannel.java:249)
    at io.micrometer.shaded.io.netty.channel.DefaultChannelPipeline$HeadContext.connect(DefaultChannelPipeline.java:1342)
    at io.micrometer.shaded.io.netty.channel.AbstractChannelHandlerContext.invokeConnect(AbstractChannelHandlerContext.java:548)
    at io.micrometer.shaded.io.netty.channel.AbstractChannelHandlerContext.connect(AbstractChannelHandlerContext.java:533)
    at io.micrometer.shaded.io.netty.channel.AbstractChannelHandlerContext.connect(AbstractChannelHandlerContext.java:517)
    at io.micrometer.shaded.io.netty.channel.DefaultChannelPipeline.connect(DefaultChannelPipeline.java:978)
    at io.micrometer.shaded.io.netty.channel.AbstractChannel.connect(AbstractChannel.java:253)
    at io.micrometer.shaded.io.netty.bootstrap.Bootstrap$3.run(Bootstrap.java:250)
    at io.micrometer.shaded.io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:164)
    at io.micrometer.shaded.io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:472)
    at io.micrometer.shaded.io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:500)
    at io.micrometer.shaded.io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:989)
    at io.micrometer.shaded.io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
    at io.micrometer.shaded.io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
    at java.base/java.lang.Thread.run(Thread.java:834)

statsd

Source

sguillope

👍6 👀4

Most helpful comment

I can confirm we don’t see that error anymore after bumping to 1.5.4. Thank you!

kdamevin on 14 Aug 2020

🎉3

All 8 comments

I've seen the same behaviour in our scenario.
Even worse it seems that it runs into an endless loop afterwards consuming a lot of cpu time and stop reporting any metric values.

Except from stack trace:
java.lang.Thread.State: RUNNABLE at java.lang.Object.hashCode(Native Method) at java.util.HashMap.hash(HashMap.java:339) at java.util.HashMap.put(HashMap.java:612) at java.util.HashSet.add(HashSet.java:220) at sun.nio.ch.EPollSelectorImpl.implRegister(EPollSelectorImpl.java:179) at sun.nio.ch.SelectorImpl.register(SelectorImpl.java:132) - locked <0x00000000b6316cf0> (a java.util.Collections$UnmodifiableSet) at java.nio.channels.spi.AbstractSelectableChannel.register(AbstractSelectableChannel.java:219) - locked <0x0000000093399aa0> (a java.lang.Object) - locked <0x0000000093399ab0> (a java.lang.Object) at io.micrometer.shaded.io.netty.channel.nio.AbstractNioChannel.doRegister(AbstractNioChannel.java:380) at io.micrometer.shaded.io.netty.channel.AbstractChannel$AbstractUnsafe.register0(AbstractChannel.java:496) at io.micrometer.shaded.io.netty.channel.AbstractChannel$AbstractUnsafe.register(AbstractChannel.java:468) at io.micrometer.shaded.io.netty.channel.SingleThreadEventLoop.register(SingleThreadEventLoop.java:87) at io.micrometer.shaded.io.netty.channel.SingleThreadEventLoop.register(SingleThreadEventLoop.java:81) at io.micrometer.shaded.reactor.netty.resources.ColocatedEventLoopGroup.register(ColocatedEventLoopGroup.java:71) at io.micrometer.shaded.io.netty.bootstrap.AbstractBootstrap.initAndRegister(AbstractBootstrap.java:323) at io.micrometer.shaded.io.netty.bootstrap.Bootstrap.doResolveAndConnect(Bootstrap.java:155) at io.micrometer.shaded.io.netty.bootstrap.Bootstrap.connect(Bootstrap.java:116) at io.micrometer.shaded.reactor.netty.resources.NewConnectionProvider.lambda$acquire$0(NewConnectionProvider.java:73) at io.micrometer.shaded.reactor.netty.resources.NewConnectionProvider$$Lambda$430/545707113.accept(Unknown Source) at io.micrometer.shaded.reactor.core.publisher.MonoCreate.subscribe(MonoCreate.java:57) at io.micrometer.shaded.reactor.core.publisher.MonoDefer.subscribe(MonoDefer.java:52) at io.micrometer.shaded.reactor.core.publisher.FluxRetryWhen.subscribe(FluxRetryWhen.java:79) at io.micrometer.shaded.reactor.core.publisher.MonoRetryWhen.subscribeOrReturn(MonoRetryWhen.java:46) at io.micrometer.shaded.reactor.core.publisher.Mono.subscribe(Mono.java:4198) at io.micrometer.shaded.reactor.core.publisher.Mono.subscribeWith(Mono.java:4324) at io.micrometer.shaded.reactor.core.publisher.Mono.subscribe(Mono.java:4184) at io.micrometer.shaded.reactor.core.publisher.Mono.subscribe(Mono.java:4120) at io.micrometer.shaded.reactor.core.publisher.Mono.subscribe(Mono.java:4067) at io.micrometer.statsd.StatsdMeterRegistry.retryReplaceClient(StatsdMeterRegistry.java:272) at io.micrometer.statsd.StatsdMeterRegistry.connectAndSubscribe(StatsdMeterRegistry.java:261) at io.micrometer.statsd.StatsdMeterRegistry.lambda$prepareUdpClient$7(StatsdMeterRegistry.java:233) at io.micrometer.statsd.StatsdMeterRegistry$$Lambda$402/1828787392.accept(Unknown Source) at io.micrometer.shaded.reactor.netty.udp.UdpClientDoOn.lambda$onStateChange$1(UdpClientDoOn.java:71) at io.micrometer.shaded.reactor.netty.udp.UdpClientDoOn$$Lambda$1607/1391024869.dispose(Unknown Source) at io.micrometer.shaded.reactor.netty.DisposableChannel$$Lambda$1609/245151462.run(Unknown Source) at io.micrometer.shaded.reactor.core.publisher.LambdaMonoSubscriber.onComplete(LambdaMonoSubscriber.java:132) at io.micrometer.shaded.reactor.core.publisher.Operators.complete(Operators.java:135) at io.micrometer.shaded.reactor.core.publisher.MonoEmpty.subscribe(MonoEmpty.java:45) at io.micrometer.shaded.reactor.core.publisher.Mono.subscribe(Mono.java:4213) at io.micrometer.shaded.reactor.core.publisher.Mono.subscribeWith(Mono.java:4324) at io.micrometer.shaded.reactor.core.publisher.Mono.subscribe(Mono.java:4184) at io.micrometer.shaded.reactor.core.publisher.Mono.subscribe(Mono.java:4120) at io.micrometer.shaded.reactor.netty.DisposableChannel.onDispose(DisposableChannel.java:134) at io.micrometer.shaded.reactor.netty.Connection.onDispose(Connection.java:268) at io.micrometer.shaded.reactor.netty.channel.ChannelOperations.onDispose(ChannelOperations.java:197) at io.micrometer.shaded.reactor.netty.udp.UdpClientDoOn.onStateChange(UdpClientDoOn.java:71) at io.micrometer.shaded.reactor.netty.ReactorNetty$CompositeConnectionObserver.onStateChange(ReactorNetty.java:514) at io.micrometer.shaded.reactor.netty.resources.NewConnectionProvider$NewConnectionObserver.onStateChange(NewConnectionProvider.java:207) at io.micrometer.shaded.reactor.netty.channel.ChannelOperations.terminate(ChannelOperations.java:432) at io.micrometer.shaded.reactor.netty.channel.ChannelOperations.onInboundClose(ChannelOperations.java:390) at io.micrometer.shaded.reactor.netty.channel.ChannelOperationsHandler.channelInactive(ChannelOperationsHandler.java:76) at io.micrometer.shaded.io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:262) at io.micrometer.shaded.io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:248) at io.micrometer.shaded.io.netty.channel.AbstractChannelHandlerContext.fireChannelInactive(AbstractChannelHandlerContext.java:241) at io.micrometer.shaded.io.netty.channel.DefaultChannelPipeline$HeadContext.channelInactive(DefaultChannelPipeline.java:1405) at io.micrometer.shaded.io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:262) at io.micrometer.shaded.io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:248) at io.micrometer.shaded.io.netty.channel.DefaultChannelPipeline.fireChannelInactive(DefaultChannelPipeline.java:901) at io.micrometer.shaded.io.netty.channel.AbstractChannel$AbstractUnsafe$8.run(AbstractChannel.java:818) at io.micrometer.shaded.io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:164) at io.micrometer.shaded.io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:472) at io.micrometer.shaded.io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:500) at io.micrometer.shaded.io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:989) at io.micrometer.shaded.io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74) at io.micrometer.shaded.io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) at java.lang.Thread.run(Thread.java:748)

garry-mcfly on 31 Jul 2020

We have been noticing the same issue and it seems highly related to some high memory usage/memory leaks on our side.

I am not entirely sure in which condition it happens but I compared two similar instances at the same time. One was using above 6gb of memory before It died and I could see this Error while discarding collection / ConcurrentModificationException error more than 20k times in the logs, another instance that seemed to behave ok was using about half the memory and this error didn't happen.

kdamevin on 4 Aug 2020

I see this when running a service in docker as well. it was functioning fine until https://github.com/micrometer-metrics/micrometer/issues/2140 showed up on 1.5.1, Upgrading to 1.5.3 started showing lot of cme's.
Is there a timeline when this will get fixed and in which version?
Java8
micrometer 1.5.3
using statsd
Spring 2.3.0.RELEASE

nikitwaghelasonos on 4 Aug 2020

The reproducer seems to be got lost inside of the other issue's conversation, so I'm pasting the link here again.

This was supposed to reproduce the memory leak, but I bet can reproduce this one too. Maybe just by updating the dependencies.

https://github.com/cicilthomas/micrometer

renannprado on 10 Aug 2020

Could anyone experiencing this issue try with the latest 1.5.4-SNAPSHOT version to see if the fix for #2177 causes this issue to also not happen anymore? I haven't been able to reproduce this issue on my machine so far.

shakuzen on 11 Aug 2020

For us this ConcurrentModificationException occurred together with #2177 (lot's of "Error while discarding collection" and then often no metrics where reported).
After using the 1.5.4-SNAPSHOT this message also no longer appears. See the other https://github.com/micrometer-metrics/micrometer/issues/2177#issuecomment-671793961
But it would be nice if we are not the only one telling that the bug seems to be fixed now.

garry-mcfly on 11 Aug 2020

👍1

I will close this with @garry-mcfly's report that it's no longer occurring. We are about to release 1.5.4. If users are still seeing this issue after upgrading, we can reopen this and investigate further.

shakuzen on 13 Aug 2020

👍1

I can confirm we don’t see that error anymore after bumping to 1.5.4. Thank you!

kdamevin on 14 Aug 2020

🎉3

Was this page helpful?

0 / 5 - 0 ratings