Http2ClientConnection attempts to write to a null stream when write queued

[zekronium]

Version

4.5.9 and above (this part of the vertx code has not been changed for a while now so likely is in older versions too)

Context

Using the Http2Client (via WebClient), the createStream fails due to the connection being closed before stream is created, thus init(stream) is never called. In createStream the call to create the child stream Http2Stream stream = this.conn.handler.encoder().connection().local().createStream(id, false); fails with the connection being closed error.

vert.x/src/main/java/io/vertx/core/http/impl/Http2ClientConnection.java

Lines 588 to 602 in 00fa556

	try {
	createStream(request, headers);
	} catch (Http2Exception ex) {
	if (handler != null) {
	handler.handle(context.failedFuture(ex));
	}
	handleException(ex);
	return;
	}
	if (buf != null) {
	doWriteHeaders(headers, false, false, null);
	doWriteData(buf, e, handler);
	} else {
	doWriteHeaders(headers, e, true, handler);
	}

vert.x/src/main/java/io/vertx/core/http/impl/Http2ClientConnection.java

Lines 605 to 628 in 00fa556

	private void createStream(HttpRequestHead head, Http2Headers headers) throws Http2Exception {
	int id = this.conn.handler.encoder().connection().local().lastStreamCreated();
	if (id == 0) {
	id = 1;
	} else {
	id += 2;
	}
	head.id = id;
	head.remoteAddress = conn.remoteAddress();
	Http2Stream stream = this.conn.handler.encoder().connection().local().createStream(id, false);
	init(stream);
	if (conn.metrics != null) {
	metric = conn.metrics.requestBegin(headers.path().toString(), head);
	}
	VertxTracer tracer = context.tracer();
	if (tracer != null) {
	BiConsumer<String, String> headers_ = (key, val) -> new Http2HeadersAdaptor(headers).add(key, val);
	String operation = head.traceOperation;
	if (operation == null) {
	operation = headers.method().toString();
	}
	trace = tracer.sendRequest(context, SpanKind.RPC, conn.client.options().getTracingPolicy(), head, operation, headers_, HttpUtils.CLIENT_HTTP_REQUEST_TAG_EXTRACTOR);
	}
	}

where init stream is set to be used by the VertxHttp2Stream

  void init(Http2Stream stream) {
    synchronized (this) {
      this.stream = stream;
      this.writable = this.conn.handler.encoder().flowController().isWritable(stream);
    }
    stream.setProperty(conn.streamKey, this);
  }

At first glance, everything is ok, exception is handled, handler is called, yet while using virtual threads, which always causes writes to queue due to the non even-loop condition !eventLoop.inEventLoop(), the stream appears to try writing to a null stream.

  void writeData(Http2Stream stream, ByteBuf chunk, boolean end, FutureListener<Void> listener) {
    ChannelPromise promise = listener == null ? chctx.voidPromise() : chctx.newPromise().addListener(listener);
    encoder().writeData(chctx, stream.id(), chunk, 0, end, promise); //stream is null here so stream.id() throws NPE
    Http2RemoteFlowController controller = encoder().flowController();
    if (!controller.isWritable(stream) || end) {
      try {
        encoder().flowController().writePendingBytes();
      } catch (Http2Exception e) {
        onError(chctx, true, e);
      }
    }
    checkFlush();
  }

[WARN]|AbstractEventExecutor| > A task raised an exception. Task: io.vertx.core.http.impl.VertxHttp2Stream$$Lambda/0x0000000800546148@771dbe57
java.lang.NullPointerException: Cannot invoke "io.netty.handler.codec.http2.Http2Stream.id()" because "stream" is null
	at io.vertx.core.http.impl.VertxHttp2ConnectionHandler.writeData(VertxHttp2ConnectionHandler.java:251) 
	at io.vertx.core.http.impl.VertxHttp2Stream.doWriteData(VertxHttp2Stream.java:252)
	at io.vertx.core.http.impl.Http2ClientConnection$Stream.doWriteData(Http2ClientConnection.java:297)
	at io.vertx.core.http.impl.VertxHttp2Stream.lambda$writeData$7(VertxHttp2Stream.java:217)
	at io.vertx.core.http.impl.VertxHttp2Stream.lambda$queueForWrite$8(VertxHttp2Stream.java:234) 
	at io.netty.util.concurrent.AbstractEventExecutor.runTask(AbstractEventExecutor.java:173) ~[netty-common-4.1.111.Final.jar:4.1.111.Final]
	at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:166) ~[netty-common-4.1.111.Final.jar:4.1.111.Final]
	at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:469) ~[netty-common-4.1.111.Final.jar:4.1.111.Final]
	at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:566) ~[netty-transport-4.1.111.Final.jar:4.1.111.Final]
	at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:994) ~[netty-common-4.1.111.Final.jar:4.1.111.Final]
	at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74) ~[netty-common-4.1.111.Final.jar:4.1.111.Final]
	at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) ~[netty-common-4.1.111.Final.jar:4.1.111.Final]
	at java.base/java.lang.Thread.run(Thread.java:1583) [?:?]

Do you have a reproducer?

Simulate connection closure while setting up the connection. Use virtual threads.

Extra

Windows Server, Temurin JDK 21.0.3

[moonkev]

I have run into the same. In my scnenario, I am making a streaming grpc client call.

java.lang.NullPointerException: Cannot invoke "io.netty.handler.codec.http2.Http2Stream.id()" because "stream" is null
	at io.vertx.core.http.impl.VertxHttp2ConnectionHandler.writeData(VertxHttp2ConnectionHandler.java:234)
	at io.vertx.core.http.impl.VertxHttp2Stream.doWriteData(VertxHttp2Stream.java:300)
	at io.vertx.core.http.impl.Http2ClientConnection$Stream.doWriteData(Http2ClientConnection.java:276)
	at io.vertx.core.http.impl.VertxHttp2Stream$4.write(VertxHttp2Stream.java:274)
	at io.vertx.core.http.impl.VertxHttp2Stream$2.test(VertxHttp2Stream.java:89)
	at io.vertx.core.http.impl.VertxHttp2Stream$2.test(VertxHttp2Stream.java:84)
	at io.vertx.core.streams.impl.OutboundWriteQueue.drainLoop(OutboundWriteQueue.java:308)
	at io.vertx.core.streams.impl.OutboundWriteQueue.drain(OutboundWriteQueue.java:274)
	at io.vertx.core.internal.concurrent.OutboundMessageQueue.drainWriteQueue(OutboundMessageQueue.java:154)
	at io.netty.util.concurrent.AbstractEventExecutor.runTask(AbstractEventExecutor.java:148)
	at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:141)
	at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:521)
	at io.netty.channel.SingleThreadIoEventLoop.run(SingleThreadIoEventLoop.java:160)
	at io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:1123)
	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(Thread.java:1583

A very important thing to note. My application is clusterered, and I hit this when I am using InfinispanClusterManager, however when I switch to ZookeeperClusterManager I do not see ever hit the error, although maybe this is just from some added latency between the two and this is just a circumstantial race condition.

I only see issues from client side of grpc communication. I never hit this error on the server side which is also a clustered vertx application, although possible that it is also just due to a race, as even on the client side it is intermittent (and the client side makes the call right away on verticle startup).

This is using vertx 5.0.0.CR4.

@zekronium were you able to find any workarounds?

[vietj]

it seems in both case write is done from a non event loop thread like a worker ?

[moonkev]

Hi @vietj My write is coming from a periodioc task, so should be the same thread as verticle correct?

Here is where I am hitting this in an example project

Note it seems today though I can only hit it using VIRTUAL_THREAD as my threading model, however I could have sworn I was also able to reproduce using EVENT_LOOP. Definitely a race condition somewhere though, as even with VIRTUAL_THREAD I can sometimes dodge the error.