tokio-quiche: do not generate an error log for Handshake errors and quiche errors

These errors are expected since they can be generated by the peer

Author: jrouviere

tokio-quiche/src/http3/driver/mod.rs

@@ -77,6 +77,7 @@ use self::streams::WaitForUpstreamCapacity;
 use crate::http3::settings::Http3Settings;
 use crate::http3::H3AuditStats;
 use crate::metrics::Metrics;
+use crate::quic::HandshakeError;
 use crate::quic::HandshakeInfo;
 use crate::quic::QuicCommand;
 use crate::quic::QuicheConnection;
@@ -1454,7 +1455,19 @@ impl<H: DriverHooks> ApplicationOverQuic for H3Driver<H> {
 
         let Some(h3_err) = work_loop_error.downcast_ref::<H3ConnectionError>()
         else {
-            log::error!("Found non-H3ConnectionError"; "error" => %work_loop_error);
+            // Errors returned by the IoWorker rather than the driver are
+            // expected and already counted in metrics:
+            // - `HandshakeError`: with 0-RTT early data, the handshake can
+            //   still fail (e.g. time out) after the application was started.
+            // - `quiche::Error`: the connection was closed by quiche, typically
+            //   because of a peer protocol violation.
+            if work_loop_error.is::<HandshakeError>() ||
+                work_loop_error.is::<quiche::Error>()
+            {
+                log::debug!("connection closed by IoWorker"; "error" => %work_loop_error);
+            } else {
+                log::error!("Found non-H3ConnectionError"; "error" => %work_loop_error);
+            }
             return;
         };
 

tokio-quiche/tests/integration_tests/zero_rtt.rs

@@ -31,6 +31,8 @@ use crate::integration_tests::Http3Settings;
 use crate::integration_tests::QuicSettings;
 use crate::integration_tests::TestConnectionHook;
 use datagram_socket::QuicAuditStats;
+use foundations::telemetry::with_test_telemetry;
+use foundations::telemetry::TestTelemetryContext;
 use futures::SinkExt;
 use h3i;
 use h3i::actions::h3::send_headers_frame;
@@ -410,8 +412,8 @@ impl EarlyDataClient {
 /// A client that resumes a session with 0-RTT, but never completes the
 /// handshake while it keeps sending 0-RTT packets, must still be subject to
 /// the handshake timeout, even though the application was already started.
-#[tokio::test]
-async fn handshake_timeout_after_0_rtt() {
+#[with_test_telemetry(tokio::test)]
+async fn handshake_timeout_after_0_rtt(cx: TestTelemetryContext) {
     const HANDSHAKE_TIMEOUT: Duration = Duration::from_secs(1);
 
     let mut server = EarlyDataServer::start(HANDSHAKE_TIMEOUT).await;
@@ -442,4 +444,17 @@ async fn handshake_timeout_after_0_rtt() {
 
     server.assert_handshake_timeout(&audit_stats);
     assert!(failed_handshake_timeouts() > failed_handshake_timeouts_before);
+
+    // A handshake timeout is an expected outcome, it must not be logged as an
+    // error by the application.
+    let error_logs: Vec<_> = cx
+        .log_records()
+        .iter()
+        .filter(|record| record.level.as_str() == "ERROR")
+        .map(|record| record.message.clone())
+        .collect();
+    assert!(
+        error_logs.is_empty(),
+        "unexpected error logs: {error_logs:?}"
+    );
 }