logging

bindings/rust/s2n-tls-tokio/src/lib.rs

@@ -55,7 +55,7 @@ where
         S: AsyncRead + AsyncWrite + Unpin,
     {
         let conn = self.builder.build_connection(Mode::Server)?;
-        TlsStream::open(conn, stream).await
+        TlsStream::open(conn, stream, Mode::Server).await
     }
 }
 
@@ -85,7 +85,7 @@ where
     {
         let mut conn = self.builder.build_connection(Mode::Client)?;
         conn.as_mut().set_server_name(domain)?;
-        TlsStream::open(conn, stream).await
+        TlsStream::open(conn, stream, Mode::Client).await
     }
 }
 
@@ -159,6 +159,7 @@ where
     conn: C,
     stream: S,
     blinding: Option<Pin<Box<BlindingState>>>,
+    mode: Mode,
 }
 
 impl<S, C> TlsStream<S, C>
@@ -176,12 +177,13 @@ where
         &mut self.stream
     }
 
-    async fn open(mut conn: C, stream: S) -> Result<Self, Error> {
+    async fn open(mut conn: C, stream: S, mode: Mode) -> Result<Self, Error> {
         conn.as_mut().set_blinding(Blinding::SelfService)?;
         let mut tls = TlsStream {
             conn,
             stream,
             blinding: None,
+            mode,
         };
         TlsHandshake {
             tls: &mut tls,
@@ -402,11 +404,16 @@ where
     }
 
     fn poll_shutdown(mut self: Pin<&mut Self>, ctx: &mut Context<'_>) -> Poll<io::Result<()>> {
+        let mode = self.mode;
+
+        println!("{:?} poll_shutdown start", mode);
         ready!(self.as_mut().poll_blinding(ctx))?;
+        println!("{:?} blinding complete", mode);
 
         let status = ready!(self.as_mut().with_io(ctx, |mut context| {
             context.conn.as_mut().poll_shutdown().map(|r| r.map(|_| ()))
         }));
+        println!("{:?} s2n_shutdown complete: {:?}", mode, status);
 
         if let Err(e) = status {
             // In case of an error shutting down, make sure you wait for
@@ -416,7 +423,10 @@ where
             unreachable!("should have returned the error we just put in!");
         }
 
-        Pin::new(&mut self.as_mut().stream).poll_shutdown(ctx)
+        println!("{:?} tcp shutdown start", mode);
+        let r = Pin::new(&mut self.as_mut().stream).poll_shutdown(ctx);
+        println!("{:?} tcp shutdown complete: {:?}", mode, r);
+        r
     }
 }
 

bindings/rust/s2n-tls-tokio/tests/shutdown.rs

@@ -144,6 +144,7 @@ async fn shutdown_after_halfclose_split() -> Result<(), Box<dyn std::error::Erro
 
 #[tokio::test(start_paused = true)]
 async fn shutdown_with_blinding() -> Result<(), Box<dyn std::error::Error>> {
+    for _ in 1..100 {
     let clock = common::TokioTime::default();
     let mut server_config = common::server_config()?;
     server_config.set_monotonic_clock(clock)?;
@@ -170,6 +171,7 @@ async fn shutdown_with_blinding() -> Result<(), Box<dyn std::error::Error>> {
     assert!(result.is_err());
 
     // Shutdown MUST NOT complete faster than minimal blinding time.
+    println!("Test: first join");
     let (timeout, _) = join!(
         time::timeout(common::MIN_BLINDING_SECS, server.shutdown()),
         time::timeout(common::MIN_BLINDING_SECS, read_until_shutdown(&mut client)),
@@ -180,11 +182,13 @@ async fn shutdown_with_blinding() -> Result<(), Box<dyn std::error::Error>> {
     //
     // We check for completion, but not for success. At the moment, the
     // call to s2n_shutdown will fail due to issues in the underlying C library.
+    println!("Test: second join");
     let (timeout, _) = join!(
         time::timeout(common::MAX_BLINDING_SECS, server.shutdown()),
         time::timeout(common::MAX_BLINDING_SECS, read_until_shutdown(&mut client)),
     );
     assert!(timeout.is_ok());
+    }
 
     Ok(())
 }