2015-10-08 17:43:56 +02:00
|
|
|
####################################################################################################################################
|
2015-10-28 11:10:36 +02:00
|
|
|
# LogTest.pm - Capture the output of commands to compare them with an expected version
|
2015-10-08 17:43:56 +02:00
|
|
|
####################################################################################################################################
|
|
|
|
package BackRestTest::Common::LogTest;
|
|
|
|
|
|
|
|
####################################################################################################################################
|
|
|
|
# Perl includes
|
|
|
|
####################################################################################################################################
|
|
|
|
use strict;
|
|
|
|
use warnings FATAL => qw(all);
|
|
|
|
use Carp qw(confess);
|
|
|
|
|
|
|
|
use Cwd qw(abs_path);
|
|
|
|
use Exporter qw(import);
|
|
|
|
our @EXPORT = qw();
|
|
|
|
use File::Basename qw(dirname);
|
|
|
|
|
|
|
|
use lib dirname($0) . '/../lib';
|
|
|
|
use BackRest::Common::Ini;
|
|
|
|
use BackRest::Common::Log;
|
|
|
|
use BackRest::Config::Config;
|
|
|
|
|
|
|
|
use BackRestTest::Common::ExecuteTest;
|
|
|
|
|
|
|
|
####################################################################################################################################
|
|
|
|
# Operation constants
|
|
|
|
####################################################################################################################################
|
|
|
|
use constant OP_LOG_TEST => 'LogTest';
|
|
|
|
|
|
|
|
use constant OP_LOG_TEST_LOG_ADD => OP_LOG_TEST . "->logAdd";
|
|
|
|
use constant OP_LOG_TEST_LOG_WRITE => OP_LOG_TEST . "->logWrite";
|
|
|
|
use constant OP_LOG_TEST_NEW => OP_LOG_TEST . "->new";
|
|
|
|
|
|
|
|
####################################################################################################################################
|
|
|
|
# new
|
|
|
|
####################################################################################################################################
|
|
|
|
sub new
|
|
|
|
{
|
|
|
|
my $class = shift; # Class name
|
|
|
|
|
|
|
|
# Create the class hash
|
|
|
|
my $self = {};
|
|
|
|
bless $self, $class;
|
|
|
|
|
|
|
|
# Assign function parameters, defaults, and log debug info
|
|
|
|
(
|
|
|
|
my $strOperation,
|
|
|
|
$self->{strModule},
|
|
|
|
$self->{strTest},
|
|
|
|
$self->{iRun},
|
|
|
|
$self->{bForce},
|
|
|
|
$self->{strComment},
|
|
|
|
$self->{strCommandMain},
|
|
|
|
$self->{strCommandRemote},
|
|
|
|
$self->{strPgSqlBin},
|
|
|
|
$self->{strTestPath},
|
|
|
|
$self->{strRepoPath}
|
|
|
|
) =
|
|
|
|
logDebugParam
|
|
|
|
(
|
|
|
|
OP_LOG_TEST_NEW, \@_,
|
|
|
|
{name => 'strModule', trace => true},
|
|
|
|
{name => 'strTest', trace => true},
|
|
|
|
{name => 'iRun', trace => true},
|
|
|
|
{name => 'bForce', trace => true},
|
|
|
|
{name => 'strComment', trace => true},
|
|
|
|
{name => 'strCommandMain', trace => true},
|
|
|
|
{name => 'strCommandRemote', trace => true},
|
|
|
|
{name => 'strPgSqlBin', trace => true},
|
|
|
|
{name => 'strTestPath', trace => true},
|
|
|
|
{name => 'strRepoPath', trace => true}
|
|
|
|
);
|
|
|
|
|
|
|
|
# Initialize the test log
|
|
|
|
$self->{strLog} = 'run ' . sprintf('%03d', $self->{iRun}) . ' - ' . $self->{strComment};
|
|
|
|
$self->{strLog} .= "\n" . ('=' x length($self->{strLog})) . "\n";
|
|
|
|
|
|
|
|
# Initialize the replacement hash
|
|
|
|
$self->{oReplaceHash} = {};
|
|
|
|
|
|
|
|
# Return from function and log return values if any
|
|
|
|
return logDebugReturn
|
|
|
|
(
|
|
|
|
$strOperation,
|
|
|
|
{name => 'self', value => $self, trace => true}
|
|
|
|
);
|
|
|
|
}
|
|
|
|
|
|
|
|
####################################################################################################################################
|
|
|
|
# logAdd
|
|
|
|
####################################################################################################################################
|
|
|
|
sub logAdd
|
|
|
|
{
|
|
|
|
my $self = shift;
|
|
|
|
|
|
|
|
# Assign function parameters, defaults, and log debug info
|
|
|
|
my
|
|
|
|
(
|
|
|
|
$strOperation,
|
|
|
|
$strCommand,
|
|
|
|
$strComment,
|
|
|
|
$strLog
|
|
|
|
) =
|
|
|
|
logDebugParam
|
|
|
|
(
|
|
|
|
OP_LOG_TEST_LOG_ADD, \@_,
|
|
|
|
{name => 'strCommand', trace => true},
|
|
|
|
{name => 'strComment', required => false, trace => true},
|
|
|
|
{name => 'strLog', required => false, trace => true}
|
|
|
|
);
|
|
|
|
|
|
|
|
$self->{strLog} .= "\n";
|
|
|
|
|
|
|
|
if (defined($strComment))
|
|
|
|
{
|
|
|
|
$self->{strLog} .= $self->regExpReplaceAll($strComment) . "\n";
|
|
|
|
}
|
|
|
|
|
|
|
|
$self->{strLog} .= '> ' . $self->regExpReplaceAll($strCommand) . "\n" . ('-' x '132') . "\n";
|
|
|
|
|
|
|
|
# Make sure there is a log before trying to output it
|
|
|
|
if (defined($strLog))
|
|
|
|
{
|
|
|
|
# Do replacements on each line of the log
|
|
|
|
foreach my $strLine (split("\n", $strLog))
|
|
|
|
{
|
|
|
|
$strLine =~ s/^[0-9]{4}-[0-1][0-9]-[0-3][0-9] [0-2][0-9]:[0-6][0-9]:[0-6][0-9]\.[0-9]{3} T[0-9]{2} //;
|
|
|
|
|
|
|
|
if ($strLine !~ /^ TEST/)
|
|
|
|
{
|
|
|
|
$strLine =~ s/^ //;
|
|
|
|
$strLine =~ s/\r$//;
|
|
|
|
|
|
|
|
$strLine = $self->regExpReplaceAll($strLine);
|
|
|
|
|
|
|
|
$self->{strLog} .= "${strLine}\n";
|
|
|
|
}
|
|
|
|
}
|
|
|
|
}
|
|
|
|
|
|
|
|
# Return from function and log return values if any
|
|
|
|
logDebugReturn($strOperation);
|
|
|
|
}
|
|
|
|
|
|
|
|
####################################################################################################################################
|
|
|
|
# supplementalAdd
|
|
|
|
####################################################################################################################################
|
|
|
|
sub supplementalAdd
|
|
|
|
{
|
|
|
|
my $self = shift;
|
|
|
|
my $strFileName = shift;
|
|
|
|
my $bRemote = shift;
|
|
|
|
my $strComment = shift;
|
|
|
|
|
|
|
|
if ($bRemote)
|
|
|
|
{
|
|
|
|
executeTest("chmod g+x " . $self->{strRepoPath},
|
|
|
|
{bRemote => true});
|
|
|
|
}
|
|
|
|
|
|
|
|
open(my $hFile, '<', $strFileName)
|
|
|
|
or confess &log(ERROR, "unable to open ${strFileName} for appending to test log");
|
|
|
|
|
|
|
|
my $strHeader .= "+ supplemental file: " . $self->regExpReplaceAll($strFileName);
|
|
|
|
|
|
|
|
if (defined($strComment))
|
|
|
|
{
|
|
|
|
$self->{strLog} .= "\n" . $self->regExpReplaceAll($strComment) . "\n" . ('=' x '132') . "\n";
|
|
|
|
}
|
|
|
|
|
|
|
|
$self->{strLog} .= "\n${strHeader}\n" . ('-' x length($strHeader)) . "\n";
|
|
|
|
|
|
|
|
while (my $strLine = readline($hFile))
|
|
|
|
{
|
|
|
|
$self->{strLog} .= $self->regExpReplaceAll($strLine);
|
|
|
|
}
|
|
|
|
|
|
|
|
close($hFile);
|
|
|
|
|
|
|
|
if ($bRemote)
|
|
|
|
{
|
|
|
|
executeTest("chmod g-x " . $self->{strRepoPath},
|
|
|
|
{bRemote => true});
|
|
|
|
|
|
|
|
}
|
|
|
|
}
|
|
|
|
|
|
|
|
####################################################################################################################################
|
|
|
|
# logWrite
|
|
|
|
####################################################################################################################################
|
|
|
|
sub logWrite
|
|
|
|
{
|
|
|
|
my $self = shift;
|
|
|
|
|
|
|
|
# Assign function parameters, defaults, and log debug info
|
|
|
|
my
|
|
|
|
(
|
|
|
|
$strOperation,
|
|
|
|
$strBasePath,
|
|
|
|
$strTestPath,
|
|
|
|
$strFileName
|
|
|
|
) =
|
|
|
|
logDebugParam
|
|
|
|
(
|
|
|
|
OP_LOG_TEST_LOG_WRITE, \@_,
|
|
|
|
{name => 'strBasePath', trace => true},
|
|
|
|
{name => 'strTestPath', trace => true},
|
|
|
|
{name => 'strFileName',
|
2016-04-06 16:00:11 +02:00
|
|
|
default => sprintf("expect/$self->{strModule}-$self->{strTest}-%03d.log", $self->{iRun}), trace => true}
|
2015-10-08 17:43:56 +02:00
|
|
|
);
|
|
|
|
|
2015-11-22 21:02:14 +02:00
|
|
|
my $strReferenceLogFile = "${strBasePath}/test/${strFileName}";
|
|
|
|
my $strTestLogFile;
|
|
|
|
|
2015-10-08 17:43:56 +02:00
|
|
|
if ($self->{bForce})
|
|
|
|
{
|
2015-11-22 21:02:14 +02:00
|
|
|
$strTestLogFile = $strReferenceLogFile;
|
2015-10-08 17:43:56 +02:00
|
|
|
}
|
|
|
|
else
|
|
|
|
{
|
2016-04-06 16:00:11 +02:00
|
|
|
my $strTestLogPath = "${strTestPath}/expect";
|
2015-10-08 17:43:56 +02:00
|
|
|
|
|
|
|
if (!-e $strTestLogPath)
|
|
|
|
{
|
|
|
|
mkdir($strTestLogPath) or
|
2016-04-06 16:00:11 +02:00
|
|
|
confess "unable to create expect log path ${strTestLogPath}";
|
2015-10-08 17:43:56 +02:00
|
|
|
}
|
|
|
|
|
2015-11-22 21:02:14 +02:00
|
|
|
$strTestLogFile = "${strTestPath}/${strFileName}";
|
2015-10-08 17:43:56 +02:00
|
|
|
}
|
|
|
|
|
2015-11-22 21:02:14 +02:00
|
|
|
open(my $hFile, '>', $strTestLogFile)
|
2016-04-06 16:00:11 +02:00
|
|
|
or confess "unable to open expect log file '${strTestLogFile}': $!";
|
2015-10-08 17:43:56 +02:00
|
|
|
|
|
|
|
syswrite($hFile, $self->{strLog})
|
2016-04-06 16:00:11 +02:00
|
|
|
or confess "unable to write expect log file '${strTestLogFile}': $!";
|
2015-10-08 17:43:56 +02:00
|
|
|
|
|
|
|
close($hFile);
|
|
|
|
|
2015-11-22 21:02:14 +02:00
|
|
|
if (!$self->{bForce})
|
|
|
|
{
|
|
|
|
executeTest("diff ${strReferenceLogFile} ${strTestLogFile}");
|
|
|
|
}
|
|
|
|
|
2015-10-08 17:43:56 +02:00
|
|
|
# Return from function and log return values if any
|
|
|
|
logDebugReturn($strOperation);
|
|
|
|
}
|
|
|
|
|
|
|
|
####################################################################################################################################
|
|
|
|
# regExpReplace
|
|
|
|
####################################################################################################################################
|
|
|
|
sub regExpReplace
|
|
|
|
{
|
|
|
|
my $self = shift;
|
|
|
|
my $strLine = shift;
|
|
|
|
my $strType = shift;
|
|
|
|
my $strExpression = shift;
|
|
|
|
my $strToken = shift;
|
|
|
|
my $bIndex = shift;
|
|
|
|
|
|
|
|
my @stryReplace = ($strLine =~ /$strExpression/g);
|
|
|
|
|
|
|
|
foreach my $strReplace (@stryReplace)
|
|
|
|
{
|
|
|
|
my $iIndex;
|
|
|
|
my $strTypeReplacement;
|
|
|
|
my $strReplacement;
|
|
|
|
|
|
|
|
if (!defined($bIndex) || $bIndex)
|
|
|
|
{
|
|
|
|
if (defined($strToken))
|
|
|
|
{
|
|
|
|
my @stryReplacement = ($strReplace =~ /$strToken/g);
|
|
|
|
|
|
|
|
if (@stryReplacement != 1)
|
|
|
|
{
|
|
|
|
confess &log(ASSERT, "'${strToken}' is not a sub-regexp of '${strExpression}' or" .
|
|
|
|
" matches multiple times on '${strReplace}'");
|
|
|
|
}
|
|
|
|
|
|
|
|
$strReplacement = $stryReplacement[0];
|
|
|
|
}
|
|
|
|
else
|
|
|
|
{
|
|
|
|
$strReplacement = $strReplace;
|
|
|
|
}
|
|
|
|
|
|
|
|
if (defined(${$self->{oReplaceHash}}{$strType}{$strReplacement}))
|
|
|
|
{
|
|
|
|
$iIndex = ${$self->{oReplaceHash}}{$strType}{$strReplacement}{index};
|
|
|
|
}
|
|
|
|
else
|
|
|
|
{
|
|
|
|
if (!defined(${$self->{oReplaceHash}}{$strType}{index}))
|
|
|
|
{
|
|
|
|
${$self->{oReplaceHash}}{$strType}{index} = 1;
|
|
|
|
}
|
|
|
|
|
|
|
|
$iIndex = ${$self->{oReplaceHash}}{$strType}{index}++;
|
|
|
|
${$self->{oReplaceHash}}{$strType}{$strReplacement}{index} = $iIndex;
|
|
|
|
}
|
|
|
|
}
|
|
|
|
|
|
|
|
$strTypeReplacement = "[${strType}" . (defined($iIndex) ? "-${iIndex}" : '') . ']';
|
|
|
|
|
|
|
|
if (defined($strToken))
|
|
|
|
{
|
|
|
|
$strReplacement = $strReplace;
|
|
|
|
$strReplacement =~ s/$strToken/$strTypeReplacement/;
|
|
|
|
}
|
|
|
|
else
|
|
|
|
{
|
|
|
|
$strReplacement = $strTypeReplacement;
|
|
|
|
}
|
|
|
|
|
|
|
|
$strLine =~ s/$strReplace/$strReplacement/g;
|
|
|
|
}
|
|
|
|
|
|
|
|
return $strLine;
|
|
|
|
}
|
|
|
|
|
|
|
|
####################################################################################################################################
|
|
|
|
# regExpReplaceAll
|
|
|
|
####################################################################################################################################
|
|
|
|
sub regExpReplaceAll
|
|
|
|
{
|
|
|
|
my $self = shift;
|
|
|
|
my $strLine = shift;
|
|
|
|
|
|
|
|
my $strBinPath = dirname(dirname(abs_path($0))) . '/bin';
|
|
|
|
|
|
|
|
$strLine =~ s/$self->{strCommandMain}/[BACKREST_BIN]/g;
|
|
|
|
$strLine =~ s/$self->{strCommandRemote}/[BACKREST_BIN]/g;
|
|
|
|
$strLine =~ s/$self->{strPgSqlBin}/[PGSQL_BIN_PATH]/g;
|
|
|
|
$strLine =~ s/$self->{strTestPath}/[TEST_PATH]/g;
|
|
|
|
|
|
|
|
$strLine = $self->regExpReplace($strLine, 'BACKREST_NAME_VERSION', '^' . BACKREST_NAME . ' ' . BACKREST_VERSION,
|
|
|
|
undef, false);
|
|
|
|
|
|
|
|
$strLine = $self->regExpReplace($strLine, 'PROCESS-ID', 'process [0-9]+', '[0-9]+$', false);
|
|
|
|
$strLine = $self->regExpReplace($strLine, 'MODIFICATION-TIME', 'lModificationTime = [0-9]+', '[0-9]+$');
|
2016-02-06 06:03:29 +02:00
|
|
|
$strLine = $self->regExpReplace($strLine, 'MODIFICATION-TIME', 'and modification time [0-9]+', '[0-9]+$');
|
2015-10-08 17:43:56 +02:00
|
|
|
$strLine = $self->regExpReplace($strLine, 'TIMESTAMP', 'timestamp"[ ]{0,1}:[ ]{0,1}[0-9]+','[0-9]+$');
|
|
|
|
|
|
|
|
$strLine = $self->regExpReplace($strLine, 'BACKUP-INCR', '[0-9]{8}\-[0-9]{6}F\_[0-9]{8}\-[0-9]{6}I');
|
|
|
|
$strLine = $self->regExpReplace($strLine, 'BACKUP-DIFF', '[0-9]{8}\-[0-9]{6}F\_[0-9]{8}\-[0-9]{6}D');
|
|
|
|
$strLine = $self->regExpReplace($strLine, 'BACKUP-FULL', '[0-9]{8}\-[0-9]{6}F');
|
|
|
|
|
|
|
|
$strLine = $self->regExpReplace($strLine, 'GROUP', 'strGroup = [^ \n,\[\]]+', '[^ \n,\[\]]+$');
|
|
|
|
$strLine = $self->regExpReplace($strLine, 'GROUP', 'group"[ ]{0,1}:[ ]{0,1}"[^"]+', '[^"]+$');
|
|
|
|
$strLine = $self->regExpReplace($strLine, 'USER', 'strUser = [^ \n,\[\]]+', '[^ \n,\[\]]+$');
|
|
|
|
$strLine = $self->regExpReplace($strLine, 'USER', 'user"[ ]{0,1}:[ ]{0,1}"[^"]+', '[^"]+$');
|
|
|
|
$strLine = $self->regExpReplace($strLine, 'USER', '^db-user=.+$', '[^=]+$');
|
|
|
|
|
|
|
|
$strLine = $self->regExpReplace($strLine, 'PORT', 'db-port=[0-9]+', '[0-9]+$');
|
|
|
|
|
|
|
|
my $strTimestampRegExp = "[0-9]{4}-[0-1][0-9]-[0-3][0-9] [0-2][0-9]:[0-6][0-9]:[0-6][0-9]";
|
|
|
|
|
2016-02-02 21:33:15 +02:00
|
|
|
$strLine = $self->regExpReplace($strLine, 'TS_PATH', "PG\\_[0-9]\\.[0-9]\\_[0-9]{9}");
|
2015-10-08 17:43:56 +02:00
|
|
|
$strLine = $self->regExpReplace($strLine, 'VERSION',
|
|
|
|
"version[\"]{0,1}[ ]{0,1}[\:\=)]{1}[ ]{0,1}[\"]{0,1}" . BACKREST_VERSION, BACKREST_VERSION . '$');
|
|
|
|
$strLine = $self->regExpReplace($strLine, 'TIMESTAMP',
|
|
|
|
"timestamp-[a-z-]+[\"]{0,1}[ ]{0,1}[\:\=)]{1}[ ]{0,1}[\"]{0,1}[0-9]+", '[0-9]+$', false);
|
|
|
|
$strLine = $self->regExpReplace($strLine, 'TIMESTAMP',
|
|
|
|
"start\" : [0-9]{10}", '[0-9]{10}$', false);
|
|
|
|
$strLine = $self->regExpReplace($strLine, 'TIMESTAMP',
|
|
|
|
"stop\" : [0-9]{10}", '[0-9]{10}$', false);
|
|
|
|
$strLine = $self->regExpReplace($strLine, 'SIZE',
|
|
|
|
"size\"[ ]{0,1}:[ ]{0,1}[0-9]+", '[0-9]+$', false);
|
|
|
|
$strLine = $self->regExpReplace($strLine, 'DELTA',
|
|
|
|
"delta\"[ ]{0,1}:[ ]{0,1}[0-9]+", '[0-9]+$', false);
|
|
|
|
$strLine = $self->regExpReplace($strLine, 'TIMESTAMP-STR', "est backup timestamp: $strTimestampRegExp",
|
|
|
|
"${strTimestampRegExp}\$", false);
|
|
|
|
$strLine = $self->regExpReplace($strLine, 'CHECKSUM', 'checksum=[\"]{0,1}[0-f]{40}', '[0-f]{40}$', false);
|
|
|
|
|
2015-11-22 21:02:14 +02:00
|
|
|
$strLine = $self->regExpReplace($strLine, 'REMOTE-PROCESS-TERMINATED-MESSAGE',
|
|
|
|
'remote process terminated: (ssh.*|no output from terminated process)$',
|
|
|
|
'(ssh.*|no output from terminated process)$', false);
|
|
|
|
|
2015-10-08 17:43:56 +02:00
|
|
|
return $strLine;
|
|
|
|
}
|
|
|
|
|
|
|
|
1;
|