From 7e4113467cb9b2fc78c393c7f1c1eadc8c9658ec Mon Sep 17 00:00:00 2001 From: =?utf8?q?Dominic=20J=C3=A4ger?= Date: Tue, 21 May 2019 13:16:13 +0200 Subject: [PATCH] Fix #352: Limit the length of backup logs for mails MIME-Version: 1.0 Content-Type: text/plain; charset=utf8 Content-Transfer-Encoding: 8bit When creating a backup the log part can make the mail too big to be transferred. To ensure delivery, two measures are taken: 1. Always omit the status lines 2. Omit the whole log part if a mail becomes (too) big Additionally, add a check for missing log files. Co-developed-by: Thomas Lamprecht Signed-off-by: Dominic Jäger --- PVE/VZDump.pm | 75 ++++++++++++++++++++++++++++++++--------------- test/Makefile | 2 +- test/mail_test.pl | 75 +++++++++++++++++++++++++++++++++++++++++++++++ 3 files changed, 127 insertions(+), 25 deletions(-) create mode 100755 test/mail_test.pl diff --git a/PVE/VZDump.pm b/PVE/VZDump.pm index 22003a65..7ba54eff 100644 --- a/PVE/VZDump.pm +++ b/PVE/VZDump.pm @@ -194,6 +194,7 @@ sub read_vzdump_defaults { return $res; } +use constant MAX_MAIL_SIZE => 1024*1024; sub sendmail { my ($self, $tasklist, $totaltime, $err, $detail_pre, $detail_post) = @_; @@ -255,23 +256,30 @@ sub sendmail { } } - $text .= "\nDetailed backup logs:\n\n"; - $text .= "$cmdline\n\n"; + my $text_log_part; + $text_log_part .= "\nDetailed backup logs:\n\n"; + $text_log_part .= "$cmdline\n\n"; - $text .= $detail_pre . "\n" if defined($detail_pre); + $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 .= "$vmid: no log available\n\n"; + $text_log_part .= "$vmid: no log available\n\n"; next; } - open (TMP, "$log"); - while (my $line = ) { $text .= encode8bit ("$vmid: $line"); } + if (open (TMP, "$log")) { + while (my $line = ) { + next if $line =~ /^status: \d+/; # not useful in mails + $text_log_part .= encode8bit ("$vmid: $line"); + } + } else { + $text_log_part .= "$vmid: Could not open log file\n\n"; + } close (TMP); - $text .= "\n"; + $text_log_part .= "\n"; } - $text .= $detail_post if defined($detail_post); + $text_log_part .= $detail_post if defined($detail_post); # html part my $html = "\n"; @@ -304,35 +312,54 @@ sub sendmail { $html .= sprintf ("TOTAL%s%s", format_time ($totaltime), format_size ($ssize)); - $html .= "

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

\n"; - $html .= "
\n";
-    $html .= escape_html($cmdline) . "\n\n";
+    $html .= "\n

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

\n";
+    $html_log_part .= "
\n";
+    $html_log_part .= escape_html($cmdline) . "\n\n";
 
-    $html .= escape_html($detail_pre) . "\n" if defined($detail_pre);
+    $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 .= "$vmid: no log available\n\n";
+	    $html_log_part .= "$vmid: no log available\n\n";
 	    next;
 	}
-	open (TMP, "$log");
-	while (my $line = ) {
-	    if ($line =~ m/^\S+\s\d+\s+\d+:\d+:\d+\s+(ERROR|WARN):/) {
-		$html .= encode8bit ("$vmid: ".
-				       escape_html ($line) . "");
-	    } else {
-		$html .= encode8bit ("$vmid: " . escape_html ($line));
+	if (open (TMP, "$log")) {
+	    while (my $line = ) {
+		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));
+		}
 	    }
+	} else {
+	    $html_log_part .= "$vmid: Could not open log file\n\n";
 	}
 	close (TMP);
-	$html .= "\n";
+	$html_log_part .= "\n";
     }
-    $html .= escape_html($detail_post) if defined($detail_post);
-    $html .= "
\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) < MAX_MAIL_SIZE) + { + $html .= $html_log_part; + $text .= $text_log_part; + } else { + my $msg = "Log output was too long to be sent by mail. ". + "See Task History for details!\n"; + $text .= $msg; + $html .= "

$msg

"; + $html .= $html_end; + } + my $subject = "vzdump backup status ($hostname) : $stat"; my $dcconf = PVE::Cluster::cfs_read_file('datacenter.cfg'); diff --git a/test/Makefile b/test/Makefile index cd934838..a3f104b4 100644 --- a/test/Makefile +++ b/test/Makefile @@ -12,7 +12,7 @@ check: ./replication_test4.pl ./replication_test5.pl ./replication_test6.pl - + ./mail_test.pl .PHONY: install install: diff --git a/test/mail_test.pl b/test/mail_test.pl new file mode 100755 index 00000000..58bfaafa --- /dev/null +++ b/test/mail_test.pl @@ -0,0 +1,75 @@ +#!/usr/bin/perl + +use strict; +use warnings; +use PVE::VZDump; +use Test::More tests => 5; +use Test::MockModule; + +my $STATUS = qr/.*status.*/; +my $NO_LOGFILE = qr/.*Could not open log file.*/; +my $LOG_TOO_LONG = qr/.*Log output was too long.*/; +my $TEST_FILE_PATH = '/tmp/mail_test'; +my $TEST_FILE_WRONG_PATH = '/tmp/mail_test_wrong'; +sub prepare_mail_with_status { + open(TEST_FILE, '>', $TEST_FILE_PATH); # Removes previous content + print TEST_FILE "start of log file\n"; + print TEST_FILE "status: 0\% this should not be in the mail\n"; + print TEST_FILE "status: 55\% this should not be in the mail\n"; + print TEST_FILE "status: 100\% this should not be in the mail\n"; + print TEST_FILE "end of log file\n"; + close(TEST_FILE); +} +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); + close(TEST_FILE); +} +{ + my $result_text; + my $result_html; + my $mock_module = Test::MockModule->new('PVE::Tools'); + $mock_module->mock('sendmail', sub { + my (undef, undef, $text, $html, undef, undef) = @_; + $result_text = $text; + $result_html = $html; + }); + my $MAILTO = ['test_address@proxmox.com']; + my $OPTS->{mailto} = $MAILTO; + my $SELF->{opts} = $OPTS; + $SELF->{cmdline} = 'test_command_on_cli'; + my $task; + $task->{state} = 'ok'; + $task->{vmid} = '1'; + { + $result_text = undef; + $result_html = undef; + $task->{tmplog} = $TEST_FILE_WRONG_PATH; + my $tasklist = [$task]; + PVE::VZDump::sendmail($SELF, $tasklist, 0, undef, undef, undef); + like($result_text, $NO_LOGFILE, "Missing logfile is detected"); + } + { + $result_text = undef; + $result_html = undef; + $task->{tmplog} = $TEST_FILE_PATH; + my $tasklist = [$task]; + 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"); + unlink $TEST_FILE_PATH; + } + { + $result_text = undef; + $result_html = undef; + $task->{tmplog} = $TEST_FILE_PATH; + my $tasklist = [$task]; + 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"); + unlink $TEST_FILE_PATH; + } +} \ No newline at end of file -- 2.39.5