Vertx thread blocked in CircuitBreakerMetrics

[anoopgarlapati]

Questions

Getting vertx thread blocked in background CircuitBreakerMetrics operation. Potential deadlock issue.

Version

4.1.8

Context

We have a blue green deployment of Vertx microservices. In one of the microservices' blue environment which is not serving any application traffic at the time of incident, we observed CPU utilization spike up to 100% due to thread blocked issues. As resolving the incident and restoring health of the service was priority, our Incident Management team immediately replaced the affected node and did not perform a thread dump.
The following is the stack trace of the error:

Thread Thread[vert.x-eventloop-thread-1,5,main] has been blocked for 733703 ms, time limit is 2000 ms io.vertx.core.VertxException: Thread blocked
	at org.HdrHistogram.AbstractHistogram.getBucketsNeededToCoverValue(AbstractHistogram.java:2212)
	at org.HdrHistogram.AbstractHistogram.determineArrayLengthNeeded(AbstractHistogram.java:374)
	at org.HdrHistogram.AbstractHistogram.establishSize(AbstractHistogram.java:361)
	at org.HdrHistogram.AbstractHistogram.init(AbstractHistogram.java:333)
	at org.HdrHistogram.AbstractHistogram.<init>(AbstractHistogram.java:273)
	at org.HdrHistogram.Histogram.<init>(Histogram.java:228)
	at org.HdrHistogram.Histogram.<init>(Histogram.java:206)
	at org.HdrHistogram.Histogram.<init>(Histogram.java:170)
	at io.vertx.circuitbreaker.impl.CircuitBreakerMetrics$RollingWindow$Summary.<init>(CircuitBreakerMetrics.java:311)
	at io.vertx.circuitbreaker.impl.CircuitBreakerMetrics$RollingWindow$Summary.<init>(CircuitBreakerMetrics.java:293)
	at io.vertx.circuitbreaker.impl.CircuitBreakerMetrics$RollingWindow.windowSummary(CircuitBreakerMetrics.java:245)
	at io.vertx.circuitbreaker.impl.CircuitBreakerMetrics$RollingWindow.totalSummary(CircuitBreakerMetrics.java:239)
	at io.vertx.circuitbreaker.impl.CircuitBreakerMetrics.toJson(CircuitBreakerMetrics.java:128)
	at io.vertx.circuitbreaker.impl.CircuitBreakerImpl.sendUpdateOnEventBus(CircuitBreakerImpl.java:160)
	at io.vertx.circuitbreaker.impl.CircuitBreakerImpl.lambda$new$2(CircuitBreakerImpl.java:83)
	at io.vertx.circuitbreaker.impl.CircuitBreakerImpl$$Lambda$672/0x00000001006e2440.handle(Unknown Source)
	at io.vertx.core.impl.VertxImpl$InternalTimerHandler.handle(VertxImpl.java:948)
	at io.vertx.core.impl.VertxImpl$InternalTimerHandler.handle(VertxImpl.java:919)
	at io.vertx.core.impl.EventLoopContext.emit(EventLoopContext.java:50)
	at io.vertx.core.impl.ContextImpl.emit(ContextImpl.java:274)
	at io.vertx.core.impl.EventLoopContext.emit(EventLoopContext.java:22)
	at io.vertx.core.impl.AbstractContext.emit(AbstractContext.java:53)
	at io.vertx.core.impl.EventLoopContext.emit(EventLoopContext.java:22)
	at io.vertx.core.impl.VertxImpl$InternalTimerHandler.run(VertxImpl.java:942)
	at io.netty.util.concurrent.PromiseTask.runTask(PromiseTask.java:98)
	at io.netty.util.concurrent.ScheduledFutureTask.run(ScheduledFutureTask.java:176)
	at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:164)
	at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:469)
	at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:503)
	at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:986)
	at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
	at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
	at java.base@11.0.14.1/java.lang.Thread.run(Unknown Source) 

[vietj]

it might be a bug in HDR histogram ?

[tsegismont]

Can you check which version of HDR Histogram you are using?

I found an issue related to getBucketsNeededToCoverValue : Infinite loop due to integer overflow

But it's fixed in the version that vertx-circuit-breaker depends on:

vertx-circuit-breaker/pom.xml

Lines 57 to 62 in d408034

	<dependency>
	<!-- for metrics -->
	<groupId>org.hdrhistogram</groupId>
	<artifactId>HdrHistogram</artifactId>
	<version>2.1.10</version>
	</dependency>

[anoopgarlapati]

@tsegismont We are using 2.1.10 for vertx-circuit-breaker in our application.
Here is snippet of output from maven dependency tree command:

+- io.vertx:vertx-circuit-breaker:jar:4.1.8:compile
|  \- org.hdrhistogram:HdrHistogram:jar:2.1.10:compile

I just went through some of the commits in releases 2.1.11 and 2.1.12 of HDR Histogram after your comment and there seem to be some overflow issues solved in these two releases which could prevent infinite loop scenarios.
We will do transitive dependency override for HDR Histogram in our application and monitor if the issue occurs again.
However it would be good if vertx updates to the latest version as well.

[tsegismont]

@anoopgarlapati thanks for the updates. I'll go ahead and upgrade to 2.1.12 in master and 4.2 branches

[tsegismont]

Closed in e23e30b