Version
5.1.2
Context
With RequestOptions#setConnectTimeout(...) set on HTTP/2 requests, the client logs bursts of unhandled java.lang.IllegalStateException: Promise already completed from SharedHttpClientConnectionGroup. The requests themselves all succeed — the exception is a late, orphaned second completion of the pool acquisition promise, so it's harmless but inflates error rates and is alarming in logs.
Root cause
An HTTP/2 client keeps a single pooled connection (http2MaxPoolSize defaults to 1), so concurrent requests queue as pool waiters while that connection is being established. setConnectTimeout arms a per-waiter wait-queue expiry timer in SharedHttpClientConnectionGroup$Request#onConnect.
When the connection comes up, SimpleConnectionPool$ConnectSuccess#execute serves the whole batch off the one connection. The primary waiter is marked waiter.disposed = true, but the extra waiters polled from the queue are not:
for (int i = 0; i < m; i++) {
leases[i] = new LeaseImpl<>(slot, pool.waiters.poll().handler); // disposed never set
}(SimpleConnectionPool$SetConcurrency#execute has the same loop.)
Later, the expiry timer fires for one of those extra waiters and calls SimpleConnectionPool#cancel. Because waiter.disposed was never set, Cancel#execute reports cancelled = true:
if (pool.waiters.remove(waiter)) { cancelled = true; waiter.disposed = true; }
else if (!waiter.disposed) { waiter.disposed = true; cancelled = true; } // <-- taken
else { cancelled = false; }so the timer callback calls promise.fail(...) on the acquisition promise that already completed successfully → IllegalStateException: Promise already completed.
Suggested fix
Mark waiters disposed when they are served in the multi-lease loops of ConnectSuccess#execute and SetConcurrency#execute, or have Cancel#execute only report cancelled = true for waiters still actually present in the queue — so a connect-timeout timer that fires after its waiter was already served becomes a no-op instead of failing the completed promise.
Steps to reproduce
import io.vertx.core.Vertx;
import io.vertx.core.http.*;
import java.util.concurrent.CountDownLatch;
import java.util.concurrent.TimeUnit;
import java.util.concurrent.atomic.AtomicInteger;
public class Http2PoolConnectTimeoutDoubleComplete {
public static void main(String[] args) throws Exception {
Vertx vertx = Vertx.vertx();
HttpServer server = vertx.createHttpServer(new HttpServerOptions()) // h2c, answers immediately
.requestHandler(req -> req.response().end("ok"))
.listen(0, "localhost").toCompletionStage().toCompletableFuture().get();
int port = server.actualPort();
HttpClient client = vertx.createHttpClient(new HttpClientOptions() // single pooled h2 connection
.setProtocolVersion(HttpVersion.HTTP_2)
.setHttp2ClearTextUpgrade(false));
int n = 20, connectTimeoutMs = 500;
AtomicInteger ok = new AtomicInteger(), failed = new AtomicInteger();
CountDownLatch done = new CountDownLatch(n);
for (int i = 0; i < n; i++) { // fire before the connection is up
client.request(new RequestOptions()
.setMethod(HttpMethod.GET).setPort(port).setHost("localhost").setURI("/")
.setConnectTimeout(connectTimeoutMs)) // <-- arms the expiry timer
.compose(req -> req.send().compose(HttpClientResponse::body))
.onComplete(ar -> { (ar.succeeded() ? ok : failed).incrementAndGet(); done.countDown(); });
}
done.await(5, TimeUnit.SECONDS);
Thread.sleep(connectTimeoutMs + 1000); // let the now-pointless timers fire on the served waiters
System.out.printf("requests ok=%d failed=%d (note the ~%d 'Promise already completed' stack traces above)%n",
ok.get(), failed.get(), n - 1);
vertx.close();
}
}Expected
No exception. Every request succeeds, and the expiry timer for an already-served waiter should be a no-op.
Actual
All N requests succeed, but ~N-1 unhandled exceptions are logged (one per batch-served waiter; the primary waiter is fine):
with 19 stack traces like:
ERROR io.vertx.core.impl.ContextImpl - Unhandled exception
java.lang.IllegalStateException: Promise already completed
at io.vertx.core.Promise.fail(Promise.java:103)
at io.vertx.core.http.impl.SharedHttpClientConnectionGroup$Request.lambda$onConnect$0(SharedHttpClientConnectionGroup.java:125)
at io.vertx.core.Completable.succeed(Completable.java:31)
at io.vertx.core.internal.pool.SimpleConnectionPool$Cancel.run(SimpleConnectionPool.java:688)
at io.vertx.core.internal.pool.Task.runNextTasks(Task.java:43)
at io.vertx.core.internal.pool.CombinerExecutor.submit(CombinerExecutor.java:91)
at io.vertx.core.internal.pool.SimpleConnectionPool.execute(SimpleConnectionPool.java:242)
at io.vertx.core.internal.pool.SimpleConnectionPool.cancel(SimpleConnectionPool.java:650)
at io.vertx.core.http.impl.SharedHttpClientConnectionGroup$Request.lambda$onConnect$1(SharedHttpClientConnectionGroup.java:123)
at io.vertx.core.impl.VertxImpl$InternalTimerHandler.handle(VertxImpl.java:1066)
at io.vertx.core.impl.VertxImpl$InternalTimerHandler.handle(VertxImpl.java:1033)
at io.vertx.core.impl.ContextBase.emit(ContextBase.java:82)
at io.vertx.core.internal.ContextInternal.emit(ContextInternal.java:187)
at io.vertx.core.impl.VertxImpl$InternalTimerHandler.run(VertxImpl.java:1055)
...
Do you have a reproducer?
No response
Version
5.1.2
Context
With
RequestOptions#setConnectTimeout(...)set on HTTP/2 requests, the client logs bursts of unhandledjava.lang.IllegalStateException: Promise already completedfromSharedHttpClientConnectionGroup. The requests themselves all succeed — the exception is a late, orphaned second completion of the pool acquisition promise, so it's harmless but inflates error rates and is alarming in logs.Root cause
An HTTP/2 client keeps a single pooled connection (
http2MaxPoolSizedefaults to 1), so concurrent requests queue as pool waiters while that connection is being established.setConnectTimeoutarms a per-waiter wait-queue expiry timer inSharedHttpClientConnectionGroup$Request#onConnect.When the connection comes up,
SimpleConnectionPool$ConnectSuccess#executeserves the whole batch off the one connection. The primary waiter is markedwaiter.disposed = true, but the extra waiters polled from the queue are not:(
SimpleConnectionPool$SetConcurrency#executehas the same loop.)Later, the expiry timer fires for one of those extra waiters and calls
SimpleConnectionPool#cancel. Becausewaiter.disposedwas never set,Cancel#executereportscancelled = true:so the timer callback calls
promise.fail(...)on the acquisition promise that already completed successfully →IllegalStateException: Promise already completed.Suggested fix
Mark waiters
disposedwhen they are served in the multi-lease loops ofConnectSuccess#executeandSetConcurrency#execute, or haveCancel#executeonly reportcancelled = truefor waiters still actually present in the queue — so a connect-timeout timer that fires after its waiter was already served becomes a no-op instead of failing the completed promise.Steps to reproduce
Expected
No exception. Every request succeeds, and the expiry timer for an already-served waiter should be a no-op.
Actual
All N requests succeed, but ~N-1 unhandled exceptions are logged (one per batch-served waiter; the primary waiter is fine):
with 19 stack traces like:
Do you have a reproducer?
No response