How to resolve h2 protocol error: http2 error locally?

[milesj]

Hey all,

I'm attempting to connect to bazel-remote (which is running locally without https/tls) using tonic/prost (powered by bazel-remote-apis-rust, but I consistently hit a h2 protocol error: http2 error error when attempting to make requests.

The bazel-remote service is http 1.1 only, not http 2. Is it simply not compatible with tonic? Or is it because we're not using tls locally (which is a pain to setup)?

Any help is appreciated, as this error is very cryptic.

Here's some logs with more information (with dbg! calls) if that helps:

[TRACE 16:04:44.275] tonic::transport::channel::service::reconnect  poll_ready; connected
[TRACE 16:04:44.275] tonic::transport::channel::service::reconnect  poll_ready; error
[TRACE 16:04:44.275] tonic::transport::channel::service::reconnect  poll_ready; idle
[TRACE 16:04:44.275] tonic::transport::channel::service::reconnect  poll_ready; connecting
[TRACE 16:04:44.275] hyper_util::client::legacy::connect::http  Http::connect; scheme=Some("http"), host=Some("0.0.0.0"), port=Some(Port(8585))
[DEBUG 16:04:44.275] hyper_util::client::legacy::connect::http  connecting to 0.0.0.0:8585
[TRACE 16:04:44.275] tonic::transport::channel::service::reconnect  poll_ready; not ready
[TRACE 16:04:44.275] tonic::transport::channel::service::reconnect  poll_ready; connecting
[DEBUG 16:04:44.275] hyper_util::client::legacy::connect::http  connected to 0.0.0.0:8585
[DEBUG 16:04:44.275] h2::client  binding client connection
[DEBUG 16:04:44.275] h2::client  client connection bound
[DEBUG 16:04:44.275] h2::codec::framed_write  send  frame=Settings { flags: (0x0), enable_push: 0, initial_window_size: 2097152, max_frame_size: 16384, max_header_list_size: 16384 }
[TRACE 16:04:44.275] h2::frame::settings  encoding SETTINGS; len=24
[TRACE 16:04:44.275] h2::frame::settings  encoding setting; val=EnablePush(0)
[TRACE 16:04:44.275] h2::frame::settings  encoding setting; val=InitialWindowSize(2097152)
[TRACE 16:04:44.275] h2::frame::settings  encoding setting; val=MaxFrameSize(16384)
[TRACE 16:04:44.275] h2::frame::settings  encoding setting; val=MaxHeaderListSize(16384)
[TRACE 16:04:44.275] h2::codec::framed_write  encoded settings  rem=33
[TRACE 16:04:44.275] h2::proto::streams::flow_control  inc_window; sz=65535; old=0; new=65535
[TRACE 16:04:44.275] h2::proto::streams::flow_control  inc_window; sz=65535; old=0; new=65535
[TRACE 16:04:44.276] h2::proto::streams::prioritize  Prioritize::new; flow=FlowControl { window_size: Window(65535), available: Window(65535) }
[TRACE 16:04:44.276] h2::proto::streams::recv  set_target_connection_window; target=5242880; available=65535, reserved=0
[TRACE 16:04:44.276] tonic::transport::channel::service::reconnect  poll_ready; connected
[TRACE 16:04:44.276] tonic::transport::channel::service::reconnect  poll_ready; ready
[TRACE 16:04:44.276] tonic::transport::channel::service::reconnect  Reconnect::call
[TRACE 16:04:44.276] h2::proto::connection connection.state=Open
[TRACE 16:04:44.276] h2::codec::framed_read  poll
[TRACE 16:04:44.276] h2::proto::streams::flow_control  inc_window; sz=65535; old=0; new=65535
[DEBUG 16:04:44.276] h2::proto::connection  Connection::poll; connection error  error=GoAway(b"", FRAME_SIZE_ERROR, Library)
[TRACE 16:04:44.276] h2::proto::streams::flow_control  inc_window; sz=65535; old=0; new=65535
[TRACE 16:04:44.276] h2::proto::streams::send  send_headers; frame=Headers { stream_id: StreamId(1), flags: (0x4: END_HEADERS) }; init_window=65535
[TRACE 16:04:44.276] h2::proto::streams::store  Queue::push_back
[TRACE 16:04:44.276] h2::proto::streams::store   -> first entry
[TRACE 16:04:44.276] h2::proto::streams::prioritize requested=1 additional=1 buffered=0 window=65535 conn=65535
[TRACE 16:04:44.276] h2::proto::streams::prioritize  assigning  capacity=1
[TRACE 16:04:44.276] h2::proto::streams::stream    assigned capacity to stream; available=1; buffered=0; id=StreamId(1); max_buffer_size=1048576 prev=0
[TRACE 16:04:44.276] h2::proto::streams::stream    notifying task
[TRACE 16:04:44.276] h2::proto::streams::prioritize available=1 requested=1 buffered=0 has_unavailable=true
[TRACE 16:04:44.276] h2::proto::streams::state  handle_error; err=GoAway(b"", FRAME_SIZE_ERROR, Library)
[TRACE 16:04:44.276] h2::proto::streams::prioritize  dropping  frame=Headers { stream_id: StreamId(1), flags: (0x4: END_HEADERS) }
[TRACE 16:04:44.276] h2::proto::streams::counts  transition_after; stream=StreamId(1); state=State { inner: Closed(Error(GoAway(b"", FRAME_SIZE_ERROR, Library))) }; is_closed=true; pending_send_empty=true; buffered_send_data=0; num_recv=0; num_send=0
[TRACE 16:04:44.276] h2::proto::connection connection.state=Open
[TRACE 16:04:44.276] h2::proto::streams::counts  transition_after; stream=StreamId(1); state=State { inner: Closed(Error(GoAway(b"", FRAME_SIZE_ERROR, Library))) }; is_closed=true; pending_send_empty=true; buffered_send_data=0; num_recv=0; num_send=0
[TRACE 16:04:44.276] h2::proto::streams::streams  drop_stream_ref; stream=Stream { id: StreamId(1), state: State { inner: Closed(Error(GoAway(b"", FRAME_SIZE_ERROR, Library))) }, is_counted: false, ref_count: 2, next_pending_send: None, is_pending_send: false, send_flow: FlowControl { window_size: Window(65535), available: Window(0) }, requested_send_capacity: 0, buffered_send_data: 0, send_task: None, pending_send: Deque { indices: None }, next_pending_send_capacity: None, is_pending_send_capacity: false, send_capacity_inc: true, next_open: None, is_pending_open: true, is_pending_push: false, next_pending_accept: None, is_pending_accept: false, recv_flow: FlowControl { window_size: Window(65535), available: Window(65535) }, in_flight_recv_data: 0, next_window_update: None, is_pending_window_update: false, reset_at: None, next_reset_expire: None, pending_recv: Deque { indices: None }, is_recv: true, recv_task: None, pending_push_promises: Queue { indices: None, _p: PhantomData<h2::proto::streams::stream::NextAccept> }, content_length: Omitted }
[TRACE 16:04:44.276] h2::proto::streams::counts  transition_after; stream=StreamId(1); state=State { inner: Closed(Error(GoAway(b"", FRAME_SIZE_ERROR, Library))) }; is_closed=true; pending_send_empty=true; buffered_send_data=0; num_recv=0; num_send=0
[DEBUG 16:04:44.276] tonic::transport::channel::service::connection  connection task error: hyper::Error(Http2, Error { kind: GoAway(b"", FRAME_SIZE_ERROR, Library) })
[DEBUG 16:04:44.276] h2::codec::framed_write  send  frame=GoAway { error_code: FRAME_SIZE_ERROR, last_stream_id: StreamId(0) }
[TRACE 16:04:44.276] h2::frame::go_away  encoding GO_AWAY; code=FRAME_SIZE_ERROR
[TRACE 16:04:44.276] h2::codec::framed_write  encoded go_away  rem=50
[TRACE 16:04:44.276] h2::proto::streams::streams  drop_stream_ref; stream=Stream { id: StreamId(1), state: State { inner: Closed(Error(GoAway(b"", FRAME_SIZE_ERROR, Library))) }, is_counted: false, ref_count: 1, next_pending_send: None, is_pending_send: false, send_flow: FlowControl { window_size: Window(65535), available: Window(0) }, requested_send_capacity: 0, buffered_send_data: 0, send_task: None, pending_send: Deque { indices: None }, next_pending_send_capacity: None, is_pending_send_capacity: false, send_capacity_inc: true, next_open: None, is_pending_open: true, is_pending_push: false, next_pending_accept: None, is_pending_accept: false, recv_flow: FlowControl { window_size: Window(65535), available: Window(65535) }, in_flight_recv_data: 0, next_window_update: None, is_pending_window_update: false, reset_at: None, next_reset_expire: None, pending_recv: Deque { indices: None }, is_recv: true, recv_task: None, pending_push_promises: Queue { indices: None, _p: PhantomData<h2::proto::streams::stream::NextAccept> }, content_length: Omitted }
[TRACE 16:04:44.277] h2::proto::streams::counts  transition_after; stream=StreamId(1); state=State { inner: Closed(Error(GoAway(b"", FRAME_SIZE_ERROR, Library))) }; is_closed=true; pending_send_empty=true; buffered_send_data=0; num_recv=0; num_send=0
[DEBUG 16:04:44.276] h2::proto::connection  Connection::poll; connection error  error=GoAway(b"", FRAME_SIZE_ERROR, Library)
[TRACE 16:04:44.277] h2::proto::connection      -> already going away
[crates/remote/src/cache_api.rs:93:13] &error = Status {
    code: Unknown,
    message: "h2 protocol error: http2 error",
    source: Some(
        tonic::transport::Error(
            Transport,
            hyper::Error(
                Http2,
                Error {
                    kind: GoAway(
                        b"",
                        FRAME_SIZE_ERROR,
                        Library,
                    ),
                },
            ),
        ),
    ),
}
[crates/remote/src/cache_api.rs:94:13] error.code() = Unknown
[crates/remote/src/cache_api.rs:95:13] error.metadata() = MetadataMap {
    headers: {},
}
[crates/remote/src/cache_api.rs:96:13] error.message() = "h2 protocol error: http2 error"
[TRACE 16:04:44.277] h2::proto::connection connection.state=Closing(FRAME_SIZE_ERROR, Library)
[TRACE 16:04:44.277] h2::proto::connection  connection closing after flush
Error:   × Main thread panicked.
  ├─▶ at /Users/miles/Projects/moon/crates/remote/src/cache_api.rs:98:13
  ╰─▶ Status { code: Unknown, message: "h2 protocol error: http2 error", source: Some(tonic::transport::Error(Transport, hyper::Error(Http2, Error { kind: GoAway(b"", FRAME_SIZE_ERROR,
      Library) }))) }
  help: set the `RUST_BACKTRACE=1` environment variable to display a backtrace.

[milesj]

@tottoto Happen to know by chance?