AssertionError: assert 'cloning namespace (--ns-to) is already in use' in 'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n' + where 'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n' = CommandResult(backend=<testinfra.backend.docker.DockerBackend object at 0x7f3bf2117110>, exit_status=1, command=b'pbm ...'', _stderr=b'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n').stderr

AssertionError: Backup failed{"Error":"get backup metadata: get: context deadline exceeded"} 2024-11-13T10:42:55Z I [rs1/rs103:27017] pbm-agent: Version: 2.7.0 Platform: linux/amd64 GitCommit: 79478b12486e64faa442adaa26183969d9b9a16e GitBranch: dev BuildTime: 2024-11-13_09:38_UTC GoVersion: go1.23.3 2024-11-13T10:42:55Z I [rs1/rs101:27017] pbm-agent: Version: 2.7.0 Platform: linux/amd64 GitCommit: 79478b12486e64faa442adaa26183969d9b9a16e GitBranch: dev BuildTime: 2024-11-13_09:38_UTC GoVersion: go1.23.3 2024-11-13T10:42:55Z I [rs1/rs101:27017] starting PITR routine 2024-11-13T10:42:55Z I [rs1/rs103:27017] starting PITR routine 2024-11-13T10:42:55Z I [rs1/rs102:27017] starting PITR routine 2024-11-13T10:42:55Z I [rs1/rs102:27017] pbm-agent: Version: 2.7.0 Platform: linux/amd64 GitCommit: 79478b12486e64faa442adaa26183969d9b9a16e GitBranch: dev BuildTime: 2024-11-13_09:38_UTC GoVersion: go1.23.3 2024-11-13T10:42:55Z I [rs1/rs103:27017] node: rs1/rs103:27017 2024-11-13T10:42:55Z I [rs1/rs101:27017] node: rs1/rs101:27017 2024-11-13T10:42:55Z E [rs1/rs101:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result 2024-11-13T10:42:55Z E [rs1/rs103:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result 2024-11-13T10:42:55Z I [rs1/rs101:27017] conn level ReadConcern: majority; WriteConcern: majority 2024-11-13T10:42:55Z E [rs1/rs102:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result 2024-11-13T10:42:55Z I [rs1/rs103:27017] conn level ReadConcern: majority; WriteConcern: majority 2024-11-13T10:42:55Z I [rs1/rs101:27017] listening for the commands 2024-11-13T10:42:55Z I [rs1/rs102:27017] node: rs1/rs102:27017 2024-11-13T10:42:55Z I [rs1/rs103:27017] listening for the commands 2024-11-13T10:42:55Z I [rs1/rs102:27017] conn level ReadConcern: majority; WriteConcern: majority 2024-11-13T10:42:55Z I [rs1/rs102:27017] listening for the commands 2024-11-13T10:43:00Z E [rs1/rs102:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result 2024-11-13T10:43:00Z E [rs1/rs101:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result 2024-11-13T10:43:00Z E [rs1/rs103:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result 2024-11-13T10:43:02Z I [rs1/rs101:27017] got command resync <ts: 1731494581>, opid: 673482b5c56f177a17552c2d 2024-11-13T10:43:02Z I [rs1/rs103:27017] got command resync <ts: 1731494581>, opid: 673482b5c56f177a17552c2d 2024-11-13T10:43:02Z I [rs1/rs101:27017] got epoch {1731494580 6} 2024-11-13T10:43:02Z I [rs1/rs103:27017] got epoch {1731494580 6} 2024-11-13T10:43:02Z I [rs1/rs102:27017] got command resync <ts: 1731494581>, opid: 673482b5c56f177a17552c2d 2024-11-13T10:43:02Z I [rs1/rs102:27017] got epoch {1731494580 6} 2024-11-13T10:43:02Z D [rs1/rs103:27017] [resync] lock not acquired 2024-11-13T10:43:02Z I [rs1/rs101:27017] [resync] started 2024-11-13T10:43:02Z D [rs1/rs102:27017] [resync] lock not acquired 2024-11-13T10:43:02Z D [rs1/rs101:27017] [resync] uploading ".pbm.init" [size hint: 5 (5.00B); part size: 10485760 (10.00MB)] 2024-11-13T10:43:02Z D [rs1/rs101:27017] [resync] got backups list: 0 2024-11-13T10:43:02Z D [rs1/rs101:27017] [resync] got physical restores list: 0 2024-11-13T10:43:02Z D [rs1/rs101:27017] [resync] epoch set to {1731494582 16} 2024-11-13T10:43:02Z I [rs1/rs101:27017] [resync] succeed 2024-11-13T10:43:07Z I [rs1/rs103:27017] got command resync <ts: 1731494586>, opid: 673482ba028d9a064894f960 2024-11-13T10:43:07Z I [rs1/rs101:27017] got command resync <ts: 1731494586>, opid: 673482ba028d9a064894f960 2024-11-13T10:43:07Z I [rs1/rs103:27017] got epoch {1731494582 16} 2024-11-13T10:43:07Z I [rs1/rs101:27017] got epoch {1731494582 16} 2024-11-13T10:43:07Z I [rs1/rs102:27017] got command resync <ts: 1731494586>, opid: 673482ba028d9a064894f960 2024-11-13T10:43:07Z I [rs1/rs102:27017] got epoch {1731494582 16} 2024-11-13T10:43:07Z I [rs1/rs103:27017] [resync] started 2024-11-13T10:43:07Z D [rs1/rs101:27017] [resync] lock not acquired 2024-11-13T10:43:07Z I [rs1/rs101:27017] got command backup [name: 2024-11-13T10:43:07Z, compression: none (level: default)] <ts: 1731494587>, opid: 673482bb39af1745310cb9e7 2024-11-13T10:43:07Z D [rs1/rs102:27017] [resync] lock not acquired 2024-11-13T10:43:07Z D [rs1/rs103:27017] [resync] got backups list: 0 2024-11-13T10:43:07Z I [rs1/rs101:27017] got epoch {1731494582 16} 2024-11-13T10:43:07Z I [rs1/rs102:27017] got command backup [name: 2024-11-13T10:43:07Z, compression: none (level: default)] <ts: 1731494587>, opid: 673482bb39af1745310cb9e7 2024-11-13T10:43:07Z I [rs1/rs102:27017] got epoch {1731494582 16} 2024-11-13T10:43:07Z E [rs1/rs101:27017] [backup/2024-11-13T10:43:07Z] unable to proceed with the backup, active lock is present 2024-11-13T10:43:07Z D [rs1/rs103:27017] [resync] got physical restores list: 0 2024-11-13T10:43:07Z D [rs1/rs103:27017] [resync] epoch set to {1731494587 21} 2024-11-13T10:43:07Z I [rs1/rs103:27017] [resync] succeed 2024-11-13T10:43:07Z I [rs1/rs103:27017] got command backup [name: 2024-11-13T10:43:07Z, compression: none (level: default)] <ts: 1731494587>, opid: 673482bb39af1745310cb9e7 2024-11-13T10:43:07Z I [rs1/rs103:27017] got epoch {1731494587 21} 2024-11-13T10:43:22Z D [rs1/rs102:27017] [backup/2024-11-13T10:43:07Z] nomination timeout 2024-11-13T10:43:22Z D [rs1/rs102:27017] [backup/2024-11-13T10:43:07Z] skip after nomination, probably started by another node 2024-11-13T10:43:22Z D [rs1/rs103:27017] [backup/2024-11-13T10:43:07Z] nomination timeout 2024-11-13T10:43:22Z D [rs1/rs103:27017] [backup/2024-11-13T10:43:07Z] skip after nomination, probably started by another node

AssertionError: assert 'cloning namespace (--ns-to) is already in use' in 'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n' + where 'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n' = CommandResult(backend=<testinfra.backend.docker.DockerBackend object at 0x7f3bf2117110>, exit_status=1, command=b'pbm ...'', _stderr=b'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n').stderr

AssertionError: Backup failed{"Error":"get backup metadata: get: context deadline exceeded"} 2024-11-13T10:46:06Z I [rs1/rs103:27017] pbm-agent: Version: 2.7.0 Platform: linux/amd64 GitCommit: 79478b12486e64faa442adaa26183969d9b9a16e GitBranch: dev BuildTime: 2024-11-13_09:38_UTC GoVersion: go1.23.3 2024-11-13T10:46:06Z I [rs1/rs103:27017] starting PITR routine 2024-11-13T10:46:06Z I [rs1/rs101:27017] pbm-agent: Version: 2.7.0 Platform: linux/amd64 GitCommit: 79478b12486e64faa442adaa26183969d9b9a16e GitBranch: dev BuildTime: 2024-11-13_09:38_UTC GoVersion: go1.23.3 2024-11-13T10:46:06Z I [rs1/rs101:27017] starting PITR routine 2024-11-13T10:46:06Z I [rs1/rs102:27017] pbm-agent: Version: 2.7.0 Platform: linux/amd64 GitCommit: 79478b12486e64faa442adaa26183969d9b9a16e GitBranch: dev BuildTime: 2024-11-13_09:38_UTC GoVersion: go1.23.3 2024-11-13T10:46:06Z I [rs1/rs102:27017] starting PITR routine 2024-11-13T10:46:06Z I [rs1/rs103:27017] node: rs1/rs103:27017 2024-11-13T10:46:06Z I [rs1/rs101:27017] node: rs1/rs101:27017 2024-11-13T10:46:06Z E [rs1/rs101:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result 2024-11-13T10:46:06Z E [rs1/rs102:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result 2024-11-13T10:46:06Z I [rs1/rs102:27017] node: rs1/rs102:27017 2024-11-13T10:46:06Z I [rs1/rs103:27017] conn level ReadConcern: majority; WriteConcern: majority 2024-11-13T10:46:06Z E [rs1/rs103:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result 2024-11-13T10:46:06Z I [rs1/rs101:27017] conn level ReadConcern: majority; WriteConcern: majority 2024-11-13T10:46:06Z I [rs1/rs103:27017] listening for the commands 2024-11-13T10:46:06Z I [rs1/rs102:27017] conn level ReadConcern: majority; WriteConcern: majority 2024-11-13T10:46:06Z I [rs1/rs101:27017] listening for the commands 2024-11-13T10:46:06Z I [rs1/rs102:27017] listening for the commands 2024-11-13T10:46:11Z E [rs1/rs101:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result 2024-11-13T10:46:11Z E [rs1/rs102:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result 2024-11-13T10:46:11Z E [rs1/rs103:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result 2024-11-13T10:46:14Z I [rs1/rs103:27017] got command resync <ts: 1731494773>, opid: 673483758b98b52f5b0a9bd4 2024-11-13T10:46:14Z I [rs1/rs103:27017] got epoch {1731494771 6} 2024-11-13T10:46:14Z I [rs1/rs102:27017] got command resync <ts: 1731494773>, opid: 673483758b98b52f5b0a9bd4 2024-11-13T10:46:14Z I [rs1/rs101:27017] got command resync <ts: 1731494773>, opid: 673483758b98b52f5b0a9bd4 2024-11-13T10:46:14Z I [rs1/rs102:27017] got epoch {1731494771 6} 2024-11-13T10:46:14Z I [rs1/rs101:27017] got epoch {1731494771 6} 2024-11-13T10:46:14Z D [rs1/rs102:27017] [resync] lock not acquired 2024-11-13T10:46:14Z I [rs1/rs103:27017] [resync] started 2024-11-13T10:46:14Z D [rs1/rs101:27017] [resync] lock not acquired 2024-11-13T10:46:14Z D [rs1/rs103:27017] [resync] uploading ".pbm.init" [size hint: 5 (5.00B); part size: 10485760 (10.00MB)] 2024-11-13T10:46:14Z D [rs1/rs103:27017] [resync] got backups list: 0 2024-11-13T10:46:14Z D [rs1/rs103:27017] [resync] got physical restores list: 0 2024-11-13T10:46:14Z D [rs1/rs103:27017] [resync] epoch set to {1731494774 16} 2024-11-13T10:46:14Z I [rs1/rs103:27017] [resync] succeed 2024-11-13T10:46:19Z I [rs1/rs103:27017] got command resync <ts: 1731494778>, opid: 6734837ac846a123a0f58d94 2024-11-13T10:46:19Z I [rs1/rs102:27017] got command resync <ts: 1731494778>, opid: 6734837ac846a123a0f58d94 2024-11-13T10:46:19Z I [rs1/rs103:27017] got epoch {1731494774 16} 2024-11-13T10:46:19Z I [rs1/rs101:27017] got command resync <ts: 1731494778>, opid: 6734837ac846a123a0f58d94 2024-11-13T10:46:19Z I [rs1/rs102:27017] got epoch {1731494774 16} 2024-11-13T10:46:19Z I [rs1/rs101:27017] got epoch {1731494774 16} 2024-11-13T10:46:19Z D [rs1/rs102:27017] [resync] lock not acquired 2024-11-13T10:46:19Z I [rs1/rs103:27017] [resync] started 2024-11-13T10:46:19Z D [rs1/rs101:27017] [resync] lock not acquired 2024-11-13T10:46:19Z I [rs1/rs102:27017] got command backup [name: 2024-11-13T10:46:19Z, compression: none (level: default)] <ts: 1731494779>, opid: 6734837be0169e51dbd11a75 2024-11-13T10:46:19Z D [rs1/rs103:27017] [resync] got backups list: 0 2024-11-13T10:46:19Z I [rs1/rs102:27017] got epoch {1731494774 16} 2024-11-13T10:46:19Z I [rs1/rs101:27017] got command backup [name: 2024-11-13T10:46:19Z, compression: none (level: default)] <ts: 1731494779>, opid: 6734837be0169e51dbd11a75 2024-11-13T10:46:19Z I [rs1/rs101:27017] got epoch {1731494774 16} 2024-11-13T10:46:19Z D [rs1/rs103:27017] [resync] got physical restores list: 0 2024-11-13T10:46:19Z E [rs1/rs101:27017] [backup/2024-11-13T10:46:19Z] unable to proceed with the backup, active lock is present 2024-11-13T10:46:19Z D [rs1/rs103:27017] [resync] epoch set to {1731494779 21} 2024-11-13T10:46:19Z I [rs1/rs103:27017] [resync] succeed 2024-11-13T10:46:19Z I [rs1/rs103:27017] got command backup [name: 2024-11-13T10:46:19Z, compression: none (level: default)] <ts: 1731494779>, opid: 6734837be0169e51dbd11a75 2024-11-13T10:46:19Z I [rs1/rs103:27017] got epoch {1731494779 21} 2024-11-13T10:46:34Z D [rs1/rs102:27017] [backup/2024-11-13T10:46:19Z] nomination timeout 2024-11-13T10:46:34Z D [rs1/rs102:27017] [backup/2024-11-13T10:46:19Z] skip after nomination, probably started by another node 2024-11-13T10:46:34Z D [rs1/rs103:27017] [backup/2024-11-13T10:46:19Z] nomination timeout 2024-11-13T10:46:34Z D [rs1/rs103:27017] [backup/2024-11-13T10:46:19Z] skip after nomination, probably started by another node

AssertionError: assert 'cloning namespace (--ns-to) is already in use' in 'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n' + where 'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n' = CommandResult(backend=<testinfra.backend.docker.DockerBackend object at 0x7f3bf2117110>, exit_status=1, command=b'pbm ...'', _stderr=b'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n').stderr

AssertionError: assert 'cloning namespace (--ns-to) is already in use' in 'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n' + where 'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n' = CommandResult(backend=<testinfra.backend.docker.DockerBackend object at 0x7f3bf2117110>, exit_status=1, command=b'pbm ...'', _stderr=b'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n').stderr

AssertionError: Backup failed{"Error":"get backup metadata: get: context deadline exceeded"} 2024-11-13T10:51:08Z I [rs1/rs103:27017] pbm-agent: Version: 2.7.0 Platform: linux/amd64 GitCommit: 79478b12486e64faa442adaa26183969d9b9a16e GitBranch: dev BuildTime: 2024-11-13_09:38_UTC GoVersion: go1.23.3 2024-11-13T10:51:08Z I [rs1/rs103:27017] starting PITR routine 2024-11-13T10:51:08Z I [rs1/rs102:27017] pbm-agent: Version: 2.7.0 Platform: linux/amd64 GitCommit: 79478b12486e64faa442adaa26183969d9b9a16e GitBranch: dev BuildTime: 2024-11-13_09:38_UTC GoVersion: go1.23.3 2024-11-13T10:51:08Z I [rs1/rs101:27017] pbm-agent: Version: 2.7.0 Platform: linux/amd64 GitCommit: 79478b12486e64faa442adaa26183969d9b9a16e GitBranch: dev BuildTime: 2024-11-13_09:38_UTC GoVersion: go1.23.3 2024-11-13T10:51:08Z I [rs1/rs101:27017] starting PITR routine 2024-11-13T10:51:08Z I [rs1/rs102:27017] starting PITR routine 2024-11-13T10:51:08Z I [rs1/rs102:27017] node: rs1/rs102:27017 2024-11-13T10:51:08Z E [rs1/rs101:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result 2024-11-13T10:51:08Z I [rs1/rs103:27017] node: rs1/rs103:27017 2024-11-13T10:51:08Z E [rs1/rs102:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result 2024-11-13T10:51:08Z I [rs1/rs101:27017] node: rs1/rs101:27017 2024-11-13T10:51:08Z E [rs1/rs103:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result 2024-11-13T10:51:08Z I [rs1/rs102:27017] conn level ReadConcern: majority; WriteConcern: majority 2024-11-13T10:51:08Z I [rs1/rs103:27017] conn level ReadConcern: majority; WriteConcern: majority 2024-11-13T10:51:08Z I [rs1/rs101:27017] conn level ReadConcern: majority; WriteConcern: majority 2024-11-13T10:51:08Z I [rs1/rs102:27017] listening for the commands 2024-11-13T10:51:08Z I [rs1/rs103:27017] listening for the commands 2024-11-13T10:51:08Z I [rs1/rs101:27017] listening for the commands 2024-11-13T10:51:13Z E [rs1/rs101:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result 2024-11-13T10:51:13Z E [rs1/rs102:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result 2024-11-13T10:51:13Z E [rs1/rs103:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result 2024-11-13T10:51:15Z I [rs1/rs102:27017] got command resync <ts: 1731495074>, opid: 673484a2a4dcee9bf86a9afe 2024-11-13T10:51:15Z I [rs1/rs102:27017] got epoch {1731495073 6} 2024-11-13T10:51:15Z I [rs1/rs101:27017] got command resync <ts: 1731495074>, opid: 673484a2a4dcee9bf86a9afe 2024-11-13T10:51:15Z I [rs1/rs103:27017] got command resync <ts: 1731495074>, opid: 673484a2a4dcee9bf86a9afe 2024-11-13T10:51:15Z I [rs1/rs101:27017] got epoch {1731495073 6} 2024-11-13T10:51:15Z I [rs1/rs103:27017] got epoch {1731495073 6} 2024-11-13T10:51:15Z I [rs1/rs102:27017] [resync] started 2024-11-13T10:51:15Z D [rs1/rs101:27017] [resync] lock not acquired 2024-11-13T10:51:15Z D [rs1/rs103:27017] [resync] lock not acquired 2024-11-13T10:51:15Z D [rs1/rs102:27017] [resync] uploading ".pbm.init" [size hint: 5 (5.00B); part size: 10485760 (10.00MB)] 2024-11-13T10:51:15Z D [rs1/rs102:27017] [resync] got backups list: 0 2024-11-13T10:51:15Z D [rs1/rs102:27017] [resync] got physical restores list: 0 2024-11-13T10:51:15Z D [rs1/rs102:27017] [resync] epoch set to {1731495075 16} 2024-11-13T10:51:15Z I [rs1/rs102:27017] [resync] succeed 2024-11-13T10:51:20Z I [rs1/rs102:27017] got command resync <ts: 1731495079>, opid: 673484a7767b42afebacdae6 2024-11-13T10:51:20Z I [rs1/rs101:27017] got command resync <ts: 1731495079>, opid: 673484a7767b42afebacdae6 2024-11-13T10:51:20Z I [rs1/rs103:27017] got command resync <ts: 1731495079>, opid: 673484a7767b42afebacdae6 2024-11-13T10:51:20Z I [rs1/rs102:27017] got epoch {1731495075 16} 2024-11-13T10:51:20Z I [rs1/rs101:27017] got epoch {1731495075 16} 2024-11-13T10:51:20Z I [rs1/rs103:27017] got epoch {1731495075 16} 2024-11-13T10:51:20Z D [rs1/rs103:27017] [resync] lock not acquired 2024-11-13T10:51:20Z D [rs1/rs101:27017] [resync] lock not acquired 2024-11-13T10:51:20Z I [rs1/rs102:27017] [resync] started 2024-11-13T10:51:20Z I [rs1/rs103:27017] got command backup [name: 2024-11-13T10:51:20Z, compression: none (level: default)] <ts: 1731495080>, opid: 673484a8aee30a360299f6e8 2024-11-13T10:51:20Z I [rs1/rs101:27017] got command backup [name: 2024-11-13T10:51:20Z, compression: none (level: default)] <ts: 1731495080>, opid: 673484a8aee30a360299f6e8 2024-11-13T10:51:20Z I [rs1/rs103:27017] got epoch {1731495075 16} 2024-11-13T10:51:20Z D [rs1/rs102:27017] [resync] got backups list: 0 2024-11-13T10:51:20Z I [rs1/rs101:27017] got epoch {1731495075 16} 2024-11-13T10:51:20Z D [rs1/rs102:27017] [resync] got physical restores list: 0 2024-11-13T10:51:20Z E [rs1/rs101:27017] [backup/2024-11-13T10:51:20Z] unable to proceed with the backup, active lock is present 2024-11-13T10:51:20Z D [rs1/rs102:27017] [resync] epoch set to {1731495080 77} 2024-11-13T10:51:20Z I [rs1/rs102:27017] [resync] succeed 2024-11-13T10:51:20Z I [rs1/rs102:27017] got command backup [name: 2024-11-13T10:51:20Z, compression: none (level: default)] <ts: 1731495080>, opid: 673484a8aee30a360299f6e8 2024-11-13T10:51:20Z I [rs1/rs102:27017] got epoch {1731495080 77} 2024-11-13T10:51:35Z D [rs1/rs103:27017] [backup/2024-11-13T10:51:20Z] nomination timeout 2024-11-13T10:51:35Z D [rs1/rs103:27017] [backup/2024-11-13T10:51:20Z] skip after nomination, probably started by another node 2024-11-13T10:51:35Z D [rs1/rs102:27017] [backup/2024-11-13T10:51:20Z] nomination timeout 2024-11-13T10:51:35Z D [rs1/rs102:27017] [backup/2024-11-13T10:51:20Z] skip after nomination, probably started by another node

AssertionError: assert 'cloning namespace (--ns-to) is already in use' in 'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n' + where 'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n' = CommandResult(backend=<testinfra.backend.docker.DockerBackend object at 0x7f3bf2117110>, exit_status=1, command=b'pbm ...'', _stderr=b'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n').stderr

AssertionError: assert 'cloning namespace (--ns-to) is already in use' in 'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n' + where 'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n' = CommandResult(backend=<testinfra.backend.docker.DockerBackend object at 0x7f7a64c0b290>, exit_status=1, command=b'pbm ...'', _stderr=b'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n').stderr

AssertionError: assert 'cloning namespace (--ns-to) is already in use' in 'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n' + where 'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n' = CommandResult(backend=<testinfra.backend.docker.DockerBackend object at 0x7f7a64c0b290>, exit_status=1, command=b'pbm ...'', _stderr=b'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n').stderr

AssertionError: assert 'cloning namespace (--ns-to) is already in use' in 'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n' + where 'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n' = CommandResult(backend=<testinfra.backend.docker.DockerBackend object at 0x7f7a64c0b290>, exit_status=1, command=b'pbm ...'', _stderr=b'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n').stderr

AssertionError: assert 'cloning namespace (--ns-to) is already in use' in 'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n' + where 'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n' = CommandResult(backend=<testinfra.backend.docker.DockerBackend object at 0x7f7a64c0b290>, exit_status=1, command=b'pbm ...'', _stderr=b'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n').stderr

AssertionError: assert 'cloning namespace (--ns-to) is already in use' in 'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n' + where 'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n' = CommandResult(backend=<testinfra.backend.docker.DockerBackend object at 0x7f7a64c0b290>, exit_status=1, command=b'pbm ...'', _stderr=b'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n').stderr

AssertionError: assert 'cloning namespace (--ns-to) is already in use' in 'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n' + where 'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n' = CommandResult(backend=<testinfra.backend.docker.DockerBackend object at 0x7f7a64c0b290>, exit_status=1, command=b'pbm ...'', _stderr=b'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n').stderr

AssertionError: assert 'cloning namespace (--ns-to) is already in use' in 'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n' + where 'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n' = CommandResult(backend=<testinfra.backend.docker.DockerBackend object at 0x7f7a64c0b290>, exit_status=1, command=b'pbm ...'', _stderr=b'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n').stderr

AssertionError: assert 'cloning namespace (--ns-to) is already in use' in 'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n' + where 'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n' = CommandResult(backend=<testinfra.backend.docker.DockerBackend object at 0x7f7a64c0b290>, exit_status=1, command=b'pbm ...'', _stderr=b'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n').stderr

AssertionError: assert 'cloning namespace (--ns-to) is already in use' in 'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n' + where 'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n' = CommandResult(backend=<testinfra.backend.docker.DockerBackend object at 0x7f5837ae9510>, exit_status=1, command=b'pbm ...'', _stderr=b'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n').stderr

AssertionError: assert 'cloning namespace (--ns-to) is already in use' in 'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n' + where 'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n' = CommandResult(backend=<testinfra.backend.docker.DockerBackend object at 0x7f5837ae9510>, exit_status=1, command=b'pbm ...'', _stderr=b'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n').stderr

AssertionError: assert 'cloning namespace (--ns-to) is already in use' in 'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n' + where 'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n' = CommandResult(backend=<testinfra.backend.docker.DockerBackend object at 0x7f5837ae9510>, exit_status=1, command=b'pbm ...'', _stderr=b'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n').stderr

AssertionError: assert 'cloning namespace (--ns-to) is already in use' in 'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n' + where 'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n' = CommandResult(backend=<testinfra.backend.docker.DockerBackend object at 0x7f5837ae9510>, exit_status=1, command=b'pbm ...'', _stderr=b'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n').stderr

AssertionError: assert 'cloning namespace (--ns-to) is already in use' in 'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n' + where 'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n' = CommandResult(backend=<testinfra.backend.docker.DockerBackend object at 0x7f5837ae9510>, exit_status=1, command=b'pbm ...'', _stderr=b'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n').stderr

AssertionError: assert 'cloning namespace (--ns-to) is already in use' in 'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n' + where 'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n' = CommandResult(backend=<testinfra.backend.docker.DockerBackend object at 0x7f5837ae9510>, exit_status=1, command=b'pbm ...'', _stderr=b'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n').stderr

AssertionError: assert 'cloning namespace (--ns-to) is already in use' in 'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n' + where 'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n' = CommandResult(backend=<testinfra.backend.docker.DockerBackend object at 0x7f5837ae9510>, exit_status=1, command=b'pbm ...'', _stderr=b'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n').stderr

AssertionError: assert 'cloning namespace (--ns-to) is already in use' in 'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n' + where 'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n' = CommandResult(backend=<testinfra.backend.docker.DockerBackend object at 0x7f5837ae9510>, exit_status=1, command=b'pbm ...'', _stderr=b'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n').stderr

Process completed with exit code 1.

Process completed with exit code 1.

Process completed with exit code 1.

AssertionError: assert 'cloning namespace (--ns-to) is already in use' in 'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n' + where 'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n' = CommandResult(backend=<testinfra.backend.docker.DockerBackend object at 0x7f644c190b90>, exit_status=1, command=b'pbm ...'', _stderr=b'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n').stderr

AssertionError: assert 'cloning namespace (--ns-to) is already in use' in 'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n' + where 'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n' = CommandResult(backend=<testinfra.backend.docker.DockerBackend object at 0x7f644c190b90>, exit_status=1, command=b'pbm ...'', _stderr=b'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n').stderr

AssertionError: assert 'cloning namespace (--ns-to) is already in use' in 'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n' + where 'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n' = CommandResult(backend=<testinfra.backend.docker.DockerBackend object at 0x7f644c190b90>, exit_status=1, command=b'pbm ...'', _stderr=b'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n').stderr

AssertionError: Backup failed{"Error":"get backup metadata: get: context deadline exceeded"} 2024-11-13T10:56:26Z I [rs1/rs101:27017] pbm-agent: Version: 2.7.0 Platform: linux/amd64 GitCommit: 79478b12486e64faa442adaa26183969d9b9a16e GitBranch: dev BuildTime: 2024-11-13_09:38_UTC GoVersion: go1.23.3 2024-11-13T10:56:26Z I [rs1/rs101:27017] starting PITR routine 2024-11-13T10:56:26Z E [rs1/rs101:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result 2024-11-13T10:56:26Z I [rs1/rs102:27017] starting PITR routine 2024-11-13T10:56:26Z I [rs1/rs101:27017] node: rs1/rs101:27017 2024-11-13T10:56:26Z I [rs1/rs102:27017] pbm-agent: Version: 2.7.0 Platform: linux/amd64 GitCommit: 79478b12486e64faa442adaa26183969d9b9a16e GitBranch: dev BuildTime: 2024-11-13_09:38_UTC GoVersion: go1.23.3 2024-11-13T10:56:26Z I [rs1/rs103:27017] pbm-agent: Version: 2.7.0 Platform: linux/amd64 GitCommit: 79478b12486e64faa442adaa26183969d9b9a16e GitBranch: dev BuildTime: 2024-11-13_09:38_UTC GoVersion: go1.23.3 2024-11-13T10:56:26Z I [rs1/rs103:27017] starting PITR routine 2024-11-13T10:56:26Z I [rs1/rs101:27017] conn level ReadConcern: majority; WriteConcern: majority 2024-11-13T10:56:26Z I [rs1/rs103:27017] node: rs1/rs103:27017 2024-11-13T10:56:26Z E [rs1/rs102:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result 2024-11-13T10:56:26Z E [rs1/rs103:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result 2024-11-13T10:56:26Z I [rs1/rs102:27017] node: rs1/rs102:27017 2024-11-13T10:56:26Z I [rs1/rs101:27017] listening for the commands 2024-11-13T10:56:26Z I [rs1/rs103:27017] conn level ReadConcern: majority; WriteConcern: majority 2024-11-13T10:56:26Z I [rs1/rs103:27017] listening for the commands 2024-11-13T10:56:26Z I [rs1/rs102:27017] conn level ReadConcern: majority; WriteConcern: majority 2024-11-13T10:56:26Z I [rs1/rs102:27017] listening for the commands 2024-11-13T10:56:31Z E [rs1/rs101:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result 2024-11-13T10:56:31Z E [rs1/rs102:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result 2024-11-13T10:56:31Z E [rs1/rs103:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result 2024-11-13T10:56:33Z I [rs1/rs101:27017] got command resync <ts: 1731495392>, opid: 673485e0a55d4255536d667d 2024-11-13T10:56:33Z I [rs1/rs103:27017] got command resync <ts: 1731495392>, opid: 673485e0a55d4255536d667d 2024-11-13T10:56:33Z I [rs1/rs101:27017] got epoch {1731495391 6} 2024-11-13T10:56:33Z I [rs1/rs103:27017] got epoch {1731495391 6} 2024-11-13T10:56:33Z I [rs1/rs102:27017] got command resync <ts: 1731495392>, opid: 673485e0a55d4255536d667d 2024-11-13T10:56:33Z D [rs1/rs103:27017] [resync] lock not acquired 2024-11-13T10:56:33Z I [rs1/rs102:27017] got epoch {1731495391 6} 2024-11-13T10:56:33Z I [rs1/rs101:27017] [resync] started 2024-11-13T10:56:33Z D [rs1/rs102:27017] [resync] lock not acquired 2024-11-13T10:56:33Z D [rs1/rs101:27017] [resync] uploading ".pbm.init" [size hint: 5 (5.00B); part size: 10485760 (10.00MB)] 2024-11-13T10:56:33Z D [rs1/rs101:27017] [resync] got backups list: 0 2024-11-13T10:56:33Z D [rs1/rs101:27017] [resync] got physical restores list: 0 2024-11-13T10:56:33Z D [rs1/rs101:27017] [resync] epoch set to {1731495393 14} 2024-11-13T10:56:33Z I [rs1/rs101:27017] [resync] succeed 2024-11-13T10:56:38Z I [rs1/rs101:27017] got command resync <ts: 1731495397>, opid: 673485e5036baaaf52c19cae 2024-11-13T10:56:38Z I [rs1/rs103:27017] got command resync <ts: 1731495397>, opid: 673485e5036baaaf52c19cae 2024-11-13T10:56:38Z I [rs1/rs101:27017] got epoch {1731495393 14} 2024-11-13T10:56:38Z I [rs1/rs103:27017] got epoch {1731495393 14} 2024-11-13T10:56:38Z I [rs1/rs102:27017] got command resync <ts: 1731495397>, opid: 673485e5036baaaf52c19cae 2024-11-13T10:56:38Z I [rs1/rs102:27017] got epoch {1731495393 14} 2024-11-13T10:56:38Z D [rs1/rs101:27017] [resync] lock not acquired 2024-11-13T10:56:38Z I [rs1/rs103:27017] [resync] started 2024-11-13T10:56:38Z I [rs1/rs101:27017] got command backup [name: 2024-11-13T10:56:38Z, compression: none (level: default)] <ts: 1731495398>, opid: 673485e6cfad5d68b982cf79 2024-11-13T10:56:38Z D [rs1/rs102:27017] [resync] lock not acquired 2024-11-13T10:56:38Z I [rs1/rs101:27017] got epoch {1731495393 14} 2024-11-13T10:56:38Z I [rs1/rs102:27017] got command backup [name: 2024-11-13T10:56:38Z, compression: none (level: default)] <ts: 1731495398>, opid: 673485e6cfad5d68b982cf79 2024-11-13T10:56:38Z D [rs1/rs103:27017] [resync] got backups list: 0 2024-11-13T10:56:38Z I [rs1/rs102:27017] got epoch {1731495393 14} 2024-11-13T10:56:38Z E [rs1/rs101:27017] [backup/2024-11-13T10:56:38Z] unable to proceed with the backup, active lock is present 2024-11-13T10:56:38Z D [rs1/rs103:27017] [resync] got physical restores list: 0 2024-11-13T10:56:38Z D [rs1/rs103:27017] [resync] epoch set to {1731495398 67} 2024-11-13T10:56:38Z I [rs1/rs103:27017] [resync] succeed 2024-11-13T10:56:38Z I [rs1/rs103:27017] got command backup [name: 2024-11-13T10:56:38Z, compression: none (level: default)] <ts: 1731495398>, opid: 673485e6cfad5d68b982cf79 2024-11-13T10:56:38Z I [rs1/rs103:27017] got epoch {1731495398 67} 2024-11-13T10:56:53Z D [rs1/rs102:27017] [backup/2024-11-13T10:56:38Z] nomination timeout 2024-11-13T10:56:53Z D [rs1/rs102:27017] [backup/2024-11-13T10:56:38Z] skip after nomination, probably started by another node 2024-11-13T10:56:53Z D [rs1/rs103:27017] [backup/2024-11-13T10:56:38Z] nomination timeout 2024-11-13T10:56:53Z D [rs1/rs103:27017] [backup/2024-11-13T10:56:38Z] skip after nomination, probably started by another node

AssertionError: Backup failed{"Error":"get backup metadata: get: context deadline exceeded"} 2024-11-13T10:57:31Z I [rs1/rs102:27017] pbm-agent: Version: 2.7.0 Platform: linux/amd64 GitCommit: 79478b12486e64faa442adaa26183969d9b9a16e GitBranch: dev BuildTime: 2024-11-13_09:38_UTC GoVersion: go1.23.3 2024-11-13T10:57:31Z I [rs1/rs102:27017] starting PITR routine 2024-11-13T10:57:31Z I [rs1/rs103:27017] pbm-agent: Version: 2.7.0 Platform: linux/amd64 GitCommit: 79478b12486e64faa442adaa26183969d9b9a16e GitBranch: dev BuildTime: 2024-11-13_09:38_UTC GoVersion: go1.23.3 2024-11-13T10:57:31Z I [rs1/rs103:27017] starting PITR routine 2024-11-13T10:57:31Z I [rs1/rs103:27017] node: rs1/rs103:27017 2024-11-13T10:57:31Z I [rs1/rs102:27017] node: rs1/rs102:27017 2024-11-13T10:57:31Z I [rs1/rs101:27017] pbm-agent: Version: 2.7.0 Platform: linux/amd64 GitCommit: 79478b12486e64faa442adaa26183969d9b9a16e GitBranch: dev BuildTime: 2024-11-13_09:38_UTC GoVersion: go1.23.3 2024-11-13T10:57:31Z I [rs1/rs101:27017] starting PITR routine 2024-11-13T10:57:31Z E [rs1/rs102:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result 2024-11-13T10:57:31Z E [rs1/rs103:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result 2024-11-13T10:57:31Z I [rs1/rs102:27017] conn level ReadConcern: majority; WriteConcern: majority 2024-11-13T10:57:31Z I [rs1/rs101:27017] node: rs1/rs101:27017 2024-11-13T10:57:31Z I [rs1/rs103:27017] conn level ReadConcern: majority; WriteConcern: majority 2024-11-13T10:57:31Z I [rs1/rs102:27017] listening for the commands 2024-11-13T10:57:31Z E [rs1/rs101:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result 2024-11-13T10:57:31Z I [rs1/rs101:27017] conn level ReadConcern: majority; WriteConcern: majority 2024-11-13T10:57:31Z I [rs1/rs103:27017] listening for the commands 2024-11-13T10:57:31Z I [rs1/rs101:27017] listening for the commands 2024-11-13T10:57:36Z E [rs1/rs103:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result 2024-11-13T10:57:36Z E [rs1/rs102:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result 2024-11-13T10:57:36Z E [rs1/rs101:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result 2024-11-13T10:57:38Z I [rs1/rs102:27017] got command resync <ts: 1731495457>, opid: 673486213897f3b75671514d 2024-11-13T10:57:38Z I [rs1/rs103:27017] got command resync <ts: 1731495457>, opid: 673486213897f3b75671514d 2024-11-13T10:57:38Z I [rs1/rs103:27017] got epoch {1731495456 6} 2024-11-13T10:57:38Z I [rs1/rs102:27017] got epoch {1731495456 6} 2024-11-13T10:57:38Z I [rs1/rs101:27017] got command resync <ts: 1731495457>, opid: 673486213897f3b75671514d 2024-11-13T10:57:38Z I [rs1/rs101:27017] got epoch {1731495456 6} 2024-11-13T10:57:38Z I [rs1/rs103:27017] [resync] started 2024-11-13T10:57:38Z D [rs1/rs102:27017] [resync] lock not acquired 2024-11-13T10:57:38Z D [rs1/rs101:27017] [resync] lock not acquired 2024-11-13T10:57:38Z D [rs1/rs103:27017] [resync] uploading ".pbm.init" [size hint: 5 (5.00B); part size: 10485760 (10.00MB)] 2024-11-13T10:57:38Z D [rs1/rs103:27017] [resync] got backups list: 0 2024-11-13T10:57:38Z D [rs1/rs103:27017] [resync] got physical restores list: 0 2024-11-13T10:57:38Z D [rs1/rs103:27017] [resync] epoch set to {1731495458 14} 2024-11-13T10:57:38Z I [rs1/rs103:27017] [resync] succeed 2024-11-13T10:57:43Z I [rs1/rs103:27017] got command resync <ts: 1731495463>, opid: 67348627e04fc2e871b058c1 2024-11-13T10:57:43Z I [rs1/rs102:27017] got command resync <ts: 1731495463>, opid: 67348627e04fc2e871b058c1 2024-11-13T10:57:43Z I [rs1/rs103:27017] got epoch {1731495458 14} 2024-11-13T10:57:43Z I [rs1/rs102:27017] got epoch {1731495458 14} 2024-11-13T10:57:43Z I [rs1/rs101:27017] got command resync <ts: 1731495463>, opid: 67348627e04fc2e871b058c1 2024-11-13T10:57:43Z I [rs1/rs101:27017] got epoch {1731495458 14} 2024-11-13T10:57:43Z D [rs1/rs102:27017] [resync] lock not acquired 2024-11-13T10:57:43Z I [rs1/rs103:27017] [resync] started 2024-11-13T10:57:43Z I [rs1/rs102:27017] got command backup [name: 2024-11-13T10:57:43Z, compression: none (level: default)] <ts: 1731495463>, opid: 673486274d1ba56fb1eab354 2024-11-13T10:57:43Z D [rs1/rs101:27017] [resync] lock not acquired 2024-11-13T10:57:43Z I [rs1/rs102:27017] got epoch {1731495458 14} 2024-11-13T10:57:43Z I [rs1/rs101:27017] got command backup [name: 2024-11-13T10:57:43Z, compression: none (level: default)] <ts: 1731495463>, opid: 673486274d1ba56fb1eab354 2024-11-13T10:57:43Z D [rs1/rs103:27017] [resync] got backups list: 0 2024-11-13T10:57:43Z I [rs1/rs101:27017] got epoch {1731495458 14} 2024-11-13T10:57:43Z D [rs1/rs103:27017] [resync] got physical restores list: 0 2024-11-13T10:57:43Z E [rs1/rs101:27017] [backup/2024-11-13T10:57:43Z] unable to proceed with the backup, active lock is present 2024-11-13T10:57:43Z D [rs1/rs103:27017] [resync] epoch set to {1731495463 78} 2024-11-13T10:57:43Z I [rs1/rs103:27017] [resync] succeed 2024-11-13T10:57:43Z I [rs1/rs103:27017] got command backup [name: 2024-11-13T10:57:43Z, compression: none (level: default)] <ts: 1731495463>, opid: 673486274d1ba56fb1eab354 2024-11-13T10:57:43Z I [rs1/rs103:27017] got epoch {1731495463 78} 2024-11-13T10:57:44Z I [rs1/rs102:27017] got command resync <ts: 1731495463>, opid: 67348627e04fc2e871b058c1 2024-11-13T10:57:44Z I [rs1/rs102:27017] got epoch {1731495463 78} 2024-11-13T10:57:44Z I [rs1/rs101:27017] got command resync <ts: 1731495463>, opid: 67348627e04fc2e871b058c1 2024-11-13T10:57:44Z I [rs1/rs101:27017] got epoch {1731495463 78} 2024-11-13T10:57:44Z D [rs1/rs102:27017] [resync] get lock: duplicate operation: 67348627e04fc2e871b058c1 [Resync storage] 2024-11-13T10:57:44Z D [rs1/rs102:27017] [resync] lock not acquired 2024-11-13T10:57:44Z I [rs1/rs102:27017] got command backup [name: 2024-11-13T10:57:43Z, compression: none (level: default)] <ts: 1731495463>, opid: 673486274d1ba56fb1eab354 2024-11-13T10:57:44Z I [rs1/rs102:27017] got epoch {1731495463 78} 2024-11-13T10:57:44Z D [rs1/rs101:27017] [resync] get lock: duplicate operation: 67348627e04fc2e871b058c1 [Resync storage] 2024-11-13T10:57:44Z I [rs1/rs103:27017] got command resync <ts: 1731495463>, opid: 67348627e04fc2e871b058c1 2024-11-13T10:57:44Z D [rs1/rs101:27017] [resync] lock not acquired 2024-11-13T10:57:44Z I [rs1/rs103:27017] got epoch {1731495463 78} 2024-11-13T10:57:44Z I [rs1/rs101:27017] got command backup [name: 2024-11-13T10:57:43Z, compression: none (level: default)] <ts: 1731495463>, opid: 673486274d1ba56fb1eab354 2024-11-13T10:57:44Z I [rs1/rs101:27017] got epoch {1731495463 78} 2024-11-13T10:57:44Z E [rs1/rs101:27017] [backup/2024-11-13T10:57:43Z] unable to proceed with the backup, active lock is present 2024-11-13T10:57:44Z D [rs1/rs103:27017] [resync] get lock: duplicate operation: 67348627e04fc2e871b058c1 [Resync storage] 2024-11-13T10:57:44Z D [rs1/rs103:27017] [resync] lock not acquired 2024-11-13T10:57:44Z I [rs1/rs103:27017] got command backup [name: 2024-11-13T10:57:43Z, compression: none (level: default)] <ts: 1731495463>, opid: 673486274d1ba56fb1eab354 2024-11-13T10:57:44Z I [rs1/rs103:27017] got epoch {1731495463 78} 2024-11-13T10:57:58Z D [rs1/rs102:27017] [backup/2024-11-13T10:57:43Z] nomination timeout 2024-11-13T10:57:58Z D [rs1/rs102:27017] [backup/2024-11-13T10:57:43Z] skip after nomination, probably started by another node 2024-11-13T10:57:58Z D [rs1/rs103:27017] [backup/2024-11-13T10:57:43Z] nomination timeout 2024-11-13T10:57:58Z D [rs1/rs103:27017] [backup/2024-11-13T10:57:43Z] skip after nomination, probably started by another node 2024-11-13T10:57:59Z D [rs1/rs102:27017] [backup/2024-11-13T10:57:43Z] nomination timeout 2024-11-13T10:57:59Z D [rs1/rs102:27017] [backup/2024-11-13T10:57:43Z] skip after nomination, probably started by another node 2024-11-13T10:57:59Z D [rs1/rs103:27017] [backup/2024-11-13T10:57:43Z] nomination timeout 2024-11-13T10:57:59Z D [rs1/rs103:27017] [backup/2024-11-13T10:57:43Z] skip after nomination, probably started by another node

AssertionError: assert 'cloning namespace (--ns-to) is already in use' in 'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n' + where 'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n' = CommandResult(backend=<testinfra.backend.docker.DockerBackend object at 0x7f644c190b90>, exit_status=1, command=b'pbm ...'', _stderr=b'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n').stderr

AssertionError: Backup failed{"Error":"get backup metadata: get: context deadline exceeded"} 2024-11-13T11:00:26Z I [rs1/rs101:27017] pbm-agent: Version: 2.7.0 Platform: linux/amd64 GitCommit: 79478b12486e64faa442adaa26183969d9b9a16e GitBranch: dev BuildTime: 2024-11-13_09:38_UTC GoVersion: go1.23.3 2024-11-13T11:00:26Z I [rs1/rs101:27017] starting PITR routine 2024-11-13T11:00:26Z I [rs1/rs102:27017] pbm-agent: Version: 2.7.0 Platform: linux/amd64 GitCommit: 79478b12486e64faa442adaa26183969d9b9a16e GitBranch: dev BuildTime: 2024-11-13_09:38_UTC GoVersion: go1.23.3 2024-11-13T11:00:26Z I [rs1/rs102:27017] starting PITR routine 2024-11-13T11:00:26Z I [rs1/rs103:27017] pbm-agent: Version: 2.7.0 Platform: linux/amd64 GitCommit: 79478b12486e64faa442adaa26183969d9b9a16e GitBranch: dev BuildTime: 2024-11-13_09:38_UTC GoVersion: go1.23.3 2024-11-13T11:00:26Z I [rs1/rs103:27017] starting PITR routine 2024-11-13T11:00:26Z E [rs1/rs101:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result 2024-11-13T11:00:26Z I [rs1/rs102:27017] node: rs1/rs102:27017 2024-11-13T11:00:26Z I [rs1/rs103:27017] node: rs1/rs103:27017 2024-11-13T11:00:26Z E [rs1/rs103:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result 2024-11-13T11:00:26Z I [rs1/rs103:27017] conn level ReadConcern: majority; WriteConcern: majority 2024-11-13T11:00:26Z E [rs1/rs102:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result 2024-11-13T11:00:26Z I [rs1/rs102:27017] conn level ReadConcern: majority; WriteConcern: majority 2024-11-13T11:00:26Z I [rs1/rs101:27017] node: rs1/rs101:27017 2024-11-13T11:00:26Z I [rs1/rs103:27017] listening for the commands 2024-11-13T11:00:26Z I [rs1/rs101:27017] conn level ReadConcern: majority; WriteConcern: majority 2024-11-13T11:00:26Z I [rs1/rs102:27017] listening for the commands 2024-11-13T11:00:26Z I [rs1/rs101:27017] listening for the commands 2024-11-13T11:00:31Z E [rs1/rs101:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result 2024-11-13T11:00:31Z E [rs1/rs103:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result 2024-11-13T11:00:31Z E [rs1/rs102:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result 2024-11-13T11:00:33Z I [rs1/rs103:27017] got command resync <ts: 1731495632>, opid: 673486d0f67d8456039450d2 2024-11-13T11:00:33Z I [rs1/rs101:27017] got command resync <ts: 1731495632>, opid: 673486d0f67d8456039450d2 2024-11-13T11:00:33Z I [rs1/rs102:27017] got command resync <ts: 1731495632>, opid: 673486d0f67d8456039450d2 2024-11-13T11:00:33Z I [rs1/rs103:27017] got epoch {1731495631 6} 2024-11-13T11:00:33Z I [rs1/rs101:27017] got epoch {1731495631 6} 2024-11-13T11:00:33Z I [rs1/rs102:27017] got epoch {1731495631 6} 2024-11-13T11:00:33Z D [rs1/rs102:27017] [resync] lock not acquired 2024-11-13T11:00:33Z D [rs1/rs101:27017] [resync] lock not acquired 2024-11-13T11:00:33Z I [rs1/rs103:27017] [resync] started 2024-11-13T11:00:33Z D [rs1/rs103:27017] [resync] uploading ".pbm.init" [size hint: 5 (5.00B); part size: 10485760 (10.00MB)] 2024-11-13T11:00:33Z D [rs1/rs103:27017] [resync] got backups list: 0 2024-11-13T11:00:33Z D [rs1/rs103:27017] [resync] got physical restores list: 0 2024-11-13T11:00:33Z D [rs1/rs103:27017] [resync] epoch set to {1731495633 14} 2024-11-13T11:00:33Z I [rs1/rs103:27017] [resync] succeed 2024-11-13T11:00:38Z I [rs1/rs103:27017] got command resync <ts: 1731495637>, opid: 673486d5f9d04a0b40dff19d 2024-11-13T11:00:38Z I [rs1/rs101:27017] got command resync <ts: 1731495637>, opid: 673486d5f9d04a0b40dff19d 2024-11-13T11:00:38Z I [rs1/rs102:27017] got command resync <ts: 1731495637>, opid: 673486d5f9d04a0b40dff19d 2024-11-13T11:00:38Z I [rs1/rs102:27017] got epoch {1731495633 14} 2024-11-13T11:00:38Z I [rs1/rs103:27017] got epoch {1731495633 14} 2024-11-13T11:00:38Z I [rs1/rs101:27017] got epoch {1731495633 14} 2024-11-13T11:00:38Z D [rs1/rs103:27017] [resync] lock not acquired 2024-11-13T11:00:38Z I [rs1/rs102:27017] [resync] started 2024-11-13T11:00:38Z I [rs1/rs103:27017] got command backup [name: 2024-11-13T11:00:38Z, compression: none (level: default)] <ts: 1731495638>, opid: 673486d6f95638ddb968aa33 2024-11-13T11:00:38Z D [rs1/rs101:27017] [resync] lock not acquired 2024-11-13T11:00:38Z I [rs1/rs103:27017] got epoch {1731495633 14} 2024-11-13T11:00:38Z I [rs1/rs101:27017] got command backup [name: 2024-11-13T11:00:38Z, compression: none (level: default)] <ts: 1731495638>, opid: 673486d6f95638ddb968aa33 2024-11-13T11:00:38Z D [rs1/rs102:27017] [resync] got backups list: 0 2024-11-13T11:00:38Z I [rs1/rs101:27017] got epoch {1731495633 14} 2024-11-13T11:00:38Z D [rs1/rs102:27017] [resync] got physical restores list: 0 2024-11-13T11:00:38Z E [rs1/rs101:27017] [backup/2024-11-13T11:00:38Z] unable to proceed with the backup, active lock is present 2024-11-13T11:00:38Z D [rs1/rs102:27017] [resync] epoch set to {1731495638 19} 2024-11-13T11:00:38Z I [rs1/rs102:27017] [resync] succeed 2024-11-13T11:00:38Z I [rs1/rs102:27017] got command backup [name: 2024-11-13T11:00:38Z, compression: none (level: default)] <ts: 1731495638>, opid: 673486d6f95638ddb968aa33 2024-11-13T11:00:38Z I [rs1/rs102:27017] got epoch {1731495638 19} 2024-11-13T11:00:53Z D [rs1/rs103:27017] [backup/2024-11-13T11:00:38Z] nomination timeout 2024-11-13T11:00:53Z D [rs1/rs103:27017] [backup/2024-11-13T11:00:38Z] skip after nomination, probably started by another node 2024-11-13T11:00:53Z D [rs1/rs102:27017] [backup/2024-11-13T11:00:38Z] nomination timeout 2024-11-13T11:00:53Z D [rs1/rs102:27017] [backup/2024-11-13T11:00:38Z] skip after nomination, probably started by another node

AssertionError: assert 'cloning namespace (--ns-to) is already in use' in 'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n' + where 'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n' = CommandResult(backend=<testinfra.backend.docker.DockerBackend object at 0x7f644c190b90>, exit_status=1, command=b'pbm ...'', _stderr=b'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n').stderr