update CODEOWNERS #1124
GitHub Actions / JUnit Test Report
failed
Nov 14, 2024 in 0s
16 tests run, 14 passed, 1 skipped, 1 failed.
Annotations
Check failure on line 120 in psmdb-testing/pbm-functional/pytest/test_azurite.py
github-actions / JUnit Test Report
test_azurite.test_incremental
AssertionError: Backup failed{"Error":"get backup metadata: get: context deadline exceeded"}
2024-11-14T10:09:20Z I [rs1/rs103:27017] pbm-agent:
Version: 2.7.0
Platform: linux/amd64
GitCommit: 093a8f123cac6afa3531d3b6197460de047a403f
GitBranch: CURRENT_PR
BuildTime: 2024-11-14_09:47_UTC
GoVersion: go1.22.9
2024-11-14T10:09:20Z I [rs1/rs101:27017] pbm-agent:
Version: 2.7.0
Platform: linux/amd64
GitCommit: 093a8f123cac6afa3531d3b6197460de047a403f
GitBranch: CURRENT_PR
BuildTime: 2024-11-14_09:47_UTC
GoVersion: go1.22.9
2024-11-14T10:09:20Z I [rs1/rs101:27017] starting PITR routine
2024-11-14T10:09:20Z I [rs1/rs103:27017] starting PITR routine
2024-11-14T10:09:20Z I [rs2/rs201:27017] pbm-agent:
Version: 2.7.0
Platform: linux/amd64
GitCommit: 093a8f123cac6afa3531d3b6197460de047a403f
GitBranch: CURRENT_PR
BuildTime: 2024-11-14_09:47_UTC
GoVersion: go1.22.9
2024-11-14T10:09:20Z I [rs2/rs201:27017] starting PITR routine
2024-11-14T10:09:20Z I [rs1/rs103:27017] node: rs1/rs103:27017
2024-11-14T10:09:20Z I [rs1/rs102:27017] pbm-agent:
Version: 2.7.0
Platform: linux/amd64
GitCommit: 093a8f123cac6afa3531d3b6197460de047a403f
GitBranch: CURRENT_PR
BuildTime: 2024-11-14_09:47_UTC
GoVersion: go1.22.9
2024-11-14T10:09:20Z I [rs1/rs102:27017] starting PITR routine
2024-11-14T10:09:20Z I [rs2/rs201:27017] node: rs2/rs201:27017
2024-11-14T10:09:20Z I [rs1/rs101:27017] node: rs1/rs101:27017
2024-11-14T10:09:20Z E [rs1/rs103:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
2024-11-14T10:09:20Z E [rs1/rs101:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
2024-11-14T10:09:20Z E [rs2/rs201:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
2024-11-14T10:09:20Z E [rs1/rs102:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
2024-11-14T10:09:20Z I [rs1/rs101:27017] conn level ReadConcern: majority; WriteConcern: majority
2024-11-14T10:09:20Z I [rs1/rs102:27017] node: rs1/rs102:27017
2024-11-14T10:09:20Z I [rs1/rs103:27017] conn level ReadConcern: majority; WriteConcern: majority
2024-11-14T10:09:20Z I [rs2/rs201:27017] conn level ReadConcern: majority; WriteConcern: majority
2024-11-14T10:09:20Z I [rs1/rs101:27017] listening for the commands
2024-11-14T10:09:20Z I [rs1/rs102:27017] conn level ReadConcern: majority; WriteConcern: majority
2024-11-14T10:09:20Z I [rs1/rs103:27017] listening for the commands
2024-11-14T10:09:20Z I [rs2/rs201:27017] listening for the commands
2024-11-14T10:09:20Z I [rs1/rs102:27017] listening for the commands
2024-11-14T10:09:22Z I [rscfg/rscfg01:27017] pbm-agent:
Version: 2.7.0
Platform: linux/amd64
GitCommit: 093a8f123cac6afa3531d3b6197460de047a403f
GitBranch: CURRENT_PR
BuildTime: 2024-11-14_09:47_UTC
GoVersion: go1.22.9
2024-11-14T10:09:22Z I [rscfg/rscfg01:27017] starting PITR routine
2024-11-14T10:09:22Z E [rscfg/rscfg01:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
2024-11-14T10:09:22Z I [rscfg/rscfg01:27017] node: rscfg/rscfg01:27017
2024-11-14T10:09:22Z I [rscfg/rscfg01:27017] conn level ReadConcern: majority; WriteConcern: majority
2024-11-14T10:09:22Z I [rscfg/rscfg01:27017] listening for the commands
2024-11-14T10:09:22Z I [rscfg/rscfg02:27017] pbm-agent:
Version: 2.7.0
Platform: linux/amd64
GitCommit: 093a8f123cac6afa3531d3b6197460de047a403f
GitBranch: CURRENT_PR
BuildTime: 2024-11-14_09:47_UTC
GoVersion: go1.22.9
2024-11-14T10:09:22Z I [rscfg/rscfg02:27017] starting PITR routine
2024-11-14T10:09:22Z I [rscfg/rscfg02:27017] node: rscfg/rscfg02:27017
2024-11-14T10:09:22Z E [rscfg/rscfg02:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
2024-11-14T10:09:22Z I [rscfg/rscfg02:27017] conn level ReadConcern: majority; WriteConcern: majority
2024-11-14T10:09:22Z I [rscfg/rscfg02:27017] listening for the commands
2024-11-14T10:09:22Z I [rs2/rs202:27017] pbm-agent:
Version: 2.7.0
Platform: linux/amd64
GitCommit: 093a8f123cac6afa3531d3b6197460de047a403f
GitBranch: CURRENT_PR
BuildTime: 2024-11-14_09:47_UTC
GoVersion: go1.22.9
2024-11-14T10:09:22Z I [rs2/rs202:27017] starting PITR routine
2024-11-14T10:09:22Z I [rs2/rs203:27017] pbm-agent:
Version: 2.7.0
Platform: linux/amd64
GitCommit: 093a8f123cac6afa3531d3b6197460de047a403f
GitBranch: CURRENT_PR
BuildTime: 2024-11-14_09:47_UTC
GoVersion: go1.22.9
2024-11-14T10:09:22Z I [rs2/rs203:27017] starting PITR routine
2024-11-14T10:09:22Z I [rs2/rs203:27017] node: rs2/rs203:27017
2024-11-14T10:09:22Z I [rs2/rs202:27017] node: rs2/rs202:27017
2024-11-14T10:09:22Z E [rs2/rs202:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
2024-11-14T10:09:22Z I [rs2/rs202:27017] conn level ReadConcern: majority; WriteConcern: majority
2024-11-14T10:09:22Z E [rs2/rs203:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
2024-11-14T10:09:22Z I [rs2/rs202:27017] listening for the commands
2024-11-14T10:09:22Z I [rs2/rs203:27017] conn level ReadConcern: majority; WriteConcern: majority
2024-11-14T10:09:22Z I [rs2/rs203:27017] listening for the commands
2024-11-14T10:09:23Z I [rscfg/rscfg03:27017] pbm-agent:
Version: 2.7.0
Platform: linux/amd64
GitCommit: 093a8f123cac6afa3531d3b6197460de047a403f
GitBranch: CURRENT_PR
BuildTime: 2024-11-14_09:47_UTC
GoVersion: go1.22.9
2024-11-14T10:09:23Z I [rscfg/rscfg03:27017] starting PITR routine
2024-11-14T10:09:23Z I [rscfg/rscfg03:27017] node: rscfg/rscfg03:27017
2024-11-14T10:09:23Z E [rscfg/rscfg03:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
2024-11-14T10:09:23Z I [rscfg/rscfg03:27017] conn level ReadConcern: majority; WriteConcern: majority
2024-11-14T10:09:23Z I [rscfg/rscfg03:27017] listening for the commands
2024-11-14T10:09:25Z E [rs1/rs101:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
2024-11-14T10:09:25Z E [rs1/rs103:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
2024-11-14T10:09:25Z E [rs1/rs102:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
2024-11-14T10:09:25Z E [rs2/rs201:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
2024-11-14T10:09:27Z E [rscfg/rscfg01:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
2024-11-14T10:09:27Z E [rscfg/rscfg02:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
2024-11-14T10:09:27Z E [rs2/rs202:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
2024-11-14T10:09:27Z E [rs2/rs203:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
2024-11-14T10:09:28Z E [rscfg/rscfg03:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
2024-11-14T10:09:30Z I [rscfg/rscfg01:27017] got command resync <ts: 1731578970>, opid: 6735cc5a3e94a1b9058d0fb1
2024-11-14T10:09:30Z I [rscfg/rscfg01:27017] got epoch {1731578969 1}
2024-11-14T10:09:30Z I [rscfg/rscfg01:27017] [resync] started
2024-11-14T10:09:30Z I [rscfg/rscfg02:27017] got command resync <ts: 1731578970>, opid: 6735cc5a3e94a1b9058d0fb1
2024-11-14T10:09:30Z I [rscfg/rscfg02:27017] got epoch {1731578969 1}
2024-11-14T10:09:30Z D [rscfg/rscfg02:27017] [resync] lock not acquired
2024-11-14T10:09:30Z D [rscfg/rscfg01:27017] [resync] uploading ".pbm.init" [size hint: 5 (5.00B); part size: 10485760 (10.00MB)]
2024-11-14T10:09:30Z I [rs2/rs202:27017] got command resync <ts: 1731578970>, opid: 6735cc5a3e94a1b9058d0fb1
2024-11-14T10:09:30Z I [rs2/rs202:27017] got epoch {1731578969 1}
2024-11-14T10:09:30Z I [rs2/rs203:27017] got command resync <ts: 1731578970>, opid: 6735cc5a3e94a1b9058d0fb1
2024-11-14T10:09:30Z I [rs2/rs202:27017] [resync] not a member of the leader rs
2024-11-14T10:09:30Z I [rs2/rs203:27017] got epoch {1731578969 1}
2024-11-14T10:09:30Z I [rs2/rs203:27017] [resync] not a member of the leader rs
2024-11-14T10:09:30Z D [rscfg/rscfg01:27017] [resync] got backups list: 0
2024-11-14T10:09:30Z D [rscfg/rscfg01:27017] [resync] got physical restores list: 3
2024-11-14T10:09:30Z D [rscfg/rscfg01:27017] [resync] epoch set to {1731578970 24}
2024-11-14T10:09:30Z I [rscfg/rscfg01:27017] [resync] succeed
2024-11-14T10:09:30Z I [rs1/rs101:27017] got command resync <ts: 1731578970>, opid: 6735cc5a3e94a1b9058d0fb1
2024-11-14T10:09:30Z I [rs2/rs201:27017] got command resync <ts: 1731578970>, opid: 6735cc5a3e94a1b9058d0fb1
2024-11-14T10:09:30Z I [rs1/rs103:27017] got command resync <ts: 1731578970>, opid: 6735cc5a3e94a1b9058d0fb1
2024-11-14T10:09:30Z I [rs1/rs102:27017] got command resync <ts: 1731578970>, opid: 6735cc5a3e94a1b9058d0fb1
2024-11-14T10:09:30Z I [rs1/rs101:27017] got epoch {1731578970 24}
2024-11-14T10:09:30Z I [rs1/rs102:27017] got epoch {1731578970 24}
2024-11-14T10:09:30Z I [rs2/rs201:27017] got epoch {1731578970 24}
2024-11-14T10:09:30Z I [rs1/rs102:27017] [resync] not a member of the leader rs
2024-11-14T10:09:30Z I [rs1/rs103:27017] got epoch {1731578970 24}
2024-11-14T10:09:30Z I [rs1/rs101:27017] [resync] not a member of the leader rs
2024-11-14T10:09:30Z I [rs2/rs201:27017] [resync] not a member of the leader rs
2024-11-14T10:09:30Z I [rs1/rs103:27017] [resync] not a member of the leader rs
2024-11-14T10:09:30Z I [rscfg/rscfg03:27017] got command resync <ts: 1731578970>, opid: 6735cc5a3e94a1b9058d0fb1
2024-11-14T10:09:30Z I [rscfg/rscfg03:27017] got epoch {1731578970 24}
2024-11-14T10:09:30Z D [rscfg/rscfg03:27017] [resync] get lock: duplicate operation: 6735cc5a3e94a1b9058d0fb1 [Resync storage]
2024-11-14T10:09:30Z D [rscfg/rscfg03:27017] [resync] lock not acquired
2024-11-14T10:09:35Z I [rs1/rs101:27017] got command resync <ts: 1731578975>, opid: 6735cc5fdc2178b3d267befc
2024-11-14T10:09:35Z I [rs1/rs103:27017] got command resync <ts: 1731578975>, opid: 6735cc5fdc2178b3d267befc
2024-11-14T10:09:35Z I [rs2/rs201:27017] got command resync <ts: 1731578975>, opid: 6735cc5fdc2178b3d267befc
2024-11-14T10:09:35Z I [rs1/rs102:27017] got command resync <ts: 1731578975>, opid: 6735cc5fdc2178b3d267befc
2024-11-14T10:09:35Z I [rs1/rs103:27017] got epoch {1731578970 24}
2024-11-14T10:09:35Z I [rs1/rs102:27017] got epoch {1731578970 24}
2024-11-14T10:09:35Z I [rs2/rs201:27017] got epoch {1731578970 24}
2024-11-14T10:09:35Z I [rs1/rs103:27017] [resync] not a member of the leader rs
2024-11-14T10:09:35Z I [rs1/rs101:27017] got epoch {1731578970 24}
2024-11-14T10:09:35Z I [rs1/rs102:27017] [resync] not a member of the leader rs
2024-11-14T10:09:35Z I [rs2/rs201:27017] [resync] not a member of the leader rs
2024-11-14T10:09:35Z I [rs1/rs101:27017] [resync] not a member of the leader rs
2024-11-14T10:09:35Z W [rs1/rs103:27017] [agentCheckup] storage is not initialized
2024-11-14T10:09:35Z W [rs2/rs201:27017] [agentCheckup] storage is not initialized
2024-11-14T10:09:35Z W [rs1/rs101:27017] [agentCheckup] storage is not initialized
2024-11-14T10:09:35Z W [rs1/rs102:27017] [agentCheckup] storage is not initialized
2024-11-14T10:09:35Z I [rscfg/rscfg03:27017] got command resync <ts: 1731578975>, opid: 6735cc5fdc2178b3d267befc
2024-11-14T10:09:35Z I [rscfg/rscfg03:27017] got epoch {1731578970 24}
2024-11-14T10:09:35Z I [rscfg/rscfg03:27017] [resync] started
2024-11-14T10:09:35Z D [rscfg/rscfg03:27017] [resync] BufferSize is set to 10485760 (~10Mb) | 5
2024-11-14T10:09:35Z D [rscfg/rscfg03:27017] [resync] got backups list: 0
2024-11-14T10:09:35Z D [rscfg/rscfg03:27017] [resync] got physical restores list: 0
2024-11-14T10:09:35Z D [rscfg/rscfg03:27017] [resync] epoch set to {1731578975 158}
2024-11-14T10:09:35Z I [rscfg/rscfg03:27017] [resync] succeed
2024-11-14T10:09:36Z I [rscfg/rscfg01:27017] got command resync <ts: 1731578975>, opid: 6735cc5fdc2178b3d267befc
2024-11-14T10:09:36Z I [rscfg/rscfg01:27017] got epoch {1731578975 158}
2024-11-14T10:09:36Z D [rscfg/rscfg01:27017] [resync] get lock: duplicate operation: 6735cc5fdc2178b3d267befc [Resync storage]
2024-11-14T10:09:36Z I [rscfg/rscfg02:27017] got command resync <ts: 1731578975>, opid: 6735cc5fdc2178b3d267befc
2024-11-14T10:09:36Z D [rscfg/rscfg01:27017] [resync] lock not acquired
2024-11-14T10:09:36Z I [rscfg/rscfg02:27017] got epoch {1731578975 158}
2024-11-14T10:09:36Z I [rscfg/rscfg01:27017] got command backup [name: 2024-11-14T10:09:36Z, compression: s2 (level: default)] <ts: 1731578976>, opid: 6735cc60565884a4ccb456a9
2024-11-14T10:09:36Z I [rscfg/rscfg01:27017] got epoch {1731578975 158}
2024-11-14T10:09:36Z D [rscfg/rscfg02:27017] [resync] get lock: duplicate operation: 6735cc5fdc2178b3d267befc [Resync storage]
2024-11-14T10:09:36Z E [rscfg/rscfg01:27017] [backup/2024-11-14T10:09:36Z] unable to proceed with the backup, active lock is present
2024-11-14T10:09:36Z D [rscfg/rscfg02:27017] [resync] lock not acquired
2024-11-14T10:09:36Z I [rscfg/rscfg02:27017] got command backup [name: 2024-11-14T10:09:36Z, compression: s2 (level: default)] <ts: 1731578976>, opid: 6735cc60565884a4ccb456a9
2024-11-14T10:09:36Z I [rs2/rs202:27017] got command resync <ts: 1731578975>, opid: 6735cc5fdc2178b3d267befc
2024-11-14T10:09:36Z I [rscfg/rscfg02:27017] got epoch {1731578975 158}
2024-11-14T10:09:36Z I [rs2/rs203:27017] got command resync <ts: 1731578975>, opid: 6735cc5fdc2178b3d267befc
2024-11-14T10:09:36Z I [rs2/rs202:27017] got epoch {1731578975 158}
2024-11-14T10:09:36Z I [rs2/rs203:27017] got epoch {1731578975 158}
2024-11-14T10:09:36Z I [rs2/rs202:27017] [resync] not a member of the leader rs
2024-11-14T10:09:36Z I [rs2/rs203:27017] [resync] not a member of the leader rs
2024-11-14T10:09:36Z I [rs2/rs202:27017] got command backup [name: 2024-11-14T10:09:36Z, compression: s2 (level: default)] <ts: 1731578976>, opid: 6735cc60565884a4ccb456a9
2024-11-14T10:09:36Z I [rs2/rs203:27017] got command backup [name: 2024-11-14T10:09:36Z, compression: s2 (level: default)] <ts: 1731578976>, opid: 6735cc60565884a4ccb456a9
2024-11-14T10:09:36Z I [rs2/rs202:27017] got epoch {1731578975 158}
2024-11-14T10:09:36Z I [rs2/rs203:27017] got epoch {1731578975 158}
2024-11-14T10:09:36Z I [rs1/rs101:27017] got command backup [name: 2024-11-14T10:09:36Z, compression: s2 (level: default)] <ts: 1731578976>, opid: 6735cc60565884a4ccb456a9
2024-11-14T10:09:36Z I [rs1/rs103:27017] got command backup [name: 2024-11-14T10:09:36Z, compression: s2 (level: default)] <ts: 1731578976>, opid: 6735cc60565884a4ccb456a9
2024-11-14T10:09:36Z I [rs2/rs201:27017] got command backup [name: 2024-11-14T10:09:36Z, compression: s2 (level: default)] <ts: 1731578976>, opid: 6735cc60565884a4ccb456a9
2024-11-14T10:09:36Z I [rs1/rs101:27017] got epoch {1731578975 158}
2024-11-14T10:09:36Z I [rs1/rs103:27017] got epoch {1731578975 158}
2024-11-14T10:09:36Z I [rs1/rs102:27017] got command backup [name: 2024-11-14T10:09:36Z, compression: s2 (level: default)] <ts: 1731578976>, opid: 6735cc60565884a4ccb456a9
2024-11-14T10:09:36Z I [rs2/rs201:27017] got epoch {1731578975 158}
2024-11-14T10:09:36Z I [rs1/rs102:27017] got epoch {1731578975 158}
2024-11-14T10:09:36Z I [rscfg/rscfg03:27017] got command backup [name: 2024-11-14T10:09:36Z, compression: s2 (level: default)] <ts: 1731578976>, opid: 6735cc60565884a4ccb456a9
2024-11-14T10:09:36Z I [rscfg/rscfg03:27017] got epoch {1731578975 158}
2024-11-14T10:09:51Z D [rscfg/rscfg02:27017] [backup/2024-11-14T10:09:36Z] nomination timeout
2024-11-14T10:09:51Z D [rscfg/rscfg02:27017] [backup/2024-11-14T10:09:36Z] skip after nomination, probably started by another node
2024-11-14T10:09:51Z D [rs2/rs202:27017] [backup/2024-11-14T10:09:36Z] nomination timeout
2024-11-14T10:09:51Z D [rs2/rs203:27017] [backup/2024-11-14T10:09:36Z] nomination timeout
2024-11-14T10:09:51Z D [rs2/rs202:27017] [backup/2024-11-14T10:09:36Z] skip after nomination, probably started by another node
2024-11-14T10:09:51Z D [rs2/rs203:27017] [backup/2024-11-14T10:09:36Z] skip after nomination, probably started by another node
2024-11-14T10:09:51Z D [rs1/rs101:27017] [backup/2024-11-14T10:09:36Z] nomination timeout
2024-11-14T10:09:51Z D [rs2/rs201:27017] [backup/2024-11-14T10:09:36Z] nomination timeout
2024-11-14T10:09:51Z D [rs1/rs103:27017] [backup/2024-11-14T10:09:36Z] nomination timeout
2024-11-14T10:09:51Z D [rs1/rs101:27017] [backup/2024-11-14T10:09:36Z] skip after nomination, probably started by another node
2024-11-14T10:09:51Z D [rs1/rs102:27017] [backup/2024-11-14T10:09:36Z] nomination timeout
2024-11-14T10:09:51Z D [rs2/rs201:27017] [backup/2024-11-14T10:09:36Z] skip after nomination, probably started by another node
2024-11-14T10:09:51Z D [rs1/rs103:27017] [backup/2024-11-14T10:09:36Z] skip after nomination, probably started by another node
2024-11-14T10:09:51Z D [rs1/rs102:27017] [backup/2024-11-14T10:09:36Z] skip after nomination, probably started by another node
2024-11-14T10:09:51Z D [rscfg/rscfg03:27017] [backup/2024-11-14T10:09:36Z] nomination timeout
2024-11-14T10:09:51Z D [rscfg/rscfg03:27017] [backup/2024-11-14T10:09:36Z] skip after nomination, probably started by another node
Raw output
start_cluster = True, cluster = <cluster.Cluster object at 0x7f02f4f07250>
@pytest.mark.timeout(300, func_only=True)
def test_incremental(start_cluster, cluster):
cluster.check_pbm_status()
> cluster.make_backup("incremental --base")
test_azurite.py:120:
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
self = <cluster.Cluster object at 0x7f02f4f07250>, type = 'incremental --base'
def make_backup(self, type):
n = testinfra.get_host("docker://" + self.pbm_cli)
timeout = time.time() + 120
while True:
running = self.get_status()['running']
Cluster.log("Current operation: " + str(running))
if not running:
if type:
start = n.run(
'pbm backup --out=json --type=' + type)
else:
start = n.run('pbm backup --out=json')
if start.rc == 0:
name = json.loads(start.stdout)['name']
Cluster.log("Backup started")
break
elif "resync" in start.stdout:
Cluster.log("Resync in progress, retrying: " + start.stdout)
else:
logs = n.check_output("pbm logs -sD -t0")
> assert False, "Backup failed" + start.stdout + start.stderr + '\n' + logs
E AssertionError: Backup failed{"Error":"get backup metadata: get: context deadline exceeded"}
E
E 2024-11-14T10:09:20Z I [rs1/rs103:27017] pbm-agent:
E Version: 2.7.0
E Platform: linux/amd64
E GitCommit: 093a8f123cac6afa3531d3b6197460de047a403f
E GitBranch: CURRENT_PR
E BuildTime: 2024-11-14_09:47_UTC
E GoVersion: go1.22.9
E 2024-11-14T10:09:20Z I [rs1/rs101:27017] pbm-agent:
E Version: 2.7.0
E Platform: linux/amd64
E GitCommit: 093a8f123cac6afa3531d3b6197460de047a403f
E GitBranch: CURRENT_PR
E BuildTime: 2024-11-14_09:47_UTC
E GoVersion: go1.22.9
E 2024-11-14T10:09:20Z I [rs1/rs101:27017] starting PITR routine
E 2024-11-14T10:09:20Z I [rs1/rs103:27017] starting PITR routine
E 2024-11-14T10:09:20Z I [rs2/rs201:27017] pbm-agent:
E Version: 2.7.0
E Platform: linux/amd64
E GitCommit: 093a8f123cac6afa3531d3b6197460de047a403f
E GitBranch: CURRENT_PR
E BuildTime: 2024-11-14_09:47_UTC
E GoVersion: go1.22.9
E 2024-11-14T10:09:20Z I [rs2/rs201:27017] starting PITR routine
E 2024-11-14T10:09:20Z I [rs1/rs103:27017] node: rs1/rs103:27017
E 2024-11-14T10:09:20Z I [rs1/rs102:27017] pbm-agent:
E Version: 2.7.0
E Platform: linux/amd64
E GitCommit: 093a8f123cac6afa3531d3b6197460de047a403f
E GitBranch: CURRENT_PR
E BuildTime: 2024-11-14_09:47_UTC
E GoVersion: go1.22.9
E 2024-11-14T10:09:20Z I [rs1/rs102:27017] starting PITR routine
E 2024-11-14T10:09:20Z I [rs2/rs201:27017] node: rs2/rs201:27017
E 2024-11-14T10:09:20Z I [rs1/rs101:27017] node: rs1/rs101:27017
E 2024-11-14T10:09:20Z E [rs1/rs103:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
E 2024-11-14T10:09:20Z E [rs1/rs101:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
E 2024-11-14T10:09:20Z E [rs2/rs201:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
E 2024-11-14T10:09:20Z E [rs1/rs102:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
E 2024-11-14T10:09:20Z I [rs1/rs101:27017] conn level ReadConcern: majority; WriteConcern: majority
E 2024-11-14T10:09:20Z I [rs1/rs102:27017] node: rs1/rs102:27017
E 2024-11-14T10:09:20Z I [rs1/rs103:27017] conn level ReadConcern: majority; WriteConcern: majority
E 2024-11-14T10:09:20Z I [rs2/rs201:27017] conn level ReadConcern: majority; WriteConcern: majority
E 2024-11-14T10:09:20Z I [rs1/rs101:27017] listening for the commands
E 2024-11-14T10:09:20Z I [rs1/rs102:27017] conn level ReadConcern: majority; WriteConcern: majority
E 2024-11-14T10:09:20Z I [rs1/rs103:27017] listening for the commands
E 2024-11-14T10:09:20Z I [rs2/rs201:27017] listening for the commands
E 2024-11-14T10:09:20Z I [rs1/rs102:27017] listening for the commands
E 2024-11-14T10:09:22Z I [rscfg/rscfg01:27017] pbm-agent:
E Version: 2.7.0
E Platform: linux/amd64
E GitCommit: 093a8f123cac6afa3531d3b6197460de047a403f
E GitBranch: CURRENT_PR
E BuildTime: 2024-11-14_09:47_UTC
E GoVersion: go1.22.9
E 2024-11-14T10:09:22Z I [rscfg/rscfg01:27017] starting PITR routine
E 2024-11-14T10:09:22Z E [rscfg/rscfg01:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
E 2024-11-14T10:09:22Z I [rscfg/rscfg01:27017] node: rscfg/rscfg01:27017
E 2024-11-14T10:09:22Z I [rscfg/rscfg01:27017] conn level ReadConcern: majority; WriteConcern: majority
E 2024-11-14T10:09:22Z I [rscfg/rscfg01:27017] listening for the commands
E 2024-11-14T10:09:22Z I [rscfg/rscfg02:27017] pbm-agent:
E Version: 2.7.0
E Platform: linux/amd64
E GitCommit: 093a8f123cac6afa3531d3b6197460de047a403f
E GitBranch: CURRENT_PR
E BuildTime: 2024-11-14_09:47_UTC
E GoVersion: go1.22.9
E 2024-11-14T10:09:22Z I [rscfg/rscfg02:27017] starting PITR routine
E 2024-11-14T10:09:22Z I [rscfg/rscfg02:27017] node: rscfg/rscfg02:27017
E 2024-11-14T10:09:22Z E [rscfg/rscfg02:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
E 2024-11-14T10:09:22Z I [rscfg/rscfg02:27017] conn level ReadConcern: majority; WriteConcern: majority
E 2024-11-14T10:09:22Z I [rscfg/rscfg02:27017] listening for the commands
E 2024-11-14T10:09:22Z I [rs2/rs202:27017] pbm-agent:
E Version: 2.7.0
E Platform: linux/amd64
E GitCommit: 093a8f123cac6afa3531d3b6197460de047a403f
E GitBranch: CURRENT_PR
E BuildTime: 2024-11-14_09:47_UTC
E GoVersion: go1.22.9
E 2024-11-14T10:09:22Z I [rs2/rs202:27017] starting PITR routine
E 2024-11-14T10:09:22Z I [rs2/rs203:27017] pbm-agent:
E Version: 2.7.0
E Platform: linux/amd64
E GitCommit: 093a8f123cac6afa3531d3b6197460de047a403f
E GitBranch: CURRENT_PR
E BuildTime: 2024-11-14_09:47_UTC
E GoVersion: go1.22.9
E 2024-11-14T10:09:22Z I [rs2/rs203:27017] starting PITR routine
E 2024-11-14T10:09:22Z I [rs2/rs203:27017] node: rs2/rs203:27017
E 2024-11-14T10:09:22Z I [rs2/rs202:27017] node: rs2/rs202:27017
E 2024-11-14T10:09:22Z E [rs2/rs202:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
E 2024-11-14T10:09:22Z I [rs2/rs202:27017] conn level ReadConcern: majority; WriteConcern: majority
E 2024-11-14T10:09:22Z E [rs2/rs203:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
E 2024-11-14T10:09:22Z I [rs2/rs202:27017] listening for the commands
E 2024-11-14T10:09:22Z I [rs2/rs203:27017] conn level ReadConcern: majority; WriteConcern: majority
E 2024-11-14T10:09:22Z I [rs2/rs203:27017] listening for the commands
E 2024-11-14T10:09:23Z I [rscfg/rscfg03:27017] pbm-agent:
E Version: 2.7.0
E Platform: linux/amd64
E GitCommit: 093a8f123cac6afa3531d3b6197460de047a403f
E GitBranch: CURRENT_PR
E BuildTime: 2024-11-14_09:47_UTC
E GoVersion: go1.22.9
E 2024-11-14T10:09:23Z I [rscfg/rscfg03:27017] starting PITR routine
E 2024-11-14T10:09:23Z I [rscfg/rscfg03:27017] node: rscfg/rscfg03:27017
E 2024-11-14T10:09:23Z E [rscfg/rscfg03:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
E 2024-11-14T10:09:23Z I [rscfg/rscfg03:27017] conn level ReadConcern: majority; WriteConcern: majority
E 2024-11-14T10:09:23Z I [rscfg/rscfg03:27017] listening for the commands
E 2024-11-14T10:09:25Z E [rs1/rs101:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
E 2024-11-14T10:09:25Z E [rs1/rs103:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
E 2024-11-14T10:09:25Z E [rs1/rs102:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
E 2024-11-14T10:09:25Z E [rs2/rs201:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
E 2024-11-14T10:09:27Z E [rscfg/rscfg01:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
E 2024-11-14T10:09:27Z E [rscfg/rscfg02:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
E 2024-11-14T10:09:27Z E [rs2/rs202:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
E 2024-11-14T10:09:27Z E [rs2/rs203:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
E 2024-11-14T10:09:28Z E [rscfg/rscfg03:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
E 2024-11-14T10:09:30Z I [rscfg/rscfg01:27017] got command resync <ts: 1731578970>, opid: 6735cc5a3e94a1b9058d0fb1
E 2024-11-14T10:09:30Z I [rscfg/rscfg01:27017] got epoch {1731578969 1}
E 2024-11-14T10:09:30Z I [rscfg/rscfg01:27017] [resync] started
E 2024-11-14T10:09:30Z I [rscfg/rscfg02:27017] got command resync <ts: 1731578970>, opid: 6735cc5a3e94a1b9058d0fb1
E 2024-11-14T10:09:30Z I [rscfg/rscfg02:27017] got epoch {1731578969 1}
E 2024-11-14T10:09:30Z D [rscfg/rscfg02:27017] [resync] lock not acquired
E 2024-11-14T10:09:30Z D [rscfg/rscfg01:27017] [resync] uploading ".pbm.init" [size hint: 5 (5.00B); part size: 10485760 (10.00MB)]
E 2024-11-14T10:09:30Z I [rs2/rs202:27017] got command resync <ts: 1731578970>, opid: 6735cc5a3e94a1b9058d0fb1
E 2024-11-14T10:09:30Z I [rs2/rs202:27017] got epoch {1731578969 1}
E 2024-11-14T10:09:30Z I [rs2/rs203:27017] got command resync <ts: 1731578970>, opid: 6735cc5a3e94a1b9058d0fb1
E 2024-11-14T10:09:30Z I [rs2/rs202:27017] [resync] not a member of the leader rs
E 2024-11-14T10:09:30Z I [rs2/rs203:27017] got epoch {1731578969 1}
E 2024-11-14T10:09:30Z I [rs2/rs203:27017] [resync] not a member of the leader rs
E 2024-11-14T10:09:30Z D [rscfg/rscfg01:27017] [resync] got backups list: 0
E 2024-11-14T10:09:30Z D [rscfg/rscfg01:27017] [resync] got physical restores list: 3
E 2024-11-14T10:09:30Z D [rscfg/rscfg01:27017] [resync] epoch set to {1731578970 24}
E 2024-11-14T10:09:30Z I [rscfg/rscfg01:27017] [resync] succeed
E 2024-11-14T10:09:30Z I [rs1/rs101:27017] got command resync <ts: 1731578970>, opid: 6735cc5a3e94a1b9058d0fb1
E 2024-11-14T10:09:30Z I [rs2/rs201:27017] got command resync <ts: 1731578970>, opid: 6735cc5a3e94a1b9058d0fb1
E 2024-11-14T10:09:30Z I [rs1/rs103:27017] got command resync <ts: 1731578970>, opid: 6735cc5a3e94a1b9058d0fb1
E 2024-11-14T10:09:30Z I [rs1/rs102:27017] got command resync <ts: 1731578970>, opid: 6735cc5a3e94a1b9058d0fb1
E 2024-11-14T10:09:30Z I [rs1/rs101:27017] got epoch {1731578970 24}
E 2024-11-14T10:09:30Z I [rs1/rs102:27017] got epoch {1731578970 24}
E 2024-11-14T10:09:30Z I [rs2/rs201:27017] got epoch {1731578970 24}
E 2024-11-14T10:09:30Z I [rs1/rs102:27017] [resync] not a member of the leader rs
E 2024-11-14T10:09:30Z I [rs1/rs103:27017] got epoch {1731578970 24}
E 2024-11-14T10:09:30Z I [rs1/rs101:27017] [resync] not a member of the leader rs
E 2024-11-14T10:09:30Z I [rs2/rs201:27017] [resync] not a member of the leader rs
E 2024-11-14T10:09:30Z I [rs1/rs103:27017] [resync] not a member of the leader rs
E 2024-11-14T10:09:30Z I [rscfg/rscfg03:27017] got command resync <ts: 1731578970>, opid: 6735cc5a3e94a1b9058d0fb1
E 2024-11-14T10:09:30Z I [rscfg/rscfg03:27017] got epoch {1731578970 24}
E 2024-11-14T10:09:30Z D [rscfg/rscfg03:27017] [resync] get lock: duplicate operation: 6735cc5a3e94a1b9058d0fb1 [Resync storage]
E 2024-11-14T10:09:30Z D [rscfg/rscfg03:27017] [resync] lock not acquired
E 2024-11-14T10:09:35Z I [rs1/rs101:27017] got command resync <ts: 1731578975>, opid: 6735cc5fdc2178b3d267befc
E 2024-11-14T10:09:35Z I [rs1/rs103:27017] got command resync <ts: 1731578975>, opid: 6735cc5fdc2178b3d267befc
E 2024-11-14T10:09:35Z I [rs2/rs201:27017] got command resync <ts: 1731578975>, opid: 6735cc5fdc2178b3d267befc
E 2024-11-14T10:09:35Z I [rs1/rs102:27017] got command resync <ts: 1731578975>, opid: 6735cc5fdc2178b3d267befc
E 2024-11-14T10:09:35Z I [rs1/rs103:27017] got epoch {1731578970 24}
E 2024-11-14T10:09:35Z I [rs1/rs102:27017] got epoch {1731578970 24}
E 2024-11-14T10:09:35Z I [rs2/rs201:27017] got epoch {1731578970 24}
E 2024-11-14T10:09:35Z I [rs1/rs103:27017] [resync] not a member of the leader rs
E 2024-11-14T10:09:35Z I [rs1/rs101:27017] got epoch {1731578970 24}
E 2024-11-14T10:09:35Z I [rs1/rs102:27017] [resync] not a member of the leader rs
E 2024-11-14T10:09:35Z I [rs2/rs201:27017] [resync] not a member of the leader rs
E 2024-11-14T10:09:35Z I [rs1/rs101:27017] [resync] not a member of the leader rs
E 2024-11-14T10:09:35Z W [rs1/rs103:27017] [agentCheckup] storage is not initialized
E 2024-11-14T10:09:35Z W [rs2/rs201:27017] [agentCheckup] storage is not initialized
E 2024-11-14T10:09:35Z W [rs1/rs101:27017] [agentCheckup] storage is not initialized
E 2024-11-14T10:09:35Z W [rs1/rs102:27017] [agentCheckup] storage is not initialized
E 2024-11-14T10:09:35Z I [rscfg/rscfg03:27017] got command resync <ts: 1731578975>, opid: 6735cc5fdc2178b3d267befc
E 2024-11-14T10:09:35Z I [rscfg/rscfg03:27017] got epoch {1731578970 24}
E 2024-11-14T10:09:35Z I [rscfg/rscfg03:27017] [resync] started
E 2024-11-14T10:09:35Z D [rscfg/rscfg03:27017] [resync] BufferSize is set to 10485760 (~10Mb) | 5
E 2024-11-14T10:09:35Z D [rscfg/rscfg03:27017] [resync] got backups list: 0
E 2024-11-14T10:09:35Z D [rscfg/rscfg03:27017] [resync] got physical restores list: 0
E 2024-11-14T10:09:35Z D [rscfg/rscfg03:27017] [resync] epoch set to {1731578975 158}
E 2024-11-14T10:09:35Z I [rscfg/rscfg03:27017] [resync] succeed
E 2024-11-14T10:09:36Z I [rscfg/rscfg01:27017] got command resync <ts: 1731578975>, opid: 6735cc5fdc2178b3d267befc
E 2024-11-14T10:09:36Z I [rscfg/rscfg01:27017] got epoch {1731578975 158}
E 2024-11-14T10:09:36Z D [rscfg/rscfg01:27017] [resync] get lock: duplicate operation: 6735cc5fdc2178b3d267befc [Resync storage]
E 2024-11-14T10:09:36Z I [rscfg/rscfg02:27017] got command resync <ts: 1731578975>, opid: 6735cc5fdc2178b3d267befc
E 2024-11-14T10:09:36Z D [rscfg/rscfg01:27017] [resync] lock not acquired
E 2024-11-14T10:09:36Z I [rscfg/rscfg02:27017] got epoch {1731578975 158}
E 2024-11-14T10:09:36Z I [rscfg/rscfg01:27017] got command backup [name: 2024-11-14T10:09:36Z, compression: s2 (level: default)] <ts: 1731578976>, opid: 6735cc60565884a4ccb456a9
E 2024-11-14T10:09:36Z I [rscfg/rscfg01:27017] got epoch {1731578975 158}
E 2024-11-14T10:09:36Z D [rscfg/rscfg02:27017] [resync] get lock: duplicate operation: 6735cc5fdc2178b3d267befc [Resync storage]
E 2024-11-14T10:09:36Z E [rscfg/rscfg01:27017] [backup/2024-11-14T10:09:36Z] unable to proceed with the backup, active lock is present
E 2024-11-14T10:09:36Z D [rscfg/rscfg02:27017] [resync] lock not acquired
E 2024-11-14T10:09:36Z I [rscfg/rscfg02:27017] got command backup [name: 2024-11-14T10:09:36Z, compression: s2 (level: default)] <ts: 1731578976>, opid: 6735cc60565884a4ccb456a9
E 2024-11-14T10:09:36Z I [rs2/rs202:27017] got command resync <ts: 1731578975>, opid: 6735cc5fdc2178b3d267befc
E 2024-11-14T10:09:36Z I [rscfg/rscfg02:27017] got epoch {1731578975 158}
E 2024-11-14T10:09:36Z I [rs2/rs203:27017] got command resync <ts: 1731578975>, opid: 6735cc5fdc2178b3d267befc
E 2024-11-14T10:09:36Z I [rs2/rs202:27017] got epoch {1731578975 158}
E 2024-11-14T10:09:36Z I [rs2/rs203:27017] got epoch {1731578975 158}
E 2024-11-14T10:09:36Z I [rs2/rs202:27017] [resync] not a member of the leader rs
E 2024-11-14T10:09:36Z I [rs2/rs203:27017] [resync] not a member of the leader rs
E 2024-11-14T10:09:36Z I [rs2/rs202:27017] got command backup [name: 2024-11-14T10:09:36Z, compression: s2 (level: default)] <ts: 1731578976>, opid: 6735cc60565884a4ccb456a9
E 2024-11-14T10:09:36Z I [rs2/rs203:27017] got command backup [name: 2024-11-14T10:09:36Z, compression: s2 (level: default)] <ts: 1731578976>, opid: 6735cc60565884a4ccb456a9
E 2024-11-14T10:09:36Z I [rs2/rs202:27017] got epoch {1731578975 158}
E 2024-11-14T10:09:36Z I [rs2/rs203:27017] got epoch {1731578975 158}
E 2024-11-14T10:09:36Z I [rs1/rs101:27017] got command backup [name: 2024-11-14T10:09:36Z, compression: s2 (level: default)] <ts: 1731578976>, opid: 6735cc60565884a4ccb456a9
E 2024-11-14T10:09:36Z I [rs1/rs103:27017] got command backup [name: 2024-11-14T10:09:36Z, compression: s2 (level: default)] <ts: 1731578976>, opid: 6735cc60565884a4ccb456a9
E 2024-11-14T10:09:36Z I [rs2/rs201:27017] got command backup [name: 2024-11-14T10:09:36Z, compression: s2 (level: default)] <ts: 1731578976>, opid: 6735cc60565884a4ccb456a9
E 2024-11-14T10:09:36Z I [rs1/rs101:27017] got epoch {1731578975 158}
E 2024-11-14T10:09:36Z I [rs1/rs103:27017] got epoch {1731578975 158}
E 2024-11-14T10:09:36Z I [rs1/rs102:27017] got command backup [name: 2024-11-14T10:09:36Z, compression: s2 (level: default)] <ts: 1731578976>, opid: 6735cc60565884a4ccb456a9
E 2024-11-14T10:09:36Z I [rs2/rs201:27017] got epoch {1731578975 158}
E 2024-11-14T10:09:36Z I [rs1/rs102:27017] got epoch {1731578975 158}
E 2024-11-14T10:09:36Z I [rscfg/rscfg03:27017] got command backup [name: 2024-11-14T10:09:36Z, compression: s2 (level: default)] <ts: 1731578976>, opid: 6735cc60565884a4ccb456a9
E 2024-11-14T10:09:36Z I [rscfg/rscfg03:27017] got epoch {1731578975 158}
E 2024-11-14T10:09:51Z D [rscfg/rscfg02:27017] [backup/2024-11-14T10:09:36Z] nomination timeout
E 2024-11-14T10:09:51Z D [rscfg/rscfg02:27017] [backup/2024-11-14T10:09:36Z] skip after nomination, probably started by another node
E 2024-11-14T10:09:51Z D [rs2/rs202:27017] [backup/2024-11-14T10:09:36Z] nomination timeout
E 2024-11-14T10:09:51Z D [rs2/rs203:27017] [backup/2024-11-14T10:09:36Z] nomination timeout
E 2024-11-14T10:09:51Z D [rs2/rs202:27017] [backup/2024-11-14T10:09:36Z] skip after nomination, probably started by another node
E 2024-11-14T10:09:51Z D [rs2/rs203:27017] [backup/2024-11-14T10:09:36Z] skip after nomination, probably started by another node
E 2024-11-14T10:09:51Z D [rs1/rs101:27017] [backup/2024-11-14T10:09:36Z] nomination timeout
E 2024-11-14T10:09:51Z D [rs2/rs201:27017] [backup/2024-11-14T10:09:36Z] nomination timeout
E 2024-11-14T10:09:51Z D [rs1/rs103:27017] [backup/2024-11-14T10:09:36Z] nomination timeout
E 2024-11-14T10:09:51Z D [rs1/rs101:27017] [backup/2024-11-14T10:09:36Z] skip after nomination, probably started by another node
E 2024-11-14T10:09:51Z D [rs1/rs102:27017] [backup/2024-11-14T10:09:36Z] nomination timeout
E 2024-11-14T10:09:51Z D [rs2/rs201:27017] [backup/2024-11-14T10:09:36Z] skip after nomination, probably started by another node
E 2024-11-14T10:09:51Z D [rs1/rs103:27017] [backup/2024-11-14T10:09:36Z] skip after nomination, probably started by another node
E 2024-11-14T10:09:51Z D [rs1/rs102:27017] [backup/2024-11-14T10:09:36Z] skip after nomination, probably started by another node
E 2024-11-14T10:09:51Z D [rscfg/rscfg03:27017] [backup/2024-11-14T10:09:36Z] nomination timeout
E 2024-11-14T10:09:51Z D [rscfg/rscfg03:27017] [backup/2024-11-14T10:09:36Z] skip after nomination, probably started by another node
cluster.py:393: AssertionError
Loading