[pve-devel] [PATCH manager v2] Fix #352: Limit the length of backup logs for mails

Dominic Jäger d.jaeger at proxmox.com
Tue May 21 13:16:13 CEST 2019


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 <t.lamprecht at proxmox.com>
Signed-off-by: Dominic Jäger <d.jaeger at proxmox.com>
---
I was not sure if Thomas' idea with the ANDs was meant as "we could" or
"we should" use that and took the easier version as a consequence.

v1->v2
Check mail size in the end instead of limiting line lengths and
each log upon insertion.

 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 0a35eea7..16035458 100644
--- a/PVE/VZDump.pm
+++ b/PVE/VZDump.pm
@@ -341,6 +341,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) = @_;
 
@@ -402,23 +403,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 = <TMP>) { $text .= encode8bit ("$vmid: $line"); }
+	if (open (TMP, "$log")) {
+	    while (my $line = <TMP>) {
+		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 = "<html><body>\n";
@@ -451,35 +459,54 @@ sub sendmail {
     $html .= sprintf ("<tr><td align=left colspan=3>TOTAL<td>%s<td>%s<td></tr>",
  format_time ($totaltime), format_size ($ssize));
 
-    $html .= "</table><br><br>\n";
-    $html .= "Detailed backup logs:<br /><br />\n";
-    $html .= "<pre>\n";
-    $html .= escape_html($cmdline) . "\n\n";
+    $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";
 
-    $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 = <TMP>) {
-	    if ($line =~ m/^\S+\s\d+\s+\d+:\d+:\d+\s+(ERROR|WARN):/) {
-		$html .= encode8bit ("$vmid: <font color=red>".
-				       escape_html ($line) . "</font>");
-	    } else {
-		$html .= encode8bit ("$vmid: " . escape_html ($line));
+	if (open (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));
+		}
 	    }
+	} 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 .= "</pre></body></html>\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) < 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 .= "<p>$msg</p>";
+	$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 at 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.11.0




More information about the pve-devel mailing list