okhttp icon indicating copy to clipboard operation
okhttp copied to clipboard

Don't reset previously closed stream, since it's racy.

Open yschimke opened this issue 2 years ago • 2 comments

To address https://github.com/square/okhttp/issues/7913

We could look at the nextStreamId and cancel after an unexpected data frame. But arguably we should terminate the connection if we are getting unexpected frames.

yschimke avatar Jul 02 '23 12:07 yschimke

Http2ConnectionTest[jvm] > bogusDataFrameDoesNotDisruptConnection()[jvm] FAILED
    java.util.concurrent.TimeoutException: bogusDataFrameDoesNotDisruptConnection() timed out after 5 seconds
        at org.junit.jupiter.engine.extension.TimeoutExceptionFactory.create(TimeoutExceptionFactory.java:29)
        at org.junit.jupiter.engine.extension.SameThreadTimeoutInvocation.proceed(SameThreadTimeoutInvocation.java:58)

yschimke avatar Jul 02 '23 12:07 yschimke

@yschimke I worked to the same solution as you for this bug and have been using it for 2 months without any issues. Also, I dont think the connection should be terminated because the bug can occur in the following case as well. (okhttp-5.0.0-alpha.11.jar)

private static void enableHttp2FrameLogging() {
		Logger frameLogger = Logger.getLogger(Http2.class.getName());
		frameLogger.setLevel(Level.FINE);
		ConsoleHandler handler = new ConsoleHandler();
		handler.setLevel(Level.FINE);
		handler.setFormatter(new SimpleFormatter() {
			@Override public String format(LogRecord record) {
				return String.format("%s%n", record.getMessage());
			}
		});
		frameLogger.addHandler(handler);
	}

	public static void main(String[] args) throws IOException {
		enableHttp2FrameLogging();
                // Start this executor service to prevent java from exiting. 
		Executors.newSingleThreadScheduledExecutor().schedule(() -> System.out.println(), 2, TimeUnit.MINUTES);
		Request r= new Request.Builder()
				...
				.build();
		try(Response res = new OkHttpClient().newCall(r).execute()) {
			System.out.println(res.code());
			return;
		}
	}

I think the code returns the response object when the headers frame is received by okhttp. In the code above, try catch closes the response object, which closes the stream. Now in this instance, if a user is consuming the response body they aren't affected, since close will be called after the last (End_Stream flag) data frame is is received. However, if one just wants the response headers, like my code above, then there is a chance that the data frames arrive after close is called. This wouldn't really suggest any issue with the connection, since peer probably sent the frames before they received our RST_STREAM with cancel flag (Which is whats sent if we call close without consuming body).

The rfc says the following However, after sending the RST_STREAM, the sending endpoint MUST be prepared to receive and process additional frames sent on the stream that might have been sent by the peer prior to the arrival of the RST_STREAM https://www.rfc-editor.org/rfc/rfc9113.html#section-6.4-5

I think this change is perfect, I think chrome actually does something similar, where they dont send a RST_STREAM (Protocol_Error) for any data frames.


void SpdySession::OnStreamFrameData(spdy::SpdyStreamId stream_id,
                                    const char* data,
                                    size_t len) {
  CHECK(in_io_loop_);
  DCHECK_LT(len, 1u << 24);
  net_log_.AddEvent(NetLogEventType::HTTP2_SESSION_RECV_DATA, [&] {
    return NetLogSpdyDataParams(stream_id, len, false);
  });
  // Build the buffer as early as possible so that we go through the
  // session flow control checks and update
  // |unacked_recv_window_bytes_| properly even when the stream is
  // inactive (since the other side has still reduced its session send
  // window).
  std::unique_ptr<SpdyBuffer> buffer;
  if (data) {
    DCHECK_GT(len, 0u);
    CHECK_LE(len, static_cast<size_t>(kReadBufferSize));
    buffer = std::make_unique<SpdyBuffer>(data, len);
    DecreaseRecvWindowSize(static_cast<int32_t>(len));
    buffer->AddConsumeCallback(base::BindRepeating(
        &SpdySession::OnReadBufferConsumed, weak_factory_.GetWeakPtr()));
  } else {
    DCHECK_EQ(len, 0u);
  }
  auto it = active_streams_.find(stream_id);
  // By the time data comes in, the stream may already be inactive.
  if (it == active_streams_.end())
    return;
  SpdyStream* stream = it->second;
  CHECK_EQ(stream->stream_id(), stream_id);
  stream->AddRawReceivedBytes(len);
  stream->OnDataReceived(std::move(buffer));
}

https://source.chromium.org/chromium/chromium/src/+/main:net/spdy/spdy_session.cc;l=2836

Another thing that should be looked into is maybe moving the code in this pr to the reset stream function for Http2.Writer, as there might be other cases where we send reset stream errors for streams we have already closed.

unlucku avatar Oct 12 '23 07:10 unlucku