1
0
mirror of https://github.com/pgbackrest/pgbackrest.git synced 2025-03-03 14:52:21 +02:00

Fix incorrectly reported error return in info logging.

A return code of 1 from the archive-get was being logged as an error message at info level but otherwise worked correctly.

Also improve info messages when an archive segment is or is not found.
This commit is contained in:
David Steele 2018-09-04 21:46:41 -04:00
parent 800afeef70
commit 6361a06181
11 changed files with 128 additions and 9 deletions

View File

@ -14,6 +14,12 @@
<release-list>
<release date="XXXX-XX-XX" version="2.06dev" title="UNDER DEVELOPMENT">
<release-core-list>
<release-bug-list>
<release-item>
<p>Fix incorrectly reported error return in <id>info</id> logging. A return code of 1 from the <cmd>archive-get</cmd> was being logged as an error message at <id>info</id> level but otherwise worked correctly.</p>
</release-item>
</release-bug-list>
<release-improvement-list>
<release-item>
<p>Ignore all files in a linked tablespace directory except the subdirectory for the current version of <postgres/>. Previously an error would be generated if other files were present and not owned by the <postgres/> user.</p>

View File

@ -170,8 +170,6 @@ sub archiveGetFile
if (!defined($strArchiveFile))
{
&log(INFO, "unable to find ${strSourceArchive} in the archive");
$iResult = 1;
}
else

View File

@ -67,7 +67,7 @@ sub process
(new pgBackRest::Archive::Get::Async(
storageSpool()->pathGet(STORAGE_SPOOL_ARCHIVE_IN), $self->{strBackRestBin}, $rstryCommandArg))->process();
}
# Else push synchronously
# Else get synchronously
else
{
# Make sure the archive file is defined
@ -89,7 +89,14 @@ sub process
$iResult = archiveGetFile($strSourceArchive, $strDestinationFile, false);
# Info for the Postgres log
&log(INFO, 'got WAL segment ' . $strSourceArchive);
if ($iResult == 0)
{
&log(INFO, 'got WAL segment ' . $strSourceArchive);
}
else
{
&log(INFO, "unable to find ${strSourceArchive} in the archive");
}
}
# Return from function and log return values if any

View File

@ -171,7 +171,6 @@ cmdEnd(int code, const String *errorMessage)
FUNCTION_DEBUG_PARAM(STRING, errorMessage);
FUNCTION_DEBUG_ASSERT(cfgCommand() != cfgCmdNone);
FUNCTION_DEBUG_ASSERT(code == 0 || errorMessage != NULL);
FUNCTION_DEBUG_END();
// Skip this log message if it won't be output. It's not too expensive but since we skipped cmdBegin(), may as well.
@ -182,7 +181,7 @@ cmdEnd(int code, const String *errorMessage)
// Basic info on command end
String *info = strNewFmt("%s command end: ", cfgCommandName(cfgCommand()));
if (code == 0)
if (errorMessage == NULL)
{
strCat(info, "completed successfully");

View File

@ -158,7 +158,7 @@ exitSafe(int result, bool error, SignalType signalType)
strCatFmt(errorMessage, "[SIG%s]", exitSignalName(signalType));
}
// Standard error exit message
else
else if (error)
errorMessage = strNewFmt("aborted with exception [%03d]", result);
}

View File

@ -791,8 +791,6 @@ static const EmbeddedModule embeddedModule[] =
"\n"
"if (!defined($strArchiveFile))\n"
"{\n"
"&log(INFO, \"unable to find ${strSourceArchive} in the archive\");\n"
"\n"
"$iResult = 1;\n"
"}\n"
"else\n"
@ -905,8 +903,15 @@ static const EmbeddedModule embeddedModule[] =
"\n"
"$iResult = archiveGetFile($strSourceArchive, $strDestinationFile, false);\n"
"\n\n"
"if ($iResult == 0)\n"
"{\n"
"&log(INFO, 'got WAL segment ' . $strSourceArchive);\n"
"}\n"
"else\n"
"{\n"
"&log(INFO, \"unable to find ${strSourceArchive} in the archive\");\n"
"}\n"
"}\n"
"\n\n"
"return logDebugReturn\n"
"(\n"

View File

@ -118,6 +118,55 @@ P00 INFO: archive-push command end: completed successfully
P00 DEBUG: common/exit::exitSafe: => 0
P00 DEBUG: main::main: => 0
> [CONTAINER-EXEC] db-master [BACKREST-BIN] --config=[TEST_PATH]/db-master/pgbackrest.conf --stanza=db archive-get --log-level-console=debug 700000007000000070000000 [TEST_PATH]/db-master/db/base/pg_xlog/RECOVERYXLOG
------------------------------------------------------------------------------------------------------------------------------------
P00 INFO: archive-get command begin [BACKREST-VERSION]: [700000007000000070000000, [TEST_PATH]/db-master/db/base/pg_xlog/RECOVERYXLOG] --no-compress --compress-level=3 --config=[TEST_PATH]/db-master/pgbackrest.conf --db-timeout=45 --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 --log-subprocess --no-log-timestamp --pg1-path=[TEST_PATH]/db-master/db/base --protocol-timeout=60 --repo1-cipher-pass=<redacted> --repo1-cipher-type=aes-256-cbc --repo1-path=[TEST_PATH]/db-master/repo --stanza=db
P00 DEBUG: config/load::cfgLoad: => void
P00 DEBUG: command/archive/get/get::cmdArchiveGet: (void)
P00 DEBUG: perl/exec::perlExec: (void)
P00 DEBUG: Archive::Get::Get->process(): rstryCommandArg = (700000007000000070000000, [TEST_PATH]/db-master/db/base/pg_xlog/RECOVERYXLOG)
P00 DEBUG: Archive::Get::File::archiveGetFile(): bAtomic = false, strDestinationFile = [TEST_PATH]/db-master/db/base/pg_xlog/RECOVERYXLOG, strSourceArchive = 700000007000000070000000
P00 DEBUG: Common::Lock::lockStopTest(): bStanzaStopRequired = <false>
P00 DEBUG: Common::Lock::lockStopTest=>: bStopExists = false
P00 DEBUG: Storage::Posix::Driver->new(): bFileSync = <true>, bPathSync = <true>
P00 DEBUG: Storage::Local->new(): bAllowTemp = <true>, hRule = [hash], lBufferMax = 4194304, oDriver = [object], strCipherPassUser = <redacted>, strCipherType = aes-256-cbc, strDefaultFileMode = <0640>, strDefaultPathMode = <0750>, strPathBase = [TEST_PATH]/db-master/repo, strTempExtension = pgbackrest.tmp
P00 DEBUG: Archive::Get::File::archiveGetCheck(): bCheck = false, strDbVersion = [undef], strFile = 700000007000000070000000, ullDbSysId = [undef]
P00 DEBUG: Db::dbObjectGet(): bMasterOnly = true
P00 DEBUG: Db->new(): iRemoteIdx = 1
P00 DEBUG: Db::dbObjectGet=>: iDbMasterIdx = 1, iDbStandbyIdx = [undef], oDbMaster = [object], oDbStandby = [undef]
P00 DEBUG: Db->info(): strDbPath = <[TEST_PATH]/db-master/db/base>
P00 DEBUG: Db->info=>: iDbCatalogVersion = 201409291, iDbControlVersion = 942, strDbVersion = 9.4, ullDbSysId = 1000000000000000094
P00 DEBUG: Archive::Info->new(): bIgnoreMissing = <false>, bLoad = <true>, bRequired = true, strArchiveClusterPath = [TEST_PATH]/db-master/repo/archive/db, strCipherPassSub = [undef]
P00 DEBUG: Storage::Posix::Driver->new(): bFileSync = <true>, bPathSync = <true>
P00 DEBUG: Storage::Local->new(): bAllowTemp = <true>, hRule = [undef], lBufferMax = 4194304, oDriver = [object], strCipherPassUser = [undef], strCipherType = [undef], strDefaultFileMode = <0640>, strDefaultPathMode = <0750>, strPathBase = /, strTempExtension = pgbackrest.tmp
P00 DEBUG: Storage::Local->encrypted(): bIgnoreMissing = true, strFileName = [TEST_PATH]/db-master/repo/archive/db/archive.info
P00 DEBUG: Storage::Local->encrypted=>: bEncrypted = true
P00 DEBUG: Storage::Local->encryptionValid(): bEncrypted = true
P00 DEBUG: Storage::Local->encryptionValid=>: bValid = true
P00 DEBUG: Storage::Local->openRead(): bIgnoreMissing = true, rhyFilter = [undef], strCipherPass = <redacted>, xFileExp = [TEST_PATH]/db-master/repo/archive/db/archive.info
P00 DEBUG: Storage::Base->get(): strCipherPass = [undef], xFile = [object]
P00 DEBUG: Archive::Info->archiveIdList(): strDbVersion = 9.4, ullDbSysId = 1000000000000000094
P00 DEBUG: Archive::Info->dbHistoryList=>: hDbHash = [hash]
P00 DEBUG: Archive::Info->archiveIdList=>: stryArchiveId = (9.4-1)
P00 DEBUG: Archive::Common::walSegmentFind(): iWaitSeconds = [undef], oStorageRepo = [object], strArchiveId = 9.4-1, strWalSegment = 700000007000000070000000
P00 DEBUG: Storage::Local->list(): bIgnoreMissing = true, strExpression = ^700000007000000070000000-[0-f]{40}(\.gz){0,1}$, strPathExp = <REPO:ARCHIVE>/9.4-1/7000000070000000, strSortOrder = <forward>
P00 DEBUG: Storage::Local->list=>: stryFileList = ()
P00 DEBUG: Archive::Common::walSegmentFind=>: strWalFileName = [undef]
P00 DEBUG: Archive::Get::File::archiveGetCheck=>: strArchiveFile = [undef], strArchiveId = 9.4-1, strCipherPass = <redacted>
P00 DEBUG: Archive::Get::File::archiveGetFile=>: iResult = 1
P00 INFO: unable to find 700000007000000070000000 in the archive
P00 DEBUG: perl/exec::perlExec: => 1
P00 DEBUG: command/archive/get/get::cmdArchiveGet: => 1
P00 DEBUG: common/exit::exitSafe: (result: 1, error: false, signalType: 0)
P00 DEBUG: common/lock::lockRelease: (failOnNoLock: false)
P00 DEBUG: common/lock::lockRelease: => false
P00 DEBUG: Main::mainCleanup(): iExitCode = 1
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: => 1
P00 DEBUG: main::main: => 1
> [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
------------------------------------------------------------------------------------------------------------------------------------
P00 INFO: archive-get command begin [BACKREST-VERSION]: [000000010000000100000001, [TEST_PATH]/db-master/db/base/pg_xlog/RECOVERYXLOG] --no-compress --compress-level=3 --config=[TEST_PATH]/db-master/pgbackrest.conf --db-timeout=45 --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 --log-subprocess --no-log-timestamp --pg1-path=[TEST_PATH]/db-master/db/base --protocol-timeout=60 --repo1-cipher-pass=<redacted> --repo1-cipher-type=aes-256-cbc --repo1-path=[TEST_PATH]/db-master/repo --stanza=db

View File

@ -102,6 +102,48 @@ P00 INFO: archive-push command end: completed successfully
P00 DEBUG: common/exit::exitSafe: => 0
P00 DEBUG: main::main: => 0
> [CONTAINER-EXEC] db-master [BACKREST-BIN] --config=[TEST_PATH]/db-master/pgbackrest.conf --stanza=db archive-get --log-level-console=debug 700000007000000070000000 [TEST_PATH]/db-master/db/base/pg_xlog/RECOVERYXLOG
------------------------------------------------------------------------------------------------------------------------------------
P00 INFO: archive-get command begin [BACKREST-VERSION]: [700000007000000070000000, [TEST_PATH]/db-master/db/base/pg_xlog/RECOVERYXLOG] --no-compress --compress-level=3 --compress-level-network=1 --config=[TEST_PATH]/db-master/pgbackrest.conf --db-timeout=45 --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 --log-subprocess --no-log-timestamp --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-1] --stanza=db
P00 DEBUG: config/load::cfgLoad: => void
P00 DEBUG: command/archive/get/get::cmdArchiveGet: (void)
P00 DEBUG: perl/exec::perlExec: (void)
P00 DEBUG: Archive::Get::Get->process(): rstryCommandArg = (700000007000000070000000, [TEST_PATH]/db-master/db/base/pg_xlog/RECOVERYXLOG)
P00 DEBUG: Archive::Get::File::archiveGetFile(): bAtomic = false, strDestinationFile = [TEST_PATH]/db-master/db/base/pg_xlog/RECOVERYXLOG, strSourceArchive = 700000007000000070000000
P00 DEBUG: Common::Lock::lockStopTest(): bStanzaStopRequired = <false>
P00 DEBUG: Common::Lock::lockStopTest=>: bStopExists = false
P00 DEBUG: Protocol::Helper::protocolGet(): bCache = <true>, iProcessIdx = [undef], iRemoteIdx = <1>, strBackRestBin = [undef], strCommand = <archive-get>, strRemoteType = backup
P00 DEBUG: Protocol::Helper::protocolGet: create (cached) remote protocol
P00 DEBUG: Protocol::Helper::protocolParam(): iProcessIdx = [undef], iRemoteIdx = 1, strBackRestBin = [undef], strCommand = archive-get, strRemoteType = backup
P00 DEBUG: Protocol::Helper::protocolParam=>: strRemoteCommand = [BACKREST-BIN] --buffer-size=4194304 --command=archive-get --compress-level=3 --compress-level-network=1 --config=[TEST_PATH]/backup/pgbackrest.conf --db-timeout=45 --log-level-file=trace --log-subprocess --pg1-path=[TEST_PATH]/db-master/db/base --process=0 --protocol-timeout=60 --stanza=db --type=backup remote, strRemoteHost = backup, strRemoteHostSshPort = [undef], strRemoteHostUser = [USER-1]
P00 DEBUG: Protocol::Remote::Master->new(): iBufferMax = 4194304, iCompressLevel = 3, iCompressLevelNetwork = 1, iProtocolTimeout = 60, iSshPort = [undef], strCommand = [BACKREST-BIN] --buffer-size=4194304 --command=archive-get --compress-level=3 --compress-level-network=1 --config=[TEST_PATH]/backup/pgbackrest.conf --db-timeout=45 --log-level-file=trace --log-subprocess --pg1-path=[TEST_PATH]/db-master/db/base --process=0 --protocol-timeout=60 --stanza=db --type=backup remote, strCommandSSH = ssh, strHost = backup, strUser = [USER-1]
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 pgbackrest@backup '[BACKREST-BIN] --buffer-size=4194304 --command=archive-get --compress-level=3 --compress-level-network=1 --config=[TEST_PATH]/backup/pgbackrest.conf --db-timeout=45 --log-level-file=trace --log-subprocess --pg1-path=[TEST_PATH]/db-master/db/base --process=0 --protocol-timeout=60 --stanza=db --type=backup remote', strId = remote process on 'backup', strName = remote
P00 DEBUG: Protocol::Storage::Remote->new(): oProtocol = [object]
P00 DEBUG: Archive::Get::File::archiveGetCheck(): bCheck = false, strDbVersion = [undef], strFile = 700000007000000070000000, ullDbSysId = [undef]
P00 DEBUG: Db::dbObjectGet(): bMasterOnly = true
P00 DEBUG: Db->new(): iRemoteIdx = 1
P00 DEBUG: Db::dbObjectGet=>: iDbMasterIdx = 1, iDbStandbyIdx = [undef], oDbMaster = [object], oDbStandby = [undef]
P00 DEBUG: Db->info(): strDbPath = <[TEST_PATH]/db-master/db/base>
P00 DEBUG: Db->info=>: iDbCatalogVersion = 201409291, iDbControlVersion = 942, strDbVersion = 9.4, ullDbSysId = 1000000000000000094
P00 DEBUG: Protocol::Helper::protocolGet(): bCache = <true>, iProcessIdx = [undef], iRemoteIdx = <1>, strBackRestBin = [undef], strCommand = <archive-get>, strRemoteType = backup
P00 DEBUG: Protocol::Helper::protocolGet: found cached protocol
P00 DEBUG: Archive::Get::File::archiveGetCheck=>: strArchiveFile = [undef], strArchiveId = 9.4-1, strCipherPass = [undef]
P00 DEBUG: Archive::Get::File::archiveGetFile=>: iResult = 1
P00 INFO: unable to find 700000007000000070000000 in the archive
P00 DEBUG: perl/exec::perlExec: => 1
P00 DEBUG: command/archive/get/get::cmdArchiveGet: => 1
P00 DEBUG: common/exit::exitSafe: (result: 1, error: false, signalType: 0)
P00 DEBUG: common/lock::lockRelease: (failOnNoLock: false)
P00 DEBUG: common/lock::lockRelease: => false
P00 DEBUG: Main::mainCleanup(): iExitCode = 1
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: => 1
P00 DEBUG: main::main: => 1
> [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
------------------------------------------------------------------------------------------------------------------------------------
P00 INFO: archive-get command begin [BACKREST-VERSION]: [000000010000000100000001, [TEST_PATH]/db-master/db/base/pg_xlog/RECOVERYXLOG] --no-compress --compress-level=3 --compress-level-network=1 --config=[TEST_PATH]/db-master/pgbackrest.conf --db-timeout=45 --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 --log-subprocess --no-log-timestamp --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-1] --stanza=db

View File

@ -56,6 +56,9 @@ db-version="9.4"
> [CONTAINER-EXEC] db-master [BACKREST-BIN] --config=[TEST_PATH]/db-master/pgbackrest.conf --stanza=db archive-push --cmd-ssh=/usr/bin/ssh --log-level-console=warn [TEST_PATH]/db-master/db/base/pg_xlog/000000010000000100000001
------------------------------------------------------------------------------------------------------------------------------------
> [CONTAINER-EXEC] db-master [BACKREST-BIN] --config=[TEST_PATH]/db-master/pgbackrest.conf --stanza=db archive-get --log-level-console=warn 700000007000000070000000 [TEST_PATH]/db-master/db/base/pg_xlog/RECOVERYXLOG
------------------------------------------------------------------------------------------------------------------------------------
> [CONTAINER-EXEC] db-master [BACKREST-BIN] --config=[TEST_PATH]/db-master/pgbackrest.conf --stanza=db archive-get --log-level-console=warn 000000010000000100000001 [TEST_PATH]/db-master/db/base/pg_xlog/RECOVERYXLOG
------------------------------------------------------------------------------------------------------------------------------------

View File

@ -162,6 +162,13 @@ sub run
# Remove WAL
storageTest()->remove("${strWalPath}/${strSourceFile}", {bIgnoreMissing => false});
#---------------------------------------------------------------------------------------------------------------------------
&log(INFO, ' get missing WAL');
$oHostDbMaster->executeSimple(
$strCommandGet . " ${strLogDebug} 700000007000000070000000 ${strWalPath}/RECOVERYXLOG",
{iExpectedExitStatus => 1, oLogTest => $self->expect()});
#---------------------------------------------------------------------------------------------------------------------------
&log(INFO, ' get first WAL');

View File

@ -55,6 +55,9 @@ testRun(void)
TEST_RESULT_INT(exitSafe(0, false, signalTypeNone), 0, "exit with no error")
harnessLogResult("P00 INFO: archive-push command end: completed successfully");
TEST_RESULT_INT(exitSafe(1, false, signalTypeNone), 1, "exit with no error")
harnessLogResult("P00 INFO: archive-push command end: completed successfully");
// -------------------------------------------------------------------------------------------------------------------------
TRY_BEGIN()
{