search

sagebind / isahc

The practical HTTP client that is fun to use.
https://docs.rs/isahc
MIT License
712 stars 62 forks source link

'INFO response dropped without fully consuming..' seen in successful / fully read requests #433

Open samothx opened 10 months ago

samothx commented 10 months ago

I see the above message in requests that are definitely fully read. Looking at trace output it appears that this is internal to isahc and a hint is given by the following traces: 

2024-01-03 08:43:59 TRACE [isahc::handler] << <html>\r\n<head><title>301 Moved Permanently</title></head>\r\n<body>\r\n<center><h1>301 Moved Permanently</h1></center>\r\n<hr><center>nginx/1.22.1</center>\r\n</body>\r\n</html>\r\n
2024-01-03 08:43:59 TRACE [isahc::handler] <- handler;
2024-01-03 08:43:59 TRACE [isahc::handler] write;
2024-01-03 08:43:59 TRACE [isahc::handler] -> write;
2024-01-03 08:43:59 TRACE [isahc::handler] received 169 bytes of data
2024-01-03 08:43:59 TRACE [isahc::handler] -> handler;
2024-01-03 08:43:59 TRACE [isahc::handler] <- handler;
2024-01-03 08:43:59 TRACE [isahc::client] -> send_async;
2024-01-03 08:43:59 TRACE [isahc::client] <- send_async;
2024-01-03 08:43:59 TRACE [isahc::client] -> send_async;
2024-01-03 08:43:59 TRACE [isahc::handler] -> handler;
2024-01-03 08:43:59 TRACE [isahc::handler] <- handler;
2024-01-03 08:43:59 TRACE [isahc::handler] -> handler;
2024-01-03 08:43:59 DEBUG [isahc::handler] TLSv1.3 (IN), TLS handshake, Encrypted Extensions (8):
2024-01-03 08:43:59 TRACE [isahc::handler] <- handler;
2024-01-03 08:43:59 TRACE [isahc::handler] -> handler;
2024-01-03 08:43:59 TRACE [isahc::handler] <- handler;
2024-01-03 08:43:59 DEBUG [isahc::handler] handler;
2024-01-03 08:43:59 TRACE [polling] Poller::notify()
2024-01-03 08:43:59 TRACE [polling::epoll] notify: epoll_fd=9, event_fd=10
2024-01-03 08:43:59 TRACE [isahc::client] <- send_async;
2024-01-03 08:43:59 TRACE [isahc::client] -> send_async;
2024-01-03 08:43:59 TRACE [isahc::client] <- send_async;
2024-01-03 08:43:59 TRACE [isahc::handler] -> handler;
2024-01-03 08:43:59 TRACE [isahc::handler] <- handler;
2024-01-03 08:43:59 INFO  response dropped without fully consuming the response body, connection won't be reused

I am thinking the unread response might be connected to the internal 301. The log probably contains output from several parallel requests so it is likely to be a little confusing.