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-1297 re-enable the test #220

Merged
merged 1 commit into from
Sep 18, 2024
Merged
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
2 changes: 1 addition & 1 deletion pbm-functional/pytest/test_PBM-1297.py
Original file line number Diff line number Diff line change
Expand Up @@ -60,7 +60,7 @@
newcluster.destroy(cleanup_backups=True)

@pytest.mark.timeout(600, func_only=True)
def test_disabled_pitr_PBM_T253(start_cluster,cluster,newcluster):
def test_logical_pitr_PBM_T253(start_cluster,cluster,newcluster):
cluster.check_pbm_status()
cluster.make_backup("logical")
cluster.enable_pitr(pitr_extra_args="--set pitr.oplogSpanMin=0.5")
Expand All @@ -83,7 +83,7 @@
newcluster.setup_pbm()
time.sleep(10)
newcluster.check_pbm_status()
newcluster.make_restore(backup,check_pbm_status=True)

Check failure on line 86 in pbm-functional/pytest/test_PBM-1297.py

View workflow job for this annotation

GitHub Actions / JUnit Test Report

test_PBM-1297.test_logical_pitr_PBM_T253

AssertionError: Starting restore 2024-09-18T07:21:17.969503978Z to point-in-time 2024-09-18T07:19:42 from '2024-09-18T07:18:19Z'....Started logical restore. Waiting to finish...Error: operation failed with: reply oplog: replay chunk 1726643903.1726643981: apply oplog for chunk: applying an entry: op: {"Timestamp":{"T":1726643951,"I":17},"Term":1,"Hash":null,"Version":2,"Operation":"i","Namespace":"config.databases","Object":[{"Key":"_id","Value":"test"},{"Key":"primary","Value":"rs2"},{"Key":"partitioned","Value":false},{"Key":"version","Value":[{"Key":"uuid","Value":{"Subtype":4,"Data":"S/ZxH+7BRRmY+Tt7skQ3Gg=="}},{"Key":"timestamp","Value":{"T":1726643951,"I":15}},{"Key":"lastMod","Value":1}]}],"Query":[{"Key":"_id","Value":"test"}],"UI":{"Subtype":4,"Data":"1EkyHPXaT4ipjVGSZjAWUg=="},"LSID":null,"TxnNumber":null,"PrevOpTime":null,"MultiOpType":null} | merr <nil>: applyOps: (NamespaceNotFound) cannot apply insert or update operation on a non-existent namespace config.databases: { ts: Timestamp(1726643951, 17), t: 1, v: 2, op: "i", ns: "config.databases", o: { _id: "test", primary: "rs2", partitioned: false, version: { uuid: UUID("4bf6711f-eec1-4519-98f9-3b7bb244371a"), timestamp: Timestamp(1726643951, 15), lastMod: 1 } }, o2: { _id: "test" }, ui: UUID("d449321c-f5da-4f88-a98d-519266301652") }
Raw output
start_cluster = True, cluster = <cluster.Cluster object at 0x7f142e08b3d0>
newcluster = <cluster.Cluster object at 0x7f142e6d7d90>

    @pytest.mark.timeout(600, func_only=True)
    def test_logical_pitr_PBM_T253(start_cluster,cluster,newcluster):
        cluster.check_pbm_status()
        cluster.make_backup("logical")
        cluster.enable_pitr(pitr_extra_args="--set pitr.oplogSpanMin=0.5")
        #Create the first database during oplog slicing
        client=pymongo.MongoClient(cluster.connection)
        client.admin.command("enableSharding", "test")
        client.admin.command("shardCollection", "test.test", key={"_id": "hashed"})
        for i in range(100):
            pymongo.MongoClient(cluster.connection)["test"]["test"].insert_one({"doc":i})
        time.sleep(30)
        pitr = datetime.utcnow().strftime("%Y-%m-%dT%H:%M:%S")
        backup="--time=" + pitr
        Cluster.log("Time for PITR is: " + pitr)
        time.sleep(30)
        cluster.disable_pitr()
        time.sleep(10)
        cluster.destroy()
    
        newcluster.create()
        newcluster.setup_pbm()
        time.sleep(10)
        newcluster.check_pbm_status()
>       newcluster.make_restore(backup,check_pbm_status=True)

test_PBM-1297.py:86: 
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 

self = <cluster.Cluster object at 0x7f142e6d7d90>
name = '--time=2024-09-18T07:19:42', kwargs = {'check_pbm_status': True}
client = MongoClient(host=['newmongos:27017'], document_class=dict, tz_aware=False, connect=True)
result = CommandResult(backend=<testinfra.backend.docker.DockerBackend object at 0x7f142e1f4bd0>, exit_status=1, command=b'time...26643951, 15), lastMod: 1 } }, o2: { _id: "test" }, ui: UUID("d449321c-f5da-4f88-a98d-519266301652") }\n', _stderr=b'')
n = <testinfra.host.Host docker://newrscfg01>, timeout = 240, error = ''
host = 'newrscfg01', container = <Container: 49872d42fb52>

    def make_restore(self, name, **kwargs):
        if self.layout == "sharded":
            client = pymongo.MongoClient(self.connection)
            result = client.admin.command("balancerStop")
            client.close()
            Cluster.log("Stopping balancer: " + str(result))
            self.stop_mongos()
        self.stop_arbiters()
        n = testinfra.get_host("docker://" + self.pbm_cli)
        timeout = time.time() + 60
    
        while True:
            if not self.get_status()['running']:
                break
            if time.time() > timeout:
                assert False, "Cannot start restore, another operation running"
            time.sleep(1)
        Cluster.log("Restore started")
        timeout=kwargs.get('timeout', 240)
        result = n.run('timeout ' + str(timeout) + ' pbm restore ' + name + ' --wait')
    
        if result.rc == 0:
            Cluster.log(result.stdout)
        else:
            # try to catch possible failures if timeout exceeded
            error=''
            for host in self.mongod_hosts:
                try:
                    container = docker.from_env().containers.get(host)
                    get_logs = container.exec_run(
                        'cat /var/lib/mongo/pbm.restore.log', stderr=False)
                    if get_logs.exit_code == 0:
                        Cluster.log(
                            "!!!!Possible failure on {}, file pbm.restore.log was found:".format(host))
                        logs = get_logs.output.decode('utf-8')
                        Cluster.log(logs)
                        if '"s":"F"' in logs:
                            error = logs
                except docker.errors.APIError:
                    pass
            if error:
                assert False, result.stdout + result.stderr + "\n" + error
            else:
>               assert False, result.stdout + result.stderr
E               AssertionError: Starting restore 2024-09-18T07:21:17.969503978Z to point-in-time 2024-09-18T07:19:42 from '2024-09-18T07:18:19Z'....Started logical restore.
E               Waiting to finish...Error: operation failed with: reply oplog: replay chunk 1726643903.1726643981: apply oplog for chunk: applying an entry: op: {"Timestamp":{"T":1726643951,"I":17},"Term":1,"Hash":null,"Version":2,"Operation":"i","Namespace":"config.databases","Object":[{"Key":"_id","Value":"test"},{"Key":"primary","Value":"rs2"},{"Key":"partitioned","Value":false},{"Key":"version","Value":[{"Key":"uuid","Value":{"Subtype":4,"Data":"S/ZxH+7BRRmY+Tt7skQ3Gg=="}},{"Key":"timestamp","Value":{"T":1726643951,"I":15}},{"Key":"lastMod","Value":1}]}],"Query":[{"Key":"_id","Value":"test"}],"UI":{"Subtype":4,"Data":"1EkyHPXaT4ipjVGSZjAWUg=="},"LSID":null,"TxnNumber":null,"PrevOpTime":null,"MultiOpType":null} | merr <nil>: applyOps: (NamespaceNotFound) cannot apply insert or update operation on a non-existent namespace config.databases: { ts: Timestamp(1726643951, 17), t: 1, v: 2, op: "i", ns: "config.databases", o: { _id: "test", primary: "rs2", partitioned: false, version: { uuid: UUID("4bf6711f-eec1-4519-98f9-3b7bb244371a"), timestamp: Timestamp(1726643951, 15), lastMod: 1 } }, o2: { _id: "test" }, ui: UUID("d449321c-f5da-4f88-a98d-519266301652") }

cluster.py:464: AssertionError
assert pymongo.MongoClient(newcluster.connection)["test"]["test"].count_documents({}) == 100
assert pymongo.MongoClient(newcluster.connection)["test"].command("collstats", "test").get("sharded", False)
Cluster.log("Finished successfully")
Expand Down
Loading