AssertionError: Backup failed{"Error":"get backup metadata: get: context deadline exceeded"} 2024-09-06T06:00:25Z I [rs1/rs103:27017] pbm-agent: Version: 2.6.0 Platform: linux/amd64 GitCommit: d18cc8320e61b3fcbde1f1af16e92a3e0d50e00d GitBranch: dev BuildTime: 2024-09-06_05:34_UTC GoVersion: go1.23.1 2024-09-06T06:00:25Z I [rs1/rs103:27017] starting PITR routine 2024-09-06T06:00:25Z I [rs1/rs102:27017] pbm-agent: Version: 2.6.0 Platform: linux/amd64 GitCommit: d18cc8320e61b3fcbde1f1af16e92a3e0d50e00d GitBranch: dev BuildTime: 2024-09-06_05:34_UTC GoVersion: go1.23.1 2024-09-06T06:00:25Z I [rs1/rs102:27017] starting PITR routine 2024-09-06T06:00:25Z I [rs2/rs201:27017] pbm-agent: Version: 2.6.0 Platform: linux/amd64 GitCommit: d18cc8320e61b3fcbde1f1af16e92a3e0d50e00d GitBranch: dev BuildTime: 2024-09-06_05:34_UTC GoVersion: go1.23.1 2024-09-06T06:00:25Z I [rs1/rs101:27017] pbm-agent: Version: 2.6.0 Platform: linux/amd64 GitCommit: d18cc8320e61b3fcbde1f1af16e92a3e0d50e00d GitBranch: dev BuildTime: 2024-09-06_05:34_UTC GoVersion: go1.23.1 2024-09-06T06:00:25Z I [rs2/rs201:27017] starting PITR routine 2024-09-06T06:00:25Z I [rs1/rs101:27017] starting PITR routine 2024-09-06T06:00:25Z I [rs1/rs103:27017] node: rs1/rs103:27017 2024-09-06T06:00:25Z I [rs1/rs102:27017] node: rs1/rs102:27017 2024-09-06T06:00:25Z I [rs1/rs101:27017] node: rs1/rs101:27017 2024-09-06T06:00:25Z I [rs2/rs201:27017] node: rs2/rs201:27017 2024-09-06T06:00:25Z I [rs1/rs101:27017] conn level ReadConcern: majority; WriteConcern: majority 2024-09-06T06:00:25Z I [rs1/rs103:27017] conn level ReadConcern: majority; WriteConcern: majority 2024-09-06T06:00:25Z I [rs1/rs102:27017] conn level ReadConcern: majority; WriteConcern: majority 2024-09-06T06:00:25Z I [rs2/rs201:27017] conn level ReadConcern: majority; WriteConcern: majority 2024-09-06T06:00:25Z I [rs1/rs101:27017] listening for the commands 2024-09-06T06:00:25Z I [rs1/rs103:27017] listening for the commands 2024-09-06T06:00:25Z I [rs2/rs201:27017] listening for the commands 2024-09-06T06:00:25Z I [rs1/rs102:27017] listening for the commands 2024-09-06T06:00:27Z I [rscfg/rscfg01:27017] pbm-agent: Version: 2.6.0 Platform: linux/amd64 GitCommit: d18cc8320e61b3fcbde1f1af16e92a3e0d50e00d GitBranch: dev BuildTime: 2024-09-06_05:34_UTC GoVersion: go1.23.1 2024-09-06T06:00:27Z I [rscfg/rscfg01:27017] starting PITR routine 2024-09-06T06:00:27Z I [rscfg/rscfg01:27017] node: rscfg/rscfg01:27017 2024-09-06T06:00:27Z I [rscfg/rscfg01:27017] conn level ReadConcern: majority; WriteConcern: majority 2024-09-06T06:00:27Z I [rscfg/rscfg02:27017] pbm-agent: Version: 2.6.0 Platform: linux/amd64 GitCommit: d18cc8320e61b3fcbde1f1af16e92a3e0d50e00d GitBranch: dev BuildTime: 2024-09-06_05:34_UTC GoVersion: go1.23.1 2024-09-06T06:00:27Z I [rscfg/rscfg02:27017] starting PITR routine 2024-09-06T06:00:27Z I [rscfg/rscfg02:27017] node: rscfg/rscfg02:27017 2024-09-06T06:00:27Z I [rscfg/rscfg01:27017] listening for the commands 2024-09-06T06:00:27Z I [rscfg/rscfg02:27017] conn level ReadConcern: majority; WriteConcern: majority 2024-09-06T06:00:27Z I [rscfg/rscfg02:27017] listening for the commands 2024-09-06T06:00:27Z I [rs2/rs203:27017] pbm-agent: Version: 2.6.0 Platform: linux/amd64 GitCommit: d18cc8320e61b3fcbde1f1af16e92a3e0d50e00d GitBranch: dev BuildTime: 2024-09-06_05:34_UTC GoVersion: go1.23.1 2024-09-06T06:00:27Z I [rs2/rs203:27017] starting PITR routine 2024-09-06T06:00:27Z I [rs2/rs203:27017] node: rs2/rs203:27017 2024-09-06T06:00:27Z I [rs2/rs203:27017] conn level ReadConcern: majority; WriteConcern: majority 2024-09-06T06:00:27Z I [rs2/rs202:27017] pbm-agent: Version: 2.6.0 Platform: linux/amd64 GitCommit: d18cc8320e61b3fcbde1f1af16e92a3e0d50e00d GitBranch: dev BuildTime: 2024-09-06_05:34_UTC GoVersion: go1.23.1 2024-09-06T06:00:27Z I [rs2/rs202:27017] starting PITR routine 2024-09-06T06:00:27Z I [rs2/rs203:27017] listening for the commands 2024-09-06T06:00:27Z I [rs2/rs202:27017] node: rs2/rs202:27017 2024-09-06T06:00:27Z I [rs2/rs202:27017] conn level ReadConcern: majority; WriteConcern: majority 2024-09-06T06:00:27Z I [rs2/rs202:27017] listening for the commands 2024-09-06T06:00:29Z I [rscfg/rscfg03:27017] pbm-agent: Version: 2.6.0 Platform: linux/amd64 GitCommit: d18cc8320e61b3fcbde1f1af16e92a3e0d50e00d GitBranch: dev BuildTime: 2024-09-06_05:34_UTC GoVersion: go1.23.1 2024-09-06T06:00:29Z I [rscfg/rscfg03:27017] starting PITR routine 2024-09-06T06:00:29Z I [rscfg/rscfg03:27017] node: rscfg/rscfg03:27017 2024-09-06T06:00:29Z I [rscfg/rscfg03:27017] conn level ReadConcern: majority; WriteConcern: majority 2024-09-06T06:00:29Z I [rscfg/rscfg03:27017] listening for the commands 2024-09-06T06:00:30Z W [rs1/rs102:27017] [agentCheckup] get current storage status: query mongo: mongo: no documents in result 2024-09-06T06:00:30Z W [rs2/rs201:27017] [agentCheckup] get current storage status: query mongo: mongo: no documents in result 2024-09-06T06:00:30Z W [rs1/rs101:27017] [agentCheckup] get current storage status: query mongo: mongo: no documents in result 2024-09-06T06:00:30Z W [rs1/rs103:27017] [agentCheckup] get current storage status: query mongo: mongo: no documents in result 2024-09-06T06:00:30Z E [rs1/rs102:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result 2024-09-06T06:00:30Z E [rs1/rs101:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result 2024-09-06T06:00:30Z E [rs2/rs201:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result 2024-09-06T06:00:30Z E [rs1/rs103:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result 2024-09-06T06:00:32Z W [rscfg/rscfg01:27017] [agentCheckup] get current storage status: query mongo: mongo: no documents in result 2024-09-06T06:00:32Z E [rscfg/rscfg01:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result 2024-09-06T06:00:32Z W [rscfg/rscfg02:27017] [agentCheckup] get current storage status: query mongo: mongo: no documents in result 2024-09-06T06:00:32Z E [rscfg/rscfg02:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result 2024-09-06T06:00:32Z W [rs2/rs203:27017] [agentCheckup] get current storage status: query mongo: mongo: no documents in result 2024-09-06T06:00:32Z E [rs2/rs203:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result 2024-09-06T06:00:32Z W [rs2/rs202:27017] [agentCheckup] get current storage status: query mongo: mongo: no documents in result 2024-09-06T06:00:32Z E [rs2/rs202:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result 2024-09-06T06:00:34Z W [rscfg/rscfg03:27017] [agentCheckup] get current storage status: query mongo: mongo: no documents in result 2024-09-06T06:00:34Z E [rscfg/rscfg03:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result 2024-09-06T06:00:35Z I [rscfg/rscfg01:27017] got command resync <ts: 1725602435> 2024-09-06T06:00:35Z I [rscfg/rscfg01:27017] got epoch {1725602434 4} 2024-09-06T06:00:35Z I [rscfg/rscfg02:27017] got command resync <ts: 1725602435> 2024-09-06T06:00:35Z I [rscfg/rscfg02:27017] got epoch {1725602434 4} 2024-09-06T06:00:35Z I [rscfg/rscfg01:27017] [resync] started 2024-09-06T06:00:35Z D [rscfg/rscfg02:27017] [resync] lock not acquired 2024-09-06T06:00:35Z I [rs2/rs203:27017] got command resync <ts: 1725602435> 2024-09-06T06:00:35Z I [rs2/rs203:27017] got epoch {1725602434 4} 2024-09-06T06:00:35Z D [rscfg/rscfg01:27017] [resync] uploading ".pbm.init" [size hint: 5 (5.00B); part size: 10485760 (10.00MB)] 2024-09-06T06:00:35Z I [rs2/rs203:27017] [resync] not a member of the leader rs 2024-09-06T06:00:35Z I [rs2/rs202:27017] got command resync <ts: 1725602435> 2024-09-06T06:00:35Z I [rs2/rs202:27017] got epoch {1725602434 4} 2024-09-06T06:00:35Z I [rs2/rs202:27017] [resync] not a member of the leader rs 2024-09-06T06:00:35Z D [rscfg/rscfg01:27017] [resync] got backups list: 0 2024-09-06T06:00:35Z D [rscfg/rscfg01:27017] [resync] got physical restores list: 0 2024-09-06T06:00:35Z D [rscfg/rscfg01:27017] [resync] epoch set to {1725602435 21} 2024-09-06T06:00:35Z I [rscfg/rscfg01:27017] [resync] succeed 2024-09-06T06:00:35Z I [rs1/rs101:27017] got command resync <ts: 1725602435> 2024-09-06T06:00:35Z I [rs2/rs201:27017] got command resync <ts: 1725602435> 2024-09-06T06:00:35Z I [rs1/rs103:27017] got command resync <ts: 1725602435> 2024-09-06T06:00:35Z I [rs1/rs101:27017] got epoch {1725602435 21} 2024-09-06T06:00:35Z I [rs1/rs102:27017] got command resync <ts: 1725602435> 2024-09-06T06:00:35Z I [rs2/rs201:27017] got epoch {1725602435 21} 2024-09-06T06:00:35Z I [rs1/rs103:27017] got epoch {1725602435 21} 2024-09-06T06:00:35Z I [rs1/rs101:27017] [resync] not a member of the leader rs 2024-09-06T06:00:35Z I [rs2/rs201:27017] [resync] not a member of the leader rs 2024-09-06T06:00:35Z I [rs1/rs103:27017] [resync] not a member of the leader rs 2024-09-06T06:00:35Z I [rs1/rs102:27017] got epoch {1725602435 21} 2024-09-06T06:00:35Z I [rs1/rs102:27017] [resync] not a member of the leader rs 2024-09-06T06:00:36Z I [rscfg/rscfg03:27017] got command resync <ts: 1725602435> 2024-09-06T06:00:36Z I [rscfg/rscfg03:27017] got epoch {1725602435 21} 2024-09-06T06:00:36Z D [rscfg/rscfg03:27017] [resync] get lock: duplicate operation: 66da9a833f1bd18cd9225da1 [Resync storage] 2024-09-06T06:00:36Z D [rscfg/rscfg03:27017] [resync] lock not acquired 2024-09-06T06:00:40Z I [rs2/rs203:27017] got command resync <ts: 1725602440> 2024-09-06T06:00:40Z I [rs2/rs203:27017] got epoch {1725602435 21} 2024-09-06T06:00:40Z I [rs2/rs202:27017] got command resync <ts: 1725602440> 2024-09-06T06:00:40Z I [rs2/rs203:27017] [resync] not a member of the leader rs 2024-09-06T06:00:40Z I [rs2/rs202:27017] got epoch {1725602435 21} 2024-09-06T06:00:40Z I [rs2/rs202:27017] [resync] not a member of the leader rs 2024-09-06T06:00:40Z I [rs2/rs201:27017] got command resync <ts: 1725602440> 2024-09-06T06:00:40Z I [rs1/rs103:27017] got command resync <ts: 1725602440> 2024-09-06T06:00:40Z I [rs1/rs102:27017] got command resync <ts: 1725602440> 2024-09-06T06:00:40Z I [rs2/rs201:27017] got epoch {1725602435 21} 2024-09-06T06:00:40Z I [rs1/rs101:27017] got command resync <ts: 1725602440> 2024-09-06T06:00:40Z I [rs1/rs103:27017] got epoch {1725602435 21} 2024-09-06T06:00:40Z I [rs1/rs102:27017] got epoch {1725602435 21} 2024-09-06T06:00:40Z I [rs2/rs201:27017] [resync] not a member of the leader rs 2024-09-06T06:00:40Z I [rs1/rs103:27017] [resync] not a member of the leader rs 2024-09-06T06:00:40Z I [rs1/rs102:27017] [resync] not a member of the leader rs 2024-09-06T06:00:40Z I [rs1/rs101:27017] got epoch {1725602435 21} 2024-09-06T06:00:40Z I [rs1/rs101:27017] [resync] not a member of the leader rs 2024-09-06T06:00:41Z I [rscfg/rscfg03:27017] got command resync <ts: 1725602440> 2024-09-06T06:00:41Z I [rscfg/rscfg03:27017] got epoch {1725602435 21} 2024-09-06T06:00:41Z I [rscfg/rscfg03:27017] [resync] started 2024-09-06T06:00:41Z D [rscfg/rscfg03:27017] [resync] got backups list: 0 2024-09-06T06:00:41Z D [rscfg/rscfg03:27017] [resync] got physical restores list: 0 2024-09-06T06:00:41Z D [rscfg/rscfg03:27017] [resync] epoch set to {1725602441 7} 2024-09-06T06:00:41Z I [rscfg/rscfg03:27017] [resync] succeed 2024-09-06T06:00:41Z I [rscfg/rscfg01:27017] got command resync <ts: 1725602440> 2024-09-06T06:00:41Z I [rscfg/rscfg01:27017] got epoch {1725602441 7} 2024-09-06T06:00:41Z I [rscfg/rscfg02:27017] got command resync <ts: 1725602440> 2024-09-06T06:00:41Z D [rscfg/rscfg01:27017] [resync] get lock: duplicate operation: 66da9a880c2055ffd84fd3b8 [Resync storage] 2024-09-06T06:00:41Z I [rscfg/rscfg02:27017] got epoch {1725602441 7} 2024-09-06T06:00:41Z D [rscfg/rscfg01:27017] [resync] lock not acquired 2024-09-06T06:00:41Z I [rscfg/rscfg01:27017] got command backup [name: 2024-09-06T06:00:41Z, compression: none (level: default)] <ts: 1725602441> 2024-09-06T06:00:41Z I [rscfg/rscfg01:27017] got epoch {1725602441 7} 2024-09-06T06:00:41Z I [rs2/rs203:27017] got command backup [name: 2024-09-06T06:00:41Z, compression: none (level: default)] <ts: 1725602441> 2024-09-06T06:00:41Z I [rs2/rs203:27017] got epoch {1725602441 7} 2024-09-06T06:00:41Z E [rscfg/rscfg01:27017] [backup/2024-09-06T06:00:41Z] unable to proceed with the backup, active lock is present 2024-09-06T06:00:41Z D [rscfg/rscfg02:27017] [resync] get lock: duplicate operation: 66da9a880c2055ffd84fd3b8 [Resync storage] 2024-09-06T06:00:41Z I [rs2/rs202:27017] got command backup [name: 2024-09-06T06:00:41Z, compression: none (level: default)] <ts: 1725602441> 2024-09-06T06:00:41Z D [rscfg/rscfg02:27017] [resync] lock not acquired 2024-09-06T06:00:41Z I [rscfg/rscfg02:27017] got command backup [name: 2024-09-06T06:00:41Z, compression: none (level: default)] <ts: 1725602441> 2024-09-06T06:00:41Z I [rs2/rs202:27017] got epoch {1725602441 7} 2024-09-06T06:00:41Z I [rscfg/rscfg02:27017] got epoch {1725602441 7} 2024-09-06T06:00:41Z I [rs2/rs201:27017] got command backup [name: 2024-09-06T06:00:41Z, compression: none (level: default)] <ts: 1725602441> 2024-09-06T06:00:41Z I [rs1/rs103:27017] got command backup [name: 2024-09-06T06:00:41Z, compression: none (level: default)] <ts: 1725602441> 2024-09-06T06:00:41Z I [rs1/rs102:27017] got command backup [name: 2024-09-06T06:00:41Z, compression: none (level: default)] <ts: 1725602441> 2024-09-06T06:00:41Z I [rs1/rs103:27017] got epoch {1725602441 7} 2024-09-06T06:00:41Z I [rs2/rs201:27017] got epoch {1725602441 7} 2024-09-06T06:00:41Z I [rs1/rs102:27017] got epoch {1725602441 7} 2024-09-06T06:00:41Z I [rs1/rs101:27017] got command backup [name: 2024-09-06T06:00:41Z, compression: none (level: default)] <ts: 1725602441> 2024-09-06T06:00:41Z I [rs1/rs101:27017] got epoch {1725602441 7} 2024-09-06T06:00:42Z I [rscfg/rscfg03:27017] got command backup [name: 2024-09-06T06:00:41Z, compression: none (level: default)] <ts: 1725602441> 2024-09-06T06:00:42Z I [rscfg/rscfg03:27017] got epoch {1725602441 7} 2024-09-06T06:00:56Z D [rs2/rs203:27017] [backup/2024-09-06T06:00:41Z] nomination timeout 2024-09-06T06:00:56Z D [rs2/rs203:27017] [backup/2024-09-06T06:00:41Z] skip after nomination, probably started by another node 2024-09-06T06:00:56Z D [rs2/rs202:27017] [backup/2024-09-06T06:00:41Z] nomination timeout 2024-09-06T06:00:56Z D [rs2/rs202:27017] [backup/2024-09-06T06:00:41Z] skip after nomination, probably started by another node 2024-09-06T06:00:56Z D [rscfg/rscfg02:27017] [backup/2024-09-06T06:00:41Z] nomination timeout 2024-09-06T06:00:56Z D [rscfg/rscfg02:27017] [backup/2024-09-06T06:00:41Z] skip after nomination, probably started by another node 2024-09-06T06:00:56Z D [rs1/rs103:27017] [backup/2024-09-06T06:00:41Z] nomination timeout 2024-09-06T06:00:56Z D [rs1/rs102:27017] [backup/2024-09-06T06:00:41Z] nomination timeout 2024-09-06T06:00:56Z D [rs2/rs201:27017] [backup/2024-09-06T06:00:41Z] nomination timeout 2024-09-06T06:00:56Z D [rs1/rs103:27017] [backup/2024-09-06T06:00:41Z] skip after nomination, probably started by another node 2024-09-06T06:00:56Z D [rs1/rs101:27017] [backup/2024-09-06T06:00:41Z] nomination timeout 2024-09-06T06:00:56Z D [rs1/rs102:27017] [backup/2024-09-06T06:00:41Z] skip after nomination, probably started by another node 2024-09-06T06:00:56Z D [rs2/rs201:27017] [backup/2024-09-06T06:00:41Z] skip after nomination, probably started by another node 2024-09-06T06:00:56Z D [rs1/rs101:27017] [backup/2024-09-06T06:00:41Z] skip after nomination, probably started by another node 2024-09-06T06:00:57Z D [rscfg/rscfg03:27017] [backup/2024-09-06T06:00:41Z] nomination timeout 2024-09-06T06:00:57Z D [rscfg/rscfg03:27017] [backup/2024-09-06T06:00:41Z] skip after nomination, probably started by another node