AssertionError: Cannot start restore, another operation running: {'type': 'backup', 'opID': '66ed347d1e61eeb19ac415c9', 'name': '2024-09-20T08:38:21Z', 'startTS': 1726821502, 'status': 'copyDone'} 2024-09-20T08:38:00Z I [rs1/rs102:27017] pbm-agent: Version: 2.6.0 Platform: linux/amd64 GitCommit: e834e3f3c48f1e8324a977111071e444d1d6028d GitBranch: CURRENT_PR BuildTime: 2024-09-20_08:37_UTC GoVersion: go1.22.7 2024-09-20T08:38:00Z I [rs1/rs103:27017] pbm-agent: Version: 2.6.0 Platform: linux/amd64 GitCommit: e834e3f3c48f1e8324a977111071e444d1d6028d GitBranch: CURRENT_PR BuildTime: 2024-09-20_08:37_UTC GoVersion: go1.22.7 2024-09-20T08:38:00Z I [rs1/rs101:27017] pbm-agent: Version: 2.6.0 Platform: linux/amd64 GitCommit: e834e3f3c48f1e8324a977111071e444d1d6028d GitBranch: CURRENT_PR BuildTime: 2024-09-20_08:37_UTC GoVersion: go1.22.7 2024-09-20T08:38:00Z I [rs1/rs102:27017] starting PITR routine 2024-09-20T08:38:00Z I [rs1/rs101:27017] starting PITR routine 2024-09-20T08:38:00Z I [rs1/rs103:27017] starting PITR routine 2024-09-20T08:38:00Z I [rs1/rs102:27017] node: rs1/rs102:27017 2024-09-20T08:38:00Z I [rs1/rs103:27017] node: rs1/rs103:27017 2024-09-20T08:38:00Z I [rs1/rs101:27017] node: rs1/rs101:27017 2024-09-20T08:38:00Z I [rs1/rs102:27017] conn level ReadConcern: majority; WriteConcern: majority 2024-09-20T08:38:00Z I [rs1/rs101:27017] conn level ReadConcern: majority; WriteConcern: majority 2024-09-20T08:38:00Z I [rs1/rs103:27017] conn level ReadConcern: majority; WriteConcern: majority 2024-09-20T08:38:00Z I [rs1/rs103:27017] listening for the commands 2024-09-20T08:38:00Z I [rs1/rs101:27017] listening for the commands 2024-09-20T08:38:00Z I [rs1/rs102:27017] listening for the commands 2024-09-20T08:38:01Z I [rs1/rs104:27017] pbm-agent: Version: 2.6.0 Platform: linux/amd64 GitCommit: e834e3f3c48f1e8324a977111071e444d1d6028d GitBranch: CURRENT_PR BuildTime: 2024-09-20_08:37_UTC GoVersion: go1.22.7 2024-09-20T08:38:01Z I [rs1/rs104:27017] node: rs1/rs104:27017 2024-09-20T08:38:01Z I [rs1/rs104:27017] conn level ReadConcern: majority; WriteConcern: majority 2024-09-20T08:38:01Z I [rs1/rs104:27017] listening for the commands 2024-09-20T08:38:05Z W [rs1/rs101:27017] [agentCheckup] get current storage status: query mongo: mongo: no documents in result 2024-09-20T08:38:05Z W [rs1/rs102:27017] [agentCheckup] get current storage status: query mongo: mongo: no documents in result 2024-09-20T08:38:05Z W [rs1/rs103:27017] [agentCheckup] get current storage status: query mongo: mongo: no documents in result 2024-09-20T08:38:05Z E [rs1/rs101:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result 2024-09-20T08:38:05Z E [rs1/rs102:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result 2024-09-20T08:38:05Z E [rs1/rs103:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result 2024-09-20T08:38:06Z W [rs1/rs104:27017] [agentCheckup] get current storage status: query mongo: mongo: no documents in result 2024-09-20T08:38:06Z E [rs1/rs104:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result 2024-09-20T08:38:10Z E [rs1/rs101:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result 2024-09-20T08:38:10Z E [rs1/rs102:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result 2024-09-20T08:38:10Z E [rs1/rs103:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result 2024-09-20T08:38:11Z W [rs1/rs104:27017] [agentCheckup] storage is not initialized 2024-09-20T08:38:11Z I [rs1/rs104:27017] got command resync <ts: 1726821491> 2024-09-20T08:38:12Z I [rs1/rs104:27017] got epoch {1726821490 6} 2024-09-20T08:38:12Z I [rs1/rs104:27017] [resync] started 2024-09-20T08:38:12Z D [rs1/rs104:27017] [resync] uploading ".pbm.init" [size hint: 5 (5.00B); part size: 10485760 (10.00MB)] 2024-09-20T08:38:12Z D [rs1/rs104:27017] [resync] got backups list: 0 2024-09-20T08:38:12Z D [rs1/rs104:27017] [resync] got physical restores list: 0 2024-09-20T08:38:12Z D [rs1/rs104:27017] [resync] epoch set to {1726821492 7} 2024-09-20T08:38:12Z I [rs1/rs104:27017] [resync] succeed 2024-09-20T08:38:12Z I [rs1/rs102:27017] got command resync <ts: 1726821491> 2024-09-20T08:38:12Z I [rs1/rs103:27017] got command resync <ts: 1726821491> 2024-09-20T08:38:12Z I [rs1/rs101:27017] got command resync <ts: 1726821491> 2024-09-20T08:38:12Z I [rs1/rs103:27017] got epoch {1726821492 7} 2024-09-20T08:38:12Z I [rs1/rs102:27017] got epoch {1726821492 7} 2024-09-20T08:38:12Z I [rs1/rs101:27017] got epoch {1726821492 7} 2024-09-20T08:38:12Z D [rs1/rs102:27017] [resync] lock not acquired 2024-09-20T08:38:12Z D [rs1/rs101:27017] [resync] lock not acquired 2024-09-20T08:38:12Z D [rs1/rs103:27017] [resync] get lock: duplicate operation: 66ed347387fa9f37b2655853 [Resync storage] 2024-09-20T08:38:12Z D [rs1/rs103:27017] [resync] lock not acquired 2024-09-20T08:38:22Z I [rs1/rs104:27017] got command backup [name: 2024-09-20T08:38:21Z, compression: s2 (level: default)] <ts: 1726821501> 2024-09-20T08:38:22Z I [rs1/rs104:27017] got epoch {1726821492 7} 2024-09-20T08:38:22Z I [rs1/rs102:27017] got command backup [name: 2024-09-20T08:38:21Z, compression: s2 (level: default)] <ts: 1726821501> 2024-09-20T08:38:22Z I [rs1/rs103:27017] got command backup [name: 2024-09-20T08:38:21Z, compression: s2 (level: default)] <ts: 1726821501> 2024-09-20T08:38:22Z I [rs1/rs101:27017] got command backup [name: 2024-09-20T08:38:21Z, compression: s2 (level: default)] <ts: 1726821501> 2024-09-20T08:38:22Z I [rs1/rs102:27017] got epoch {1726821492 7} 2024-09-20T08:38:22Z I [rs1/rs103:27017] got epoch {1726821492 7} 2024-09-20T08:38:22Z I [rs1/rs101:27017] got epoch {1726821492 7} 2024-09-20T08:38:22Z D [rs1/rs101:27017] [backup/2024-09-20T08:38:21Z] init backup meta 2024-09-20T08:38:22Z D [rs1/rs101:27017] [backup/2024-09-20T08:38:21Z] nomination list for rs1: [[rs103:27017] [rs102:27017] [rs101:27017]] 2024-09-20T08:38:22Z D [rs1/rs101:27017] [backup/2024-09-20T08:38:21Z] nomination rs1, set candidates [rs103:27017] 2024-09-20T08:38:22Z I [rs1/rs103:27017] [backup/2024-09-20T08:38:21Z] backup started 2024-09-20T08:38:22Z D [rs1/rs101:27017] [backup/2024-09-20T08:38:21Z] skip after nomination, probably started by another node 2024-09-20T08:38:23Z D [rs1/rs104:27017] [backup/2024-09-20T08:38:21Z] skip after nomination, probably started by another node 2024-09-20T08:38:23Z D [rs1/rs102:27017] [backup/2024-09-20T08:38:21Z] skip after nomination, probably started by another node 2024-09-20T08:38:23Z D [rs1/rs103:27017] [backup/2024-09-20T08:38:21Z] backup cursor id: e32b3593-0c93-4e44-b0cb-7efe2a15034c 2024-09-20T08:38:26Z D [rs1/rs103:27017] [backup/2024-09-20T08:38:21Z] set journal up to {1726821503 3} 2024-09-20T08:38:27Z D [rs1/rs101:27017] [backup/2024-09-20T08:38:21Z] bcp nomination: rs1 won by rs103:27017

AssertionError: Cannot start restore, another operation running: {'type': 'backup', 'opID': '66ed38f69f4b9ff2c26a2ec4', 'name': '2024-09-20T08:57:26Z', 'startTS': 1726822646, 'status': 'copyDone'} 2024-09-20T08:57:14Z I [rs1/rs103:27017] pbm-agent: Version: 2.6.0 Platform: linux/amd64 GitCommit: e834e3f3c48f1e8324a977111071e444d1d6028d GitBranch: CURRENT_PR BuildTime: 2024-09-20_08:37_UTC GoVersion: go1.22.7 2024-09-20T08:57:14Z I [rs1/rs103:27017] starting PITR routine 2024-09-20T08:57:14Z I [rs1/rs101:27017] pbm-agent: Version: 2.6.0 Platform: linux/amd64 GitCommit: e834e3f3c48f1e8324a977111071e444d1d6028d GitBranch: CURRENT_PR BuildTime: 2024-09-20_08:37_UTC GoVersion: go1.22.7 2024-09-20T08:57:14Z I [rs1/rs102:27017] pbm-agent: Version: 2.6.0 Platform: linux/amd64 GitCommit: e834e3f3c48f1e8324a977111071e444d1d6028d GitBranch: CURRENT_PR BuildTime: 2024-09-20_08:37_UTC GoVersion: go1.22.7 2024-09-20T08:57:14Z I [rs1/rs102:27017] starting PITR routine 2024-09-20T08:57:14Z I [rs1/rs101:27017] starting PITR routine 2024-09-20T08:57:14Z I [rs1/rs102:27017] node: rs1/rs102:27017 2024-09-20T08:57:14Z I [rs1/rs101:27017] node: rs1/rs101:27017 2024-09-20T08:57:14Z I [rs1/rs103:27017] node: rs1/rs103:27017 2024-09-20T08:57:14Z I [rs1/rs102:27017] conn level ReadConcern: majority; WriteConcern: majority 2024-09-20T08:57:14Z I [rs1/rs101:27017] conn level ReadConcern: majority; WriteConcern: majority 2024-09-20T08:57:14Z I [rs1/rs103:27017] conn level ReadConcern: majority; WriteConcern: majority 2024-09-20T08:57:14Z I [rs1/rs102:27017] listening for the commands 2024-09-20T08:57:14Z I [rs1/rs101:27017] listening for the commands 2024-09-20T08:57:14Z I [rs1/rs103:27017] listening for the commands 2024-09-20T08:57:19Z W [rs1/rs101:27017] [agentCheckup] get current storage status: query mongo: mongo: no documents in result 2024-09-20T08:57:19Z W [rs1/rs103:27017] [agentCheckup] get current storage status: query mongo: mongo: no documents in result 2024-09-20T08:57:19Z W [rs1/rs102:27017] [agentCheckup] get current storage status: query mongo: mongo: no documents in result 2024-09-20T08:57:19Z E [rs1/rs101:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result 2024-09-20T08:57:19Z E [rs1/rs103:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result 2024-09-20T08:57:19Z E [rs1/rs102:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result 2024-09-20T08:57:21Z I [rs1/rs102:27017] got command resync <ts: 1726822641> 2024-09-20T08:57:21Z I [rs1/rs103:27017] got command resync <ts: 1726822641> 2024-09-20T08:57:21Z I [rs1/rs101:27017] got command resync <ts: 1726822641> 2024-09-20T08:57:21Z I [rs1/rs102:27017] got epoch {1726822639 12} 2024-09-20T08:57:21Z I [rs1/rs101:27017] got epoch {1726822639 12} 2024-09-20T08:57:21Z I [rs1/rs103:27017] got epoch {1726822639 12} 2024-09-20T08:57:21Z D [rs1/rs103:27017] [resync] lock not acquired 2024-09-20T08:57:21Z D [rs1/rs101:27017] [resync] lock not acquired 2024-09-20T08:57:21Z I [rs1/rs102:27017] [resync] started 2024-09-20T08:57:21Z D [rs1/rs102:27017] [resync] uploading ".pbm.init" [size hint: 5 (5.00B); part size: 10485760 (10.00MB)] 2024-09-20T08:57:21Z E [rs1/rs102:27017] [resync] read metadata of backup 2024-09-20T08:41:06Z.pbm.json: open: get file stat: no such file 2024-09-20T08:57:21Z E [rs1/rs102:27017] [resync] read metadata of backup 2024-09-20T08:46:34Z.pbm.json: open: get file stat: no such file 2024-09-20T08:57:21Z E [rs1/rs102:27017] [resync] read metadata of backup 2024-09-20T08:52:04Z.pbm.json: open: get file stat: no such file 2024-09-20T08:57:21Z D [rs1/rs102:27017] [resync] got backups list: 0 2024-09-20T08:57:21Z D [rs1/rs102:27017] [resync] got physical restores list: 2 2024-09-20T08:57:22Z D [rs1/rs102:27017] [resync] epoch set to {1726822642 3} 2024-09-20T08:57:22Z I [rs1/rs102:27017] [resync] succeed 2024-09-20T08:57:26Z I [rs1/rs103:27017] got command backup [name: 2024-09-20T08:57:26Z, compression: s2 (level: default)] <ts: 1726822646> 2024-09-20T08:57:26Z I [rs1/rs102:27017] got command backup [name: 2024-09-20T08:57:26Z, compression: s2 (level: default)] <ts: 1726822646> 2024-09-20T08:57:26Z I [rs1/rs101:27017] got command backup [name: 2024-09-20T08:57:26Z, compression: s2 (level: default)] <ts: 1726822646> 2024-09-20T08:57:26Z I [rs1/rs103:27017] got epoch {1726822642 3} 2024-09-20T08:57:26Z I [rs1/rs102:27017] got epoch {1726822642 3} 2024-09-20T08:57:26Z I [rs1/rs101:27017] got epoch {1726822642 3} 2024-09-20T08:57:26Z D [rs1/rs101:27017] [backup/2024-09-20T08:57:26Z] init backup meta 2024-09-20T08:57:26Z D [rs1/rs101:27017] [backup/2024-09-20T08:57:26Z] nomination list for rs1: [[rs103:27017 rs102:27017] [rs101:27017]] 2024-09-20T08:57:26Z D [rs1/rs101:27017] [backup/2024-09-20T08:57:26Z] nomination rs1, set candidates [rs103:27017 rs102:27017] 2024-09-20T08:57:27Z D [rs1/rs102:27017] [backup/2024-09-20T08:57:26Z] skip: lock not acquired 2024-09-20T08:57:27Z I [rs1/rs103:27017] [backup/2024-09-20T08:57:26Z] backup started 2024-09-20T08:57:27Z D [rs1/rs101:27017] [backup/2024-09-20T08:57:26Z] skip after nomination, probably started by another node 2024-09-20T08:57:28Z D [rs1/rs103:27017] [backup/2024-09-20T08:57:26Z] backup cursor id: 86180e81-b1e6-4a52-8361-38da7b1e51d0 2024-09-20T08:57:31Z D [rs1/rs103:27017] [backup/2024-09-20T08:57:26Z] set journal up to {1726822648 1} 2024-09-20T08:57:31Z D [rs1/rs101:27017] [backup/2024-09-20T08:57:26Z] bcp nomination: rs1 won by rs103:27017

AssertionError: Cannot start restore, another operation running: {'type': 'backup', 'opID': '66ed347a198a586609c8e2d8', 'name': '2024-09-20T08:38:18Z', 'startTS': 1726821498, 'status': 'copyDone'} 2024-09-20T08:37:56Z I [rs1/rs102:27017] pbm-agent: Version: 2.6.0 Platform: linux/amd64 GitCommit: e834e3f3c48f1e8324a977111071e444d1d6028d GitBranch: CURRENT_PR BuildTime: 2024-09-20_08:36_UTC GoVersion: go1.22.7 2024-09-20T08:37:56Z I [rs1/rs102:27017] starting PITR routine 2024-09-20T08:37:56Z I [rs1/rs103:27017] pbm-agent: Version: 2.6.0 Platform: linux/amd64 GitCommit: e834e3f3c48f1e8324a977111071e444d1d6028d GitBranch: CURRENT_PR BuildTime: 2024-09-20_08:36_UTC GoVersion: go1.22.7 2024-09-20T08:37:56Z I [rs1/rs101:27017] starting PITR routine 2024-09-20T08:37:56Z I [rs1/rs103:27017] starting PITR routine 2024-09-20T08:37:56Z I [rs1/rs101:27017] pbm-agent: Version: 2.6.0 Platform: linux/amd64 GitCommit: e834e3f3c48f1e8324a977111071e444d1d6028d GitBranch: CURRENT_PR BuildTime: 2024-09-20_08:36_UTC GoVersion: go1.22.7 2024-09-20T08:37:56Z I [rs1/rs102:27017] node: rs1/rs102:27017 2024-09-20T08:37:56Z I [rs1/rs103:27017] node: rs1/rs103:27017 2024-09-20T08:37:56Z I [rs1/rs101:27017] node: rs1/rs101:27017 2024-09-20T08:37:56Z I [rs1/rs103:27017] conn level ReadConcern: majority; WriteConcern: majority 2024-09-20T08:37:56Z I [rs1/rs102:27017] conn level ReadConcern: majority; WriteConcern: majority 2024-09-20T08:37:56Z I [rs1/rs101:27017] conn level ReadConcern: majority; WriteConcern: majority 2024-09-20T08:37:56Z I [rs1/rs103:27017] listening for the commands 2024-09-20T08:37:56Z I [rs1/rs102:27017] listening for the commands 2024-09-20T08:37:56Z I [rs1/rs101:27017] listening for the commands 2024-09-20T08:37:57Z I [rs1/rs104:27017] pbm-agent: Version: 2.6.0 Platform: linux/amd64 GitCommit: e834e3f3c48f1e8324a977111071e444d1d6028d GitBranch: CURRENT_PR BuildTime: 2024-09-20_08:36_UTC GoVersion: go1.22.7 2024-09-20T08:37:57Z I [rs1/rs104:27017] node: rs1/rs104:27017 2024-09-20T08:37:57Z I [rs1/rs104:27017] conn level ReadConcern: majority; WriteConcern: majority 2024-09-20T08:37:57Z I [rs1/rs104:27017] listening for the commands 2024-09-20T08:38:01Z W [rs1/rs101:27017] [agentCheckup] get current storage status: query mongo: mongo: no documents in result 2024-09-20T08:38:01Z W [rs1/rs103:27017] [agentCheckup] get current storage status: query mongo: mongo: no documents in result 2024-09-20T08:38:01Z W [rs1/rs102:27017] [agentCheckup] get current storage status: query mongo: mongo: no documents in result 2024-09-20T08:38:01Z E [rs1/rs101:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result 2024-09-20T08:38:01Z E [rs1/rs103:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result 2024-09-20T08:38:01Z E [rs1/rs102:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result 2024-09-20T08:38:02Z W [rs1/rs104:27017] [agentCheckup] get current storage status: query mongo: mongo: no documents in result 2024-09-20T08:38:02Z E [rs1/rs104:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result 2024-09-20T08:38:06Z E [rs1/rs101:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result 2024-09-20T08:38:06Z E [rs1/rs102:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result 2024-09-20T08:38:06Z E [rs1/rs103:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result 2024-09-20T08:38:07Z E [rs1/rs104:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result 2024-09-20T08:38:08Z I [rs1/rs104:27017] got command resync <ts: 1726821488> 2024-09-20T08:38:08Z I [rs1/rs104:27017] got epoch {1726821487 2} 2024-09-20T08:38:08Z I [rs1/rs104:27017] [resync] started 2024-09-20T08:38:08Z I [rs1/rs103:27017] got command resync <ts: 1726821488> 2024-09-20T08:38:08Z I [rs1/rs102:27017] got command resync <ts: 1726821488> 2024-09-20T08:38:08Z I [rs1/rs101:27017] got command resync <ts: 1726821488> 2024-09-20T08:38:08Z D [rs1/rs104:27017] [resync] uploading ".pbm.init" [size hint: 5 (5.00B); part size: 10485760 (10.00MB)] 2024-09-20T08:38:08Z I [rs1/rs102:27017] got epoch {1726821487 2} 2024-09-20T08:38:08Z I [rs1/rs103:27017] got epoch {1726821487 2} 2024-09-20T08:38:08Z I [rs1/rs101:27017] got epoch {1726821487 2} 2024-09-20T08:38:08Z D [rs1/rs103:27017] [resync] lock not acquired 2024-09-20T08:38:08Z D [rs1/rs102:27017] [resync] lock not acquired 2024-09-20T08:38:08Z D [rs1/rs101:27017] [resync] lock not acquired 2024-09-20T08:38:08Z D [rs1/rs104:27017] [resync] got backups list: 0 2024-09-20T08:38:08Z D [rs1/rs104:27017] [resync] got physical restores list: 0 2024-09-20T08:38:08Z D [rs1/rs104:27017] [resync] epoch set to {1726821488 23} 2024-09-20T08:38:08Z I [rs1/rs104:27017] [resync] succeed 2024-09-20T08:38:18Z I [rs1/rs104:27017] got command backup [name: 2024-09-20T08:38:18Z, compression: s2 (level: default)] <ts: 1726821498> 2024-09-20T08:38:18Z I [rs1/rs104:27017] got epoch {1726821488 23} 2024-09-20T08:38:18Z I [rs1/rs102:27017] got command backup [name: 2024-09-20T08:38:18Z, compression: s2 (level: default)] <ts: 1726821498> 2024-09-20T08:38:18Z I [rs1/rs103:27017] got command backup [name: 2024-09-20T08:38:18Z, compression: s2 (level: default)] <ts: 1726821498> 2024-09-20T08:38:18Z I [rs1/rs101:27017] got command backup [name: 2024-09-20T08:38:18Z, compression: s2 (level: default)] <ts: 1726821498> 2024-09-20T08:38:18Z I [rs1/rs102:27017] got epoch {1726821488 23} 2024-09-20T08:38:18Z I [rs1/rs103:27017] got epoch {1726821488 23} 2024-09-20T08:38:18Z I [rs1/rs101:27017] got epoch {1726821488 23} 2024-09-20T08:38:18Z D [rs1/rs101:27017] [backup/2024-09-20T08:38:18Z] init backup meta 2024-09-20T08:38:18Z D [rs1/rs101:27017] [backup/2024-09-20T08:38:18Z] nomination list for rs1: [[rs103:27017] [rs102:27017] [rs101:27017]] 2024-09-20T08:38:18Z D [rs1/rs101:27017] [backup/2024-09-20T08:38:18Z] nomination rs1, set candidates [rs103:27017] 2024-09-20T08:38:19Z I [rs1/rs103:27017] [backup/2024-09-20T08:38:18Z] backup started 2024-09-20T08:38:19Z D [rs1/rs101:27017] [backup/2024-09-20T08:38:18Z] skip after nomination, probably started by another node 2024-09-20T08:38:19Z D [rs1/rs104:27017] [backup/2024-09-20T08:38:18Z] skip after nomination, probably started by another node 2024-09-20T08:38:19Z D [rs1/rs102:27017] [backup/2024-09-20T08:38:18Z] skip after nomination, probably started by another node 2024-09-20T08:38:20Z D [rs1/rs103:27017] [backup/2024-09-20T08:38:18Z] backup cursor id: c821cd88-1d0e-43e6-80eb-de6f0de87d7a 2024-09-20T08:38:23Z D [rs1/rs103:27017] [backup/2024-09-20T08:38:18Z] set journal up to {1726821500 1} 2024-09-20T08:38:23Z D [rs1/rs101:27017] [backup/2024-09-20T08:38:18Z] bcp nomination: rs1 won by rs103:27017

AssertionError: Cannot start restore, another operation running: {'type': 'backup', 'opID': '66ed390421d8aea213f90a2a', 'name': '2024-09-20T08:57:40Z', 'startTS': 1726822660, 'status': 'copyDone'} 2024-09-20T08:57:28Z I [rs1/rs102:27017] pbm-agent: Version: 2.6.0 Platform: linux/amd64 GitCommit: e834e3f3c48f1e8324a977111071e444d1d6028d GitBranch: CURRENT_PR BuildTime: 2024-09-20_08:36_UTC GoVersion: go1.22.7 2024-09-20T08:57:28Z I [rs1/rs102:27017] starting PITR routine 2024-09-20T08:57:28Z I [rs1/rs101:27017] pbm-agent: Version: 2.6.0 Platform: linux/amd64 GitCommit: e834e3f3c48f1e8324a977111071e444d1d6028d GitBranch: CURRENT_PR BuildTime: 2024-09-20_08:36_UTC GoVersion: go1.22.7 2024-09-20T08:57:28Z I [rs1/rs103:27017] pbm-agent: Version: 2.6.0 Platform: linux/amd64 GitCommit: e834e3f3c48f1e8324a977111071e444d1d6028d GitBranch: CURRENT_PR BuildTime: 2024-09-20_08:36_UTC GoVersion: go1.22.7 2024-09-20T08:57:28Z I [rs1/rs101:27017] starting PITR routine 2024-09-20T08:57:28Z I [rs1/rs103:27017] starting PITR routine 2024-09-20T08:57:28Z I [rs1/rs102:27017] node: rs1/rs102:27017 2024-09-20T08:57:28Z I [rs1/rs101:27017] node: rs1/rs101:27017 2024-09-20T08:57:28Z I [rs1/rs103:27017] node: rs1/rs103:27017 2024-09-20T08:57:28Z I [rs1/rs102:27017] conn level ReadConcern: majority; WriteConcern: majority 2024-09-20T08:57:28Z I [rs1/rs101:27017] conn level ReadConcern: majority; WriteConcern: majority 2024-09-20T08:57:28Z I [rs1/rs103:27017] conn level ReadConcern: majority; WriteConcern: majority 2024-09-20T08:57:28Z I [rs1/rs102:27017] listening for the commands 2024-09-20T08:57:28Z I [rs1/rs101:27017] listening for the commands 2024-09-20T08:57:28Z I [rs1/rs103:27017] listening for the commands 2024-09-20T08:57:33Z W [rs1/rs101:27017] [agentCheckup] get current storage status: query mongo: mongo: no documents in result 2024-09-20T08:57:33Z W [rs1/rs102:27017] [agentCheckup] get current storage status: query mongo: mongo: no documents in result 2024-09-20T08:57:33Z W [rs1/rs103:27017] [agentCheckup] get current storage status: query mongo: mongo: no documents in result 2024-09-20T08:57:33Z E [rs1/rs101:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result 2024-09-20T08:57:33Z E [rs1/rs102:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result 2024-09-20T08:57:33Z E [rs1/rs103:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result 2024-09-20T08:57:35Z I [rs1/rs102:27017] got command resync <ts: 1726822655> 2024-09-20T08:57:35Z I [rs1/rs101:27017] got command resync <ts: 1726822655> 2024-09-20T08:57:35Z I [rs1/rs103:27017] got command resync <ts: 1726822655> 2024-09-20T08:57:35Z I [rs1/rs102:27017] got epoch {1726822653 12} 2024-09-20T08:57:35Z I [rs1/rs101:27017] got epoch {1726822653 12} 2024-09-20T08:57:35Z I [rs1/rs103:27017] got epoch {1726822653 12} 2024-09-20T08:57:35Z D [rs1/rs101:27017] [resync] lock not acquired 2024-09-20T08:57:35Z D [rs1/rs103:27017] [resync] lock not acquired 2024-09-20T08:57:35Z I [rs1/rs102:27017] [resync] started 2024-09-20T08:57:35Z D [rs1/rs102:27017] [resync] uploading ".pbm.init" [size hint: 5 (5.00B); part size: 10485760 (10.00MB)] 2024-09-20T08:57:35Z E [rs1/rs102:27017] [resync] read metadata of backup 2024-09-20T08:41:06Z.pbm.json: open: get file stat: no such file 2024-09-20T08:57:35Z E [rs1/rs102:27017] [resync] read metadata of backup 2024-09-20T08:46:50Z.pbm.json: open: get file stat: no such file 2024-09-20T08:57:35Z E [rs1/rs102:27017] [resync] read metadata of backup 2024-09-20T08:52:11Z.pbm.json: open: get file stat: no such file 2024-09-20T08:57:35Z D [rs1/rs102:27017] [resync] got backups list: 0 2024-09-20T08:57:35Z D [rs1/rs102:27017] [resync] got physical restores list: 2 2024-09-20T08:57:36Z D [rs1/rs102:27017] [resync] epoch set to {1726822655 25} 2024-09-20T08:57:36Z I [rs1/rs102:27017] [resync] succeed 2024-09-20T08:57:40Z I [rs1/rs101:27017] got command backup [name: 2024-09-20T08:57:40Z, compression: s2 (level: default)] <ts: 1726822660> 2024-09-20T08:57:40Z I [rs1/rs102:27017] got command backup [name: 2024-09-20T08:57:40Z, compression: s2 (level: default)] <ts: 1726822660> 2024-09-20T08:57:40Z I [rs1/rs103:27017] got command backup [name: 2024-09-20T08:57:40Z, compression: s2 (level: default)] <ts: 1726822660> 2024-09-20T08:57:40Z I [rs1/rs101:27017] got epoch {1726822655 25} 2024-09-20T08:57:40Z I [rs1/rs102:27017] got epoch {1726822655 25} 2024-09-20T08:57:40Z I [rs1/rs103:27017] got epoch {1726822655 25} 2024-09-20T08:57:40Z D [rs1/rs101:27017] [backup/2024-09-20T08:57:40Z] init backup meta 2024-09-20T08:57:40Z D [rs1/rs101:27017] [backup/2024-09-20T08:57:40Z] nomination list for rs1: [[rs102:27017 rs103:27017] [rs101:27017]] 2024-09-20T08:57:40Z D [rs1/rs101:27017] [backup/2024-09-20T08:57:40Z] nomination rs1, set candidates [rs102:27017 rs103:27017] 2024-09-20T08:57:41Z D [rs1/rs103:27017] [backup/2024-09-20T08:57:40Z] skip: lock not acquired 2024-09-20T08:57:41Z I [rs1/rs102:27017] [backup/2024-09-20T08:57:40Z] backup started 2024-09-20T08:57:41Z D [rs1/rs101:27017] [backup/2024-09-20T08:57:40Z] skip after nomination, probably started by another node 2024-09-20T08:57:42Z D [rs1/rs102:27017] [backup/2024-09-20T08:57:40Z] backup cursor id: 8a61be52-86fe-4af3-adfb-f789b36eb658 2024-09-20T08:57:45Z D [rs1/rs102:27017] [backup/2024-09-20T08:57:40Z] set journal up to {1726822662 1} 2024-09-20T08:57:45Z D [rs1/rs101:27017] [backup/2024-09-20T08:57:40Z] bcp nomination: rs1 won by rs102:27017

AssertionError: Cannot start restore, another operation running: {'type': 'backup', 'opID': '66ed395554fc74192b92fdbe', 'name': '2024-09-20T08:59:01Z', 'startTS': 1726822741, 'status': 'copyDone'} 2024-09-20T08:58:49Z I [rs1/rs101:27017] pbm-agent: Version: 2.6.0 Platform: linux/amd64 GitCommit: e834e3f3c48f1e8324a977111071e444d1d6028d GitBranch: CURRENT_PR BuildTime: 2024-09-20_08:36_UTC GoVersion: go1.22.7 2024-09-20T08:58:49Z I [rs1/rs102:27017] pbm-agent: Version: 2.6.0 Platform: linux/amd64 GitCommit: e834e3f3c48f1e8324a977111071e444d1d6028d GitBranch: CURRENT_PR BuildTime: 2024-09-20_08:36_UTC GoVersion: go1.22.7 2024-09-20T08:58:49Z I [rs1/rs103:27017] starting PITR routine 2024-09-20T08:58:49Z I [rs1/rs102:27017] starting PITR routine 2024-09-20T08:58:49Z I [rs1/rs101:27017] starting PITR routine 2024-09-20T08:58:49Z I [rs1/rs103:27017] pbm-agent: Version: 2.6.0 Platform: linux/amd64 GitCommit: e834e3f3c48f1e8324a977111071e444d1d6028d GitBranch: CURRENT_PR BuildTime: 2024-09-20_08:36_UTC GoVersion: go1.22.7 2024-09-20T08:58:49Z I [rs1/rs102:27017] node: rs1/rs102:27017 2024-09-20T08:58:49Z I [rs1/rs101:27017] node: rs1/rs101:27017 2024-09-20T08:58:49Z I [rs1/rs103:27017] node: rs1/rs103:27017 2024-09-20T08:58:49Z I [rs1/rs102:27017] conn level ReadConcern: majority; WriteConcern: majority 2024-09-20T08:58:49Z I [rs1/rs101:27017] conn level ReadConcern: majority; WriteConcern: majority 2024-09-20T08:58:49Z I [rs1/rs103:27017] conn level ReadConcern: majority; WriteConcern: majority 2024-09-20T08:58:49Z I [rs1/rs102:27017] listening for the commands 2024-09-20T08:58:49Z I [rs1/rs101:27017] listening for the commands 2024-09-20T08:58:49Z I [rs1/rs103:27017] listening for the commands 2024-09-20T08:58:54Z W [rs1/rs101:27017] [agentCheckup] get current storage status: query mongo: mongo: no documents in result 2024-09-20T08:58:54Z W [rs1/rs102:27017] [agentCheckup] get current storage status: query mongo: mongo: no documents in result 2024-09-20T08:58:54Z E [rs1/rs101:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result 2024-09-20T08:58:54Z E [rs1/rs102:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result 2024-09-20T08:58:54Z W [rs1/rs103:27017] [agentCheckup] get current storage status: query mongo: mongo: no documents in result 2024-09-20T08:58:54Z E [rs1/rs103:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result 2024-09-20T08:58:56Z I [rs1/rs103:27017] got command resync <ts: 1726822736> 2024-09-20T08:58:56Z I [rs1/rs102:27017] got command resync <ts: 1726822736> 2024-09-20T08:58:56Z I [rs1/rs102:27017] got epoch {1726822734 12} 2024-09-20T08:58:56Z I [rs1/rs101:27017] got command resync <ts: 1726822736> 2024-09-20T08:58:56Z I [rs1/rs103:27017] got epoch {1726822734 12} 2024-09-20T08:58:56Z I [rs1/rs101:27017] got epoch {1726822734 12} 2024-09-20T08:58:56Z D [rs1/rs103:27017] [resync] lock not acquired 2024-09-20T08:58:56Z I [rs1/rs102:27017] [resync] started 2024-09-20T08:58:56Z D [rs1/rs101:27017] [resync] lock not acquired 2024-09-20T08:58:57Z D [rs1/rs102:27017] [resync] uploading ".pbm.init" [size hint: 5 (5.00B); part size: 10485760 (10.00MB)] 2024-09-20T08:58:57Z E [rs1/rs102:27017] [resync] read metadata of backup 2024-09-20T08:38:21Z.pbm.json: open: get file stat: no such file 2024-09-20T08:58:57Z E [rs1/rs102:27017] [resync] read metadata of backup 2024-09-20T08:42:53Z.pbm.json: open: get file stat: no such file 2024-09-20T08:58:57Z E [rs1/rs102:27017] [resync] read metadata of backup 2024-09-20T08:48:08Z.pbm.json: open: get file stat: no such file 2024-09-20T08:58:57Z E [rs1/rs102:27017] [resync] read metadata of backup 2024-09-20T08:53:36Z.pbm.json: open: get file stat: no such file 2024-09-20T08:58:57Z D [rs1/rs102:27017] [resync] got backups list: 0 2024-09-20T08:58:57Z D [rs1/rs102:27017] [resync] got physical restores list: 2 2024-09-20T08:58:57Z D [rs1/rs102:27017] [resync] epoch set to {1726822737 10} 2024-09-20T08:58:57Z I [rs1/rs102:27017] [resync] succeed 2024-09-20T08:59:01Z I [rs1/rs102:27017] got command backup [name: 2024-09-20T08:59:01Z, compression: s2 (level: default)] <ts: 1726822741> 2024-09-20T08:59:01Z I [rs1/rs103:27017] got command backup [name: 2024-09-20T08:59:01Z, compression: s2 (level: default)] <ts: 1726822741> 2024-09-20T08:59:01Z I [rs1/rs102:27017] got epoch {1726822737 10} 2024-09-20T08:59:01Z I [rs1/rs101:27017] got command backup [name: 2024-09-20T08:59:01Z, compression: s2 (level: default)] <ts: 1726822741> 2024-09-20T08:59:01Z I [rs1/rs103:27017] got epoch {1726822737 10} 2024-09-20T08:59:01Z I [rs1/rs101:27017] got epoch {1726822737 10} 2024-09-20T08:59:01Z D [rs1/rs101:27017] [backup/2024-09-20T08:59:01Z] init backup meta 2024-09-20T08:59:02Z D [rs1/rs101:27017] [backup/2024-09-20T08:59:01Z] nomination list for rs1: [[rs102:27017 rs103:27017] [rs101:27017]] 2024-09-20T08:59:02Z D [rs1/rs101:27017] [backup/2024-09-20T08:59:01Z] nomination rs1, set candidates [rs102:27017 rs103:27017] 2024-09-20T08:59:02Z D [rs1/rs103:27017] [backup/2024-09-20T08:59:01Z] skip: lock not acquired 2024-09-20T08:59:02Z I [rs1/rs102:27017] [backup/2024-09-20T08:59:01Z] backup started 2024-09-20T08:59:02Z D [rs1/rs101:27017] [backup/2024-09-20T08:59:01Z] skip after nomination, probably started by another node 2024-09-20T08:59:03Z D [rs1/rs102:27017] [backup/2024-09-20T08:59:01Z] backup cursor id: 3267c895-33ae-40c4-8bc7-8039dc55f528 2024-09-20T08:59:06Z D [rs1/rs102:27017] [backup/2024-09-20T08:59:01Z] set journal up to {1726822743 1} 2024-09-20T08:59:07Z D [rs1/rs101:27017] [backup/2024-09-20T08:59:01Z] bcp nomination: rs1 won by rs102:27017

AssertionError: Error: backup '2024-09-20T09:06:56Z' not found

AssertionError: Error: backup '2024-09-20T09:12:53Z' not found

AssertionError: Error: backup '2024-09-20T09:06:33Z' not found

AssertionError: Error: backup '2024-09-20T09:12:27Z' not found

AssertionError: Error: backup '2024-09-20T09:07:33Z' not found

AssertionError: Error: backup '2024-09-20T09:13:36Z' not found

AssertionError: Error: no base snapshot found

AssertionError: Error: no base snapshot found

AssertionError: Error: backup '2024-09-20T09:09:49Z' not found

AssertionError: Error: backup '2024-09-20T09:24:04Z' not found

AssertionError: Error: backup '2024-09-20T09:28:41Z' not found

AssertionError: Error: backup '2024-09-20T09:30:05Z' not found

AssertionError: Error: backup '2024-09-20T09:33:59Z' not found

AssertionError: Error: no base snapshot found

AssertionError: Error: no base snapshot found

AssertionError: Error: backup '2024-09-20T09:09:58Z' not found

AssertionError: Error: backup '2024-09-20T09:24:17Z' not found

AssertionError: Error: backup '2024-09-20T09:29:06Z' not found

AssertionError: Error: backup '2024-09-20T09:30:19Z' not found

AssertionError: Error: backup '2024-09-20T09:34:19Z' not found

AssertionError: Error: no base snapshot found

AssertionError: Error: no base snapshot found

AssertionError: Error: backup '2024-09-20T09:09:56Z' not found

AssertionError: Error: backup '2024-09-20T09:24:25Z' not found

AssertionError: Error: backup '2024-09-20T09:29:16Z' not found

AssertionError: Error: backup '2024-09-20T09:30:41Z' not found

AssertionError: Error: backup '2024-09-20T09:34:35Z' not found

AssertionError: Error: backup '2024-09-20T09:27:16Z' not found

AssertionError: Error: backup '2024-09-20T09:32:44Z' not found

AssertionError: Error: backup '2024-09-20T09:27:55Z' not found

AssertionError: Error: backup '2024-09-20T09:33:17Z' not found

AssertionError: Error: backup '2024-09-20T09:28:07Z' not found

AssertionError: Error: backup '2024-09-20T09:33:31Z' not found

The following actions use a deprecated Node.js version and will be forced to run on node20: github/codeql-action/upload-sarif@v2. For more info: https://github.blog/changelog/2024-03-07-github-actions-all-actions-will-run-on-node20-instead-of-node16-by-default/