Skip to content

[PBM-1171] support mixed env in pre-check validation #484

[PBM-1171] support mixed env in pre-check validation

[PBM-1171] support mixed env in pre-check validation #484

This check has been archived and is scheduled for deletion. Learn more about checks retention
GitHub Actions / JUnit Test Report failed Sep 14, 2023 in 0s

14 tests run, 13 passed, 0 skipped, 1 failed.

Annotations

Check failure on line 76 in psmdb-testing/pbm-functional/pytest/test_remap_sharded.py

See this annotation in the file changed.

@github-actions github-actions / JUnit Test Report

test_remap_sharded.test_logical

AssertionError: Starting restore 2023-09-14T13:59:59.659421228Z from '2023-09-14T13:59:30Z'...Started logical restore.
Waiting to finish.....Error: operation failed with: reply oplog: replay chunk 1694699969.1694699976: apply oplog for chunk: applying an entry: op: {"Timestamp":{"T":1694699969,"I":12},"Term":1,"Hash":null,"Version":2,"Operation":"i","Namespace":"config.changelog","Object":[{"Key":"_id","Value":"rs101:27017-2023-09-14T13:59:29.314+00:00-650311c1650ad48eeeab40d6"},{"Key":"server","Value":"rs101:27017"},{"Key":"shard","Value":"rs1"},{"Key":"clientAddr","Value":"172.18.0.15:43502"},{"Key":"time","Value":"2023-09-14T13:59:29.314Z"},{"Key":"what","Value":"shardCollection.end"},{"Key":"ns","Value":"test.test"},{"Key":"details","Value":[{"Key":"version","Value":"1|3||650311bf650ad48eeeab4091"},{"Key":"numChunks","Value":4}]}],"Query":null,"UI":{"Subtype":4,"Data":"8NQTNAcISr+0vIFVOttnDw=="},"LSID":null,"TxnNumber":null,"PrevOpTime":null} | merr <nil>: applyOps: (NamespaceNotFound) Failed to apply operation due to missing collection (f0d41334-0708-4abf-b4bc-81553adb670f): { ts: Timestamp(1694699969, 12), t: 1, h: null, v: 2, op: "i", ns: "config.changelog", o: { _id: "rs101:27017-2023-09-14T13:59:29.314+00:00-650311c1650ad48eeeab40d6", server: "rs101:27017", shard: "rs1", clientAddr: "172.18.0.15:43502", time: new Date(1694699969314), what: "shardCollection.end", ns: "test.test", details: { version: "1|3||650311bf650ad48eeeab4091", numChunks: 4 } }, ui: UUID("f0d41334-0708-4abf-b4bc-81553adb670f"), wall: new Date(0) }
Raw output
start_cluster = True, cluster = <cluster.Cluster object at 0x7f7277a5c690>
newcluster = <cluster.Cluster object at 0x7f7277930950>

    @pytest.mark.testcase(test_case_key="T211", test_step_key=1)
    @pytest.mark.timeout(600,func_only=True)
    def test_logical(start_cluster,cluster,newcluster):
        cluster.check_pbm_status()
        pymongo.MongoClient(cluster.connection)["test"]["test"].insert_many(documents)
        backup=cluster.make_backup("logical")
        backup = backup + ' --replset-remapping="newrs1=rs1,newrs2=rs2,newrscfg=rscfg"'
        cluster.destroy()
    
        newcluster.make_resync()
>       newcluster.make_restore(backup,check_pbm_status=True)

test_remap_sharded.py:76: 
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 

self = <cluster.Cluster object at 0x7f7277930950>
name = '2023-09-14T13:59:30Z --replset-remapping="newrs1=rs1,newrs2=rs2,newrscfg=rscfg"'
kwargs = {'check_pbm_status': True}
client = MongoClient(host=['newmongos:27017'], document_class=dict, tz_aware=False, connect=True)
result = CommandResult(command=b'timeout 180 pbm restore 2023-09-14T13:59:30Z --replset-remapping="newrs1=rs1,newrs2=rs2,newrsc...0ad48eeeab4091", numChunks: 4 } }, ui: UUID("f0d41334-0708-4abf-b4bc-81553adb670f"), wall: new Date(0) }\n', stderr='')
n = <testinfra.host.Host docker://newrscfg01>, timeout = 1694700059.259249

    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")
        result = n.run('timeout 180 pbm restore ' + name + ' --wait')
        if result.rc == 124:
            # try to catch possible failures if timeout exceeded
            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))
                        Cluster.log(get_logs.output.decode('utf-8'))
                except docker.errors.APIError:
                    pass
            assert False, "Timeout for restore exceeded"
        elif result.rc == 0:
            Cluster.log(result.stdout)
        else:
>           assert False, result.stdout + result.stderr
E           AssertionError: Starting restore 2023-09-14T13:59:59.659421228Z from '2023-09-14T13:59:30Z'...Started logical restore.
E           Waiting to finish.....Error: operation failed with: reply oplog: replay chunk 1694699969.1694699976: apply oplog for chunk: applying an entry: op: {"Timestamp":{"T":1694699969,"I":12},"Term":1,"Hash":null,"Version":2,"Operation":"i","Namespace":"config.changelog","Object":[{"Key":"_id","Value":"rs101:27017-2023-09-14T13:59:29.314+00:00-650311c1650ad48eeeab40d6"},{"Key":"server","Value":"rs101:27017"},{"Key":"shard","Value":"rs1"},{"Key":"clientAddr","Value":"172.18.0.15:43502"},{"Key":"time","Value":"2023-09-14T13:59:29.314Z"},{"Key":"what","Value":"shardCollection.end"},{"Key":"ns","Value":"test.test"},{"Key":"details","Value":[{"Key":"version","Value":"1|3||650311bf650ad48eeeab4091"},{"Key":"numChunks","Value":4}]}],"Query":null,"UI":{"Subtype":4,"Data":"8NQTNAcISr+0vIFVOttnDw=="},"LSID":null,"TxnNumber":null,"PrevOpTime":null} | merr <nil>: applyOps: (NamespaceNotFound) Failed to apply operation due to missing collection (f0d41334-0708-4abf-b4bc-81553adb670f): { ts: Timestamp(1694699969, 12), t: 1, h: null, v: 2, op: "i", ns: "config.changelog", o: { _id: "rs101:27017-2023-09-14T13:59:29.314+00:00-650311c1650ad48eeeab40d6", server: "rs101:27017", shard: "rs1", clientAddr: "172.18.0.15:43502", time: new Date(1694699969314), what: "shardCollection.end", ns: "test.test", details: { version: "1|3||650311bf650ad48eeeab4091", numChunks: 4 } }, ui: UUID("f0d41334-0708-4abf-b4bc-81553adb670f"), wall: new Date(0) }

cluster.py:450: AssertionError