diff --git a/doc/xml/release.xml b/doc/xml/release.xml index f6e77c3ef..542511b81 100644 --- a/doc/xml/release.xml +++ b/doc/xml/release.xml @@ -32,6 +32,23 @@ + + + + + + + + + + + + + +

Make backup size logging exactly match info command output.

+ + + @@ -10701,6 +10718,11 @@ mhagander + + Mahomed + mahomedh + + Oscar MannerMan diff --git a/src/command/backup/backup.c b/src/command/backup/backup.c index 226a6d921..62b32f123 100644 --- a/src/command/backup/backup.c +++ b/src/command/backup/backup.c @@ -1116,10 +1116,10 @@ backupJobResultPageChecksum(PackRead *const checksumPageResult) /*********************************************************************************************************************************** Log the results of a job and throw errors ***********************************************************************************************************************************/ -static uint64_t +static void backupJobResult( Manifest *manifest, const String *host, const String *const fileName, StringList *fileRemove, ProtocolParallelJob *const job, - const uint64_t sizeTotal, uint64_t sizeCopied) + const uint64_t sizeTotal, uint64_t *sizeProgress, uint64_t *sizeCopied) { FUNCTION_LOG_BEGIN(logLevelDebug); FUNCTION_LOG_PARAM(MANIFEST, manifest); @@ -1128,7 +1128,8 @@ backupJobResult( FUNCTION_LOG_PARAM(STRING_LIST, fileRemove); FUNCTION_LOG_PARAM(PROTOCOL_PARALLEL_JOB, job); FUNCTION_LOG_PARAM(UINT64, sizeTotal); - FUNCTION_LOG_PARAM(UINT64, sizeCopied); + FUNCTION_LOG_PARAM_P(UINT64, sizeProgress); + FUNCTION_LOG_PARAM_P(UINT64, sizeCopied); FUNCTION_LOG_END(); ASSERT(manifest != NULL); @@ -1152,7 +1153,7 @@ backupJobResult( PackRead *const checksumPageResult = pckReadPackReadP(jobResult); // Increment backup copy progress - sizeCopied += copySize; + *sizeProgress += copySize; // Create log file name const String *fileLog = host == NULL ? fileName : strNewFmt("%s:%s", strZ(host), strZ(fileName)); @@ -1160,7 +1161,7 @@ backupJobResult( // Format log strings const String *const logProgress = strNewFmt( - "%s, %" PRIu64 "%%", strZ(strSizeFormat(copySize)), sizeTotal == 0 ? 100 : sizeCopied * 100 / sizeTotal); + "%s, %" PRIu64 "%%", strZ(strSizeFormat(copySize)), sizeTotal == 0 ? 100 : *sizeProgress * 100 / sizeTotal); const String *const logChecksum = copySize != 0 ? strNewFmt(" checksum %s", strZ(copyChecksum)) : EMPTY_STR; // If the file is in a prior backup and nothing changed, just log it @@ -1172,6 +1173,9 @@ backupJobResult( // Else if the repo matched the expect checksum, just log it else if (copyResult == backupCopyResultChecksum) { + // Increment size to account for checksum resumed file + *sizeCopied += copySize; + LOG_DETAIL_PID_FMT( processId, "checksum resumed file %s (%s)%s", strZ(fileLog), strZ(logProgress), strZ(logChecksum)); } @@ -1186,6 +1190,9 @@ backupJobResult( // Else file was copied so update manifest else { + // Increment size of files copied + *sizeCopied += copySize; + // If the file had to be recopied then warn that there may be an issue with corruption in the repository // ??? This should really be below the message below for more context -- can be moved after the migration // ??? The name should be a pg path not manifest name -- can be fixed after the migration @@ -1289,7 +1296,7 @@ backupJobResult( else THROW_CODE(protocolParallelJobErrorCode(job), strZ(protocolParallelJobErrorMessage(job))); - FUNCTION_LOG_RETURN(UINT64, sizeCopied); + FUNCTION_LOG_RETURN_VOID(); } /*********************************************************************************************************************************** @@ -1598,6 +1605,7 @@ backupProcess(BackupData *backupData, Manifest *manifest, const String *lsnStart ASSERT(manifest != NULL); uint64_t sizeTotal = 0; + uint64_t sizeCopied = 0; MEM_CONTEXT_TEMP_BEGIN() { @@ -1688,7 +1696,7 @@ backupProcess(BackupData *backupData, Manifest *manifest, const String *lsnStart manifestSaveSize = cfgOptionUInt64(cfgOptManifestSaveThreshold); // Process jobs - uint64_t sizeCopied = 0; + uint64_t sizeProgress = 0; MEM_CONTEXT_TEMP_RESET_BEGIN() { @@ -1700,23 +1708,23 @@ backupProcess(BackupData *backupData, Manifest *manifest, const String *lsnStart { ProtocolParallelJob *job = protocolParallelResult(parallelExec); - sizeCopied = backupJobResult( + backupJobResult( manifest, backupStandby && protocolParallelJobProcessId(job) > 1 ? backupData->hostStandby : backupData->hostPrimary, storagePathP( protocolParallelJobProcessId(job) > 1 ? storagePgIdx(pgIdx) : backupData->storagePrimary, manifestPathPg(manifestFileFind(manifest, varStr(protocolParallelJobKey(job)))->name)), - fileRemove, job, sizeTotal, sizeCopied); + fileRemove, job, sizeTotal, &sizeProgress, &sizeCopied); } // A keep-alive is required here for the remote holding open the backup connection protocolKeepAlive(); // Save the manifest periodically to preserve checksums for resume - if (sizeCopied - manifestSaveLast >= manifestSaveSize) + if (sizeProgress - manifestSaveLast >= manifestSaveSize) { backupManifestSaveCopy(manifest, cipherPassBackup); - manifestSaveLast = sizeCopied; + manifestSaveLast = sizeProgress; } // Reset the memory context occasionally so we don't use too much memory or slow down processing @@ -1784,7 +1792,7 @@ backupProcess(BackupData *backupData, Manifest *manifest, const String *lsnStart } MEM_CONTEXT_TEMP_END(); - FUNCTION_LOG_RETURN(UINT64, sizeTotal); + FUNCTION_LOG_RETURN(UINT64, sizeCopied); } /*********************************************************************************************************************************** diff --git a/test/expect/mock-all-001.log b/test/expect/mock-all-001.log index 9fcf742a6..2ad1f7da7 100644 --- a/test/expect/mock-all-001.log +++ b/test/expect/mock-all-001.log @@ -1006,7 +1006,7 @@ P00 DETAIL: reference pg_data/postgresql.conf to [BACKUP-FULL-2] P00 DETAIL: reference pg_data/special-!_.*'()&!@;:+,? to [BACKUP-FULL-2] P00 DETAIL: reference pg_data/zero_from_start to [BACKUP-FULL-2] P00 INFO: new backup label = [BACKUP-INCR-2] -P00 INFO: incr backup size = 192KB, file total = 22 +P00 INFO: incr backup size = 41B, file total = 22 P00 INFO: backup command end: completed successfully P00 INFO: expire command begin [BACKREST-VERSION]: --buffer-size=[BUFFER-SIZE] --config=[TEST_PATH]/db-primary/pgbackrest.conf --exec-id=[EXEC-ID] --lock-path=[TEST_PATH]/db-primary/lock --log-level-console=detail --log-level-file=[LOG-LEVEL-FILE] --log-level-stderr=off --log-path=[TEST_PATH]/db-primary/log --no-log-timestamp --repo1-path=[TEST_PATH]/db-primary/repo --stanza=db P00 INFO: option 'repo1-retention-archive' is not set - archive logs will not be expired @@ -1224,7 +1224,7 @@ P00 DETAIL: reference pg_data/postgresql.conf to [BACKUP-FULL-2] P00 DETAIL: reference pg_data/special-!_.*'()&!@;:+,? to [BACKUP-FULL-2] P00 DETAIL: reference pg_data/zero_from_start to [BACKUP-FULL-2] P00 INFO: new backup label = [BACKUP-DIFF-1] -P00 INFO: diff backup size = 192KB, file total = 21 +P00 INFO: diff backup size = 32B, file total = 21 P00 INFO: backup command end: completed successfully P00 INFO: expire command begin [BACKREST-VERSION]: --buffer-size=[BUFFER-SIZE] --config=[TEST_PATH]/db-primary/pgbackrest.conf --exec-id=[EXEC-ID] --lock-path=[TEST_PATH]/db-primary/lock --log-level-console=detail --log-level-file=[LOG-LEVEL-FILE] --log-level-stderr=off --log-path=[TEST_PATH]/db-primary/log --no-log-timestamp --repo1-path=[TEST_PATH]/db-primary/repo --stanza=db P00 INFO: option 'repo1-retention-archive' is not set - archive logs will not be expired @@ -1800,7 +1800,7 @@ P00 DETAIL: reference pg_data/zerosize.txt to [BACKUP-DIFF-1] P00 DETAIL: reference pg_tblspc/2/[TS_PATH-1]/32768/tablespace2.txt to [BACKUP-DIFF-1] P00 DETAIL: reference pg_tblspc/2/[TS_PATH-1]/32768/tablespace2b.txt to [BACKUP-INCR-3] P00 INFO: new backup label = [BACKUP-INCR-4] -P00 INFO: incr backup size = 176KB, file total = 22 +P00 INFO: incr backup size = 8B, file total = 22 P00 INFO: backup command end: completed successfully P00 INFO: expire command begin [BACKREST-VERSION]: --buffer-size=[BUFFER-SIZE] --config=[TEST_PATH]/db-primary/pgbackrest.conf --exec-id=[EXEC-ID] --lock-path=[TEST_PATH]/db-primary/lock --log-level-console=detail --log-level-file=[LOG-LEVEL-FILE] --log-level-stderr=off --log-path=[TEST_PATH]/db-primary/log --no-log-timestamp --repo1-path=[TEST_PATH]/db-primary/repo --stanza=db P00 INFO: option 'repo1-retention-archive' is not set - archive logs will not be expired @@ -2017,7 +2017,7 @@ P00 DETAIL: reference pg_data/postgresql.conf to [BACKUP-FULL-2] P00 DETAIL: reference pg_data/special-!_.*'()&!@;:+,? to [BACKUP-FULL-2] P00 DETAIL: reference pg_data/zero_from_start to [BACKUP-FULL-2] P00 INFO: new backup label = [BACKUP-DIFF-2] -P00 INFO: diff backup size = 176KB, file total = 22 +P00 INFO: diff backup size = 46B, file total = 22 P00 INFO: backup command end: completed successfully P00 INFO: expire command begin [BACKREST-VERSION]: --buffer-size=[BUFFER-SIZE] --config=[TEST_PATH]/db-primary/pgbackrest.conf --exec-id=[EXEC-ID] --lock-path=[TEST_PATH]/db-primary/lock --log-level-console=detail --log-level-file=[LOG-LEVEL-FILE] --log-level-stderr=off --log-path=[TEST_PATH]/db-primary/log --no-log-timestamp --repo1-path=[TEST_PATH]/db-primary/repo --stanza=db P00 INFO: option 'repo1-retention-archive' is not set - archive logs will not be expired @@ -2234,7 +2234,7 @@ P00 DETAIL: reference pg_data/postgresql.conf to [BACKUP-FULL-2] P00 DETAIL: reference pg_data/special-!_.*'()&!@;:+,? to [BACKUP-FULL-2] P00 DETAIL: reference pg_data/zero_from_start to [BACKUP-FULL-2] P00 INFO: new backup label = [BACKUP-DIFF-3] -P00 INFO: diff backup size = 176KB, file total = 20 +P00 INFO: diff backup size = 37B, file total = 20 P00 INFO: backup command end: completed successfully P00 INFO: expire command begin [BACKREST-VERSION]: --buffer-size=[BUFFER-SIZE] --config=[TEST_PATH]/db-primary/pgbackrest.conf --exec-id=[EXEC-ID] --lock-path=[TEST_PATH]/db-primary/lock --log-level-console=detail --log-level-file=[LOG-LEVEL-FILE] --log-level-stderr=off --log-path=[TEST_PATH]/db-primary/log --no-log-timestamp --repo1-path=[TEST_PATH]/db-primary/repo --stanza=db P00 INFO: option 'repo1-retention-archive' is not set - archive logs will not be expired diff --git a/test/src/module/command/backupTest.c b/test/src/module/command/backupTest.c index 019847681..b3a63a12b 100644 --- a/test/src/module/command/backupTest.c +++ b/test/src/module/command/backupTest.c @@ -1325,7 +1325,7 @@ testRun(void) ProtocolParallelJob *job = protocolParallelJobNew(VARSTRDEF("key"), protocolCommandNew(strIdFromZ("x"))); protocolParallelJobErrorSet(job, errorTypeCode(&AssertError), STRDEF("error message")); - TEST_ERROR(backupJobResult((Manifest *)1, NULL, STRDEF("log"), strLstNew(), job, 0, 0), AssertError, "error message"); + TEST_ERROR(backupJobResult((Manifest *)1, NULL, STRDEF("log"), strLstNew(), job, 0, NULL, NULL), AssertError, "error message"); // ------------------------------------------------------------------------------------------------------------------------- TEST_TITLE("report host/100% progress on noop result"); @@ -1353,8 +1353,11 @@ testRun(void) } OBJ_NEW_END(); - TEST_RESULT_UINT( - backupJobResult(manifest, STRDEF("host"), STRDEF("log-test"), strLstNew(), job, 0, 0), 0, "log noop result"); + uint64_t sizeProgress = 0; + uint64_t sizeCopied = 0; + + TEST_RESULT_VOID( + backupJobResult(manifest, STRDEF("host"), STRDEF("log-test"), strLstNew(), job, 0, &sizeProgress, &sizeCopied), "log noop result"); TEST_RESULT_LOG("P00 DETAIL: match file from prior backup host:log-test (0B, 100%)"); }