feat: Improve logging (#13)

Improves logs and reduces verbosity.

Fixes: #8

Signed-off-by: Jagoda Ślązak <jslazak@jslazak.com>
This commit is contained in:
Jagoda Estera Ślązak
2026-08-18 12:21:27 +02:00
committed by missytake
parent 8ba2bc22c5
commit 44c8c1906f
5 changed files with 25 additions and 31 deletions
+6 -6
View File
@@ -32,7 +32,7 @@ impl SmtpHandler for IncomingBeforeQueueHandler {
} }
fn check_data(&self, envelope: &Envelope) -> Result<(), String> { fn check_data(&self, envelope: &Envelope) -> Result<(), String> {
log::info!("Processing DATA message from {}", envelope.mail_from); log::debug!("Processing DATA message from {}", envelope.mail_from);
let message = match parse_mail(&envelope.data) { let message = match parse_mail(&envelope.data) {
Ok(m) => m, Ok(m) => m,
@@ -40,16 +40,16 @@ impl SmtpHandler for IncomingBeforeQueueHandler {
}; };
let mail_encrypted = check_encrypted(&message, false); let mail_encrypted = check_encrypted(&message, false);
log::debug!("mail_encrypted: {}", mail_encrypted); log::debug!("mail_encrypted: {mail_encrypted}");
log::debug!("is_securejoin: {}", is_securejoin(&message)); log::debug!("is_securejoin: {}", is_securejoin(&message));
// Allow encrypted or securejoin messages // Allow encrypted or securejoin messages
if mail_encrypted || is_securejoin(&message) { if mail_encrypted || is_securejoin(&message) {
log::info!("Incoming: Filtering encrypted mail."); log::debug!("Incoming: Filtering encrypted mail.");
return Ok(()); return Ok(());
} }
log::info!("Incoming: Filtering unencrypted mail."); log::debug!("Incoming: Filtering unencrypted mail.");
// Allow cleartext mailer-daemon messages // Allow cleartext mailer-daemon messages
if let Some(auto_submitted) = message.headers.get_first_value("Auto-Submitted") if let Some(auto_submitted) = message.headers.get_first_value("Auto-Submitted")
@@ -72,7 +72,7 @@ impl SmtpHandler for IncomingBeforeQueueHandler {
for recipient in &envelope.rcpt_to { for recipient in &envelope.rcpt_to {
if !self.config.is_cleartext_ok(recipient) { if !self.config.is_cleartext_ok(recipient) {
log::info!("Rejected unencrypted mail."); log::warn!("Rejected unencrypted email from: {}", envelope.mail_from);
return Err(ENCRYPTION_NEEDED_523.to_string()); return Err(ENCRYPTION_NEEDED_523.to_string());
} }
} }
@@ -81,7 +81,7 @@ impl SmtpHandler for IncomingBeforeQueueHandler {
} }
async fn reinject_mail(&self, envelope: &Envelope) -> Result<(), String> { async fn reinject_mail(&self, envelope: &Envelope) -> Result<(), String> {
log::info!("Re-injecting the mail that passed checks"); log::debug!("Re-injecting the mail that passed checks");
let mailer = AsyncSmtpTransport::<Tokio1Executor>::builder_dangerous("localhost") let mailer = AsyncSmtpTransport::<Tokio1Executor>::builder_dangerous("localhost")
.port(self.config.postfix_reinject_port_incoming) .port(self.config.postfix_reinject_port_incoming)
+2 -2
View File
@@ -55,7 +55,7 @@ async fn main() {
let handler = Arc::new(OutgoingBeforeQueueHandler::new(config.clone())); let handler = Arc::new(OutgoingBeforeQueueHandler::new(config.clone()));
let addr = format!("127.0.0.1:{}", config.filtermail_smtp_port); let addr = format!("127.0.0.1:{}", config.filtermail_smtp_port);
let max_size = config.max_message_size; let max_size = config.max_message_size;
log::debug!("Outgoing SMTP server listening on {}", addr); log::debug!("Outgoing SMTP server listening on {addr}");
if let Err(e) = run_smtp_server(&addr, handler, max_size).await { if let Err(e) = run_smtp_server(&addr, handler, max_size).await {
eprintln!("Server error: {}", e); eprintln!("Server error: {}", e);
@@ -65,7 +65,7 @@ async fn main() {
let handler = Arc::new(IncomingBeforeQueueHandler::new(config.clone())); let handler = Arc::new(IncomingBeforeQueueHandler::new(config.clone()));
let addr = format!("127.0.0.1:{}", config.filtermail_smtp_port_incoming); let addr = format!("127.0.0.1:{}", config.filtermail_smtp_port_incoming);
let max_size = config.max_message_size; let max_size = config.max_message_size;
log::debug!("Incoming SMTP server listening on {}", addr); log::debug!("Incoming SMTP server listening on {addr}");
if let Err(e) = run_smtp_server(&addr, handler, max_size).await { if let Err(e) = run_smtp_server(&addr, handler, max_size).await {
eprintln!("Server error: {}", e); eprintln!("Server error: {}", e);
+2 -8
View File
@@ -71,20 +71,14 @@ fn check_openpgp_payload(payload: &[u8]) -> Result<bool, error::Error> {
// Symmetrically Encrypted and Integrity Protected Data Packet (SEIPD) // Symmetrically Encrypted and Integrity Protected Data Packet (SEIPD)
// //
// This is the only place where this function may return `True`. // This is the only place where this function may return `True`.
log::debug!( log::debug!("check_openpgp_payload: i={i} packat_type_id={packet_type_id}");
"check_openpgp_payload: i={i} packat_type_id={}",
packet_type_id
);
return Ok(packet_type_id == 18); return Ok(packet_type_id == 18);
} else if ![1, 3].contains(&packet_type_id) { } else if ![1, 3].contains(&packet_type_id) {
// All packets except the last one must be either // All packets except the last one must be either
// Public-Key Encrypted Session Key Packet (PKESK) // Public-Key Encrypted Session Key Packet (PKESK)
// or // or
// Symmetric-Key Encrypted Session Key Packet (SKESK) // Symmetric-Key Encrypted Session Key Packet (SKESK)
log::debug!( log::debug!("check_openpgp_payload: i={i} packet_type_id={packet_type_id}");
"check_openpgp_payload: i={i} packet_type_id={}",
packet_type_id
);
return Ok(false); return Ok(false);
} }
} }
+8 -8
View File
@@ -30,7 +30,7 @@ impl OutgoingBeforeQueueHandler {
#[async_trait] #[async_trait]
impl SmtpHandler for OutgoingBeforeQueueHandler { impl SmtpHandler for OutgoingBeforeQueueHandler {
fn handle_mail(&self, address: &str) -> Result<(), String> { fn handle_mail(&self, address: &str) -> Result<(), String> {
log::info!("handle_MAIL from {}", address); log::debug!("handle_MAIL from {address}");
let parts: Vec<&str> = address.split('@').collect(); let parts: Vec<&str> = address.split('@').collect();
if parts.len() != 2 { if parts.len() != 2 {
@@ -40,15 +40,15 @@ impl SmtpHandler for OutgoingBeforeQueueHandler {
let max_sent = self.config.max_user_send_per_minute; let max_sent = self.config.max_user_send_per_minute;
let mut limiter = self.send_rate_limiter.lock().unwrap(); let mut limiter = self.send_rate_limiter.lock().unwrap();
if !limiter.is_sending_allowed(address, max_sent) { if !limiter.is_sending_allowed(address, max_sent) {
log::debug!("Rate limit exceeded for {}", address); log::debug!("Rate limit exceeded for {address}");
return Err(format!("450 4.7.1: Too much mail from {}", address)); return Err(format!("450 4.7.1: Too much mail from {address}"));
} }
Ok(()) Ok(())
} }
fn check_data(&self, envelope: &Envelope) -> Result<(), String> { fn check_data(&self, envelope: &Envelope) -> Result<(), String> {
log::info!("Processing DATA message from {}", envelope.mail_from); log::debug!("Processing DATA message from {}", envelope.mail_from);
let message = match parse_mail(&envelope.data) { let message = match parse_mail(&envelope.data) {
Ok(m) => m, Ok(m) => m,
@@ -76,11 +76,11 @@ impl SmtpHandler for OutgoingBeforeQueueHandler {
// Allow encrypted or securejoin messages // Allow encrypted or securejoin messages
if mail_encrypted || is_securejoin(&message) { if mail_encrypted || is_securejoin(&message) {
log::info!("Outgoing: Filtering encrypted mail."); log::debug!("Outgoing: Filtering encrypted mail.");
return Ok(()); return Ok(());
} }
log::info!("Outgoing: Filtering unencrypted mail."); log::debug!("Outgoing: Filtering unencrypted mail.");
// Allow passthrough senders // Allow passthrough senders
if self if self
@@ -104,7 +104,7 @@ impl SmtpHandler for OutgoingBeforeQueueHandler {
for recipient in &envelope.rcpt_to { for recipient in &envelope.rcpt_to {
if !recipient_matches_passthrough(recipient, &self.config.passthrough_recipients) { if !recipient_matches_passthrough(recipient, &self.config.passthrough_recipients) {
log::info!("Rejected unencrypted mail."); log::warn!("Rejected unencrypted mail from: {}", envelope.mail_from);
return Err(ENCRYPTION_NEEDED_523.to_string()); return Err(ENCRYPTION_NEEDED_523.to_string());
} }
} }
@@ -113,7 +113,7 @@ impl SmtpHandler for OutgoingBeforeQueueHandler {
} }
async fn reinject_mail(&self, envelope: &Envelope) -> Result<(), String> { async fn reinject_mail(&self, envelope: &Envelope) -> Result<(), String> {
log::info!("Re-injecting the mail that passed checks"); log::debug!("Re-injecting the mail that passed checks");
let mailer = AsyncSmtpTransport::<Tokio1Executor>::builder_dangerous("localhost") let mailer = AsyncSmtpTransport::<Tokio1Executor>::builder_dangerous("localhost")
.port(self.config.postfix_reinject_port) .port(self.config.postfix_reinject_port)
+7 -7
View File
@@ -28,10 +28,10 @@ pub trait SmtpHandler: Send + Sync {
/// Handles the DATA command. /// Handles the DATA command.
async fn handle_data(&self, envelope: &Envelope) -> Result<String, String> { async fn handle_data(&self, envelope: &Envelope) -> Result<String, String> {
log::info!("handle_DATA before-queue"); log::debug!("handle_DATA before-queue");
self.check_data(envelope)?; self.check_data(envelope)?;
self.reinject_mail(envelope).await.map_err(|e| { self.reinject_mail(envelope).await.map_err(|e| {
log::warn!("Failed to reinject mail: {}", e); log::warn!("Failed to reinject mail: {e}");
e e
})?; })?;
Ok("250 OK".to_string()) Ok("250 OK".to_string())
@@ -56,7 +56,7 @@ where
let handler = handler.clone(); let handler = handler.clone();
tokio::spawn(async move { tokio::spawn(async move {
if let Err(e) = handle_connection(socket, handler, max_size).await { if let Err(e) = handle_connection(socket, handler, max_size).await {
log::error!("Error handling connection: {}", e); log::error!("Error handling connection: {e}");
} }
}); });
} }
@@ -98,7 +98,7 @@ where
break 'connection; break 'connection;
}; };
log::debug!("Received: {}", cmd); log::debug!("Received: {cmd}");
if cmd.to_uppercase().starts_with("HELO") || cmd.to_uppercase().starts_with("EHLO") { if cmd.to_uppercase().starts_with("HELO") || cmd.to_uppercase().starts_with("EHLO") {
writer.write_all(b"250 OK\r\n").await?; writer.write_all(b"250 OK\r\n").await?;
@@ -115,7 +115,7 @@ where
} }
} }
} else { } else {
log::debug!("Invalid MAIL FROM command. Can't extract address."); log::warn!("Invalid MAIL FROM command. Can't extract address. Received: {cmd}");
writer writer
.write_all(b"500 Invalid address in MAIL FROM\r\n") .write_all(b"500 Invalid address in MAIL FROM\r\n")
.await?; .await?;
@@ -159,13 +159,13 @@ where
// Process the message // Process the message
match handler.handle_data(&envelope).await { match handler.handle_data(&envelope).await {
Ok(response) => { Ok(response) => {
log::debug!("Sent: {}", response); log::debug!("Sent: {response}");
writer writer
.write_all(format!("{}\r\n", response).as_bytes()) .write_all(format!("{}\r\n", response).as_bytes())
.await?; .await?;
} }
Err(e) => { Err(e) => {
log::debug!("Sent: {}", e); log::debug!("Sent: {e}");
writer.write_all(format!("{}\r\n", e).as_bytes()).await?; writer.write_all(format!("{}\r\n", e).as_bytes()).await?;
} }
} }