[pmg-devel] [PATCH pmg-api] Add rule name to RuleAction logging

Stoiko Ivanov s.ivanov at proxmox.com
Fri Apr 12 16:00:13 CEST 2019


With complicated rulesets knowing which rule is responsible for the action
applied to a mail can become complex. Since relevant actions [0] do log a line
when being executed adding the rule's name to this logline should simplify
understanding and debugging complex rules.

Additionally the mix of string interpolation and formatstrings in Quarantine.pm
got unified to formatstrings.

[0] Attach is covered via Notify, Counter, Disclaimer and ModField could result
in too verbose logging (i.e. users adding many headers to a mail) without any
gain.

Signed-off-by: Stoiko Ivanov <s.ivanov at proxmox.com>
---
Initially the patch did encode the RuleName as UTF-8, until I noticed that we
do not support that yet (interaction between Postgres and Perl - see #2057)
when creating a rule. Adding wider/complete support for UTF-8 for writing/
reading from the database should also probably happen while reading/writing
the Database (and is a fight for another day).

AFAIS the only caller of the execute subs of the Actions is bin/pmg-smtp-filter

My (quick) tests included sending a mail with that patch applied and checking
that the logs still show up in the Tracking Center.

 PMG/RuleDB/Accept.pm     |  6 ++++--
 PMG/RuleDB/BCC.pm        |  8 +++++---
 PMG/RuleDB/Block.pm      |  4 +++-
 PMG/RuleDB/Notify.pm     |  8 +++++---
 PMG/RuleDB/Quarantine.pm |  6 ++++--
 PMG/RuleDB/Remove.pm     | 10 ++++++----
 PMG/RuleDB/ReportSpam.pm |  3 +++
 7 files changed, 30 insertions(+), 15 deletions(-)

diff --git a/PMG/RuleDB/Accept.pm b/PMG/RuleDB/Accept.pm
index 2956927..31e628c 100644
--- a/PMG/RuleDB/Accept.pm
+++ b/PMG/RuleDB/Accept.pm
@@ -91,6 +91,8 @@ sub execute {
 
     my $subgroups = $mod_group->subgroups($targets, 1);
 
+    my $rulename = $vars->{RULE};
+
     foreach my $ta (@$subgroups) {
 	my ($tg, $entity) = (@$ta[0], @$ta[1]);
 
@@ -111,12 +113,12 @@ sub execute {
 		$msginfo->{xforward}, $msginfo->{fqdn});
 	    if ($qid) {
 		foreach (@$tg) {
-		    syslog('info', "%s: accept mail to <%s> (%s)", $queue->{logid}, encode('UTF-8', $_), $qid);
+		    syslog('info', "%s: accept mail to <%s> (rule: %s, %s)", $queue->{logid}, encode('UTF-8', $_), $rulename, $qid);
 		}
 		$queue->set_status ($tg, 'delivered', $qid);
 	    } else {
 		foreach (@$tg) {
-		    syslog('err', "%s: reinject mail to <%s> failed", $queue->{logid}, encode('UTF-8', $_));
+		    syslog('err', "%s: reinject mail to <%s> (rule: %s) failed", $queue->{logid}, encode('UTF-8', $_, $rulename));
 		}
 		if ($code) {
 		    my $resp = substr($code, 0, 1);
diff --git a/PMG/RuleDB/BCC.pm b/PMG/RuleDB/BCC.pm
index 1ee5561..cbe2810 100644
--- a/PMG/RuleDB/BCC.pm
+++ b/PMG/RuleDB/BCC.pm
@@ -114,12 +114,14 @@ sub execute {
 
     my $subgroups = $mod_group->subgroups($targets, 1);
 
+    my $rulename = $vars->{RULE};
+
     my $bcc_to = PMG::Utils::subst_values($self->{target}, $vars);
 
     if ($bcc_to =~ m/^\s*$/) {
 	# this happens if a notification is triggered by bounce mails
 	# which notifies the sender <> - we just log and then ignore it
-	syslog('info', "%s: bcc to <> (ignored)", $queue->{logid});
+	syslog('info', "%s: bcc to <> (rule: %s, ignored)", $queue->{logid}, $rulename);
 	return;
     }
 
@@ -148,9 +150,9 @@ sub execute {
 		$msginfo->{xforward}, $msginfo->{fqdn}, 1);
 	    foreach (@bcc_targets) {
 		if ($qid) {
-		    syslog('info', "%s: bcc to <%s> (%s)", $queue->{logid}, $_, $qid);
+		    syslog('info', "%s: bcc to <%s> (rule: %s, %s)", $queue->{logid}, $_, $rulename, $qid);
 		} else {
-		    syslog('err', "%s: bcc to <%s> failed", $queue->{logid}, $_);
+		    syslog('err', "%s: bcc to <%s> (rule: %s) failed", $queue->{logid}, $_, $rulename);
 		}
 	    }
 	}
diff --git a/PMG/RuleDB/Block.pm b/PMG/RuleDB/Block.pm
index 81f00b9..c7c640e 100644
--- a/PMG/RuleDB/Block.pm
+++ b/PMG/RuleDB/Block.pm
@@ -89,6 +89,8 @@ sub execute {
     my ($self, $queue, $ruledb, $mod_group, $targets, 
 	$msginfo, $vars, $marks) = @_;
 
+    my $rulename = $vars->{RULE};
+
     if ($msginfo->{testmode}) {
 	my $fh = $msginfo->{test_fh};
 	print $fh "block from: $msginfo->{sender}\n";
@@ -96,7 +98,7 @@ sub execute {
     }
 
     foreach my $to (@$targets) {
-	syslog('info', "%s: block mail to <%s>", $queue->{logid}, encode('UTF-8', $to));
+	syslog('info', "%s: block mail to <%s> (rule: %s)", $queue->{logid}, encode('UTF-8', $to), $rulename);
     }
 
     $queue->set_status($targets, 'blocked');
diff --git a/PMG/RuleDB/Notify.pm b/PMG/RuleDB/Notify.pm
index 22b8bd2..20d87af 100644
--- a/PMG/RuleDB/Notify.pm
+++ b/PMG/RuleDB/Notify.pm
@@ -207,6 +207,8 @@ sub execute {
 
     my $from = 'postmaster';
 
+    my $rulename = $vars->{RULE};
+
     my $body = PMG::Utils::subst_values($self->{body}, $vars);
     my $subject = PMG::Utils::subst_values($self->{subject}, $vars);
     my $to = PMG::Utils::subst_values($self->{to}, $vars);
@@ -214,7 +216,7 @@ sub execute {
     if ($to =~ m/^\s*$/) {
 	# this happens if a notification is triggered by bounce mails
 	# which notifies the sender <> - we just log and then ignore it
-	syslog('info', "%s: notify <> (ignored)", $queue->{logid});
+	syslog('info', "%s: notify <> (rule: %s, ignored)", $queue->{logid}, $rulename);
 	return;
     }
 
@@ -255,9 +257,9 @@ sub execute {
 	    $top, $from, \@targets, undef, $msginfo->{fqdn});
 	foreach (@targets) {
 	    if ($qid) {
-		syslog('info', "%s: notify <%s> (%s)", $queue->{logid}, $_, $qid);
+		syslog('info', "%s: notify <%s> (rule: %s, %s)", $queue->{logid}, $_, $rulename, $qid);
 	    } else {
-		syslog ('err', "%s: notify <%s> failed", $queue->{logid}, $_);
+		syslog ('err', "%s: notify <%s> (rule: %s) failed", $queue->{logid}, $_, $rulename);
 	    }
 	}
     }
diff --git a/PMG/RuleDB/Quarantine.pm b/PMG/RuleDB/Quarantine.pm
index eb423a7..487fa6e 100644
--- a/PMG/RuleDB/Quarantine.pm
+++ b/PMG/RuleDB/Quarantine.pm
@@ -89,6 +89,8 @@ sub execute {
     
     my $subgroups = $mod_group->subgroups($targets, 1);
 
+    my $rulename = $vars->{RULE};
+
     foreach my $ta (@$subgroups) {
 	my ($tg, $entity) = (@$ta[0], @$ta[1]);
 
@@ -98,7 +100,7 @@ sub execute {
 	    if (my $qid = $queue->quarantine_mail($ruledb, 'V', $entity, $tg, $msginfo, $vars, $ldap)) {
 
 		foreach (@$tg) {
-		    syslog ('info', "$queue->{logid}: moved mail for <%s> to virus quarantine - $qid", $_);
+		    syslog ('info', "$queue->{logid}: moved mail for <%s> to virus quarantine (rule: %s, %s)", $_, $rulename, $qid);
 		}
 
 		$queue->set_status ($tg, 'delivered');
@@ -108,7 +110,7 @@ sub execute {
 	    if (my $qid = $queue->quarantine_mail($ruledb, 'S', $entity, $tg, $msginfo, $vars, $ldap)) {
 
 		foreach (@$tg) {
-		    syslog ('info', "$queue->{logid}: moved mail for <%s> to spam quarantine - $qid", $_);
+		    syslog ('info', "$queue->{logid}: moved mail for <%s> to spam quarantine (rule: %s, %s)", $_, $rulename, $qid);
 		}
 
 		$queue->set_status($tg, 'delivered');
diff --git a/PMG/RuleDB/Remove.pm b/PMG/RuleDB/Remove.pm
index 1bb7a85..551fb97 100644
--- a/PMG/RuleDB/Remove.pm
+++ b/PMG/RuleDB/Remove.pm
@@ -111,7 +111,7 @@ sub save {
 }
 
 sub delete_marked_parts {
-    my ($self, $queue, $entity, $html, $rtype, $marks) = @_;
+    my ($self, $queue, $entity, $html, $rtype, $marks, $rulename) = @_;
 
     my $nparts = [];
 
@@ -155,8 +155,8 @@ sub delete_marked_parts {
 
 	    push (@$nparts, $ent);
 
-	    syslog ('info', "%s: removed attachment $id ('%s')",
-		    $queue->{logid}, $on);
+	    syslog ('info', "%s: removed attachment $id ('%s', rule: %s)",
+		    $queue->{logid}, $on, $rulename);
 
 	} else {
 	    $self->delete_marked_parts($queue, $part, $html, $rtype, $marks);
@@ -171,6 +171,8 @@ sub execute {
     my ($self, $queue, $ruledb, $mod_group, $targets,
 	$msginfo, $vars, $marks) = @_;
 
+    my $rulename = $vars->{RULE};
+
     if (!$self->{all} && ($#$marks == -1)) {
 	# no marks
 	return;
@@ -200,7 +202,7 @@ sub execute {
 	    $entity->head->delete('x-proxmox-tmp-aid');
 	}
 
-	$self->delete_marked_parts($queue, $entity, $html, $rtype, $marks);
+	$self->delete_marked_parts($queue, $entity, $html, $rtype, $marks, $rulename);
 
 	if ($msginfo->{testmode}) {
 	    $entity->head->mime_attr('Content-type.boundary' => '------=_TEST123456') if $entity->is_multipart;
diff --git a/PMG/RuleDB/ReportSpam.pm b/PMG/RuleDB/ReportSpam.pm
index 105a67f..a3e06ee 100644
--- a/PMG/RuleDB/ReportSpam.pm
+++ b/PMG/RuleDB/ReportSpam.pm
@@ -85,6 +85,8 @@ sub execute {
     my ($self, $queue, $ruledb, $mod_group, $targets, 
 	$msginfo, $vars, $marks) = @_;
 
+    my $rulename = $vars->{RULE};
+
     my $subgroups = $mod_group->subgroups($targets);
 
     foreach my $ta (@$subgroups) {
@@ -105,6 +107,7 @@ sub execute {
 	    
 	    $mail->finish();	
 	}
+	syslog('info', "%s: report mail as spam (rule: %s)", $queue->{logid}, $rulename);
 	$queue->set_status ($tg, 'delivered');
     }
 }
-- 
2.11.0




More information about the pmg-devel mailing list