From f0250dab4b7fba2eda57fc0a483352f7cd70d0ab Mon Sep 17 00:00:00 2001 From: David Steele Date: Thu, 12 Apr 2018 20:42:26 -0400 Subject: [PATCH] Move async forking and more error handling to C. The Perl process was exiting directly when called but that interfered with proper locking for the forked async process. Now Perl returns results to the C process which handles all errors, including signals. --- doc/xml/release.xml | 4 + doc/xml/user-guide.xml | 6 +- lib/pgBackRest/Archive/Push/Async.pm | 81 +--- lib/pgBackRest/Archive/Push/Push.pm | 6 +- lib/pgBackRest/Backup/Backup.pm | 1 - lib/pgBackRest/Check/Check.pm | 2 +- lib/pgBackRest/Common/Exit.pm | 114 ------ lib/pgBackRest/Config/Config.pm | 47 +-- lib/pgBackRest/Info.pm | 6 +- lib/pgBackRest/Main.pm | 373 +++++++++--------- lib/pgBackRest/Protocol/Base/Minion.pm | 2 - lib/pgBackRest/Stanza.pm | 15 +- src/Makefile | 1 + src/command/archive/push/push.c | 91 +++-- src/command/command.c | 128 +++--- src/command/command.h | 6 +- src/common/exit.c | 110 +++++- src/common/exit.h | 16 +- src/common/fork.c | 29 ++ src/common/fork.h | 12 + src/common/lock.c | 30 ++ src/common/lock.h | 1 + src/common/log.h | 2 + src/config/load.c | 62 +-- src/config/load.h | 1 + src/main.c | 27 +- src/perl/config.h | 2 + src/perl/exec.c | 102 +++-- src/perl/exec.h | 8 +- test/define.yaml | 13 +- test/expect/mock-all-001.log | 121 +++--- test/expect/mock-all-002.log | 146 +++---- test/expect/mock-all-003.log | 4 +- test/expect/mock-archive-001.log | 6 +- test/expect/mock-archive-002.log | 6 +- test/expect/mock-stanza-001.log | 16 +- test/expect/mock-stanza-002.log | 16 +- test/expect/mock-stanza-003.log | 16 +- test/lib/pgBackRestTest/Common/JobTest.pm | 15 +- .../Module/Archive/ArchivePushPerlTest.pm | 41 +- .../Module/Info/InfoUnitTest.pm | 6 +- .../Module/Stanza/StanzaAllTest.pm | 14 +- test/src/module/archive/pushTest.c | 31 +- test/src/module/command/commandTest.c | 10 +- test/src/module/common/exitTest.c | 68 +++- test/src/module/common/forkTest.c | 44 +++ test/src/module/common/lockTest.c | 51 ++- test/src/module/perl/execTest.c | 28 +- test/test.pl | 5 +- 49 files changed, 1058 insertions(+), 884 deletions(-) delete mode 100644 lib/pgBackRest/Common/Exit.pm create mode 100644 src/common/fork.c create mode 100644 src/common/fork.h create mode 100644 test/src/module/common/forkTest.c diff --git a/doc/xml/release.xml b/doc/xml/release.xml index 60824be4e..766b48f55 100644 --- a/doc/xml/release.xml +++ b/doc/xml/release.xml @@ -35,6 +35,10 @@

Make backup.history sync more efficient. Only the backup.history/[year] directory was being synced, so check if the backup.history is newly created and sync it as well.

+ +

Move async forking and more error handling to C. The Perl process was exiting directly when called but that interfered with proper locking for the forked async process. Now Perl returns results to the C process which handles all errors, including signals.

+ +

Improved lock implementation written in C. Now only two types of locks can be taken: archive and backup. Most commands use one or the other but the stanza-* commands acquire both locks. This provides better protection than the old command-based locking scheme.

 diff --git a/doc/xml/user-guide.xml b/doc/xml/user-guide.xml index 624e3978c..3d9392c05 100644 --- a/doc/xml/user-guide.xml +++ b/doc/xml/user-guide.xml @@ -1851,13 +1851,13 @@ 2 -

The archive-async.log file can be used to monitor the activity of the asynchronous process. A good way to test this is to quickly push a number of WAL segments.

+

The [stanza]-archive-push-async.log file can be used to monitor the activity of the asynchronous process. A good way to test this is to quickly push a number of WAL segments.

Test parallel asynchronous archiving - rm -f /var/log/pgbackrest/demo-archive-async.log + rm -f /var/log/pgbackrest/demo-archive-push-async.log @@ -1883,7 +1883,7 @@ Check results in the log - cat /var/log/pgbackrest/demo-archive-async.log + cat /var/log/pgbackrest/demo-archive-push-async.log WAL file\(s\) to archive|pushed WAL file 0000000 diff --git a/lib/pgBackRest/Archive/Push/Async.pm b/lib/pgBackRest/Archive/Push/Async.pm index b66a3b6b3..f45cf66ca 100644 --- a/lib/pgBackRest/Archive/Push/Async.pm +++ b/lib/pgBackRest/Archive/Push/Async.pm @@ -68,78 +68,6 @@ sub new ); } -#################################################################################################################################### -# process -# -# Fork and run the async process if it is not already running. -#################################################################################################################################### -sub process -{ - my $self = shift; - - # Assign function parameters, defaults, and log debug info - my ($strOperation) = logDebugParam(__PACKAGE__ . '->process'); - - my $bClient = true; - - # Check if processes have been stopped - lockStopTest(); - - # This first lock request is a quick test to see if the async process is running. If the lock is successful we need to release - # the lock, fork, and then let the async process acquire its own lock. Otherwise the lock will be held by the client process - # which will soon exit and leave the async process unlocked. - if (lockAcquire(cfgOption(CFGOPT_LOCK_PATH), cfgCommandName(cfgCommandGet()), cfgOption(CFGOPT_STANZA), 30, false)) - { - &log(TEST, TEST_ARCHIVE_PUSH_ASYNC_START); - - lockRelease(true); - $bClient = fork() == 0 ? false : true; - } - else - { - logDebugMisc($strOperation, 'async archive-push process is already running'); - } - - # Run async process - if (!$bClient) - { - # uncoverable branch false - reacquire the lock since it was released by the client process above - if (lockAcquire(cfgOption(CFGOPT_LOCK_PATH), cfgCommandName(cfgCommandGet()), cfgOption(CFGOPT_STANZA), 30, false)) - { - # uncoverable branch true - chdir to / - chdir '/' - or confess &log(ERROR, "unable to chdir to /: $OS_ERROR", ERROR_PATH_MISSING); - - # uncoverable branch true - close stdin - open(STDIN, '<', '/dev/null') - or confess &log(ERROR, "unable to close stdin: $OS_ERROR", ERROR_FILE_OPEN); - # uncoverable branch true - close stdout - open(STDOUT, '>', '/dev/null') - or confess &log(ERROR, "unable to close stdout: $OS_ERROR", ERROR_FILE_OPEN); - # uncoverable branch true - close stderr - open(STDERR, '>', '/dev/null') - or confess &log(ERROR, "unable to close stderr: $OS_ERROR", ERROR_FILE_OPEN); - - # uncoverable branch true - create new session group - setsid() - or confess &log(ERROR, "unable to create new session group: $OS_ERROR", ERROR_ASSERT); - - # Open the log file - logFileSet(storageLocal(), cfgOption(CFGOPT_LOG_PATH) . '/' . cfgOption(CFGOPT_STANZA) . '-archive-async', true); - - # Start processing - $self->processServer(); - } - } - - # Return from function and log return values if any - return logDebugReturn - ( - $strOperation, - {name => 'bClient', value => $bClient, trace => true} - ); -} - #################################################################################################################################### # initServer # @@ -166,16 +94,19 @@ sub initServer } #################################################################################################################################### -# processServer +# process # # Setup the server and process the queue. This function is separate from processQueue() for testing purposes. #################################################################################################################################### -sub processServer +sub process { my $self = shift; # Assign function parameters, defaults, and log debug info - my ($strOperation) = logDebugParam(__PACKAGE__ . '->processServer'); + my ($strOperation) = logDebugParam(__PACKAGE__ . '->process'); + + # Open the log file + logFileSet(storageLocal(), cfgOption(CFGOPT_LOG_PATH) . '/' . cfgOption(CFGOPT_STANZA) . '-archive-push-async'); # There is no loop here because it seems wise to let the async process exit periodically. As the queue grows each async # execution will naturally run longer. This behavior is also far easier to test. diff --git a/lib/pgBackRest/Archive/Push/Push.pm b/lib/pgBackRest/Archive/Push/Push.pm index 601d859e5..b053eac6a 100644 --- a/lib/pgBackRest/Archive/Push/Push.pm +++ b/lib/pgBackRest/Archive/Push/Push.pm @@ -103,11 +103,7 @@ sub process } # Return from function and log return values if any - return logDebugReturn - ( - $strOperation, - {name => 'iResult', value => 0, trace => true} - ); + return logDebugReturn($strOperation); } #################################################################################################################################### diff --git a/lib/pgBackRest/Backup/Backup.pm b/lib/pgBackRest/Backup/Backup.pm index 329446a07..8d2ede5e3 100644 --- a/lib/pgBackRest/Backup/Backup.pm +++ b/lib/pgBackRest/Backup/Backup.pm @@ -18,7 +18,6 @@ use pgBackRest::Backup::File; use pgBackRest::Backup::Info; use pgBackRest::Common::Cipher; use pgBackRest::Common::Exception; -use pgBackRest::Common::Exit; use pgBackRest::Common::Ini; use pgBackRest::Common::Log; use pgBackRest::Common::Wait; diff --git a/lib/pgBackRest/Check/Check.pm b/lib/pgBackRest/Check/Check.pm index b2af86e9c..abf58df59 100644 --- a/lib/pgBackRest/Check/Check.pm +++ b/lib/pgBackRest/Check/Check.pm @@ -201,7 +201,7 @@ sub process } else { - # Throw the captured error + # Log the captured error &log(ERROR, $strResultMessage, $iResult); # If a WAL switch was attempted, then alert the user that the WAL that did not reach the archive diff --git a/lib/pgBackRest/Common/Exit.pm b/lib/pgBackRest/Common/Exit.pm deleted file mode 100644 index 9c1114193..000000000 --- a/lib/pgBackRest/Common/Exit.pm +++ /dev/null @@ -1,114 +0,0 @@ -#################################################################################################################################### -# COMMON EXIT MODULE -#################################################################################################################################### -package pgBackRest::Common::Exit; - -use strict; -use warnings FATAL => qw(all); -use Carp qw(confess); -use English '-no_match_vars'; - -use Exporter qw(import); - our @EXPORT = qw(); -use File::Basename qw(dirname); - -use pgBackRest::Common::Exception; -use pgBackRest::Common::Lock; -use pgBackRest::Common::Log; -use pgBackRest::Config::Config; -use pgBackRest::LibC qw(:lock); -use pgBackRest::Protocol::Helper; - -#################################################################################################################################### -# Signal constants -#################################################################################################################################### -use constant SIGNAL_HUP => 'HUP'; -use constant SIGNAL_INT => 'INT'; -use constant SIGNAL_TERM => 'TERM'; - -#################################################################################################################################### -# Hook important signals into exitSafe function -#################################################################################################################################### -$SIG{&SIGNAL_HUP} = sub {exitSafe(ERROR_TERM, undef, SIGNAL_HUP)}; -$SIG{&SIGNAL_INT} = sub {exitSafe(ERROR_TERM, undef, SIGNAL_INT)}; -$SIG{&SIGNAL_TERM} = sub {exitSafe(ERROR_TERM, undef, SIGNAL_TERM)}; - -#################################################################################################################################### -# exitSafe -# -# Terminate all remotes and release locks. -#################################################################################################################################### -sub exitSafe -{ - # Assign function parameters, defaults, and log debug info - my - ( - $strOperation, - $iExitCode, - $oException, - $strSignal, - ) = - logDebugParam - ( - __PACKAGE__ . '::exitSafe', \@_, - {name => 'iExitCode', required => false}, - {name => 'oException', required => false}, - {name => 'strSignal', required => false}, - ); - - # Reset logging in case it was disabled when the exception/signal occurred - configLogging(); - - # Close the remote - protocolDestroy(undef, undef, defined($iExitCode) && ($iExitCode == 0 || $iExitCode == 1)); - - # If exit code is not defined then try to get it from the exception - if (!defined($iExitCode)) - { - # If a backrest exception - if (isException(\$oException)) - { - $iExitCode = $oException->code(); - logException($oException); - } - else - { - $iExitCode = ERROR_UNHANDLED; - - &log( - ERROR, - 'process terminated due to an unhandled exception' . - (defined($oException) ? ":\n${oException}" : ': [exception not defined]'), - $iExitCode); - } - } - elsif ($iExitCode == ERROR_TERM) - { - &log(ERROR, "terminated on signal [SIG${strSignal}]", ERROR_TERM); - } - - # Log command end - commandEnd(defined($oException) || $iExitCode == ERROR_TERM ? $iExitCode : undef, $strSignal); - - # Release the lock as late as possible - eval - { - # Don't fail if the lock can't be released (it will be freed by the system though the file will remain) - lockRelease(false); - } - # uncoverable branch false - this eval exists only to suppress lock errors so original error will not be lost - or do {}; - - # Log return values if any - logDebugReturn - ( - $strOperation, - {name => 'iExitCode', value => $iExitCode} - ); - - exit $iExitCode; -} - -push @EXPORT, qw(exitSafe); - -1; diff --git a/lib/pgBackRest/Config/Config.pm b/lib/pgBackRest/Config/Config.pm index 26960124d..9c0f0ad06 100644 --- a/lib/pgBackRest/Config/Config.pm +++ b/lib/pgBackRest/Config/Config.pm @@ -74,7 +74,7 @@ sub configLogging push @EXPORT, qw(configLogging); #################################################################################################################################### -# configLoad - load configuration +# Load configuration # # Additional conditions that cannot be codified by the option definitions are also tested here. #################################################################################################################################### @@ -321,56 +321,13 @@ sub cfgCommandTest push @EXPORT, qw(cfgCommandTest); #################################################################################################################################### -# commandBegin -# -# Log information about the command when it begins. -#################################################################################################################################### -sub commandBegin -{ - &log( - $strCommand eq cfgCommandName(CFGCMD_INFO) ? DEBUG : INFO, - "${strCommand} command begin " . BACKREST_VERSION . ':' . - cfgCommandWrite(cfgCommandId($strCommand), true, '', false, undef, true)); -} - -push @EXPORT, qw(commandBegin); - -#################################################################################################################################### -# commandEnd -# -# Log information about the command that ended. -#################################################################################################################################### -sub commandEnd -{ - my $iExitCode = shift; - my $strSignal = shift; - - if (defined($strCommand)) - { - &log( - $strCommand eq cfgCommandName(CFGCMD_INFO) ? DEBUG : INFO, - "${strCommand} command end: " . (defined($iExitCode) && $iExitCode != 0 ? - ($iExitCode == ERROR_TERM ? "terminated on signal " . - (defined($strSignal) ? "[SIG${strSignal}]" : 'from child process') : - sprintf('aborted with exception [%03d]', $iExitCode)) : - 'completed successfully')); - } -} - -push @EXPORT, qw(commandEnd); - -#################################################################################################################################### -# cfgCommandSet - set current command (usually for triggering follow-on commands) +# Set current command #################################################################################################################################### sub cfgCommandSet { my $iCommandId = shift; - commandEnd(); - $strCommand = cfgCommandName($iCommandId); - - commandBegin(); } push @EXPORT, qw(cfgCommandSet); diff --git a/lib/pgBackRest/Info.pm b/lib/pgBackRest/Info.pm index e695287fe..314e0d2e9 100644 --- a/lib/pgBackRest/Info.pm +++ b/lib/pgBackRest/Info.pm @@ -131,11 +131,7 @@ sub process } # Return from function and log return values if any - return logDebugReturn - ( - $strOperation, - {name => 'iResult', value => 0, trace => true} - ); + return logDebugReturn($strOperation); } #################################################################################################################################### diff --git a/lib/pgBackRest/Main.pm b/lib/pgBackRest/Main.pm index 41ade198a..13688651e 100644 --- a/lib/pgBackRest/Main.pm +++ b/lib/pgBackRest/Main.pm @@ -3,21 +3,17 @@ #################################################################################################################################### package pgBackRest::Main; -#################################################################################################################################### -# Perl includes -#################################################################################################################################### use strict; use warnings FATAL => qw(all); use Carp qw(confess); use English '-no_match_vars'; # Convert die to confess to capture the stack trace -$SIG{__DIE__} = sub { Carp::confess @_ }; +$SIG{__DIE__} = sub {Carp::confess @_}; use File::Basename qw(dirname); use pgBackRest::Common::Exception; -use pgBackRest::Common::Exit; use pgBackRest::Common::Lock; use pgBackRest::Common::Log; use pgBackRest::Config::Config; @@ -28,9 +24,12 @@ use pgBackRest::Version; # Set config JSON separately to avoid exposing secrets in the stack trace #################################################################################################################################### my $strConfigJson; +my $strConfigBin; +my $bConfigLoaded = false; -sub configSet +sub mainConfigSet { + $strConfigBin = shift; $strConfigJson = shift; } @@ -39,60 +38,60 @@ sub configSet #################################################################################################################################### sub main { - my $strBackRestBin = shift; my $strCommand = shift; my @stryCommandArg = @_; - ################################################################################################################################ # Run in eval block to catch errors - ################################################################################################################################ + # ------------------------------------------------------------------------------------------------------------------------------ + my $result = 0; + my $message = ''; + eval { - ############################################################################################################################ # Load command line parameters and config -- pass config by reference to hide secrets more than for efficiency - ############################################################################################################################ - configLoad(undef, $strBackRestBin, $strCommand, \$strConfigJson); - - # Set test options - if (cfgOptionTest(CFGOPT_TEST) && cfgOption(CFGOPT_TEST)) + # -------------------------------------------------------------------------------------------------------------------------- + if (!$bConfigLoaded) { - testSet(cfgOption(CFGOPT_TEST), cfgOption(CFGOPT_TEST_DELAY), cfgOption(CFGOPT_TEST_POINT, false)); - } + configLoad(undef, $strConfigBin, $strCommand, \$strConfigJson); - ############################################################################################################################ - # Process archive-push command - ############################################################################################################################ - if (cfgCommandTest(CFGCMD_ARCHIVE_PUSH)) - { - # If async then run command begin so that it gets output to the log file when it is opened - if (cfgOption(CFGOPT_ARCHIVE_ASYNC)) + # Set test options + if (cfgOptionTest(CFGOPT_TEST) && cfgOption(CFGOPT_TEST)) { - commandBegin(); + testSet(cfgOption(CFGOPT_TEST), cfgOption(CFGOPT_TEST_DELAY), cfgOption(CFGOPT_TEST_POINT, false)); } + $bConfigLoaded = true; + } + else + { + cfgCommandSet(cfgCommandId($strCommand)); + } + + # Process archive-push command + # -------------------------------------------------------------------------------------------------------------------------- + if (cfgCommandTest(CFGCMD_ARCHIVE_PUSH)) + { # Load module dynamically require pgBackRest::Archive::Push::Push; pgBackRest::Archive::Push::Push->import(); - exitSafe(new pgBackRest::Archive::Push::Push()->process($stryCommandArg[0])); + new pgBackRest::Archive::Push::Push()->process($stryCommandArg[0]); } - ############################################################################################################################ # Process archive-get command - ############################################################################################################################ - if (cfgCommandTest(CFGCMD_ARCHIVE_GET)) + # -------------------------------------------------------------------------------------------------------------------------- + elsif (cfgCommandTest(CFGCMD_ARCHIVE_GET)) { # Load module dynamically require pgBackRest::Archive::Get::Get; pgBackRest::Archive::Get::Get->import(); - exitSafe(new pgBackRest::Archive::Get::Get()->process($stryCommandArg[0], $stryCommandArg[1])); + $result = new pgBackRest::Archive::Get::Get()->process($stryCommandArg[0], $stryCommandArg[1]); } - ############################################################################################################################ - # Process remote commands - ############################################################################################################################ - if (cfgCommandTest(CFGCMD_REMOTE)) + # Process remote command + # -------------------------------------------------------------------------------------------------------------------------- + elsif (cfgCommandTest(CFGCMD_REMOTE)) { # Set log levels cfgOptionSet(CFGOPT_LOG_LEVEL_STDERR, PROTOCOL, true); @@ -116,13 +115,12 @@ sub main cfgOption(CFGOPT_BUFFER_SIZE), cfgOption(CFGOPT_PROTOCOL_TIMEOUT)); # Process remote requests - exitSafe($oRemote->process(cfgOption(CFGOPT_LOCK_PATH), cfgOption(CFGOPT_COMMAND), cfgOption(CFGOPT_STANZA, false))); + $oRemote->process(cfgOption(CFGOPT_LOCK_PATH), cfgOption(CFGOPT_COMMAND), cfgOption(CFGOPT_STANZA, false)); } - ############################################################################################################################ - # Process local commands - ############################################################################################################################ - if (cfgCommandTest(CFGCMD_LOCAL)) + # Process local command + # -------------------------------------------------------------------------------------------------------------------------- + elsif (cfgCommandTest(CFGCMD_LOCAL)) { # Set log levels cfgOptionSet(CFGOPT_LOG_LEVEL_STDERR, PROTOCOL, true); @@ -136,186 +134,207 @@ sub main my $oLocal = new pgBackRest::Protocol::Local::Minion(); # Process local requests - exitSafe($oLocal->process()); + $oLocal->process(); } - ############################################################################################################################ # Process check command - ############################################################################################################################ - if (cfgCommandTest(CFGCMD_CHECK)) + # -------------------------------------------------------------------------------------------------------------------------- + elsif (cfgCommandTest(CFGCMD_CHECK)) { # Load module dynamically require pgBackRest::Check::Check; pgBackRest::Check::Check->import(); - exitSafe(new pgBackRest::Check::Check()->process()); + $result = new pgBackRest::Check::Check()->process(); } - ############################################################################################################################ # Process start/stop commands - ############################################################################################################################ - if (cfgCommandTest(CFGCMD_START)) + # -------------------------------------------------------------------------------------------------------------------------- + elsif (cfgCommandTest(CFGCMD_START)) { lockStart(); - exitSafe(0); } elsif (cfgCommandTest(CFGCMD_STOP)) { lockStop(); - exitSafe(0); - } - - # Check that the repo path exists - require pgBackRest::Protocol::Storage::Helper; - pgBackRest::Protocol::Storage::Helper->import(); - - if (isRepoLocal() && !cfgOptionTest(CFGOPT_REPO_TYPE, CFGOPTVAL_REPO_TYPE_S3) && !storageRepo()->pathExists('')) - { - confess &log(ERROR, - cfgOptionName(CFGOPT_REPO_PATH) . ' \'' . cfgOption(CFGOPT_REPO_PATH) . '\' does not exist', ERROR_PATH_MISSING); - } - - ############################################################################################################################ - # Process info command - ############################################################################################################################ - if (cfgCommandTest(CFGCMD_INFO)) - { - # Load module dynamically - require pgBackRest::Info; - pgBackRest::Info->import(); - - exitSafe(new pgBackRest::Info()->process()); - } - - ############################################################################################################################ - # Process stanza-delete command - ############################################################################################################################ - if (cfgCommandTest(CFGCMD_STANZA_DELETE)) - { - if (!isRepoLocal()) - { - confess &log(ERROR, - cfgCommandName(cfgCommandGet()) . ' command must be run on the repository host', ERROR_HOST_INVALID); - } - - # Load module dynamically - require pgBackRest::Stanza; - pgBackRest::Stanza->import(); - - exitSafe(new pgBackRest::Stanza()->process()); - } - - ############################################################################################################################ - # Check if processes have been stopped - ############################################################################################################################ - lockStopTest(); - - ############################################################################################################################ - # Open the log file - ############################################################################################################################ - require pgBackRest::Storage::Helper; - pgBackRest::Storage::Helper->import(); - - logFileSet( - storageLocal(), - cfgOption(CFGOPT_LOG_PATH) . '/' . cfgOption(CFGOPT_STANZA) . '-' . lc(cfgCommandName(cfgCommandGet()))); - - ############################################################################################################################ - # Process stanza-create command - ############################################################################################################################ - if (cfgCommandTest(CFGCMD_STANZA_CREATE) || cfgCommandTest(CFGCMD_STANZA_UPGRADE)) - { - if (!isRepoLocal()) - { - confess &log(ERROR, - cfgCommandName(cfgCommandGet()) . ' command must be run on the repository host', ERROR_HOST_INVALID); - } - - # Load module dynamically - require pgBackRest::Stanza; - pgBackRest::Stanza->import(); - - exitSafe(new pgBackRest::Stanza()->process()); - } - - ############################################################################################################################ - # RESTORE - ############################################################################################################################ - if (cfgCommandTest(CFGCMD_RESTORE)) - { - if (!isDbLocal()) - { - confess &log(ERROR, 'restore command must be run on the PostgreSQL host', ERROR_HOST_INVALID); - } - - # Load module dynamically - require pgBackRest::Restore; - pgBackRest::Restore->import(); - - # Do the restore - new pgBackRest::Restore()->process(); - - exitSafe(0); } else { - ######################################################################################################################## - # Make sure backup and expire commands happen on the backup side - ######################################################################################################################## - if (!isRepoLocal()) + # Check that the repo path exists + require pgBackRest::Protocol::Storage::Helper; + pgBackRest::Protocol::Storage::Helper->import(); + + if (isRepoLocal() && !cfgOptionTest(CFGOPT_REPO_TYPE, CFGOPTVAL_REPO_TYPE_S3) && !storageRepo()->pathExists('')) { - confess &log(ERROR, 'backup and expire commands must be run on the repository host', ERROR_HOST_INVALID); + confess &log(ERROR, + cfgOptionName(CFGOPT_REPO_PATH) . ' \'' . cfgOption(CFGOPT_REPO_PATH) . '\' does not exist', + ERROR_PATH_MISSING); } - ######################################################################################################################## - # BACKUP - ######################################################################################################################## - if (cfgCommandTest(CFGCMD_BACKUP)) + # Process info command + # ---------------------------------------------------------------------------------------------------------------------- + if (cfgCommandTest(CFGCMD_INFO)) { # Load module dynamically - require pgBackRest::Backup::Backup; - pgBackRest::Backup::Backup->import(); + require pgBackRest::Info; + pgBackRest::Info->import(); - new pgBackRest::Backup::Backup()->process(); - - cfgCommandSet(CFGCMD_EXPIRE); + new pgBackRest::Info()->process(); } - - ######################################################################################################################## - # EXPIRE - ######################################################################################################################## - if (cfgCommandTest(CFGCMD_EXPIRE)) + else { - # Load module dynamically - require pgBackRest::Expire; - pgBackRest::Expire->import(); + # Open log file + require pgBackRest::Storage::Helper; + pgBackRest::Storage::Helper->import(); - new pgBackRest::Expire()->process(); + logFileSet( + storageLocal(), + cfgOption(CFGOPT_LOG_PATH) . '/' . cfgOption(CFGOPT_STANZA) . '-' . lc(cfgCommandName(cfgCommandGet()))); + + # Process delete command + # -------------------------------------------------------------------------------------------------------------- + if (cfgCommandTest(CFGCMD_STANZA_DELETE)) + { + # Load module dynamically + require pgBackRest::Stanza; + pgBackRest::Stanza->import(); + + new pgBackRest::Stanza()->process(); + } + # Process restore command + # ------------------------------------------------------------------------------------------------------------------ + elsif (cfgCommandTest(CFGCMD_RESTORE)) + { + # Check locality + if (!isDbLocal()) + { + confess &log(ERROR, + cfgCommandName(cfgCommandGet()) . ' command must be run on the PostgreSQL host', ERROR_HOST_INVALID); + } + + # Load module dynamically + require pgBackRest::Restore; + pgBackRest::Restore->import(); + + # Do the restore + new pgBackRest::Restore()->process(); + } + else + { + # Check if processes have been stopped + lockStopTest(); + + # Check locality + if (!isRepoLocal()) + { + confess &log(ERROR, + cfgCommandName(cfgCommandGet()) . ' command must be run on the repository host', ERROR_HOST_INVALID); + } + + # Process stanza-create and stanza-upgrade commands + # -------------------------------------------------------------------------------------------------------------- + if (cfgCommandTest(CFGCMD_STANZA_CREATE) || cfgCommandTest(CFGCMD_STANZA_UPGRADE)) + { + # Load module dynamically + require pgBackRest::Stanza; + pgBackRest::Stanza->import(); + + $result = new pgBackRest::Stanza()->process(); + } + + # Process backup command + # -------------------------------------------------------------------------------------------------------------- + elsif (cfgCommandTest(CFGCMD_BACKUP)) + { + # Load module dynamically + require pgBackRest::Backup::Backup; + pgBackRest::Backup::Backup->import(); + + new pgBackRest::Backup::Backup()->process(); + } + + # Process expire command + # -------------------------------------------------------------------------------------------------------------- + elsif (cfgCommandTest(CFGCMD_EXPIRE)) + { + # Load module dynamically + require pgBackRest::Expire; + pgBackRest::Expire->import(); + + new pgBackRest::Expire()->process(); + } + } } } - # Exit with success - exitSafe(0); - - # uncoverable statement - exit should happen above - &log(ASSERT, 'execution reached invalid location in ' . __FILE__ . ', line ' . __LINE__); - exit ERROR_ASSERT; # uncoverable statement + return 1; } - ################################################################################################################################ # Check for errors - ################################################################################################################################ + # ------------------------------------------------------------------------------------------------------------------------------ or do { # Perl 5.10 seems to have a problem propogating errors up through a large call stack, so in the case that the error arrives # blank just use the last logged error instead. Don't do this in all cases because newer Perls seem to work fine and there # are other errors that could be arriving in $EVAL_ERROR. - exitSafe(undef, defined($EVAL_ERROR) && length($EVAL_ERROR) > 0 ? $EVAL_ERROR : logErrorLast()); + my $oException = defined($EVAL_ERROR) && length($EVAL_ERROR) > 0 ? $EVAL_ERROR : logErrorLast(); + + # If a backrest exception then only return the code since the message has already been logged + if (isException(\$oException)) + { + $result = $oException->code(); + } + # Else a regular Perl exception + else + { + $result = ERROR_UNHANDLED; + $message = + 'process terminated due to an unhandled exception' . + (defined($oException) ? ":\n${oException}" : ': [exception not defined]'); + } }; - # uncoverable statement - errors should be handled in the do block above - &log(ASSERT, 'execution reached invalid location in ' . __FILE__ . ', line ' . __LINE__); - exit ERROR_ASSERT; # uncoverable statement + # Return result and error message if the result is an error + return $result, $message; +} + +#################################################################################################################################### +# Do any cleanup required when the perl process is about to be shut down +#################################################################################################################################### +sub mainCleanup +{ + # Assign function parameters, defaults, and log debug info + my + ( + $strOperation, + $iExitCode, + ) = + logDebugParam + ( + __PACKAGE__ . '::mainCleanup', \@_, + {name => 'iExitCode', required => false}, + ); + + # Don't fail if the remote can't be closed + eval + { + protocolDestroy(undef, undef, defined($iExitCode) && ($iExitCode == 0 || $iExitCode == 1)); + return true; + } + # this eval exists only to suppress protocol shutdown errors so original error will not be lost + or do {}; + + # Don't fail if the lock can't be released (it will be freed by the system though the file will remain) + eval + { + lockRelease(false); + return true; + } + # this eval exists only to suppress lock errors so original error will not be lost + or do {}; + + # Log return values if any + return logDebugReturn($strOperation); } 1; diff --git a/lib/pgBackRest/Protocol/Base/Minion.pm b/lib/pgBackRest/Protocol/Base/Minion.pm index 837afe63b..aadbdd0c7 100644 --- a/lib/pgBackRest/Protocol/Base/Minion.pm +++ b/lib/pgBackRest/Protocol/Base/Minion.pm @@ -235,8 +235,6 @@ sub process # Else unexpected Perl exception confess &log(ERROR, 'unknown error: ' . $oException, ERROR_UNKNOWN); }; - - return 0; } #################################################################################################################################### diff --git a/lib/pgBackRest/Stanza.pm b/lib/pgBackRest/Stanza.pm index 86558963a..76a25c5d8 100644 --- a/lib/pgBackRest/Stanza.pm +++ b/lib/pgBackRest/Stanza.pm @@ -87,12 +87,12 @@ sub process # Process stanza upgrade elsif (cfgCommandTest(CFGCMD_STANZA_UPGRADE)) { - $iResult = $self->stanzaUpgrade(); + $self->stanzaUpgrade(); } # Process stanza delete elsif (cfgCommandTest(CFGCMD_STANZA_DELETE)) { - $iResult = $self->stanzaDelete(); + $self->stanzaDelete(); } # Else error if any other command is found else @@ -284,10 +284,7 @@ sub stanzaUpgrade # Return from function and log return values if any return logDebugReturn - ( - $strOperation, - {name => 'iResult', value => 0, trace => true} - ); + return logDebugReturn($strOperation); } #################################################################################################################################### @@ -359,11 +356,7 @@ sub stanzaDelete } # Return from function and log return values if any - return logDebugReturn - ( - $strOperation, - {name => 'iResult', value => 0, trace => true} - ); + return logDebugReturn($strOperation); } #################################################################################################################################### diff --git a/src/Makefile b/src/Makefile index cef69e256..1ddf37acb 100644 --- a/src/Makefile +++ b/src/Makefile @@ -57,6 +57,7 @@ SRCS = \ command/archive/push/push.c \ command/help/help.c \ command/command.c \ + common/fork.c \ common/error.c \ common/exit.c \ common/io/handle.c \ diff --git a/src/command/archive/push/push.c b/src/command/archive/push/push.c index 38bf8aaaa..7460c035c 100644 --- a/src/command/archive/push/push.c +++ b/src/command/archive/push/push.c @@ -4,17 +4,21 @@ Archive Push Command #include #include #include +#include #include #include #include #include +#include "command/command.h" +#include "common/fork.h" #include "common/error.h" #include "common/log.h" #include "common/memContext.h" #include "common/regExp.h" #include "common/wait.h" #include "config/config.h" +#include "config/load.h" #include "perl/exec.h" #include "storage/helper.h" @@ -124,7 +128,9 @@ cmdArchivePush() if (cfgOptionBool(cfgOptArchiveAsync)) { bool pushed = false; // Has the WAL segment been pushed yet? + bool forked = false; // Has the async process been forked yet? bool confessOnError = false; // Should we confess errors? + bool server = false; // Is this the async server process? // Loop and wait for the WAL segment to be pushed Wait *wait = waitNew(cfgOptionDbl(cfgOptArchiveTimeout)); @@ -135,50 +141,77 @@ cmdArchivePush() // process a chance to fix them. pushed = walStatus(walSegment, confessOnError); - // If the WAL segment has not already been pushed then start the async process to push it - if (!pushed) + // If the WAL segment has not already been pushed then start the async process to push it. There's no point in + // forking the async process off more than once so track that as well. Use an archive lock to prevent more than + // one async process being launched. + if (!pushed && !forked && + lockAcquire(cfgOptionStr(cfgOptLockPath), cfgOptionStr(cfgOptStanza), cfgLockType(), 0, false)) { - // Async process is currently implemented in Perl - int processId = 0; - - if ((processId = fork()) == 0) + // Fork off the async process + if (fork() == 0) { - // Only want to see warnings and errors on the console from async process - cfgOptionSet(cfgOptLogLevelConsole, cfgSourceParam, varNewStrZ("warn")); + // This is the server process + server = true; - // Execute async process - perlExec(); + // The async process should not output on the console at all + cfgOptionSet(cfgOptLogLevelConsole, cfgSourceParam, varNewStrZ("off")); + cfgOptionSet(cfgOptLogLevelStderr, cfgSourceParam, varNewStrZ("off")); + cfgLoadLogSetting(); + + // Open the log file + logFileSet( + strPtr(strNewFmt("%s/%s-%s-async.log", strPtr(cfgOptionStr(cfgOptLogPath)), + strPtr(cfgOptionStr(cfgOptStanza)), cfgCommandName(cfgCommand())))); + + // Log command info since we are starting a new log + cmdBegin(true); + + // Detach from parent process + forkDetach(); + + // Execute async process and catch exceptions + TRY_BEGIN() + { + perlExec(); + } + CATCH_ANY() + { + RETHROW(); + } + FINALLY() + { + // Release the lock (mostly here for testing since it would be freed in exitSafe() anyway) + lockRelease(true); + } + TRY_END(); } - // Wait for async process to exit (this should happen quickly) and report any errors + // Else mark async process as forked else { - int processStatus; - - if (waitpid(processId, &processStatus, 0) != processId) // {uncoverable - fork() does not fail} - THROW_SYS_ERROR(AssertError, "unable to find perl child process"); // {uncoverable+} - - if (WEXITSTATUS(processStatus) != 0) - THROW(AssertError, "perl exited with error %d", WEXITSTATUS(processStatus)); + lockClear(true); + forked = true; } } // Now that the async process has been launched, confess any errors that are found confessOnError = true; } - while (!pushed && waitMore(wait)); + while (!server && !pushed && waitMore(wait)); - waitFree(wait); - - // If the WAL segment was not pushed then error - if (!pushed) + // The aysnc server does not give notifications + if (!server) { - THROW( - ArchiveTimeoutError, "unable to push WAL segment '%s' asynchronously after %lg second(s)", strPtr(walSegment), - cfgOptionDbl(cfgOptArchiveTimeout)); - } + // If the WAL segment was not pushed then error + if (!pushed) + { + THROW( + ArchiveTimeoutError, "unable to push WAL segment '%s' asynchronously after %lg second(s)", + strPtr(walSegment), cfgOptionDbl(cfgOptArchiveTimeout)); + } - // Log success - LOG_INFO("pushed WAL segment %s asynchronously", strPtr(walSegment)); + // Log success + LOG_INFO("pushed WAL segment %s asynchronously", strPtr(walSegment)); + } } else THROW(AssertError, "archive-push in C does not support synchronous mode"); diff --git a/src/command/command.c b/src/command/command.c index 575828f79..e32d5ec00 100644 --- a/src/command/command.c +++ b/src/command/command.c @@ -20,7 +20,7 @@ Debug Asserts Begin the command ***********************************************************************************************************************************/ void -cmdBegin() +cmdBegin(bool logOption) { ASSERT_DEBUG_COMMAND_SET(); @@ -30,77 +30,82 @@ cmdBegin() MEM_CONTEXT_TEMP_BEGIN() { // Basic info on command start - String *info = strNewFmt("%s command begin %s:", cfgCommandName(cfgCommand()), PGBACKREST_VERSION); + String *info = strNewFmt("%s command begin", cfgCommandName(cfgCommand())); - // Loop though options and add the ones that are interesting - for (ConfigOption optionId = 0; optionId < CFG_OPTION_TOTAL; optionId++) + if (logOption) { - // Skip the option if it is not valid - if (!cfgOptionValid(optionId)) - continue; + strCatFmt(info, " %s:", PGBACKREST_VERSION); - // If option was negated - if (cfgOptionNegate(optionId)) - strCatFmt(info, " --no-%s", cfgOptionName(optionId)); - // If option was reset - else if (cfgOptionReset(optionId)) - strCatFmt(info, " --reset-%s", cfgOptionName(optionId)); - // Else set and not default - else if (cfgOptionSource(optionId) != cfgSourceDefault && cfgOptionTest(optionId)) + // Loop though options and add the ones that are interesting + for (ConfigOption optionId = 0; optionId < CFG_OPTION_TOTAL; optionId++) { - ConfigDefineOption optionDefId = cfgOptionDefIdFromId(optionId); + // Skip the option if it is not valid + if (!cfgOptionValid(optionId)) + continue; - // Don't show redacted options - if (cfgDefOptionSecure(optionDefId)) - strCatFmt(info, " --%s=", cfgOptionName(optionId)); - // Output boolean option - else if (cfgDefOptionType(optionDefId) == cfgDefOptTypeBoolean) - strCatFmt(info, " --%s", cfgOptionName(optionId)); - // Output other options - else + // If option was negated + if (cfgOptionNegate(optionId)) + strCatFmt(info, " --no-%s", cfgOptionName(optionId)); + // If option was reset + else if (cfgOptionReset(optionId)) + strCatFmt(info, " --reset-%s", cfgOptionName(optionId)); + // Else set and not default + else if (cfgOptionSource(optionId) != cfgSourceDefault && cfgOptionTest(optionId)) { - StringList *valueList = NULL; + ConfigDefineOption optionDefId = cfgOptionDefIdFromId(optionId); - // Generate the values of hash options - if (cfgDefOptionType(optionDefId) == cfgDefOptTypeHash) - { - valueList = strLstNew(); - - const KeyValue *optionKv = cfgOptionKv(optionId); - const VariantList *keyList = kvKeyList(optionKv); - - for (unsigned int keyIdx = 0; keyIdx < varLstSize(keyList); keyIdx++) - { - strLstAdd( - valueList, - strNewFmt( - "%s=%s", strPtr(varStr(varLstGet(keyList, keyIdx))), - strPtr(varStrForce(kvGet(optionKv, varLstGet(keyList, keyIdx)))))); - } - } - // Generate values for list options - else if (cfgDefOptionType(optionDefId) == cfgDefOptTypeList) - { - valueList = strLstNewVarLst(cfgOptionLst(optionId)); - } - // Else only one value + // Don't show redacted options + if (cfgDefOptionSecure(optionDefId)) + strCatFmt(info, " --%s=", cfgOptionName(optionId)); + // Output boolean option + else if (cfgDefOptionType(optionDefId) == cfgDefOptTypeBoolean) + strCatFmt(info, " --%s", cfgOptionName(optionId)); + // Output other options else { - valueList = strLstNew(); - strLstAdd(valueList, varStrForce(cfgOption(optionId))); - } + StringList *valueList = NULL; - // Output options and values - for (unsigned int valueListIdx = 0; valueListIdx < strLstSize(valueList); valueListIdx++) - { - const String *value = strLstGet(valueList, valueListIdx); + // Generate the values of hash options + if (cfgDefOptionType(optionDefId) == cfgDefOptTypeHash) + { + valueList = strLstNew(); - strCatFmt(info, " --%s", cfgOptionName(optionId)); + const KeyValue *optionKv = cfgOptionKv(optionId); + const VariantList *keyList = kvKeyList(optionKv); - if (strchr(strPtr(value), ' ') != NULL) - value = strNewFmt("\"%s\"", strPtr(value)); + for (unsigned int keyIdx = 0; keyIdx < varLstSize(keyList); keyIdx++) + { + strLstAdd( + valueList, + strNewFmt( + "%s=%s", strPtr(varStr(varLstGet(keyList, keyIdx))), + strPtr(varStrForce(kvGet(optionKv, varLstGet(keyList, keyIdx)))))); + } + } + // Generate values for list options + else if (cfgDefOptionType(optionDefId) == cfgDefOptTypeList) + { + valueList = strLstNewVarLst(cfgOptionLst(optionId)); + } + // Else only one value + else + { + valueList = strLstNew(); + strLstAdd(valueList, varStrForce(cfgOption(optionId))); + } - strCatFmt(info, "=%s", strPtr(value)); + // Output options and values + for (unsigned int valueListIdx = 0; valueListIdx < strLstSize(valueList); valueListIdx++) + { + const String *value = strLstGet(valueList, valueListIdx); + + strCatFmt(info, " --%s", cfgOptionName(optionId)); + + if (strchr(strPtr(value), ' ') != NULL) + value = strNewFmt("\"%s\"", strPtr(value)); + + strCatFmt(info, "=%s", strPtr(value)); + } } } } @@ -116,9 +121,10 @@ cmdBegin() End the command ***********************************************************************************************************************************/ void -cmdEnd(int code) +cmdEnd(int code, const String *errorMessage) { ASSERT_DEBUG_COMMAND_SET(); + ASSERT_DEBUG(code == 0 || errorMessage != NULL); // Skip this log message if it won't be output. It's not too expensive but since we skipped cmdBegin(), may as well. if (logWill(cfgLogLevelDefault())) @@ -131,7 +137,7 @@ cmdEnd(int code) if (code == 0) strCat(info, "completed successfully"); else - strCatFmt(info, "aborted with exception [%03d]", code); + strCat(info, strPtr(errorMessage)); LOG_ANY(cfgLogLevelDefault(), 0, strPtr(info)); } diff --git a/src/command/command.h b/src/command/command.h index 3102aad74..4680ca8ef 100644 --- a/src/command/command.h +++ b/src/command/command.h @@ -4,10 +4,12 @@ Common Command Routines #ifndef COMMAND_COMMAND_H #define COMMAND_COMMAND_H +#include "common/type/string.h" + /*********************************************************************************************************************************** Functions ***********************************************************************************************************************************/ -void cmdBegin(); -void cmdEnd(int code); +void cmdBegin(bool logOption); +void cmdEnd(int code, const String *errorMessage); #endif diff --git a/src/common/exit.c b/src/common/exit.c index a6913a6c5..e0e4c8449 100644 --- a/src/common/exit.c +++ b/src/common/exit.c @@ -1,29 +1,129 @@ /*********************************************************************************************************************************** Exit Routines ***********************************************************************************************************************************/ +#include +#include + #include "command/command.h" +#include "common/error.h" #include "common/exit.h" +#include "common/lock.h" #include "common/log.h" #include "config/config.h" +#include "perl/exec.h" + +/*********************************************************************************************************************************** +Return signal names +***********************************************************************************************************************************/ +static const char * +exitSignalName(int signalType) +{ + const char *name = NULL; + + switch (signalType) + { + case signalTypeHup: + { + name = "HUP"; + break; + } + + case signalTypeInt: + { + name = "INT"; + break; + } + + case signalTypeTerm: + { + name = "TERM"; + break; + } + + case signalTypeNone: + THROW(AssertError, "no name for signal none"); + } + + return name; +} + +/*********************************************************************************************************************************** +Catch signals +***********************************************************************************************************************************/ +static void +exitOnSignal(int signalType) +{ + exit(exitSafe(errorTypeCode(&TermError), false, (SignalType)signalType)); +} + +/*********************************************************************************************************************************** +Setup signal handlers +***********************************************************************************************************************************/ +void +exitInit() +{ + signal(SIGHUP, exitOnSignal); + signal(SIGINT, exitOnSignal); + signal(SIGTERM, exitOnSignal); +} /*********************************************************************************************************************************** Do cleanup and return result code ***********************************************************************************************************************************/ int -exitSafe(bool error) +exitSafe(int result, bool error, SignalType signalType) { - int result = 0; - // Report error if one was thrown if (error) { - LOG_ANY(errorCode() == errorTypeCode(&AssertError) ? logLevelAssert : logLevelError, errorCode(), errorMessage()); + // Don't log the error if it has already been logged by Perl + if (strcmp(errorMessage(), PERL_EMBED_ERROR) != 0) + LOG_ANY(errorCode() == errorTypeCode(&AssertError) ? logLevelAssert : logLevelError, errorCode(), errorMessage()); + result = errorCode(); } + // Release any locks but ignore errors + TRY_BEGIN() + { + lockRelease(false); + } + TRY_END(); + + // Free Perl but ignore errors + TRY_BEGIN() + { + perlFree(result); + } + TRY_END(); + // Log command end if a command is set if (cfgCommand() != cfgCmdNone) - cmdEnd(result); + { + String *errorMessage = NULL; + + // On error generate an error message + if (result != 0) + { + // On process terminate + if (result == errorTypeCode(&TermError)) + { + errorMessage = strNew("terminated on signal "); + + // Terminate from a child + if (signalType == signalTypeNone) + strCat(errorMessage, "from child process"); + // Else terminated directly + else + strCatFmt(errorMessage, "[SIG%s]", exitSignalName(signalType)); + } + // Standard error exit message + else + errorMessage = strNewFmt("aborted with exception [%03d]", result); + } + + cmdEnd(result, errorMessage); + } // Return result - caller should immediate pass this result to exit() return result; diff --git a/src/common/exit.h b/src/common/exit.h index da7cad5b9..68de27be6 100644 --- a/src/common/exit.h +++ b/src/common/exit.h @@ -4,11 +4,23 @@ Exit Routines #ifndef COMMON_EXIT_H #define COMMON_EXIT_H -#include "common/error.h" +#include + +/*********************************************************************************************************************************** +Signal type +***********************************************************************************************************************************/ +typedef enum +{ + signalTypeNone = 0, + signalTypeHup = SIGHUP, + signalTypeInt = SIGINT, + signalTypeTerm = SIGTERM, +} SignalType; /*********************************************************************************************************************************** Functions ***********************************************************************************************************************************/ -int exitSafe(bool error); +void exitInit(); +int exitSafe(int result, bool error, SignalType signalType); #endif diff --git a/src/common/fork.c b/src/common/fork.c new file mode 100644 index 000000000..8b26757ff --- /dev/null +++ b/src/common/fork.c @@ -0,0 +1,29 @@ +/*********************************************************************************************************************************** +Fork Handler +***********************************************************************************************************************************/ +#include + +#include "common/error.h" + +/*********************************************************************************************************************************** +Fork a new process and detach it so it can continue running after the parent process has exited. This is not a typical daemon +startup because the parent process may continue to run and perform work for some time. +***********************************************************************************************************************************/ +void +forkDetach() +{ + if (chdir("/") == -1) // {uncoverable - should never fail} + THROW_SYS_ERROR(PathMissingError, "unable to change directory to '/'"); // {uncoverable+} + + if (setsid() == -1) // {uncoverable - should never fail} + THROW_SYS_ERROR(AssertError, "unable to create new session group"); // {uncoverable+} + + if (close(STDIN_FILENO) == -1) // {uncoverable - should never fail} + THROW_SYS_ERROR(FileCloseError, "unable to close stdin"); // {uncoverable+} + + if (close(STDOUT_FILENO) == -1) // {uncoverable - should never fail} + THROW_SYS_ERROR(FileCloseError, "unable to close stdout"); // {uncoverable+} + + if (close(STDERR_FILENO) == -1) // {uncoverable - should never fail} + THROW_SYS_ERROR(FileCloseError, "unable to close stderr"); // {uncoverable+} +} diff --git a/src/common/fork.h b/src/common/fork.h new file mode 100644 index 000000000..de66b2c2f --- /dev/null +++ b/src/common/fork.h @@ -0,0 +1,12 @@ +/*********************************************************************************************************************************** +Fork Handler +***********************************************************************************************************************************/ +#ifndef COMMON_FORK_H +#define COMMON_FORK_H + +/*********************************************************************************************************************************** +Functions +***********************************************************************************************************************************/ +void forkDetach(); + +#endif diff --git a/src/common/lock.c b/src/common/lock.c index e02cfe555..4e2337e17 100644 --- a/src/common/lock.c +++ b/src/common/lock.c @@ -189,6 +189,36 @@ lockAcquire(const String *lockPath, const String *stanza, LockType lockType, dou return result; } +/*********************************************************************************************************************************** +Clear the lock without releasing it. This is used by a master process after it has spawned a child so the child can keep the lock +and the master process won't try to free it. +***********************************************************************************************************************************/ +bool +lockClear(bool failOnNoLock) +{ + bool result = false; + + if (lockTypeHeld == lockTypeNone) + { + if (failOnNoLock) + THROW(AssertError, "no lock is held by this process"); + } + else + { + // Clear locks + LockType lockMin = lockTypeHeld == lockTypeAll ? lockTypeArchive : lockTypeHeld; + LockType lockMax = lockTypeHeld == lockTypeAll ? (lockTypeAll - 1) : lockTypeHeld; + + for (LockType lockIdx = lockMin; lockIdx <= lockMax; lockIdx++) + strFree(lockFile[lockIdx]); + + lockTypeHeld = lockTypeNone; + result = true; + } + + return result; +} + /*********************************************************************************************************************************** Release a lock type ***********************************************************************************************************************************/ diff --git a/src/common/lock.h b/src/common/lock.h index d7828e2c3..4cdaad642 100644 --- a/src/common/lock.h +++ b/src/common/lock.h @@ -21,6 +21,7 @@ typedef enum Functions ***********************************************************************************************************************************/ bool lockAcquire(const String *lockPath, const String *stanza, LockType lockType, double lockTimeout, bool failOnNoLock); +bool lockClear(bool failOnNoLock); bool lockRelease(bool failOnNoLock); #endif diff --git a/src/common/log.h b/src/common/log.h index 270778a77..17e865e17 100644 --- a/src/common/log.h +++ b/src/common/log.h @@ -61,6 +61,8 @@ Only call logInternal() if the message will be logged to one of the available ou LOG_ANY(logLevelAssert, errorTypeCode(&AssertError), __VA_ARGS__) #define LOG_ERROR(code, ...) \ LOG_ANY(logLevelError, code, __VA_ARGS__) +#define LOG_DEBUG(...) \ + LOG_ANY(logLevelDebug, 0, __VA_ARGS__) #define LOG_INFO(...) \ LOG_ANY(logLevelInfo, 0, __VA_ARGS__) #define LOG_WARN(...) \ diff --git a/src/config/load.c b/src/config/load.c index 0c8fe3e94..fef3cce04 100644 --- a/src/config/load.c +++ b/src/config/load.c @@ -12,6 +12,39 @@ Configuration Load #include "config/load.h" #include "config/parse.h" +/*********************************************************************************************************************************** +Load log settings +***********************************************************************************************************************************/ +void +cfgLoadLogSetting() +{ + // Initialize logging + LogLevel logLevelConsole = logLevelOff; + LogLevel logLevelStdErr = logLevelOff; + LogLevel logLevelFile = logLevelOff; + bool logTimestamp = true; + + if (cfgOptionValid(cfgOptLogLevelConsole)) + logLevelConsole = logLevelEnum(strPtr(cfgOptionStr(cfgOptLogLevelConsole))); + + if (cfgOptionValid(cfgOptLogLevelStderr)) + { + logLevelStdErr = logLevelEnum(strPtr(cfgOptionStr(cfgOptLogLevelStderr))); + + // If configured log level exceeds the max for a command, set it to the max + if (logLevelStdErr > cfgLogLevelStdErrMax()) + logLevelStdErr = cfgLogLevelStdErrMax(); + } + + if (cfgOptionValid(cfgOptLogLevelFile)) + logLevelFile = logLevelEnum(strPtr(cfgOptionStr(cfgOptLogLevelFile))); + + if (cfgOptionValid(cfgOptLogTimestamp)) + logTimestamp = cfgOptionBool(cfgOptLogTimestamp); + + logInit(logLevelConsole, logLevelStdErr, logLevelFile, logTimestamp); +} + /*********************************************************************************************************************************** Load the configuration ***********************************************************************************************************************************/ @@ -29,31 +62,8 @@ cfgLoadParam(unsigned int argListSize, const char *argList[], String *exe) // Parse config from command line and config file configParse(argListSize, argList); - // Initialize logging - LogLevel logLevelConsole = logLevelOff; - LogLevel logLevelStdErr = logLevelOff; - LogLevel logLevelFile = logLevelOff; - bool logTimestamp = true; - - if (cfgOptionValid(cfgOptLogLevelConsole)) - logLevelConsole = logLevelEnum(strPtr(cfgOptionStr(cfgOptLogLevelConsole))); - - if (cfgOptionValid(cfgOptLogLevelStderr)) - { - logLevelStdErr = logLevelEnum(strPtr(cfgOptionStr(cfgOptLogLevelStderr))); - - // If configured log level exceeds the max for a command, set it to the max - if (logLevelStdErr > cfgLogLevelStdErrMax()) - logLevelStdErr = cfgLogLevelStdErrMax(); - } - - if (cfgOptionValid(cfgOptLogLevelFile)) - logLevelFile = logLevelEnum(strPtr(cfgOptionStr(cfgOptLogLevelFile))); - - if (cfgOptionValid(cfgOptLogTimestamp)) - logTimestamp = cfgOptionBool(cfgOptLogTimestamp); - - logInit(logLevelConsole, logLevelStdErr, logLevelFile, logTimestamp); + // Load the log settings + cfgLoadLogSetting(); // Only continue if a command was set. If no command is set then help will be displayed if (cfgCommand() != cfgCmdNone) @@ -67,7 +77,7 @@ cfgLoadParam(unsigned int argListSize, const char *argList[], String *exe) } // Begin the command - cmdBegin(); + cmdBegin(true); // If an exe was passed in then use it if (exe != NULL) diff --git a/src/config/load.h b/src/config/load.h index 701f7c5f2..516174eae 100644 --- a/src/config/load.h +++ b/src/config/load.h @@ -9,5 +9,6 @@ Functions ***********************************************************************************************************************************/ void cfgLoad(unsigned int argListSize, const char *argList[]); void cfgLoadParam(unsigned int argListSize, const char *argList[], String *exe); +void cfgLoadLogSetting(); #endif diff --git a/src/main.c b/src/main.c index 612ef0737..57378db03 100644 --- a/src/main.c +++ b/src/main.c @@ -6,6 +6,7 @@ Main #include "command/archive/push/push.h" #include "command/help/help.h" +#include "command/command.h" #include "common/error.h" #include "common/exit.h" #include "config/config.h" @@ -16,7 +17,11 @@ Main int main(int argListSize, const char *argList[]) { - bool error = false; + volatile bool result = 0; + volatile bool error = false; + + // Initialize exit handler + exitInit(); TRY_BEGIN() { @@ -46,11 +51,27 @@ main(int argListSize, const char *argList[]) cmdArchivePush(); } + // Backup command. Still executed in Perl but this implements running expire after backup. + // ------------------------------------------------------------------------------------------------------------------------- + else if (cfgCommand() == cfgCmdBackup) + { + // Run backup + perlExec(); + + // Switch to expire command + cmdEnd(0, NULL); + cfgCommandSet(cfgCmdExpire); + cmdBegin(false); + + // Run expire + perlExec(); + } + // Execute Perl for commands not implemented in C // ------------------------------------------------------------------------------------------------------------------------- else { - perlExec(); + result = perlExec(); } } CATCH_ANY() @@ -59,5 +80,5 @@ main(int argListSize, const char *argList[]) } TRY_END(); - return exitSafe(error); + return exitSafe(result, error, 0); } diff --git a/src/perl/config.h b/src/perl/config.h index 2e7c4b17b..489b11bb1 100644 --- a/src/perl/config.h +++ b/src/perl/config.h @@ -4,6 +4,8 @@ Perl Configuration #ifndef PERL_CONFIG_H #define PERL_CONFIG_H +#include "common/type/string.h" + /*********************************************************************************************************************************** Functions ***********************************************************************************************************************************/ diff --git a/src/perl/exec.c b/src/perl/exec.c index 9e40397b0..214d6100d 100644 --- a/src/perl/exec.c +++ b/src/perl/exec.c @@ -12,6 +12,7 @@ Execute Perl for Legacy Functionality #include "common/memContext.h" #include "config/config.h" #include "perl/config.h" +#include "perl/exec.h" #if __GNUC__ > 4 || (__GNUC__ == 4 && __GNUC_MINOR__ >= 8) #define WARNING_PEDANTIC 1 @@ -41,7 +42,13 @@ Constants used to build perl options ***********************************************************************************************************************************/ #define PGBACKREST_MODULE PGBACKREST_NAME "::Main" #define PGBACKREST_MAIN PGBACKREST_MODULE "::main" -#define PGBACKREST_CONFIG_SET PGBACKREST_MODULE "::configSet" + +/*********************************************************************************************************************************** +Perl interpreter + +This is a silly name but Perl prefers it. +***********************************************************************************************************************************/ +static PerlInterpreter *my_perl = NULL; /*********************************************************************************************************************************** Build list of parameters to use for perl main @@ -57,7 +64,7 @@ perlMain() // Construct Perl main call String *mainCall = strNewFmt( - PGBACKREST_MAIN "('%s','%s'%s)", strPtr(cfgExe()), cfgCommandName(cfgCommand()), strPtr(commandParam)); + "($result, $message) = " PGBACKREST_MAIN "('%s'%s)", cfgCommandName(cfgCommand()), strPtr(commandParam)); return mainCall; } @@ -77,34 +84,77 @@ static void xs_init(pTHX) newXS("DynaLoader::boot_DynaLoader", boot_DynaLoader, file); } +/*********************************************************************************************************************************** +Evaluate a perl statement +***********************************************************************************************************************************/ +static void +perlEval(const String *statement) +{ + eval_pv(strPtr(statement), TRUE); +} + +/*********************************************************************************************************************************** +Initialize Perl +***********************************************************************************************************************************/ +static void +perlInit() +{ + if (!my_perl) + { + // Initialize Perl with dummy args and environment + int argc = 1; + const char *argv[1] = {strPtr(cfgExe())}; + const char *env[1] = {NULL}; + PERL_SYS_INIT3(&argc, (char ***)&argv, (char ***)&env); + + // Create the interpreter + const char *embedding[] = {"", "-M"PGBACKREST_MODULE, "-e", "0"}; + my_perl = perl_alloc(); + perl_construct(my_perl); + + // Don't let $0 assignment update the proctitle or embedding[0] + PL_origalen = 1; + + // Start the interpreter + perl_parse(my_perl, xs_init, 3, (char **)embedding, NULL); + PL_exit_flags |= PERL_EXIT_DESTRUCT_END; + perl_run(my_perl); + + // Set config data -- this is done separately to avoid it being included in stack traces + perlEval(strNewFmt(PGBACKREST_MAIN "ConfigSet('%s', '%s')", strPtr(cfgExe()), strPtr(perlOptionJson()))); + } +} + /*********************************************************************************************************************************** Execute main function in Perl ***********************************************************************************************************************************/ -void +int perlExec() { - // Initialize Perl with dummy args and environment - int argc = 1; - const char *argv[1] = {strPtr(cfgExe())}; - const char *env[1] = {NULL}; - PERL_SYS_INIT3(&argc, (char ***)&argv, (char ***)&env); - - // Create the interpreter - const char *embedding[] = {"", "-M"PGBACKREST_MODULE, "-e", "0"}; - PerlInterpreter *my_perl = perl_alloc(); - perl_construct(my_perl); - - // Don't let $0 assignment update the proctitle or embedding[0] - PL_origalen = 1; - - // Start the interpreter - perl_parse(my_perl, xs_init, 3, (char **)embedding, NULL); - PL_exit_flags |= PERL_EXIT_DESTRUCT_END; - perl_run(my_perl); - - // Set config data -- this is done separately to avoid it being included in stack traces - eval_pv(strPtr(strNewFmt(PGBACKREST_CONFIG_SET "('%s')", strPtr(perlOptionJson()))), TRUE); + // Initialize Perl + perlInit(); // Run perl main function - eval_pv(strPtr(perlMain()), TRUE); -} // {uncoverable - perlExec() does not return} + perlEval(perlMain()); + + // Return result code + int code = (int)SvIV(get_sv("result", 0)); + char *message = SvPV_nolen(get_sv("message", 0)); // {uncovered - internal Perl macro branch} + + if (code >= errorTypeCode(&AssertError)) // {uncovered - success tested in integration} + THROW_CODE(code, strlen(message) == 0 ? PERL_EMBED_ERROR : message); // {+uncovered} + + return code; // {+uncovered} +} + +/*********************************************************************************************************************************** +Free Perl objects + +Don't bother freeing Perl itself since we are about to exit. +***********************************************************************************************************************************/ +void +perlFree(int result) +{ + if (my_perl != NULL) + perlEval(strNewFmt(PGBACKREST_MAIN "Cleanup(%d)", result)); +} diff --git a/src/perl/exec.h b/src/perl/exec.h index 1f3639ff5..606f951c1 100644 --- a/src/perl/exec.h +++ b/src/perl/exec.h @@ -4,9 +4,15 @@ Execute Perl for Legacy Functionality #ifndef PERL_EXEC_H #define PERL_EXEC_H +/*********************************************************************************************************************************** +Error message for errors thrown from embedded Perl +***********************************************************************************************************************************/ +#define PERL_EMBED_ERROR "!!!EMBEDDEDPERLERROR!!!" + /*********************************************************************************************************************************** Functions ***********************************************************************************************************************************/ -void perlExec(); +int perlExec(); +void perlFree(int result); #endif diff --git a/test/define.yaml b/test/define.yaml index f8868055d..f6053ac9f 100644 --- a/test/define.yaml +++ b/test/define.yaml @@ -69,6 +69,15 @@ module: coverage: common/assert: noCode + # ---------------------------------------------------------------------------------------------------------------------------- + - name: fork + total: 1 + c: true + cDef: -DNO_LOG + + coverage: + common/fork: full + # ---------------------------------------------------------------------------------------------------------------------------- - name: mem-context total: 7 @@ -123,7 +132,7 @@ module: # ---------------------------------------------------------------------------------------------------------------------------- - name: exit - total: 1 + total: 3 c: true coverage: @@ -541,7 +550,7 @@ module: total: 8 coverage: - Archive/Push/Async: partial + Archive/Push/Async: full Archive/Push/File: partial Archive/Push/Push: full Protocol/Local/Master: full diff --git a/test/expect/mock-all-001.log b/test/expect/mock-all-001.log index d4b429815..37757c65c 100644 --- a/test/expect/mock-all-001.log +++ b/test/expect/mock-all-001.log @@ -89,11 +89,11 @@ P00 DEBUG: Storage::Posix::Driver->new(): bFileSync = , bPathSync = < P00 DEBUG: Storage::Local->new(): bAllowTemp = , hRule = [hash], lBufferMax = 16384, oDriver = [object], strCipherPassUser = [undef], strCipherType = [undef], strDefaultFileMode = <0640>, strDefaultPathMode = <0750>, strPathBase = [TEST_PATH]/db-master/repo, strTempExtension = pgbackrest.tmp P00 DEBUG: Storage::Local->pathExists(): strPathExp = P00 DEBUG: Storage::Local->pathExists=>: bExists = true -P00 DEBUG: Common::Lock::lockStopTest(): bStanzaStopRequired = -P00 DEBUG: Common::Lock::lockStopTest=>: bStopExists = false P00 DEBUG: Storage::Posix::Driver->new(): bFileSync = , bPathSync = P00 DEBUG: Storage::Local->new(): bAllowTemp = , hRule = [undef], lBufferMax = 16384, oDriver = [object], strCipherPassUser = [undef], strCipherType = [undef], strDefaultFileMode = <0640>, strDefaultPathMode = <0750>, strPathBase = /, strTempExtension = pgbackrest.tmp P00 DEBUG: Storage::Local->pathCreate(): bCreateParent = true, bIgnoreExists = true, strMode = 0770, strPathExp = [TEST_PATH]/db-master/log +P00 DEBUG: Common::Lock::lockStopTest(): bStanzaStopRequired = +P00 DEBUG: Common::Lock::lockStopTest=>: bStopExists = false P00 DEBUG: Backup::Info->new(): bIgnoreMissing = , bLoad = , bRequired = , bValidate = , oStorage = <[object]>, strBackupClusterPath = [TEST_PATH]/db-master/repo/backup/db, strCipherPassSub = [undef] P00 DEBUG: Storage::Local->encrypted(): bIgnoreMissing = true, strFileName = [TEST_PATH]/db-master/repo/backup/db/backup.info P00 DEBUG: Storage::Local->encrypted=>: bEncrypted = false @@ -285,7 +285,12 @@ P00 DEBUG: Storage::Local->pathSync(): bRecurse = , strPathExp = [TE P00 DEBUG: Storage::Local->openWrite(): bAtomic = , bPathCreate = , lTimestamp = [undef], rhyFilter = [undef], strCipherPass = [undef], strGroup = [undef], strMode = <0640>, strUser = [undef], xFileExp = [TEST_PATH]/db-master/repo/backup/db/backup.info.copy P00 DEBUG: Storage::Local->pathSync(): bRecurse = , strPathExp = [TEST_PATH]/db-master/repo/backup/db P00 INFO: backup command end: completed successfully -P00 INFO: expire command begin [BACKREST-VERSION]: --buffer-size=16384 --config=[TEST_PATH]/db-master/pgbackrest.conf --lock-path=[TEST_PATH]/db-master/lock --log-level-console=debug --log-level-file=trace --log-level-stderr=off --log-path=[TEST_PATH]/db-master/log --repo1-path=[TEST_PATH]/db-master/repo --repo1-type=cifs --stanza=db +P00 INFO: expire command begin +P00 DEBUG: Storage::Local->pathExists(): strPathExp = +P00 DEBUG: Storage::Local->pathExists=>: bExists = true +P00 DEBUG: Storage::Local->pathCreate(): bCreateParent = true, bIgnoreExists = true, strMode = 0770, strPathExp = [TEST_PATH]/db-master/log +P00 DEBUG: Common::Lock::lockStopTest(): bStanzaStopRequired = +P00 DEBUG: Common::Lock::lockStopTest=>: bStopExists = false P00 DEBUG: Backup::Info->new(): bIgnoreMissing = , bLoad = , bRequired = , bValidate = , oStorage = <[object]>, strBackupClusterPath = [TEST_PATH]/db-master/repo/backup/db, strCipherPassSub = [undef] P00 DEBUG: Storage::Local->encrypted(): bIgnoreMissing = true, strFileName = [TEST_PATH]/db-master/repo/backup/db/backup.info P00 DEBUG: Storage::Local->encrypted=>: bEncrypted = false @@ -311,11 +316,10 @@ P00 DEBUG: Storage::Local->list=>: stryFileList = ([BACKUP-FULL-1]) P00 DEBUG: Backup::Info->current(): strBackup = [BACKUP-FULL-1] P00 DEBUG: Backup::Info->current=>: bTest = true P00 INFO: option 'repo1-retention-archive' is not set - archive logs will not be expired -P00 DEBUG: Common::Exit::exitSafe(): iExitCode = 0, oException = [undef], strSignal = [undef] +P00 DEBUG: Main::mainCleanup(): iExitCode = 0 P00 DEBUG: Protocol::Helper::protocolDestroy(): bComplete = true, iRemoteIdx = [undef], strRemoteType = [undef] P00 DEBUG: Protocol::Helper::protocolDestroy=>: iExitStatus = 0 P00 INFO: expire command end: completed successfully -P00 DEBUG: Common::Exit::exitSafe=>: iExitCode = 0 + supplemental file: [TEST_PATH]/db-master/pgbackrest.conf ---------------------------------------------------------- @@ -460,11 +464,10 @@ P00 DEBUG: Storage::Posix::Driver->new(): bFileSync = , bPathSync = < P00 DEBUG: Storage::Local->new(): bAllowTemp = , hRule = [undef], lBufferMax = [undef], oDriver = [object], strCipherPassUser = [undef], strCipherType = [undef], strDefaultFileMode = <0640>, strDefaultPathMode = <0750>, strPathBase = /, strTempExtension = pgbackrest.tmp P00 DEBUG: Storage::Local->pathCreate(): bCreateParent = true, bIgnoreExists = true, strMode = 770, strPathExp = [TEST_PATH]/db-master/lock P00 INFO: sent term signal to process [PROCESS-ID] -P00 DEBUG: Common::Exit::exitSafe(): iExitCode = 0, oException = [undef], strSignal = [undef] +P00 DEBUG: Main::mainCleanup(): iExitCode = 0 P00 DEBUG: Protocol::Helper::protocolDestroy(): bComplete = true, iRemoteIdx = [undef], strRemoteType = [undef] P00 DEBUG: Protocol::Helper::protocolDestroy=>: iExitStatus = 0 P00 INFO: stop command end: completed successfully -P00 DEBUG: Common::Exit::exitSafe=>: iExitCode = 0 full backup - abort backup - local (db-master host) > [CONTAINER-EXEC] db-master [BACKREST-BIN] --config=[TEST_PATH]/db-master/pgbackrest.conf --no-online --type=full --stanza=db backup --test --test-delay=5 --test-point=backup-start=y @@ -476,11 +479,11 @@ P00 DEBUG: Storage::Posix::Driver->new(): bFileSync = , bPathSync = < P00 DEBUG: Storage::Local->new(): bAllowTemp = , hRule = [hash], lBufferMax = 4194304, oDriver = [object], strCipherPassUser = [undef], strCipherType = [undef], strDefaultFileMode = <0640>, strDefaultPathMode = <0750>, strPathBase = [TEST_PATH]/db-master/repo, strTempExtension = pgbackrest.tmp P00 DEBUG: Storage::Local->pathExists(): strPathExp = P00 DEBUG: Storage::Local->pathExists=>: bExists = true -P00 DEBUG: Common::Lock::lockStopTest(): bStanzaStopRequired = -P00 DEBUG: Common::Lock::lockStopTest=>: bStopExists = false P00 DEBUG: Storage::Posix::Driver->new(): bFileSync = , bPathSync = P00 DEBUG: Storage::Local->new(): bAllowTemp = , hRule = [undef], lBufferMax = 4194304, oDriver = [object], strCipherPassUser = [undef], strCipherType = [undef], strDefaultFileMode = <0640>, strDefaultPathMode = <0750>, strPathBase = /, strTempExtension = pgbackrest.tmp P00 DEBUG: Storage::Local->pathCreate(): bCreateParent = true, bIgnoreExists = true, strMode = 0770, strPathExp = [TEST_PATH]/db-master/log +P00 DEBUG: Common::Lock::lockStopTest(): bStanzaStopRequired = +P00 DEBUG: Common::Lock::lockStopTest=>: bStopExists = false P00 DEBUG: Backup::Info->new(): bIgnoreMissing = , bLoad = , bRequired = , bValidate = , oStorage = <[object]>, strBackupClusterPath = [TEST_PATH]/db-master/repo/backup/db, strCipherPassSub = [undef] P00 DEBUG: Storage::Local->encrypted(): bIgnoreMissing = true, strFileName = [TEST_PATH]/db-master/repo/backup/db/backup.info P00 DEBUG: Storage::Local->encrypted=>: bEncrypted = false @@ -537,12 +540,10 @@ P00 DEBUG: Storage::Local->exists=>: bExists = false P00 DEBUG: Storage::Local->openWrite(): bAtomic = , bPathCreate = , lTimestamp = [undef], rhyFilter = [undef], strCipherPass = [undef], strGroup = [undef], strMode = <0640>, strUser = [undef], xFileExp = [TEST_PATH]/db-master/repo/backup/db/[BACKUP-FULL-2]/backup.manifest.copy P00 DEBUG: Backup::Backup->processManifest(): bCompress = false, bHardLink = false, oBackupManifest = [object], strBackupLabel = [BACKUP-FULL-2], strDbCopyPath = [TEST_PATH]/db-master/db/base, strDbMasterPath = [TEST_PATH]/db-master/db/base, strDbVersion = 9.4, strLsnStart = [undef], strType = full P00 TEST: PgBaCkReStTeSt-BACKUP-START-PgBaCkReStTeSt -P00 DEBUG: Common::Exit::exitSafe(): iExitCode = 63, oException = [undef], strSignal = TERM +P00 DEBUG: Main::mainCleanup(): iExitCode = 63 P00 DEBUG: Protocol::Helper::protocolDestroy(): bComplete = false, iRemoteIdx = [undef], strRemoteType = [undef] P00 DEBUG: Protocol::Helper::protocolDestroy=>: iExitStatus = 0 -P00 ERROR: [063]: terminated on signal [SIGTERM] P00 INFO: backup command end: terminated on signal [SIGTERM] -P00 DEBUG: Common::Exit::exitSafe=>: iExitCode = 63 full backup - global stop (db-master host) > [CONTAINER-EXEC] db-master [BACKREST-BIN] --config=[TEST_PATH]/db-master/pgbackrest.conf --no-online --type=full --stanza=db backup @@ -554,13 +555,15 @@ P00 DEBUG: Storage::Posix::Driver->new(): bFileSync = , bPathSync = < P00 DEBUG: Storage::Local->new(): bAllowTemp = , hRule = [hash], lBufferMax = 4194304, oDriver = [object], strCipherPassUser = [undef], strCipherType = [undef], strDefaultFileMode = <0640>, strDefaultPathMode = <0750>, strPathBase = [TEST_PATH]/db-master/repo, strTempExtension = pgbackrest.tmp P00 DEBUG: Storage::Local->pathExists(): strPathExp = P00 DEBUG: Storage::Local->pathExists=>: bExists = true +P00 DEBUG: Storage::Posix::Driver->new(): bFileSync = , bPathSync = +P00 DEBUG: Storage::Local->new(): bAllowTemp = , hRule = [undef], lBufferMax = 4194304, oDriver = [object], strCipherPassUser = [undef], strCipherType = [undef], strDefaultFileMode = <0640>, strDefaultPathMode = <0750>, strPathBase = /, strTempExtension = pgbackrest.tmp +P00 DEBUG: Storage::Local->pathCreate(): bCreateParent = true, bIgnoreExists = true, strMode = 0770, strPathExp = [TEST_PATH]/db-master/log P00 DEBUG: Common::Lock::lockStopTest(): bStanzaStopRequired = P00 ERROR: [062]: stop file exists for all stanzas -P00 DEBUG: Common::Exit::exitSafe(): iExitCode = [undef], oException = [object], strSignal = [undef] +P00 DEBUG: Main::mainCleanup(): iExitCode = 62 P00 DEBUG: Protocol::Helper::protocolDestroy(): bComplete = false, iRemoteIdx = [undef], strRemoteType = [undef] P00 DEBUG: Protocol::Helper::protocolDestroy=>: iExitStatus = 0 P00 INFO: backup command end: aborted with exception [062] -P00 DEBUG: Common::Exit::exitSafe=>: iExitCode = 62 stop db stanza (db-master host) > [CONTAINER-EXEC] db-master [BACKREST-BIN] --config=[TEST_PATH]/db-master/pgbackrest.conf --stanza=db stop @@ -569,11 +572,10 @@ P00 INFO: stop command begin [BACKREST-VERSION]: --config=[TEST_PATH]/db-maste P00 DEBUG: Storage::Posix::Driver->new(): bFileSync = , bPathSync = P00 DEBUG: Storage::Local->new(): bAllowTemp = , hRule = [undef], lBufferMax = [undef], oDriver = [object], strCipherPassUser = [undef], strCipherType = [undef], strDefaultFileMode = <0640>, strDefaultPathMode = <0750>, strPathBase = /, strTempExtension = pgbackrest.tmp P00 DEBUG: Storage::Local->pathCreate(): bCreateParent = true, bIgnoreExists = true, strMode = 770, strPathExp = [TEST_PATH]/db-master/lock -P00 DEBUG: Common::Exit::exitSafe(): iExitCode = 0, oException = [undef], strSignal = [undef] +P00 DEBUG: Main::mainCleanup(): iExitCode = 0 P00 DEBUG: Protocol::Helper::protocolDestroy(): bComplete = true, iRemoteIdx = [undef], strRemoteType = [undef] P00 DEBUG: Protocol::Helper::protocolDestroy=>: iExitStatus = 0 P00 INFO: stop command end: completed successfully -P00 DEBUG: Common::Exit::exitSafe=>: iExitCode = 0 stop db stanza (db-master host) > [CONTAINER-EXEC] db-master [BACKREST-BIN] --config=[TEST_PATH]/db-master/pgbackrest.conf --stanza=db stop @@ -583,11 +585,10 @@ P00 DEBUG: Storage::Posix::Driver->new(): bFileSync = , bPathSync = < P00 DEBUG: Storage::Local->new(): bAllowTemp = , hRule = [undef], lBufferMax = [undef], oDriver = [object], strCipherPassUser = [undef], strCipherType = [undef], strDefaultFileMode = <0640>, strDefaultPathMode = <0750>, strPathBase = /, strTempExtension = pgbackrest.tmp P00 DEBUG: Storage::Local->pathCreate(): bCreateParent = true, bIgnoreExists = true, strMode = 770, strPathExp = [TEST_PATH]/db-master/lock P00 WARN: stop file already exists for stanza db -P00 DEBUG: Common::Exit::exitSafe(): iExitCode = 0, oException = [undef], strSignal = [undef] +P00 DEBUG: Main::mainCleanup(): iExitCode = 0 P00 DEBUG: Protocol::Helper::protocolDestroy(): bComplete = true, iRemoteIdx = [undef], strRemoteType = [undef] P00 DEBUG: Protocol::Helper::protocolDestroy=>: iExitStatus = 0 P00 INFO: stop command end: completed successfully -P00 DEBUG: Common::Exit::exitSafe=>: iExitCode = 0 full backup - stanza stop (db-master host) > [CONTAINER-EXEC] db-master [BACKREST-BIN] --config=[TEST_PATH]/db-master/pgbackrest.conf --no-online --type=full --stanza=db backup @@ -599,44 +600,43 @@ P00 DEBUG: Storage::Posix::Driver->new(): bFileSync = , bPathSync = < P00 DEBUG: Storage::Local->new(): bAllowTemp = , hRule = [hash], lBufferMax = 4194304, oDriver = [object], strCipherPassUser = [undef], strCipherType = [undef], strDefaultFileMode = <0640>, strDefaultPathMode = <0750>, strPathBase = [TEST_PATH]/db-master/repo, strTempExtension = pgbackrest.tmp P00 DEBUG: Storage::Local->pathExists(): strPathExp = P00 DEBUG: Storage::Local->pathExists=>: bExists = true +P00 DEBUG: Storage::Posix::Driver->new(): bFileSync = , bPathSync = +P00 DEBUG: Storage::Local->new(): bAllowTemp = , hRule = [undef], lBufferMax = 4194304, oDriver = [object], strCipherPassUser = [undef], strCipherType = [undef], strDefaultFileMode = <0640>, strDefaultPathMode = <0750>, strPathBase = /, strTempExtension = pgbackrest.tmp +P00 DEBUG: Storage::Local->pathCreate(): bCreateParent = true, bIgnoreExists = true, strMode = 0770, strPathExp = [TEST_PATH]/db-master/log P00 DEBUG: Common::Lock::lockStopTest(): bStanzaStopRequired = P00 ERROR: [062]: stop file exists for stanza db -P00 DEBUG: Common::Exit::exitSafe(): iExitCode = [undef], oException = [object], strSignal = [undef] +P00 DEBUG: Main::mainCleanup(): iExitCode = 62 P00 DEBUG: Protocol::Helper::protocolDestroy(): bComplete = false, iRemoteIdx = [undef], strRemoteType = [undef] P00 DEBUG: Protocol::Helper::protocolDestroy=>: iExitStatus = 0 P00 INFO: backup command end: aborted with exception [062] -P00 DEBUG: Common::Exit::exitSafe=>: iExitCode = 62 start db stanza (db-master host) > [CONTAINER-EXEC] db-master [BACKREST-BIN] --config=[TEST_PATH]/db-master/pgbackrest.conf --stanza=db start ------------------------------------------------------------------------------------------------------------------------------------ P00 INFO: start command begin [BACKREST-VERSION]: --config=[TEST_PATH]/db-master/pgbackrest.conf --lock-path=[TEST_PATH]/db-master/lock --log-level-console=debug --log-level-file=trace --log-level-stderr=off --log-path=[TEST_PATH]/db-master/log --repo1-path=[TEST_PATH]/db-master/repo --stanza=db -P00 DEBUG: Common::Exit::exitSafe(): iExitCode = 0, oException = [undef], strSignal = [undef] +P00 DEBUG: Main::mainCleanup(): iExitCode = 0 P00 DEBUG: Protocol::Helper::protocolDestroy(): bComplete = true, iRemoteIdx = [undef], strRemoteType = [undef] P00 DEBUG: Protocol::Helper::protocolDestroy=>: iExitStatus = 0 P00 INFO: start command end: completed successfully -P00 DEBUG: Common::Exit::exitSafe=>: iExitCode = 0 start all stanzas (db-master host) > [CONTAINER-EXEC] db-master [BACKREST-BIN] --config=[TEST_PATH]/db-master/pgbackrest.conf start ------------------------------------------------------------------------------------------------------------------------------------ P00 INFO: start command begin [BACKREST-VERSION]: --config=[TEST_PATH]/db-master/pgbackrest.conf --lock-path=[TEST_PATH]/db-master/lock --log-level-console=debug --log-level-file=trace --log-level-stderr=off --log-path=[TEST_PATH]/db-master/log --repo1-path=[TEST_PATH]/db-master/repo -P00 DEBUG: Common::Exit::exitSafe(): iExitCode = 0, oException = [undef], strSignal = [undef] +P00 DEBUG: Main::mainCleanup(): iExitCode = 0 P00 DEBUG: Protocol::Helper::protocolDestroy(): bComplete = true, iRemoteIdx = [undef], strRemoteType = [undef] P00 DEBUG: Protocol::Helper::protocolDestroy=>: iExitStatus = 0 P00 INFO: start command end: completed successfully -P00 DEBUG: Common::Exit::exitSafe=>: iExitCode = 0 start all stanzas (db-master host) > [CONTAINER-EXEC] db-master [BACKREST-BIN] --config=[TEST_PATH]/db-master/pgbackrest.conf start ------------------------------------------------------------------------------------------------------------------------------------ P00 INFO: start command begin [BACKREST-VERSION]: --config=[TEST_PATH]/db-master/pgbackrest.conf --lock-path=[TEST_PATH]/db-master/lock --log-level-console=debug --log-level-file=trace --log-level-stderr=off --log-path=[TEST_PATH]/db-master/log --repo1-path=[TEST_PATH]/db-master/repo P00 WARN: stop file does not exist -P00 DEBUG: Common::Exit::exitSafe(): iExitCode = 0, oException = [undef], strSignal = [undef] +P00 DEBUG: Main::mainCleanup(): iExitCode = 0 P00 DEBUG: Protocol::Helper::protocolDestroy(): bComplete = true, iRemoteIdx = [undef], strRemoteType = [undef] P00 DEBUG: Protocol::Helper::protocolDestroy=>: iExitStatus = 0 P00 INFO: start command end: completed successfully -P00 DEBUG: Common::Exit::exitSafe=>: iExitCode = 0 full backup - resume (db-master host) > [CONTAINER-EXEC] db-master [BACKREST-BIN] --config=[TEST_PATH]/db-master/pgbackrest.conf --no-online --force --checksum-page --type=full --stanza=db backup --test --test-delay=0.2 --test-point=backup-resume=y @@ -648,11 +648,11 @@ P00 DEBUG: Storage::Posix::Driver->new(): bFileSync = , bPathSync = < P00 DEBUG: Storage::Local->new(): bAllowTemp = , hRule = [hash], lBufferMax = 4194304, oDriver = [object], strCipherPassUser = [undef], strCipherType = [undef], strDefaultFileMode = <0640>, strDefaultPathMode = <0750>, strPathBase = [TEST_PATH]/db-master/repo, strTempExtension = pgbackrest.tmp P00 DEBUG: Storage::Local->pathExists(): strPathExp = P00 DEBUG: Storage::Local->pathExists=>: bExists = true -P00 DEBUG: Common::Lock::lockStopTest(): bStanzaStopRequired = -P00 DEBUG: Common::Lock::lockStopTest=>: bStopExists = false P00 DEBUG: Storage::Posix::Driver->new(): bFileSync = , bPathSync = P00 DEBUG: Storage::Local->new(): bAllowTemp = , hRule = [undef], lBufferMax = 4194304, oDriver = [object], strCipherPassUser = [undef], strCipherType = [undef], strDefaultFileMode = <0640>, strDefaultPathMode = <0750>, strPathBase = /, strTempExtension = pgbackrest.tmp P00 DEBUG: Storage::Local->pathCreate(): bCreateParent = true, bIgnoreExists = true, strMode = 0770, strPathExp = [TEST_PATH]/db-master/log +P00 DEBUG: Common::Lock::lockStopTest(): bStanzaStopRequired = +P00 DEBUG: Common::Lock::lockStopTest=>: bStopExists = false P00 DEBUG: Backup::Info->new(): bIgnoreMissing = , bLoad = , bRequired = , bValidate = , oStorage = <[object]>, strBackupClusterPath = [TEST_PATH]/db-master/repo/backup/db, strCipherPassSub = [undef] P00 DEBUG: Storage::Local->encrypted(): bIgnoreMissing = true, strFileName = [TEST_PATH]/db-master/repo/backup/db/backup.info P00 DEBUG: Storage::Local->encrypted=>: bEncrypted = false @@ -843,7 +843,12 @@ P00 DEBUG: Storage::Local->openWrite(): bAtomic = , bPathCreate = pathSync(): bRecurse = , strPathExp = [TEST_PATH]/db-master/repo/backup/db P00 DEBUG: Storage::Local->pathSync(): bRecurse = , strPathExp = P00 INFO: backup command end: completed successfully -P00 INFO: expire command begin [BACKREST-VERSION]: --config=[TEST_PATH]/db-master/pgbackrest.conf --lock-path=[TEST_PATH]/db-master/lock --log-level-console=debug --log-level-file=trace --log-level-stderr=off --log-path=[TEST_PATH]/db-master/log --repo1-path=[TEST_PATH]/db-master/repo --stanza=db +P00 INFO: expire command begin +P00 DEBUG: Storage::Local->pathExists(): strPathExp = +P00 DEBUG: Storage::Local->pathExists=>: bExists = true +P00 DEBUG: Storage::Local->pathCreate(): bCreateParent = true, bIgnoreExists = true, strMode = 0770, strPathExp = [TEST_PATH]/db-master/log +P00 DEBUG: Common::Lock::lockStopTest(): bStanzaStopRequired = +P00 DEBUG: Common::Lock::lockStopTest=>: bStopExists = false P00 DEBUG: Backup::Info->new(): bIgnoreMissing = , bLoad = , bRequired = , bValidate = , oStorage = <[object]>, strBackupClusterPath = [TEST_PATH]/db-master/repo/backup/db, strCipherPassSub = [undef] P00 DEBUG: Storage::Local->encrypted(): bIgnoreMissing = true, strFileName = [TEST_PATH]/db-master/repo/backup/db/backup.info P00 DEBUG: Storage::Local->encrypted=>: bEncrypted = false @@ -869,11 +874,10 @@ P00 DEBUG: Storage::Local->list=>: stryFileList = ([BACKUP-FULL-2]) P00 DEBUG: Backup::Info->current(): strBackup = [BACKUP-FULL-2] P00 DEBUG: Backup::Info->current=>: bTest = true P00 INFO: option 'repo1-retention-archive' is not set - archive logs will not be expired -P00 DEBUG: Common::Exit::exitSafe(): iExitCode = 0, oException = [undef], strSignal = [undef] +P00 DEBUG: Main::mainCleanup(): iExitCode = 0 P00 DEBUG: Protocol::Helper::protocolDestroy(): bComplete = true, iRemoteIdx = [undef], strRemoteType = [undef] P00 DEBUG: Protocol::Helper::protocolDestroy=>: iExitStatus = 0 P00 INFO: expire command end: completed successfully -P00 DEBUG: Common::Exit::exitSafe=>: iExitCode = 0 + supplemental file: [TEST_PATH]/db-master/pgbackrest.conf ---------------------------------------------------------- @@ -1020,8 +1024,6 @@ P00 DEBUG: Storage::Posix::Driver->new(): bFileSync = , bPathSync = < P00 DEBUG: Storage::Local->new(): bAllowTemp = , hRule = [hash], lBufferMax = 4194304, oDriver = [object], strCipherPassUser = [undef], strCipherType = [undef], strDefaultFileMode = <0640>, strDefaultPathMode = <0750>, strPathBase = [TEST_PATH]/db-master/repo, strTempExtension = pgbackrest.tmp P00 DEBUG: Storage::Local->pathExists(): strPathExp = P00 DEBUG: Storage::Local->pathExists=>: bExists = true -P00 DEBUG: Common::Lock::lockStopTest(): bStanzaStopRequired = -P00 DEBUG: Common::Lock::lockStopTest=>: bStopExists = false P00 DEBUG: Storage::Posix::Driver->new(): bFileSync = , bPathSync = P00 DEBUG: Storage::Local->new(): bAllowTemp = , hRule = [undef], lBufferMax = 4194304, oDriver = [object], strCipherPassUser = [undef], strCipherType = [undef], strDefaultFileMode = <0640>, strDefaultPathMode = <0750>, strPathBase = /, strTempExtension = pgbackrest.tmp P00 DEBUG: Storage::Local->pathCreate(): bCreateParent = true, bIgnoreExists = true, strMode = 0770, strPathExp = [TEST_PATH]/db-master/log @@ -1277,11 +1279,10 @@ P00 DEBUG: Storage::Local->pathSync(): bRecurse = , strPathExp = [TE P00 DEBUG: Storage::Local->remove(): bIgnoreMissing = , bRecurse = , xstryPathFileExp = [TEST_PATH]/db-master/db/base/backup.manifest P00 DEBUG: Storage::Local->remove=>: bRemoved = true P00 DEBUG: Storage::Local->pathSync(): bRecurse = , strPathExp = [TEST_PATH]/db-master/db/base -P00 DEBUG: Common::Exit::exitSafe(): iExitCode = 0, oException = [undef], strSignal = [undef] +P00 DEBUG: Main::mainCleanup(): iExitCode = 0 P00 DEBUG: Protocol::Helper::protocolDestroy(): bComplete = true, iRemoteIdx = [undef], strRemoteType = [undef] P00 DEBUG: Protocol::Helper::protocolDestroy=>: iExitStatus = 0 P00 INFO: restore command end: completed successfully -P00 DEBUG: Common::Exit::exitSafe=>: iExitCode = 0 + supplemental file: [TEST_PATH]/db-master/db/base/recovery.conf ---------------------------------------------------------------- @@ -1654,11 +1655,11 @@ P00 DEBUG: Storage::Posix::Driver->new(): bFileSync = , bPathSync = < P00 DEBUG: Storage::Local->new(): bAllowTemp = , hRule = [hash], lBufferMax = 4194304, oDriver = [object], strCipherPassUser = [undef], strCipherType = [undef], strDefaultFileMode = <0640>, strDefaultPathMode = <0750>, strPathBase = [TEST_PATH]/db-master/repo, strTempExtension = pgbackrest.tmp P00 DEBUG: Storage::Local->pathExists(): strPathExp = P00 DEBUG: Storage::Local->pathExists=>: bExists = true -P00 DEBUG: Common::Lock::lockStopTest(): bStanzaStopRequired = -P00 DEBUG: Common::Lock::lockStopTest=>: bStopExists = false P00 DEBUG: Storage::Posix::Driver->new(): bFileSync = , bPathSync = P00 DEBUG: Storage::Local->new(): bAllowTemp = , hRule = [undef], lBufferMax = 4194304, oDriver = [object], strCipherPassUser = [undef], strCipherType = [undef], strDefaultFileMode = <0640>, strDefaultPathMode = <0750>, strPathBase = /, strTempExtension = pgbackrest.tmp P00 DEBUG: Storage::Local->pathCreate(): bCreateParent = true, bIgnoreExists = true, strMode = 0770, strPathExp = [TEST_PATH]/db-master/log +P00 DEBUG: Common::Lock::lockStopTest(): bStanzaStopRequired = +P00 DEBUG: Common::Lock::lockStopTest=>: bStopExists = false P00 DEBUG: Backup::Info->new(): bIgnoreMissing = , bLoad = , bRequired = , bValidate = , oStorage = <[object]>, strBackupClusterPath = [TEST_PATH]/db-master/repo/backup/db, strCipherPassSub = [undef] P00 DEBUG: Storage::Local->encrypted(): bIgnoreMissing = true, strFileName = [TEST_PATH]/db-master/repo/backup/db/backup.info P00 DEBUG: Storage::Local->encrypted=>: bEncrypted = false @@ -1832,7 +1833,12 @@ P00 DEBUG: Storage::Local->openWrite(): bAtomic = , bPathCreate = pathSync(): bRecurse = , strPathExp = [TEST_PATH]/db-master/repo/backup/db P00 DEBUG: Storage::Local->pathSync(): bRecurse = , strPathExp = P00 INFO: backup command end: completed successfully -P00 INFO: expire command begin [BACKREST-VERSION]: --config=[TEST_PATH]/db-master/pgbackrest.conf --lock-path=[TEST_PATH]/db-master/lock --log-level-console=debug --log-level-file=trace --log-level-stderr=off --log-path=[TEST_PATH]/db-master/log --repo1-path=[TEST_PATH]/db-master/repo --stanza=db +P00 INFO: expire command begin +P00 DEBUG: Storage::Local->pathExists(): strPathExp = +P00 DEBUG: Storage::Local->pathExists=>: bExists = true +P00 DEBUG: Storage::Local->pathCreate(): bCreateParent = true, bIgnoreExists = true, strMode = 0770, strPathExp = [TEST_PATH]/db-master/log +P00 DEBUG: Common::Lock::lockStopTest(): bStanzaStopRequired = +P00 DEBUG: Common::Lock::lockStopTest=>: bStopExists = false P00 DEBUG: Backup::Info->new(): bIgnoreMissing = , bLoad = , bRequired = , bValidate = , oStorage = <[object]>, strBackupClusterPath = [TEST_PATH]/db-master/repo/backup/db, strCipherPassSub = [undef] P00 DEBUG: Storage::Local->encrypted(): bIgnoreMissing = true, strFileName = [TEST_PATH]/db-master/repo/backup/db/backup.info P00 DEBUG: Storage::Local->encrypted=>: bEncrypted = false @@ -1866,11 +1872,10 @@ P00 DEBUG: Backup::Info->current=>: bTest = true P00 DEBUG: Backup::Info->current(): strBackup = [BACKUP-FULL-2] P00 DEBUG: Backup::Info->current=>: bTest = true P00 INFO: option 'repo1-retention-archive' is not set - archive logs will not be expired -P00 DEBUG: Common::Exit::exitSafe(): iExitCode = 0, oException = [undef], strSignal = [undef] +P00 DEBUG: Main::mainCleanup(): iExitCode = 0 P00 DEBUG: Protocol::Helper::protocolDestroy(): bComplete = true, iRemoteIdx = [undef], strRemoteType = [undef] P00 DEBUG: Protocol::Helper::protocolDestroy=>: iExitStatus = 0 P00 INFO: expire command end: completed successfully -P00 DEBUG: Common::Exit::exitSafe=>: iExitCode = 0 + supplemental file: [TEST_PATH]/db-master/pgbackrest.conf ---------------------------------------------------------- @@ -2016,11 +2021,11 @@ P00 DEBUG: Storage::Posix::Driver->new(): bFileSync = , bPathSync = < P00 DEBUG: Storage::Local->new(): bAllowTemp = , hRule = [hash], lBufferMax = 4194304, oDriver = [object], strCipherPassUser = [undef], strCipherType = [undef], strDefaultFileMode = <0640>, strDefaultPathMode = <0750>, strPathBase = [TEST_PATH]/db-master/repo, strTempExtension = pgbackrest.tmp P00 DEBUG: Storage::Local->pathExists(): strPathExp = P00 DEBUG: Storage::Local->pathExists=>: bExists = true -P00 DEBUG: Common::Lock::lockStopTest(): bStanzaStopRequired = -P00 DEBUG: Common::Lock::lockStopTest=>: bStopExists = false P00 DEBUG: Storage::Posix::Driver->new(): bFileSync = , bPathSync = P00 DEBUG: Storage::Local->new(): bAllowTemp = , hRule = [undef], lBufferMax = 4194304, oDriver = [object], strCipherPassUser = [undef], strCipherType = [undef], strDefaultFileMode = <0640>, strDefaultPathMode = <0750>, strPathBase = /, strTempExtension = pgbackrest.tmp P00 DEBUG: Storage::Local->pathCreate(): bCreateParent = true, bIgnoreExists = true, strMode = 0770, strPathExp = [TEST_PATH]/db-master/log +P00 DEBUG: Common::Lock::lockStopTest(): bStanzaStopRequired = +P00 DEBUG: Common::Lock::lockStopTest=>: bStopExists = false P00 DEBUG: Backup::Info->new(): bIgnoreMissing = , bLoad = , bRequired = , bValidate = , oStorage = <[object]>, strBackupClusterPath = [TEST_PATH]/db-master/repo/backup/db, strCipherPassSub = [undef] P00 DEBUG: Storage::Local->encrypted(): bIgnoreMissing = true, strFileName = [TEST_PATH]/db-master/repo/backup/db/backup.info P00 DEBUG: Storage::Local->encrypted=>: bEncrypted = false @@ -2238,7 +2243,12 @@ P00 DEBUG: Storage::Local->openWrite(): bAtomic = , bPathCreate = pathSync(): bRecurse = , strPathExp = [TEST_PATH]/db-master/repo/backup/db P00 DEBUG: Storage::Local->pathSync(): bRecurse = , strPathExp = P00 INFO: backup command end: completed successfully -P00 INFO: expire command begin [BACKREST-VERSION]: --config=[TEST_PATH]/db-master/pgbackrest.conf --lock-path=[TEST_PATH]/db-master/lock --log-level-console=debug --log-level-file=trace --log-level-stderr=off --log-path=[TEST_PATH]/db-master/log --repo1-path=[TEST_PATH]/db-master/repo --stanza=db +P00 INFO: expire command begin +P00 DEBUG: Storage::Local->pathExists(): strPathExp = +P00 DEBUG: Storage::Local->pathExists=>: bExists = true +P00 DEBUG: Storage::Local->pathCreate(): bCreateParent = true, bIgnoreExists = true, strMode = 0770, strPathExp = [TEST_PATH]/db-master/log +P00 DEBUG: Common::Lock::lockStopTest(): bStanzaStopRequired = +P00 DEBUG: Common::Lock::lockStopTest=>: bStopExists = false P00 DEBUG: Backup::Info->new(): bIgnoreMissing = , bLoad = , bRequired = , bValidate = , oStorage = <[object]>, strBackupClusterPath = [TEST_PATH]/db-master/repo/backup/db, strCipherPassSub = [undef] P00 DEBUG: Storage::Local->encrypted(): bIgnoreMissing = true, strFileName = [TEST_PATH]/db-master/repo/backup/db/backup.info P00 DEBUG: Storage::Local->encrypted=>: bEncrypted = false @@ -2272,11 +2282,10 @@ P00 DEBUG: Backup::Info->current=>: bTest = true P00 DEBUG: Backup::Info->current(): strBackup = [BACKUP-FULL-2] P00 DEBUG: Backup::Info->current=>: bTest = true P00 INFO: option 'repo1-retention-archive' is not set - archive logs will not be expired -P00 DEBUG: Common::Exit::exitSafe(): iExitCode = 0, oException = [undef], strSignal = [undef] +P00 DEBUG: Main::mainCleanup(): iExitCode = 0 P00 DEBUG: Protocol::Helper::protocolDestroy(): bComplete = true, iRemoteIdx = [undef], strRemoteType = [undef] P00 DEBUG: Protocol::Helper::protocolDestroy=>: iExitStatus = 0 P00 INFO: expire command end: completed successfully -P00 DEBUG: Common::Exit::exitSafe=>: iExitCode = 0 + supplemental file: [TEST_PATH]/db-master/pgbackrest.conf ---------------------------------------------------------- @@ -2441,7 +2450,7 @@ P00 WARN: page misalignment in file [TEST_PATH]/db-master/db/base/pg_tblspc/1/ P00 INFO: diff backup size = 25B P00 INFO: new backup label = [BACKUP-DIFF-1] P00 INFO: backup command end: completed successfully -P00 INFO: expire command begin [BACKREST-VERSION]: --config=[TEST_PATH]/db-master/pgbackrest.conf --lock-path=[TEST_PATH]/db-master/lock --log-level-console=detail --log-level-file=trace --log-level-stderr=off --log-path=[TEST_PATH]/db-master/log --repo1-path=[TEST_PATH]/db-master/repo --stanza=db +P00 INFO: expire command begin P00 INFO: option 'repo1-retention-archive' is not set - archive logs will not be expired P00 INFO: expire command end: completed successfully @@ -2604,7 +2613,7 @@ P00 WARN: page misalignment in file [TEST_PATH]/db-master/db/base/pg_tblspc/1/ P00 INFO: diff backup size = 25B P00 INFO: new backup label = [BACKUP-DIFF-2] P00 INFO: backup command end: completed successfully -P00 INFO: expire command begin [BACKREST-VERSION]: --config=[TEST_PATH]/db-master/pgbackrest.conf --lock-path=[TEST_PATH]/db-master/lock --log-level-console=detail --log-level-file=trace --log-level-stderr=off --log-path=[TEST_PATH]/db-master/log --repo1-path=[TEST_PATH]/db-master/repo --stanza=db +P00 INFO: expire command begin P00 INFO: option 'repo1-retention-archive' is not set - archive logs will not be expired P00 INFO: expire command end: completed successfully @@ -2844,7 +2853,7 @@ P00 WARN: page misalignment in file [TEST_PATH]/db-master/db/base-2/base/base2 P00 INFO: incr backup size = 13B P00 INFO: new backup label = [BACKUP-INCR-3] P00 INFO: backup command end: completed successfully -P00 INFO: expire command begin [BACKREST-VERSION]: --config=[TEST_PATH]/db-master/pgbackrest.conf --lock-path=[TEST_PATH]/db-master/lock --log-level-console=detail --log-level-file=trace --log-level-stderr=off --log-path=[TEST_PATH]/db-master/log --repo1-path=[TEST_PATH]/db-master/repo --stanza=db +P00 INFO: expire command begin P00 INFO: option 'repo1-retention-archive' is not set - archive logs will not be expired P00 INFO: expire command end: completed successfully @@ -3079,7 +3088,7 @@ P00 WARN: page misalignment in file [TEST_PATH]/db-master/db/base-2/base/16384 P00 INFO: incr backup size = 8B P00 INFO: new backup label = [BACKUP-INCR-4] P00 INFO: backup command end: completed successfully -P00 INFO: expire command begin [BACKREST-VERSION]: --config=[TEST_PATH]/db-master/pgbackrest.conf --lock-path=[TEST_PATH]/db-master/lock --log-level-console=detail --log-level-file=trace --log-level-stderr=off --log-path=[TEST_PATH]/db-master/log --repo1-path=[TEST_PATH]/db-master/repo --stanza=db +P00 INFO: expire command begin P00 INFO: option 'repo1-retention-archive' is not set - archive logs will not be expired P00 INFO: expire command end: completed successfully @@ -3245,7 +3254,7 @@ P00 WARN: page misalignment in file [TEST_PATH]/db-master/db/base-2/pg_tblspc/ P00 INFO: diff backup size = 39B P00 INFO: new backup label = [BACKUP-DIFF-3] P00 INFO: backup command end: completed successfully -P00 INFO: expire command begin [BACKREST-VERSION]: --config=[TEST_PATH]/db-master/pgbackrest.conf --lock-path=[TEST_PATH]/db-master/lock --log-level-console=detail --log-level-file=trace --log-level-stderr=off --log-path=[TEST_PATH]/db-master/log --repo1-path=[TEST_PATH]/db-master/repo --stanza=db +P00 INFO: expire command begin P00 INFO: option 'repo1-retention-archive' is not set - archive logs will not be expired P00 INFO: expire command end: completed successfully @@ -3405,7 +3414,7 @@ P00 TEST: PgBaCkReStTeSt-MANIFEST-BUILD-PgBaCkReStTeSt P00 INFO: incr backup size = 0B P00 INFO: new backup label = [BACKUP-INCR-5] P00 INFO: backup command end: completed successfully -P00 INFO: expire command begin [BACKREST-VERSION]: --config=[TEST_PATH]/db-master/pgbackrest.conf --lock-path=[TEST_PATH]/db-master/lock --log-level-console=detail --log-level-file=trace --log-level-stderr=off --log-path=[TEST_PATH]/db-master/log --repo1-path=[TEST_PATH]/db-master/repo --stanza=db +P00 INFO: expire command begin P00 INFO: option 'repo1-retention-archive' is not set - archive logs will not be expired P00 INFO: expire command end: completed successfully @@ -3573,7 +3582,7 @@ P00 WARN: page misalignment in file [TEST_PATH]/db-master/db/base-2/pg_tblspc/ P00 INFO: diff backup size = 31B P00 INFO: new backup label = [BACKUP-DIFF-4] P00 INFO: backup command end: completed successfully -P00 INFO: expire command begin [BACKREST-VERSION]: --config=[TEST_PATH]/db-master/pgbackrest.conf --lock-path=[TEST_PATH]/db-master/lock --log-level-console=detail --log-level-file=trace --log-level-stderr=off --log-path=[TEST_PATH]/db-master/log --repo1-path=[TEST_PATH]/db-master/repo --stanza=db +P00 INFO: expire command begin P00 INFO: option 'repo1-retention-archive' is not set - archive logs will not be expired P00 INFO: expire command end: completed successfully @@ -3745,7 +3754,7 @@ P01 INFO: backup file [TEST_PATH]/db-master/db/base-2/pg_tblspc/2/[TS_PATH-1]/ P00 INFO: full backup size = 144KB P00 INFO: new backup label = [BACKUP-FULL-3] P00 INFO: backup command end: completed successfully -P00 INFO: expire command begin [BACKREST-VERSION]: --config=[TEST_PATH]/db-master/pgbackrest.conf --lock-path=[TEST_PATH]/db-master/lock --log-level-console=detail --log-level-file=trace --log-level-stderr=off --log-path=[TEST_PATH]/db-master/log --repo1-path=[TEST_PATH]/db-master/repo --stanza=db +P00 INFO: expire command begin P00 INFO: option 'repo1-retention-archive' is not set - archive logs will not be expired P00 INFO: expire command end: completed successfully @@ -4277,7 +4286,7 @@ P01 INFO: backup file [TEST_PATH]/db-master/db/base-2/base/base2.txt (9B, 100% P00 INFO: diff backup size = 9B P00 INFO: new backup label = [BACKUP-DIFF-5] P00 INFO: backup command end: completed successfully -P00 INFO: expire command begin [BACKREST-VERSION]: --config=[TEST_PATH]/db-master/pgbackrest.conf --lock-path=[TEST_PATH]/db-master/lock --log-level-console=detail --log-level-file=trace --log-level-stderr=off --log-path=[TEST_PATH]/db-master/log --repo1-path=[TEST_PATH]/db-master/repo --stanza=db +P00 INFO: expire command begin P00 INFO: option 'repo1-retention-archive' is not set - archive logs will not be expired P00 INFO: expire command end: completed successfully @@ -4731,7 +4740,7 @@ P01 INFO: backup file [TEST_PATH]/db-master/db/base-2/base/base/base2.txt (9B, P00 INFO: diff backup size = 9B P00 INFO: new backup label = [BACKUP-DIFF-6] P00 INFO: backup command end: completed successfully -P00 INFO: expire command begin [BACKREST-VERSION]: --config=[TEST_PATH]/db-master/pgbackrest.conf --lock-path=[TEST_PATH]/db-master/lock --log-level-console=info --log-level-file=trace --log-level-stderr=off --log-path=[TEST_PATH]/db-master/log --repo1-path=[TEST_PATH]/db-master/repo --stanza=db +P00 INFO: expire command begin P00 INFO: option 'repo1-retention-archive' is not set - archive logs will not be expired P00 INFO: expire command end: completed successfully @@ -4888,7 +4897,7 @@ P01 INFO: backup file [TEST_PATH]/db-master/db/base-2/base/base/base2.txt (9B, P00 INFO: diff backup size = 9B P00 INFO: new backup label = [BACKUP-DIFF-7] P00 INFO: backup command end: completed successfully -P00 INFO: expire command begin [BACKREST-VERSION]: --config=[TEST_PATH]/db-master/pgbackrest.conf --lock-path=[TEST_PATH]/db-master/lock --log-level-console=info --log-level-file=trace --log-level-stderr=off --log-path=[TEST_PATH]/db-master/log --repo1-path=[TEST_PATH]/db-master/repo --stanza=db +P00 INFO: expire command begin P00 INFO: option 'repo1-retention-archive' is not set - archive logs will not be expired P00 INFO: expire command end: completed successfully diff --git a/test/expect/mock-all-002.log b/test/expect/mock-all-002.log index 44e24bfa4..655e77d01 100644 --- a/test/expect/mock-all-002.log +++ b/test/expect/mock-all-002.log @@ -77,11 +77,11 @@ P00 DEBUG: Storage::Posix::Driver->new(): bFileSync = , bPathSync = < P00 DEBUG: Storage::Local->new(): bAllowTemp = , hRule = [hash], lBufferMax = 16384, oDriver = [object], strCipherPassUser = [undef], strCipherType = [undef], strDefaultFileMode = <0640>, strDefaultPathMode = <0750>, strPathBase = [TEST_PATH]/backup/repo, strTempExtension = pgbackrest.tmp P00 DEBUG: Storage::Local->pathExists(): strPathExp = P00 DEBUG: Storage::Local->pathExists=>: bExists = true -P00 DEBUG: Common::Lock::lockStopTest(): bStanzaStopRequired = -P00 DEBUG: Common::Lock::lockStopTest=>: bStopExists = false P00 DEBUG: Storage::Posix::Driver->new(): bFileSync = , bPathSync = P00 DEBUG: Storage::Local->new(): bAllowTemp = , hRule = [undef], lBufferMax = 16384, oDriver = [object], strCipherPassUser = [undef], strCipherType = [undef], strDefaultFileMode = <0640>, strDefaultPathMode = <0750>, strPathBase = /, strTempExtension = pgbackrest.tmp P00 DEBUG: Storage::Local->pathCreate(): bCreateParent = true, bIgnoreExists = true, strMode = 0770, strPathExp = [TEST_PATH]/backup/log +P00 DEBUG: Common::Lock::lockStopTest(): bStanzaStopRequired = +P00 DEBUG: Common::Lock::lockStopTest=>: bStopExists = false P00 DEBUG: Backup::Info->new(): bIgnoreMissing = , bLoad = , bRequired = , bValidate = , oStorage = <[object]>, strBackupClusterPath = [TEST_PATH]/backup/repo/backup/db, strCipherPassSub = [undef] P00 DEBUG: Storage::Local->encrypted(): bIgnoreMissing = true, strFileName = [TEST_PATH]/backup/repo/backup/db/backup.info P00 DEBUG: Storage::Local->encrypted=>: bEncrypted = false @@ -277,7 +277,12 @@ P00 DEBUG: Storage::Local->pathSync(): bRecurse = , strPathExp = [TE P00 DEBUG: Storage::Local->openWrite(): bAtomic = , bPathCreate = , lTimestamp = [undef], rhyFilter = [undef], strCipherPass = [undef], strGroup = [undef], strMode = <0640>, strUser = [undef], xFileExp = [TEST_PATH]/backup/repo/backup/db/backup.info.copy P00 DEBUG: Storage::Local->pathSync(): bRecurse = , strPathExp = [TEST_PATH]/backup/repo/backup/db P00 INFO: backup command end: completed successfully -P00 INFO: expire command begin [BACKREST-VERSION]: --buffer-size=16384 --cmd-ssh=/usr/bin/ssh --config=[TEST_PATH]/backup/pgbackrest.conf --lock-path=[TEST_PATH]/backup/lock --log-level-console=debug --log-level-file=trace --log-level-stderr=off --log-path=[TEST_PATH]/backup/log --pg1-host=db-master --pg1-host-cmd=[BACKREST-BIN] --pg1-host-config=[TEST_PATH]/db-master/pgbackrest.conf --pg1-host-user=[USER-1] --repo1-path=[TEST_PATH]/backup/repo --repo1-type=cifs --stanza=db +P00 INFO: expire command begin +P00 DEBUG: Storage::Local->pathExists(): strPathExp = +P00 DEBUG: Storage::Local->pathExists=>: bExists = true +P00 DEBUG: Storage::Local->pathCreate(): bCreateParent = true, bIgnoreExists = true, strMode = 0770, strPathExp = [TEST_PATH]/backup/log +P00 DEBUG: Common::Lock::lockStopTest(): bStanzaStopRequired = +P00 DEBUG: Common::Lock::lockStopTest=>: bStopExists = false P00 DEBUG: Backup::Info->new(): bIgnoreMissing = , bLoad = , bRequired = , bValidate = , oStorage = <[object]>, strBackupClusterPath = [TEST_PATH]/backup/repo/backup/db, strCipherPassSub = [undef] P00 DEBUG: Storage::Local->encrypted(): bIgnoreMissing = true, strFileName = [TEST_PATH]/backup/repo/backup/db/backup.info P00 DEBUG: Storage::Local->encrypted=>: bEncrypted = false @@ -303,11 +308,10 @@ P00 DEBUG: Storage::Local->list=>: stryFileList = ([BACKUP-FULL-1]) P00 DEBUG: Backup::Info->current(): strBackup = [BACKUP-FULL-1] P00 DEBUG: Backup::Info->current=>: bTest = true P00 INFO: option 'repo1-retention-archive' is not set - archive logs will not be expired -P00 DEBUG: Common::Exit::exitSafe(): iExitCode = 0, oException = [undef], strSignal = [undef] +P00 DEBUG: Main::mainCleanup(): iExitCode = 0 P00 DEBUG: Protocol::Helper::protocolDestroy(): bComplete = true, iRemoteIdx = [undef], strRemoteType = [undef] P00 DEBUG: Protocol::Helper::protocolDestroy=>: iExitStatus = 0 P00 INFO: expire command end: completed successfully -P00 DEBUG: Common::Exit::exitSafe=>: iExitCode = 0 + supplemental file: [TEST_PATH]/db-master/pgbackrest.conf ---------------------------------------------------------- @@ -469,11 +473,10 @@ P00 DEBUG: Storage::Posix::Driver->new(): bFileSync = , bPathSync = < P00 DEBUG: Storage::Local->new(): bAllowTemp = , hRule = [undef], lBufferMax = [undef], oDriver = [object], strCipherPassUser = [undef], strCipherType = [undef], strDefaultFileMode = <0640>, strDefaultPathMode = <0750>, strPathBase = /, strTempExtension = pgbackrest.tmp P00 DEBUG: Storage::Local->pathCreate(): bCreateParent = true, bIgnoreExists = true, strMode = 770, strPathExp = [TEST_PATH]/db-master/lock P00 INFO: sent term signal to process [PROCESS-ID] -P00 DEBUG: Common::Exit::exitSafe(): iExitCode = 0, oException = [undef], strSignal = [undef] +P00 DEBUG: Main::mainCleanup(): iExitCode = 0 P00 DEBUG: Protocol::Helper::protocolDestroy(): bComplete = true, iRemoteIdx = [undef], strRemoteType = [undef] P00 DEBUG: Protocol::Helper::protocolDestroy=>: iExitStatus = 0 P00 INFO: stop command end: completed successfully -P00 DEBUG: Common::Exit::exitSafe=>: iExitCode = 0 full backup - abort backup - local (backup host) > [CONTAINER-EXEC] backup [BACKREST-BIN] --config=[TEST_PATH]/backup/pgbackrest.conf --no-online --type=full --stanza=db backup --test --test-delay=5 --test-point=backup-start=y @@ -485,11 +488,11 @@ P00 DEBUG: Storage::Posix::Driver->new(): bFileSync = , bPathSync = < P00 DEBUG: Storage::Local->new(): bAllowTemp = , hRule = [hash], lBufferMax = 4194304, oDriver = [object], strCipherPassUser = [undef], strCipherType = [undef], strDefaultFileMode = <0640>, strDefaultPathMode = <0750>, strPathBase = [TEST_PATH]/backup/repo, strTempExtension = pgbackrest.tmp P00 DEBUG: Storage::Local->pathExists(): strPathExp = P00 DEBUG: Storage::Local->pathExists=>: bExists = true -P00 DEBUG: Common::Lock::lockStopTest(): bStanzaStopRequired = -P00 DEBUG: Common::Lock::lockStopTest=>: bStopExists = false P00 DEBUG: Storage::Posix::Driver->new(): bFileSync = , bPathSync = P00 DEBUG: Storage::Local->new(): bAllowTemp = , hRule = [undef], lBufferMax = 4194304, oDriver = [object], strCipherPassUser = [undef], strCipherType = [undef], strDefaultFileMode = <0640>, strDefaultPathMode = <0750>, strPathBase = /, strTempExtension = pgbackrest.tmp P00 DEBUG: Storage::Local->pathCreate(): bCreateParent = true, bIgnoreExists = true, strMode = 0770, strPathExp = [TEST_PATH]/backup/log +P00 DEBUG: Common::Lock::lockStopTest(): bStanzaStopRequired = +P00 DEBUG: Common::Lock::lockStopTest=>: bStopExists = false P00 DEBUG: Backup::Info->new(): bIgnoreMissing = , bLoad = , bRequired = , bValidate = , oStorage = <[object]>, strBackupClusterPath = [TEST_PATH]/backup/repo/backup/db, strCipherPassSub = [undef] P00 DEBUG: Storage::Local->encrypted(): bIgnoreMissing = true, strFileName = [TEST_PATH]/backup/repo/backup/db/backup.info P00 DEBUG: Storage::Local->encrypted=>: bEncrypted = false @@ -570,13 +573,12 @@ P00 DEBUG: Backup::Backup->processManifest(): bCompress = false, bHardLink P00 TEST: PgBaCkReStTeSt-BACKUP-START-PgBaCkReStTeSt P00 DEBUG: Protocol::Helper::protocolGet(): bCache = , iProcessIdx = [undef], iRemoteIdx = 1, strBackRestBin = [undef], strCommand = , strRemoteType = db P00 DEBUG: Protocol::Helper::protocolGet: found cached protocol -P00 ERROR: [063]: remote process on 'db-master' terminated unexpectedly [063]: terminated on signal [SIGTERM] -P00 DEBUG: Common::Exit::exitSafe(): iExitCode = [undef], oException = [object], strSignal = [undef] +P00 ERROR: [063]: remote process on 'db-master' terminated unexpectedly [063] +P00 DEBUG: Main::mainCleanup(): iExitCode = 63 P00 DEBUG: Protocol::Helper::protocolDestroy(): bComplete = false, iRemoteIdx = [undef], strRemoteType = [undef] P00 DEBUG: Protocol::Helper::protocolDestroy: found cached protocol: iRemoteIdx = 1, strRemoteType = db P00 DEBUG: Protocol::Helper::protocolDestroy=>: iExitStatus = 0 P00 INFO: backup command end: terminated on signal from child process -P00 DEBUG: Common::Exit::exitSafe=>: iExitCode = 63 full backup - global stop (backup host) > [CONTAINER-EXEC] backup [BACKREST-BIN] --config=[TEST_PATH]/backup/pgbackrest.conf --no-online --type=full --stanza=db backup @@ -588,11 +590,11 @@ P00 DEBUG: Storage::Posix::Driver->new(): bFileSync = , bPathSync = < P00 DEBUG: Storage::Local->new(): bAllowTemp = , hRule = [hash], lBufferMax = 4194304, oDriver = [object], strCipherPassUser = [undef], strCipherType = [undef], strDefaultFileMode = <0640>, strDefaultPathMode = <0750>, strPathBase = [TEST_PATH]/backup/repo, strTempExtension = pgbackrest.tmp P00 DEBUG: Storage::Local->pathExists(): strPathExp = P00 DEBUG: Storage::Local->pathExists=>: bExists = true -P00 DEBUG: Common::Lock::lockStopTest(): bStanzaStopRequired = -P00 DEBUG: Common::Lock::lockStopTest=>: bStopExists = false P00 DEBUG: Storage::Posix::Driver->new(): bFileSync = , bPathSync = P00 DEBUG: Storage::Local->new(): bAllowTemp = , hRule = [undef], lBufferMax = 4194304, oDriver = [object], strCipherPassUser = [undef], strCipherType = [undef], strDefaultFileMode = <0640>, strDefaultPathMode = <0750>, strPathBase = /, strTempExtension = pgbackrest.tmp P00 DEBUG: Storage::Local->pathCreate(): bCreateParent = true, bIgnoreExists = true, strMode = 0770, strPathExp = [TEST_PATH]/backup/log +P00 DEBUG: Common::Lock::lockStopTest(): bStanzaStopRequired = +P00 DEBUG: Common::Lock::lockStopTest=>: bStopExists = false P00 DEBUG: Backup::Info->new(): bIgnoreMissing = , bLoad = , bRequired = , bValidate = , oStorage = <[object]>, strBackupClusterPath = [TEST_PATH]/backup/repo/backup/db, strCipherPassSub = [undef] P00 DEBUG: Storage::Local->encrypted(): bIgnoreMissing = true, strFileName = [TEST_PATH]/backup/repo/backup/db/backup.info P00 DEBUG: Storage::Local->encrypted=>: bEncrypted = false @@ -625,11 +627,10 @@ P00 DEBUG: Protocol::Remote::Master->new(): iBufferMax = 4194304, iCompress P00 DEBUG: Protocol::Command::Master->new(): iBufferMax = 4194304, iCompressLevel = 3, iCompressLevelNetwork = 1, iProtocolTimeout = 60, strCommand = ssh -o LogLevel=error -o Compression=no -o PasswordAuthentication=no [USER-1]@db-master '[BACKREST-BIN] --buffer-size=4194304 --command=backup --compress-level=3 --compress-level-network=1 --config=[TEST_PATH]/db-master/pgbackrest.conf --db-timeout=45 --pg1-path=[TEST_PATH]/db-master/db/base --protocol-timeout=60 --repo1-path=[TEST_PATH]/backup/repo --stanza=db --type=db remote', strId = remote process on 'db-master', strName = remote P00 ERROR: [062]: raised from remote process on 'db-master': stop file exists for all stanzas P00 DEBUG: Protocol::Command::Master->close=>: iExitStatus = 0 -P00 DEBUG: Common::Exit::exitSafe(): iExitCode = [undef], oException = [object], strSignal = [undef] +P00 DEBUG: Main::mainCleanup(): iExitCode = 62 P00 DEBUG: Protocol::Helper::protocolDestroy(): bComplete = false, iRemoteIdx = [undef], strRemoteType = [undef] P00 DEBUG: Protocol::Helper::protocolDestroy=>: iExitStatus = 0 P00 INFO: backup command end: aborted with exception [062] -P00 DEBUG: Common::Exit::exitSafe=>: iExitCode = 62 stop db stanza (db-master host) > [CONTAINER-EXEC] db-master [BACKREST-BIN] --config=[TEST_PATH]/db-master/pgbackrest.conf --stanza=db stop @@ -638,11 +639,10 @@ P00 INFO: stop command begin [BACKREST-VERSION]: --config=[TEST_PATH]/db-maste P00 DEBUG: Storage::Posix::Driver->new(): bFileSync = , bPathSync = P00 DEBUG: Storage::Local->new(): bAllowTemp = , hRule = [undef], lBufferMax = [undef], oDriver = [object], strCipherPassUser = [undef], strCipherType = [undef], strDefaultFileMode = <0640>, strDefaultPathMode = <0750>, strPathBase = /, strTempExtension = pgbackrest.tmp P00 DEBUG: Storage::Local->pathCreate(): bCreateParent = true, bIgnoreExists = true, strMode = 770, strPathExp = [TEST_PATH]/db-master/lock -P00 DEBUG: Common::Exit::exitSafe(): iExitCode = 0, oException = [undef], strSignal = [undef] +P00 DEBUG: Main::mainCleanup(): iExitCode = 0 P00 DEBUG: Protocol::Helper::protocolDestroy(): bComplete = true, iRemoteIdx = [undef], strRemoteType = [undef] P00 DEBUG: Protocol::Helper::protocolDestroy=>: iExitStatus = 0 P00 INFO: stop command end: completed successfully -P00 DEBUG: Common::Exit::exitSafe=>: iExitCode = 0 stop db stanza (db-master host) > [CONTAINER-EXEC] db-master [BACKREST-BIN] --config=[TEST_PATH]/db-master/pgbackrest.conf --stanza=db stop @@ -652,11 +652,10 @@ P00 DEBUG: Storage::Posix::Driver->new(): bFileSync = , bPathSync = < P00 DEBUG: Storage::Local->new(): bAllowTemp = , hRule = [undef], lBufferMax = [undef], oDriver = [object], strCipherPassUser = [undef], strCipherType = [undef], strDefaultFileMode = <0640>, strDefaultPathMode = <0750>, strPathBase = /, strTempExtension = pgbackrest.tmp P00 DEBUG: Storage::Local->pathCreate(): bCreateParent = true, bIgnoreExists = true, strMode = 770, strPathExp = [TEST_PATH]/db-master/lock P00 WARN: stop file already exists for stanza db -P00 DEBUG: Common::Exit::exitSafe(): iExitCode = 0, oException = [undef], strSignal = [undef] +P00 DEBUG: Main::mainCleanup(): iExitCode = 0 P00 DEBUG: Protocol::Helper::protocolDestroy(): bComplete = true, iRemoteIdx = [undef], strRemoteType = [undef] P00 DEBUG: Protocol::Helper::protocolDestroy=>: iExitStatus = 0 P00 INFO: stop command end: completed successfully -P00 DEBUG: Common::Exit::exitSafe=>: iExitCode = 0 full backup - stanza stop (backup host) > [CONTAINER-EXEC] backup [BACKREST-BIN] --config=[TEST_PATH]/backup/pgbackrest.conf --no-online --type=full --stanza=db backup @@ -668,11 +667,11 @@ P00 DEBUG: Storage::Posix::Driver->new(): bFileSync = , bPathSync = < P00 DEBUG: Storage::Local->new(): bAllowTemp = , hRule = [hash], lBufferMax = 4194304, oDriver = [object], strCipherPassUser = [undef], strCipherType = [undef], strDefaultFileMode = <0640>, strDefaultPathMode = <0750>, strPathBase = [TEST_PATH]/backup/repo, strTempExtension = pgbackrest.tmp P00 DEBUG: Storage::Local->pathExists(): strPathExp = P00 DEBUG: Storage::Local->pathExists=>: bExists = true -P00 DEBUG: Common::Lock::lockStopTest(): bStanzaStopRequired = -P00 DEBUG: Common::Lock::lockStopTest=>: bStopExists = false P00 DEBUG: Storage::Posix::Driver->new(): bFileSync = , bPathSync = P00 DEBUG: Storage::Local->new(): bAllowTemp = , hRule = [undef], lBufferMax = 4194304, oDriver = [object], strCipherPassUser = [undef], strCipherType = [undef], strDefaultFileMode = <0640>, strDefaultPathMode = <0750>, strPathBase = /, strTempExtension = pgbackrest.tmp P00 DEBUG: Storage::Local->pathCreate(): bCreateParent = true, bIgnoreExists = true, strMode = 0770, strPathExp = [TEST_PATH]/backup/log +P00 DEBUG: Common::Lock::lockStopTest(): bStanzaStopRequired = +P00 DEBUG: Common::Lock::lockStopTest=>: bStopExists = false P00 DEBUG: Backup::Info->new(): bIgnoreMissing = , bLoad = , bRequired = , bValidate = , oStorage = <[object]>, strBackupClusterPath = [TEST_PATH]/backup/repo/backup/db, strCipherPassSub = [undef] P00 DEBUG: Storage::Local->encrypted(): bIgnoreMissing = true, strFileName = [TEST_PATH]/backup/repo/backup/db/backup.info P00 DEBUG: Storage::Local->encrypted=>: bEncrypted = false @@ -705,42 +704,38 @@ P00 DEBUG: Protocol::Remote::Master->new(): iBufferMax = 4194304, iCompress P00 DEBUG: Protocol::Command::Master->new(): iBufferMax = 4194304, iCompressLevel = 3, iCompressLevelNetwork = 1, iProtocolTimeout = 60, strCommand = ssh -o LogLevel=error -o Compression=no -o PasswordAuthentication=no [USER-1]@db-master '[BACKREST-BIN] --buffer-size=4194304 --command=backup --compress-level=3 --compress-level-network=1 --config=[TEST_PATH]/db-master/pgbackrest.conf --db-timeout=45 --pg1-path=[TEST_PATH]/db-master/db/base --protocol-timeout=60 --repo1-path=[TEST_PATH]/backup/repo --stanza=db --type=db remote', strId = remote process on 'db-master', strName = remote P00 ERROR: [062]: raised from remote process on 'db-master': stop file exists for stanza db P00 DEBUG: Protocol::Command::Master->close=>: iExitStatus = 0 -P00 DEBUG: Common::Exit::exitSafe(): iExitCode = [undef], oException = [object], strSignal = [undef] +P00 DEBUG: Main::mainCleanup(): iExitCode = 62 P00 DEBUG: Protocol::Helper::protocolDestroy(): bComplete = false, iRemoteIdx = [undef], strRemoteType = [undef] P00 DEBUG: Protocol::Helper::protocolDestroy=>: iExitStatus = 0 P00 INFO: backup command end: aborted with exception [062] -P00 DEBUG: Common::Exit::exitSafe=>: iExitCode = 62 start db stanza (db-master host) > [CONTAINER-EXEC] db-master [BACKREST-BIN] --config=[TEST_PATH]/db-master/pgbackrest.conf --stanza=db start ------------------------------------------------------------------------------------------------------------------------------------ P00 INFO: start command begin [BACKREST-VERSION]: --config=[TEST_PATH]/db-master/pgbackrest.conf --lock-path=[TEST_PATH]/db-master/lock --log-level-console=debug --log-level-file=trace --log-level-stderr=off --log-path=[TEST_PATH]/db-master/log --repo1-host=backup --repo1-host-cmd=[BACKREST-BIN] --repo1-host-config=[TEST_PATH]/backup/pgbackrest.conf --repo1-host-user=[USER-2] --stanza=db -P00 DEBUG: Common::Exit::exitSafe(): iExitCode = 0, oException = [undef], strSignal = [undef] +P00 DEBUG: Main::mainCleanup(): iExitCode = 0 P00 DEBUG: Protocol::Helper::protocolDestroy(): bComplete = true, iRemoteIdx = [undef], strRemoteType = [undef] P00 DEBUG: Protocol::Helper::protocolDestroy=>: iExitStatus = 0 P00 INFO: start command end: completed successfully -P00 DEBUG: Common::Exit::exitSafe=>: iExitCode = 0 start all stanzas (db-master host) > [CONTAINER-EXEC] db-master [BACKREST-BIN] --config=[TEST_PATH]/db-master/pgbackrest.conf start ------------------------------------------------------------------------------------------------------------------------------------ P00 INFO: start command begin [BACKREST-VERSION]: --config=[TEST_PATH]/db-master/pgbackrest.conf --lock-path=[TEST_PATH]/db-master/lock --log-level-console=debug --log-level-file=trace --log-level-stderr=off --log-path=[TEST_PATH]/db-master/log --repo1-host=backup --repo1-host-cmd=[BACKREST-BIN] --repo1-host-config=[TEST_PATH]/backup/pgbackrest.conf --repo1-host-user=[USER-2] -P00 DEBUG: Common::Exit::exitSafe(): iExitCode = 0, oException = [undef], strSignal = [undef] +P00 DEBUG: Main::mainCleanup(): iExitCode = 0 P00 DEBUG: Protocol::Helper::protocolDestroy(): bComplete = true, iRemoteIdx = [undef], strRemoteType = [undef] P00 DEBUG: Protocol::Helper::protocolDestroy=>: iExitStatus = 0 P00 INFO: start command end: completed successfully -P00 DEBUG: Common::Exit::exitSafe=>: iExitCode = 0 start all stanzas (db-master host) > [CONTAINER-EXEC] db-master [BACKREST-BIN] --config=[TEST_PATH]/db-master/pgbackrest.conf start ------------------------------------------------------------------------------------------------------------------------------------ P00 INFO: start command begin [BACKREST-VERSION]: --config=[TEST_PATH]/db-master/pgbackrest.conf --lock-path=[TEST_PATH]/db-master/lock --log-level-console=debug --log-level-file=trace --log-level-stderr=off --log-path=[TEST_PATH]/db-master/log --repo1-host=backup --repo1-host-cmd=[BACKREST-BIN] --repo1-host-config=[TEST_PATH]/backup/pgbackrest.conf --repo1-host-user=[USER-2] P00 WARN: stop file does not exist -P00 DEBUG: Common::Exit::exitSafe(): iExitCode = 0, oException = [undef], strSignal = [undef] +P00 DEBUG: Main::mainCleanup(): iExitCode = 0 P00 DEBUG: Protocol::Helper::protocolDestroy(): bComplete = true, iRemoteIdx = [undef], strRemoteType = [undef] P00 DEBUG: Protocol::Helper::protocolDestroy=>: iExitStatus = 0 P00 INFO: start command end: completed successfully -P00 DEBUG: Common::Exit::exitSafe=>: iExitCode = 0 stop all stanzas (backup host) > [CONTAINER-EXEC] backup [BACKREST-BIN] --config=[TEST_PATH]/backup/pgbackrest.conf --force stop @@ -750,11 +745,10 @@ P00 DEBUG: Storage::Posix::Driver->new(): bFileSync = , bPathSync = < P00 DEBUG: Storage::Local->new(): bAllowTemp = , hRule = [undef], lBufferMax = [undef], oDriver = [object], strCipherPassUser = [undef], strCipherType = [undef], strDefaultFileMode = <0640>, strDefaultPathMode = <0750>, strPathBase = /, strTempExtension = pgbackrest.tmp P00 DEBUG: Storage::Local->pathCreate(): bCreateParent = true, bIgnoreExists = true, strMode = 770, strPathExp = [TEST_PATH]/backup/lock P00 INFO: sent term signal to process [PROCESS-ID] -P00 DEBUG: Common::Exit::exitSafe(): iExitCode = 0, oException = [undef], strSignal = [undef] +P00 DEBUG: Main::mainCleanup(): iExitCode = 0 P00 DEBUG: Protocol::Helper::protocolDestroy(): bComplete = true, iRemoteIdx = [undef], strRemoteType = [undef] P00 DEBUG: Protocol::Helper::protocolDestroy=>: iExitStatus = 0 P00 INFO: stop command end: completed successfully -P00 DEBUG: Common::Exit::exitSafe=>: iExitCode = 0 full backup - abort backup - remote (backup host) > [CONTAINER-EXEC] backup [BACKREST-BIN] --config=[TEST_PATH]/backup/pgbackrest.conf --no-online --type=full --stanza=db backup --test --test-delay=5 --test-point=backup-start=y @@ -766,11 +760,11 @@ P00 DEBUG: Storage::Posix::Driver->new(): bFileSync = , bPathSync = < P00 DEBUG: Storage::Local->new(): bAllowTemp = , hRule = [hash], lBufferMax = 4194304, oDriver = [object], strCipherPassUser = [undef], strCipherType = [undef], strDefaultFileMode = <0640>, strDefaultPathMode = <0750>, strPathBase = [TEST_PATH]/backup/repo, strTempExtension = pgbackrest.tmp P00 DEBUG: Storage::Local->pathExists(): strPathExp = P00 DEBUG: Storage::Local->pathExists=>: bExists = true -P00 DEBUG: Common::Lock::lockStopTest(): bStanzaStopRequired = -P00 DEBUG: Common::Lock::lockStopTest=>: bStopExists = false P00 DEBUG: Storage::Posix::Driver->new(): bFileSync = , bPathSync = P00 DEBUG: Storage::Local->new(): bAllowTemp = , hRule = [undef], lBufferMax = 4194304, oDriver = [object], strCipherPassUser = [undef], strCipherType = [undef], strDefaultFileMode = <0640>, strDefaultPathMode = <0750>, strPathBase = /, strTempExtension = pgbackrest.tmp P00 DEBUG: Storage::Local->pathCreate(): bCreateParent = true, bIgnoreExists = true, strMode = 0770, strPathExp = [TEST_PATH]/backup/log +P00 DEBUG: Common::Lock::lockStopTest(): bStanzaStopRequired = +P00 DEBUG: Common::Lock::lockStopTest=>: bStopExists = false P00 DEBUG: Backup::Info->new(): bIgnoreMissing = , bLoad = , bRequired = , bValidate = , oStorage = <[object]>, strBackupClusterPath = [TEST_PATH]/backup/repo/backup/db, strCipherPassSub = [undef] P00 DEBUG: Storage::Local->encrypted(): bIgnoreMissing = true, strFileName = [TEST_PATH]/backup/repo/backup/db/backup.info P00 DEBUG: Storage::Local->encrypted=>: bEncrypted = false @@ -849,14 +843,12 @@ P00 DEBUG: Storage::Local->exists=>: bExists = false P00 DEBUG: Storage::Local->openWrite(): bAtomic = , bPathCreate = , lTimestamp = [undef], rhyFilter = [undef], strCipherPass = [undef], strGroup = [undef], strMode = <0640>, strUser = [undef], xFileExp = [TEST_PATH]/backup/repo/backup/db/[BACKUP-FULL-2]/backup.manifest.copy P00 DEBUG: Backup::Backup->processManifest(): bCompress = false, bHardLink = false, oBackupManifest = [object], strBackupLabel = [BACKUP-FULL-2], strDbCopyPath = [TEST_PATH]/db-master/db/base, strDbMasterPath = [TEST_PATH]/db-master/db/base, strDbVersion = 9.4, strLsnStart = [undef], strType = full P00 TEST: PgBaCkReStTeSt-BACKUP-START-PgBaCkReStTeSt -P00 DEBUG: Common::Exit::exitSafe(): iExitCode = 63, oException = [undef], strSignal = TERM +P00 DEBUG: Main::mainCleanup(): iExitCode = 63 P00 DEBUG: Protocol::Helper::protocolDestroy(): bComplete = false, iRemoteIdx = [undef], strRemoteType = [undef] P00 DEBUG: Protocol::Helper::protocolDestroy: found cached protocol: iRemoteIdx = 1, strRemoteType = db P00 DEBUG: Protocol::Command::Master->close=>: iExitStatus = 0 P00 DEBUG: Protocol::Helper::protocolDestroy=>: iExitStatus = 0 -P00 ERROR: [063]: terminated on signal [SIGTERM] P00 INFO: backup command end: terminated on signal [SIGTERM] -P00 DEBUG: Common::Exit::exitSafe=>: iExitCode = 63 full backup - global stop (backup host) > [CONTAINER-EXEC] backup [BACKREST-BIN] --config=[TEST_PATH]/backup/pgbackrest.conf --no-online --type=full --stanza=db backup @@ -868,23 +860,24 @@ P00 DEBUG: Storage::Posix::Driver->new(): bFileSync = , bPathSync = < P00 DEBUG: Storage::Local->new(): bAllowTemp = , hRule = [hash], lBufferMax = 4194304, oDriver = [object], strCipherPassUser = [undef], strCipherType = [undef], strDefaultFileMode = <0640>, strDefaultPathMode = <0750>, strPathBase = [TEST_PATH]/backup/repo, strTempExtension = pgbackrest.tmp P00 DEBUG: Storage::Local->pathExists(): strPathExp = P00 DEBUG: Storage::Local->pathExists=>: bExists = true +P00 DEBUG: Storage::Posix::Driver->new(): bFileSync = , bPathSync = +P00 DEBUG: Storage::Local->new(): bAllowTemp = , hRule = [undef], lBufferMax = 4194304, oDriver = [object], strCipherPassUser = [undef], strCipherType = [undef], strDefaultFileMode = <0640>, strDefaultPathMode = <0750>, strPathBase = /, strTempExtension = pgbackrest.tmp +P00 DEBUG: Storage::Local->pathCreate(): bCreateParent = true, bIgnoreExists = true, strMode = 0770, strPathExp = [TEST_PATH]/backup/log P00 DEBUG: Common::Lock::lockStopTest(): bStanzaStopRequired = P00 ERROR: [062]: stop file exists for all stanzas -P00 DEBUG: Common::Exit::exitSafe(): iExitCode = [undef], oException = [object], strSignal = [undef] +P00 DEBUG: Main::mainCleanup(): iExitCode = 62 P00 DEBUG: Protocol::Helper::protocolDestroy(): bComplete = false, iRemoteIdx = [undef], strRemoteType = [undef] P00 DEBUG: Protocol::Helper::protocolDestroy=>: iExitStatus = 0 P00 INFO: backup command end: aborted with exception [062] -P00 DEBUG: Common::Exit::exitSafe=>: iExitCode = 62 start all stanzas (backup host) > [CONTAINER-EXEC] backup [BACKREST-BIN] --config=[TEST_PATH]/backup/pgbackrest.conf start ------------------------------------------------------------------------------------------------------------------------------------ P00 INFO: start command begin [BACKREST-VERSION]: --config=[TEST_PATH]/backup/pgbackrest.conf --lock-path=[TEST_PATH]/backup/lock --log-level-console=debug --log-level-file=trace --log-level-stderr=off --log-path=[TEST_PATH]/backup/log --repo1-path=[TEST_PATH]/backup/repo -P00 DEBUG: Common::Exit::exitSafe(): iExitCode = 0, oException = [undef], strSignal = [undef] +P00 DEBUG: Main::mainCleanup(): iExitCode = 0 P00 DEBUG: Protocol::Helper::protocolDestroy(): bComplete = true, iRemoteIdx = [undef], strRemoteType = [undef] P00 DEBUG: Protocol::Helper::protocolDestroy=>: iExitStatus = 0 P00 INFO: start command end: completed successfully -P00 DEBUG: Common::Exit::exitSafe=>: iExitCode = 0 full backup - resume (backup host) > [CONTAINER-EXEC] backup [BACKREST-BIN] --config=[TEST_PATH]/backup/pgbackrest.conf --no-online --force --checksum-page --type=full --stanza=db backup --test --test-delay=0.2 --test-point=backup-resume=y @@ -896,11 +889,11 @@ P00 DEBUG: Storage::Posix::Driver->new(): bFileSync = , bPathSync = < P00 DEBUG: Storage::Local->new(): bAllowTemp = , hRule = [hash], lBufferMax = 4194304, oDriver = [object], strCipherPassUser = [undef], strCipherType = [undef], strDefaultFileMode = <0640>, strDefaultPathMode = <0750>, strPathBase = [TEST_PATH]/backup/repo, strTempExtension = pgbackrest.tmp P00 DEBUG: Storage::Local->pathExists(): strPathExp = P00 DEBUG: Storage::Local->pathExists=>: bExists = true -P00 DEBUG: Common::Lock::lockStopTest(): bStanzaStopRequired = -P00 DEBUG: Common::Lock::lockStopTest=>: bStopExists = false P00 DEBUG: Storage::Posix::Driver->new(): bFileSync = , bPathSync = P00 DEBUG: Storage::Local->new(): bAllowTemp = , hRule = [undef], lBufferMax = 4194304, oDriver = [object], strCipherPassUser = [undef], strCipherType = [undef], strDefaultFileMode = <0640>, strDefaultPathMode = <0750>, strPathBase = /, strTempExtension = pgbackrest.tmp P00 DEBUG: Storage::Local->pathCreate(): bCreateParent = true, bIgnoreExists = true, strMode = 0770, strPathExp = [TEST_PATH]/backup/log +P00 DEBUG: Common::Lock::lockStopTest(): bStanzaStopRequired = +P00 DEBUG: Common::Lock::lockStopTest=>: bStopExists = false P00 DEBUG: Backup::Info->new(): bIgnoreMissing = , bLoad = , bRequired = , bValidate = , oStorage = <[object]>, strBackupClusterPath = [TEST_PATH]/backup/repo/backup/db, strCipherPassSub = [undef] P00 DEBUG: Storage::Local->encrypted(): bIgnoreMissing = true, strFileName = [TEST_PATH]/backup/repo/backup/db/backup.info P00 DEBUG: Storage::Local->encrypted=>: bEncrypted = false @@ -1088,7 +1081,12 @@ P00 DEBUG: Storage::Local->openWrite(): bAtomic = , bPathCreate = pathSync(): bRecurse = , strPathExp = [TEST_PATH]/backup/repo/backup/db P00 DEBUG: Storage::Local->pathSync(): bRecurse = , strPathExp = P00 INFO: backup command end: completed successfully -P00 INFO: expire command begin [BACKREST-VERSION]: --config=[TEST_PATH]/backup/pgbackrest.conf --lock-path=[TEST_PATH]/backup/lock --log-level-console=debug --log-level-file=trace --log-level-stderr=off --log-path=[TEST_PATH]/backup/log --pg1-host=db-master --pg1-host-cmd=[BACKREST-BIN] --pg1-host-config=[TEST_PATH]/db-master/pgbackrest.conf --pg1-host-user=[USER-1] --repo1-path=[TEST_PATH]/backup/repo --stanza=db +P00 INFO: expire command begin +P00 DEBUG: Storage::Local->pathExists(): strPathExp = +P00 DEBUG: Storage::Local->pathExists=>: bExists = true +P00 DEBUG: Storage::Local->pathCreate(): bCreateParent = true, bIgnoreExists = true, strMode = 0770, strPathExp = [TEST_PATH]/backup/log +P00 DEBUG: Common::Lock::lockStopTest(): bStanzaStopRequired = +P00 DEBUG: Common::Lock::lockStopTest=>: bStopExists = false P00 DEBUG: Backup::Info->new(): bIgnoreMissing = , bLoad = , bRequired = , bValidate = , oStorage = <[object]>, strBackupClusterPath = [TEST_PATH]/backup/repo/backup/db, strCipherPassSub = [undef] P00 DEBUG: Storage::Local->encrypted(): bIgnoreMissing = true, strFileName = [TEST_PATH]/backup/repo/backup/db/backup.info P00 DEBUG: Storage::Local->encrypted=>: bEncrypted = false @@ -1114,11 +1112,10 @@ P00 DEBUG: Storage::Local->list=>: stryFileList = ([BACKUP-FULL-2]) P00 DEBUG: Backup::Info->current(): strBackup = [BACKUP-FULL-2] P00 DEBUG: Backup::Info->current=>: bTest = true P00 INFO: option 'repo1-retention-archive' is not set - archive logs will not be expired -P00 DEBUG: Common::Exit::exitSafe(): iExitCode = 0, oException = [undef], strSignal = [undef] +P00 DEBUG: Main::mainCleanup(): iExitCode = 0 P00 DEBUG: Protocol::Helper::protocolDestroy(): bComplete = true, iRemoteIdx = [undef], strRemoteType = [undef] P00 DEBUG: Protocol::Helper::protocolDestroy=>: iExitStatus = 0 P00 INFO: expire command end: completed successfully -P00 DEBUG: Common::Exit::exitSafe=>: iExitCode = 0 + supplemental file: [TEST_PATH]/db-master/pgbackrest.conf ---------------------------------------------------------- @@ -1280,8 +1277,6 @@ restore delta, backup '[BACKUP-FULL-2]' - add and delete files (db-master host) > [CONTAINER-EXEC] db-master [BACKREST-BIN] --config=[TEST_PATH]/db-master/pgbackrest.conf --delta --set=[BACKUP-FULL-2] --link-all --cmd-ssh=/usr/bin/ssh --stanza=db restore ------------------------------------------------------------------------------------------------------------------------------------ P00 INFO: restore command begin [BACKREST-VERSION]: --cmd-ssh=/usr/bin/ssh --no-compress --compress-level=3 --compress-level-network=1 --config=[TEST_PATH]/db-master/pgbackrest.conf --delta --link-all --lock-path=[TEST_PATH]/db-master/lock --log-level-console=debug --log-level-file=trace --log-level-stderr=off --log-path=[TEST_PATH]/db-master/log --pg1-path=[TEST_PATH]/db-master/db/base --protocol-timeout=60 --repo1-host=backup --repo1-host-cmd=[BACKREST-BIN] --repo1-host-config=[TEST_PATH]/backup/pgbackrest.conf --repo1-host-user=[USER-2] --set=[BACKUP-FULL-2] --stanza=db -P00 DEBUG: Common::Lock::lockStopTest(): bStanzaStopRequired = -P00 DEBUG: Common::Lock::lockStopTest=>: bStopExists = false P00 DEBUG: Storage::Posix::Driver->new(): bFileSync = , bPathSync = P00 DEBUG: Storage::Local->new(): bAllowTemp = , hRule = [undef], lBufferMax = 4194304, oDriver = [object], strCipherPassUser = [undef], strCipherType = [undef], strDefaultFileMode = <0640>, strDefaultPathMode = <0750>, strPathBase = /, strTempExtension = pgbackrest.tmp P00 DEBUG: Storage::Local->pathCreate(): bCreateParent = true, bIgnoreExists = true, strMode = 0770, strPathExp = [TEST_PATH]/db-master/log @@ -1488,13 +1483,12 @@ P00 DEBUG: Storage::Local->pathSync(): bRecurse = , strPathExp = [TE P00 DEBUG: Storage::Local->remove(): bIgnoreMissing = , bRecurse = , xstryPathFileExp = [TEST_PATH]/db-master/db/base/backup.manifest P00 DEBUG: Storage::Local->remove=>: bRemoved = true P00 DEBUG: Storage::Local->pathSync(): bRecurse = , strPathExp = [TEST_PATH]/db-master/db/base -P00 DEBUG: Common::Exit::exitSafe(): iExitCode = 0, oException = [undef], strSignal = [undef] +P00 DEBUG: Main::mainCleanup(): iExitCode = 0 P00 DEBUG: Protocol::Helper::protocolDestroy(): bComplete = true, iRemoteIdx = [undef], strRemoteType = [undef] P00 DEBUG: Protocol::Helper::protocolDestroy: found cached protocol: iRemoteIdx = 1, strRemoteType = backup P00 DEBUG: Protocol::Command::Master->close=>: iExitStatus = 0 P00 DEBUG: Protocol::Helper::protocolDestroy=>: iExitStatus = 0 P00 INFO: restore command end: completed successfully -P00 DEBUG: Common::Exit::exitSafe=>: iExitCode = 0 + supplemental file: [TEST_PATH]/db-master/db/base/recovery.conf ---------------------------------------------------------------- @@ -1572,7 +1566,7 @@ full backup - backup errors on db host (db-master host) ------------------------------------------------------------------------------------------------------------------------------------ P00 WARN: option repo1-retention-full is not set, the repository may run out of space HINT: to retain full backups indefinitely (without warning), set option 'repo1-retention-full' to the maximum. -P00 ERROR: [072]: backup and expire commands must be run on the repository host +P00 ERROR: [072]: backup command must be run on the repository host restore delta, force, backup '[BACKUP-FULL-2]', expect exit 40 - fail on missing PG_VERSION (db-master host) > [CONTAINER-EXEC] db-master [BACKREST-BIN] --config=[TEST_PATH]/db-master/pgbackrest.conf --delta --force --set=[BACKUP-FULL-2] --log-level-console=detail --stanza=db restore @@ -1704,11 +1698,11 @@ P00 DEBUG: Storage::Posix::Driver->new(): bFileSync = , bPathSync = < P00 DEBUG: Storage::Local->new(): bAllowTemp = , hRule = [hash], lBufferMax = 4194304, oDriver = [object], strCipherPassUser = [undef], strCipherType = [undef], strDefaultFileMode = <0640>, strDefaultPathMode = <0750>, strPathBase = [TEST_PATH]/backup/repo, strTempExtension = pgbackrest.tmp P00 DEBUG: Storage::Local->pathExists(): strPathExp = P00 DEBUG: Storage::Local->pathExists=>: bExists = true -P00 DEBUG: Common::Lock::lockStopTest(): bStanzaStopRequired = -P00 DEBUG: Common::Lock::lockStopTest=>: bStopExists = false P00 DEBUG: Storage::Posix::Driver->new(): bFileSync = , bPathSync = P00 DEBUG: Storage::Local->new(): bAllowTemp = , hRule = [undef], lBufferMax = 4194304, oDriver = [object], strCipherPassUser = [undef], strCipherType = [undef], strDefaultFileMode = <0640>, strDefaultPathMode = <0750>, strPathBase = /, strTempExtension = pgbackrest.tmp P00 DEBUG: Storage::Local->pathCreate(): bCreateParent = true, bIgnoreExists = true, strMode = 0770, strPathExp = [TEST_PATH]/backup/log +P00 DEBUG: Common::Lock::lockStopTest(): bStanzaStopRequired = +P00 DEBUG: Common::Lock::lockStopTest=>: bStopExists = false P00 DEBUG: Backup::Info->new(): bIgnoreMissing = , bLoad = , bRequired = , bValidate = , oStorage = <[object]>, strBackupClusterPath = [TEST_PATH]/backup/repo/backup/db, strCipherPassSub = [undef] P00 DEBUG: Storage::Local->encrypted(): bIgnoreMissing = true, strFileName = [TEST_PATH]/backup/repo/backup/db/backup.info P00 DEBUG: Storage::Local->encrypted=>: bEncrypted = false @@ -1879,7 +1873,12 @@ P00 DEBUG: Storage::Local->openWrite(): bAtomic = , bPathCreate = pathSync(): bRecurse = , strPathExp = [TEST_PATH]/backup/repo/backup/db P00 DEBUG: Storage::Local->pathSync(): bRecurse = , strPathExp = P00 INFO: backup command end: completed successfully -P00 INFO: expire command begin [BACKREST-VERSION]: --config=[TEST_PATH]/backup/pgbackrest.conf --lock-path=[TEST_PATH]/backup/lock --log-level-console=debug --log-level-file=trace --log-level-stderr=off --log-path=[TEST_PATH]/backup/log --pg1-host=db-master --pg1-host-cmd=[BACKREST-BIN] --pg1-host-config=[TEST_PATH]/db-master/pgbackrest.conf --pg1-host-user=[USER-1] --repo1-path=[TEST_PATH]/backup/repo --stanza=db +P00 INFO: expire command begin +P00 DEBUG: Storage::Local->pathExists(): strPathExp = +P00 DEBUG: Storage::Local->pathExists=>: bExists = true +P00 DEBUG: Storage::Local->pathCreate(): bCreateParent = true, bIgnoreExists = true, strMode = 0770, strPathExp = [TEST_PATH]/backup/log +P00 DEBUG: Common::Lock::lockStopTest(): bStanzaStopRequired = +P00 DEBUG: Common::Lock::lockStopTest=>: bStopExists = false P00 DEBUG: Backup::Info->new(): bIgnoreMissing = , bLoad = , bRequired = , bValidate = , oStorage = <[object]>, strBackupClusterPath = [TEST_PATH]/backup/repo/backup/db, strCipherPassSub = [undef] P00 DEBUG: Storage::Local->encrypted(): bIgnoreMissing = true, strFileName = [TEST_PATH]/backup/repo/backup/db/backup.info P00 DEBUG: Storage::Local->encrypted=>: bEncrypted = false @@ -1913,11 +1912,10 @@ P00 DEBUG: Backup::Info->current=>: bTest = true P00 DEBUG: Backup::Info->current(): strBackup = [BACKUP-FULL-2] P00 DEBUG: Backup::Info->current=>: bTest = true P00 INFO: option 'repo1-retention-archive' is not set - archive logs will not be expired -P00 DEBUG: Common::Exit::exitSafe(): iExitCode = 0, oException = [undef], strSignal = [undef] +P00 DEBUG: Main::mainCleanup(): iExitCode = 0 P00 DEBUG: Protocol::Helper::protocolDestroy(): bComplete = true, iRemoteIdx = [undef], strRemoteType = [undef] P00 DEBUG: Protocol::Helper::protocolDestroy=>: iExitStatus = 0 P00 INFO: expire command end: completed successfully -P00 DEBUG: Common::Exit::exitSafe=>: iExitCode = 0 + supplemental file: [TEST_PATH]/db-master/pgbackrest.conf ---------------------------------------------------------- @@ -2082,11 +2080,11 @@ P00 DEBUG: Storage::Posix::Driver->new(): bFileSync = , bPathSync = < P00 DEBUG: Storage::Local->new(): bAllowTemp = , hRule = [hash], lBufferMax = 4194304, oDriver = [object], strCipherPassUser = [undef], strCipherType = [undef], strDefaultFileMode = <0640>, strDefaultPathMode = <0750>, strPathBase = [TEST_PATH]/backup/repo, strTempExtension = pgbackrest.tmp P00 DEBUG: Storage::Local->pathExists(): strPathExp = P00 DEBUG: Storage::Local->pathExists=>: bExists = true -P00 DEBUG: Common::Lock::lockStopTest(): bStanzaStopRequired = -P00 DEBUG: Common::Lock::lockStopTest=>: bStopExists = false P00 DEBUG: Storage::Posix::Driver->new(): bFileSync = , bPathSync = P00 DEBUG: Storage::Local->new(): bAllowTemp = , hRule = [undef], lBufferMax = 4194304, oDriver = [object], strCipherPassUser = [undef], strCipherType = [undef], strDefaultFileMode = <0640>, strDefaultPathMode = <0750>, strPathBase = /, strTempExtension = pgbackrest.tmp P00 DEBUG: Storage::Local->pathCreate(): bCreateParent = true, bIgnoreExists = true, strMode = 0770, strPathExp = [TEST_PATH]/backup/log +P00 DEBUG: Common::Lock::lockStopTest(): bStanzaStopRequired = +P00 DEBUG: Common::Lock::lockStopTest=>: bStopExists = false P00 DEBUG: Backup::Info->new(): bIgnoreMissing = , bLoad = , bRequired = , bValidate = , oStorage = <[object]>, strBackupClusterPath = [TEST_PATH]/backup/repo/backup/db, strCipherPassSub = [undef] P00 DEBUG: Storage::Local->encrypted(): bIgnoreMissing = true, strFileName = [TEST_PATH]/backup/repo/backup/db/backup.info P00 DEBUG: Storage::Local->encrypted=>: bEncrypted = false @@ -2301,7 +2299,12 @@ P00 DEBUG: Storage::Local->openWrite(): bAtomic = , bPathCreate = pathSync(): bRecurse = , strPathExp = [TEST_PATH]/backup/repo/backup/db P00 DEBUG: Storage::Local->pathSync(): bRecurse = , strPathExp = P00 INFO: backup command end: completed successfully -P00 INFO: expire command begin [BACKREST-VERSION]: --config=[TEST_PATH]/backup/pgbackrest.conf --lock-path=[TEST_PATH]/backup/lock --log-level-console=debug --log-level-file=trace --log-level-stderr=off --log-path=[TEST_PATH]/backup/log --pg1-host=db-master --pg1-host-cmd=[BACKREST-BIN] --pg1-host-config=[TEST_PATH]/db-master/pgbackrest.conf --pg1-host-user=[USER-1] --repo1-path=[TEST_PATH]/backup/repo --stanza=db +P00 INFO: expire command begin +P00 DEBUG: Storage::Local->pathExists(): strPathExp = +P00 DEBUG: Storage::Local->pathExists=>: bExists = true +P00 DEBUG: Storage::Local->pathCreate(): bCreateParent = true, bIgnoreExists = true, strMode = 0770, strPathExp = [TEST_PATH]/backup/log +P00 DEBUG: Common::Lock::lockStopTest(): bStanzaStopRequired = +P00 DEBUG: Common::Lock::lockStopTest=>: bStopExists = false P00 DEBUG: Backup::Info->new(): bIgnoreMissing = , bLoad = , bRequired = , bValidate = , oStorage = <[object]>, strBackupClusterPath = [TEST_PATH]/backup/repo/backup/db, strCipherPassSub = [undef] P00 DEBUG: Storage::Local->encrypted(): bIgnoreMissing = true, strFileName = [TEST_PATH]/backup/repo/backup/db/backup.info P00 DEBUG: Storage::Local->encrypted=>: bEncrypted = false @@ -2335,11 +2338,10 @@ P00 DEBUG: Backup::Info->current=>: bTest = true P00 DEBUG: Backup::Info->current(): strBackup = [BACKUP-FULL-2] P00 DEBUG: Backup::Info->current=>: bTest = true P00 INFO: option 'repo1-retention-archive' is not set - archive logs will not be expired -P00 DEBUG: Common::Exit::exitSafe(): iExitCode = 0, oException = [undef], strSignal = [undef] +P00 DEBUG: Main::mainCleanup(): iExitCode = 0 P00 DEBUG: Protocol::Helper::protocolDestroy(): bComplete = true, iRemoteIdx = [undef], strRemoteType = [undef] P00 DEBUG: Protocol::Helper::protocolDestroy=>: iExitStatus = 0 P00 INFO: expire command end: completed successfully -P00 DEBUG: Common::Exit::exitSafe=>: iExitCode = 0 + supplemental file: [TEST_PATH]/db-master/pgbackrest.conf ---------------------------------------------------------- @@ -2523,7 +2525,7 @@ P00 WARN: page misalignment in file db-master:[TEST_PATH]/db-master/db/base/pg P00 INFO: diff backup size = 25B P00 INFO: new backup label = [BACKUP-DIFF-1] P00 INFO: backup command end: completed successfully -P00 INFO: expire command begin [BACKREST-VERSION]: --config=[TEST_PATH]/backup/pgbackrest.conf --lock-path=[TEST_PATH]/backup/lock --log-level-console=detail --log-level-file=trace --log-level-stderr=off --log-path=[TEST_PATH]/backup/log --pg1-host=db-master --pg1-host-cmd=[BACKREST-BIN] --pg1-host-config=[TEST_PATH]/db-master/pgbackrest.conf --pg1-host-user=[USER-1] --repo1-path=[TEST_PATH]/backup/repo --stanza=db +P00 INFO: expire command begin P00 INFO: option 'repo1-retention-archive' is not set - archive logs will not be expired P00 INFO: expire command end: completed successfully @@ -2705,7 +2707,7 @@ P00 WARN: page misalignment in file db-master:[TEST_PATH]/db-master/db/base/pg P00 INFO: diff backup size = 25B P00 INFO: new backup label = [BACKUP-DIFF-2] P00 INFO: backup command end: completed successfully -P00 INFO: expire command begin [BACKREST-VERSION]: --config=[TEST_PATH]/backup/pgbackrest.conf --lock-path=[TEST_PATH]/backup/lock --log-level-console=detail --log-level-file=trace --log-level-stderr=off --log-path=[TEST_PATH]/backup/log --pg1-host=db-master --pg1-host-cmd=[BACKREST-BIN] --pg1-host-config=[TEST_PATH]/db-master/pgbackrest.conf --pg1-host-user=[USER-1] --repo1-path=[TEST_PATH]/backup/repo --stanza=db +P00 INFO: expire command begin P00 INFO: option 'repo1-retention-archive' is not set - archive logs will not be expired P00 INFO: expire command end: completed successfully @@ -2964,7 +2966,7 @@ P00 WARN: page misalignment in file db-master:[TEST_PATH]/db-master/db/base-2/ P00 INFO: incr backup size = 13B P00 INFO: new backup label = [BACKUP-INCR-3] P00 INFO: backup command end: completed successfully -P00 INFO: expire command begin [BACKREST-VERSION]: --config=[TEST_PATH]/backup/pgbackrest.conf --lock-path=[TEST_PATH]/backup/lock --log-level-console=detail --log-level-file=trace --log-level-stderr=off --log-path=[TEST_PATH]/backup/log --pg1-host=db-master --pg1-host-cmd=[BACKREST-BIN] --pg1-host-config=[TEST_PATH]/db-master/pgbackrest.conf --pg1-host-user=[USER-1] --repo1-path=[TEST_PATH]/backup/repo --stanza=db +P00 INFO: expire command begin P00 INFO: option 'repo1-retention-archive' is not set - archive logs will not be expired P00 INFO: expire command end: completed successfully @@ -3184,7 +3186,7 @@ P00 WARN: page misalignment in file db-master:[TEST_PATH]/db-master/db/base-2/ P00 INFO: incr backup size = 8B P00 INFO: new backup label = [BACKUP-INCR-4] P00 INFO: backup command end: completed successfully -P00 INFO: expire command begin [BACKREST-VERSION]: --config=[TEST_PATH]/backup/pgbackrest.conf --lock-path=[TEST_PATH]/backup/lock --log-level-console=detail --log-level-file=trace --log-level-stderr=off --log-path=[TEST_PATH]/backup/log --pg1-host=db-master --pg1-host-cmd=[BACKREST-BIN] --pg1-host-config=[TEST_PATH]/db-master/pgbackrest.conf --pg1-host-user=[USER-1] --repo1-path=[TEST_PATH]/backup/repo --stanza=db +P00 INFO: expire command begin P00 INFO: option 'repo1-retention-archive' is not set - archive logs will not be expired P00 INFO: expire command end: completed successfully @@ -3369,7 +3371,7 @@ P00 WARN: page misalignment in file db-master:[TEST_PATH]/db-master/db/base-2/ P00 INFO: diff backup size = 39B P00 INFO: new backup label = [BACKUP-DIFF-3] P00 INFO: backup command end: completed successfully -P00 INFO: expire command begin [BACKREST-VERSION]: --config=[TEST_PATH]/backup/pgbackrest.conf --lock-path=[TEST_PATH]/backup/lock --log-level-console=detail --log-level-file=trace --log-level-stderr=off --log-path=[TEST_PATH]/backup/log --pg1-host=db-master --pg1-host-cmd=[BACKREST-BIN] --pg1-host-config=[TEST_PATH]/db-master/pgbackrest.conf --pg1-host-user=[USER-1] --repo1-path=[TEST_PATH]/backup/repo --stanza=db +P00 INFO: expire command begin P00 INFO: option 'repo1-retention-archive' is not set - archive logs will not be expired P00 INFO: expire command end: completed successfully @@ -3548,7 +3550,7 @@ P00 TEST: PgBaCkReStTeSt-MANIFEST-BUILD-PgBaCkReStTeSt P00 INFO: incr backup size = 0B P00 INFO: new backup label = [BACKUP-INCR-5] P00 INFO: backup command end: completed successfully -P00 INFO: expire command begin [BACKREST-VERSION]: --config=[TEST_PATH]/backup/pgbackrest.conf --lock-path=[TEST_PATH]/backup/lock --log-level-console=detail --log-level-file=trace --log-level-stderr=off --log-path=[TEST_PATH]/backup/log --pg1-host=db-master --pg1-host-cmd=[BACKREST-BIN] --pg1-host-config=[TEST_PATH]/db-master/pgbackrest.conf --pg1-host-user=[USER-1] --repo1-path=[TEST_PATH]/backup/repo --stanza=db +P00 INFO: expire command begin P00 INFO: option 'repo1-retention-archive' is not set - archive logs will not be expired P00 INFO: expire command end: completed successfully @@ -3735,7 +3737,7 @@ P00 WARN: page misalignment in file db-master:[TEST_PATH]/db-master/db/base-2/ P00 INFO: diff backup size = 31B P00 INFO: new backup label = [BACKUP-DIFF-4] P00 INFO: backup command end: completed successfully -P00 INFO: expire command begin [BACKREST-VERSION]: --config=[TEST_PATH]/backup/pgbackrest.conf --lock-path=[TEST_PATH]/backup/lock --log-level-console=detail --log-level-file=trace --log-level-stderr=off --log-path=[TEST_PATH]/backup/log --pg1-host=db-master --pg1-host-cmd=[BACKREST-BIN] --pg1-host-config=[TEST_PATH]/db-master/pgbackrest.conf --pg1-host-user=[USER-1] --repo1-path=[TEST_PATH]/backup/repo --stanza=db +P00 INFO: expire command begin P00 INFO: option 'repo1-retention-archive' is not set - archive logs will not be expired P00 INFO: expire command end: completed successfully @@ -3926,7 +3928,7 @@ P01 INFO: backup file db-master:[TEST_PATH]/db-master/db/base-2/pg_tblspc/2/[T P00 INFO: full backup size = 144KB P00 INFO: new backup label = [BACKUP-FULL-3] P00 INFO: backup command end: completed successfully -P00 INFO: expire command begin [BACKREST-VERSION]: --config=[TEST_PATH]/backup/pgbackrest.conf --lock-path=[TEST_PATH]/backup/lock --log-level-console=detail --log-level-file=trace --log-level-stderr=off --log-path=[TEST_PATH]/backup/log --pg1-host=db-master --pg1-host-cmd=[BACKREST-BIN] --pg1-host-config=[TEST_PATH]/db-master/pgbackrest.conf --pg1-host-user=[USER-1] --repo1-path=[TEST_PATH]/backup/repo --stanza=db +P00 INFO: expire command begin P00 INFO: option 'repo1-retention-archive' is not set - archive logs will not be expired P00 INFO: expire command end: completed successfully @@ -4477,7 +4479,7 @@ P01 INFO: backup file db-master:[TEST_PATH]/db-master/db/base-2/base/base2.txt P00 INFO: diff backup size = 9B P00 INFO: new backup label = [BACKUP-DIFF-5] P00 INFO: backup command end: completed successfully -P00 INFO: expire command begin [BACKREST-VERSION]: --config=[TEST_PATH]/backup/pgbackrest.conf --lock-path=[TEST_PATH]/backup/lock --log-level-console=detail --log-level-file=trace --log-level-stderr=off --log-path=[TEST_PATH]/backup/log --pg1-host=db-master --pg1-host-cmd=[BACKREST-BIN] --pg1-host-config=[TEST_PATH]/db-master/pgbackrest.conf --pg1-host-user=[USER-1] --repo1-path=[TEST_PATH]/backup/repo --stanza=db +P00 INFO: expire command begin P00 INFO: option 'repo1-retention-archive' is not set - archive logs will not be expired P00 INFO: expire command end: completed successfully @@ -4929,7 +4931,7 @@ P01 INFO: backup file db-master:[TEST_PATH]/db-master/db/base-2/base/base/base P00 INFO: diff backup size = 9B P00 INFO: new backup label = [BACKUP-DIFF-6] P00 INFO: backup command end: completed successfully -P00 INFO: expire command begin [BACKREST-VERSION]: --config=[TEST_PATH]/backup/pgbackrest.conf --lock-path=[TEST_PATH]/backup/lock --log-level-console=info --log-level-file=trace --log-level-stderr=off --log-path=[TEST_PATH]/backup/log --pg1-host=db-master --pg1-host-cmd=[BACKREST-BIN] --pg1-host-config=[TEST_PATH]/db-master/pgbackrest.conf --pg1-host-user=[USER-1] --repo1-path=[TEST_PATH]/backup/repo --stanza=db +P00 INFO: expire command begin P00 INFO: option 'repo1-retention-archive' is not set - archive logs will not be expired P00 INFO: expire command end: completed successfully @@ -5105,7 +5107,7 @@ P01 INFO: backup file db-master:[TEST_PATH]/db-master/db/base-2/base/base/base P00 INFO: diff backup size = 9B P00 INFO: new backup label = [BACKUP-DIFF-7] P00 INFO: backup command end: completed successfully -P00 INFO: expire command begin [BACKREST-VERSION]: --config=[TEST_PATH]/backup/pgbackrest.conf --lock-path=[TEST_PATH]/backup/lock --log-level-console=info --log-level-file=trace --log-level-stderr=off --log-path=[TEST_PATH]/backup/log --pg1-host=db-master --pg1-host-cmd=[BACKREST-BIN] --pg1-host-config=[TEST_PATH]/db-master/pgbackrest.conf --pg1-host-user=[USER-1] --repo1-path=[TEST_PATH]/backup/repo --stanza=db +P00 INFO: expire command begin P00 INFO: option 'repo1-retention-archive' is not set - archive logs will not be expired P00 INFO: expire command end: completed successfully diff --git a/test/expect/mock-all-003.log b/test/expect/mock-all-003.log index eb9002f14..515a0edd0 100644 --- a/test/expect/mock-all-003.log +++ b/test/expect/mock-all-003.log @@ -3158,7 +3158,7 @@ P01 INFO: backup file db-master:[TEST_PATH]/db-master/db/base-2/base/base/base P00 INFO: diff backup size = 9B P00 INFO: new backup label = [BACKUP-DIFF-6] P00 INFO: backup command end: completed successfully -P00 INFO: expire command begin [BACKREST-VERSION]: --config=[TEST_PATH]/backup/pgbackrest.conf --lock-path=[TEST_PATH]/backup/lock --log-level-console=info --log-level-file=trace --log-level-stderr=off --log-path=[TEST_PATH]/backup/log --pg1-host=db-master --pg1-host-cmd=[BACKREST-BIN] --pg1-host-config=[TEST_PATH]/db-master/pgbackrest.conf --pg1-host-user=[USER-1] --repo1-cipher-pass= --repo1-cipher-type=aes-256-cbc --repo1-path=/ --repo1-s3-bucket=pgbackrest-dev --repo1-s3-endpoint=s3.amazonaws.com --repo1-s3-key= --repo1-s3-key-secret= --repo1-s3-region=us-east-1 --no-repo1-s3-verify-ssl --repo1-type=s3 --stanza=db +P00 INFO: expire command begin P00 INFO: option 'repo1-retention-archive' is not set - archive logs will not be expired P00 INFO: expire command end: completed successfully @@ -3350,7 +3350,7 @@ P01 INFO: backup file db-master:[TEST_PATH]/db-master/db/base-2/base/base/base P00 INFO: diff backup size = 9B P00 INFO: new backup label = [BACKUP-DIFF-7] P00 INFO: backup command end: completed successfully -P00 INFO: expire command begin [BACKREST-VERSION]: --config=[TEST_PATH]/backup/pgbackrest.conf --lock-path=[TEST_PATH]/backup/lock --log-level-console=info --log-level-file=trace --log-level-stderr=off --log-path=[TEST_PATH]/backup/log --pg1-host=db-master --pg1-host-cmd=[BACKREST-BIN] --pg1-host-config=[TEST_PATH]/db-master/pgbackrest.conf --pg1-host-user=[USER-1] --repo1-cipher-pass= --repo1-cipher-type=aes-256-cbc --repo1-path=/ --repo1-s3-bucket=pgbackrest-dev --repo1-s3-endpoint=s3.amazonaws.com --repo1-s3-key= --repo1-s3-key-secret= --repo1-s3-region=us-east-1 --no-repo1-s3-verify-ssl --repo1-type=s3 --stanza=db +P00 INFO: expire command begin P00 INFO: option 'repo1-retention-archive' is not set - archive logs will not be expired P00 INFO: expire command end: completed successfully diff --git a/test/expect/mock-archive-001.log b/test/expect/mock-archive-001.log index fb65edf6b..3f24b6e91 100644 --- a/test/expect/mock-archive-001.log +++ b/test/expect/mock-archive-001.log @@ -106,11 +106,10 @@ P00 DEBUG: Storage::Local->openWrite(): bAtomic = true, bPathCreate = true, P00 DEBUG: Storage::Base->copy(): xDestinationFile = [object], xSourceFile = [object] P00 DEBUG: Archive::Push::File::archivePushFile=>: strWarning = [undef] P00 INFO: pushed WAL segment 000000010000000100000001 -P00 DEBUG: Common::Exit::exitSafe(): iExitCode = 0, oException = [undef], strSignal = [undef] +P00 DEBUG: Main::mainCleanup(): iExitCode = 0 P00 DEBUG: Protocol::Helper::protocolDestroy(): bComplete = true, iRemoteIdx = [undef], strRemoteType = [undef] P00 DEBUG: Protocol::Helper::protocolDestroy=>: iExitStatus = 0 P00 INFO: archive-push command end: completed successfully -P00 DEBUG: Common::Exit::exitSafe=>: iExitCode = 0 > [CONTAINER-EXEC] db-master [BACKREST-BIN] --config=[TEST_PATH]/db-master/pgbackrest.conf --stanza=db archive-get --log-level-console=debug 000000010000000100000001 [TEST_PATH]/db-master/db/base/pg_xlog/RECOVERYXLOG ------------------------------------------------------------------------------------------------------------------------------------ @@ -151,11 +150,10 @@ P00 DEBUG: Storage::Local->new(): bAllowTemp = , hRule = [undef], lBu P00 DEBUG: Storage::Local->openWrite(): bAtomic = , bPathCreate = , lTimestamp = [undef], rhyFilter = [undef], strCipherPass = [undef], strGroup = [undef], strMode = <0640>, strUser = [undef], xFileExp = [TEST_PATH]/db-master/db/base/pg_xlog/RECOVERYXLOG P00 DEBUG: Storage::Base->copy(): xDestinationFile = [object], xSourceFile = [object] P00 DEBUG: Archive::Get::Get->get=>: iResult = 0 -P00 DEBUG: Common::Exit::exitSafe(): iExitCode = 0, oException = [undef], strSignal = [undef] +P00 DEBUG: Main::mainCleanup(): iExitCode = 0 P00 DEBUG: Protocol::Helper::protocolDestroy(): bComplete = true, iRemoteIdx = [undef], strRemoteType = [undef] P00 DEBUG: Protocol::Helper::protocolDestroy=>: iExitStatus = 0 P00 INFO: archive-get command end: completed successfully -P00 DEBUG: Common::Exit::exitSafe=>: iExitCode = 0 > [CONTAINER-EXEC] db-master [BACKREST-BIN] --config=[TEST_PATH]/db-master/pgbackrest.conf --stanza=db archive-push --compress --archive-async --process-max=2 [TEST_PATH]/db-master/db/base/pg_xlog/000000010000000100000002 ------------------------------------------------------------------------------------------------------------------------------------ diff --git a/test/expect/mock-archive-002.log b/test/expect/mock-archive-002.log index 9e1a996c1..491210a8f 100644 --- a/test/expect/mock-archive-002.log +++ b/test/expect/mock-archive-002.log @@ -88,13 +88,12 @@ P00 DEBUG: Protocol::Storage::Remote->openWrite(): rhParam = [hash], strFil P00 DEBUG: Storage::Base->copy(): xDestinationFile = [object], xSourceFile = [object] P00 DEBUG: Archive::Push::File::archivePushFile=>: strWarning = [undef] P00 INFO: pushed WAL segment 000000010000000100000001 -P00 DEBUG: Common::Exit::exitSafe(): iExitCode = 0, oException = [undef], strSignal = [undef] +P00 DEBUG: Main::mainCleanup(): iExitCode = 0 P00 DEBUG: Protocol::Helper::protocolDestroy(): bComplete = true, iRemoteIdx = [undef], strRemoteType = [undef] P00 DEBUG: Protocol::Helper::protocolDestroy: found cached protocol: iRemoteIdx = 1, strRemoteType = backup P00 DEBUG: Protocol::Command::Master->close=>: iExitStatus = 0 P00 DEBUG: Protocol::Helper::protocolDestroy=>: iExitStatus = 0 P00 INFO: archive-push command end: completed successfully -P00 DEBUG: Common::Exit::exitSafe=>: iExitCode = 0 > [CONTAINER-EXEC] db-master [BACKREST-BIN] --config=[TEST_PATH]/db-master/pgbackrest.conf --stanza=db archive-get --log-level-console=debug 000000010000000100000001 [TEST_PATH]/db-master/db/base/pg_xlog/RECOVERYXLOG ------------------------------------------------------------------------------------------------------------------------------------ @@ -126,13 +125,12 @@ P00 DEBUG: Storage::Local->new(): bAllowTemp = , hRule = [undef], lBu P00 DEBUG: Storage::Local->openWrite(): bAtomic = , bPathCreate = , lTimestamp = [undef], rhyFilter = [undef], strCipherPass = [undef], strGroup = [undef], strMode = <0640>, strUser = [undef], xFileExp = [TEST_PATH]/db-master/db/base/pg_xlog/RECOVERYXLOG P00 DEBUG: Storage::Base->copy(): xDestinationFile = [object], xSourceFile = [object] P00 DEBUG: Archive::Get::Get->get=>: iResult = 0 -P00 DEBUG: Common::Exit::exitSafe(): iExitCode = 0, oException = [undef], strSignal = [undef] +P00 DEBUG: Main::mainCleanup(): iExitCode = 0 P00 DEBUG: Protocol::Helper::protocolDestroy(): bComplete = true, iRemoteIdx = [undef], strRemoteType = [undef] P00 DEBUG: Protocol::Helper::protocolDestroy: found cached protocol: iRemoteIdx = 1, strRemoteType = backup P00 DEBUG: Protocol::Command::Master->close=>: iExitStatus = 0 P00 DEBUG: Protocol::Helper::protocolDestroy=>: iExitStatus = 0 P00 INFO: archive-get command end: completed successfully -P00 DEBUG: Common::Exit::exitSafe=>: iExitCode = 0 > [CONTAINER-EXEC] db-master [BACKREST-BIN] --config=[TEST_PATH]/db-master/pgbackrest.conf --stanza=db archive-push --compress --archive-async --process-max=2 [TEST_PATH]/db-master/db/base/pg_xlog/000000010000000100000002 ------------------------------------------------------------------------------------------------------------------------------------ diff --git a/test/expect/mock-stanza-001.log b/test/expect/mock-stanza-001.log index 43516b179..4c26a8633 100644 --- a/test/expect/mock-stanza-001.log +++ b/test/expect/mock-stanza-001.log @@ -215,11 +215,10 @@ P00 DEBUG: Storage::Local->openWrite(): bAtomic = true, bPathCreate = true, P00 DEBUG: Storage::Base->copy(): xDestinationFile = [object], xSourceFile = [object] P00 DEBUG: Archive::Push::File::archivePushFile=>: strWarning = [undef] P00 INFO: pushed WAL segment 000000010000000100000001 -P00 DEBUG: Common::Exit::exitSafe(): iExitCode = 0, oException = [undef], strSignal = [undef] +P00 DEBUG: Main::mainCleanup(): iExitCode = 0 P00 DEBUG: Protocol::Helper::protocolDestroy(): bComplete = true, iRemoteIdx = [undef], strRemoteType = [undef] P00 DEBUG: Protocol::Helper::protocolDestroy=>: iExitStatus = 0 P00 INFO: archive-push command end: completed successfully -P00 DEBUG: Common::Exit::exitSafe=>: iExitCode = 0 stanza-create db - fail on archive info file missing from non-empty dir (db-master host) > [CONTAINER-EXEC] db-master [BACKREST-BIN] --config=[TEST_PATH]/db-master/pgbackrest.conf --stanza=db --log-level-console=detail --no-online stanza-create @@ -463,11 +462,10 @@ P00 DEBUG: Storage::Local->openWrite(): bAtomic = true, bPathCreate = true, P00 DEBUG: Storage::Base->copy(): xDestinationFile = [object], xSourceFile = [object] P00 DEBUG: Archive::Push::File::archivePushFile=>: strWarning = [undef] P00 INFO: pushed WAL segment 000000010000000100000002 -P00 DEBUG: Common::Exit::exitSafe(): iExitCode = 0, oException = [undef], strSignal = [undef] +P00 DEBUG: Main::mainCleanup(): iExitCode = 0 P00 DEBUG: Protocol::Helper::protocolDestroy(): bComplete = true, iRemoteIdx = [undef], strRemoteType = [undef] P00 DEBUG: Protocol::Helper::protocolDestroy=>: iExitStatus = 0 P00 INFO: archive-push command end: completed successfully -P00 DEBUG: Common::Exit::exitSafe=>: iExitCode = 0 > [CONTAINER-EXEC] db-master [BACKREST-BIN] --config=[TEST_PATH]/db-master/pgbackrest.conf --log-level-console=warn --archive-queue-max=33554432 --stanza=db archive-push [TEST_PATH]/db-master/db/base/pg_xlog/000000010000000100000001 ------------------------------------------------------------------------------------------------------------------------------------ @@ -554,11 +552,10 @@ P00 DEBUG: Storage::Local->new(): bAllowTemp = , hRule = [undef], lBu P00 DEBUG: Storage::Local->openWrite(): bAtomic = , bPathCreate = , lTimestamp = [undef], rhyFilter = ({rxyParam => ({strCompressType => decompress}), strClass => pgBackRest::Storage::Filter::Gzip}), strCipherPass = [undef], strGroup = [undef], strMode = <0640>, strUser = [undef], xFileExp = [TEST_PATH]/db-master/db/base/pg_xlog/RECOVERYXLOG P00 DEBUG: Storage::Base->copy(): xDestinationFile = [object], xSourceFile = [object] P00 DEBUG: Archive::Get::Get->get=>: iResult = 0 -P00 DEBUG: Common::Exit::exitSafe(): iExitCode = 0, oException = [undef], strSignal = [undef] +P00 DEBUG: Main::mainCleanup(): iExitCode = 0 P00 DEBUG: Protocol::Helper::protocolDestroy(): bComplete = true, iRemoteIdx = [undef], strRemoteType = [undef] P00 DEBUG: Protocol::Helper::protocolDestroy=>: iExitStatus = 0 P00 INFO: archive-get command end: completed successfully -P00 DEBUG: Common::Exit::exitSafe=>: iExitCode = 0 > [CONTAINER-EXEC] db-master [BACKREST-BIN] --config=[TEST_PATH]/db-master/pgbackrest.conf --log-level-console=warn --archive-queue-max=33554432 --stanza=db archive-push [TEST_PATH]/db-master/db/base/pg_xlog/000000010000000100000001 ------------------------------------------------------------------------------------------------------------------------------------ @@ -655,7 +652,7 @@ P01 INFO: backup file [TEST_PATH]/db-master/db/base/pg_xlog/archive_status/000 P00 INFO: full backup size = 48MB P00 INFO: new backup label = [BACKUP-FULL-1] P00 INFO: backup command end: completed successfully -P00 INFO: expire command begin [BACKREST-VERSION]: --config=[TEST_PATH]/db-master/pgbackrest.conf --lock-path=[TEST_PATH]/db-master/lock --log-level-console=detail --log-level-file=trace --log-level-stderr=off --log-path=[TEST_PATH]/db-master/log --repo1-path=[TEST_PATH]/db-master/repo --repo1-retention-full=2 --stanza=db +P00 INFO: expire command begin P00 INFO: remove archive path: [TEST_PATH]/db-master/repo/archive/db/9.3-1 P00 INFO: full backup total < 2 - using oldest full backup for 9.4-2 archive retention P00 INFO: expire command end: completed successfully @@ -809,7 +806,7 @@ P01 INFO: backup file [TEST_PATH]/db-master/db/base/pg_xlog/archive_status/000 P00 INFO: full backup size = 48MB P00 INFO: new backup label = [BACKUP-FULL-2] P00 INFO: backup command end: completed successfully -P00 INFO: expire command begin [BACKREST-VERSION]: --config=[TEST_PATH]/db-master/pgbackrest.conf --lock-path=[TEST_PATH]/db-master/lock --log-level-console=detail --log-level-file=trace --log-level-stderr=off --log-path=[TEST_PATH]/db-master/log --repo1-path=[TEST_PATH]/db-master/repo --repo1-retention-full=2 --stanza=db +P00 INFO: expire command begin P00 INFO: remove archive path: [TEST_PATH]/db-master/repo/archive/db/10.0-3 P00 INFO: expire command end: completed successfully @@ -962,11 +959,10 @@ P00 INFO: stop command begin [BACKREST-VERSION]: --config=[TEST_PATH]/db-maste P00 DEBUG: Storage::Posix::Driver->new(): bFileSync = , bPathSync = P00 DEBUG: Storage::Local->new(): bAllowTemp = , hRule = [undef], lBufferMax = [undef], oDriver = [object], strCipherPassUser = [undef], strCipherType = [undef], strDefaultFileMode = <0640>, strDefaultPathMode = <0750>, strPathBase = /, strTempExtension = pgbackrest.tmp P00 DEBUG: Storage::Local->pathCreate(): bCreateParent = true, bIgnoreExists = true, strMode = 770, strPathExp = [TEST_PATH]/db-master/lock -P00 DEBUG: Common::Exit::exitSafe(): iExitCode = 0, oException = [undef], strSignal = [undef] +P00 DEBUG: Main::mainCleanup(): iExitCode = 0 P00 DEBUG: Protocol::Helper::protocolDestroy(): bComplete = true, iRemoteIdx = [undef], strRemoteType = [undef] P00 DEBUG: Protocol::Helper::protocolDestroy=>: iExitStatus = 0 P00 INFO: stop command end: completed successfully -P00 DEBUG: Common::Exit::exitSafe=>: iExitCode = 0 stanza-delete db - successfully delete the stanza (db-master host) > [CONTAINER-EXEC] db-master [BACKREST-BIN] --config=[TEST_PATH]/db-master/pgbackrest.conf --stanza=db --log-level-console=detail stanza-delete diff --git a/test/expect/mock-stanza-002.log b/test/expect/mock-stanza-002.log index 3efacdbe2..0578b8eb3 100644 --- a/test/expect/mock-stanza-002.log +++ b/test/expect/mock-stanza-002.log @@ -229,13 +229,12 @@ P00 DEBUG: Protocol::Storage::Remote->openWrite(): rhParam = [hash], strFil P00 DEBUG: Storage::Base->copy(): xDestinationFile = [object], xSourceFile = [object] P00 DEBUG: Archive::Push::File::archivePushFile=>: strWarning = [undef] P00 INFO: pushed WAL segment 000000010000000100000001 -P00 DEBUG: Common::Exit::exitSafe(): iExitCode = 0, oException = [undef], strSignal = [undef] +P00 DEBUG: Main::mainCleanup(): iExitCode = 0 P00 DEBUG: Protocol::Helper::protocolDestroy(): bComplete = true, iRemoteIdx = [undef], strRemoteType = [undef] P00 DEBUG: Protocol::Helper::protocolDestroy: found cached protocol: iRemoteIdx = 1, strRemoteType = backup P00 DEBUG: Protocol::Command::Master->close=>: iExitStatus = 0 P00 DEBUG: Protocol::Helper::protocolDestroy=>: iExitStatus = 0 P00 INFO: archive-push command end: completed successfully -P00 DEBUG: Common::Exit::exitSafe=>: iExitCode = 0 stanza-create db - gunzip fail on forced stanza-create (backup host) > [CONTAINER-EXEC] backup [BACKREST-BIN] --config=[TEST_PATH]/backup/pgbackrest.conf --stanza=db --log-level-console=detail --no-online --force stanza-create @@ -321,13 +320,12 @@ P00 DEBUG: Protocol::Storage::Remote->openWrite(): rhParam = [hash], strFil P00 DEBUG: Storage::Base->copy(): xDestinationFile = [object], xSourceFile = [object] P00 DEBUG: Archive::Push::File::archivePushFile=>: strWarning = [undef] P00 INFO: pushed WAL segment 000000010000000100000002 -P00 DEBUG: Common::Exit::exitSafe(): iExitCode = 0, oException = [undef], strSignal = [undef] +P00 DEBUG: Main::mainCleanup(): iExitCode = 0 P00 DEBUG: Protocol::Helper::protocolDestroy(): bComplete = true, iRemoteIdx = [undef], strRemoteType = [undef] P00 DEBUG: Protocol::Helper::protocolDestroy: found cached protocol: iRemoteIdx = 1, strRemoteType = backup P00 DEBUG: Protocol::Command::Master->close=>: iExitStatus = 0 P00 DEBUG: Protocol::Helper::protocolDestroy=>: iExitStatus = 0 P00 INFO: archive-push command end: completed successfully -P00 DEBUG: Common::Exit::exitSafe=>: iExitCode = 0 > [CONTAINER-EXEC] db-master [BACKREST-BIN] --config=[TEST_PATH]/db-master/pgbackrest.conf --log-level-console=warn --archive-queue-max=33554432 --stanza=db archive-push [TEST_PATH]/db-master/db/base/pg_xlog/000000010000000100000001 ------------------------------------------------------------------------------------------------------------------------------------ @@ -411,13 +409,12 @@ P00 DEBUG: Storage::Local->new(): bAllowTemp = , hRule = [undef], lBu P00 DEBUG: Storage::Local->openWrite(): bAtomic = , bPathCreate = , lTimestamp = [undef], rhyFilter = ({rxyParam => ({strCompressType => decompress}), strClass => pgBackRest::Storage::Filter::Gzip}), strCipherPass = [undef], strGroup = [undef], strMode = <0640>, strUser = [undef], xFileExp = [TEST_PATH]/db-master/db/base/pg_xlog/RECOVERYXLOG P00 DEBUG: Storage::Base->copy(): xDestinationFile = [object], xSourceFile = [object] P00 DEBUG: Archive::Get::Get->get=>: iResult = 0 -P00 DEBUG: Common::Exit::exitSafe(): iExitCode = 0, oException = [undef], strSignal = [undef] +P00 DEBUG: Main::mainCleanup(): iExitCode = 0 P00 DEBUG: Protocol::Helper::protocolDestroy(): bComplete = true, iRemoteIdx = [undef], strRemoteType = [undef] P00 DEBUG: Protocol::Helper::protocolDestroy: found cached protocol: iRemoteIdx = 1, strRemoteType = backup P00 DEBUG: Protocol::Command::Master->close=>: iExitStatus = 0 P00 DEBUG: Protocol::Helper::protocolDestroy=>: iExitStatus = 0 P00 INFO: archive-get command end: completed successfully -P00 DEBUG: Common::Exit::exitSafe=>: iExitCode = 0 > [CONTAINER-EXEC] db-master [BACKREST-BIN] --config=[TEST_PATH]/db-master/pgbackrest.conf --log-level-console=warn --archive-queue-max=33554432 --stanza=db archive-push [TEST_PATH]/db-master/db/base/pg_xlog/000000010000000100000001 ------------------------------------------------------------------------------------------------------------------------------------ @@ -435,7 +432,7 @@ P01 INFO: backup file db-master:[TEST_PATH]/db-master/db/base/pg_xlog/archive_ P00 INFO: full backup size = 48MB P00 INFO: new backup label = [BACKUP-FULL-1] P00 INFO: backup command end: completed successfully -P00 INFO: expire command begin [BACKREST-VERSION]: --config=[TEST_PATH]/backup/pgbackrest.conf --lock-path=[TEST_PATH]/backup/lock --log-level-console=detail --log-level-file=trace --log-level-stderr=off --log-path=[TEST_PATH]/backup/log --pg1-host=db-master --pg1-host-cmd=[BACKREST-BIN] --pg1-host-config=[TEST_PATH]/db-master/pgbackrest.conf --pg1-host-user=[USER-1] --repo1-cipher-pass= --repo1-cipher-type=aes-256-cbc --repo1-path=[TEST_PATH]/backup/repo --repo1-retention-full=2 --stanza=db +P00 INFO: expire command begin P00 INFO: remove archive path: [TEST_PATH]/backup/repo/archive/db/9.3-1 P00 INFO: full backup total < 2 - using oldest full backup for 9.4-2 archive retention P00 INFO: expire command end: completed successfully @@ -609,7 +606,7 @@ P01 INFO: backup file db-master:[TEST_PATH]/db-master/db/base/pg_xlog/archive_ P00 INFO: full backup size = 48MB P00 INFO: new backup label = [BACKUP-FULL-2] P00 INFO: backup command end: completed successfully -P00 INFO: expire command begin [BACKREST-VERSION]: --config=[TEST_PATH]/backup/pgbackrest.conf --lock-path=[TEST_PATH]/backup/lock --log-level-console=detail --log-level-file=trace --log-level-stderr=off --log-path=[TEST_PATH]/backup/log --pg1-host=db-master --pg1-host-cmd=[BACKREST-BIN] --pg1-host-config=[TEST_PATH]/db-master/pgbackrest.conf --pg1-host-user=[USER-1] --repo1-cipher-pass= --repo1-cipher-type=aes-256-cbc --repo1-path=[TEST_PATH]/backup/repo --repo1-retention-full=2 --stanza=db +P00 INFO: expire command begin P00 INFO: remove archive path: [TEST_PATH]/backup/repo/archive/db/10.0-3 P00 INFO: expire command end: completed successfully @@ -794,11 +791,10 @@ P00 INFO: stop command begin [BACKREST-VERSION]: --config=[TEST_PATH]/backup/p P00 DEBUG: Storage::Posix::Driver->new(): bFileSync = , bPathSync = P00 DEBUG: Storage::Local->new(): bAllowTemp = , hRule = [undef], lBufferMax = [undef], oDriver = [object], strCipherPassUser = [undef], strCipherType = [undef], strDefaultFileMode = <0640>, strDefaultPathMode = <0750>, strPathBase = /, strTempExtension = pgbackrest.tmp P00 DEBUG: Storage::Local->pathCreate(): bCreateParent = true, bIgnoreExists = true, strMode = 770, strPathExp = [TEST_PATH]/backup/lock -P00 DEBUG: Common::Exit::exitSafe(): iExitCode = 0, oException = [undef], strSignal = [undef] +P00 DEBUG: Main::mainCleanup(): iExitCode = 0 P00 DEBUG: Protocol::Helper::protocolDestroy(): bComplete = true, iRemoteIdx = [undef], strRemoteType = [undef] P00 DEBUG: Protocol::Helper::protocolDestroy=>: iExitStatus = 0 P00 INFO: stop command end: completed successfully -P00 DEBUG: Common::Exit::exitSafe=>: iExitCode = 0 stanza-delete db - successfully delete the stanza (backup host) > [CONTAINER-EXEC] backup [BACKREST-BIN] --config=[TEST_PATH]/backup/pgbackrest.conf --stanza=db --log-level-console=detail stanza-delete diff --git a/test/expect/mock-stanza-003.log b/test/expect/mock-stanza-003.log index 7d42d8c14..e92d1b3c7 100644 --- a/test/expect/mock-stanza-003.log +++ b/test/expect/mock-stanza-003.log @@ -215,11 +215,10 @@ P00 DEBUG: Storage::Local->openWrite(): bAtomic = true, bPathCreate = true, P00 DEBUG: Storage::Base->copy(): xDestinationFile = [object], xSourceFile = [object] P00 DEBUG: Archive::Push::File::archivePushFile=>: strWarning = [undef] P00 INFO: pushed WAL segment 000000010000000100000001 -P00 DEBUG: Common::Exit::exitSafe(): iExitCode = 0, oException = [undef], strSignal = [undef] +P00 DEBUG: Main::mainCleanup(): iExitCode = 0 P00 DEBUG: Protocol::Helper::protocolDestroy(): bComplete = true, iRemoteIdx = [undef], strRemoteType = [undef] P00 DEBUG: Protocol::Helper::protocolDestroy=>: iExitStatus = 0 P00 INFO: archive-push command end: completed successfully -P00 DEBUG: Common::Exit::exitSafe=>: iExitCode = 0 stanza-create db - fail on archive info file missing from non-empty dir (db-master host) > [CONTAINER-EXEC] db-master [BACKREST-BIN] --config=[TEST_PATH]/db-master/pgbackrest.conf --stanza=db --log-level-console=detail --no-online stanza-create @@ -438,11 +437,10 @@ P00 DEBUG: Storage::Local->openWrite(): bAtomic = true, bPathCreate = true, P00 DEBUG: Storage::Base->copy(): xDestinationFile = [object], xSourceFile = [object] P00 DEBUG: Archive::Push::File::archivePushFile=>: strWarning = [undef] P00 INFO: pushed WAL segment 000000010000000100000002 -P00 DEBUG: Common::Exit::exitSafe(): iExitCode = 0, oException = [undef], strSignal = [undef] +P00 DEBUG: Main::mainCleanup(): iExitCode = 0 P00 DEBUG: Protocol::Helper::protocolDestroy(): bComplete = true, iRemoteIdx = [undef], strRemoteType = [undef] P00 DEBUG: Protocol::Helper::protocolDestroy=>: iExitStatus = 0 P00 INFO: archive-push command end: completed successfully -P00 DEBUG: Common::Exit::exitSafe=>: iExitCode = 0 > [CONTAINER-EXEC] db-master [BACKREST-BIN] --config=[TEST_PATH]/db-master/pgbackrest.conf --log-level-console=warn --archive-queue-max=33554432 --stanza=db archive-push [TEST_PATH]/db-master/db/base/pg_xlog/000000010000000100000001 ------------------------------------------------------------------------------------------------------------------------------------ @@ -529,11 +527,10 @@ P00 DEBUG: Storage::Local->new(): bAllowTemp = , hRule = [undef], lBu P00 DEBUG: Storage::Local->openWrite(): bAtomic = , bPathCreate = , lTimestamp = [undef], rhyFilter = ({rxyParam => ({strCompressType => decompress}), strClass => pgBackRest::Storage::Filter::Gzip}), strCipherPass = [undef], strGroup = [undef], strMode = <0640>, strUser = [undef], xFileExp = [TEST_PATH]/db-master/db/base/pg_xlog/RECOVERYXLOG P00 DEBUG: Storage::Base->copy(): xDestinationFile = [object], xSourceFile = [object] P00 DEBUG: Archive::Get::Get->get=>: iResult = 0 -P00 DEBUG: Common::Exit::exitSafe(): iExitCode = 0, oException = [undef], strSignal = [undef] +P00 DEBUG: Main::mainCleanup(): iExitCode = 0 P00 DEBUG: Protocol::Helper::protocolDestroy(): bComplete = true, iRemoteIdx = [undef], strRemoteType = [undef] P00 DEBUG: Protocol::Helper::protocolDestroy=>: iExitStatus = 0 P00 INFO: archive-get command end: completed successfully -P00 DEBUG: Common::Exit::exitSafe=>: iExitCode = 0 > [CONTAINER-EXEC] db-master [BACKREST-BIN] --config=[TEST_PATH]/db-master/pgbackrest.conf --log-level-console=warn --archive-queue-max=33554432 --stanza=db archive-push [TEST_PATH]/db-master/db/base/pg_xlog/000000010000000100000001 ------------------------------------------------------------------------------------------------------------------------------------ @@ -630,7 +627,7 @@ P01 INFO: backup file [TEST_PATH]/db-master/db/base/pg_xlog/archive_status/000 P00 INFO: full backup size = 48MB P00 INFO: new backup label = [BACKUP-FULL-1] P00 INFO: backup command end: completed successfully -P00 INFO: expire command begin [BACKREST-VERSION]: --config=[TEST_PATH]/db-master/pgbackrest.conf --lock-path=[TEST_PATH]/db-master/lock --log-level-console=detail --log-level-file=trace --log-level-stderr=off --log-path=[TEST_PATH]/db-master/log --repo1-path=/ --repo1-retention-full=2 --repo1-s3-bucket=pgbackrest-dev --repo1-s3-endpoint=s3.amazonaws.com --repo1-s3-key= --repo1-s3-key-secret= --repo1-s3-region=us-east-1 --no-repo1-s3-verify-ssl --repo1-type=s3 --stanza=db +P00 INFO: expire command begin P00 INFO: remove archive path: /archive/db/9.3-1 P00 INFO: full backup total < 2 - using oldest full backup for 9.4-2 archive retention P00 INFO: expire command end: completed successfully @@ -791,7 +788,7 @@ P01 INFO: backup file [TEST_PATH]/db-master/db/base/pg_xlog/archive_status/000 P00 INFO: full backup size = 48MB P00 INFO: new backup label = [BACKUP-FULL-2] P00 INFO: backup command end: completed successfully -P00 INFO: expire command begin [BACKREST-VERSION]: --config=[TEST_PATH]/db-master/pgbackrest.conf --lock-path=[TEST_PATH]/db-master/lock --log-level-console=detail --log-level-file=trace --log-level-stderr=off --log-path=[TEST_PATH]/db-master/log --repo1-path=/ --repo1-retention-full=2 --repo1-s3-bucket=pgbackrest-dev --repo1-s3-endpoint=s3.amazonaws.com --repo1-s3-key= --repo1-s3-key-secret= --repo1-s3-region=us-east-1 --no-repo1-s3-verify-ssl --repo1-type=s3 --stanza=db +P00 INFO: expire command begin P00 INFO: remove archive path: /archive/db/10.0-3 P00 INFO: expire command end: completed successfully @@ -949,11 +946,10 @@ P00 INFO: stop command begin [BACKREST-VERSION]: --config=[TEST_PATH]/db-maste P00 DEBUG: Storage::Posix::Driver->new(): bFileSync = , bPathSync = P00 DEBUG: Storage::Local->new(): bAllowTemp = , hRule = [undef], lBufferMax = [undef], oDriver = [object], strCipherPassUser = [undef], strCipherType = [undef], strDefaultFileMode = <0640>, strDefaultPathMode = <0750>, strPathBase = /, strTempExtension = pgbackrest.tmp P00 DEBUG: Storage::Local->pathCreate(): bCreateParent = true, bIgnoreExists = true, strMode = 770, strPathExp = [TEST_PATH]/db-master/lock -P00 DEBUG: Common::Exit::exitSafe(): iExitCode = 0, oException = [undef], strSignal = [undef] +P00 DEBUG: Main::mainCleanup(): iExitCode = 0 P00 DEBUG: Protocol::Helper::protocolDestroy(): bComplete = true, iRemoteIdx = [undef], strRemoteType = [undef] P00 DEBUG: Protocol::Helper::protocolDestroy=>: iExitStatus = 0 P00 INFO: stop command end: completed successfully -P00 DEBUG: Common::Exit::exitSafe=>: iExitCode = 0 stanza-delete db - successfully delete the stanza (db-master host) > [CONTAINER-EXEC] db-master [BACKREST-BIN] --config=[TEST_PATH]/db-master/pgbackrest.conf --stanza=db --log-level-console=detail stanza-delete diff --git a/test/lib/pgBackRestTest/Common/JobTest.pm b/test/lib/pgBackRestTest/Common/JobTest.pm index 7bad9bac9..b1d941997 100644 --- a/test/lib/pgBackRestTest/Common/JobTest.pm +++ b/test/lib/pgBackRestTest/Common/JobTest.pm @@ -216,11 +216,13 @@ sub run if ($self->{oTest}->{&TEST_C}) { $strCommand = - 'docker exec -i -u ' . TEST_USER . " ${strImage}" . + 'docker exec -i -u ' . TEST_USER . " ${strImage} bash -l -c '" . + "cd $self->{strGCovPath} && " . + "make -s 2>&1 && " . ($self->{oTest}->{&TEST_VM} ne VM_CO6 ? " valgrind -q --gen-suppressions=all --suppressions=$self->{strBackRestBase}/test/src/valgrind.suppress" . " --leak-check=full --leak-resolution=high" : '') . - " $self->{strGCovPath}/test"; + " ./test 2>&1'"; } else { @@ -369,17 +371,10 @@ sub run "\t\$(CC) \$(CFLAGS) \$(TESTFLAGS) -O2 -c \$< -o \$@\n"; $self->{oStorageTest}->put($self->{strGCovPath} . "/Makefile", $strMakefile); - - # Run the Makefile - executeTest( - 'docker exec -i -u ' . TEST_USER . " ${strImage} bash -l -c '" . - "cd $self->{strGCovPath} && " . - "make'"); } my $oExec = new pgBackRestTest::Common::ExecuteTest( - $strCommand, - {bSuppressError => !$self->{oTest}->{&TEST_C}, bShowOutputAsync => $self->{bShowOutputAsync}}); + $strCommand, {bSuppressError => true, bShowOutputAsync => $self->{bShowOutputAsync}}); $oExec->begin(); diff --git a/test/lib/pgBackRestTest/Module/Archive/ArchivePushPerlTest.pm b/test/lib/pgBackRestTest/Module/Archive/ArchivePushPerlTest.pm index c3b95cf62..8eb19a777 100644 --- a/test/lib/pgBackRestTest/Module/Archive/ArchivePushPerlTest.pm +++ b/test/lib/pgBackRestTest/Module/Archive/ArchivePushPerlTest.pm @@ -590,7 +590,7 @@ sub run my $strSegment = $self->walSegment($iWalTimeline, $iWalMajor, $iWalMinor++); $self->walGenerate($self->{strWalPath}, PG_VERSION_94, 1, $strSegment); - $self->testResult(sub {$oPush->process("pg_xlog/${strSegment}")}, 0, "${strSegment} WAL pushed (with relative path)"); + $self->testResult(sub {$oPush->process("pg_xlog/${strSegment}")}, undef, "${strSegment} WAL pushed (with relative path)"); $self->testResult( sub {walSegmentFind(storageRepo(), $self->{strArchiveId}, $strSegment)}, "${strSegment}-$self->{strWalHash}", @@ -606,7 +606,7 @@ sub run $strSegment = $self->walSegment($iWalTimeline, $iWalMajor, $iWalMinor++); $self->walGenerate($self->{strWalPath}, PG_VERSION_94, 1, $strSegment); - $self->testResult(sub {$oPush->process("$self->{strWalPath}/${strSegment}")}, 0, "${strSegment} WAL dropped"); + $self->testResult(sub {$oPush->process("$self->{strWalPath}/${strSegment}")}, undef, "${strSegment} WAL dropped"); $self->testResult( sub {walSegmentFind(storageRepo(), $self->{strArchiveId}, $strSegment)}, '[undef]', "${strSegment} WAL in archive"); @@ -615,7 +615,7 @@ sub run $self->optionTestSet(CFGOPT_ARCHIVE_QUEUE_MAX, PG_WAL_SIZE * 4); $self->configTestLoad(CFGCMD_ARCHIVE_PUSH); - $self->testResult(sub {$oPush->process("$self->{strWalPath}/${strSegment}")}, 0, "${strSegment} WAL pushed"); + $self->testResult(sub {$oPush->process("$self->{strWalPath}/${strSegment}")}, undef, "${strSegment} WAL pushed"); $self->testResult( sub {walSegmentFind(storageRepo(), $self->{strArchiveId}, $strSegment)}, "${strSegment}-$self->{strWalHash}", "${strSegment} WAL in archive"); @@ -634,18 +634,7 @@ sub run $strSegment = $self->walSegment($iWalTimeline, $iWalMajor, $iWalMinor++); $self->walGenerate($self->{strWalPath}, PG_VERSION_94, 1, $strSegment); - $self->testResult(sub {$oPush->process("$self->{strWalPath}/${strSegment}")}, 0, "${strSegment} WAL pushed async"); - $self->testResult(sub {$oPush->process("$self->{strWalPath}/${strSegment}")}, 0, "hit lock - already running"); - - # Wait for child process to exit - if ($iProcessId == $PID) - { - waitpid(-1, 0); - } - else - { - exit 0; - } + $self->testResult(sub {$oPush->process("$self->{strWalPath}/${strSegment}")}, undef, "${strSegment} WAL pushed async"); $self->testResult( sub {walSegmentFind(storageRepo(), $self->{strArchiveId}, $strSegment, 5)}, "${strSegment}-$self->{strWalHash}", @@ -662,28 +651,10 @@ sub run $self->optionTestSet(CFGOPT_ARCHIVE_TIMEOUT, 5); $self->configTestLoad(CFGCMD_ARCHIVE_PUSH); - - # Wait for error file to appear - my $oWait = waitInit(10); - my $strErrorFile = STORAGE_SPOOL_ARCHIVE_OUT . "/${strSegment}.error"; - - do - { - $self->testResult(sub {$oPush->process("$self->{strWalPath}/${strSegment}")}, 0, 'process connect error'); - - # Wait for child process to exit - if ($iProcessId == $PID) - { - waitpid(-1, 0); - } - else - { - exit 0; - } - } - while (!storageSpool()->exists($strErrorFile) && waitMore($oWait)); + $self->testResult(sub {$oPush->process("$self->{strWalPath}/${strSegment}")}, undef, 'process connect error'); # Check contents of error file + my $strErrorFile = STORAGE_SPOOL_ARCHIVE_OUT . "/${strSegment}.error"; my $strErrorFileContents = ${storageSpool()->get($strErrorFile)}; $self->testResult( diff --git a/test/lib/pgBackRestTest/Module/Info/InfoUnitTest.pm b/test/lib/pgBackRestTest/Module/Info/InfoUnitTest.pm index 453e1e67e..19183c260 100644 --- a/test/lib/pgBackRestTest/Module/Info/InfoUnitTest.pm +++ b/test/lib/pgBackRestTest/Module/Info/InfoUnitTest.pm @@ -175,7 +175,7 @@ sub run # Output No stanzas exist in default text option #--------------------------------------------------------------------------------------------------------------------------- - $self->testResult(sub {$oInfo->process()}, 0, 'No stanzas exist and default text option'); + $self->testResult(sub {$oInfo->process()}, undef, 'No stanzas exist and default text option'); # Invalid option #--------------------------------------------------------------------------------------------------------------------------- @@ -188,7 +188,7 @@ sub run $self->optionTestSet(CFGOPT_OUTPUT, CFGOPTVAL_INFO_OUTPUT_JSON); $self->configTestLoad(CFGCMD_INFO); - $self->testResult(sub {$oInfo->process()}, 0, 'json option'); + $self->testResult(sub {$oInfo->process()}, undef, 'json option'); # Add linefeed to JSON #--------------------------------------------------------------------------------------------------------------------------- @@ -285,7 +285,7 @@ sub run $self->optionTestClear(CFGOPT_OUTPUT); $self->configTestLoad(CFGCMD_INFO); - $self->testResult(sub {$oInfo->process()}, 0, 'stanza set'); + $self->testResult(sub {$oInfo->process()}, undef, 'stanza set'); # Create the stanza - no WAL or backups #--------------------------------------------------------------------------------------------------------------------------- diff --git a/test/lib/pgBackRestTest/Module/Stanza/StanzaAllTest.pm b/test/lib/pgBackRestTest/Module/Stanza/StanzaAllTest.pm index 8fe5fbd36..981599192 100644 --- a/test/lib/pgBackRestTest/Module/Stanza/StanzaAllTest.pm +++ b/test/lib/pgBackRestTest/Module/Stanza/StanzaAllTest.pm @@ -514,10 +514,10 @@ sub run my $oStanza = new pgBackRest::Stanza(); #--------------------------------------------------------------------------------------------------------------------------- - $self->testResult(sub {$oStanza->stanzaUpgrade()}, 0, 'successfully upgraded'); + $self->testResult(sub {$oStanza->stanzaUpgrade()}, undef, 'successfully upgraded'); #--------------------------------------------------------------------------------------------------------------------------- - $self->testResult(sub {$oStanza->stanzaUpgrade()}, 0, 'upgrade not required'); + $self->testResult(sub {$oStanza->stanzaUpgrade()}, undef, 'upgrade not required'); # Attempt to change the encryption settings #--------------------------------------------------------------------------------------------------------------------------- @@ -570,7 +570,7 @@ sub run $self->testResult(sub {storageRepo()->encrypted($strArchivedFile)}, true, 'created encrypted archive WAL'); # Upgrade - $self->testResult(sub {$oStanza->stanzaUpgrade()}, 0, ' successfully upgraded'); + $self->testResult(sub {$oStanza->stanzaUpgrade()}, undef, ' successfully upgraded'); $self->testResult(sub {storageRepo()->encrypted(storageRepo()->pathGet(STORAGE_REPO_ARCHIVE) . '/' . ARCHIVE_INFO_FILE)}, true, ' upgraded archive info encrypted'); $self->testResult(sub {storageRepo()->encrypted(storageRepo()->pathGet(STORAGE_REPO_BACKUP) . '/' @@ -720,7 +720,7 @@ sub run $self->optionTestSetBool(CFGOPT_FORCE, true); $self->configTestLoad(CFGCMD_STANZA_DELETE); - $self->testResult(sub {$oStanza->stanzaDelete()}, 0, 'successfully delete stanza with force'); + $self->testResult(sub {$oStanza->stanzaDelete()}, undef, 'successfully delete stanza with force'); $self->testResult(sub {storageRepo()->pathExists($self->{strArchivePath}) || storageRepo()->pathExists($self->{strBackupPath})}, false, ' neither archive nor backup repo paths for the stanza exist'); @@ -731,7 +731,7 @@ sub run # Rerun stanza-delete without force and with missing stanza directories #--------------------------------------------------------------------------------------------------------------------------- - $self->testResult(sub {$oStanza->stanzaDelete()}, 0, 'successful - stanza already deleted'); + $self->testResult(sub {$oStanza->stanzaDelete()}, undef, 'successful - stanza already deleted'); # Recursive dir delete with archive directory and stanza directory but missing info files #--------------------------------------------------------------------------------------------------------------------------- @@ -750,7 +750,7 @@ sub run executeTest("sudo chown 777 " . $self->{strBackupPath} . "/${strFullLabel}/" . BOGUS); lockStop(); - $self->testResult(sub {$oStanza->stanzaDelete()}, 0, + $self->testResult(sub {$oStanza->stanzaDelete()}, undef, 'successful - recursive delete with missing info files and inaccessible file'); $self->testResult(sub {storageRepo()->pathExists($self->{strArchivePath}) || storageRepo()->pathExists($self->{strBackupPath})}, @@ -801,7 +801,7 @@ sub run "[undef]", ' manifest saved'); lockStop(); - $self->testResult(sub {$oStanza->stanzaDelete()}, 0, + $self->testResult(sub {$oStanza->stanzaDelete()}, undef, ' successful - recursive delete on encrypted repo'); $self->testResult(sub {storageRepo()->pathExists($self->{strArchivePath}) || storageRepo()->pathExists($self->{strBackupPath})}, diff --git a/test/src/module/archive/pushTest.c b/test/src/module/archive/pushTest.c index d46b068cb..df40f83c5 100644 --- a/test/src/module/archive/pushTest.c +++ b/test/src/module/archive/pushTest.c @@ -107,35 +107,26 @@ testRun() TEST_ERROR(cmdArchivePush(), AssertError, "archive-push in C does not support synchronous mode"); - // Test that a bogus perl bin generates the correct errors + // Make sure the process times out when there is nothing to archive // ------------------------------------------------------------------------------------------------------------------------- strLstAdd(argList, strNewFmt("--spool-path=%s", testPath())); strLstAddZ(argList, "--archive-async"); strLstAddZ(argList, "--log-level-console=off"); strLstAddZ(argList, "--log-level-stderr=off"); - cfgLoad(strLstSize(argList), strLstPtr(argList)); - logInit(logLevelInfo, logLevelOff, logLevelOff, false); - - TRY_BEGIN() - { - cmdArchivePush(); - - THROW(AssertError, "error should have been thrown"); // {uncoverable - test should not get here} - } - CATCH_ANY() - { - // Check expected error on the parent process - TEST_RESULT_INT(errorCode(), errorTypeCode(&AssertError), "error code matches after failed Perl exec"); - TEST_RESULT_STR(errorMessage(), "perl exited with error 37", "error message matches after failed Perl exec"); - } - TRY_END(); - - // Make sure the process times out when there is nothing to archive - // ------------------------------------------------------------------------------------------------------------------------- strLstAdd(argList, strNewFmt("--pg1-path=%s/db", testPath())); cfgLoad(strLstSize(argList), strLstPtr(argList)); logInit(logLevelInfo, logLevelOff, logLevelOff, false); + TEST_ERROR( + cmdArchivePush(), ArchiveTimeoutError, + "unable to push WAL segment '000000010000000100000001' asynchronously after 1 second(s)"); + + // Make sure the process times out when there is nothing to archive and it can't get a lock + // ------------------------------------------------------------------------------------------------------------------------- + TEST_RESULT_VOID( + lockAcquire(cfgOptionStr(cfgOptLockPath), cfgOptionStr(cfgOptStanza), cfgLockType(), 30, true), "acquire lock"); + TEST_RESULT_VOID(lockClear(true), "clear lock"); + TEST_ERROR( cmdArchivePush(), ArchiveTimeoutError, "unable to push WAL segment '000000010000000100000001' asynchronously after 1 second(s)"); diff --git a/test/src/module/command/commandTest.c b/test/src/module/command/commandTest.c index 4ba40045d..fc13cde48 100644 --- a/test/src/module/command/commandTest.c +++ b/test/src/module/command/commandTest.c @@ -53,18 +53,22 @@ testRun() kvPut(recoveryKv, varNewStr(strNew("primary_conn_info")), varNewStr(strNew("blah"))); cfgOptionSet(cfgOptRecoveryOption, cfgSourceParam, recoveryVar); - cmdBegin(); + TEST_RESULT_VOID(cmdBegin(true), "command begin with option logging"); testLogResult( "P00 INFO: archive-get command begin " PGBACKREST_VERSION ": --compress --no-config --db-include=db1" " --db-include=db2 --recovery-option=standby_mode=on --recovery-option=primary_conn_info=blah --reset-repo1-host" " --repo1-path=\"/path/to the/repo\" --repo1-s3-key="); + TEST_RESULT_VOID(cmdBegin(false), "command begin no option logging"); + testLogResult( + "P00 INFO: archive-get command begin"); + // ------------------------------------------------------------------------------------------------------------------------- - cmdEnd(0); + TEST_RESULT_VOID(cmdEnd(0, NULL), "command end with success"); testLogResult("P00 INFO: archive-get command end: completed successfully"); // ------------------------------------------------------------------------------------------------------------------------- - cmdEnd(25); + TEST_RESULT_VOID(cmdEnd(25, strNew("aborted with exception [025]")), "command end with error"); testLogResult("P00 INFO: archive-get command end: aborted with exception [025]"); } } diff --git a/test/src/module/common/exitTest.c b/test/src/module/common/exitTest.c index 5633104a2..2b2be36c1 100644 --- a/test/src/module/common/exitTest.c +++ b/test/src/module/common/exitTest.c @@ -1,6 +1,10 @@ /*********************************************************************************************************************************** Test Exit Routines ***********************************************************************************************************************************/ +#include +#include + +#include "common/error.h" #include "config/config.h" /*********************************************************************************************************************************** @@ -9,13 +13,50 @@ Test Run void testRun() { + // ***************************************************************************************************************************** + if (testBegin("exitSignalName()")) + { + TEST_RESULT_STR(exitSignalName(signalTypeHup), "HUP", "SIGHUP name"); + TEST_RESULT_STR(exitSignalName(signalTypeInt), "INT", "SIGINT name"); + TEST_RESULT_STR(exitSignalName(signalTypeTerm), "TERM", "SIGTERM name"); + TEST_ERROR(exitSignalName(signalTypeNone), AssertError, "no name for signal none"); + } + + // ***************************************************************************************************************************** + if (testBegin("exitInit() and exitOnSignal()")) + { + int processId = fork(); + + // If this is the fork + if (processId == 0) + { + exitInit(); + raise(SIGTERM); + } + else + { + int processStatus; + + if (waitpid(processId, &processStatus, 0) != processId) // {uncoverable - fork() does not fail} + THROW_SYS_ERROR(AssertError, "unable to find child process"); // {uncoverable+} + + TEST_RESULT_INT(WEXITSTATUS(processStatus), errorTypeCode(&TermError), "test error result"); + } + } + // ***************************************************************************************************************************** if (testBegin("exitSafe()")) { + cfgInit(); + cfgCommandSet(cfgCmdNone); + + TEST_RESULT_INT(exitSafe(0, false, signalTypeNone), 0, "exit with no command") + + // ------------------------------------------------------------------------------------------------------------------------- cfgInit(); cfgCommandSet(cfgCmdArchivePush); - TEST_RESULT_INT(exitSafe(false), 0, "exit with no error") + TEST_RESULT_INT(exitSafe(0, false, signalTypeNone), 0, "exit with no error") testLogResult("P00 INFO: archive-push command end: completed successfully"); // ------------------------------------------------------------------------------------------------------------------------- @@ -25,11 +66,34 @@ testRun() } CATCH_ANY() { - exitSafe(true); + exitSafe(0, true, signalTypeNone); testLogResult( "P00 ERROR: [122]: test error message\n" "P00 INFO: archive-push command end: aborted with exception [122]"); } TRY_END(); + + // ------------------------------------------------------------------------------------------------------------------------- + TRY_BEGIN() + { + THROW(RuntimeError, PERL_EMBED_ERROR); + } + CATCH_ANY() + { + exitSafe(0, true, signalTypeNone); + testLogResult( + "P00 INFO: archive-push command end: aborted with exception [122]"); + } + TRY_END(); + + // ------------------------------------------------------------------------------------------------------------------------- + TEST_RESULT_INT( + exitSafe(errorTypeCode(&TermError), false, signalTypeNone), errorTypeCode(&TermError), "exit on term with no signal"); + testLogResult("P00 INFO: archive-push command end: terminated on signal from child process"); + + // ------------------------------------------------------------------------------------------------------------------------- + TEST_RESULT_INT( + exitSafe(errorTypeCode(&TermError), false, signalTypeTerm), errorTypeCode(&TermError), "exit on term with SIGTERM"); + testLogResult("P00 INFO: archive-push command end: terminated on signal [SIGTERM]"); } } diff --git a/test/src/module/common/forkTest.c b/test/src/module/common/forkTest.c new file mode 100644 index 000000000..1dd632cac --- /dev/null +++ b/test/src/module/common/forkTest.c @@ -0,0 +1,44 @@ +/*********************************************************************************************************************************** +Test Fork Handler +***********************************************************************************************************************************/ +#include + +/*********************************************************************************************************************************** +Test Run +***********************************************************************************************************************************/ +void +testRun() +{ + // ***************************************************************************************************************************** + if (testBegin("forkAndDetach()")) + { + int sessionId = getsid(0); + int processId = fork(); + + // If this is the fork + if (processId == 0) + { + char buffer[1024]; + + forkDetach(); + + TEST_RESULT_BOOL(getsid(0) != sessionId, true, "new session id has been created"); + TEST_RESULT_STR(getcwd(buffer, sizeof(buffer)), "/", "current working directory is '/'"); + TEST_RESULT_INT(write(STDIN_FILENO, buffer, strlen(buffer)), -1, "write to stdin fails"); + TEST_RESULT_INT(write(STDOUT_FILENO, buffer, strlen(buffer)), -1, "write to stdout fails"); + TEST_RESULT_INT(write(STDERR_FILENO, buffer, strlen(buffer)), -1, "write to stderr fails"); + + exit(0); + } + else + { + int processStatus; + + if (waitpid(processId, &processStatus, 0) != processId) // {uncoverable - fork() does not fail} + THROW_SYS_ERROR(AssertError, "unable to find child process"); // {uncoverable+} + + if (WEXITSTATUS(processStatus) != 0) + THROW(AssertError, "perl exited with error %d", WEXITSTATUS(processStatus)); + } + } +} diff --git a/test/src/module/common/lockTest.c b/test/src/module/common/lockTest.c index 9da9b81e7..ba6b0f49f 100644 --- a/test/src/module/common/lockTest.c +++ b/test/src/module/common/lockTest.c @@ -16,11 +16,11 @@ testRun() if (testBegin("lockAcquireFile() and lockReleaseFile()")) { String *archiveLock = strNewFmt("%s/main-archive.lock", testPath()); - int lockHandle = -1; + int lockHandleTest = -1; TEST_RESULT_INT(system(strPtr(strNewFmt("touch %s", strPtr(archiveLock)))), 0, "touch lock file"); - TEST_ASSIGN(lockHandle, lockAcquireFile(archiveLock, 0, true), "get lock"); - TEST_RESULT_BOOL(lockHandle != -1, true, "lock succeeds"); + TEST_ASSIGN(lockHandleTest, lockAcquireFile(archiveLock, 0, true), "get lock"); + TEST_RESULT_BOOL(lockHandleTest != -1, true, "lock succeeds"); TEST_RESULT_BOOL(storageExistsNP(storageTest, archiveLock), true, "lock file was created"); TEST_ERROR(lockAcquireFile(archiveLock, 0, true), LockAcquireError, strPtr( @@ -35,19 +35,19 @@ testRun() "HINT: is another pgBackRest process running?", strPtr(archiveLock)))); TEST_RESULT_BOOL(lockAcquireFile(archiveLock, 0, false) == -1, true, "lock is already held"); - TEST_RESULT_VOID(lockReleaseFile(lockHandle, archiveLock), "release lock"); + TEST_RESULT_VOID(lockReleaseFile(lockHandleTest, archiveLock), "release lock"); - TEST_RESULT_VOID(lockReleaseFile(lockHandle, archiveLock), "release lock"); + TEST_RESULT_VOID(lockReleaseFile(lockHandleTest, archiveLock), "release lock"); TEST_RESULT_BOOL(storageExistsNP(storageTest, archiveLock), false, "lock file was removed"); - TEST_RESULT_VOID(lockReleaseFile(lockHandle, archiveLock), "release lock again without error"); + TEST_RESULT_VOID(lockReleaseFile(lockHandleTest, archiveLock), "release lock again without error"); // ------------------------------------------------------------------------------------------------------------------------- String *subPathLock = strNewFmt("%s/sub1/sub2/db-backup.lock", testPath()); - TEST_ASSIGN(lockHandle, lockAcquireFile(subPathLock, 0, true), "get lock in subpath"); + TEST_ASSIGN(lockHandleTest, lockAcquireFile(subPathLock, 0, true), "get lock in subpath"); TEST_RESULT_BOOL(storageExistsNP(storageTest, subPathLock), true, "lock file was created"); - TEST_RESULT_BOOL(lockHandle != -1, true, "lock succeeds"); - TEST_RESULT_VOID(lockReleaseFile(lockHandle, subPathLock), "release lock"); + TEST_RESULT_BOOL(lockHandleTest != -1, true, "lock succeeds"); + TEST_RESULT_VOID(lockReleaseFile(lockHandleTest, subPathLock), "release lock"); TEST_RESULT_BOOL(storageExistsNP(storageTest, subPathLock), false, "lock file was removed"); // ------------------------------------------------------------------------------------------------------------------------- @@ -95,20 +95,23 @@ testRun() } // ***************************************************************************************************************************** - if (testBegin("lockAcquire() and lockRelease()")) + if (testBegin("lockAcquire(), lockRelease(), and lockClear()")) { String *stanza = strNew("test"); String *lockPath = strNew(testPath()); String *archiveLockFile = strNewFmt("%s/%s-archive.lock", testPath(), strPtr(stanza)); String *backupLockFile = strNewFmt("%s/%s-backup.lock", testPath(), strPtr(stanza)); - int lockHandle = -1; + int lockHandleTest = -1; // ------------------------------------------------------------------------------------------------------------------------- TEST_ERROR(lockRelease(true), AssertError, "no lock is held by this process"); TEST_RESULT_BOOL(lockRelease(false), false, "release when there is no lock"); + TEST_ERROR(lockClear(true), AssertError, "no lock is held by this process"); + TEST_RESULT_BOOL(lockClear(false), false, "release when there is no lock"); + // ------------------------------------------------------------------------------------------------------------------------- - TEST_ASSIGN(lockHandle, lockAcquireFile(archiveLockFile, 0, true), "archive lock by file"); + TEST_ASSIGN(lockHandleTest, lockAcquireFile(archiveLockFile, 0, true), "archive lock by file"); TEST_RESULT_BOOL(lockAcquire(lockPath, stanza, lockTypeArchive, 0, false), false, "archive already locked"); TEST_ERROR( lockAcquire(lockPath, stanza, lockTypeArchive, 0, true), LockAcquireError, @@ -120,7 +123,7 @@ testRun() strPtr(strNewFmt( "unable to acquire lock on file '%s': Resource temporarily unavailable\n" "HINT: is another pgBackRest process running?", strPtr(archiveLockFile)))); - TEST_RESULT_VOID(lockReleaseFile(lockHandle, archiveLockFile), "release lock"); + TEST_RESULT_VOID(lockReleaseFile(lockHandleTest, archiveLockFile), "release lock"); // ------------------------------------------------------------------------------------------------------------------------- TEST_RESULT_BOOL(lockAcquire(lockPath, stanza, lockTypeArchive, 0, true), true, "archive lock"); @@ -129,7 +132,7 @@ testRun() TEST_RESULT_VOID(lockRelease(true), "release archive lock"); // // ------------------------------------------------------------------------------------------------------------------------- - TEST_ASSIGN(lockHandle, lockAcquireFile(backupLockFile, 0, true), "backup lock by file"); + TEST_ASSIGN(lockHandleTest, lockAcquireFile(backupLockFile, 0, true), "backup lock by file"); TEST_ERROR( lockAcquire(lockPath, stanza, lockTypeBackup, 0, true), LockAcquireError, strPtr(strNewFmt( @@ -140,8 +143,8 @@ testRun() strPtr(strNewFmt( "unable to acquire lock on file '%s': Resource temporarily unavailable\n" "HINT: is another pgBackRest process running?", strPtr(backupLockFile)))); - TEST_RESULT_VOID(lockReleaseFile(lockHandle, archiveLockFile), "release lock"); - TEST_RESULT_VOID(lockReleaseFile(lockHandle, backupLockFile), "release lock"); + TEST_RESULT_VOID(lockReleaseFile(lockHandleTest, archiveLockFile), "release lock"); + TEST_RESULT_VOID(lockReleaseFile(lockHandleTest, backupLockFile), "release lock"); // ------------------------------------------------------------------------------------------------------------------------- TEST_RESULT_BOOL(lockAcquire(lockPath, stanza, lockTypeAll, 0, true), true, "all lock"); @@ -151,5 +154,21 @@ testRun() lockAcquire(lockPath, stanza, lockTypeAll, 0, false), AssertError, "debug assertion 'failOnNoLock || lockType != lockTypeAll' failed"); TEST_RESULT_VOID(lockRelease(true), "release all lock"); + + // ------------------------------------------------------------------------------------------------------------------------- + TEST_RESULT_BOOL(lockAcquire(lockPath, stanza, lockTypeBackup, 0, true), true, "backup lock"); + + lockHandleTest = lockHandle[lockTypeBackup]; + String *lockFileTest = strDup(lockFile[lockTypeBackup]); + + TEST_RESULT_VOID(lockClear(true), "clear backup lock"); + TEST_RESULT_BOOL(storageExistsNP(storageTest, backupLockFile), true, "backup lock file still exists"); + lockReleaseFile(lockHandleTest, lockFileTest); + + // ------------------------------------------------------------------------------------------------------------------------- + TEST_RESULT_BOOL(lockAcquire(lockPath, stanza, lockTypeAll, 0, true), true, "all lock"); + TEST_RESULT_VOID(lockClear(true), "clear all lock"); + TEST_RESULT_BOOL(storageExistsNP(storageTest, archiveLockFile), true, "archive lock file still exists"); + TEST_RESULT_BOOL(storageExistsNP(storageTest, backupLockFile), true, "backup lock file still exists"); } } diff --git a/test/src/module/perl/execTest.c b/test/src/module/perl/execTest.c index ae31f4b75..dbe852102 100644 --- a/test/src/module/perl/execTest.c +++ b/test/src/module/perl/execTest.c @@ -18,8 +18,7 @@ testRun() cfgCommandSet(cfgCmdInfo); cfgExeSet(strNew("/path/to/pgbackrest")); - TEST_RESULT_STR( - strPtr(perlMain()), "pgBackRest::Main::main('/path/to/pgbackrest','info')", "command with no options"); + TEST_RESULT_STR(strPtr(perlMain()), "($result, $message) = pgBackRest::Main::main('info')", "command with no options"); // ------------------------------------------------------------------------------------------------------------------------- cfgOptionValidSet(cfgOptCompress, true); @@ -31,13 +30,12 @@ testRun() cfgCommandParamSet(commandParamList); TEST_RESULT_STR( - strPtr(perlMain()), - "pgBackRest::Main::main('/path/to/pgbackrest','info','A','B')", + strPtr(perlMain()), "($result, $message) = pgBackRest::Main::main('info','A','B')", "command with one option and params"); } // ----------------------------------------------------------------------------------------------------------------------------- - if (testBegin("perlExec()")) + if (testBegin("perlInit(), perlExec(), and perlFree()")) { StringList *argList = strLstNew(); strLstAdd(argList, strNew("pgbackrest")); @@ -48,21 +46,9 @@ testRun() TEST_RESULT_VOID(cfgLoad(strLstSize(argList), strLstPtr(argList)), "load archive-push config"); - int processId = 0; - - if ((processId = fork()) == 0) - { - perlExec(); - } - // Wait for async process to exit (this should happen quickly) and report any errors - else - { - int processStatus; - - if (waitpid(processId, &processStatus, 0) != processId) // {uncoverable - write does not fail} - THROW_SYS_ERROR(AssertError, "unable to find perl child process"); // {uncoverable+} - - TEST_RESULT_INT(WEXITSTATUS(processStatus), errorTypeCode(&ParamRequiredError), "check error code"); - } + TEST_RESULT_VOID(perlFree(0), "free Perl before it is init'd"); + TEST_RESULT_VOID(perlInit(), "init Perl"); + TEST_ERROR(perlExec(), ParamRequiredError, PERL_EMBED_ERROR); + TEST_RESULT_VOID(perlFree(0), "free Perl"); } } diff --git a/test/test.pl b/test/test.pl index d9f441ead..6bbef0359 100755 --- a/test/test.pl +++ b/test/test.pl @@ -1185,9 +1185,8 @@ eval if ($iCoveragePercent == 100) { - # This has been changed to a warning for now so archive/async tests will pass - &log(WARN, "perl module ${strCodeModule} has 100% coverage but is not marked fully covered"); - # $iUncoveredCodeModuleTotal++; + &log(ERROR, "perl module ${strCodeModule} has 100% coverage but is not marked fully covered"); + $iUncoveredCodeModuleTotal++; } else {