pmg-smtp-filter: die if processing took longer than the timeout

[pmg-api.git] / src / bin / pmg-smtp-filter

diff --git a/src/bin/pmg-smtp-filter b/src/bin/pmg-smtp-filter
index 13da635cb0f3fcba2e29ec0e95a423de42ec26b1..dc7128c5b42534dde424b8370a7b2dcf3a5ce1fd 100755 (executable)
--- a/src/bin/pmg-smtp-filter
+++ b/src/bin/pmg-smtp-filter
@@ -70,10 +70,12 @@ my $prog_name = 'pmg-smtp-filter';
 
 initlog($prog_name, 'mail');
 
-if (!GetOptions ('testmode=s' => \$opt_testmode,
-                'pidfile=s' => \$opt_pidfile,
-                'untrusted' => \$opt_untrusted,
-                'database=s' => \$opt_database)) {
+if (!GetOptions(
+    'testmode=s' => \$opt_testmode,
+    'pidfile=s' => \$opt_pidfile,
+    'untrusted' => \$opt_untrusted,
+    'database=s' => \$opt_database
+)) {
     die "usage error\n";
     exit (-1);
 }
@@ -96,6 +98,12 @@ if (!$opt_testmode) {
        exit (0);
     }
 
+    my $memory = PMG::Config::Mail::physical_memory();
+    if ($memory < 3840) {
+       warn "total memory below 4 GiB, consider setting 'max_filters' manually to avoid OOM-kills\n"
+           if !defined($pmg_cfg->get('mail', 'max_filters', 1));
+    }
+
     $max_servers = $pmg_cfg->get('mail', 'max_filters') + 2;
     $min_servers = 2;
     $min_spare_servers = 1;
@@ -103,6 +111,9 @@ if (!$opt_testmode) {
     $max_requests = 20;
 }
 
+print "using pre-fork workers with min=$min_servers, max=$max_servers, min_spare=$min_spare_servers"
+    .", max_spare=$max_spare_servers, max_requests=$max_requests\n";
+
 $opt_max_dequeue = 0 if $opt_testmode;
 
 my $daemonize = 1;
@@ -231,6 +242,7 @@ sub apply_rules {
     my %rule_targets;
     my %rule_actions;
     my %rule_marks;
+    my %rule_spaminfo;
     my $matching_rules = [];
 
     my $rulecache = $self->{rulecache};
@@ -266,9 +278,12 @@ sub apply_rules {
            next;
        }
 
-       $rule_marks{$rule->{id}} =
+       my ($marks, $spaminfo) =
            $rulecache->what_match ($rule->{id}, $queue, $entity, $msginfo, $dbh);
 
+       $rule_marks{$rule->{id}} = $marks;
+       $rule_spaminfo{$rule->{id}} = $spaminfo;
+
        $rule_actions{$rule->{id}} = $rulecache->get_actions ($rule->{id});
        my $fin = $rulecache->final ($rule->{id});
 
@@ -277,7 +292,6 @@ sub apply_rules {
            next if $final->{$target};
            next if !defined ($rule_marks{$rule->{id}});
            next if !defined ($rule_marks{$rule->{id}}->{$target});
-           next if !defined ($rule_marks{$rule->{id}}->{$target}->{marks});
            next if !$rulecache->to_match ($rule->{id}, $target, $ldap);
 
            $final->{$target} = $fin;
@@ -316,28 +330,24 @@ sub apply_rules {
 
     my $mod_group = PMG::ModGroup->new($entity, $msginfo->{targets});
 
+    my $processing_time = int(tv_interval($msginfo->{starttime}));
+    my $filter_timeout = $self->{pmg_cfg}->get('mail', 'filter-timeout');
+    die "processing took ${processing_time}s, longer than the timeout (${filter_timeout}s)\n"
+       if $processing_time > $filter_timeout;
+
     foreach my $rule (@$rules) {
        my $targets = $rule_targets{$rule->{id}};
        next if !$targets;
 
-       my $spaminfo;
-       foreach my $t (@$targets) {
-           if ($rule_marks{$rule->{id}}->{$t} && $rule_marks{$rule->{id}}->{$t}->{spaminfo}) {
-               $spaminfo = $rule_marks{$rule->{id}}->{$t}->{spaminfo};
-               # we assume spam info is the same for all matching targets
-               last;
-           }
-       }
-
        my $vars = $self->get_prox_vars (
-           $queue, $entity, $msginfo, $rule, $rule_targets{$rule->{id}}, $spaminfo);
+           $queue, $entity, $msginfo, $rule, $rule_targets{$rule->{id}}, $rule_spaminfo{$rule->{id}});
 
        my @sorted_actions = sort {$a->priority <=> $b->priority} @{$rule_actions{$rule->{id}}};
 
        foreach my $action (@sorted_actions) {
            $action->execute(
                $queue, $self->{ruledb}, $mod_group, $rule_targets{$rule->{id}}, $msginfo, $vars,
-               $rule_marks{$rule->{id}}->{marks}, $ldap
+               $rule_marks{$rule->{id}}, $ldap
            );
            last if $action->final;
        }
@@ -366,7 +376,7 @@ sub load_config {
     my $prop = $self->{server};
 
     if ($self->{ruledb}) {
-       $self->log (0, "reloading configuration $database");
+       $self->log ('info', "reloading configuration $database");
        $self->{ruledb}->close ();
     }
 
@@ -426,7 +436,7 @@ sub pre_loop_hook {
 
     $prop->{log_level} = 3;
 
-    $self->log (0, "Filter daemon (re)started (max. $max_servers processes)");
+    $self->log ('info', "Filter daemon (re)started (max. $max_servers processes)");
 
     eval {  PMG::MailQueue::cleanup_active(); };
     $self->log (0, "Cleanup failures: $@") if $@;
@@ -524,7 +534,7 @@ sub run_dequeue {
 
     $self->log (2, "starting database maintenance");
 
-    my ($csec, $usec) = gettimeofday ();
+    my $starttime = [ gettimeofday() ];
 
     my $cinfo = PVE::INotify::read_file("cluster.conf");
 
@@ -540,8 +550,7 @@ sub run_dequeue {
     if ($err) {
        $self->log (0, $err);
     } else {
-       my ($csec_end, $usec_end) = gettimeofday ();
-       my $ptime = int (($csec_end - $csec) * 1000 + ($usec_end - $usec) / 1000);
+       my $ptime = int(tv_interval($starttime) * 1000);
        $self->log (2, "end database maintenance ($ptime ms)");
     }
 
@@ -560,7 +569,7 @@ sub unpack_entity {
        if (PMG::Unpack::is_archive ($magic)) {
            $self->log (3, "$queue->{logid}: found archive '$filename' ($magic)");
 
-           my $start = [gettimeofday];
+           my $start = [ gettimeofday() ];
 
            $unpack->{mime} = {};
 
@@ -591,7 +600,7 @@ sub unpack_entity {
 sub handle_smtp {
     my ($self, $smtp) = @_;
 
-    my ($csec, $usec) = gettimeofday ();
+    my $starttime = [ gettimeofday() ];
 
     my $queue;
     my $msginfo = {};
@@ -638,6 +647,7 @@ sub handle_smtp {
        $msginfo->{fqdn} = $msginfo->{hostname};
        $msginfo->{fqdn} .= ".$msginfo->{domain}" if $msginfo->{domain};
        $msginfo->{lcid} = $lcid;
+       $msginfo->{starttime} = $starttime;
 
        # $msginfo->{targets} is case sensitive,
        # but pmail is always lower case!
@@ -656,7 +666,8 @@ sub handle_smtp {
 
        my $maxfiles = $pmg_cfg->get('clamav', 'archivemaxfiles');
 
-       my $entity = $queue->parse_mail($maxfiles);
+       my ($entity, $max_aid) = $queue->parse_mail($maxfiles);
+       $msginfo->{max_aid} = $max_aid;
 
        $self->log (3, "$queue->{logid}: new mail message-id=%s", $queue->{msgid});
 
@@ -714,7 +725,7 @@ sub handle_smtp {
            my $decdir = $queue->{dumpdir} . "/__decoded_archives";
            mkdir $decdir;
 
-           my $start = [gettimeofday];
+           my $start = [ gettimeofday() ];
 
            my $unpack;
            eval {
@@ -769,9 +780,7 @@ sub handle_smtp {
 
     die $err if $err;
 
-    my ($csec_end, $usec_end) = gettimeofday ();
-    my $time_total =
-       int (($csec_end-$csec)*1000 + ($usec_end - $usec)/1000);
+    my $time_total = int(tv_interval($starttime) * 1000);
 
 # PHASE 5 - log statistics
 # on error: log error messages
@@ -944,10 +953,12 @@ if (!$opt_testmode) {
        $server->run();
     } else {
 
-       my $sender ='sender@proxtest.com';
-       my $targets = ['target1@proxtest.com',
-                      'target2@proxtest.com',
-                      'target3@proxtest.com'];
+       my $sender ='sender@pmg.example';
+       my $targets = [
+           'target1@pmg.example',
+           'target2@pmg.example',
+           'target3@pmg.example',
+       ];
 
        my $smtp;
        while (!$smtp) {