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

Dominic Jäger d.jaeger at proxmox.com
Tue May 14 12:20:08 CEST 2019


When creating a backup the log for a single job can be to big to be
transferred by mail. To ensure that mails get delivered nonetheless
the amount of lines and their length are limited.

Signed-off-by: Dominic Jäger <d.jaeger at proxmox.com>
---
The alternative way would have been to build the whole mail, check the          
size, then go into the string back again to identify parts of which the
size explodes.           
Limiting while building up the string seemed more straightforward and            
efficient to me. The loss of information is none, as everything is              
in the task history anyway.

 PVE/VZDump.pm     | 106 +++++++++++++++++++++++++++++++++++++++++++++++-------
 test/Makefile     |   1 +
 test/mail_test.pl |  70 ++++++++++++++++++++++++++++++++++++
 3 files changed, 164 insertions(+), 13 deletions(-)
 create mode 100755 test/mail_test.pl

diff --git a/PVE/VZDump.pm b/PVE/VZDump.pm
index 6508c833..62097ad7 100644
--- a/PVE/VZDump.pm
+++ b/PVE/VZDump.pm
@@ -341,6 +341,96 @@ sub read_vzdump_defaults {
     return $res;
 }
 
+use constant MAX_LINE_LENGTH => 200;
+# Returns an adequate (not too long, contains html formatting)
+# version of $line:
+sub format_single_line {
+    my ($line, $html_or_text, $vmid) = @_;
+
+    my $vmid_string = "$vmid: ";
+    my $replace_string = "(...)\n";
+    my $diff = length($line) + length($vmid_string) - MAX_LINE_LENGTH;
+    if ($diff > 0) {
+	substr($line, -($diff+length($replace_string) + length($vmid_string)))
+	    = $replace_string;
+    }
+    my $result = "";
+    if ($html_or_text eq "html") {
+	# Assume MAX_LINE_LENGTH is bigger than this initial part
+	if ($line =~ m/^.+(ERROR|WARN):.*/) {
+	    $result .= encode8bit("$vmid: <font color=red>".escape_html ($line)."</font>");
+	} else {
+	    $result .= encode8bit($vmid_string . escape_html ($line));
+	}
+    } else {
+	$result .= encode8bit($vmid_string . $line);
+    }
+    return $result;
+}
+
+use constant MAX_LOG_LINES => 100;
+# Returns a version of all the lines of a task's log file with limited size.
+# Limits includes line length and amount of lines.
+# Limited mails look like this:
+#
+# Mail starts
+# and really long long long long lines get truncated like this (...)
+# and
+# when it reaches
+# some amount of lines
+# it starts to truncate
+# .
+# .
+# .
+# (...)
+# .
+# .
+# .
+# And then there are
+# LINES_AT_END lines in the
+# end again (e.g summaries)
+#
+#
+# $html_or_text decide if this is for the html or text part of a mail
+# $log_file handler for a task's log file
+# $vmid which VM this log is for
+sub format_lines {
+    my ($html_or_text, $log, $vmid) = @_;
+    my $result = "";
+    my $log_lines = `wc -l < $log`;
+    $log_lines =~ s/[^0-9]//g; # Remove white space to make it a valid number
+    my $line_diff = MAX_LOG_LINES - $log_lines;
+    open (TMP, '<', "$log") or die "Can't open $log!";
+    if ($line_diff >= 0) {
+	while (my $line = <TMP>) {
+	    $result .= format_single_line($line, $html_or_text, $vmid);
+	}
+    } else {
+	my $LINES_AT_END         = 10;
+	my $line_counter         = 0;
+	my $omit_message_printed = 0;
+	my $print_until       = MAX_LOG_LINES - $LINES_AT_END;
+	my $omit_until        = MAX_LOG_LINES - $LINES_AT_END - $line_diff;
+	my $print_again_until = MAX_LOG_LINES;
+	while (my $line = <TMP>) {
+	    if ($line_counter > $print_until && $line_counter <= $omit_until) {
+		if (!$omit_message_printed) {
+		    # Spaces in string keep html part of mail intact
+		    $result .= encode8bit(". \n. \n. \n(Omitted ".-$line_diff." lines.".
+			" Consult task history for all information!)\n. \n. \n. \n");
+		    $omit_message_printed = 1;
+		}
+	    } else {
+		    $result .= format_single_line($line, $html_or_text, $vmid);
+	    }
+	$line_counter++;
+	}
+    }
+    close (TMP);
+
+    return $result;
+}
+
 sub sendmail {
     my ($self, $tasklist, $totaltime, $err, $detail_pre, $detail_post) = @_;
 
@@ -413,9 +503,7 @@ sub sendmail {
 	    $text .= "$vmid: no log available\n\n";
 	    next;
 	}
-	open (TMP, "$log");
-	while (my $line = <TMP>) { $text .= encode8bit ("$vmid: $line"); }
-	close (TMP);
+	$text .= format_lines("text", $log, $vmid);
 	$text .= "\n";
     }
     $text .= $detail_post if defined($detail_post);
@@ -464,20 +552,12 @@ sub sendmail {
 	    $html .= "$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));
-	    }
-	}
-	close (TMP);
+	$html .= format_lines("html", $log, $vmid);
 	$html .= "\n";
     }
     $html .= escape_html($detail_post) if defined($detail_post);
     $html .= "</pre></body></html>\n";
+
     # end html part
 
     my $subject = "vzdump backup status ($hostname) : $stat";
diff --git a/test/Makefile b/test/Makefile
index cd934838..99c64568 100644
--- a/test/Makefile
+++ b/test/Makefile
@@ -12,6 +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..0ef7c06f
--- /dev/null
+++ b/test/mail_test.pl
@@ -0,0 +1,70 @@
+#!/usr/bin/perl
+
+use strict;
+use warnings;
+use PVE::VZDump;
+use Test::More tests => 15;
+
+my $TEXT_INDICATOR = "text";
+my $HTML_INDICATOR = "html";
+my $VM_ID = "123";
+my $START_STRING = "asdf";
+# The message that some lines were omitted takes some lines
+# Those are added on top of the maximum line count MAX_MAIL_LIENS
+my $OMIT_MESSAGE_LINES = 7;
+
+my $SOME_LINE = "jklö";
+my $WITH_SOME_LINE = qr/.*$SOME_LINE.*/;
+like(PVE::VZDump::format_single_line ($SOME_LINE, $TEXT_INDICATOR, $VM_ID),
+    $WITH_SOME_LINE, "Text result still contains original input");
+like(PVE::VZDump::format_single_line ($SOME_LINE, $HTML_INDICATOR, $VM_ID),
+    $WITH_SOME_LINE, "HTML result still contains original input");
+
+my $JUST_SHORT_ENOUGH_LINE     = 'A' x (PVE::VZDump::MAX_LINE_LENGTH - 1);
+my $LINE_WITH_MAX_LENGTH       = 'A' x (PVE::VZDump::MAX_LINE_LENGTH);
+my $LINE_ABOVE_MAX_LENGTH      = 'A' x (PVE::VZDump::MAX_LINE_LENGTH + 1);
+my $LINE_MUCH_ABOVE_MAX_LENGTH = 'A' x (PVE::VZDump::MAX_LINE_LENGTH + 500);
+
+cmp_ok(PVE::VZDump::MAX_LINE_LENGTH, ">", 0, "Reasonable maximum line length");
+cmp_ok(length(PVE::VZDump::format_single_line ($JUST_SHORT_ENOUGH_LINE,
+    $TEXT_INDICATOR, $VM_ID)), "<=", PVE::VZDump::MAX_LINE_LENGTH,
+    "Short lines stay short");
+cmp_ok(length(PVE::VZDump::format_single_line ($LINE_WITH_MAX_LENGTH,
+    $TEXT_INDICATOR, $VM_ID)), "<=", PVE::VZDump::MAX_LINE_LENGTH,
+    "Line with max length stays short (is even shortened due to vm id)");
+cmp_ok(length(PVE::VZDump::format_single_line ($LINE_ABOVE_MAX_LENGTH,
+    $TEXT_INDICATOR, $VM_ID)), "<=", PVE::VZDump::MAX_LINE_LENGTH,
+    "Too long line is shortened");
+cmp_ok(length(PVE::VZDump::format_single_line ($LINE_MUCH_ABOVE_MAX_LENGTH,
+    $TEXT_INDICATOR, $VM_ID)), "<=", PVE::VZDump::MAX_LINE_LENGTH,
+    "Much too long line is shortened");
+
+my $START_WITH_WARN  = "20190430 11:23:38 WARN:";
+my $START_WITH_ERROR = "2019-04-30 11:23:38 ERROR:";
+my $WITH_RED_COLOR = qr/.*color=red.*/;
+like(PVE::VZDump::format_single_line ($START_WITH_WARN, $HTML_INDICATOR, $VM_ID),
+    $WITH_RED_COLOR, "Warnings printed red");
+like(PVE::VZDump::format_single_line ($START_WITH_ERROR, $HTML_INDICATOR, $VM_ID),
+    $WITH_RED_COLOR, "Errors printed red");
+
+cmp_ok(PVE::VZDump::MAX_LOG_LINES, ">", 1, "Useful amount of maximum mail lines");
+
+my $TEST_FILE_PATH = '/tmp/mail_test';
+sub prepare_test_mail {
+    my ($number_of_lines) = @_;
+    my $TEST_LINE = 'A'x24 . "\n"; # 4 byte * 25 characters= 100 byte
+    open(TEST_FILE, '>', $TEST_FILE_PATH); # Removes previous content
+    print TEST_FILE $TEST_LINE x $number_of_lines;
+    close(TEST_FILE);
+}
+
+prepare_test_mail(PVE::VZDump::MAX_LOG_LINES - 1);
+is(PVE::VZDump::format_lines($TEXT_INDICATOR, $TEST_FILE_PATH, $VM_ID) =~ tr/\n//, PVE::VZDump::MAX_LOG_LINES - 1, "Mails with not to many lines stay the same");
+prepare_test_mail(PVE::VZDump::MAX_LOG_LINES);
+is(PVE::VZDump::format_lines($TEXT_INDICATOR, $TEST_FILE_PATH, $VM_ID) =~ tr/\n//, PVE::VZDump::MAX_LOG_LINES, "Mails with exactly the maximum amount of lines stay the same");
+prepare_test_mail(PVE::VZDump::MAX_LOG_LINES + 1);
+is(PVE::VZDump::format_lines($TEXT_INDICATOR, $TEST_FILE_PATH, $VM_ID) =~ tr/\n//, PVE::VZDump::MAX_LOG_LINES + $OMIT_MESSAGE_LINES, "Mails with one line to many are shortened");
+prepare_test_mail(PVE::VZDump::MAX_LOG_LINES + 2);
+is(PVE::VZDump::format_lines($TEXT_INDICATOR, $TEST_FILE_PATH, $VM_ID) =~ tr/\n//, PVE::VZDump::MAX_LOG_LINES + $OMIT_MESSAGE_LINES, "Mails with two lines to many are shortened");
+prepare_test_mail(PVE::VZDump::MAX_LOG_LINES + 300);
+is(PVE::VZDump::format_lines($TEXT_INDICATOR, $TEST_FILE_PATH, $VM_ID) =~ tr/\n//, PVE::VZDump::MAX_LOG_LINES + $OMIT_MESSAGE_LINES, "Mails with way too many lines are shortened");
-- 
2.11.0




More information about the pve-devel mailing list