add way more logging

This commit is contained in:
Quentin 2024-02-08 15:12:52 +01:00
parent 22f0eb901a
commit 678c5bacc6
Signed by: quentin
GPG key ID: E9602264D639FF68

View file

@ -141,6 +141,8 @@ use std::sync::Arc;
use tokio::sync::mpsc::*; use tokio::sync::mpsc::*;
use tokio::sync::Notify; use tokio::sync::Notify;
use tokio_util::bytes::BytesMut; use tokio_util::bytes::BytesMut;
#[derive(Debug)]
enum LoopMode { enum LoopMode {
Quit, Quit,
Interactive, Interactive,
@ -238,8 +240,10 @@ impl NetLoop {
} }
async fn core(mut self) -> Result<()> { async fn core(mut self) -> Result<()> {
tracing::trace!("Starting the core loop");
let mut mode = LoopMode::Interactive; let mut mode = LoopMode::Interactive;
loop { loop {
tracing::trace!(mode=?mode, "Core loop iter");
mode = match mode { mode = match mode {
LoopMode::Interactive => self.interactive_mode().await?, LoopMode::Interactive => self.interactive_mode().await?,
LoopMode::Idle(buff, stop) => self.idle_mode(buff, stop).await?, LoopMode::Idle(buff, stop) => self.idle_mode(buff, stop).await?,
@ -281,6 +285,7 @@ impl NetLoop {
// Managing response generated by Aerogramme // Managing response generated by Aerogramme
maybe_msg = self.resp_rx.recv() => match maybe_msg { maybe_msg = self.resp_rx.recv() => match maybe_msg {
Some(ResponseOrIdle::Response(response)) => { Some(ResponseOrIdle::Response(response)) => {
tracing::trace!("Interactive, server has a response for the client");
for body_elem in response.body.into_iter() { for body_elem in response.body.into_iter() {
let _handle = match body_elem { let _handle = match body_elem {
Body::Data(d) => self.server.enqueue_data(d), Body::Data(d) => self.server.enqueue_data(d),
@ -290,6 +295,7 @@ impl NetLoop {
self.server.enqueue_status(response.completion); self.server.enqueue_status(response.completion);
}, },
Some(ResponseOrIdle::StartIdle(stop)) => { Some(ResponseOrIdle::StartIdle(stop)) => {
tracing::trace!("Interactive, server agreed to switch in idle mode");
let cr = CommandContinuationRequest::basic(None, "Idling")?; let cr = CommandContinuationRequest::basic(None, "Idling")?;
self.server.enqueue_continuation(cr); self.server.enqueue_continuation(cr);
self.cmd_tx.try_send(Request::Idle)?; self.cmd_tx.try_send(Request::Idle)?;
@ -305,6 +311,7 @@ impl NetLoop {
// When receiving a CTRL+C // When receiving a CTRL+C
_ = self.ctx.must_exit.changed() => { _ = self.ctx.must_exit.changed() => {
tracing::trace!("Interactive, CTRL+C, exiting");
self.server.enqueue_status(Status::bye(None, "Server is being shutdown").unwrap()); 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<Notify>) -> Result<LoopMode> { async fn idle_mode(&mut self, mut buff: BytesMut, stop: Arc<Notify>) -> Result<LoopMode> {
// Flush send // Flush send
loop { loop {
tracing::trace!("flush server send");
match self.server.progress_send().await? { match self.server.progress_send().await? {
Some(..) => continue, Some(..) => continue,
None => break, None => break,
@ -325,6 +333,7 @@ impl NetLoop {
maybe_msg = self.resp_rx.recv() => match maybe_msg { maybe_msg = self.resp_rx.recv() => match maybe_msg {
// Session decided idle is terminated // Session decided idle is terminated
Some(ResponseOrIdle::Response(response)) => { 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() { for body_elem in response.body.into_iter() {
let _handle = match body_elem { let _handle = match body_elem {
Body::Data(d) => self.server.enqueue_data(d), Body::Data(d) => self.server.enqueue_data(d),
@ -336,6 +345,7 @@ impl NetLoop {
}, },
// Session has some information for user // Session has some information for user
Some(ResponseOrIdle::IdleEvent(elems)) => { Some(ResponseOrIdle::IdleEvent(elems)) => {
tracing::trace!("server imap session has some change to communicate to the client");
for body_elem in elems.into_iter() { for body_elem in elems.into_iter() {
let _handle = match body_elem { let _handle = match body_elem {
Body::Data(d) => self.server.enqueue_data(d), Body::Data(d) => self.server.enqueue_data(d),
@ -361,13 +371,17 @@ impl NetLoop {
_read_client_bytes = self.server.stream.read(&mut buff) => { _read_client_bytes = self.server.stream.read(&mut buff) => {
use imap_codec::decode::Decoder; use imap_codec::decode::Decoder;
let codec = imap_codec::IdleDoneCodec::new(); let codec = imap_codec::IdleDoneCodec::new();
tracing::trace!("client sent some data for the server IMAP session");
match codec.decode(&buff) { match codec.decode(&buff) {
Ok(([], imap_codec::imap_types::extensions::idle::IdleDone)) => { Ok(([], imap_codec::imap_types::extensions::idle::IdleDone)) => {
// Session will be informed that it must stop idle // Session will be informed that it must stop idle
// It will generate the "done" message and change the loop mode // It will generate the "done" message and change the loop mode
tracing::trace!("client sent DONE and want to stop IDLE");
stop.notify_one() 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."), _ => 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 // When receiving a CTRL+C
_ = self.ctx.must_exit.changed() => { _ = 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()); self.server.enqueue_status(Status::bye(None, "Server is being shutdown").unwrap());
return Ok(LoopMode::Interactive) return Ok(LoopMode::Interactive)
}, },