From 678c5bacc68b31e10ef35e6ebaa00d2c8f9e156c Mon Sep 17 00:00:00 2001 From: Quentin Dufour Date: Thu, 8 Feb 2024 15:12:52 +0100 Subject: add way more logging --- src/imap/mod.rs | 17 ++++++++++++++++- 1 file changed, 16 insertions(+), 1 deletion(-) diff --git a/src/imap/mod.rs b/src/imap/mod.rs index 21b4d58..d3508fa 100644 --- a/src/imap/mod.rs +++ b/src/imap/mod.rs @@ -141,6 +141,8 @@ use std::sync::Arc; use tokio::sync::mpsc::*; use tokio::sync::Notify; use tokio_util::bytes::BytesMut; + +#[derive(Debug)] enum LoopMode { Quit, Interactive, @@ -238,8 +240,10 @@ impl NetLoop { } async fn core(mut self) -> Result<()> { + tracing::trace!("Starting the core loop"); let mut mode = LoopMode::Interactive; loop { + tracing::trace!(mode=?mode, "Core loop iter"); mode = match mode { LoopMode::Interactive => self.interactive_mode().await?, LoopMode::Idle(buff, stop) => self.idle_mode(buff, stop).await?, @@ -281,6 +285,7 @@ impl NetLoop { // Managing response generated by Aerogramme maybe_msg = self.resp_rx.recv() => match maybe_msg { Some(ResponseOrIdle::Response(response)) => { + tracing::trace!("Interactive, server has a response for the client"); for body_elem in response.body.into_iter() { let _handle = match body_elem { Body::Data(d) => self.server.enqueue_data(d), @@ -290,6 +295,7 @@ impl NetLoop { self.server.enqueue_status(response.completion); }, Some(ResponseOrIdle::StartIdle(stop)) => { + tracing::trace!("Interactive, server agreed to switch in idle mode"); let cr = CommandContinuationRequest::basic(None, "Idling")?; self.server.enqueue_continuation(cr); self.cmd_tx.try_send(Request::Idle)?; @@ -305,6 +311,7 @@ impl NetLoop { // When receiving a CTRL+C _ = self.ctx.must_exit.changed() => { + tracing::trace!("Interactive, CTRL+C, exiting"); self.server.enqueue_status(Status::bye(None, "Server is being shutdown").unwrap()); }, }; @@ -314,6 +321,7 @@ impl NetLoop { async fn idle_mode(&mut self, mut buff: BytesMut, stop: Arc) -> Result { // Flush send loop { + tracing::trace!("flush server send"); match self.server.progress_send().await? { Some(..) => continue, None => break, @@ -325,6 +333,7 @@ impl NetLoop { maybe_msg = self.resp_rx.recv() => match maybe_msg { // Session decided idle is terminated Some(ResponseOrIdle::Response(response)) => { + tracing::trace!("server imap session said idle is done, sending response done, switching to interactive"); for body_elem in response.body.into_iter() { let _handle = match body_elem { Body::Data(d) => self.server.enqueue_data(d), @@ -336,6 +345,7 @@ impl NetLoop { }, // Session has some information for user Some(ResponseOrIdle::IdleEvent(elems)) => { + tracing::trace!("server imap session has some change to communicate to the client"); for body_elem in elems.into_iter() { let _handle = match body_elem { Body::Data(d) => self.server.enqueue_data(d), @@ -361,13 +371,17 @@ impl NetLoop { _read_client_bytes = self.server.stream.read(&mut buff) => { use imap_codec::decode::Decoder; let codec = imap_codec::IdleDoneCodec::new(); + tracing::trace!("client sent some data for the server IMAP session"); match codec.decode(&buff) { Ok(([], imap_codec::imap_types::extensions::idle::IdleDone)) => { // Session will be informed that it must stop idle // It will generate the "done" message and change the loop mode + tracing::trace!("client sent DONE and want to stop IDLE"); stop.notify_one() }, - Err(_) => (), + Err(_) => { + tracing::trace!("Unable to decode DONE, maybe not enough data were sent?"); + }, _ => bail!("Client sent data after terminating the continuation without waiting for the server. This is an unsupported behavior and bug in Aerogramme, quitting."), }; @@ -376,6 +390,7 @@ impl NetLoop { // When receiving a CTRL+C _ = self.ctx.must_exit.changed() => { + tracing::trace!("CTRL+C sent, aborting IDLE for this session"); self.server.enqueue_status(Status::bye(None, "Server is being shutdown").unwrap()); return Ok(LoopMode::Interactive) }, -- cgit v1.2.3