Looking for debugging suggestions for TLS failures w/ partially read bodies

[rfairfax]

I'm trying to debug some TLS response weirdness I'm seeing. This is with Hyper 1.0.1.

My code takes large payloads from the client (a few MBs to GBs) and then processes results. If it hits an error it will abort early and return an error response to the client after only having read part of the payload.

With HTTP (no TLS) this works perfectly. The client gets the response and handles the abort properly. The moment I add in TLS I see some weird behavior.

1. If I never read from the incoming body at all things work properly.
2. If I read the entire incoming body and send a response, things work properly.
3. If I read at least one frame but not all and send a response the client sees an unexpected TLS EOF and can't decode the response.

I see the same behavior with rustls based streams and openssl based streams, so it doesn't appear to be the TLS library / wrapper.

If I turn on tracing for hyper I see the following on a "good" request:

2023-12-08T21:47:56.424378Z TRACE encode_headers: hyper::proto::h1::role: Server::encode status=400, body=Some(Known(228)), req_method=Some(PUT)
2023-12-08T21:47:56.424456Z TRACE hyper::proto::h1::encode: sized write, len = 228
2023-12-08T21:47:56.424473Z TRACE hyper::proto::h1::io: buffer.flatten self.len=365 buf.len=228
2023-12-08T21:47:56.424504Z DEBUG hyper::proto::h1::io: flushed 593 bytes
2023-12-08T21:47:56.424510Z TRACE hyper::proto::h1::conn: flushed({role=server}): State { reading: Continue(Length(3145728)), writing: KeepAlive, keep_alive: Busy }
2023-12-08T21:47:56.424542Z TRACE hyper::proto::h1::dispatch: body receiver dropped before eof, draining or closing
2023-12-08T21:47:56.424547Z TRACE hyper::proto::h1::decode: decode; state=Length(3145728)
2023-12-08T21:47:56.424556Z TRACE hyper::proto::h1::conn: State::close_read()
2023-12-08T21:47:56.424561Z TRACE hyper::proto::h1::conn: State::close()
2023-12-08T21:47:56.424565Z TRACE hyper::proto::h1::conn: flushed({role=server}): State { reading: Closed, writing: Closed, keep_alive: Disabled }
2023-12-08T21:47:56.424585Z TRACE hyper::proto::h1::conn: shut down IO complete

A bad request looks like:

2023-12-08T21:33:56.663274Z TRACE encode_headers: hyper::proto::h1::role: Server::encode status=400, body=Some(Known(228)), req_method=Some(PUT)
2023-12-08T21:33:56.663345Z TRACE hyper::proto::h1::encode: sized write, len = 228
2023-12-08T21:33:56.663356Z TRACE hyper::proto::h1::io: buffer.queue self.len=365 buf.len=228
2023-12-08T21:33:56.663417Z DEBUG hyper::proto::h1::io: flushed 365 bytes
2023-12-08T21:33:56.663437Z DEBUG hyper::proto::h1::io: flushed 228 bytes
2023-12-08T21:33:56.663443Z TRACE hyper::proto::h1::conn: flushed({role=server}): State { reading: Body(Length(3137536)), writing: KeepAlive, keep_alive: Busy }
2023-12-08T21:33:56.663470Z TRACE hyper::proto::h1::dispatch: body receiver dropped before eof, draining or closing
2023-12-08T21:33:56.663476Z TRACE hyper::proto::h1::decode: decode; state=Length(3137536)
2023-12-08T21:33:56.663522Z TRACE hyper::proto::h1::io: received 8192 bytes
2023-12-08T21:33:56.663531Z TRACE hyper::proto::h1::conn: State::close_read()
2023-12-08T21:33:56.663538Z TRACE hyper::proto::h1::conn: State::close()
2023-12-08T21:33:56.663542Z TRACE hyper::proto::h1::conn: flushed({role=server}): State { reading: Closed, writing: Closed, keep_alive: Disabled }
2023-12-08T21:33:56.663568Z TRACE hyper::proto::h1::conn: shut down IO complete

The only obvious different besides some flushing pattern differences is an extra read after the body receiver is dropped in the bad case.

I'm looking for suggestions on how to debug and root cause this. My guess is we're aborting/closing the connection differently in the two cases but I can't find an obvious place where it diverges in a way that could cause problems.

Suggestions / thoughts on what this might be would be appreciated.

[thefaxman]

I think I see the problem on my end - please ignore for now until I debug more