ConcurrentModificationException when publishing metrics with StatsdMeterRegistry

[prasanna-palle]

Hello Team,

Recently upgraded micrometer jars to 1.5.3 and have been facing the ConcurrentModificationException. Came across thread : #2218 and upgraded to 1.5.4. Still facing the same issue.

Downgrading version is not an option because it then throws an other error :
i.m.s.i.n.util.ResourceLeakDetector - LEAK: ByteBuf.release() was not called before it's garbage-collected. See https://netty.io/wiki/reference-counted-objects.html for more information.
Recent access records:

Could you please help on how to go about this? We have updates pending to be rolled to production and application seems to be stopping on this error.

Micrometer : 1.5.3 / 1.5.4
Spring boot version : 2.3.2.RELEASE
Java : 1.8

java.util.ConcurrentModificationException: null at java.util.ArrayList$Itr.checkForComodification(ArrayList.java:911) ~[na:1.8.0_265] at java.util.ArrayList$Itr.next(ArrayList.java:861) ~[na:1.8.0_265] at io.micrometer.shaded.reactor.core.publisher.Operators.onDiscardMultiple(Operators.java:565) [micrometer-registry-statsd-1.5.4.jar!/:1.5.4] at io.micrometer.shaded.reactor.core.publisher.FluxBufferPredicate$BufferPredicateSubscriber.cancel(FluxBufferPredicate.java:174) [micrometer-registry-statsd-1.5.4.jar!/:1.5.4] at io.micrometer.shaded.reactor.core.publisher.FluxMap$MapSubscriber.cancel(FluxMap.java:160) [micrometer-registry-statsd-1.5.4.jar!/:1.5.4] at io.micrometer.shaded.reactor.core.publisher.FluxOnBackpressureLatest$LatestSubscriber.cancel(FluxOnBackpressureLatest.java:99) [micrometer-registry-statsd-1.5.4.jar!/:1.5.4] at io.micrometer.shaded.reactor.core.publisher.FluxMap$MapSubscriber.cancel(FluxMap.java:160) [micrometer-registry-statsd-1.5.4.jar!/:1.5.4] at io.micrometer.shaded.reactor.core.publisher.Operators.terminate(Operators.java:1222) [micrometer-registry-statsd-1.5.4.jar!/:1.5.4] at io.micrometer.shaded.reactor.netty.channel.MonoSendMany$SendManyInner.tryFailure(MonoSendMany.java:577) [micrometer-registry-statsd-1.5.4.jar!/:1.5.4] at io.micrometer.shaded.io.netty.util.internal.PromiseNotificationUtil.tryFailure(PromiseNotificationUtil.java:64) [micrometer-registry-statsd-1.5.4.jar!/:1.5.4] at io.micrometer.shaded.io.netty.channel.ChannelOutboundBuffer.safeFail(ChannelOutboundBuffer.java:723) [micrometer-registry-statsd-1.5.4.jar!/:1.5.4] at io.micrometer.shaded.io.netty.channel.ChannelOutboundBuffer.remove0(ChannelOutboundBuffer.java:308) [micrometer-registry-statsd-1.5.4.jar!/:1.5.4] at io.micrometer.shaded.io.netty.channel.ChannelOutboundBuffer.remove(ChannelOutboundBuffer.java:288) [micrometer-registry-statsd-1.5.4.jar!/:1.5.4] at io.micrometer.shaded.io.netty.channel.nio.AbstractNioMessageChannel.doWrite(AbstractNioMessageChannel.java:159) [micrometer-registry-statsd-1.5.4.jar!/:1.5.4] at io.micrometer.shaded.io.netty.channel.AbstractChannel$AbstractUnsafe.flush0(AbstractChannel.java:930) [micrometer-registry-statsd-1.5.4.jar!/:1.5.4] at io.micrometer.shaded.io.netty.channel.nio.AbstractNioChannel$AbstractNioUnsafe.flush0(AbstractNioChannel.java:354) [micrometer-registry-statsd-1.5.4.jar!/:1.5.4] at io.micrometer.shaded.io.netty.channel.AbstractChannel$AbstractUnsafe.flush(AbstractChannel.java:897) [micrometer-registry-statsd-1.5.4.jar!/:1.5.4] at io.micrometer.shaded.io.netty.channel.DefaultChannelPipeline$HeadContext.flush(DefaultChannelPipeline.java:1372) [micrometer-registry-statsd-1.5.4.jar!/:1.5.4] at io.micrometer.shaded.io.netty.channel.AbstractChannelHandlerContext.invokeFlush0(AbstractChannelHandlerContext.java:750) [micrometer-registry-statsd-1.5.4.jar!/:1.5.4] at io.micrometer.shaded.io.netty.channel.AbstractChannelHandlerContext.invokeFlush(AbstractChannelHandlerContext.java:742) [micrometer-registry-statsd-1.5.4.jar!/:1.5.4] at io.micrometer.shaded.io.netty.channel.AbstractChannelHandlerContext.flush(AbstractChannelHandlerContext.java:728) [micrometer-registry-statsd-1.5.4.jar!/:1.5.4] at io.micrometer.shaded.reactor.netty.channel.MonoSendMany$SendManyInner$AsyncFlush.run(MonoSendMany.java:758) [micrometer-registry-statsd-1.5.4.jar!/:1.5.4] at io.micrometer.shaded.io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:164) [micrometer-registry-statsd-1.5.4.jar!/:1.5.4] at io.micrometer.shaded.io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:472) [micrometer-registry-statsd-1.5.4.jar!/:1.5.4] at io.micrometer.shaded.io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:500) [micrometer-registry-statsd-1.5.4.jar!/:1.5.4] at io.micrometer.shaded.io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:989) [micrometer-registry-statsd-1.5.4.jar!/:1.5.4] at io.micrometer.shaded.io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74) [micrometer-registry-statsd-1.5.4.jar!/:1.5.4] at io.micrometer.shaded.io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) [micrometer-registry-statsd-1.5.4.jar!/:1.5.4] at java.lang.Thread.run(Thread.java:748) [na:1.8.0_265]

java.util.ConcurrentModifica

Thanks.

[gallaharsha]

We too see the issue after the upgrade. This is blocking us from upgrading to Spring boot 2.3 as well. Thanks.

[tlark]

Same here. Our environment:

• JDK 11 (OpenJDK 64-Bit Server VM AdoptOpenJDK (build 11.0.8+10, mixed mode))
• Spring Boot 2.3.3
• Micrometer 1.5.4 (same as bundled with Spring Boot 2.3.3)

[shakuzen]

We have updates pending to be rolled to production and application seems to be stopping on this error.

I would not expect this error to affect the application's main code. Are you saying this has an effect beyond the metrics not being published?

It would really help if we had a way to reliably reproduce the issue so we can find the root cause.

[shakuzen]

After consulting the Reactor team, they've pointed me at this recently fixed issue in reactor, which may fix the similar reported issue reactor/reactor-netty#1245. I've upgraded the 1.5.x branch to the latest reactor 3.3.x snapshots (5fe966b). Could those having the issue reported here try with the latest 1.5.5-SNAPSHOT version of Micrometer dependencies to see if the upgrade to reactor-core fixes this or not?

[prasanna-palle]

We have updates pending to be rolled to production and application seems to be stopping on this error.

I would not expect this error to affect the application's main code. Are you saying this has an effect beyond the metrics not being published?

It would really help if we had a way to reliably reproduce the issue so we can find the root cause.

Yeah, looks like it is not stopping the application. But logs are just filled with these errors and we have some alarms based on these metrics in prod, so cannot just roll out changes to prod until we fix it.

To give a more preview on the issue, we use kafka-streams which uses micrometer in turn for metric logging, etc., app has two separate spring-boot modules, running in separate docker containers. Micrometer is being used just in one module though.
Everything seemed to be working fine until we bumped up the Spring boot version to 2.3.2.RELEASE because of which had to bump up the other jars, including micrometer. And then started seeing the issue.

So I am trying to download the 1.5.5-SNAPSHOT using gradle. Is there any specific location to tap for these jars? The default locations for mvn repository doesn't seem to be working.

[prasanna-palle]

Found this : https://repo.spring.io/snapshot/io/micrometer/. Would let you know after testing. Thanks

[prasanna-palle]

Tried with 1.5.5-SNAPSHOT. Seeing the same error :

[ udp-nio-1] i.m.s.reactor.core.publisher.Operators : Error while discarding collection, stopping | 2020-08-20 15:48:45.658 WARN 1 --- [ udp-nio-1] i.m.s.reactor.core.publisher.Operators : Error while discarding collection, stopping

java.util.ConcurrentModificationException: null at java.util.ArrayList$Itr.checkForComodification(ArrayList.java:911) ~[na:1.8.0_265] at java.util.ArrayList$Itr.next(ArrayList.java:861) ~[na:1.8.0_265] at io.micrometer.shaded.reactor.core.publisher.Operators.onDiscardMultiple(Operators.java:565) [micrometer-registry-statsd-1.5.5-SNAPSHOT.jar!/:1.5.5-SNAPSHOT] at io.micrometer.shaded.reactor.core.publisher.FluxBufferPredicate$BufferPredicateSubscriber.cancel(FluxBufferPredicate.java:174) [micrometer-registry-statsd-1.5.5-SNAPSHOT.jar!/:1.5.5-SNAPSHOT] at io.micrometer.shaded.reactor.core.publisher.FluxMap$MapSubscriber.cancel(FluxMap.java:160) [micrometer-registry-statsd-1.5.5-SNAPSHOT.jar!/:1.5.5-SNAPSHOT] at io.micrometer.shaded.reactor.core.publisher.FluxOnBackpressureLatest$LatestSubscriber.cancel(FluxOnBackpressureLatest.java:99) [micrometer-registry-statsd-1.5.5-SNAPSHOT.jar!/:1.5.5-SNAPSHOT] at io.micrometer.shaded.reactor.core.publisher.FluxMap$MapSubscriber.cancel(FluxMap.java:160) [micrometer-registry-statsd-1.5.5-SNAPSHOT.jar!/:1.5.5-SNAPSHOT] at io.micrometer.shaded.reactor.core.publisher.Operators.terminate(Operators.java:1222) [micrometer-registry-statsd-1.5.5-SNAPSHOT.jar!/:1.5.5-SNAPSHOT] at io.micrometer.shaded.reactor.netty.channel.MonoSendMany$SendManyInner.tryFailure(MonoSendMany.java:577) [micrometer-registry-statsd-1.5.5-SNAPSHOT.jar!/:1.5.5-SNAPSHOT] at io.micrometer.shaded.io.netty.util.internal.PromiseNotificationUtil.tryFailure(PromiseNotificationUtil.java:64) [micrometer-registry-statsd-1.5.5-SNAPSHOT.jar!/:1.5.5-SNAPSHOT] at io.micrometer.shaded.io.netty.channel.ChannelOutboundBuffer.safeFail(ChannelOutboundBuffer.java:723) [micrometer-registry-statsd-1.5.5-SNAPSHOT.jar!/:1.5.5-SNAPSHOT] at io.micrometer.shaded.io.netty.channel.ChannelOutboundBuffer.remove0(ChannelOutboundBuffer.java:308) [micrometer-registry-statsd-1.5.5-SNAPSHOT.jar!/:1.5.5-SNAPSHOT] at io.micrometer.shaded.io.netty.channel.ChannelOutboundBuffer.remove(ChannelOutboundBuffer.java:288) [micrometer-registry-statsd-1.5.5-SNAPSHOT.jar!/:1.5.5-SNAPSHOT] at io.micrometer.shaded.io.netty.channel.nio.AbstractNioMessageChannel.doWrite(AbstractNioMessageChannel.java:159) [micrometer-registry-statsd-1.5.5-SNAPSHOT.jar!/:1.5.5-SNAPSHOT] at io.micrometer.shaded.io.netty.channel.AbstractChannel$AbstractUnsafe.flush0(AbstractChannel.java:930) [micrometer-registry-statsd-1.5.5-SNAPSHOT.jar!/:1.5.5-SNAPSHOT] at io.micrometer.shaded.io.netty.channel.nio.AbstractNioChannel$AbstractNioUnsafe.flush0(AbstractNioChannel.java:354) [micrometer-registry-statsd-1.5.5-SNAPSHOT.jar!/:1.5.5-SNAPSHOT] at io.micrometer.shaded.io.netty.channel.AbstractChannel$AbstractUnsafe.flush(AbstractChannel.java:897) [micrometer-registry-statsd-1.5.5-SNAPSHOT.jar!/:1.5.5-SNAPSHOT] at io.micrometer.shaded.io.netty.channel.DefaultChannelPipeline$HeadContext.flush(DefaultChannelPipeline.java:1372) [micrometer-registry-statsd-1.5.5-SNAPSHOT.jar!/:1.5.5-SNAPSHOT] at io.micrometer.shaded.io.netty.channel.AbstractChannelHandlerContext.invokeFlush0(AbstractChannelHandlerContext.java:750) [micrometer-registry-statsd-1.5.5-SNAPSHOT.jar!/:1.5.5-SNAPSHOT] at io.micrometer.shaded.io.netty.channel.AbstractChannelHandlerContext.invokeFlush(AbstractChannelHandlerContext.java:742) [micrometer-registry-statsd-1.5.5-SNAPSHOT.jar!/:1.5.5-SNAPSHOT] at io.micrometer.shaded.io.netty.channel.AbstractChannelHandlerContext.flush(AbstractChannelHandlerContext.java:728) [micrometer-registry-statsd-1.5.5-SNAPSHOT.jar!/:1.5.5-SNAPSHOT] at io.micrometer.shaded.reactor.netty.channel.MonoSendMany$SendManyInner$AsyncFlush.run(MonoSendMany.java:758) [micrometer-registry-statsd-1.5.5-SNAPSHOT.jar!/:1.5.5-SNAPSHOT] at io.micrometer.shaded.io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:164) [micrometer-registry-statsd-1.5.5-SNAPSHOT.jar!/:1.5.5-SNAPSHOT] at io.micrometer.shaded.io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:472) [micrometer-registry-statsd-1.5.5-SNAPSHOT.jar!/:1.5.5-SNAPSHOT] at io.micrometer.shaded.io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:500) [micrometer-registry-statsd-1.5.5-SNAPSHOT.jar!/:1.5.5-SNAPSHOT] at io.micrometer.shaded.io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:989) [micrometer-registry-statsd-1.5.5-SNAPSHOT.jar!/:1.5.5-SNAPSHOT] at io.micrometer.shaded.io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74) [micrometer-registry-statsd-1.5.5-SNAPSHOT.jar!/:1.5.5-SNAPSHOT] at io.micrometer.shaded.io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) [micrometer-registry-statsd-1.5.5-SNAPSHOT.jar!/:1.5.5-SNAPSHOT] at java.lang.Thread.run(Thread.java:748) [na:1.8.0_265] | java.util.ConcurrentModification

[shakuzen]

@prasanna-palle thank you for testing the snapshot version. Any clues on how to reproduce it? Are you able to make and share a minimal sample application that has the exception so we can better investigate? Are you using the KafkaStreamsMetrics with your kafka-streams? I'm suspecting that may be related.

[prasanna-palle]

Actually no. We are using MeterRegistry to count number of messages flowing in, for example.

To give a gist, we are passing the MeterRegistry bean to our Stream function.
We are initializing counters as :
messageCounter = meterRegistry.counter("some name for counter")
For each message streamed, we are incrementing counter.

Eg :

StreamsBuilder.stream(inputTopic)
.peek(key, value) -> {
messageCounter.increment();
}
. //do other message processing

So we are not using KafkaStreamsMetrics. And MeterRegistry seems to be isolated from streams too.
But this piece of code is like really at the top of streams logic, so I do not see the app getting past this point and continue after it errors out on concurrentException.
Kafka streams does have a threads parameter (StreamsConfig.NUM_STREAM_THREADS_CONFIG) which configured at 10 for our app.

[prasanna-palle]

@gallaharsha @tlark Could you please give a gist of your application use of meterRegistry too, to rule out any relation to other libraries.

[tlark]

@prasanna-palle We are referencing a MeterRegistry Spring bean within a Spring @EventListener. These events are originally from Kafka. Something like this:

@Slf4j
@Component
public class SyncMetrics {
    private final MeterRegistry meterRegistry;

    @Autowired
    public SyncMetrics(MeterRegistry meterRegistry) {
        this.meterRegistry = meterRegistry;
    }

    @EventListener
    public void handleSyncEvent(SyncEvent event) {
        meterRegistry.counter("sync.event", buildTags(event.getContext())).increment();
    }

    List<Tag> buildTags(Context context) {
        return Arrays.asList(
                Tag.of("accountId", context.getAccountId()),
                Tag.of("typeId", context.getTypeId()),
                Tag.of("Id", context.getId()));
    }
}

[shakuzen]

If someone can provide a minimal sample project with steps to reproduce, it would be helpful in getting this resolved.

[internetstaff]

We also began experiencing this same warning being logged continually on Micrometer 1.5.4, Spring Boot 2.3.3, Java 11, statsd plugin. It seems to be related to the crashing of our Datadog agent sidecar container.

[tommyk-gears]

@shakuzen I tried to reproduce this with a test case. I ended up with this; https://github.com/tommyk-gears/micrometer-2238. There is only a single test case, based on io.micrometer.statsd.StatsdMeterRegistryPublishTest from micrometer source. It is not even a proper test case since it just runs for 1 minute and logs whatever happens, but the test does not fail even if the error is reproduced. When I run the test on my machine I reproduce the error pretty much instantly and then ~90 times within a minute.

Using my code I could only reproduce it with buffering enabled, which makes sense since the root cause seems to be metrics being pushed to the buffer when the buffer is being disposed. The test case can currently only reproduce the error on UDP since it uses an overly large maxPacketLength to trigger an IOException.

Hope this can help shed some light on the issue.