1
0
mirror of https://github.com/pgbackrest/pgbackrest.git synced 2025-10-30 23:37:45 +02:00

Protocol timeout option and keep-alive fixes.

* Fixed an issue where keep-alives could be starved out by lots of small files during multi-threaded operation and were completely absent during single-threaded operation when resuming from a previous incomplete backup.

Reported by Janice Parkinson.

* Added the protocol-timeout option. Previously protocol-timeout was set as db-timeout + 30 seconds.
* Failure to shutdown remotes at the end of the backup no longer throws an exception. A warning is still generated that recommends a higher protocol-timeout.
This commit is contained in:
David Steele
2016-06-22 18:01:18 -04:00
parent 4cff5bb0e6
commit 41b27c0456
13 changed files with 203 additions and 69 deletions

View File

@@ -78,7 +78,7 @@ eval
optionGet(OPTION_BUFFER_SIZE), optionGet(OPTION_BUFFER_SIZE),
optionGet(OPTION_COMPRESS_LEVEL), optionGet(OPTION_COMPRESS_LEVEL),
optionGet(OPTION_COMPRESS_LEVEL_NETWORK), optionGet(OPTION_COMPRESS_LEVEL_NETWORK),
protocolTimeoutGet() optionGet(OPTION_PROTOCOL_TIMEOUT)
); );
# ??? Would like to remove this check and allow a test lock # ??? Would like to remove this check and allow a test lock
@@ -226,6 +226,9 @@ eval
} }
} }
# Process exit test point
&log(TEST, TEST_PROCESS_EXIT);
lockRelease(); lockRelease();
exitSafe(0); exitSafe(0);
}; };

View File

@@ -178,6 +178,15 @@
<example>/backup/db/spool</example> <example>/backup/db/spool</example>
</config-key> </config-key>
<!-- CONFIG - GENERAL SECTION - PROTOCOL-TIMEOUT KEY -->
<config-key id="protocol-timeout" name="Protocol Timeout">
<summary>Protocol timeout.</summary>
<text>Sets the timeout, in seconds, that the master or remote process will wait for a new message to be received on the protocol layer. This prevents processes from waiting indefinitely for a message. The <br-option>protocol-timeout</br-option> option must be greater than the <br-option>db-timeout</br-option> option.</text>
<example>630</example>
</config-key>
<!-- CONFIG - GENERAL SECTION - REPO-PATH KEY --> <!-- CONFIG - GENERAL SECTION - REPO-PATH KEY -->
<config-key id="repo-path" name="Repository Path"> <config-key id="repo-path" name="Repository Path">
<summary>Repository path where WAL segments and backups stored.</summary> <summary>Repository path where WAL segments and backups stored.</summary>

View File

@@ -57,6 +57,11 @@
<contributor-id type="github">Dwaligon</contributor-id> <contributor-id type="github">Dwaligon</contributor-id>
</contributor> </contributor>
<contributor id="parkinson.janice">
<contributor-name-display>Janice Parkinson</contributor-name-display>
<contributor-id type="github">jpabt</contributor-id>
</contributor>
<contributor id="renner.michael"> <contributor id="renner.michael">
<contributor-name-display>Michael Renner</contributor-name-display> <contributor-name-display>Michael Renner</contributor-name-display>
<contributor-id type="github">terrorobe</contributor-id> <contributor-id type="github">terrorobe</contributor-id>
@@ -92,6 +97,14 @@
<release date="XXXX-XX-XX" version="1.03dev" title="UNDER DEVELOPMENT"> <release date="XXXX-XX-XX" version="1.03dev" title="UNDER DEVELOPMENT">
<release-core-list> <release-core-list>
<release-bug-list> <release-bug-list>
<release-item>
<release-item-contributor-list>
<release-item-ideator id="parkinson.janice"/>
</release-item-contributor-list>
<p>Fixed an issue where <id>keep-alives</id> could be starved out by lots of small files during multi-threaded operation and were completely absent during single-threaded operation when resuming from a previous incomplete backup.</p>
</release-item>
<release-item> <release-item>
<release-item-contributor-list> <release-item-contributor-list>
<release-item-ideator id="barber.chris"/> <release-item-ideator id="barber.chris"/>
@@ -111,6 +124,14 @@
<p>Added <cmd>check</cmd> command to validate that <backrest/> is configured correctly for archiving and backups.</p> <p>Added <cmd>check</cmd> command to validate that <backrest/> is configured correctly for archiving and backups.</p>
</release-item> </release-item>
<release-item>
<p>Added the <br-option>protocol-timeout</br-option> option. Previously <br-option>protocol-timeout</br-option> was set as <br-option>db-timeout</br-option> + 30 seconds.</p>
</release-item>
<release-item>
<p>Failure to shutdown remotes at the end of the backup no longer throws an exception. A warning is still generated that recommends a higher <br-option>protocol-timeout</br-option>.</p>
</release-item>
</release-feature-list> </release-feature-list>
<release-refactor-list> <release-refactor-list>

View File

@@ -448,6 +448,10 @@ sub processManifest
$lManifestSaveCurrent = backupManifestUpdate($oBackupManifest, $$oFileCopy{repo_file}, $bCopied, $lCopySize, $lManifestSaveCurrent = backupManifestUpdate($oBackupManifest, $$oFileCopy{repo_file}, $bCopied, $lCopySize,
$lRepoSize, $strCopyChecksum, $lManifestSaveSize, $lRepoSize, $strCopyChecksum, $lManifestSaveSize,
$lManifestSaveCurrent); $lManifestSaveCurrent);
# A keep-alive is required here because if there are a large number of resumed files that need to be checksummed
# then the remote might timeout while waiting for a command.
protocolGet()->keepAlive();
} }
} }
} }
@@ -481,10 +485,12 @@ sub processManifest
# Complete thread queues # Complete thread queues
my $bDone = false; my $bDone = false;
my $bKeepAlive = false;
do do
{ {
$bDone = threadGroupComplete(); $bDone = threadGroupComplete();
$bKeepAlive = false;
# Read the messages that are passed back from the backup threads # Read the messages that are passed back from the backup threads
while (my $oMessage = $oResultQueue->dequeue_nb()) while (my $oMessage = $oResultQueue->dequeue_nb())
@@ -494,10 +500,18 @@ sub processManifest
$lManifestSaveCurrent = backupManifestUpdate($oBackupManifest, $$oMessage{repo_file}, $$oMessage{copied}, $lManifestSaveCurrent = backupManifestUpdate($oBackupManifest, $$oMessage{repo_file}, $$oMessage{copied},
$$oMessage{size}, $$oMessage{repo_size}, $$oMessage{checksum}, $$oMessage{size}, $$oMessage{repo_size}, $$oMessage{checksum},
$lManifestSaveSize, $lManifestSaveCurrent); $lManifestSaveSize, $lManifestSaveCurrent);
# A keep-alive is required inside the loop because a flood of thread messages could prevent the keep-alive
# outside the loop from running in a timely fashion.
protocolGet()->keepAlive();
$bKeepAlive = true;
} }
# Keep the protocol layer from timing out # This keep-alive only runs if the keep-alive in the loop did not run
protocolGet()->keepAlive(); if (!$bKeepAlive)
{
protocolGet()->keepAlive();
}
} }
while (!$bDone); while (!$bDone);
} }
@@ -679,7 +693,7 @@ sub process
$oDatabaseMap = $self->{oDb}->databaseMapGet(); $oDatabaseMap = $self->{oDb}->databaseMapGet();
} }
# Buid the manifest # Build the manifest
$oBackupManifest->build($self->{oFile}, optionGet(OPTION_DB_PATH), $oLastManifest, optionGet(OPTION_ONLINE), $oBackupManifest->build($self->{oFile}, optionGet(OPTION_DB_PATH), $oLastManifest, optionGet(OPTION_ONLINE),
$oTablespaceMap, $oDatabaseMap); $oTablespaceMap, $oDatabaseMap);
&log(TEST, TEST_MANIFEST_BUILD); &log(TEST, TEST_MANIFEST_BUILD);

View File

@@ -114,25 +114,8 @@ sub exitSafe
} }
} }
# Don't fail if protocol cannot be destroyed # Close the remote
eval protocolDestroy();
{
protocolDestroy();
};
if ($@ && defined($iExitCode))
{
my $oMessage = $@;
if (blessed($oMessage) && $oMessage->isa('pgBackRest::Common::Exception'))
{
&log(WARN, 'unable to shutdown protocol (' . $oMessage->code() . '): ' . $oMessage->message());
exit $oMessage->code();
}
&log(WARN, "unable to shutdown protocol: $oMessage");
}
# Don't fail if the lock can't be released # Don't fail if the lock can't be released
eval eval

View File

@@ -94,6 +94,8 @@ use constant TEST_BACKUP_START => 'BACKUP-S
push @EXPORT, qw(TEST_BACKUP_START); push @EXPORT, qw(TEST_BACKUP_START);
use constant TEST_KEEP_ALIVE => 'KEEP_ALIVE'; use constant TEST_KEEP_ALIVE => 'KEEP_ALIVE';
push @EXPORT, qw(TEST_KEEP_ALIVE); push @EXPORT, qw(TEST_KEEP_ALIVE);
use constant TEST_PROCESS_EXIT => 'TEST_PROCESS_EXIT';
push @EXPORT, qw(TEST_PROCESS_EXIT);
use constant TEST_ARCHIVE_PUSH_ASYNC_START => 'ARCHIVE-PUSH-ASYNC-START'; use constant TEST_ARCHIVE_PUSH_ASYNC_START => 'ARCHIVE-PUSH-ASYNC-START';
push @EXPORT, qw(TEST_ARCHIVE_PUSH_ASYNC_START); push @EXPORT, qw(TEST_ARCHIVE_PUSH_ASYNC_START);

View File

@@ -259,6 +259,8 @@ use constant OPTION_COMPRESS_LEVEL_NETWORK => 'compress
push @EXPORT, qw(OPTION_COMPRESS_LEVEL_NETWORK); push @EXPORT, qw(OPTION_COMPRESS_LEVEL_NETWORK);
use constant OPTION_NEUTRAL_UMASK => 'neutral-umask'; use constant OPTION_NEUTRAL_UMASK => 'neutral-umask';
push @EXPORT, qw(OPTION_NEUTRAL_UMASK); push @EXPORT, qw(OPTION_NEUTRAL_UMASK);
use constant OPTION_PROTOCOL_TIMEOUT => 'protocol-timeout';
push @EXPORT, qw(OPTION_PROTOCOL_TIMEOUT);
use constant OPTION_THREAD_MAX => 'thread-max'; use constant OPTION_THREAD_MAX => 'thread-max';
push @EXPORT, qw(OPTION_THREAD_MAX); push @EXPORT, qw(OPTION_THREAD_MAX);
use constant OPTION_THREAD_TIMEOUT => 'thread-timeout'; use constant OPTION_THREAD_TIMEOUT => 'thread-timeout';
@@ -424,6 +426,13 @@ use constant OPTION_DEFAULT_DB_TIMEOUT_MIN => WAIT_TIME
use constant OPTION_DEFAULT_DB_TIMEOUT_MAX => 86400 * 7; use constant OPTION_DEFAULT_DB_TIMEOUT_MAX => 86400 * 7;
push @EXPORT, qw(OPTION_DEFAULT_DB_TIMEOUT_MAX); push @EXPORT, qw(OPTION_DEFAULT_DB_TIMEOUT_MAX);
use constant OPTION_DEFAULT_PROTOCOL_TIMEOUT => OPTION_DEFAULT_DB_TIMEOUT + 30;
push @EXPORT, qw(OPTION_DEFAULT_PROTOCOL_TIMEOUT);
use constant OPTION_DEFAULT_PROTOCOL_TIMEOUT_MIN => OPTION_DEFAULT_DB_TIMEOUT_MIN;
push @EXPORT, qw(OPTION_DEFAULT_PROTOCOL_TIMEOUT_MIN);
use constant OPTION_DEFAULT_PROTOCOL_TIMEOUT_MAX => OPTION_DEFAULT_DB_TIMEOUT_MAX;
push @EXPORT, qw(OPTION_DEFAULT_PROTOCOL_TIMEOUT_MAX);
use constant OPTION_DEFAULT_CONFIG => '/etc/' . BACKREST_EXE . '.conf'; use constant OPTION_DEFAULT_CONFIG => '/etc/' . BACKREST_EXE . '.conf';
push @EXPORT, qw(OPTION_DEFAULT_CONFIG); push @EXPORT, qw(OPTION_DEFAULT_CONFIG);
use constant OPTION_DEFAULT_LOCK_PATH => '/tmp/' . BACKREST_EXE; use constant OPTION_DEFAULT_LOCK_PATH => '/tmp/' . BACKREST_EXE;
@@ -921,14 +930,14 @@ my %oOptionRule =
&OPTION_RULE_ALLOW_RANGE => [OPTION_DEFAULT_DB_TIMEOUT_MIN, OPTION_DEFAULT_DB_TIMEOUT_MAX], &OPTION_RULE_ALLOW_RANGE => [OPTION_DEFAULT_DB_TIMEOUT_MIN, OPTION_DEFAULT_DB_TIMEOUT_MAX],
&OPTION_RULE_COMMAND => &OPTION_RULE_COMMAND =>
{ {
&CMD_ARCHIVE_GET => true, &CMD_ARCHIVE_GET => false,
&CMD_ARCHIVE_PUSH => true, &CMD_ARCHIVE_PUSH => false,
&CMD_BACKUP => true, &CMD_BACKUP => true,
&CMD_CHECK => true, &CMD_CHECK => true,
&CMD_EXPIRE => false, &CMD_EXPIRE => false,
&CMD_INFO => true, &CMD_INFO => false,
&CMD_REMOTE => true, &CMD_REMOTE => true,
&CMD_RESTORE => true &CMD_RESTORE => false
} }
}, },
@@ -1060,6 +1069,25 @@ my %oOptionRule =
}, },
}, },
&OPTION_PROTOCOL_TIMEOUT =>
{
&OPTION_RULE_SECTION => CONFIG_SECTION_GLOBAL,
&OPTION_RULE_TYPE => OPTION_TYPE_FLOAT,
&OPTION_RULE_DEFAULT => OPTION_DEFAULT_PROTOCOL_TIMEOUT,
&OPTION_RULE_ALLOW_RANGE => [OPTION_DEFAULT_PROTOCOL_TIMEOUT_MIN, OPTION_DEFAULT_PROTOCOL_TIMEOUT_MAX],
&OPTION_RULE_COMMAND =>
{
&CMD_ARCHIVE_GET => true,
&CMD_ARCHIVE_PUSH => true,
&CMD_BACKUP => true,
&CMD_CHECK => true,
&CMD_EXPIRE => false,
&CMD_INFO => true,
&CMD_REMOTE => true,
&CMD_RESTORE => true
}
},
&OPTION_REPO_PATH => &OPTION_REPO_PATH =>
{ {
&OPTION_RULE_SECTION => CONFIG_SECTION_GLOBAL, &OPTION_RULE_SECTION => CONFIG_SECTION_GLOBAL,
@@ -1687,6 +1715,16 @@ sub configLoad
umask(0000); umask(0000);
} }
# Protocol timeout should be greater than db timeout
if (optionTest(OPTION_DB_TIMEOUT) && optionTest(OPTION_PROTOCOL_TIMEOUT) &&
optionGet(OPTION_PROTOCOL_TIMEOUT) <= optionGet(OPTION_DB_TIMEOUT))
{
confess &log(ERROR,
"'" . optionGet(OPTION_PROTOCOL_TIMEOUT) . "' is not valid for '" . OPTION_PROTOCOL_TIMEOUT . "' option\n" .
"HINT: 'protocol-timeout' option should be greater than 'db-timeout' option.",
ERROR_OPTION_INVALID_VALUE);
}
# Check if the backup host is remote # Check if the backup host is remote
if (optionTest(OPTION_BACKUP_HOST)) if (optionTest(OPTION_BACKUP_HOST))
{ {
@@ -2461,7 +2499,7 @@ sub protocolGet
optionGet(OPTION_BUFFER_SIZE), optionGet(OPTION_BUFFER_SIZE),
commandTest(CMD_EXPIRE) ? OPTION_DEFAULT_COMPRESS_LEVEL : optionGet(OPTION_COMPRESS_LEVEL), commandTest(CMD_EXPIRE) ? OPTION_DEFAULT_COMPRESS_LEVEL : optionGet(OPTION_COMPRESS_LEVEL),
commandTest(CMD_EXPIRE) ? OPTION_DEFAULT_COMPRESS_LEVEL_NETWORK : optionGet(OPTION_COMPRESS_LEVEL_NETWORK), commandTest(CMD_EXPIRE) ? OPTION_DEFAULT_COMPRESS_LEVEL_NETWORK : optionGet(OPTION_COMPRESS_LEVEL_NETWORK),
protocolTimeoutGet() optionGet(OPTION_PROTOCOL_TIMEOUT)
); );
} }
@@ -2483,7 +2521,7 @@ sub protocolGet
commandTest(CMD_EXPIRE) ? OPTION_DEFAULT_COMPRESS_LEVEL_NETWORK : optionGet(OPTION_COMPRESS_LEVEL_NETWORK), commandTest(CMD_EXPIRE) ? OPTION_DEFAULT_COMPRESS_LEVEL_NETWORK : optionGet(OPTION_COMPRESS_LEVEL_NETWORK),
optionRemoteTypeTest(DB) ? optionGet(OPTION_DB_HOST) : optionGet(OPTION_BACKUP_HOST), optionRemoteTypeTest(DB) ? optionGet(OPTION_DB_HOST) : optionGet(OPTION_BACKUP_HOST),
optionRemoteTypeTest(DB) ? optionGet(OPTION_DB_USER) : optionGet(OPTION_BACKUP_USER), optionRemoteTypeTest(DB) ? optionGet(OPTION_DB_USER) : optionGet(OPTION_BACKUP_USER),
protocolTimeoutGet() optionGet(OPTION_PROTOCOL_TIMEOUT)
); );
if (!defined($bStore) || $bStore) if (!defined($bStore) || $bStore)
@@ -2496,19 +2534,6 @@ sub protocolGet
push @EXPORT, qw(protocolGet); push @EXPORT, qw(protocolGet);
####################################################################################################################################
# protocolTimeoutGet
#
# Get the protocol time - for the moment this is based on the db timeout + 30 seconds.
####################################################################################################################################
sub protocolTimeoutGet
{
return optionGet(OPTION_DB_TIMEOUT) >= OPTION_DEFAULT_DB_TIMEOUT ?
optionGet(OPTION_DB_TIMEOUT) + 30 : optionGet(OPTION_DB_TIMEOUT);
}
push @EXPORT, qw(protocolTimeoutGet);
#################################################################################################################################### ####################################################################################################################################
# protocolDestroy # protocolDestroy
# #
@@ -2516,11 +2541,15 @@ push @EXPORT, qw(protocolTimeoutGet);
#################################################################################################################################### ####################################################################################################################################
sub protocolDestroy sub protocolDestroy
{ {
my $iExitStatus = 0;
if (defined($oProtocol)) if (defined($oProtocol))
{ {
$oProtocol->close(); $iExitStatus = $oProtocol->close();
undef($oProtocol); undef($oProtocol);
} }
return $iExitStatus;
} }
push @EXPORT, qw(protocolDestroy); push @EXPORT, qw(protocolDestroy);

View File

@@ -439,6 +439,19 @@ my $oConfigHelpData =
"the command line." "the command line."
}, },
# PROTOCOL-TIMEOUT Option Help
#---------------------------------------------------------------------------------------------------------------------------
'protocol-timeout' =>
{
section => 'general',
summary =>
"Protocol timeout.",
description =>
"Sets the timeout, in seconds, that the master or remote process will wait for a new message to be received on " .
"the protocol layer. This prevents processes from waiting indefinitely for a message. The protocol-timeout " .
"option must be greater than the db-timeout option."
},
# RECOVERY-OPTION Option Help # RECOVERY-OPTION Option Help
#--------------------------------------------------------------------------------------------------------------------------- #---------------------------------------------------------------------------------------------------------------------------
'recovery-option' => 'recovery-option' =>
@@ -686,12 +699,12 @@ my $oConfigHelpData =
'config' => 'default', 'config' => 'default',
'config-remote' => 'section', 'config-remote' => 'section',
'db-path' => 'section', 'db-path' => 'section',
'db-timeout' => 'section',
'lock-path' => 'section', 'lock-path' => 'section',
'log-level-console' => 'section', 'log-level-console' => 'section',
'log-level-file' => 'section', 'log-level-file' => 'section',
'log-path' => 'section', 'log-path' => 'section',
'neutral-umask' => 'section', 'neutral-umask' => 'section',
'protocol-timeout' => 'section',
'repo-path' => 'section', 'repo-path' => 'section',
'stanza' => 'default' 'stanza' => 'default'
} }
@@ -721,12 +734,12 @@ my $oConfigHelpData =
'config' => 'default', 'config' => 'default',
'config-remote' => 'section', 'config-remote' => 'section',
'db-path' => 'section', 'db-path' => 'section',
'db-timeout' => 'section',
'lock-path' => 'section', 'lock-path' => 'section',
'log-level-console' => 'section', 'log-level-console' => 'section',
'log-level-file' => 'section', 'log-level-file' => 'section',
'log-path' => 'section', 'log-path' => 'section',
'neutral-umask' => 'section', 'neutral-umask' => 'section',
'protocol-timeout' => 'section',
'repo-path' => 'section', 'repo-path' => 'section',
'spool-path' => 'section', 'spool-path' => 'section',
'stanza' => 'default' 'stanza' => 'default'
@@ -803,6 +816,7 @@ my $oConfigHelpData =
"archive-check is automatically disabled for the backup." "archive-check is automatically disabled for the backup."
}, },
'protocol-timeout' => 'section',
'repo-path' => 'section', 'repo-path' => 'section',
'resume' => 'section', 'resume' => 'section',
'retention-archive' => 'section', 'retention-archive' => 'section',
@@ -869,6 +883,7 @@ my $oConfigHelpData =
'log-level-file' => 'section', 'log-level-file' => 'section',
'log-path' => 'section', 'log-path' => 'section',
'neutral-umask' => 'section', 'neutral-umask' => 'section',
'protocol-timeout' => 'section',
'repo-path' => 'section', 'repo-path' => 'section',
'stanza' => 'default' 'stanza' => 'default'
} }
@@ -941,7 +956,6 @@ my $oConfigHelpData =
'compress-level-network' => 'section', 'compress-level-network' => 'section',
'config' => 'default', 'config' => 'default',
'config-remote' => 'section', 'config-remote' => 'section',
'db-timeout' => 'section',
'lock-path' => 'section', 'lock-path' => 'section',
'log-level-console' => 'section', 'log-level-console' => 'section',
'log-level-file' => 'section', 'log-level-file' => 'section',
@@ -960,6 +974,7 @@ my $oConfigHelpData =
"* json - Exhaustive machine-readable backup information in JSON format." "* json - Exhaustive machine-readable backup information in JSON format."
}, },
'protocol-timeout' => 'section',
'repo-path' => 'section', 'repo-path' => 'section',
'stanza' => 'default' 'stanza' => 'default'
} }
@@ -987,7 +1002,6 @@ my $oConfigHelpData =
'config-remote' => 'section', 'config-remote' => 'section',
'db-include' => 'section', 'db-include' => 'section',
'db-path' => 'section', 'db-path' => 'section',
'db-timeout' => 'section',
# DELTA Option Help # DELTA Option Help
#------------------------------------------------------------------------------------------------------------------- #-------------------------------------------------------------------------------------------------------------------
@@ -1031,6 +1045,7 @@ my $oConfigHelpData =
'log-level-file' => 'section', 'log-level-file' => 'section',
'log-path' => 'section', 'log-path' => 'section',
'neutral-umask' => 'section', 'neutral-umask' => 'section',
'protocol-timeout' => 'section',
'recovery-option' => 'section', 'recovery-option' => 'section',
'repo-path' => 'section', 'repo-path' => 'section',

View File

@@ -10,6 +10,7 @@ use Carp qw(confess);
use File::Basename qw(dirname); use File::Basename qw(dirname);
use Time::HiRes qw(gettimeofday); use Time::HiRes qw(gettimeofday);
use Scalar::Util qw(blessed);
use lib dirname($0) . '/../lib'; use lib dirname($0) . '/../lib';
use pgBackRest::Common::Exception; use pgBackRest::Common::Exception;
@@ -92,22 +93,48 @@ sub close
{ {
my $self = shift; my $self = shift;
# Exit status defaults to success
my $iExitStatus = 0;
# Only send the exit command if the process is running # Only send the exit command if the process is running
if (defined($self->{io}) && defined($self->{io}->pIdGet())) if (defined($self->{io}) && defined($self->{io}->pIdGet()))
{ {
&log(TRACE, "sending exit command to process"); &log(TRACE, "sending exit command to process");
$self->cmdWrite('exit'); eval
{
$self->cmdWrite('exit');
};
if ($@)
{
my $oMessage = $@;
my $strError = 'unable to shutdown protocol';
my $strHint = 'HINT: the process completed successfully but protocol-timeout may need to be increased.';
if (blessed($oMessage) && $oMessage->isa('pgBackRest::Common::Exception'))
{
$iExitStatus = $oMessage->code();
}
else
{
if (!defined($oMessage))
{
$oMessage = 'unknown error';
}
$iExitStatus = ERROR_UNKNOWN;
}
&log(WARN,
$strError . ($iExitStatus == ERROR_UNKNOWN ? '' : ' [' . $oMessage->code() . ']') . ': ' .
($iExitStatus == ERROR_UNKNOWN ? $oMessage : $oMessage->message()) . "\n${strHint}");
}
undef($self->{io}); undef($self->{io});
# &log(TRACE, "waiting for remote process");
# if (!$self->waitPid(5, false))
# {
# &log(TRACE, "killed remote process");
# kill('KILL', $self->{pId});
# }
} }
return $iExitStatus;
} }
#################################################################################################################################### ####################################################################################################################################

View File

@@ -26,13 +26,13 @@ full backup (error on link to a link)
INFO: backup stop INFO: backup stop
full backup full backup
> [BACKREST_BIN] --config=[TEST_PATH]/backrest/pgbackrest.conf --no-online --manifest-save-threshold=3 --db-timeout=2 --type=full --stanza=db backup > [BACKREST_BIN] --config=[TEST_PATH]/backrest/pgbackrest.conf --no-online --manifest-save-threshold=3 --protocol-timeout=2 --db-timeout=1 --type=full --stanza=db backup
------------------------------------------------------------------------------------------------------------------------------------ ------------------------------------------------------------------------------------------------------------------------------------
INFO: backup start: --cmd-remote=[BACKREST_BIN] --no-compress --config=[TEST_PATH]/backrest/pgbackrest.conf --config-remote=[TEST_PATH]/db/pgbackrest.conf --db-host=127.0.0.1 --db-path=[TEST_PATH]/db/common --db-port=[PORT-1] --db-socket-path=[TEST_PATH]/db --db-timeout=2 --db-user=vagrant --lock-path=[TEST_PATH]/backrest/lock --log-level-console=debug --log-level-file=trace --log-path=[TEST_PATH]/backrest/log --manifest-save-threshold=3 --no-online --repo-path=[TEST_PATH]/backrest --stanza=db --start-fast --type=full INFO: backup start: --cmd-remote=[BACKREST_BIN] --no-compress --config=[TEST_PATH]/backrest/pgbackrest.conf --config-remote=[TEST_PATH]/db/pgbackrest.conf --db-host=127.0.0.1 --db-path=[TEST_PATH]/db/common --db-port=[PORT-1] --db-socket-path=[TEST_PATH]/db --db-timeout=1 --db-user=vagrant --lock-path=[TEST_PATH]/backrest/lock --log-level-console=debug --log-level-file=trace --log-path=[TEST_PATH]/backrest/log --manifest-save-threshold=3 --no-online --protocol-timeout=2 --repo-path=[TEST_PATH]/backrest --stanza=db --start-fast --type=full
DEBUG: Common:::Lock::lockAquire(): bFailOnNoLock = <true>, bRemote = <false>, iProcessIdx = [undef], strLockType = backup DEBUG: Common:::Lock::lockAquire(): bFailOnNoLock = <true>, bRemote = <false>, iProcessIdx = [undef], strLockType = backup
DEBUG: Common:::Lock::lockAquire=>: bResult = true DEBUG: Common:::Lock::lockAquire=>: bResult = true
DEBUG: Protocol::RemoteMaster->new(): iBufferMax = 4194304, iCompressLevel = 6, iCompressLevelNetwork = 3, iProtocolTimeout = 2, strCommand = [BACKREST_BIN] --command=backup --config=[TEST_PATH]/db/pgbackrest.conf --db-host=127.0.0.1 --db-port=[PORT-1] --db-socket-path=[TEST_PATH]/db --db-timeout=2 --repo-path=[TEST_PATH]/backrest --stanza=db remote, strHost = 127.0.0.1, strUser = [USER-1] DEBUG: Protocol::RemoteMaster->new(): iBufferMax = 4194304, iCompressLevel = 6, iCompressLevelNetwork = 3, iProtocolTimeout = 2, strCommand = [BACKREST_BIN] --command=backup --config=[TEST_PATH]/db/pgbackrest.conf --db-host=127.0.0.1 --db-port=[PORT-1] --db-socket-path=[TEST_PATH]/db --db-timeout=1 --protocol-timeout=2 --repo-path=[TEST_PATH]/backrest --stanza=db remote, strHost = 127.0.0.1, strUser = [USER-1]
DEBUG: Protocol::CommonMaster->new(): iBufferMax = 4194304, iCompressLevel = 6, iCompressLevelNetwork = 3, iProtocolTimeout = 2, strCommand = ssh -o Compression=no -o PasswordAuthentication=no vagrant@127.0.0.1 '[BACKREST_BIN] --command=backup --config=[TEST_PATH]/db/pgbackrest.conf --db-host=127.0.0.1 --db-port=[PORT-1] --db-socket-path=[TEST_PATH]/db --db-timeout=2 --repo-path=[TEST_PATH]/backrest --stanza=db remote', strName = remote DEBUG: Protocol::CommonMaster->new(): iBufferMax = 4194304, iCompressLevel = 6, iCompressLevelNetwork = 3, iProtocolTimeout = 2, strCommand = ssh -o Compression=no -o PasswordAuthentication=no vagrant@127.0.0.1 '[BACKREST_BIN] --command=backup --config=[TEST_PATH]/db/pgbackrest.conf --db-host=127.0.0.1 --db-port=[PORT-1] --db-socket-path=[TEST_PATH]/db --db-timeout=1 --protocol-timeout=2 --repo-path=[TEST_PATH]/backrest --stanza=db remote', strName = remote
DEBUG: File->new(): iThreadIdx = [undef], oProtocol = [object], strBackupPath = [TEST_PATH]/backrest, strDefaultFileMode = <0640>, strDefaultPathMode = <0750>, strRemote = db, strStanza = db DEBUG: File->new(): iThreadIdx = [undef], oProtocol = [object], strBackupPath = [TEST_PATH]/backrest, strDefaultFileMode = <0640>, strDefaultPathMode = <0750>, strRemote = db, strStanza = db
DEBUG: File->pathCreate(): bCreateParents = true, bIgnoreExists = true, strMode = <0750>, strPath = backup.history, strPathType = backup:cluster DEBUG: File->pathCreate(): bCreateParents = true, bIgnoreExists = true, strMode = <0750>, strPath = backup.history, strPathType = backup:cluster
DEBUG: BackupInfo->new(): bValidate = <true>, strBackupClusterPath = [TEST_PATH]/backrest/backup/db DEBUG: BackupInfo->new(): bValidate = <true>, strBackupClusterPath = [TEST_PATH]/backrest/backup/db
@@ -105,7 +105,7 @@ full backup
DEBUG: File->remove=>: bRemoved = false DEBUG: File->remove=>: bRemoved = false
DEBUG: File->linkCreate(): bHard = <false>, bPathCreate = <true>, bRelative = true, strDestinationFile = latest, strDestinationPathType = backup:cluster, strSourceFile = [BACKUP-FULL-1], strSourcePathType = backup:cluster DEBUG: File->linkCreate(): bHard = <false>, bPathCreate = <true>, bRelative = true, strDestinationFile = latest, strDestinationPathType = backup:cluster, strSourceFile = [BACKUP-FULL-1], strSourcePathType = backup:cluster
INFO: backup stop INFO: backup stop
INFO: expire start: --no-compress --config=[TEST_PATH]/backrest/pgbackrest.conf --db-host=127.0.0.1 --db-timeout=2 --lock-path=[TEST_PATH]/backrest/lock --log-level-console=debug --log-level-file=trace --log-path=[TEST_PATH]/backrest/log --repo-path=[TEST_PATH]/backrest --stanza=db INFO: expire start: --no-compress --config=[TEST_PATH]/backrest/pgbackrest.conf --db-host=127.0.0.1 --db-timeout=1 --lock-path=[TEST_PATH]/backrest/lock --log-level-console=debug --log-level-file=trace --log-path=[TEST_PATH]/backrest/log --protocol-timeout=2 --repo-path=[TEST_PATH]/backrest --stanza=db
DEBUG: File->new(): iThreadIdx = [undef], oProtocol = [object], strBackupPath = [TEST_PATH]/backrest, strDefaultFileMode = <0640>, strDefaultPathMode = <0750>, strRemote = db, strStanza = db DEBUG: File->new(): iThreadIdx = [undef], oProtocol = [object], strBackupPath = [TEST_PATH]/backrest, strDefaultFileMode = <0640>, strDefaultPathMode = <0750>, strRemote = db, strStanza = db
DEBUG: BackupInfo->new(): bValidate = <true>, strBackupClusterPath = [TEST_PATH]/backrest/backup/db DEBUG: BackupInfo->new(): bValidate = <true>, strBackupClusterPath = [TEST_PATH]/backrest/backup/db
DEBUG: BackupCommon::backupRegExpGet(): bAnchor = <true>, bDifferential = true, bFull = true, bIncremental = true DEBUG: BackupCommon::backupRegExpGet(): bAnchor = <true>, bDifferential = true, bFull = true, bIncremental = true
@@ -263,13 +263,13 @@ db-version="9.3"
1={"db-catalog-version":201306121,"db-control-version":937,"db-system-id":6156904820763115222,"db-version":"9.3"} 1={"db-catalog-version":201306121,"db-control-version":937,"db-system-id":6156904820763115222,"db-version":"9.3"}
full backup (protocol timeout) full backup (protocol timeout)
> [BACKREST_BIN] --config=[TEST_PATH]/backrest/pgbackrest.conf --no-online --db-timeout=1 --type=full --stanza=db backup --test --test-delay=1 --test-point=backup-start=y > [BACKREST_BIN] --config=[TEST_PATH]/backrest/pgbackrest.conf --no-online --protocol-timeout=1 --db-timeout=.1 --type=full --stanza=db backup --test --test-delay=1 --test-point=backup-start=y
------------------------------------------------------------------------------------------------------------------------------------ ------------------------------------------------------------------------------------------------------------------------------------
INFO: backup start: --cmd-remote=[BACKREST_BIN] --no-compress --config=[TEST_PATH]/backrest/pgbackrest.conf --config-remote=[TEST_PATH]/db/pgbackrest.conf --db-host=127.0.0.1 --db-path=[TEST_PATH]/db/common --db-port=[PORT-1] --db-socket-path=[TEST_PATH]/db --db-timeout=1 --db-user=vagrant --lock-path=[TEST_PATH]/backrest/lock --log-level-console=debug --log-level-file=trace --log-path=[TEST_PATH]/backrest/log --no-online --repo-path=[TEST_PATH]/backrest --stanza=db --start-fast --test --test-delay=1 --test-point=backup-start=y --type=full INFO: backup start: --cmd-remote=[BACKREST_BIN] --no-compress --config=[TEST_PATH]/backrest/pgbackrest.conf --config-remote=[TEST_PATH]/db/pgbackrest.conf --db-host=127.0.0.1 --db-path=[TEST_PATH]/db/common --db-port=[PORT-1] --db-socket-path=[TEST_PATH]/db --db-timeout=.1 --db-user=vagrant --lock-path=[TEST_PATH]/backrest/lock --log-level-console=debug --log-level-file=trace --log-path=[TEST_PATH]/backrest/log --no-online --protocol-timeout=1 --repo-path=[TEST_PATH]/backrest --stanza=db --start-fast --test --test-delay=1 --test-point=backup-start=y --type=full
DEBUG: Common:::Lock::lockAquire(): bFailOnNoLock = <true>, bRemote = <false>, iProcessIdx = [undef], strLockType = backup DEBUG: Common:::Lock::lockAquire(): bFailOnNoLock = <true>, bRemote = <false>, iProcessIdx = [undef], strLockType = backup
DEBUG: Common:::Lock::lockAquire=>: bResult = true DEBUG: Common:::Lock::lockAquire=>: bResult = true
DEBUG: Protocol::RemoteMaster->new(): iBufferMax = 4194304, iCompressLevel = 6, iCompressLevelNetwork = 3, iProtocolTimeout = 1, strCommand = [BACKREST_BIN] --command=backup --config=[TEST_PATH]/db/pgbackrest.conf --db-host=127.0.0.1 --db-port=[PORT-1] --db-socket-path=[TEST_PATH]/db --db-timeout=1 --repo-path=[TEST_PATH]/backrest --stanza=db remote, strHost = 127.0.0.1, strUser = [USER-1] DEBUG: Protocol::RemoteMaster->new(): iBufferMax = 4194304, iCompressLevel = 6, iCompressLevelNetwork = 3, iProtocolTimeout = 1, strCommand = [BACKREST_BIN] --command=backup --config=[TEST_PATH]/db/pgbackrest.conf --db-host=127.0.0.1 --db-port=[PORT-1] --db-socket-path=[TEST_PATH]/db --db-timeout=.1 --protocol-timeout=1 --repo-path=[TEST_PATH]/backrest --stanza=db remote, strHost = 127.0.0.1, strUser = [USER-1]
DEBUG: Protocol::CommonMaster->new(): iBufferMax = 4194304, iCompressLevel = 6, iCompressLevelNetwork = 3, iProtocolTimeout = 1, strCommand = ssh -o Compression=no -o PasswordAuthentication=no vagrant@127.0.0.1 '[BACKREST_BIN] --command=backup --config=[TEST_PATH]/db/pgbackrest.conf --db-host=127.0.0.1 --db-port=[PORT-1] --db-socket-path=[TEST_PATH]/db --db-timeout=1 --repo-path=[TEST_PATH]/backrest --stanza=db remote', strName = remote DEBUG: Protocol::CommonMaster->new(): iBufferMax = 4194304, iCompressLevel = 6, iCompressLevelNetwork = 3, iProtocolTimeout = 1, strCommand = ssh -o Compression=no -o PasswordAuthentication=no vagrant@127.0.0.1 '[BACKREST_BIN] --command=backup --config=[TEST_PATH]/db/pgbackrest.conf --db-host=127.0.0.1 --db-port=[PORT-1] --db-socket-path=[TEST_PATH]/db --db-timeout=.1 --protocol-timeout=1 --repo-path=[TEST_PATH]/backrest --stanza=db remote', strName = remote
DEBUG: File->new(): iThreadIdx = [undef], oProtocol = [object], strBackupPath = [TEST_PATH]/backrest, strDefaultFileMode = <0640>, strDefaultPathMode = <0750>, strRemote = db, strStanza = db DEBUG: File->new(): iThreadIdx = [undef], oProtocol = [object], strBackupPath = [TEST_PATH]/backrest, strDefaultFileMode = <0640>, strDefaultPathMode = <0750>, strRemote = db, strStanza = db
DEBUG: File->pathCreate(): bCreateParents = true, bIgnoreExists = true, strMode = <0750>, strPath = backup.history, strPathType = backup:cluster DEBUG: File->pathCreate(): bCreateParents = true, bIgnoreExists = true, strMode = <0750>, strPath = backup.history, strPathType = backup:cluster
DEBUG: BackupInfo->new(): bValidate = <true>, strBackupClusterPath = [TEST_PATH]/backrest/backup/db DEBUG: BackupInfo->new(): bValidate = <true>, strBackupClusterPath = [TEST_PATH]/backrest/backup/db
@@ -3742,3 +3742,10 @@ info bogus
} }
} }
] ]
diff backup (protocol shutdown timeout)
> [BACKREST_BIN] --config=[TEST_PATH]/backrest/pgbackrest.conf --no-online --protocol-timeout=1 --db-timeout=.5 --log-level-console=warn --type=diff --stanza=db backup --test --test-delay=1 --test-point=test_process_exit=y
------------------------------------------------------------------------------------------------------------------------------------
ERROR: [141]: remote process terminated: ERROR [141]: unable to read line after 1 seconds
WARN: unable to shutdown protocol [141]: remote process terminated: ERROR [141]: unable to read line after 1 seconds
HINT: the process completed successfully but protocol-timeout may need to be increased.

View File

@@ -1236,6 +1236,7 @@ push @EXPORT, qw(BackRestTestBackup_BackupEnd);
sub BackRestTestBackup_BackupEnd sub BackRestTestBackup_BackupEnd
{ {
my $oExpectedManifestRef = shift; my $oExpectedManifestRef = shift;
my $bSupplemental = shift;
my $iExitStatus = $oExecuteBackup->end(); my $iExitStatus = $oExecuteBackup->end();
@@ -1258,7 +1259,7 @@ sub BackRestTestBackup_BackupEnd
BackRestTestBackup_BackupCompare($oBackupFile, $bBackupRemote, $strBackup, $oExpectedManifestRef); BackRestTestBackup_BackupCompare($oBackupFile, $bBackupRemote, $strBackup, $oExpectedManifestRef);
} }
if (defined($oBackupLogTest)) if (defined($oBackupLogTest) && (!defined($bSupplemental) || $bSupplemental))
{ {
$oBackupLogTest->supplementalAdd(BackRestTestCommon_DbPathGet() . "/pgbackrest.conf", $bBackupRemote); $oBackupLogTest->supplementalAdd(BackRestTestCommon_DbPathGet() . "/pgbackrest.conf", $bBackupRemote);
@@ -1290,7 +1291,7 @@ sub BackRestTestBackup_BackupSynthetic
my $oParam = shift; my $oParam = shift;
BackRestTestBackup_BackupBegin($strType, $strStanza, $strComment, $oParam); BackRestTestBackup_BackupBegin($strType, $strStanza, $strComment, $oParam);
return BackRestTestBackup_BackupEnd($oExpectedManifestRef); return BackRestTestBackup_BackupEnd($oExpectedManifestRef, $$oParam{bSupplemental});
} }
#################################################################################################################################### ####################################################################################################################################

View File

@@ -963,7 +963,7 @@ sub BackRestTestBackup_Test
if ($bNeutralTest && $bRemote) if ($bNeutralTest && $bRemote)
{ {
$strOptionalParam .= ' --db-timeout=2'; $strOptionalParam .= ' --protocol-timeout=2 --db-timeout=1';
if ($iThreadMax > 1) if ($iThreadMax > 1)
{ {
@@ -1019,7 +1019,7 @@ sub BackRestTestBackup_Test
{ {
BackRestTestBackup_BackupSynthetic( BackRestTestBackup_BackupSynthetic(
$strType, $strStanza, \%oManifest, 'protocol timeout', $strType, $strStanza, \%oManifest, 'protocol timeout',
{strOptionalParam => '--db-timeout=1', {strOptionalParam => '--protocol-timeout=1 --db-timeout=.1',
strTest => TEST_BACKUP_START, strTest => TEST_BACKUP_START,
fTestDelay => 1, fTestDelay => 1,
iExpectedExitStatus => ERROR_PROTOCOL_TIMEOUT}); iExpectedExitStatus => ERROR_PROTOCOL_TIMEOUT});
@@ -1640,6 +1640,16 @@ sub BackRestTestBackup_Test
executeTest('ls -1R ' . BackRestTestCommon_RepoPathGet() . "/backup/${strStanza}/" . PATH_BACKUP_HISTORY, executeTest('ls -1R ' . BackRestTestCommon_RepoPathGet() . "/backup/${strStanza}/" . PATH_BACKUP_HISTORY,
{oLogTest => $oLogTest, bRemote => $bRemote}); {oLogTest => $oLogTest, bRemote => $bRemote});
} }
# Test protocol shutdown timeout
#-----------------------------------------------------------------------------------------------------------------------
if ($bNeutralTest && $bRemote)
{
BackRestTestBackup_BackupSynthetic(
$strType, $strStanza, \%oManifest, 'protocol shutdown timeout',
{strOptionalParam => '--protocol-timeout=1 --db-timeout=.5 --log-level-console=warn',
strTest => TEST_PROCESS_EXIT, fTestDelay => 1, bSupplemental => false});
}
} }
} }
} }

View File

@@ -153,7 +153,8 @@ sub configLoadExpect
} }
elsif ($iExpectedError == ERROR_OPTION_INVALID_VALUE) elsif ($iExpectedError == ERROR_OPTION_INVALID_VALUE)
{ {
$strError = "'${strErrorParam1}' is not valid for '${strErrorParam2}' option"; $strError = "'${strErrorParam1}' is not valid for '${strErrorParam2}' option" .
(defined($strErrorParam3) ? "\nHINT: ${strErrorParam3}." : '');
} }
elsif ($iExpectedError == ERROR_OPTION_INVALID_RANGE) elsif ($iExpectedError == ERROR_OPTION_INVALID_RANGE)
{ {
@@ -470,6 +471,18 @@ sub BackRestTestConfig_Test
configLoadExpect($oOption, CMD_BACKUP, ERROR_OPTION_INVALID_VALUE, BOGUS, OPTION_RETENTION_ARCHIVE_TYPE); configLoadExpect($oOption, CMD_BACKUP, ERROR_OPTION_INVALID_VALUE, BOGUS, OPTION_RETENTION_ARCHIVE_TYPE);
} }
if (BackRestTestCommon_Run(++$iRun, CMD_BACKUP . ' invalid value ' . OPTION_PROTOCOL_TIMEOUT))
{
optionSetTest($oOption, OPTION_STANZA, $strStanza);
optionSetTest($oOption, OPTION_DB_PATH, '/db');
optionSetTest($oOption, OPTION_DB_TIMEOUT, 5);
optionSetTest($oOption, OPTION_PROTOCOL_TIMEOUT, 4);
configLoadExpect(
$oOption, CMD_BACKUP, ERROR_OPTION_INVALID_VALUE, 4, OPTION_PROTOCOL_TIMEOUT,
"'protocol-timeout' option should be greater than 'db-timeout' option");
}
if (BackRestTestCommon_Run(++$iRun, CMD_BACKUP . ' valid value ' . OPTION_RETENTION_ARCHIVE_TYPE)) if (BackRestTestCommon_Run(++$iRun, CMD_BACKUP . ' valid value ' . OPTION_RETENTION_ARCHIVE_TYPE))
{ {
optionSetTest($oOption, OPTION_STANZA, $strStanza); optionSetTest($oOption, OPTION_STANZA, $strStanza);