[pve-devel] [PATCH v2 pve-manager 29/42] vzdump: send notifications via new notification module

[Lukas Wagner <l.wagner@proxmox.com>]

... instead of using sendmail directly.

In case the (new) 'notification-mode' parameter is set to 'mail',
we add an anonymous notification channel with a sendmail endpoint
sending mails to the addresses configured in the 'mailto' paramter.

If set to 'channel', we notify via the configured channel.

This commit also refactors the old 'sendmail' sub heavily:
  - Use template-based notification text instead of endless
    string concatenations
  - Removing the old plaintext/HTML table rendering in favor of
    the new template/property-based approach offered by the
    `proxmox-notify` crate.
  - Rename `sendmail` sub to `send_notification`
  - Breaking out some of the code into helper subs, hopefully
    reducing the spaghetti factor a bit

Signed-off-by: Lukas Wagner <l.wagner@proxmox.com>
---
 PVE/API2/VZDump.pm |   2 +-
 PVE/VZDump.pm      | 323 ++++++++++++++++++++++++---------------------
 test/mail_test.pl  |  36 ++---
 3 files changed, 195 insertions(+), 166 deletions(-)

diff --git a/PVE/API2/VZDump.pm b/PVE/API2/VZDump.pm
index 8e873c05..83772e73 100644
--- a/PVE/API2/VZDump.pm
+++ b/PVE/API2/VZDump.pm
@@ -126,7 +126,7 @@ __PACKAGE__->register_method ({
 		$vzdump->getlock($upid); # only one process allowed
 	    };
 	    if (my $err = $@) {
-		$vzdump->sendmail([], 0, $err);
+		$vzdump->send_notification([], 0, $err);
 		exit(-1);
 	    }
 
diff --git a/PVE/VZDump.pm b/PVE/VZDump.pm
index a04837e7..21a443aa 100644
--- a/PVE/VZDump.pm
+++ b/PVE/VZDump.pm
@@ -19,6 +19,7 @@ use PVE::Exception qw(raise_param_exc);
 use PVE::HA::Config;
 use PVE::HA::Env::PVE2;
 use PVE::JSONSchema qw(get_standard_option);
+use PVE::Notify;
 use PVE::RPCEnvironment;
 use PVE::Storage;
 use PVE::VZDump::Common;
@@ -300,21 +301,90 @@ sub read_vzdump_defaults {
     return $res;
 }
 
-use constant MAX_MAIL_SIZE => 1024*1024;
-sub sendmail {
-    my ($self, $tasklist, $totaltime, $err, $detail_pre, $detail_post) = @_;
+sub read_backup_task_logs {
+    my ($task_list) = @_;
 
-    my $opts = $self->{opts};
+    my $task_logs = "";
 
-    my $mailto = $opts->{mailto};
+    for my $task (@$task_list) {
+	my $vmid = $task->{vmid};
+	my $log_file = $task->{tmplog};
+	if (!$task->{tmplog}) {
+	    $task_logs .= "$vmid: no log available\n\n";
+	    next;
+	}
+	if (open (my $TMP, '<', "$log_file")) {
+	    while (my $line = <$TMP>) {
+		next if $line =~ /^status: \d+/; # not useful in mails
+		$task_logs .= encode8bit ("$vmid: $line");
+	    }
+	    close ($TMP);
+	} else {
+	    $task_logs .= "$vmid: Could not open log file\n\n";
+	}
+	$task_logs .= "\n";
+    }
 
-    return if !($mailto && scalar(@$mailto));
+    return $task_logs;
+}
 
-    my $cmdline = $self->{cmdline};
+sub build_guest_table {
+    my ($task_list) = @_;
+
+    my $table = {
+	schema => {
+	    columns => [
+		{
+		    label => "VMID",
+		    id  => "vmid"
+		},
+		{
+		    label => "Name",
+		    id  => "name"
+		},
+		{
+		    label => "Status",
+		    id  => "status"
+		},
+		{
+		    label => "Time",
+		    id  => "time",
+		    renderer => "duration"
+		},
+		{
+		    label => "Size",
+		    id  => "size",
+		    renderer => "human-bytes"
+		},
+		{
+		    label => "Filename",
+		    id  => "filename"
+		},
+	    ]
+	},
+	data => []
+    };
+
+    for my $task (@$task_list) {
+	my $successful = $task->{state} eq 'ok';
+	my $size = $successful ? $task->{size} : 0;
+	my $filename = $successful ? $task->{target} : undef;
+	push @{$table->{data}}, {
+	    "vmid" => $task->{vmid},
+	    "name" => $task->{hostname},
+	    "status" => $task->{state},
+	    "time" => $task->{backuptime},
+	    "size" => $size,
+	    "filename" => $filename,
+	};
+    }
+
+    return $table;
+}
 
-    my $ecount = 0;
-    foreach my $task (@$tasklist) {
-	$ecount++ if $task->{state} ne 'ok';
+sub sanitize_task_list {
+    my ($task_list) = @_;
+    for my $task (@$task_list) {
 	chomp $task->{msg} if $task->{msg};
 	$task->{backuptime} = 0 if !$task->{backuptime};
 	$task->{size} = 0 if !$task->{size};
@@ -325,164 +395,121 @@ sub sendmail {
 	    $task->{msg} = 'aborted';
 	}
     }
+}
 
-    my $notify = $opts->{mailnotification} || 'always';
-    return if (!$ecount && !$err && ($notify eq 'failure'));
+sub count_failed_tasks {
+    my ($tasklist) = @_;
 
-    my $stat = ($ecount || $err) ? 'backup failed' : 'backup successful';
-    if ($err) {
-	if ($err =~ /\n/) {
-	    $stat .= ": multiple problems";
-	} else {
-	    $stat .= ": $err";
-	    $err = undef;
-	}
+    my $error_count = 0;
+    for my $task (@$tasklist) {
+	$error_count++ if $task->{state} ne 'ok';
     }
 
+    return $error_count;
+}
+
+sub get_hostname {
     my $hostname = `hostname -f` || PVE::INotify::nodename();
     chomp $hostname;
+    return $hostname;
+}
 
-    # text part
-    my $text = $err ? "$err\n\n" : '';
-    my $namelength = 20;
-    $text .= sprintf (
-	"%-10s %-${namelength}s %-6s %10s %10s  %s\n",
-	qw(VMID NAME STATUS TIME SIZE FILENAME)
-    );
-    foreach my $task (@$tasklist) {
-	my $name = substr($task->{hostname}, 0, $namelength);
-	my $successful = $task->{state} eq 'ok';
-	my $size = $successful ? format_size ($task->{size}) : 0;
-	my $filename = $successful ? $task->{target} : '-';
-	my $size_fmt = $successful ? "%10s": "%8.2fMB";
-	$text .= sprintf(
-	    "%-10s %-${namelength}s %-6s %10s $size_fmt  %s\n",
-	    $task->{vmid},
-	    $name,
-	    $task->{state},
-	    format_time($task->{backuptime}),
-	    $size,
-	    $filename,
-	);
-    }
+my $subject_template = "vzdump backup status ({{hostname}}): {{status-text}}";
 
-    my $text_log_part;
-    $text_log_part .= "\nDetailed backup logs:\n\n";
-    $text_log_part .= "$cmdline\n\n";
+my $body_template = <<EOT;
+{{error-message}}
+{{heading-1 "Details"}}
+{{table guest-table}}
 
-    $text_log_part .= $detail_pre . "\n" if defined($detail_pre);
-    foreach my $task (@$tasklist) {
-	my $vmid = $task->{vmid};
-	my $log = $task->{tmplog};
-	if (!$log) {
-	    $text_log_part .= "$vmid: no log available\n\n";
-	    next;
-	}
-	if (open (my $TMP, '<', "$log")) {
-	    while (my $line = <$TMP>) {
-		next if $line =~ /^status: \d+/; # not useful in mails
-		$text_log_part .= encode8bit ("$vmid: $line");
-	    }
-	    close ($TMP);
-	} else {
-	    $text_log_part .= "$vmid: Could not open log file\n\n";
-	}
-	$text_log_part .= "\n";
-    }
-    $text_log_part .= $detail_post if defined($detail_post);
+Total running time: {{duration total-time}}
 
-    # html part
-    my $html = "<html><body>\n";
-    $html .= "<p>" . (escape_html($err) =~ s/\n/<br>/gr) . "</p>\n" if $err;
-    $html .= "<table border=1 cellpadding=3>\n";
-    $html .= "<tr><td>VMID<td>NAME<td>STATUS<td>TIME<td>SIZE<td>FILENAME</tr>\n";
+{{heading-1 "Logs"}}
+{{verbatim-monospaced logs}}
+EOT
 
-    my $ssize = 0;
-    foreach my $task (@$tasklist) {
-	my $vmid = $task->{vmid};
-	my $name = $task->{hostname};
-
-	if  ($task->{state} eq 'ok') {
-	    $ssize += $task->{size};
-
-	    $html .= sprintf (
-	        "<tr><td>%s<td>%s<td>OK<td>%s<td align=right>%s<td>%s</tr>\n",
-	        $vmid,
-	        $name,
-	        format_time($task->{backuptime}),
-	        format_size ($task->{size}),
-	        escape_html ($task->{target}),
-	    );
-	} else {
-	    $html .= sprintf (
-	        "<tr><td>%s<td>%s<td><font color=red>FAILED<td>%s<td colspan=2>%s</tr>\n",
-	        $vmid,
-	        $name,
-	        format_time($task->{backuptime}),
-	        escape_html ($task->{msg}),
-	    );
-	}
-    }
+use constant MAX_LOG_SIZE => 1024*1024;
 
-    $html .= sprintf ("<tr><td align=left colspan=3>TOTAL<td>%s<td>%s<td></tr>",
- format_time ($totaltime), format_size ($ssize));
+sub send_notification {
+    my ($self, $tasklist, $total_time, $err, $detail_pre, $detail_post) = @_;
 
-    $html .= "\n</table><br><br>\n";
-    my $html_log_part;
-    $html_log_part .= "Detailed backup logs:<br /><br />\n";
-    $html_log_part .= "<pre>\n";
-    $html_log_part .= escape_html($cmdline) . "\n\n";
+    my $opts = $self->{opts};
+    my $mailto = $opts->{mailto};
+    my $cmdline = $self->{cmdline};
+    my $notification_mode = $opts->{"notification-mode"} // "mail";
+    my $channel = $opts->{"notification-channel"};
+    # Fall back to 'mailnotification' if 'notification-policy' is not set.
+    # If both are set, 'notification-policy' takes precedence
+    my $policy = $opts->{"notification-policy"} // $opts->{mailnotification} // 'always';
 
-    $html_log_part .= escape_html($detail_pre) . "\n" if defined($detail_pre);
-    foreach my $task (@$tasklist) {
-	my $vmid = $task->{vmid};
-	my $log = $task->{tmplog};
-	if (!$log) {
-	    $html_log_part .= "$vmid: no log available\n\n";
-	    next;
-	}
-	if (open (my $TMP, '<', "$log")) {
-	    while (my $line = <$TMP>) {
-		next if $line =~ /^status: \d+/; # not useful in mails
-		if ($line =~ m/^\S+\s\d+\s+\d+:\d+:\d+\s+(ERROR|WARN):/) {
-		    $html_log_part .= encode8bit ("$vmid: <font color=red>".
-			escape_html ($line) . "</font>");
-		} else {
-		    $html_log_part .= encode8bit ("$vmid: " . escape_html ($line));
-		}
-	    }
-	    close ($TMP);
+    return if ($policy eq 'never');
+
+    sanitize_task_list($tasklist);
+    my $error_count = count_failed_tasks($tasklist);
+
+    my $failed = ($error_count || $err);
+
+    return if (!$failed && ($policy eq 'failure'));
+
+    my $status_text = $failed ? 'backup failed' : 'backup successful';
+
+    if ($err) {
+	if ($err =~ /\n/) {
+	    $status_text .= ": multiple problems";
 	} else {
-	    $html_log_part .= "$vmid: Could not open log file\n\n";
+	    $status_text .= ": $err";
+	    $err = undef;
 	}
-	$html_log_part .= "\n";
     }
-    $html_log_part .= escape_html($detail_post) if defined($detail_post);
-    $html_log_part .= "</pre>";
-    my $html_end = "\n</body></html>\n";
-    # end html part
-
-    if (length($text) + length($text_log_part) +
-	length($html) + length($html_log_part) +
-	length($html_end) < MAX_MAIL_SIZE)
+
+    my $text_log_part = "$cmdline\n\n";
+    $text_log_part .= $detail_pre . "\n" if defined($detail_pre);
+    $text_log_part .= read_backup_task_logs($tasklist);
+    $text_log_part .= $detail_post if defined($detail_post);
+
+    if (length($text_log_part)  > MAX_LOG_SIZE)
     {
-	$html .= $html_log_part;
-	$html .= $html_end;
-	$text .= $text_log_part;
-    } else {
-	my $msg = "Log output was too long to be sent by mail. ".
+	# Let's limit the maximum length of included logs
+	$text_log_part = "Log output was too long to be sent. ".
 	    "See Task History for details!\n";
-	$text .= $msg;
-	$html .= "<p>$msg</p>";
-	$html .= $html_end;
+    };
+
+    my $notification_props = {
+	"hostname"      => get_hostname(),
+	"error-message" => $err,
+	"guest-table"   => build_guest_table($tasklist),
+	"logs"          => $text_log_part,
+	"status-text"   => $status_text,
+	"total-time"    => $total_time,
+    };
+
+    my $notification_config = PVE::Notify::read_config();
+
+    if ($mailto && scalar(@$mailto) && $notification_mode eq "mail") {
+	my $dcconf = PVE::Cluster::cfs_read_file('datacenter.cfg');
+	my $mailfrom = $dcconf->{email_from} || "root";
+
+	$channel = "anonymous-sendmail-channel";
+	$notification_config->add_sendmail_endpoint(
+	    "anonymous-vzdump-sendmail",
+	    $mailto,
+	    $mailfrom,
+	    "vzdump backup tool",
+	    undef);
+	$notification_config->add_channel($channel, ["anonymous-vzdump-sendmail"]);
     }
 
-    my $subject = "vzdump backup status ($hostname) : $stat";
+    return if !defined($channel);
 
-    my $dcconf = PVE::Cluster::cfs_read_file('datacenter.cfg');
-    my $mailfrom = $dcconf->{email_from} || "root";
+    my $severity = $failed ? "error" : "info";
 
-    PVE::Tools::sendmail($mailto, $subject, $text, $html, $mailfrom, "vzdump backup tool");
+    PVE::Notify::send_notification(
+	$channel,
+	$severity,
+	$subject_template,
+	$body_template,
+	$notification_props,
+	$notification_config
+    );
 };
 
 sub new {
@@ -615,7 +642,7 @@ sub new {
     }
 
     if ($errors) {
-	eval { $self->sendmail([], 0, $errors); };
+	eval { $self->send_notification([], 0, $errors); };
 	debugmsg ('err', $@) if $@;
 	die "$errors\n";
     }
@@ -1305,11 +1332,11 @@ sub exec_backup {
     my $totaltime = time() - $starttime;
 
     eval {
-	# otherwise $self->sendmail() will interpret it as multiple problems
+	# otherwise $self->send_notification() will interpret it as multiple problems
 	my $chomped_err = $err;
 	chomp($chomped_err) if $chomped_err;
 
-	$self->sendmail(
+	$self->send_notification(
 	    $tasklist,
 	    $totaltime,
 	    $chomped_err,
diff --git a/test/mail_test.pl b/test/mail_test.pl
index d0114441..0635ebb7 100755
--- a/test/mail_test.pl
+++ b/test/mail_test.pl
@@ -5,7 +5,7 @@ use warnings;
 
 use lib '..';
 
-use Test::More tests => 5;
+use Test::More tests => 3;
 use Test::MockModule;
 
 use PVE::VZDump;
@@ -29,17 +29,19 @@ sub prepare_mail_with_status {
 sub prepare_long_mail {
     open(TEST_FILE, '>', $TEST_FILE_PATH); # Removes previous content
     # 0.5 MB * 2 parts + the overview tables gives more than 1 MB mail
-    print TEST_FILE "a" x (1024*1024/2);
+    print TEST_FILE "a" x (1024*1024);
     close(TEST_FILE);
 }
 
-my ($result_text, $result_html);
+my $result_text;
+my $result_properties;
+
+my $mock_notification_module = Test::MockModule->new('PVE::Notify');
+$mock_notification_module->mock('send_notification', sub {
+    my ($channel, $severity, $title, $text, $properties) = @_;
 
-my $mock_tools_module = Test::MockModule->new('PVE::Tools');
-$mock_tools_module->mock('sendmail', sub {
-    my (undef, undef, $text, $html, undef, undef) = @_;
     $result_text = $text;
-    $result_html = $html;
+    $result_properties = $properties;
 });
 
 my $mock_cluster_module = Test::MockModule->new('PVE::Cluster');
@@ -47,7 +49,9 @@ $mock_cluster_module->mock('cfs_read_file', sub {
     my $path = shift;
 
     if ($path eq 'datacenter.cfg') {
-	return {};
+        return {};
+    } elsif ($path eq 'notifications.cfg' || $path eq 'priv/notifications.cfg') {
+        return '';
     } else {
 	die "unexpected cfs_read_file\n";
     }
@@ -62,28 +66,26 @@ my $SELF = {
 my $task = { state => 'ok', vmid => '100', };
 my $tasklist;
 sub prepare_test {
-    $result_text = $result_html = undef;
+    $result_text = undef;
     $task->{tmplog} = shift;
     $tasklist = [ $task ];
 }
 
 {
     prepare_test($TEST_FILE_WRONG_PATH);
-    PVE::VZDump::sendmail($SELF, $tasklist, 0, undef, undef, undef);
-    like($result_text, $NO_LOGFILE, "Missing logfile is detected");
+    PVE::VZDump::send_notification($SELF, $tasklist, 0, undef, undef, undef);
+    like($result_properties->{logs}, $NO_LOGFILE, "Missing logfile is detected");
 }
 {
     prepare_test($TEST_FILE_PATH);
     prepare_mail_with_status();
-    PVE::VZDump::sendmail($SELF, $tasklist, 0, undef, undef, undef);
-    unlike($result_text, $STATUS, "Status are not in text part of mails");
-    unlike($result_html, $STATUS, "Status are not in HTML part of mails");
+    PVE::VZDump::send_notification($SELF, $tasklist, 0, undef, undef, undef);
+    unlike($result_properties->{"status-text"}, $STATUS, "Status are not in text part of mails");
 }
 {
     prepare_test($TEST_FILE_PATH);
     prepare_long_mail();
-    PVE::VZDump::sendmail($SELF, $tasklist, 0, undef, undef, undef);
-    like($result_text, $LOG_TOO_LONG, "Text part of mails gets shortened");
-    like($result_html, $LOG_TOO_LONG, "HTML part of mails gets shortened");
+    PVE::VZDump::send_notification($SELF, $tasklist, 0, undef, undef, undef);
+    like($result_properties->{logs}, $LOG_TOO_LONG, "Text part of mails gets shortened");
 }
 unlink $TEST_FILE_PATH;
-- 
2.30.2