Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

PBM-1043 Oplog slicer should survive if either mongo or pbm-agent is unavailable #162

Merged
merged 7 commits into from
Jul 23, 2024
1 change: 1 addition & 0 deletions pbm-functional/pytest/Dockerfile
Original file line number Diff line number Diff line change
Expand Up @@ -56,6 +56,7 @@ COPY --from=pykmip /root/easy-rsa/easyrsa3/pki/ca.crt /etc/pykmip/ca.crt
COPY --from=x509 /etc/x509/ /etc/x509/
COPY conf/supervisord.d/ /etc/supervisord.d/
COPY conf/pbm/minio.yaml /etc/pbm.conf
COPY conf/pbm/pbm-1043.yaml /etc/pbm-1043.conf
COPY conf/krb5.conf /etc/krb5.conf
COPY keyfile /etc/keyfile
COPY mongodb-keyfile /etc/mongodb-keyfile
Expand Down
17 changes: 17 additions & 0 deletions pbm-functional/pytest/conf/pbm/pbm-1043.yaml
Original file line number Diff line number Diff line change
@@ -0,0 +1,17 @@
storage:
type: s3
s3:
endpointUrl: http://minio:9000
bucket: bcp
prefix: pbme2etest
credentials:
access-key-id: "minio1234"
secret-access-key: "minio1234"
pitr:
enabled: true
oplogSpanMin: 0.5
priority:
rs103:27017: 2
rs203:27017: 2
rscfg03:27017: 2
compression: none
108 changes: 108 additions & 0 deletions pbm-functional/pytest/test_PBM-1043.py
Original file line number Diff line number Diff line change
@@ -0,0 +1,108 @@
import pytest
import pymongo
import bson
import testinfra
import time
import os
import docker
import threading

from datetime import datetime
from cluster import Cluster

@pytest.fixture(scope="package")
def docker_client():
return docker.from_env()

@pytest.fixture(scope="package")
def config():
return { "mongos": "mongos",
"configserver":
{"_id": "rscfg", "members": [{"host":"rscfg01"},{"host": "rscfg02"},{"host": "rscfg03" }]},
"shards":[
{"_id": "rs1", "members": [{"host":"rs101"},{"host": "rs102"},{"host": "rs103"}]},
{"_id": "rs2", "members": [{"host":"rs201"},{"host": "rs202"},{"host": "rs203"}]}
]}

@pytest.fixture(scope="package")
def cluster(config):
return Cluster(config)

@pytest.fixture(scope="function")
def start_cluster(cluster,request):
try:
cluster.destroy()
os.chmod("/backups",0o777)
os.system("rm -rf /backups/*")
cluster.create()
cluster.setup_pbm()
client=pymongo.MongoClient(cluster.connection)
client.admin.command("enableSharding", "test")
client.admin.command("shardCollection", "test.test", key={"_id": "hashed"})
yield True

finally:
if request.config.getoption("--verbose"):
cluster.get_logs()
cluster.destroy(cleanup_backups=True)

@pytest.mark.timeout(600,func_only=True)
def test_logical_PBM_T255(start_cluster,cluster):
def insert_docs():
client=pymongo.MongoClient(cluster.connection)
for i in range(200):
client['test']['test'].insert_one({"doc":i})
time.sleep(1)

cluster.check_pbm_status()
cluster.make_backup("logical")
cluster.exec_pbm_cli("config --file=/etc/pbm-1043.conf")
time.sleep(60)
Cluster.log("Check if PITR is running")
if not cluster.check_pitr():
logs=cluster.exec_pbm_cli("logs -sD -t0")
assert False, logs.stdout

Check failure on line 64 in pbm-functional/pytest/test_PBM-1043.py

View workflow job for this annotation

GitHub Actions / JUnit Test Report

test_PBM-1043.test_logical_PBM_T255

AssertionError: 2024-07-18T07:30:29Z I [rs2/rs201:27017] pbm-agent: Version: 2.5.0 Platform: linux/amd64 GitCommit: ae58fb510bc6cdb2648f154e729a205e78aae9cd GitBranch: dev BuildTime: 2024-07-18_07:29_UTC GoVersion: go1.22.5 2024-07-18T07:30:29Z I [rs1/rs101:27017] starting PITR routine 2024-07-18T07:30:29Z I [rs1/rs102:27017] pbm-agent: Version: 2.5.0 Platform: linux/amd64 GitCommit: ae58fb510bc6cdb2648f154e729a205e78aae9cd GitBranch: dev BuildTime: 2024-07-18_07:29_UTC GoVersion: go1.22.5 2024-07-18T07:30:29Z I [rs1/rs101:27017] pbm-agent: Version: 2.5.0 Platform: linux/amd64 GitCommit: ae58fb510bc6cdb2648f154e729a205e78aae9cd GitBranch: dev BuildTime: 2024-07-18_07:29_UTC GoVersion: go1.22.5 2024-07-18T07:30:29Z I [rs2/rs201:27017] starting PITR routine 2024-07-18T07:30:29Z I [rs1/rs102:27017] starting PITR routine 2024-07-18T07:30:29Z I [rs1/rs103:27017] pbm-agent: Version: 2.5.0 Platform: linux/amd64 GitCommit: ae58fb510bc6cdb2648f154e729a205e78aae9cd GitBranch: dev BuildTime: 2024-07-18_07:29_UTC GoVersion: go1.22.5 2024-07-18T07:30:29Z I [rs1/rs103:27017] starting PITR routine 2024-07-18T07:30:29Z I [rs1/rs101:27017] node: rs1/rs101:27017 2024-07-18T07:30:29Z I [rs2/rs201:27017] node: rs2/rs201:27017 2024-07-18T07:30:29Z I [rs1/rs102:27017] node: rs1/rs102:27017 2024-07-18T07:30:29Z I [rs1/rs101:27017] conn level ReadConcern: majority; WriteConcern: majority 2024-07-18T07:30:29Z I [rs1/rs103:27017] node: rs1/rs103:27017 2024-07-18T07:30:29Z I [rs2/rs201:27017] conn level ReadConcern: majority; WriteConcern: majority 2024-07-18T07:30:29Z I [rs1/rs102:27017] conn level ReadConcern: majority; WriteConcern: majority 2024-07-18T07:30:29Z I [rs1/rs101:27017] listening for the commands 2024-07-18T07:30:29Z I [rs1/rs103:27017] conn level ReadConcern: majority; WriteConcern: majority 2024-07-18T07:30:29Z I [rs2/rs201:27017] listening for the commands 2024-07-18T07:30:29Z I [rs1/rs102:27017] listening for the commands 2024-07-18T07:30:29Z I [rs1/rs103:27017] listening for the commands 2024-07-18T07:30:30Z I [rs2/rs202:27017] pbm-agent: Version: 2.5.0 Platform: linux/amd64 GitCommit: ae58fb510bc6cdb2648f154e729a205e78aae9cd GitBranch: dev BuildTime: 2024-07-18_07:29_UTC GoVersion: go1.22.5 2024-07-18T07:30:30Z I [rs2/rs202:27017] starting PITR routine 2024-07-18T07:30:30Z I [rs2/rs202:27017] node: rs2/rs202:27017 2024-07-18T07:30:30Z I [rs2/rs202:27017] conn level ReadConcern: majority; WriteConcern: majority 2024-07-18T07:30:30Z I [rs2/rs202:27017] listening for the commands 2024-07-18T07:30:30Z I [rs2/rs203:27017] pbm-agent: Version: 2.5.0 Platform: linux/amd64 GitCommit: ae58fb510bc6cdb2648f154e729a205e78aae9cd GitBranch: dev BuildTime: 2024-07-18_07:29_UTC GoVersion: go1.22.5 2024-07-18T07:30:30Z I [rs2/rs203:27017] starting PITR routine 2024-07-18T07:30:30Z I [rs2/rs203:27017] node: rs2/rs203:27017 2024-07-18T07:30:30Z I [rs2/rs203:27017] conn level ReadConcern: majority; WriteConcern: majority 2024-07-18T07:30:30Z I [rs2/rs203:27017] listening for the commands 2024-07-18T07:30:30Z I [rscfg/rscfg02:27017] pbm-agent: Version: 2.5.0 Platform: linux/amd64 GitCommit: ae58fb510bc6cdb2648f154e729a205e78aae9cd GitBranch: dev BuildTime: 2024-07-18_07:29_UTC GoVersion: go1.22.5 2024-07-18T07:30:30Z I [rscfg/rscfg02:27017] starting PITR routine 2024-07-18T07:30:30Z I [rscfg/rscfg02:27017] node: rscfg/rscfg02:27017 2024-07-18T07:30:30Z I [rscfg/rscfg02:27017] conn level ReadConcern: majority; WriteConcern: majority 2024-07-18T07:30:30Z I [rscfg/rscfg02:27017] listening for the commands 2024-07-18T07:30:30Z I [rscfg/rscfg01:27017] pbm-agent: Version: 2.5.0 Platform: linux/amd64 GitCommit: ae58fb510bc6cdb2648f154e729a205e78aae9cd GitBranch: dev BuildTime: 2024-07-18_07:29_UTC GoVersion: go1.22.5 2024-07-18T07:30:30Z I [rscfg/rscfg01:27017] starting PITR routine 2024-07-18T07:30:30Z I [rscfg/rscfg01:27017] node: rscfg/rscfg01:27017 2024-07-18T07:30:30Z I [rscfg/rscfg01:27017] conn level ReadConcern: majority; WriteConcern: majority 2024-07-18T07:30:30Z I [rscfg/rscfg01:27017] listening for the commands 2024-07-18T07:30:32Z I [rscfg/rscfg03:27017] pbm-agent: Version: 2.5.0 Platform: linux/amd64 GitCommit: ae58fb510bc6cdb2648f154e729a205e78aae9cd GitBranch: dev BuildTime: 2024-07-18_07:29_UTC GoVersion: go1.22.5 2024-07-18T07:30:32Z I [rscfg/rscfg03:27017] starting PITR routine 2024-07-18T07:30:32Z I [rscfg/rscfg03:27017] node: rscfg/rscfg03:27017 2024-07-18T07:30:32Z I [rscfg/rscfg03:27017] conn level ReadConcern: majority; WriteConcern: majority 2024-07-18T07:30:32Z I [rscfg/rscfg03:27017] listening for the commands 2024-07-18T07:30:34Z W [rs1/rs101:27017] [agentCheckup] get current storage status: query mongo: mongo: no documents in result 2024-07-18T07:30:34Z W [rs1/rs102:27017] [agentCheckup] get current storage status: query mongo: mongo: no documents in result 2024-07-18T07:30:34Z W [rs1/rs103:27017] [agentCheckup] get current storage status: query mongo: mongo: no documents in result 2024-07-18T07:30:34Z W [rs2/rs201:27017] [agentCheckup] get current storage status: query mongo: mongo: no documents in result 2024-07-18T07:30:34Z E [rs1/rs102:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result 2024-07-18T07:30:34Z E [rs1/rs101:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result 2024-07-18T07:30:34Z E [rs1/rs103:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result 2024-07-18T07:30:34Z E [rs2/rs201:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result 2024-07-18T07:30:35Z W [rs2/rs202:27017] [agentCheckup] get current storage status: query mongo: mongo: no documents in result 2024-07-18T07:30:35Z E [rs2/rs202:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result 2024-07-18T07:30:35Z W [rs2/rs203:27017] [agentCheckup] get current storage status: query mongo: mongo: no documents in result 2024-07-18T07:30:35Z E [rs2/rs203:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result 2024-07-18T07:30:35Z W [rscfg/rscfg02:27017] [agentCheckup] get current storage status: query mongo: mongo: no documents in result 2024-07-18T07:30:35Z E [rscfg/rscfg02:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result 2024-07-18T07:30:35Z W [rscfg/rscfg01:27017] [agentCheckup] get current storage status: query mongo: mongo: no documents in result 2024-07-18T07:30:35Z E [rscfg/rscfg01:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result 2024-07-18T07:30:37Z W [rscfg/rscfg03:27017] [agentCheckup] get current storage status: query mongo: mongo: no documents in result 2024-07-18T07:30:37Z E [rscfg/rscfg03:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result 2024-07-18T07:30:38Z I [rs2/rs202:27017] got command resync <ts: 1721287838> 2024-07-18T07:30:38Z I [rs2/rs202:27017] got epoch {1721287838 1} 2024-07-18T07:30:38Z I [rs2/rs202:27017] [resync] not a member of the leader rs 2024-07-18T07:30:38Z I [rs2/rs203:27017] got command resync <ts: 1721287838> 2024-07-18T07:30:38Z I [rs2/rs203:27017] got epoch {1721287838 1} 2024-07-18T07:30:38Z I [rs2/rs203:27017] [resync] not a member of the leader rs 2024-07-18T07:30:38Z I [rscfg/rscfg02:27017] got command resync <ts: 1721287838> 2024-07-18T07:30:38Z I [rscfg/rscfg02:27017] got epoch {1721287838 1} 2024-07-18T07:30:38Z I [rscfg/rscfg02:27017] [resync] started 2024-07-18T07:30:38Z I [rscfg/rscfg01:27017] got command resync <ts: 1721287838> 2024-07-18T07:30:38Z I [rscfg/rscfg01:27017] got epoch {1721287838 1} 2024-07-18T07:30:38Z D [rscfg/rscfg01:27017] [resync] lock not acquired 2024-07-18T07:30:38Z D [rscfg/rscfg02:27017] [resync] got backups list: 0 2024-07-18T07:30:38Z D [rscfg/rscfg02:27017] [resync] got physical restores list: 0 2024-07-18T07:30:38Z D [rscfg/rscfg02:27017] [resync] epoch set to {1721287838 21} 2024-07-18T07:30:38Z I [rscfg/rscfg02:27017] [resync] succeed 2024-07-18T07:30:39Z I [rs1/rs101:27017] got command resync <ts: 1721287838> 2024-07-18T07:30:39Z I [rs1/rs101:27017] got epoch {1721287838 21} 2024-07-18T07:30:39Z I [rs1/rs102:27017] got command resync <ts: 1721287838> 2024-07-18T07:30:39Z I [rs1/rs103:27017] got command resync <ts: 1721287838> 2024-07-18T07:30:39Z I [rs1/rs101:27017] [resync] not a member of the leader rs 2024-07-18T07:30:39Z I [rs2/rs201:27017] got command resync <ts: 1721287838> 2024-07-18T07:30:39Z I [rs1/rs102:27017] got epoch {1721287838 21} 2024-07-18T07:30:39Z I [rs1/rs103:27017] got epoch {1721287838 21} 2024-07-18T07:30:39Z I [rs2/rs201:27017] got epoch {1721287838 21} 2024-07-18T07:30:39Z I [rs1/rs102:27017] [resync] not a member of the leader rs 2024-07-18T07:30:39Z I [rs1/rs103:27017] [resync] not a member of the leader rs 2024-07-18T07:30:39Z I [rs2/rs201:27017] [resync] not a member of the leader rs 2024-07-18T07:30:39Z I [rscfg/rscfg03:27017] got command resync <ts: 1721287838> 2024-07-18T07:30:39Z I [rscfg/rscfg03:27017] got epoch {1721287838 21} 2024-07-18T07:30:39Z D [rscfg/rscfg03:27017] [resync] get lock: duplicate operation: 6698c49e5eeeaef29d77e15c [Resync storage] 2024-07-18T07:30:39Z D [rscfg/rscfg03:27017] [resync] lock not acquired 2024-07-18T07:30:44Z I [rscfg/rscfg03:27017] got command backup [name: 2024-07-18T07:30:44Z, compression: s2 (level: default)] <ts: 1721287844> 2024-07-18T07:30:44Z I [rscfg/rscfg03:27017] got epoch {1721287838 21} 2024-07-18T07:30:44Z I [rs2/rs202:27017] got command backup [name: 2024-07-18T07:30:44Z, compression: s2 (level: default)] <ts: 1721287844> 2024-07-18T07:30:44Z I [rs2/rs202:27017] got epoch {1721287838 21} 2024-07-18T07:30:44Z I [rs2/rs203:27017] got command backup [name: 2024-07-18T07:30:44Z, compression: s2 (level: default)] <ts: 1721287844> 2024-07-18T07:30:44Z I [rs2/rs203:27017] got epoch {1721287838 21} 2024-07-18T07:30:44Z I [rscfg/rscfg02:27017] got command backup [name: 2024-07-18T07:30:44Z, compression: s2 (level: default)] <ts: 1721287844> 2024-07-18T07:30:44Z I [rscfg/rscfg02:27017] got epoch {1721287838 21} 2024-07-18T07:30:44Z I [rscfg/rscfg01:27017] got command backup [name: 2024-07-18T07:30:44Z, compression: s2 (level: default)] <ts: 1721287844> 2024-07-18T07:30:44Z I [rscfg/rscfg01:27017] got epoch {1721287838 21} 2024-07-18T07:30:44Z D [rscfg/rscfg01:27017] [backup/2024-07-18T07:30:44Z] init backup meta 2024-07-18T07:30:44Z D [rscfg/rscfg01:27017] [backup/2024-07-18T07:30:44Z] nomination list for rscfg: [[rscfg02:27017 rscfg03:27017] [rscfg01:27017]] 2024-07-18T07:30:44Z D [rscfg/rscfg01:27017] [backup/2024-07-18T07:30:44Z] nomination list for rs1: [[rs102:27017 rs103:27017] [rs101:27017]] 2024-07-18T07:30:44Z D [rscfg/rscfg01:27017] [backup/2024-07-18T07:30:44Z] nomination list for rs2: [[rs202:27017 rs203:27017] [rs201:27017]] 2024-07-18T07:30:44Z D [rscfg/rscfg01:27017] [backup/2024-07-18T07:30:44Z] nomination rs1, set candidates [rs102:27017 rs103:27017] 2024-07-18T07:30:44Z D [rscfg/rscfg01:27017] [backup/2024-07-18T07:30:44Z] nomination rscfg, set candidates [rscfg02:27017 rscfg03:27017] 2024-07-18T07:30:44Z D [rscfg/rscfg01:27017] [backup/2024-07-18T07:30:44Z] nomination rs2, set candidates [rs202:27017 rs203:27017] 2024-07-18T07:30:45Z I [rs1/rs101:27017] got command backup [name: 2024-07-18T07:30:44Z, compression: s2 (level: default)] <ts: 1721287844> 2024-07-18T07:30:45Z I [rs1/rs102:27017] got command backup [name: 2024-07-18T07:30:44Z, compression: s2 (level: default)] <ts: 1721287844> 2024-07-18T07:30:45Z I [rs1/rs103:27017] got command backup [name: 2024-07-18T07:30:44Z, compression: s2 (level: default)] <ts: 1721287844> 2024-07-18T07:30:45Z I [rs1/rs101:27017] got epoch {1721287838 21} 2024-07-18T07:30:45Z I [rs2/rs201:27017] got command backup [name: 2024-07-18T07:30:44Z, compression: s2 (level: default)] <ts: 1721287844> 2024-07-18T07:30:45Z I [rs1/rs102:27017] got epoch {1721287838 21} 2024-07-18T07:30:45Z I [rs1/rs103:27017] got epoch {1721287838 21} 2024-07-18T07:30:45Z I [rs2/rs201:27017] got epoch {1721287838 21} 2024-07-18T07:30:45Z I [rs2/rs202:27017] [backup/2024-07-18T07:30:44Z] backup started 2024-07-18T07:30:45Z D [rs2/rs203:27017] [backup/2024-07-18T07:30:44Z] skip after nomination, probably started by another node 2024-07-18T07:30:45Z I [rscfg/rscfg02:27017] [backup/2024-07-18T07:30:44Z] backup started 2024-07-18T07:30:45Z D [rscfg/rscfg01:27017] [backup/2024-07-18T07:30:44Z] skip after nomination, probably started by another node 2024-07-18T07:30:45Z D [rscfg/rscfg03:27017] [backup/2024-07-18T07:30:44Z] skip after nomination, probably started by another node 2024-07-18T07:30:45Z D [rscfg/rscfg02:27017] [backup/2024-07-18T07:30:44Z] waiting for balancer off 2024-07-18T07:30:45Z D [rs2/rs201:27017] [backup/2024-07-18T07:30:44Z] skip after nomination, probably started by another node 2024-07-18T07:30:45Z D [rs1/rs103:27017] [backup/2024-07-18T07:30:44Z] skip: lock not acquired 2024-07-18T07:30:45Z I [rs1/rs102:27017] [backup/2024-07-18T07:30:44Z] backup started 2024-07-18T07:30:46Z D [rscfg/rscfg02:27017] [backup/2024-07-18T07:30:44Z] balancer status: off 2024-07-18T07:30:46Z D [rs1/rs101:27017] [backup/2024-07-18T07:30:44Z] skip after nomination, probably started by another node 2024-07-18T07:30:48Z D [rs2/rs202:27017] [backup/2024-07-18T07:30:44Z] wait for tmp users {1721287848 5} 2024-07-18T07:30:48Z D [rs1/rs102:27017] [backup/2024-07-18T07:30:44Z] wait for tmp users {1721287848 5} 2024-07-18T07:30:48Z I [rs1/rs102:27017] [backup/2024-07-18T07:30:44Z] mongodump finished, waiting for the oplog 2024-07-18T07:30:49Z D [rscfg/rscfg02:27017] [backup/2024-07-18T07:30:44Z] wait for tmp users {1721287849 5} 2024-07-18T07:30:49Z I [rscfg/rscfg02:27017] [backup/2024-07-18T07:30:44Z] mongodump finished, waiting for the oplog 2024-07-18T07:30:49Z I [rs2/rs202:27017] [backup/2024-07-18T07:30:44Z] mongodump finished, waiting for the oplog 2024-07-18T07:30:49Z D [rscfg/rscfg01:27017] [backup/2024-07-18T07:30:44Z] bcp nomination: rs1 won by rs102:27017 2024-07-18T07:30:49Z D [rscfg/rscfg01:27017] [backup/2024-07-18T07:30:44Z] bcp nomination: rs2 won by rs202:27017 2024-07-18T07:30:49Z D [rscfg/rscfg01:27017] [backup/2024-07-18T07:30:44Z] bcp nomination: rscfg won by rscfg02:27017 2024-07-18T07:30:52Z I [rscfg/rscfg02:27017] [backup/2024-07-18T07:30:44Z] created chunk 2024-07-18T07:30:45 - 2024-07-18T07:30:50 2024-07-18T07:30:58Z I [rs2/rs202:27017] [backup/2024-07-18T07:30:44Z] created chunk 2024-07-18T07:30:44 - 2024-07-18T07:30:48 2024-07-18T07:30:58Z I [rs2/rs202:27017] [backup/2024-07-18T07:30:44Z] dropping tmp collections 2024-07-18T07:30:59Z I [rs1/rs102:27017] [backup/2024-07-18T07:30:44Z] created chunk 2024-07-18T07:30:44 - 2024-07-18T07:30:48 2024-07-18T07:30:59Z I [rs1/rs102:27017] [backup/2024-07-18T07:30:44Z] dropping tmp collections 2024-07-18T07:31:00Z I [rscfg/rscfg02:27017] [backup/2024-07-18T07:30:44Z] dropping tmp collections 2024-07-18T07:31:01Z D [rs1/rs102:27017] [backup/2024-07-18T07:30:44Z] set balancer on 2024-07-18T07:31:01Z I [rs1/rs102:27017] [backup/2024-07-18T07:30:44Z] backup finished 2024-07-18T07:31:01Z D [rs1/rs102:27017] [backup/2024-07-18T07:30:44Z] releasing lock 2024-07-18T07:31:01Z D [rs2/rs202:27017] [backup/2024-07-18T07:30:44Z] set balancer on 2024-07-18T07:31:01Z I [rs2/rs202:27017] [backup/2024-07-18T07:30:44Z] backup finished 2024-07-18T07:31:01Z D [rs2/rs202:27017] [backup/2024-07-18T07:30:44Z] releasing lock 2024-07-18T07:31:02Z D [rscfg/rscfg02:27017] [backup/2024-07-18T07:30:44Z] set balancer on 2024-07-18T07:31:02Z I [rscfg/rscfg02:27017] [backup/2024-07-18T07:30:44Z] backup finished 2024-07-18T07:31:02Z D [rscfg/rscfg02:27017] [backup/2024-07-18T07:30:44Z] releasing lock assert False
Raw output
start_cluster = True, cluster = <cluster.Cluster object at 0x7ff28ab28ed0>

    @pytest.mark.timeout(600,func_only=True)
    def test_logical_PBM_T255(start_cluster,cluster):
        def insert_docs():
            client=pymongo.MongoClient(cluster.connection)
            for i in range(200):
                client['test']['test'].insert_one({"doc":i})
                time.sleep(1)
    
        cluster.check_pbm_status()
        cluster.make_backup("logical")
        cluster.exec_pbm_cli("config --file=/etc/pbm-1043.conf")
        time.sleep(60)
        Cluster.log("Check if PITR is running")
        if not cluster.check_pitr():
            logs=cluster.exec_pbm_cli("logs -sD -t0")
>           assert False, logs.stdout
E           AssertionError: 2024-07-18T07:30:29Z I [rs2/rs201:27017] pbm-agent:
E             Version:   2.5.0
E             Platform:  linux/amd64
E             GitCommit: ae58fb510bc6cdb2648f154e729a205e78aae9cd
E             GitBranch: dev
E             BuildTime: 2024-07-18_07:29_UTC
E             GoVersion: go1.22.5
E             2024-07-18T07:30:29Z I [rs1/rs101:27017] starting PITR routine
E             2024-07-18T07:30:29Z I [rs1/rs102:27017] pbm-agent:
E             Version:   2.5.0
E             Platform:  linux/amd64
E             GitCommit: ae58fb510bc6cdb2648f154e729a205e78aae9cd
E             GitBranch: dev
E             BuildTime: 2024-07-18_07:29_UTC
E             GoVersion: go1.22.5
E             2024-07-18T07:30:29Z I [rs1/rs101:27017] pbm-agent:
E             Version:   2.5.0
E             Platform:  linux/amd64
E             GitCommit: ae58fb510bc6cdb2648f154e729a205e78aae9cd
E             GitBranch: dev
E             BuildTime: 2024-07-18_07:29_UTC
E             GoVersion: go1.22.5
E             2024-07-18T07:30:29Z I [rs2/rs201:27017] starting PITR routine
E             2024-07-18T07:30:29Z I [rs1/rs102:27017] starting PITR routine
E             2024-07-18T07:30:29Z I [rs1/rs103:27017] pbm-agent:
E             Version:   2.5.0
E             Platform:  linux/amd64
E             GitCommit: ae58fb510bc6cdb2648f154e729a205e78aae9cd
E             GitBranch: dev
E             BuildTime: 2024-07-18_07:29_UTC
E             GoVersion: go1.22.5
E             2024-07-18T07:30:29Z I [rs1/rs103:27017] starting PITR routine
E             2024-07-18T07:30:29Z I [rs1/rs101:27017] node: rs1/rs101:27017
E             2024-07-18T07:30:29Z I [rs2/rs201:27017] node: rs2/rs201:27017
E             2024-07-18T07:30:29Z I [rs1/rs102:27017] node: rs1/rs102:27017
E             2024-07-18T07:30:29Z I [rs1/rs101:27017] conn level ReadConcern: majority; WriteConcern: majority
E             2024-07-18T07:30:29Z I [rs1/rs103:27017] node: rs1/rs103:27017
E             2024-07-18T07:30:29Z I [rs2/rs201:27017] conn level ReadConcern: majority; WriteConcern: majority
E             2024-07-18T07:30:29Z I [rs1/rs102:27017] conn level ReadConcern: majority; WriteConcern: majority
E             2024-07-18T07:30:29Z I [rs1/rs101:27017] listening for the commands
E             2024-07-18T07:30:29Z I [rs1/rs103:27017] conn level ReadConcern: majority; WriteConcern: majority
E             2024-07-18T07:30:29Z I [rs2/rs201:27017] listening for the commands
E             2024-07-18T07:30:29Z I [rs1/rs102:27017] listening for the commands
E             2024-07-18T07:30:29Z I [rs1/rs103:27017] listening for the commands
E             2024-07-18T07:30:30Z I [rs2/rs202:27017] pbm-agent:
E             Version:   2.5.0
E             Platform:  linux/amd64
E             GitCommit: ae58fb510bc6cdb2648f154e729a205e78aae9cd
E             GitBranch: dev
E             BuildTime: 2024-07-18_07:29_UTC
E             GoVersion: go1.22.5
E             2024-07-18T07:30:30Z I [rs2/rs202:27017] starting PITR routine
E             2024-07-18T07:30:30Z I [rs2/rs202:27017] node: rs2/rs202:27017
E             2024-07-18T07:30:30Z I [rs2/rs202:27017] conn level ReadConcern: majority; WriteConcern: majority
E             2024-07-18T07:30:30Z I [rs2/rs202:27017] listening for the commands
E             2024-07-18T07:30:30Z I [rs2/rs203:27017] pbm-agent:
E             Version:   2.5.0
E             Platform:  linux/amd64
E             GitCommit: ae58fb510bc6cdb2648f154e729a205e78aae9cd
E             GitBranch: dev
E             BuildTime: 2024-07-18_07:29_UTC
E             GoVersion: go1.22.5
E             2024-07-18T07:30:30Z I [rs2/rs203:27017] starting PITR routine
E             2024-07-18T07:30:30Z I [rs2/rs203:27017] node: rs2/rs203:27017
E             2024-07-18T07:30:30Z I [rs2/rs203:27017] conn level ReadConcern: majority; WriteConcern: majority
E             2024-07-18T07:30:30Z I [rs2/rs203:27017] listening for the commands
E             2024-07-18T07:30:30Z I [rscfg/rscfg02:27017] pbm-agent:
E             Version:   2.5.0
E             Platform:  linux/amd64
E             GitCommit: ae58fb510bc6cdb2648f154e729a205e78aae9cd
E             GitBranch: dev
E             BuildTime: 2024-07-18_07:29_UTC
E             GoVersion: go1.22.5
E             2024-07-18T07:30:30Z I [rscfg/rscfg02:27017] starting PITR routine
E             2024-07-18T07:30:30Z I [rscfg/rscfg02:27017] node: rscfg/rscfg02:27017
E             2024-07-18T07:30:30Z I [rscfg/rscfg02:27017] conn level ReadConcern: majority; WriteConcern: majority
E             2024-07-18T07:30:30Z I [rscfg/rscfg02:27017] listening for the commands
E             2024-07-18T07:30:30Z I [rscfg/rscfg01:27017] pbm-agent:
E             Version:   2.5.0
E             Platform:  linux/amd64
E             GitCommit: ae58fb510bc6cdb2648f154e729a205e78aae9cd
E             GitBranch: dev
E             BuildTime: 2024-07-18_07:29_UTC
E             GoVersion: go1.22.5
E             2024-07-18T07:30:30Z I [rscfg/rscfg01:27017] starting PITR routine
E             2024-07-18T07:30:30Z I [rscfg/rscfg01:27017] node: rscfg/rscfg01:27017
E             2024-07-18T07:30:30Z I [rscfg/rscfg01:27017] conn level ReadConcern: majority; WriteConcern: majority
E             2024-07-18T07:30:30Z I [rscfg/rscfg01:27017] listening for the commands
E             2024-07-18T07:30:32Z I [rscfg/rscfg03:27017] pbm-agent:
E             Version:   2.5.0
E             Platform:  linux/amd64
E             GitCommit: ae58fb510bc6cdb2648f154e729a205e78aae9cd
E             GitBranch: dev
E             BuildTime: 2024-07-18_07:29_UTC
E             GoVersion: go1.22.5
E             2024-07-18T07:30:32Z I [rscfg/rscfg03:27017] starting PITR routine
E             2024-07-18T07:30:32Z I [rscfg/rscfg03:27017] node: rscfg/rscfg03:27017
E             2024-07-18T07:30:32Z I [rscfg/rscfg03:27017] conn level ReadConcern: majority; WriteConcern: majority
E             2024-07-18T07:30:32Z I [rscfg/rscfg03:27017] listening for the commands
E             2024-07-18T07:30:34Z W [rs1/rs101:27017] [agentCheckup] get current storage status: query mongo: mongo: no documents in result
E             2024-07-18T07:30:34Z W [rs1/rs102:27017] [agentCheckup] get current storage status: query mongo: mongo: no documents in result
E             2024-07-18T07:30:34Z W [rs1/rs103:27017] [agentCheckup] get current storage status: query mongo: mongo: no documents in result
E             2024-07-18T07:30:34Z W [rs2/rs201:27017] [agentCheckup] get current storage status: query mongo: mongo: no documents in result
E             2024-07-18T07:30:34Z E [rs1/rs102:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
E             2024-07-18T07:30:34Z E [rs1/rs101:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
E             2024-07-18T07:30:34Z E [rs1/rs103:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
E             2024-07-18T07:30:34Z E [rs2/rs201:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
E             2024-07-18T07:30:35Z W [rs2/rs202:27017] [agentCheckup] get current storage status: query mongo: mongo: no documents in result
E             2024-07-18T07:30:35Z E [rs2/rs202:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
E             2024-07-18T07:30:35Z W [rs2/rs203:27017] [agentCheckup] get current storage status: query mongo: mongo: no documents in result
E             2024-07-18T07:30:35Z E [rs2/rs203:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
E             2024-07-18T07:30:35Z W [rscfg/rscfg02:27017] [agentCheckup] get current storage status: query mongo: mongo: no documents in result
E             2024-07-18T07:30:35Z E [rscfg/rscfg02:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
E             2024-07-18T07:30:35Z W [rscfg/rscfg01:27017] [agentCheckup] get current storage status: query mongo: mongo: no documents in result
E             2024-07-18T07:30:35Z E [rscfg/rscfg01:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
E             2024-07-18T07:30:37Z W [rscfg/rscfg03:27017] [agentCheckup] get current storage status: query mongo: mongo: no documents in result
E             2024-07-18T07:30:37Z E [rscfg/rscfg03:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
E             2024-07-18T07:30:38Z I [rs2/rs202:27017] got command resync <ts: 1721287838>
E             2024-07-18T07:30:38Z I [rs2/rs202:27017] got epoch {1721287838 1}
E             2024-07-18T07:30:38Z I [rs2/rs202:27017] [resync] not a member of the leader rs
E             2024-07-18T07:30:38Z I [rs2/rs203:27017] got command resync <ts: 1721287838>
E             2024-07-18T07:30:38Z I [rs2/rs203:27017] got epoch {1721287838 1}
E             2024-07-18T07:30:38Z I [rs2/rs203:27017] [resync] not a member of the leader rs
E             2024-07-18T07:30:38Z I [rscfg/rscfg02:27017] got command resync <ts: 1721287838>
E             2024-07-18T07:30:38Z I [rscfg/rscfg02:27017] got epoch {1721287838 1}
E             2024-07-18T07:30:38Z I [rscfg/rscfg02:27017] [resync] started
E             2024-07-18T07:30:38Z I [rscfg/rscfg01:27017] got command resync <ts: 1721287838>
E             2024-07-18T07:30:38Z I [rscfg/rscfg01:27017] got epoch {1721287838 1}
E             2024-07-18T07:30:38Z D [rscfg/rscfg01:27017] [resync] lock not acquired
E             2024-07-18T07:30:38Z D [rscfg/rscfg02:27017] [resync] got backups list: 0
E             2024-07-18T07:30:38Z D [rscfg/rscfg02:27017] [resync] got physical restores list: 0
E             2024-07-18T07:30:38Z D [rscfg/rscfg02:27017] [resync] epoch set to {1721287838 21}
E             2024-07-18T07:30:38Z I [rscfg/rscfg02:27017] [resync] succeed
E             2024-07-18T07:30:39Z I [rs1/rs101:27017] got command resync <ts: 1721287838>
E             2024-07-18T07:30:39Z I [rs1/rs101:27017] got epoch {1721287838 21}
E             2024-07-18T07:30:39Z I [rs1/rs102:27017] got command resync <ts: 1721287838>
E             2024-07-18T07:30:39Z I [rs1/rs103:27017] got command resync <ts: 1721287838>
E             2024-07-18T07:30:39Z I [rs1/rs101:27017] [resync] not a member of the leader rs
E             2024-07-18T07:30:39Z I [rs2/rs201:27017] got command resync <ts: 1721287838>
E             2024-07-18T07:30:39Z I [rs1/rs102:27017] got epoch {1721287838 21}
E             2024-07-18T07:30:39Z I [rs1/rs103:27017] got epoch {1721287838 21}
E             2024-07-18T07:30:39Z I [rs2/rs201:27017] got epoch {1721287838 21}
E             2024-07-18T07:30:39Z I [rs1/rs102:27017] [resync] not a member of the leader rs
E             2024-07-18T07:30:39Z I [rs1/rs103:27017] [resync] not a member of the leader rs
E             2024-07-18T07:30:39Z I [rs2/rs201:27017] [resync] not a member of the leader rs
E             2024-07-18T07:30:39Z I [rscfg/rscfg03:27017] got command resync <ts: 1721287838>
E             2024-07-18T07:30:39Z I [rscfg/rscfg03:27017] got epoch {1721287838 21}
E             2024-07-18T07:30:39Z D [rscfg/rscfg03:27017] [resync] get lock: duplicate operation: 6698c49e5eeeaef29d77e15c [Resync storage]
E             2024-07-18T07:30:39Z D [rscfg/rscfg03:27017] [resync] lock not acquired
E             2024-07-18T07:30:44Z I [rscfg/rscfg03:27017] got command backup [name: 2024-07-18T07:30:44Z, compression: s2 (level: default)] <ts: 1721287844>
E             2024-07-18T07:30:44Z I [rscfg/rscfg03:27017] got epoch {1721287838 21}
E             2024-07-18T07:30:44Z I [rs2/rs202:27017] got command backup [name: 2024-07-18T07:30:44Z, compression: s2 (level: default)] <ts: 1721287844>
E             2024-07-18T07:30:44Z I [rs2/rs202:27017] got epoch {1721287838 21}
E             2024-07-18T07:30:44Z I [rs2/rs203:27017] got command backup [name: 2024-07-18T07:30:44Z, compression: s2 (level: default)] <ts: 1721287844>
E             2024-07-18T07:30:44Z I [rs2/rs203:27017] got epoch {1721287838 21}
E             2024-07-18T07:30:44Z I [rscfg/rscfg02:27017] got command backup [name: 2024-07-18T07:30:44Z, compression: s2 (level: default)] <ts: 1721287844>
E             2024-07-18T07:30:44Z I [rscfg/rscfg02:27017] got epoch {1721287838 21}
E             2024-07-18T07:30:44Z I [rscfg/rscfg01:27017] got command backup [name: 2024-07-18T07:30:44Z, compression: s2 (level: default)] <ts: 1721287844>
E             2024-07-18T07:30:44Z I [rscfg/rscfg01:27017] got epoch {1721287838 21}
E             2024-07-18T07:30:44Z D [rscfg/rscfg01:27017] [backup/2024-07-18T07:30:44Z] init backup meta
E             2024-07-18T07:30:44Z D [rscfg/rscfg01:27017] [backup/2024-07-18T07:30:44Z] nomination list for rscfg: [[rscfg02:27017 rscfg03:27017] [rscfg01:27017]]
E             2024-07-18T07:30:44Z D [rscfg/rscfg01:27017] [backup/2024-07-18T07:30:44Z] nomination list for rs1: [[rs102:27017 rs103:27017] [rs101:27017]]
E             2024-07-18T07:30:44Z D [rscfg/rscfg01:27017] [backup/2024-07-18T07:30:44Z] nomination list for rs2: [[rs202:27017 rs203:27017] [rs201:27017]]
E             2024-07-18T07:30:44Z D [rscfg/rscfg01:27017] [backup/2024-07-18T07:30:44Z] nomination rs1, set candidates [rs102:27017 rs103:27017]
E             2024-07-18T07:30:44Z D [rscfg/rscfg01:27017] [backup/2024-07-18T07:30:44Z] nomination rscfg, set candidates [rscfg02:27017 rscfg03:27017]
E             2024-07-18T07:30:44Z D [rscfg/rscfg01:27017] [backup/2024-07-18T07:30:44Z] nomination rs2, set candidates [rs202:27017 rs203:27017]
E             2024-07-18T07:30:45Z I [rs1/rs101:27017] got command backup [name: 2024-07-18T07:30:44Z, compression: s2 (level: default)] <ts: 1721287844>
E             2024-07-18T07:30:45Z I [rs1/rs102:27017] got command backup [name: 2024-07-18T07:30:44Z, compression: s2 (level: default)] <ts: 1721287844>
E             2024-07-18T07:30:45Z I [rs1/rs103:27017] got command backup [name: 2024-07-18T07:30:44Z, compression: s2 (level: default)] <ts: 1721287844>
E             2024-07-18T07:30:45Z I [rs1/rs101:27017] got epoch {1721287838 21}
E             2024-07-18T07:30:45Z I [rs2/rs201:27017] got command backup [name: 2024-07-18T07:30:44Z, compression: s2 (level: default)] <ts: 1721287844>
E             2024-07-18T07:30:45Z I [rs1/rs102:27017] got epoch {1721287838 21}
E             2024-07-18T07:30:45Z I [rs1/rs103:27017] got epoch {1721287838 21}
E             2024-07-18T07:30:45Z I [rs2/rs201:27017] got epoch {1721287838 21}
E             2024-07-18T07:30:45Z I [rs2/rs202:27017] [backup/2024-07-18T07:30:44Z] backup started
E             2024-07-18T07:30:45Z D [rs2/rs203:27017] [backup/2024-07-18T07:30:44Z] skip after nomination, probably started by another node
E             2024-07-18T07:30:45Z I [rscfg/rscfg02:27017] [backup/2024-07-18T07:30:44Z] backup started
E             2024-07-18T07:30:45Z D [rscfg/rscfg01:27017] [backup/2024-07-18T07:30:44Z] skip after nomination, probably started by another node
E             2024-07-18T07:30:45Z D [rscfg/rscfg03:27017] [backup/2024-07-18T07:30:44Z] skip after nomination, probably started by another node
E             2024-07-18T07:30:45Z D [rscfg/rscfg02:27017] [backup/2024-07-18T07:30:44Z] waiting for balancer off
E             2024-07-18T07:30:45Z D [rs2/rs201:27017] [backup/2024-07-18T07:30:44Z] skip after nomination, probably started by another node
E             2024-07-18T07:30:45Z D [rs1/rs103:27017] [backup/2024-07-18T07:30:44Z] skip: lock not acquired
E             2024-07-18T07:30:45Z I [rs1/rs102:27017] [backup/2024-07-18T07:30:44Z] backup started
E             2024-07-18T07:30:46Z D [rscfg/rscfg02:27017] [backup/2024-07-18T07:30:44Z] balancer status: off
E             2024-07-18T07:30:46Z D [rs1/rs101:27017] [backup/2024-07-18T07:30:44Z] skip after nomination, probably started by another node
E             2024-07-18T07:30:48Z D [rs2/rs202:27017] [backup/2024-07-18T07:30:44Z] wait for tmp users {1721287848 5}
E             2024-07-18T07:30:48Z D [rs1/rs102:27017] [backup/2024-07-18T07:30:44Z] wait for tmp users {1721287848 5}
E             2024-07-18T07:30:48Z I [rs1/rs102:27017] [backup/2024-07-18T07:30:44Z] mongodump finished, waiting for the oplog
E             2024-07-18T07:30:49Z D [rscfg/rscfg02:27017] [backup/2024-07-18T07:30:44Z] wait for tmp users {1721287849 5}
E             2024-07-18T07:30:49Z I [rscfg/rscfg02:27017] [backup/2024-07-18T07:30:44Z] mongodump finished, waiting for the oplog
E             2024-07-18T07:30:49Z I [rs2/rs202:27017] [backup/2024-07-18T07:30:44Z] mongodump finished, waiting for the oplog
E             2024-07-18T07:30:49Z D [rscfg/rscfg01:27017] [backup/2024-07-18T07:30:44Z] bcp nomination: rs1 won by rs102:27017
E             2024-07-18T07:30:49Z D [rscfg/rscfg01:27017] [backup/2024-07-18T07:30:44Z] bcp nomination: rs2 won by rs202:27017
E             2024-07-18T07:30:49Z D [rscfg/rscfg01:27017] [backup/2024-07-18T07:30:44Z] bcp nomination: rscfg won by rscfg02:27017
E             2024-07-18T07:30:52Z I [rscfg/rscfg02:27017] [backup/2024-07-18T07:30:44Z] created chunk 2024-07-18T07:30:45 - 2024-07-18T07:30:50
E             2024-07-18T07:30:58Z I [rs2/rs202:27017] [backup/2024-07-18T07:30:44Z] created chunk 2024-07-18T07:30:44 - 2024-07-18T07:30:48
E             2024-07-18T07:30:58Z I [rs2/rs202:27017] [backup/2024-07-18T07:30:44Z] dropping tmp collections
E             2024-07-18T07:30:59Z I [rs1/rs102:27017] [backup/2024-07-18T07:30:44Z] created chunk 2024-07-18T07:30:44 - 2024-07-18T07:30:48
E             2024-07-18T07:30:59Z I [rs1/rs102:27017] [backup/2024-07-18T07:30:44Z] dropping tmp collections
E             2024-07-18T07:31:00Z I [rscfg/rscfg02:27017] [backup/2024-07-18T07:30:44Z] dropping tmp collections
E             2024-07-18T07:31:01Z D [rs1/rs102:27017] [backup/2024-07-18T07:30:44Z] set balancer on
E             2024-07-18T07:31:01Z I [rs1/rs102:27017] [backup/2024-07-18T07:30:44Z] backup finished
E             2024-07-18T07:31:01Z D [rs1/rs102:27017] [backup/2024-07-18T07:30:44Z] releasing lock
E             2024-07-18T07:31:01Z D [rs2/rs202:27017] [backup/2024-07-18T07:30:44Z] set balancer on
E             2024-07-18T07:31:01Z I [rs2/rs202:27017] [backup/2024-07-18T07:30:44Z] backup finished
E             2024-07-18T07:31:01Z D [rs2/rs202:27017] [backup/2024-07-18T07:30:44Z] releasing lock
E             2024-07-18T07:31:02Z D [rscfg/rscfg02:27017] [backup/2024-07-18T07:30:44Z] set balancer on
E             2024-07-18T07:31:02Z I [rscfg/rscfg02:27017] [backup/2024-07-18T07:30:44Z] backup finished
E             2024-07-18T07:31:02Z D [rscfg/rscfg02:27017] [backup/2024-07-18T07:30:44Z] releasing lock
E             
E           assert False

test_PBM-1043.py:64: AssertionError


Cluster.log("Start inserting docs in the background")
background_insert = threading.Thread(target=insert_docs)
background_insert.start()
time.sleep(60)
Cluster.log("Check if oplog slicer has been started on the nodes with the highest priorities")
logs=cluster.exec_pbm_cli("logs -sD -t0 -e pitr")
assert '[rscfg/rscfg03:27017] [pitr] created chunk' in logs.stdout
assert '[rs1/rs103:27017] [pitr] created chunk' in logs.stdout
assert '[rs2/rs203:27017] [pitr] created chunk' in logs.stdout

nrs103=testinfra.get_host("docker://rs103")
nrs203=testinfra.get_host("docker://rs203")

Cluster.log("Oplog slicer should survive if either mongo or pbm-agent is unavailable")
nrs103.check_output('supervisorctl stop mongod')
nrs203.check_output('supervisorctl stop pbm-agent')

time.sleep(60)

Cluster.log("Start pbm-agent and mongod")
nrs103.check_output('supervisorctl start mongod')
nrs203.check_output('supervisorctl start pbm-agent')

time.sleep(60)
background_insert.join()

assert pymongo.MongoClient(cluster.connection)["test"]["test"].count_documents({}) == 200
pitr = datetime.utcnow().strftime("%Y-%m-%dT%H:%M:%S")
backup="--time=" + pitr
Cluster.log("Time for PITR is: " + pitr)
time.sleep(60)
cluster.disable_pitr()
pymongo.MongoClient(cluster.connection).drop_database('test')
status=cluster.exec_pbm_cli("status")
Cluster.log(status.stdout)
cluster.make_restore(backup,check_pbm_status=True)
assert pymongo.MongoClient(cluster.connection)["test"]["test"].count_documents({}) == 200
assert pymongo.MongoClient(cluster.connection)["test"].command("collstats", "test").get("sharded", False)
time.sleep(60)
Cluster.log("PITR must be disabled after the restore")
assert not cluster.check_pitr()
cluster.check_pbm_status()
Loading