From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: from firstgate.proxmox.com (firstgate.proxmox.com [212.224.123.68]) (using TLSv1.3 with cipher TLS_AES_256_GCM_SHA384 (256/256 bits) key-exchange X25519 server-signature RSA-PSS (2048 bits)) (No client certificate requested) by lists.proxmox.com (Postfix) with ESMTPS id DC5669B1A2 for ; Wed, 24 May 2023 15:58:05 +0200 (CEST) Received: from firstgate.proxmox.com (localhost [127.0.0.1]) by firstgate.proxmox.com (Proxmox) with ESMTP id A40711F767 for ; Wed, 24 May 2023 15:57:43 +0200 (CEST) Received: from proxmox-new.maurer-it.com (proxmox-new.maurer-it.com [94.136.29.106]) (using TLSv1.3 with cipher TLS_AES_256_GCM_SHA384 (256/256 bits) key-exchange X25519 server-signature RSA-PSS (2048 bits)) (No client certificate requested) by firstgate.proxmox.com (Proxmox) with ESMTPS for ; Wed, 24 May 2023 15:57:40 +0200 (CEST) Received: from proxmox-new.maurer-it.com (localhost.localdomain [127.0.0.1]) by proxmox-new.maurer-it.com (Proxmox) with ESMTP id 3BD8946E39 for ; Wed, 24 May 2023 15:57:36 +0200 (CEST) From: Lukas Wagner To: pve-devel@lists.proxmox.com Date: Wed, 24 May 2023 15:56:36 +0200 Message-Id: <20230524135649.934881-30-l.wagner@proxmox.com> X-Mailer: git-send-email 2.30.2 In-Reply-To: <20230524135649.934881-1-l.wagner@proxmox.com> References: <20230524135649.934881-1-l.wagner@proxmox.com> MIME-Version: 1.0 Content-Transfer-Encoding: 8bit X-SPAM-LEVEL: Spam detection results: 0 AWL -0.152 Adjusted score from AWL reputation of From: address BAYES_00 -1.9 Bayes spam probability is 0 to 1% DMARC_MISSING 0.1 Missing DMARC policy KAM_DMARC_STATUS 0.01 Test Rule for DKIM or SPF Failure with Strict Alignment SPF_HELO_NONE 0.001 SPF: HELO does not publish an SPF Record SPF_PASS -0.001 SPF: sender matches SPF record T_SCC_BODY_TEXT_LINE -0.01 - Subject: [pve-devel] [PATCH v2 pve-manager 29/42] vzdump: send notifications via new notification module X-BeenThere: pve-devel@lists.proxmox.com X-Mailman-Version: 2.1.29 Precedence: list List-Id: Proxmox VE development discussion List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Wed, 24 May 2023 13:58:06 -0000 ... 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 --- 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 = <{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 = "\n"; - $html .= "

" . (escape_html($err) =~ s/\n/
/gr) . "

\n" if $err; - $html .= "\n"; - $html .= "\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 ( - "\n", - $vmid, - $name, - format_time($task->{backuptime}), - format_size ($task->{size}), - escape_html ($task->{target}), - ); - } else { - $html .= sprintf ( - "\n", - $vmid, - $name, - format_time($task->{backuptime}), - escape_html ($task->{msg}), - ); - } - } +use constant MAX_LOG_SIZE => 1024*1024; - $html .= sprintf ("", - format_time ($totaltime), format_size ($ssize)); +sub send_notification { + my ($self, $tasklist, $total_time, $err, $detail_pre, $detail_post) = @_; - $html .= "\n
VMIDNAMESTATUSTIMESIZEFILENAME
%s%sOK%s%s%s
%s%sFAILED%s%s
TOTAL%s%s


\n"; - my $html_log_part; - $html_log_part .= "Detailed backup logs:

\n"; - $html_log_part .= "
\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: ".
-			escape_html ($line) . "");
-		} 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 .= "
"; - my $html_end = "\n\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 .= "

$msg

"; - $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