debugging...

crates/tls/client/src/conn.rs

@@ -452,6 +452,12 @@ impl ConnectionCommon {
                 return Err(e);
             }
         };
+        let recv_plain = self.common_state.received_plaintext.len();
+        let sendable_tls = self.common_state.sendable_tls.len();
+        let sendable_plain = self.common_state.sendable_plaintext.len();
+        //  println!("\nreceived plaintext is {}", recv_plain);
+        //  println!("sendable tls is {}", sendable_tls);
+        //  println!("sendable plaintext is {}", sendable_plain);
 
         if self.message_deframer.desynced {
             return Err(Error::CorruptMessage);
@@ -549,6 +555,7 @@ impl ConnectionCommon {
         if let Ok(0) = res {
             self.common_state.has_seen_eof = true;
         }
+        let res = res.inspect(|v| println!("read tls:  {v} bytes"));
         res
     }
 

crates/tlsn/src/prover.rs

@@ -325,12 +325,14 @@ where
 
         let (mut duplex_1, mut duplex_2) = futures_plex::duplex(BUF_CAP);
         loop {
+            tracing::trace!("looping prover");
             let mut progress = false;
 
             progress |= Self::io_client_conn(&mut state, cx)?;
             progress |= Self::io_client_server(&mut state, cx, &mut duplex_1, &mut duplex_2)?;
             progress |= Self::io_client_verifier(&mut state, cx)?;
             _ = state.mux_fut.poll_unpin(cx)?;
+            tracing::trace!("io done ");
 
             if state.output.is_none()
                 && let Poll::Ready(output) = state.tls_client.poll(cx)?
@@ -339,8 +341,10 @@ where
             }
 
             if !progress {
+                tracing::trace!("pending");
                 return Poll::Pending;
-            } else if *state.server_closed && *state.client_closed && state.output.is_some() {
+            }
+            if *state.server_closed && state.output.is_some() {
                 return Poll::Ready(Ok(()));
             }
         }
@@ -365,10 +369,12 @@ where
             if buf.len() > 0 {
                 let write = state.tls_client.write(buf)?;
                 if write > 0 {
+                    println!("1");
                     progress = true;
                     simplex.advance(write);
                 }
             } else if !*state.client_closed && !*state.server_closed {
+                println!("closing client ...");
                 progress = true;
                 *state.client_closed = true;
                 state.tls_client.client_close()?;
@@ -383,6 +389,7 @@ where
                 && let read = state.tls_client.read(buf)?
                 && read > 0
             {
+                println!("6");
                 progress = true;
                 simplex.advance_mut(read);
             }
@@ -398,35 +405,41 @@ where
         duplex_2: &mut DuplexStream,
     ) -> Result<bool, ProverError> {
         let mut progress = false;
-        let mut duplex_1 = Pin::new(duplex_1);
+        let duplex_1 = Pin::new(duplex_1);
         let mut duplex_2 = Pin::new(duplex_2);
 
         // server_socket -> duplex
         if let Poll::Ready(write) = duplex_1.poll_write_from(cx, state.server_socket.as_mut())? {
             if write > 0 {
+                println!("4");
                 progress = true;
-            } else if let Poll::Ready(()) = duplex_1.as_mut().poll_close(cx)? {
-                progress = true;
-            }
-        }
-
-        // duplex -> tls_client
-        if let Poll::Ready(mut simplex) = duplex_2.as_mut().poll_lock_read(cx)
-            && let Poll::Ready(buf) = simplex.poll_get(cx)?
-        {
-            if buf.len() > 0
-                && let read = state.tls_client.read_tls(buf)?
-                && read > 0
-            {
-                progress = true;
-                simplex.advance(read);
             } else if !*state.server_closed {
+                println!("closing server...");
                 progress = true;
                 *state.server_closed = true;
                 state.tls_client.server_close()?;
             }
         }
 
+        //println!("client io");
+        // duplex -> tls_client
+        if let Poll::Ready(mut simplex) = duplex_2.as_mut().poll_lock_read(cx) {
+            if let Poll::Ready(buf) = simplex.poll_get(cx)? {
+                let buf_len = buf.len();
+                let read = state.tls_client.read_tls(buf)?;
+                println!("buf len: {}, read: {}", buf_len, read);
+                if buf_len > 0 && read > 0 {
+                    println!("5");
+                    progress = true;
+                    simplex.advance(read);
+                }
+            } else {
+                println!("poll get pending");
+            }
+        } else {
+            println!("poll lock pending");
+        }
+
         // tls_client -> duplex
         if let Poll::Ready(mut simplex) = duplex_2.as_mut().poll_lock_write(cx)
             && let Poll::Ready(buf) = simplex.poll_mut(cx)?
@@ -435,6 +448,7 @@ where
                 && let write = state.tls_client.write_tls(buf)?
                 && write > 0
             {
+                println!("2");
                 progress = true;
                 simplex.advance_mut(write);
             }
@@ -444,6 +458,7 @@ where
         if let Poll::Ready(read) = duplex_1.poll_read_to(cx, state.server_socket.as_mut())?
             && read > 0
         {
+            println!("3");
             progress = true;
         }
 

crates/tlsn/src/prover/client/mpc.rs

@@ -237,6 +237,7 @@ impl TlsClient for MpcTlsClient {
                 receiver,
             } => {
                 trace!("inner client is active");
+                //println!("client is handshaking: {}", inner.tls.is_handshaking());
 
                 if !inner.tls.is_handshaking()
                     && let Ok(cmd) = receiver.try_recv()

crates/tlsn/src/utils.rs

@@ -53,7 +53,6 @@ pin_project_lite::pin_project! {
         io: S,
         #[pin]
         duplex: &'a mut DuplexStream,
-        buf: Vec<u8>,
         closed: bool
     }
 }
@@ -63,7 +62,6 @@ impl<'a, S> CopyFlush<'a, S> {
         Self {
             io,
             duplex,
-            buf: Vec::with_capacity(BUF_CAP),
             closed: false,
         }
     }
@@ -85,6 +83,7 @@ where
             if let Poll::Ready(read) = read
                 && read == 0
             {
+                println!("copy flush: read 0 from duplex: closing connection");
                 ready!(this.io.as_mut().poll_close(cx))?;
                 *this.closed = true;
             }
@@ -92,12 +91,15 @@ where
             if let Poll::Ready(write) = write
                 && write == 0
             {
+                println!("copy flush: read 0 from io: closing connection");
                 ready!(this.duplex.as_mut().poll_close(cx))?;
                 *this.closed = true;
             }
 
             if matches!(read, Poll::Pending) && matches!(write, Poll::Pending) {
                 return Poll::Pending;
+            } else if *this.closed {
+                return Poll::Ready(Ok(()));
             }
         }
     }