From 59d7958914d2965d0690ebd579541c21a40ad201 Mon Sep 17 00:00:00 2001 From: David Steele Date: Sat, 23 Feb 2019 15:05:06 +0200 Subject: [PATCH] Reduce expect log level in mock/archive tests. The expect tests were originally a rough-and-ready type of unit test so monitoring changes in the expect log helped us detect changes in behavior. Now the archive code is heavily unit-tested so the detailed logs mainly cause churn and don't have any measurable benefit. Reduce the log level to DETAIL to make the logs less verbose and volatile, yet still check user-facing log messages. --- doc/xml/release.xml | 4 + test/expect/mock-archive-001.log | 143 +--------------- test/expect/mock-archive-002.log | 155 +----------------- .../Module/Mock/MockArchiveTest.pm | 11 +- 4 files changed, 22 insertions(+), 291 deletions(-) diff --git a/doc/xml/release.xml b/doc/xml/release.xml index 0bf1b5789..e07fddf3a 100644 --- a/doc/xml/release.xml +++ b/doc/xml/release.xml @@ -111,6 +111,10 @@ + +

Reduce expect log level in mock/archive tests.

+ +

Disable test-level stack trace by default.

 diff --git a/test/expect/mock-archive-001.log b/test/expect/mock-archive-001.log index dd75470be..92f98ed3e 100644 --- a/test/expect/mock-archive-001.log +++ b/test/expect/mock-archive-001.log @@ -67,154 +67,23 @@ db-version="9.4" [db:history] 1={"db-id":1000000000000000094,"db-version":"9.4"} -> [CONTAINER-EXEC] db-master [BACKREST-BIN] --config=[TEST_PATH]/db-master/pgbackrest.conf --stanza=db archive-push --compress --log-level-console=debug [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-push --compress [TEST_PATH]/db-master/db/base/pg_xlog/000000010000000100000001 ------------------------------------------------------------------------------------------------------------------------------------ -P00 INFO: archive-push command begin [BACKREST-VERSION]: [[TEST_PATH]/db-master/db/base/pg_xlog/000000010000000100000001] --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= --repo1-cipher-type=aes-256-cbc --repo1-path=[TEST_PATH]/db-master/repo --stanza=db -P00 DEBUG: config/load::cfgLoad: => void -P00 DEBUG: perl/exec::perlExec: (void) -P00 DEBUG: Archive::Push::Push->process(): strWalPathFile = [TEST_PATH]/db-master/db/base/pg_xlog/000000010000000100000001 -P00 DEBUG: Common::Lock::lockStopTest(): bStanzaStopRequired = -P00 DEBUG: Common::Lock::lockStopTest=>: bStopExists = false -P00 DEBUG: Archive::Push::File::archivePushFile(): bCompress = true, iCompressLevel = 3, strWalFile = 000000010000000100000001, strWalPath = [TEST_PATH]/db-master/db/base/pg_xlog -P00 DEBUG: Storage::Posix::Driver->new(): bFileSync = , bPathSync = -P00 DEBUG: Storage::Local->new(): bAllowTemp = , hRule = [hash], lBufferMax = 4194304, oDriver = [object], strCipherPassUser = , strCipherType = aes-256-cbc, strDefaultFileMode = <0640>, strDefaultPathMode = <0750>, strPathBase = [TEST_PATH]/db-master/repo, strTempExtension = pgbackrest.tmp -P00 DEBUG: Archive::Common::walInfo(): strWalFile = [TEST_PATH]/db-master/db/base/pg_xlog/000000010000000100000001 -P00 DEBUG: Archive::Common::walInfo=>: strDbVersion = 9.4, ullDbSysId = 1000000000000000094 -P00 DEBUG: Archive::Push::File::archivePushCheck(): strArchiveFile = 000000010000000100000001, strDbVersion = 9.4, strWalFile = [TEST_PATH]/db-master/db/base/pg_xlog/000000010000000100000001, ullDbSysId = 1000000000000000094 -P00 DEBUG: Archive::Info->new(): bIgnoreMissing = , bLoad = , bRequired = , strArchiveClusterPath = [TEST_PATH]/db-master/repo/archive/db, strCipherPassSub = [undef] -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->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 = , xFileExp = [TEST_PATH]/db-master/repo/archive/db/archive.info -P00 DEBUG: Storage::Base->get(): strCipherPass = [undef], xFile = [object] -P00 DEBUG: Archive::Info->check(): bRequired = , strDbVersion = 9.4, ullDbSysId = 1000000000000000094 -P00 DEBUG: Archive::Info->archiveId(): strDbVersion = [undef], ullDbSysId = [undef] -P00 DEBUG: Archive::Info->archiveId=>: strArchiveId = 9.4-1 -P00 DEBUG: Archive::Info->check=>: strArchiveId = 9.4-1 -P00 DEBUG: Archive::Common::walSegmentFind(): iWaitSeconds = [undef], oStorageRepo = [object], strArchiveId = 9.4-1, strWalSegment = 000000010000000100000001 -P00 DEBUG: Storage::Local->list(): bIgnoreMissing = true, strExpression = ^000000010000000100000001-[0-f]{40}(\.gz){0,1}$, strPathExp = /9.4-1/0000000100000001, strSortOrder = -P00 DEBUG: Storage::Local->list=>: stryFileList = () -P00 DEBUG: Archive::Common::walSegmentFind=>: strWalFileName = [undef] -P00 DEBUG: Archive::Push::File::archivePushCheck=>: strArchiveId = 9.4-1, strChecksum = [undef], strCipherPass = , strWarning = [undef] -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 = [TEST_PATH]/db-master/db/base, strTempExtension = pgbackrest.tmp -P00 DEBUG: Storage::Local->hashSize(): bIgnoreMissing = , xFileExp = [TEST_PATH]/db-master/db/base/pg_xlog/000000010000000100000001 -P00 DEBUG: Storage::Local->openRead(): bIgnoreMissing = false, rhyFilter = [undef], strCipherPass = [undef], xFileExp = [TEST_PATH]/db-master/db/base/pg_xlog/000000010000000100000001 -P00 DEBUG: Storage::Local->hashSize=>: lSize = 16777216, strHash = ceb021d9bb41f220511e413b095d2b0d89fec113 -P00 DEBUG: Storage::Local->openRead(): bIgnoreMissing = , rhyFilter = ({rxyParam => ({iLevel => 3}), strClass => pgBackRest::Storage::Filter::Gzip}), strCipherPass = [undef], xFileExp = [TEST_PATH]/db-master/db/base/pg_xlog/000000010000000100000001 -P00 DEBUG: Storage::Local->openWrite(): bAtomic = true, bPathCreate = true, lTimestamp = [undef], rhyFilter = [undef], strCipherPass = , strGroup = [undef], strMode = <0640>, strUser = [undef], xFileExp = /9.4-1/000000010000000100000001-ceb021d9bb41f220511e413b095d2b0d89fec113.gz -P00 DEBUG: Storage::Base->copy(): xDestinationFile = [object], xSourceFile = [object] -P00 DEBUG: Archive::Push::File::archivePushFile=>: strWarning = [undef] +P00 INFO: archive-push command begin [BACKREST-VERSION]: [[TEST_PATH]/db-master/db/base/pg_xlog/000000010000000100000001] --compress --compress-level=3 --config=[TEST_PATH]/db-master/pgbackrest.conf --db-timeout=45 --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 --log-subprocess --no-log-timestamp --pg1-path=[TEST_PATH]/db-master/db/base --protocol-timeout=60 --repo1-cipher-pass= --repo1-cipher-type=aes-256-cbc --repo1-path=[TEST_PATH]/db-master/repo --stanza=db P00 INFO: pushed WAL segment 000000010000000100000001 -P00 DEBUG: perl/exec::perlExec: => 0 -P00 DEBUG: common/exit::exitSafe: (result: 0, error: false, signalType: 0) -P00 DEBUG: common/lock::lockRelease: (failOnNoLock: false) -P00 DEBUG: common/lock::lockRelease: => false -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: => 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 +> [CONTAINER-EXEC] db-master [BACKREST-BIN] --config=[TEST_PATH]/db-master/pgbackrest.conf --stanza=db archive-get 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= --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: storage/driver/posix/storage::storageDriverPosixNew: (path: {"[TEST_PATH]/db-master/repo"}, modeFile: 0640, modePath: 0750, write: false, pathExpressionFunction: (function *)) -P00 DEBUG: storage/driver/posix/storage::storageDriverPosixNew: => {StorageDriverPosix} -P00 DEBUG: command/archive/get/file::archiveGetFile: (archiveFile: {"700000007000000070000000"}, walDestination: {"[TEST_PATH]/db-master/db/base/pg_xlog/RECOVERYXLOG"}, cipherType: 1) -P00 DEBUG: command/control/control::lockStopTest: (void) -P00 DEBUG: storage/storage::storageExists: (this: {type: posix, path: {"/"}, write: false}, pathExp: {"[TEST_PATH]/db-master/lock/db.stop"}, param.timeout: 0) -P00 DEBUG: storage/storage::storageExists: => false -P00 DEBUG: storage/storage::storageExists: (this: {type: posix, path: {"/"}, write: false}, pathExp: {"[TEST_PATH]/db-master/lock/all.stop"}, param.timeout: 0) -P00 DEBUG: storage/storage::storageExists: => false -P00 DEBUG: command/control/control::lockStopTest: => void -P00 DEBUG: command/archive/get/file::archiveGetCheck: (archiveFile: {"700000007000000070000000"}, cipherType: 1) -P00 DEBUG: postgres/interface::pgControlFromFile: (pgPath: {"[TEST_PATH]/db-master/db/base"}) -P00 DEBUG: storage/storage::storageNewRead: (this: {type: posix, path: {"/"}, write: false}, fileExp: {"[TEST_PATH]/db-master/db/base/global/pg_control"}, param.ignoreMissing: false, param.filterGroup: null) -P00 DEBUG: storage/storage::storageNewRead: => {type: posix, name: {"[TEST_PATH]/db-master/db/base/global/pg_control"}, ignoreMissing: false} -P00 DEBUG: storage/storage::storageGet: (file: {type: posix, name: {"[TEST_PATH]/db-master/db/base/global/pg_control"}, ignoreMissing: false}, param.exactSize: 512) -P00 DEBUG: storage/storage::storageGet: => {used: 512, size: 512, limit: } -P00 DEBUG: postgres/interface::pgControlFromFile: => {version: 90400, systemId: 1000000000000000094, walSegmentSize: 16777216, pageChecksum: true} -P00 DEBUG: info/infoArchive::infoArchiveNew: (storage: {type: posix, path: {"[TEST_PATH]/db-master/repo"}, write: false}, fileName: {"/archive.info"}, ignoreMissing: false, cipherType: 1) -P00 DEBUG: info/infoPg::infoPgNew: (storage: {type: posix, path: {"[TEST_PATH]/db-master/repo"}, write: false}, fileName: {"/archive.info"}, type: 0, cipherType: 1) -P00 DEBUG: info/info::infoNew: (storage: {type: posix, path: {"[TEST_PATH]/db-master/repo"}, write: false}, fileName: {"/archive.info"}, cipherType: 1) -P00 DEBUG: info/info::infoNew: => {Info} -P00 DEBUG: info/infoPg::infoPgNew: => {InfoPg} -P00 DEBUG: info/infoArchive::infoArchiveNew: => {InfoArchive} -P00 DEBUG: command/archive/common::walSegmentFind: (storage: {type: posix, path: {"[TEST_PATH]/db-master/repo"}, write: false}, archiveId: {"9.4-1"}, walSegment: {"700000007000000070000000"}) -P00 DEBUG: storage/storage::storageList: (this: {type: posix, path: {"[TEST_PATH]/db-master/repo"}, write: false}, pathExp: {"/9.4-1/7000000070000000"}, param.errorOnMissing: false, param.expression: {"^700000007000000070000000-[0-f]{40}(\.gz){0,1}$"}) -P00 DEBUG: storage/storage::storageList: => null -P00 DEBUG: command/archive/common::walSegmentFind: => null -P00 DEBUG: command/archive/get/file::archiveGetCheck: => {ArchiveGetCheckResult} -P00 DEBUG: command/archive/get/file::archiveGetFile: => 1 +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=detail --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= --repo1-cipher-type=aes-256-cbc --repo1-path=[TEST_PATH]/db-master/repo --stanza=db P00 INFO: unable to find 700000007000000070000000 in the archive -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 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 +> [CONTAINER-EXEC] db-master [BACKREST-BIN] --config=[TEST_PATH]/db-master/pgbackrest.conf --stanza=db archive-get 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= --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: storage/driver/posix/storage::storageDriverPosixNew: (path: {"[TEST_PATH]/db-master/repo"}, modeFile: 0640, modePath: 0750, write: false, pathExpressionFunction: (function *)) -P00 DEBUG: storage/driver/posix/storage::storageDriverPosixNew: => {StorageDriverPosix} -P00 DEBUG: command/archive/get/file::archiveGetFile: (archiveFile: {"000000010000000100000001"}, walDestination: {"[TEST_PATH]/db-master/db/base/pg_xlog/RECOVERYXLOG"}, cipherType: 1) -P00 DEBUG: command/control/control::lockStopTest: (void) -P00 DEBUG: storage/storage::storageExists: (this: {type: posix, path: {"/"}, write: false}, pathExp: {"[TEST_PATH]/db-master/lock/db.stop"}, param.timeout: 0) -P00 DEBUG: storage/storage::storageExists: => false -P00 DEBUG: storage/storage::storageExists: (this: {type: posix, path: {"/"}, write: false}, pathExp: {"[TEST_PATH]/db-master/lock/all.stop"}, param.timeout: 0) -P00 DEBUG: storage/storage::storageExists: => false -P00 DEBUG: command/control/control::lockStopTest: => void -P00 DEBUG: command/archive/get/file::archiveGetCheck: (archiveFile: {"000000010000000100000001"}, cipherType: 1) -P00 DEBUG: postgres/interface::pgControlFromFile: (pgPath: {"[TEST_PATH]/db-master/db/base"}) -P00 DEBUG: storage/storage::storageNewRead: (this: {type: posix, path: {"/"}, write: false}, fileExp: {"[TEST_PATH]/db-master/db/base/global/pg_control"}, param.ignoreMissing: false, param.filterGroup: null) -P00 DEBUG: storage/storage::storageNewRead: => {type: posix, name: {"[TEST_PATH]/db-master/db/base/global/pg_control"}, ignoreMissing: false} -P00 DEBUG: storage/storage::storageGet: (file: {type: posix, name: {"[TEST_PATH]/db-master/db/base/global/pg_control"}, ignoreMissing: false}, param.exactSize: 512) -P00 DEBUG: storage/storage::storageGet: => {used: 512, size: 512, limit: } -P00 DEBUG: postgres/interface::pgControlFromFile: => {version: 90400, systemId: 1000000000000000094, walSegmentSize: 16777216, pageChecksum: true} -P00 DEBUG: info/infoArchive::infoArchiveNew: (storage: {type: posix, path: {"[TEST_PATH]/db-master/repo"}, write: false}, fileName: {"/archive.info"}, ignoreMissing: false, cipherType: 1) -P00 DEBUG: info/infoPg::infoPgNew: (storage: {type: posix, path: {"[TEST_PATH]/db-master/repo"}, write: false}, fileName: {"/archive.info"}, type: 0, cipherType: 1) -P00 DEBUG: info/info::infoNew: (storage: {type: posix, path: {"[TEST_PATH]/db-master/repo"}, write: false}, fileName: {"/archive.info"}, cipherType: 1) -P00 DEBUG: info/info::infoNew: => {Info} -P00 DEBUG: info/infoPg::infoPgNew: => {InfoPg} -P00 DEBUG: info/infoArchive::infoArchiveNew: => {InfoArchive} -P00 DEBUG: command/archive/common::walSegmentFind: (storage: {type: posix, path: {"[TEST_PATH]/db-master/repo"}, write: false}, archiveId: {"9.4-1"}, walSegment: {"000000010000000100000001"}) -P00 DEBUG: storage/storage::storageList: (this: {type: posix, path: {"[TEST_PATH]/db-master/repo"}, write: false}, pathExp: {"/9.4-1/0000000100000001"}, param.errorOnMissing: false, param.expression: {"^000000010000000100000001-[0-f]{40}(\.gz){0,1}$"}) -P00 DEBUG: storage/storage::storageList: => {["000000010000000100000001-ceb021d9bb41f220511e413b095d2b0d89fec113.gz"]} -P00 DEBUG: command/archive/common::walSegmentFind: => {"000000010000000100000001-ceb021d9bb41f220511e413b095d2b0d89fec113.gz"} -P00 DEBUG: command/archive/get/file::archiveGetCheck: => {ArchiveGetCheckResult} -P00 DEBUG: storage/driver/posix/storage::storageDriverPosixNew: (path: {"/"}, modeFile: 0640, modePath: 0750, write: true, pathExpressionFunction: null) -P00 DEBUG: storage/driver/posix/storage::storageDriverPosixNew: => {StorageDriverPosix} -P00 DEBUG: storage/storage::storageNewWrite: (this: {type: posix, path: {"/"}, write: true}, fileExp: {"[TEST_PATH]/db-master/db/base/pg_xlog/RECOVERYXLOG"}, param.modeFile: 0000, param.modePath: 0000, param.noCreatePath: true, param.noSyncFile: true, param.noSyncPath: true, param.noAtomic: true, param.filterGroup: null) -P00 DEBUG: storage/storage::storageNewWrite: => {type: posix, name: {"[TEST_PATH]/db-master/db/base/pg_xlog/RECOVERYXLOG"}, modeFile: 0640, modePath: 0750, createPath: false, syncFile: false, syncPath: false, atomic: false} -P00 DEBUG: common/io/filter/group::ioFilterGroupAdd: (this: {inputSame: false, done: true}, filter: {IoFilter}) -P00 DEBUG: common/io/filter/group::ioFilterGroupAdd: => {inputSame: false, done: true} -P00 DEBUG: common/io/filter/group::ioFilterGroupAdd: (this: {inputSame: false, done: true}, filter: {IoFilter}) -P00 DEBUG: common/io/filter/group::ioFilterGroupAdd: => {inputSame: false, done: true} -P00 DEBUG: storage/storage::storageNewRead: (this: {type: posix, path: {"[TEST_PATH]/db-master/repo"}, write: false}, fileExp: {"/9.4-1/0000000100000001/000000010000000100000001-ceb021d9bb41f220511e413b095d2b0d89fec113.gz"}, param.ignoreMissing: false, param.filterGroup: null) -P00 DEBUG: storage/storage::storageNewRead: => {type: posix, name: {"[TEST_PATH]/db-master/repo/archive/db/9.4-1/0000000100000001/000000010000000100000001-ceb021d9bb41f220511e413b095d2b0d89fec113.gz"}, ignoreMissing: false} -P00 DEBUG: storage/storage::storageCopy: (source: {type: posix, name: {"[TEST_PATH]/db-master/repo/archive/db/9.4-1/0000000100000001/000000010000000100000001-ceb021d9bb41f220511e413b095d2b0d89fec113.gz"}, ignoreMissing: false}, destination: {type: posix, name: {"[TEST_PATH]/db-master/db/base/pg_xlog/RECOVERYXLOG"}, modeFile: 0640, modePath: 0750, createPath: false, syncFile: false, syncPath: false, atomic: false}) -P00 DEBUG: storage/storage::storageCopy: => true -P00 DEBUG: command/archive/get/file::archiveGetFile: => 0 +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=detail --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= --repo1-cipher-type=aes-256-cbc --repo1-path=[TEST_PATH]/db-master/repo --stanza=db P00 INFO: found 000000010000000100000001 in the archive -P00 DEBUG: command/archive/get/get::cmdArchiveGet: => 0 -P00 DEBUG: common/exit::exitSafe: (result: 0, error: false, signalType: 0) -P00 DEBUG: common/lock::lockRelease: (failOnNoLock: false) -P00 DEBUG: common/lock::lockRelease: => false P00 INFO: archive-get 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-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 b31b74a30..450c36e0c 100644 --- a/test/expect/mock-archive-002.log +++ b/test/expect/mock-archive-002.log @@ -60,166 +60,23 @@ db-version="9.4" [db:history] 1={"db-id":1000000000000000094,"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 --compress --log-level-console=debug [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-push --cmd-ssh=/usr/bin/ssh --compress [TEST_PATH]/db-master/db/base/pg_xlog/000000010000000100000001 ------------------------------------------------------------------------------------------------------------------------------------ -P00 INFO: archive-push command begin [BACKREST-VERSION]: [[TEST_PATH]/db-master/db/base/pg_xlog/000000010000000100000001] --cmd-ssh=/usr/bin/ssh --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: perl/exec::perlExec: (void) -P00 DEBUG: Archive::Push::Push->process(): strWalPathFile = [TEST_PATH]/db-master/db/base/pg_xlog/000000010000000100000001 -P00 DEBUG: Common::Lock::lockStopTest(): bStanzaStopRequired = -P00 DEBUG: Common::Lock::lockStopTest=>: bStopExists = false -P00 DEBUG: Archive::Push::File::archivePushFile(): bCompress = true, iCompressLevel = 3, strWalFile = 000000010000000100000001, strWalPath = [TEST_PATH]/db-master/db/base/pg_xlog -P00 DEBUG: Protocol::Helper::protocolGet(): bCache = , iProcessIdx = [undef], iRemoteIdx = <1>, strBackRestBin = [undef], strCommand = , strRemoteType = backup -P00 DEBUG: Protocol::Helper::protocolGet: create (cached) remote protocol -P00 DEBUG: Protocol::Helper::protocolParam(): iProcessIdx = [undef], iRemoteIdx = 1, strBackRestBin = [undef], strCommand = archive-push, strRemoteType = backup -P00 DEBUG: Protocol::Helper::protocolParam=>: strRemoteCommand = [BACKREST-BIN] --buffer-size=4194304 --command=archive-push --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-push --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 = /usr/bin/ssh, strHost = backup, strUser = [USER-1] -P00 DEBUG: Protocol::Command::Master->new(): iBufferMax = 4194304, iCompressLevel = 3, iCompressLevelNetwork = 1, iProtocolTimeout = 60, strCommand = /usr/bin/ssh -o LogLevel=error -o Compression=no -o PasswordAuthentication=no pgbackrest@backup '[BACKREST-BIN] --buffer-size=4194304 --command=archive-push --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::Common::walInfo(): strWalFile = [TEST_PATH]/db-master/db/base/pg_xlog/000000010000000100000001 -P00 DEBUG: Archive::Common::walInfo=>: strDbVersion = 9.4, ullDbSysId = 1000000000000000094 -P00 DEBUG: Archive::Push::File::archivePushCheck(): strArchiveFile = 000000010000000100000001, strDbVersion = 9.4, strWalFile = [TEST_PATH]/db-master/db/base/pg_xlog/000000010000000100000001, ullDbSysId = 1000000000000000094 -P00 DEBUG: Protocol::Helper::protocolGet(): bCache = , iProcessIdx = [undef], iRemoteIdx = <1>, strBackRestBin = [undef], strCommand = , strRemoteType = backup -P00 DEBUG: Protocol::Helper::protocolGet: found cached protocol -P00 DEBUG: Archive::Push::File::archivePushCheck=>: strArchiveId = 9.4-1, strChecksum = [undef], strCipherPass = [undef], strWarning = [undef] -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 = [TEST_PATH]/db-master/db/base, strTempExtension = pgbackrest.tmp -P00 DEBUG: Storage::Local->hashSize(): bIgnoreMissing = , xFileExp = [TEST_PATH]/db-master/db/base/pg_xlog/000000010000000100000001 -P00 DEBUG: Storage::Local->openRead(): bIgnoreMissing = false, rhyFilter = [undef], strCipherPass = [undef], xFileExp = [TEST_PATH]/db-master/db/base/pg_xlog/000000010000000100000001 -P00 DEBUG: Storage::Local->hashSize=>: lSize = 16777216, strHash = ceb021d9bb41f220511e413b095d2b0d89fec113 -P00 DEBUG: Storage::Local->openRead(): bIgnoreMissing = , rhyFilter = ({rxyParam => ({iLevel => 3}), strClass => pgBackRest::Storage::Filter::Gzip}), strCipherPass = [undef], xFileExp = [TEST_PATH]/db-master/db/base/pg_xlog/000000010000000100000001 -P00 DEBUG: Protocol::Storage::Remote->openWrite(): rhParam = [hash], strFileExp = /9.4-1/000000010000000100000001-ceb021d9bb41f220511e413b095d2b0d89fec113.gz -P00 DEBUG: Storage::Base->copy(): xDestinationFile = [object], xSourceFile = [object] -P00 DEBUG: Archive::Push::File::archivePushFile=>: strWarning = [undef] +P00 INFO: archive-push command begin [BACKREST-VERSION]: [[TEST_PATH]/db-master/db/base/pg_xlog/000000010000000100000001] --cmd-ssh=/usr/bin/ssh --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=detail --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 INFO: pushed WAL segment 000000010000000100000001 -P00 DEBUG: perl/exec::perlExec: => 0 -P00 DEBUG: common/exit::exitSafe: (result: 0, error: false, signalType: 0) -P00 DEBUG: common/lock::lockRelease: (failOnNoLock: false) -P00 DEBUG: common/lock::lockRelease: => false -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: => 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 +> [CONTAINER-EXEC] db-master [BACKREST-BIN] --config=[TEST_PATH]/db-master/pgbackrest.conf --stanza=db archive-get 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: storage/driver/remote/storage::storageDriverRemoteNew: (modeFile: 0640, modePath: 0750, write: false, pathExpressionFunction: (function *)) -P00 DEBUG: protocol/helper::protocolGet: (remoteType: 0, remoteId: 1) -P00 DEBUG: protocol/helper::protocolParam: (remoteType: 0, remoteId: 1) -P00 DEBUG: protocol/helper::protocolParam: => {["-o", "LogLevel=error", "-o", "Compression=no", "-o", "PasswordAuthentication=no", "pgbackrest@backup", "[BACKREST-BIN] --command=archive-get --compress-level=3 --compress-level-network=1 --config=[TEST_PATH]/backup/pgbackrest.conf --db-timeout=45 --lock-path=[TEST_PATH]/db-master/lock --log-level-file=trace --log-level-stderr=off --log-path=[TEST_PATH]/db-master/log --log-subprocess --pg1-path=[TEST_PATH]/db-master/db/base --process=0 --protocol-timeout=60 --type=backup remote"]} -P00 DEBUG: common/exec::execNew: (command: {"ssh"}, param: {["-o", "LogLevel=error", "-o", "Compression=no", "-o", "PasswordAuthentication=no", "pgbackrest@backup", "[BACKREST-BIN] --command=archive-get --compress-level=3 --compress-level-network=1 --config=[TEST_PATH]/backup/pgbackrest.conf --db-timeout=45 --lock-path=[TEST_PATH]/db-master/lock --log-level-file=trace --log-level-stderr=off --log-path=[TEST_PATH]/db-master/log --log-subprocess --pg1-path=[TEST_PATH]/db-master/db/base --process=0 --protocol-timeout=60 --type=backup remote"]}, name: {"remote-1 process on 'backup'"}, timeout: 60000) -P00 DEBUG: common/exec::execNew: => {Exec} -P00 DEBUG: common/exec::execOpen: (this: {Exec}) -P00 DEBUG: common/exec::execOpen: => void -P00 DEBUG: protocol/helper::protocolGet: => {name: remote-1 protocol on 'backup'} -P00 DEBUG: storage/driver/remote/storage::storageDriverRemoteNew: => {StorageDriverRemote} -P00 DEBUG: command/archive/get/file::archiveGetFile: (archiveFile: {"700000007000000070000000"}, walDestination: {"[TEST_PATH]/db-master/db/base/pg_xlog/RECOVERYXLOG"}, cipherType: 0) -P00 DEBUG: command/control/control::lockStopTest: (void) -P00 DEBUG: storage/storage::storageExists: (this: {type: posix, path: {"/"}, write: false}, pathExp: {"[TEST_PATH]/db-master/lock/db.stop"}, param.timeout: 0) -P00 DEBUG: storage/storage::storageExists: => false -P00 DEBUG: storage/storage::storageExists: (this: {type: posix, path: {"/"}, write: false}, pathExp: {"[TEST_PATH]/db-master/lock/all.stop"}, param.timeout: 0) -P00 DEBUG: storage/storage::storageExists: => false -P00 DEBUG: command/control/control::lockStopTest: => void -P00 DEBUG: command/archive/get/file::archiveGetCheck: (archiveFile: {"700000007000000070000000"}, cipherType: 0) -P00 DEBUG: postgres/interface::pgControlFromFile: (pgPath: {"[TEST_PATH]/db-master/db/base"}) -P00 DEBUG: storage/storage::storageNewRead: (this: {type: posix, path: {"/"}, write: false}, fileExp: {"[TEST_PATH]/db-master/db/base/global/pg_control"}, param.ignoreMissing: false, param.filterGroup: null) -P00 DEBUG: storage/storage::storageNewRead: => {type: posix, name: {"[TEST_PATH]/db-master/db/base/global/pg_control"}, ignoreMissing: false} -P00 DEBUG: storage/storage::storageGet: (file: {type: posix, name: {"[TEST_PATH]/db-master/db/base/global/pg_control"}, ignoreMissing: false}, param.exactSize: 512) -P00 DEBUG: storage/storage::storageGet: => {used: 512, size: 512, limit: } -P00 DEBUG: postgres/interface::pgControlFromFile: => {version: 90400, systemId: 1000000000000000094, walSegmentSize: 16777216, pageChecksum: true} -P00 DEBUG: info/infoArchive::infoArchiveNew: (storage: {type: remote, path: null, write: false}, fileName: {"/archive.info"}, ignoreMissing: false, cipherType: 0) -P00 DEBUG: info/infoPg::infoPgNew: (storage: {type: remote, path: null, write: false}, fileName: {"/archive.info"}, type: 0, cipherType: 0) -P00 DEBUG: info/info::infoNew: (storage: {type: remote, path: null, write: false}, fileName: {"/archive.info"}, cipherType: 0) -P00 DEBUG: info/info::infoNew: => {Info} -P00 DEBUG: info/infoPg::infoPgNew: => {InfoPg} -P00 DEBUG: info/infoArchive::infoArchiveNew: => {InfoArchive} -P00 DEBUG: command/archive/common::walSegmentFind: (storage: {type: remote, path: null, write: false}, archiveId: {"9.4-1"}, walSegment: {"700000007000000070000000"}) -P00 DEBUG: storage/storage::storageList: (this: {type: remote, path: null, write: false}, pathExp: {"/9.4-1/7000000070000000"}, param.errorOnMissing: false, param.expression: {"^700000007000000070000000-[0-f]{40}(\.gz){0,1}$"}) -P00 DEBUG: storage/driver/remote/storage::storageDriverRemoteList: (this: {StorageDriverRemote}, path: {"archive/db/9.4-1/7000000070000000"}, errorOnMissing: false, expression: {"^700000007000000070000000-[0-f]{40}(\.gz){0,1}$"}) -P00 DEBUG: storage/driver/remote/storage::storageDriverRemoteList: => null -P00 DEBUG: storage/storage::storageList: => null -P00 DEBUG: command/archive/common::walSegmentFind: => null -P00 DEBUG: command/archive/get/file::archiveGetCheck: => {ArchiveGetCheckResult} -P00 DEBUG: command/archive/get/file::archiveGetFile: => 1 +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=detail --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 INFO: unable to find 700000007000000070000000 in the archive -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 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 +> [CONTAINER-EXEC] db-master [BACKREST-BIN] --config=[TEST_PATH]/db-master/pgbackrest.conf --stanza=db archive-get 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 -P00 DEBUG: config/load::cfgLoad: => void -P00 DEBUG: command/archive/get/get::cmdArchiveGet: (void) -P00 DEBUG: storage/driver/remote/storage::storageDriverRemoteNew: (modeFile: 0640, modePath: 0750, write: false, pathExpressionFunction: (function *)) -P00 DEBUG: protocol/helper::protocolGet: (remoteType: 0, remoteId: 1) -P00 DEBUG: protocol/helper::protocolParam: (remoteType: 0, remoteId: 1) -P00 DEBUG: protocol/helper::protocolParam: => {["-o", "LogLevel=error", "-o", "Compression=no", "-o", "PasswordAuthentication=no", "pgbackrest@backup", "[BACKREST-BIN] --command=archive-get --compress-level=3 --compress-level-network=1 --config=[TEST_PATH]/backup/pgbackrest.conf --db-timeout=45 --lock-path=[TEST_PATH]/db-master/lock --log-level-file=trace --log-level-stderr=off --log-path=[TEST_PATH]/db-master/log --log-subprocess --pg1-path=[TEST_PATH]/db-master/db/base --process=0 --protocol-timeout=60 --type=backup remote"]} -P00 DEBUG: common/exec::execNew: (command: {"ssh"}, param: {["-o", "LogLevel=error", "-o", "Compression=no", "-o", "PasswordAuthentication=no", "pgbackrest@backup", "[BACKREST-BIN] --command=archive-get --compress-level=3 --compress-level-network=1 --config=[TEST_PATH]/backup/pgbackrest.conf --db-timeout=45 --lock-path=[TEST_PATH]/db-master/lock --log-level-file=trace --log-level-stderr=off --log-path=[TEST_PATH]/db-master/log --log-subprocess --pg1-path=[TEST_PATH]/db-master/db/base --process=0 --protocol-timeout=60 --type=backup remote"]}, name: {"remote-1 process on 'backup'"}, timeout: 60000) -P00 DEBUG: common/exec::execNew: => {Exec} -P00 DEBUG: common/exec::execOpen: (this: {Exec}) -P00 DEBUG: common/exec::execOpen: => void -P00 DEBUG: protocol/helper::protocolGet: => {name: remote-1 protocol on 'backup'} -P00 DEBUG: storage/driver/remote/storage::storageDriverRemoteNew: => {StorageDriverRemote} -P00 DEBUG: command/archive/get/file::archiveGetFile: (archiveFile: {"000000010000000100000001"}, walDestination: {"[TEST_PATH]/db-master/db/base/pg_xlog/RECOVERYXLOG"}, cipherType: 0) -P00 DEBUG: command/control/control::lockStopTest: (void) -P00 DEBUG: storage/storage::storageExists: (this: {type: posix, path: {"/"}, write: false}, pathExp: {"[TEST_PATH]/db-master/lock/db.stop"}, param.timeout: 0) -P00 DEBUG: storage/storage::storageExists: => false -P00 DEBUG: storage/storage::storageExists: (this: {type: posix, path: {"/"}, write: false}, pathExp: {"[TEST_PATH]/db-master/lock/all.stop"}, param.timeout: 0) -P00 DEBUG: storage/storage::storageExists: => false -P00 DEBUG: command/control/control::lockStopTest: => void -P00 DEBUG: command/archive/get/file::archiveGetCheck: (archiveFile: {"000000010000000100000001"}, cipherType: 0) -P00 DEBUG: postgres/interface::pgControlFromFile: (pgPath: {"[TEST_PATH]/db-master/db/base"}) -P00 DEBUG: storage/storage::storageNewRead: (this: {type: posix, path: {"/"}, write: false}, fileExp: {"[TEST_PATH]/db-master/db/base/global/pg_control"}, param.ignoreMissing: false, param.filterGroup: null) -P00 DEBUG: storage/storage::storageNewRead: => {type: posix, name: {"[TEST_PATH]/db-master/db/base/global/pg_control"}, ignoreMissing: false} -P00 DEBUG: storage/storage::storageGet: (file: {type: posix, name: {"[TEST_PATH]/db-master/db/base/global/pg_control"}, ignoreMissing: false}, param.exactSize: 512) -P00 DEBUG: storage/storage::storageGet: => {used: 512, size: 512, limit: } -P00 DEBUG: postgres/interface::pgControlFromFile: => {version: 90400, systemId: 1000000000000000094, walSegmentSize: 16777216, pageChecksum: true} -P00 DEBUG: info/infoArchive::infoArchiveNew: (storage: {type: remote, path: null, write: false}, fileName: {"/archive.info"}, ignoreMissing: false, cipherType: 0) -P00 DEBUG: info/infoPg::infoPgNew: (storage: {type: remote, path: null, write: false}, fileName: {"/archive.info"}, type: 0, cipherType: 0) -P00 DEBUG: info/info::infoNew: (storage: {type: remote, path: null, write: false}, fileName: {"/archive.info"}, cipherType: 0) -P00 DEBUG: info/info::infoNew: => {Info} -P00 DEBUG: info/infoPg::infoPgNew: => {InfoPg} -P00 DEBUG: info/infoArchive::infoArchiveNew: => {InfoArchive} -P00 DEBUG: command/archive/common::walSegmentFind: (storage: {type: remote, path: null, write: false}, archiveId: {"9.4-1"}, walSegment: {"000000010000000100000001"}) -P00 DEBUG: storage/storage::storageList: (this: {type: remote, path: null, write: false}, pathExp: {"/9.4-1/0000000100000001"}, param.errorOnMissing: false, param.expression: {"^000000010000000100000001-[0-f]{40}(\.gz){0,1}$"}) -P00 DEBUG: storage/driver/remote/storage::storageDriverRemoteList: (this: {StorageDriverRemote}, path: {"archive/db/9.4-1/0000000100000001"}, errorOnMissing: false, expression: {"^000000010000000100000001-[0-f]{40}(\.gz){0,1}$"}) -P00 DEBUG: storage/driver/remote/storage::storageDriverRemoteList: => {["000000010000000100000001-ceb021d9bb41f220511e413b095d2b0d89fec113.gz"]} -P00 DEBUG: storage/storage::storageList: => {["000000010000000100000001-ceb021d9bb41f220511e413b095d2b0d89fec113.gz"]} -P00 DEBUG: command/archive/common::walSegmentFind: => {"000000010000000100000001-ceb021d9bb41f220511e413b095d2b0d89fec113.gz"} -P00 DEBUG: command/archive/get/file::archiveGetCheck: => {ArchiveGetCheckResult} -P00 DEBUG: storage/driver/posix/storage::storageDriverPosixNew: (path: {"/"}, modeFile: 0640, modePath: 0750, write: true, pathExpressionFunction: null) -P00 DEBUG: storage/driver/posix/storage::storageDriverPosixNew: => {StorageDriverPosix} -P00 DEBUG: storage/storage::storageNewWrite: (this: {type: posix, path: {"/"}, write: true}, fileExp: {"[TEST_PATH]/db-master/db/base/pg_xlog/RECOVERYXLOG"}, param.modeFile: 0000, param.modePath: 0000, param.noCreatePath: true, param.noSyncFile: true, param.noSyncPath: true, param.noAtomic: true, param.filterGroup: null) -P00 DEBUG: storage/storage::storageNewWrite: => {type: posix, name: {"[TEST_PATH]/db-master/db/base/pg_xlog/RECOVERYXLOG"}, modeFile: 0640, modePath: 0750, createPath: false, syncFile: false, syncPath: false, atomic: false} -P00 DEBUG: common/io/filter/group::ioFilterGroupAdd: (this: {inputSame: false, done: true}, filter: {IoFilter}) -P00 DEBUG: common/io/filter/group::ioFilterGroupAdd: => {inputSame: false, done: true} -P00 DEBUG: storage/storage::storageNewRead: (this: {type: remote, path: null, write: false}, fileExp: {"/9.4-1/0000000100000001/000000010000000100000001-ceb021d9bb41f220511e413b095d2b0d89fec113.gz"}, param.ignoreMissing: false, param.filterGroup: null) -P00 DEBUG: storage/driver/remote/storage::storageDriverRemoteNewRead: (this: {StorageDriverRemote}, file: {"archive/db/9.4-1/0000000100000001/000000010000000100000001-ceb021d9bb41f220511e413b095d2b0d89fec113.gz"}, ignoreMissing: false) -P00 DEBUG: storage/driver/remote/storage::storageDriverRemoteNewRead: => {type: remote, name: {"archive/db/9.4-1/0000000100000001/000000010000000100000001-ceb021d9bb41f220511e413b095d2b0d89fec113.gz"}, ignoreMissing: false} -P00 DEBUG: storage/storage::storageNewRead: => {type: remote, name: {"archive/db/9.4-1/0000000100000001/000000010000000100000001-ceb021d9bb41f220511e413b095d2b0d89fec113.gz"}, ignoreMissing: false} -P00 DEBUG: storage/storage::storageCopy: (source: {type: remote, name: {"archive/db/9.4-1/0000000100000001/000000010000000100000001-ceb021d9bb41f220511e413b095d2b0d89fec113.gz"}, ignoreMissing: false}, destination: {type: posix, name: {"[TEST_PATH]/db-master/db/base/pg_xlog/RECOVERYXLOG"}, modeFile: 0640, modePath: 0750, createPath: false, syncFile: false, syncPath: false, atomic: false}) -P00 DEBUG: storage/storage::storageCopy: => true -P00 DEBUG: command/archive/get/file::archiveGetFile: => 0 +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=detail --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 INFO: found 000000010000000100000001 in the archive -P00 DEBUG: command/archive/get/get::cmdArchiveGet: => 0 -P00 DEBUG: common/exit::exitSafe: (result: 0, error: false, signalType: 0) -P00 DEBUG: common/lock::lockRelease: (failOnNoLock: false) -P00 DEBUG: common/lock::lockRelease: => false P00 INFO: archive-get 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-push --compress --archive-async --process-max=2 [TEST_PATH]/db-master/db/base/pg_xlog/000000010000000100000002 ------------------------------------------------------------------------------------------------------------------------------------ diff --git a/test/lib/pgBackRestTest/Module/Mock/MockArchiveTest.pm b/test/lib/pgBackRestTest/Module/Mock/MockArchiveTest.pm index 079960bc2..7eb4dea96 100644 --- a/test/lib/pgBackRestTest/Module/Mock/MockArchiveTest.pm +++ b/test/lib/pgBackRestTest/Module/Mock/MockArchiveTest.pm @@ -94,7 +94,7 @@ sub run # Reduce console logging to detail $oHostDbMaster->configUpdate({&CFGDEF_SECTION_GLOBAL => {cfgOptionName(CFGOPT_LOG_LEVEL_CONSOLE) => lc(DETAIL)}}); - my $strLogDebug = '--' . cfgOptionName(CFGOPT_LOG_LEVEL_CONSOLE) . qw{=} . lc(DEBUG); + my $strLogOverride = ''; # If S3 set process max to 2. This seems like the best place for parallel testing since it will help speed S3 processing # without slowing down the other tests too much. @@ -105,7 +105,7 @@ sub run # Reduce console logging to warn (even for debug exceptions) $oHostDbMaster->configUpdate({&CFGDEF_SECTION_GLOBAL => {cfgOptionName(CFGOPT_LOG_LEVEL_CONSOLE) => lc(WARN)}}); - $strLogDebug = '--' . cfgOptionName(CFGOPT_LOG_LEVEL_CONSOLE) . qw{=} . lc(WARN); + $strLogOverride = '--' . cfgOptionName(CFGOPT_LOG_LEVEL_CONSOLE) . qw{=} . lc(WARN); } # Create the wal path @@ -152,7 +152,8 @@ sub run my $strArchiveFile = $self->walGenerate($strWalPath, PG_VERSION_94, 2, $strSourceFile); $oHostDbMaster->executeSimple( - $strCommandPush . ($bRemote ? ' --cmd-ssh=/usr/bin/ssh' : '') . " --compress ${strLogDebug} ${strWalPath}/${strSourceFile}", + $strCommandPush . ($bRemote ? ' --cmd-ssh=/usr/bin/ssh' : '') . + " --compress ${strLogOverride} ${strWalPath}/${strSourceFile}", {oLogTest => $self->expect()}); push(@stryExpectedWAL, "${strSourceFile}-${strArchiveChecksum}.gz"); @@ -169,14 +170,14 @@ sub run &log(INFO, ' get missing WAL'); $oHostDbMaster->executeSimple( - $strCommandGet . " ${strLogDebug} 700000007000000070000000 ${strWalPath}/RECOVERYXLOG", + $strCommandGet . " ${strLogOverride} 700000007000000070000000 ${strWalPath}/RECOVERYXLOG", {iExpectedExitStatus => 1, oLogTest => $self->expect()}); #--------------------------------------------------------------------------------------------------------------------------- &log(INFO, ' get first WAL'); $oHostDbMaster->executeSimple( - $strCommandGet . " ${strLogDebug} ${strSourceFile} ${strWalPath}/RECOVERYXLOG", + $strCommandGet . " ${strLogOverride} ${strSourceFile} ${strWalPath}/RECOVERYXLOG", {oLogTest => $self->expect()}); # Check that the destination file exists