1 files changed, 44 insertions, 8 deletions

diff --git a/src/proto.rs b/src/proto.rs
index e843bff..8f7e70f 100644
--- a/src/proto.rs
+++ b/src/proto.rs
@@ -1,4 +1,5 @@
 use std::collections::{HashMap, VecDeque};
+use std::fmt::Write;
 use std::sync::Arc;
 
 use log::trace;
@@ -94,6 +95,22 @@ impl SendQueue {
 	fn is_empty(&self) -> bool {
 		self.items.iter().all(|(_k, v)| v.is_empty())
 	}
+	fn dump(&self) -> String {
+		let mut ret = String::new();
+		for (prio, q) in self.items.iter() {
+			for item in q.iter() {
+				write!(
+					&mut ret,
+					" [{} {} ({})]",
+					prio,
+					item.data.len() - item.cursor,
+					item.id
+				)
+				.unwrap();
+			}
+		}
+		ret
+	}
 }
 
 /// The SendLoop trait, which is implemented both by the client and the server
@@ -110,6 +127,7 @@ pub(crate) trait SendLoop: Sync {
 		self: Arc<Self>,
 		mut msg_recv: mpsc::UnboundedReceiver<(RequestID, RequestPriority, Vec<u8>)>,
 		mut write: BoxStreamWrite<W>,
+		debug_name: String,
 	) -> Result<(), Error>
 	where
 		W: AsyncWriteExt + Unpin + Send + Sync,
@@ -117,8 +135,15 @@ pub(crate) trait SendLoop: Sync {
 		let mut sending = SendQueue::new();
 		let mut should_exit = false;
 		while !should_exit || !sending.is_empty() {
+			trace!("send_loop({}): queue = {}", debug_name, sending.dump());
 			if let Ok((id, prio, data)) = msg_recv.try_recv() {
-				trace!("send_loop: got {}, {} bytes", id, data.len());
+				trace!(
+					"send_loop({}): new message to send, id = {}, prio = {}, {} bytes",
+					debug_name,
+					id,
+					prio,
+					data.len()
+				);
 				sending.push(SendQueueItem {
 					id,
 					prio,
@@ -127,7 +152,8 @@ pub(crate) trait SendLoop: Sync {
 				});
 			} else if let Some(mut item) = sending.pop() {
 				trace!(
-					"send_loop: sending bytes for {} ({} bytes, {} already sent)",
+					"send_loop({}): sending bytes for {} ({} bytes, {} already sent)",
+					debug_name,
 					item.id,
 					item.data.len(),
 					item.cursor
@@ -157,7 +183,13 @@ pub(crate) trait SendLoop: Sync {
 			} else {
 				let sth = msg_recv.recv().await;
 				if let Some((id, prio, data)) = sth {
-					trace!("send_loop: got {}, {} bytes", id, data.len());
+					trace!(
+						"send_loop({}): new message to send, id = {}, prio = {}, {} bytes",
+						debug_name,
+						id,
+						prio,
+						data.len()
+					);
 					sending.push(SendQueueItem {
 						id,
 						prio,
@@ -186,13 +218,12 @@ pub(crate) trait SendLoop: Sync {
 pub(crate) trait RecvLoop: Sync + 'static {
 	fn recv_handler(self: &Arc<Self>, id: RequestID, msg: Vec<u8>);
 
-	async fn recv_loop<R>(self: Arc<Self>, mut read: R) -> Result<(), Error>
+	async fn recv_loop<R>(self: Arc<Self>, mut read: R, debug_name: String) -> Result<(), Error>
 	where
 		R: AsyncReadExt + Unpin + Send + Sync,
 	{
 		let mut receiving = HashMap::new();
 		loop {
-			trace!("recv_loop: reading packet");
 			let mut header_id = [0u8; RequestID::BITS as usize / 8];
 			match read.read_exact(&mut header_id[..]).await {
 				Ok(_) => (),
@@ -200,19 +231,24 @@ pub(crate) trait RecvLoop: Sync + 'static {
 				Err(e) => return Err(e.into()),
 			};
 			let id = RequestID::from_be_bytes(header_id);
-			trace!("recv_loop: got header id: {:04x}", id);
 
 			let mut header_size = [0u8; ChunkLength::BITS as usize / 8];
 			read.read_exact(&mut header_size[..]).await?;
 			let size = ChunkLength::from_be_bytes(header_size);
-			trace!("recv_loop: got header size: {:04x}", size);
+			trace!(
+				"recv_loop({}): got header id = {}, size = 0x{:04x} ({} bytes)",
+				debug_name,
+				id,
+				size,
+				size & !CHUNK_HAS_CONTINUATION
+			);
 
 			let has_cont = (size & CHUNK_HAS_CONTINUATION) != 0;
 			let size = size & !CHUNK_HAS_CONTINUATION;
 
 			let mut next_slice = vec![0; size as usize];
 			read.read_exact(&mut next_slice[..]).await?;
-			trace!("recv_loop: read {} bytes", next_slice.len());
+			trace!("recv_loop({}): read {} bytes", debug_name, next_slice.len());
 
 			let mut msg_bytes: Vec<_> = receiving.remove(&id).unwrap_or_default();
 			msg_bytes.extend_from_slice(&next_slice[..]);