From 4591003224670144536b812a2248f2b17107a9cf Mon Sep 17 00:00:00 2001 From: Jason Carver Date: Thu, 1 Jun 2023 16:27:59 -0700 Subject: [PATCH] Log more information during an idle timeout Show current state, handle the case when there were dual FIN's and an ACK got dropped (doesn't need a scary WARN log). --- src/conn.rs | 18 +++++++++++++++++- 1 file changed, 17 insertions(+), 1 deletion(-) diff --git a/src/conn.rs b/src/conn.rs index 6ab4985..e61768c 100644 --- a/src/conn.rs +++ b/src/conn.rs @@ -306,8 +306,24 @@ impl Connection { } () = &mut idle_timeout => { if !std::matches!(self.state, State::Closed { .. }) { + // Warn that we are giving up on the connection due to a lack of activity. + + // First, we look for this special situation: + // Our outgoing FIN was sent, but the incoming ACK was dropped. + // This timeout is not worthy of a warning log, because everything + // basically went fine: all data was sent and ACK'd. + // There is no more work to do. + let unacked: Vec = self.unacked.keys().copied().collect(); - tracing::warn!(?unacked, "idle timeout expired, closing..."); + if let State::Closing { local_fin, remote_fin, .. } = self.state { + if unacked.len() == 1 && local_fin.is_some() && &local_fin.unwrap() == unacked.last().unwrap() && remote_fin.is_some() { + tracing::debug!(?self.state, ?unacked, "Idle timeout with both FINs sent, with only FIN unacked."); + } else { + tracing::warn!(?self.state, ?unacked, "quitting idle connection..."); + } + } else { + tracing::warn!(?self.state, ?unacked, "quitting idle connection..."); + } self.state = State::Closed { err: Some(Error::TimedOut) }; }