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

Dominik Csapak d.csapak at proxmox.com
Fri May 17 12:16:09 CEST 2019


first of all, great that you include tests :) +1

second, i am not really happy with the approach, since it
is quite a bit of code, for not that much gain

On 5/14/19 12:20 PM, Dominic Jäger wrote:
> 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.

one approach i would favor is to generate the mail, check the size,
and only send the initial overview table with a notice that the
mail was too long and where to find the log

with your approach, the mail sending is much more complicated,
for very little gain (a user must probably look for the full
task log anyway if he wants to get the information) and
does not even prevent the problem if someone has many vms that
get backed up (or am i missing that bit?)

in any case, one comment about the code itself is inline

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

why hardcoded here?

the MAX_LOG_LINES and MAX_LINE_LENGTH are global constants,
but the $LINES_AT_END (below) is defined in the function

i would rather have them as parameter, so that
someone can tune this (if necessary)

> +# 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");
> 





More information about the pve-devel mailing list