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

Thomas Lamprecht t.lamprecht at proxmox.com
Thu Apr 18 13:01:52 CEST 2019


Am 4/12/19 um 4:00 PM schrieb Stoiko Ivanov:
> 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));
.                                                                                                                     ^^^^^^^^^^^^

AFAIK, and as far perldoc knows about encode it can not do encoding of a list
but of a single scalar value, and the third param is the 'check' (croak)
one, so this is probably a artefact from your prev. "encode all $rulename"
approach, can you re-check and test this please, thanks! 


>  		}
>  		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');
>      }
>  }
> 




More information about the pmg-devel mailing list