Repository: seanmonstar/reqwest (language: rust)

Issue:
`connection_verbose` does not emit the response headers and body
Given the following code:
```rust
#[tokio::main]
async fn main() {
    env_logger::init();  // RUST_LOG=trace
    let client = reqwest::Client::builder()
        .connection_verbose(true)
        .build()
        .expect("Client::new()");
    let _ = client.get("https://eu.httpbin.org/get")
        .send()
        .await;
}
```

If executed with `reqwest`  v0.11.27 it outputs the response haeaders and body log correctly:
```
% RUST_LOG=trace cargo run
[2024-05-06T06:57:18Z DEBUG reqwest::connect] starting new connection: https://eu.httpbin.org/
[2024-05-06T06:57:19Z TRACE reqwest::connect::verbose] 7e642c23 write: b"GET /get HTTP/1.1\r\naccept: */*\r\nhost: eu.httpbin.org\r\n\r\n"
[2024-05-06T06:57:19Z TRACE reqwest::connect::verbose] 7e642c23 read: b"HTTP/1.1 200 OK\r\nDate: Mon, 06 May 2024 06:57:19 GMT\r\nContent-Type: application/json\r\nContent-Length: 228\r\nConnection: keep-alive\r\nServer: gunicorn/19.9.0\r\nAccess-Control-Allow-Origin: *\r\nAccess-Control-Allow-Credentials: true\r\n\r\n"
[2024-05-06T06:57:19Z TRACE reqwest::connect::verbose] 7e642c23 read: b"{\n  \"args\": {}, \n  \"headers\": {\n    \"Accept\": \"*/*\", \n    \"Host\": \"eu.httpbin.org\", \n    \"X-Amzn-Trace-Id\": \"Root=1-66387f4f-25a929b24f3cb1f5250ce27f\"\n  }, \n  \"origin\": \"91.116.229.190\", \n  \"url\": \"https://eu.httpbin.org/get\"\n}\n"
```

But if run it with 0.12 it doesn't:
```
[2024-05-06T06:56:30Z TRACE hyper_util::client::legacy::pool] checkout waiting for idle connection: ("https", eu.httpbin.org)
[2024-05-06T06:56:30Z DEBUG reqwest::connect] starting new connection: https://eu.httpbin.org/
[2024-05-06T06:56:30Z TRACE hyper_util::client::legacy::connect::http] Http::connect; scheme=Some("https"), host=Some("eu.httpbin.org"), port=None
[2024-05-06T06:56:30Z DEBUG hyper_util::client::legacy::connect::dns] resolving host="eu.httpbin.org"
[2024-05-06T06:56:30Z DEBUG hyper_util::client::legacy::connect::http] connecting to 3.211.223.136:443
[2024-05-06T06:56:30Z DEBUG hyper_util::client::legacy::connect::http] connected to 3.211.223.136:443
[2024-05-06T06:56:30Z TRACE hyper_util::client::legacy::client] http1 handshake complete, spawning background dispatcher task
[2024-05-06T06:56:30Z TRACE hyper_util::client::legacy::pool] checkout dropped for ("https", eu.httpbin.org)
[2024-05-06T06:56:30Z TRACE reqwest::connect::verbose] 52085a80 write: b"GET /get HTTP/1.1\r\naccept: */*\r\nhost: eu.httpbin.org\r\n\r\n"
[2024-05-06T06:56:30Z TRACE reqwest::connect::verbose] TODO: verbose poll_read
[2024-05-06T06:56:30Z TRACE reqwest::connect::verbose] TODO: verbose poll_read
[2024-05-06T06:56:30Z TRACE hyper_util::client::legacy::pool] put; add idle connection for ("https", eu.httpbin.org)
[2024-05-06T06:56:30Z DEBUG hyper_util::client::legacy::pool] pooling idle connection for ("https", eu.httpbin.org)
```

The truth is that I don't know if those two `TODO` lines it emits refer to this.


Discussion / hints:
Oh yes, that got left behind in the upgrade, as the `TODO` reveals. Woops!

Looking in the source, the problem is that hyper's `ReadBuf`/`ReadBufCursor` don't currently have a way to inspect what was just read. We'd need to propose a method in the hyper repo to do that.
Any news on this? If it is necessary to open a bug in the upstream I can open it myself without problems (although I am not very clear about what is missing).

Fix patch:
diff --git a/src/connect.rs b/src/connect.rs
index bf681f9b5..ff86ba3c9 100644
--- a/src/connect.rs
+++ b/src/connect.rs
@@ -1140,14 +1140,21 @@ mod verbose {
         fn poll_read(
             mut self: Pin<&mut Self>,
             cx: &mut Context,
-            buf: ReadBufCursor<'_>,
+            mut buf: ReadBufCursor<'_>,
         ) -> Poll<std::io::Result<()>> {
-            match Pin::new(&mut self.inner).poll_read(cx, buf) {
+            // TODO: This _does_ forget the `init` len, so it could result in
+            // re-initializing twice. Needs upstream support, perhaps.
+            // SAFETY: Passing to a ReadBuf will never de-initialize any bytes.
+            let mut vbuf = hyper::rt::ReadBuf::uninit(unsafe { buf.as_mut() });
+            match Pin::new(&mut self.inner).poll_read(cx, vbuf.unfilled()) {
                 Poll::Ready(Ok(())) => {
-                    /*
-                    log::trace!("{:08x} read: {:?}", self.id, Escape(buf.filled()));
-                    */
-                    log::trace!("TODO: verbose poll_read");
+                    log::trace!("{:08x} read: {:?}", self.id, Escape(vbuf.filled()));
+                    let len = vbuf.filled().len();
+                    // SAFETY: The two cursors were for the same buffer. What was
+                    // filled in one is safe in the other.
+                    unsafe {
+                        buf.advance(len);
+                    }
                     Poll::Ready(Ok(()))
                 }
                 Poll::Ready(Err(e)) => Poll::Ready(Err(e)),


Test patch: