def measure_pvc_creation_time(interface, pvc_objs, start_time): """ Measures and Logs PVC Creation Time of all PVCs. Args: interface (str) : an interface (RBD or CephFS) to run on. pvc_objs (list) : List of PVC objects for which we have to measure the time. start_time (str) : Formatted time from which and on to search the relevant logs. Logs: PVC Creation Time of all the PVCs. """ accepted_creation_time = 1 for pvc_obj in pvc_objs: creation_time = performance_lib.measure_pvc_creation_time( interface, pvc_obj.name, start_time) if creation_time <= accepted_creation_time: log.info( f"PVC {pvc_obj.name} was created in {creation_time} seconds.") else: log.error( f"PVC {pvc_obj.name} creation time is {creation_time} and is greater than " f"{accepted_creation_time} seconds.")
def create_clone(self, clone_num): """ Creating clone for pvc, measure the creation time Args: clone_num (int) the number of clones to create Returns: str: The created clone name int: the creation time of the clone (in secs.) int: the csi creation time of the clone (in secs.) """ csi_start_time = self.get_time("csi") cloned_pvc_obj = pvc.create_pvc_clone( sc_name=self.pvc_obj.backed_sc, parent_pvc=self.pvc_obj.name, pvc_name=f"pvc-clone-pas-test-{clone_num}", clone_yaml=Interfaces_info[self.interface]["clone_yaml"], namespace=self.namespace, storage_size=f"{self.pvc_obj.size}Gi", ) helpers.wait_for_resource_state(cloned_pvc_obj, constants.STATUS_BOUND, 600) cloned_pvc_obj.reload() clone_name = cloned_pvc_obj.name create_time = performance_lib.measure_pvc_creation_time( self.interface, clone_name, csi_start_time) csi_create_time = performance_lib.csi_pvc_time_measure( self.interface, cloned_pvc_obj, "create", csi_start_time) del cloned_pvc_obj return (clone_name, create_time, csi_create_time)
def create_clone(self, clone_num, clone_yaml): """ Creating clone for pvc, measure the creation time Args: clone_num (int) the number of clones to create clone_yaml : a template of clone yaml Returns: int: the creation time of the clone (in secs.) """ log.info( f"Creating clone number {clone_num} for interface {self.interface}" ) clone_name = f"pvc-clone-{clone_num}-" clone_name += self.params["pvcname"].split("-")[-1] clone_yaml["metadata"]["name"] = clone_name tmpfile = self.params["tmpfile"] log.info(f"Going to create {tmpfile}") with open(tmpfile, "w") as f: yaml.dump(clone_yaml, f, default_flow_style=False) start_time = datetime.datetime.utcnow().strftime("%Y-%m-%dT%H:%M:%SZ") log.info(f"Clone yaml file is {clone_yaml}") res = performance_lib.run_oc_command(f"create -f {tmpfile}", self.params["nspace"]) if self.params["ERRMSG"] in res[0]: raise Exception(f"Can not create clone : {res}") # wait until clone is ready self.wait_for_clone_creation(clone_name) create_time = performance_lib.measure_pvc_creation_time( self.interface, clone_name, start_time) log.info(f"Creation time of clone {clone_name} is {create_time} secs.") return create_time
def test_pvc_creation_deletion_measurement_performance( self, teardown_factory, pvc_size): """ Measuring PVC creation and deletion times for pvc samples Verifying that those times are within required limits """ # Getting the full path for the test logs self.full_log_path = get_full_test_logs_path(cname=self) if self.interface == constants.CEPHBLOCKPOOL: self.sc = "RBD" if self.interface == constants.CEPHFILESYSTEM: self.sc = "CephFS" self.full_log_path += f"-{self.sc}-{pvc_size}" log.info(f"Logs file path name is : {self.full_log_path}") self.start_time = time.strftime("%Y-%m-%dT%H:%M:%SGMT", time.gmtime()) self.get_env_info() # Initialize the results doc file. self.full_results = self.init_full_results( ResultsAnalyse(self.uuid, self.crd_data, self.full_log_path)) self.full_results.add_key("pvc_size", pvc_size) num_of_samples = 5 accepted_creation_time = 1 accepted_deletion_time = 2 if self.interface == constants.CEPHFILESYSTEM else 1 self.full_results.add_key("samples", num_of_samples) accepted_creation_deviation_percent = 50 accepted_deletion_deviation_percent = 50 creation_time_measures = [] deletion_time_measures = [] msg_prefix = f"Interface: {self.interface}, PVC size: {pvc_size}." for i in range(num_of_samples): logging.info(f"{msg_prefix} Start creating PVC number {i + 1}.") start_time = datetime.datetime.utcnow().strftime( "%Y-%m-%dT%H:%M:%SZ") pvc_obj = helpers.create_pvc(sc_name=self.sc_obj.name, size=pvc_size) helpers.wait_for_resource_state(pvc_obj, constants.STATUS_BOUND) pvc_obj.reload() creation_time = performance_lib.measure_pvc_creation_time( self.interface, pvc_obj.name, start_time) logging.info( f"{msg_prefix} PVC number {i + 1} was created in {creation_time} seconds." ) if creation_time > accepted_creation_time: raise ex.PerformanceException( f"{msg_prefix} PVC creation time is {creation_time} and is greater than " f"{accepted_creation_time} seconds.") creation_time_measures.append(creation_time) pv_name = pvc_obj.backed_pv pvc_reclaim_policy = pvc_obj.reclaim_policy pod_obj = self.write_file_on_pvc(pvc_obj) pod_obj.delete(wait=True) teardown_factory(pvc_obj) logging.info(f"{msg_prefix} Start deleting PVC number {i + 1}") if pvc_reclaim_policy == constants.RECLAIM_POLICY_DELETE: pvc_obj.delete() pvc_obj.ocp.wait_for_delete(pvc_obj.name) helpers.validate_pv_delete(pvc_obj.backed_pv) deletion_time = helpers.measure_pvc_deletion_time( self.interface, pv_name) logging.info( f"{msg_prefix} PVC number {i + 1} was deleted in {deletion_time} seconds." ) if deletion_time > accepted_deletion_time: raise ex.PerformanceException( f"{msg_prefix} PVC deletion time is {deletion_time} and is greater than " f"{accepted_deletion_time} seconds.") deletion_time_measures.append(deletion_time) else: logging.info( f"Reclaim policy of the PVC {pvc_obj.name} is not Delete;" f" therefore not measuring deletion time for this PVC.") creation_average = self.process_time_measurements( "creation", creation_time_measures, accepted_creation_deviation_percent, msg_prefix, ) self.full_results.add_key("creation-time", creation_average) deletion_average = self.process_time_measurements( "deletion", deletion_time_measures, accepted_deletion_deviation_percent, msg_prefix, ) self.full_results.add_key("deletion-time", deletion_average) self.full_results.all_results["creation"] = creation_time_measures self.full_results.all_results["deletion"] = deletion_time_measures self.end_time = time.strftime("%Y-%m-%dT%H:%M:%SGMT", time.gmtime()) self.full_results.add_key("test_time", { "start": self.start_time, "end": self.end_time }) self.full_results.es_write() log.info( f"The Result can be found at : {self.full_results.results_link()}") if not self.dev_mode: # all the results are OK, the test passes, push the results to the codespeed push_to_pvc_time_dashboard(self.interface, "1-pvc-creation", creation_average) push_to_pvc_time_dashboard(self.interface, "1-pvc-deletion", deletion_average)
def test_pvc_creation_deletion_measurement_performance( self, teardown_factory, pvc_size ): """ Measuring PVC creation and deletion times for pvc samples Verifying that those times are within required limits """ num_of_samples = 5 accepted_creation_time = 1 accepted_deletion_time = 2 if self.interface == constants.CEPHFILESYSTEM else 1 accepted_creation_deviation_percent = 50 accepted_deletion_deviation_percent = 50 creation_time_measures = [] deletion_time_measures = [] msg_prefix = f"Interface: {self.interface}, PVC size: {pvc_size}." for i in range(num_of_samples): logging.info(f"{msg_prefix} Start creating PVC number {i + 1}.") start_time = datetime.datetime.utcnow().strftime("%Y-%m-%dT%H:%M:%SZ") pvc_obj = helpers.create_pvc(sc_name=self.sc_obj.name, size=pvc_size) helpers.wait_for_resource_state(pvc_obj, constants.STATUS_BOUND) pvc_obj.reload() creation_time = performance_lib.measure_pvc_creation_time( self.interface, pvc_obj.name, start_time ) logging.info( f"{msg_prefix} PVC number {i + 1} was created in {creation_time} seconds." ) if creation_time > accepted_creation_time: raise ex.PerformanceException( f"{msg_prefix} PVC creation time is {creation_time} and is greater than " f"{accepted_creation_time} seconds." ) creation_time_measures.append(creation_time) pv_name = pvc_obj.backed_pv pvc_reclaim_policy = pvc_obj.reclaim_policy pod_obj = self.write_file_on_pvc(pvc_obj) pod_obj.delete(wait=True) teardown_factory(pvc_obj) logging.info(f"{msg_prefix} Start deleting PVC number {i + 1}") if pvc_reclaim_policy == constants.RECLAIM_POLICY_DELETE: pvc_obj.delete() pvc_obj.ocp.wait_for_delete(pvc_obj.name) helpers.validate_pv_delete(pvc_obj.backed_pv) deletion_time = helpers.measure_pvc_deletion_time( self.interface, pv_name ) logging.info( f"{msg_prefix} PVC number {i + 1} was deleted in {deletion_time} seconds." ) if deletion_time > accepted_deletion_time: raise ex.PerformanceException( f"{msg_prefix} PVC deletion time is {deletion_time} and is greater than " f"{accepted_deletion_time} seconds." ) deletion_time_measures.append(deletion_time) else: logging.info( f"Reclaim policy of the PVC {pvc_obj.name} is not Delete;" f" therefore not measuring deletion time for this PVC." ) creation_average = self.process_time_measurements( "creation", creation_time_measures, accepted_creation_deviation_percent, msg_prefix, ) deletion_average = self.process_time_measurements( "deletion", deletion_time_measures, accepted_deletion_deviation_percent, msg_prefix, ) # all the results are OK, the test passes, push the results to the codespeed push_to_pvc_time_dashboard(self.interface, "1-pvc-creation", creation_average) push_to_pvc_time_dashboard(self.interface, "1-pvc-deletion", deletion_average)
def test_pvc_snapshot_performance(self, pvc_size): """ 1. Run I/O on a pod file 2. Calculate md5sum of the file 3. Take a snapshot of the PVC 4. Measure the total snapshot creation time and the CSI snapshot creation time 4. Restore From the snapshot and measure the time 5. Attach a new pod to it 6. Verify that the file is present on the new pod also 7. Verify that the md5sum of the file on the new pod matches with the md5sum of the file on the original pod This scenario run 3 times and report all the average results of the 3 runs and will send them to the ES Args: pvc_size: the size of the PVC to be tested - parametrize """ # Getting the total Storage capacity ceph_capacity = self.ceph_cluster.get_ceph_capacity() log.info(f"Total capacity size is : {ceph_capacity}") log.info(f"PVC Size is : {pvc_size}") log.info(f"Needed capacity is {int(int(pvc_size) * 5)}") if int(ceph_capacity) < int(pvc_size) * 5: log.error( f"PVC size is {pvc_size}GiB and it is too large for this system" f" which have only {ceph_capacity}GiB") return # Calculating the file size as 25% of the PVC size # in the end the PVC will be 75% full filesize = self.pvc_obj.size * 0.25 # Change the file size to MB and from int to str file_size = f"{int(filesize * 1024)}M" all_results = [] # Produce ES report # Collecting environment information self.get_env_info() # Initialize the results doc file. self.full_results = self.init_full_results( ResultsAnalyse( self.uuid, self.crd_data, self.full_log_path, "pvc_snapshot_perf", )) self.full_results.add_key("pvc_size", pvc_size + " GiB") self.full_results.add_key("interface", self.sc) self.full_results.all_results["creation_time"] = [] self.full_results.all_results["csi_creation_time"] = [] self.full_results.all_results["creation_speed"] = [] self.full_results.all_results["restore_time"] = [] self.full_results.all_results["restore_speed"] = [] self.full_results.all_results["restore_csi_time"] = [] self.full_results.all_results["dataset_inMiB"] = [] for test_num in range(self.tests_numbers): test_results = { "test_num": test_num + 1, "dataset": (test_num + 1) * filesize * 1024, # size in MiB "create": { "time": None, "csi_time": None, "speed": None }, "restore": { "time": None, "speed": None }, } log.info(f"Starting test phase number {test_num}") # Step 1. Run I/O on a pod file. file_name = f"{self.pod_object.name}-{test_num}" log.info(f"Starting IO on the POD {self.pod_object.name}") # Going to run only write IO to fill the PVC for the snapshot self.pod_object.fillup_fs(size=file_size, fio_filename=file_name) # Wait for fio to finish fio_result = self.pod_object.get_fio_results() err_count = fio_result.get("jobs")[0].get("error") assert ( err_count == 0 ), f"IO error on pod {self.pod_object.name}. FIO result: {fio_result}" log.info("IO on the PVC Finished") # Verify presence of the file file_path = pod.get_file_path(self.pod_object, file_name) log.info(f"Actual file path on the pod {file_path}") assert pod.check_file_existence( self.pod_object, file_path), f"File {file_name} doesn't exist" log.info(f"File {file_name} exists in {self.pod_object.name}") # Step 2. Calculate md5sum of the file. orig_md5_sum = pod.cal_md5sum(self.pod_object, file_name) # Step 3. Take a snapshot of the PVC and measure the time of creation. snap_name = self.pvc_obj.name.replace("pvc-test", f"snapshot-test{test_num}") log.info(f"Taking snapshot of the PVC {snap_name}") start_time = self.get_time("CSI") test_results["create"]["time"] = self.measure_create_snapshot_time( pvc_name=self.pvc_obj.name, snap_name=snap_name, namespace=self.pod_object.namespace, interface=self.interface, start_time=start_time, ) test_results["create"][ "csi_time"] = performance_lib.measure_csi_snapshot_creation_time( interface=self.interface, snapshot_id=self.snap_uid, start_time=start_time, ) test_results["create"]["speed"] = int( test_results["dataset"] / test_results["create"]["time"]) log.info( f' Test {test_num} dataset is {test_results["dataset"]} MiB') log.info( f"Snapshot name {snap_name} and id {self.snap_uid} creation time is" f' : {test_results["create"]["time"]} sec.') log.info( f"Snapshot name {snap_name} and id {self.snap_uid} csi creation time is" f' : {test_results["create"]["csi_time"]} sec.') log.info( f'Snapshot speed is : {test_results["create"]["speed"]} MB/sec' ) # Step 4. Restore the PVC from the snapshot and measure the time # Same Storage class of the original PVC sc_name = self.pvc_obj.backed_sc # Size should be same as of the original PVC pvc_size = str(self.pvc_obj.size) + "Gi" # Create pvc out of the snapshot # Both, the snapshot and the restore PVC should be in same namespace log.info("Restoring from the Snapshot") restore_pvc_name = self.pvc_obj.name.replace( "pvc-test", f"restore-pvc{test_num}") restore_pvc_yaml = constants.CSI_RBD_PVC_RESTORE_YAML if self.interface == constants.CEPHFILESYSTEM: restore_pvc_yaml = constants.CSI_CEPHFS_PVC_RESTORE_YAML csi_start_time = self.get_time("csi") log.info("Restoring the PVC from Snapshot") restore_pvc_obj = pvc.create_restore_pvc( sc_name=sc_name, snap_name=self.snap_obj.name, namespace=self.snap_obj.namespace, size=pvc_size, pvc_name=restore_pvc_name, restore_pvc_yaml=restore_pvc_yaml, ) helpers.wait_for_resource_state( restore_pvc_obj, constants.STATUS_BOUND, timeout=3600 # setting this to 60 Min. # since it can be take long time to restore, and we want it to finished. ) restore_pvc_obj.reload() log.info("PVC was restored from the snapshot") test_results["restore"][ "time"] = performance_lib.measure_pvc_creation_time( self.interface, restore_pvc_obj.name, csi_start_time) test_results["restore"]["speed"] = int( test_results["dataset"] / test_results["restore"]["time"]) log.info( f'Snapshot restore time is : {test_results["restore"]["time"]}' ) log.info( f'restore speed is : {test_results["restore"]["speed"]} MB/sec' ) test_results["restore"][ "csi_time"] = performance_lib.csi_pvc_time_measure( self.interface, restore_pvc_obj, "create", csi_start_time) log.info( f'Snapshot csi restore time is : {test_results["restore"]["csi_time"]}' ) # Step 5. Attach a new pod to the restored PVC restore_pod_object = helpers.create_pod( interface_type=self.interface, pvc_name=restore_pvc_obj.name, namespace=self.snap_obj.namespace, pod_dict_path=constants.PERF_POD_YAML, ) # Confirm that the pod is running helpers.wait_for_resource_state(resource=restore_pod_object, state=constants.STATUS_RUNNING) restore_pod_object.reload() # Step 6. Verify that the file is present on the new pod also. log.info(f"Checking the existence of {file_name} " f"on restore pod {restore_pod_object.name}") assert pod.check_file_existence( restore_pod_object, file_path), f"File {file_name} doesn't exist" log.info(f"File {file_name} exists in {restore_pod_object.name}") # Step 7. Verify that the md5sum matches log.info( f"Verifying that md5sum of {file_name} " f"on pod {self.pod_object.name} matches with md5sum " f"of the same file on restore pod {restore_pod_object.name}") assert pod.verify_data_integrity( restore_pod_object, file_name, orig_md5_sum), "Data integrity check failed" log.info("Data integrity check passed, md5sum are same") restore_pod_object.delete() restore_pvc_obj.delete() all_results.append(test_results) # clean the enviroment self.pod_object.delete() self.pvc_obj.delete() self.delete_test_project() # logging the test summary, all info in one place for easy log reading c_speed, c_runtime, c_csi_runtime, r_speed, r_runtime, r_csi_runtime = ( 0 for i in range(6)) log.info("Test summary :") for tst in all_results: c_speed += tst["create"]["speed"] c_runtime += tst["create"]["time"] c_csi_runtime += tst["create"]["csi_time"] r_speed += tst["restore"]["speed"] r_runtime += tst["restore"]["time"] r_csi_runtime += tst["restore"]["csi_time"] self.full_results.all_results["creation_time"].append( tst["create"]["time"]) self.full_results.all_results["csi_creation_time"].append( tst["create"]["csi_time"]) self.full_results.all_results["creation_speed"].append( tst["create"]["speed"]) self.full_results.all_results["restore_time"].append( tst["restore"]["time"]) self.full_results.all_results["restore_speed"].append( tst["restore"]["speed"]) self.full_results.all_results["restore_csi_time"].append( tst["restore"]["csi_time"]) self.full_results.all_results["dataset_inMiB"].append( tst["dataset"]) log.info( f"Test {tst['test_num']} results : dataset is {tst['dataset']} MiB. " f"Take snapshot time is {tst['create']['time']} " f"at {tst['create']['speed']} MiB/Sec " f"Restore from snapshot time is {tst['restore']['time']} " f"at {tst['restore']['speed']} MiB/Sec ") avg_snap_c_time = c_runtime / self.tests_numbers avg_snap_csi_c_time = c_csi_runtime / self.tests_numbers avg_snap_c_speed = c_speed / self.tests_numbers avg_snap_r_time = r_runtime / self.tests_numbers avg_snap_r_speed = r_speed / self.tests_numbers avg_snap_r_csi_time = r_csi_runtime / self.tests_numbers log.info(f" Average snapshot creation time is {avg_snap_c_time} sec.") log.info( f" Average csi snapshot creation time is {avg_snap_csi_c_time} sec." ) log.info( f" Average snapshot creation speed is {avg_snap_c_speed} MiB/sec") log.info(f" Average snapshot restore time is {avg_snap_r_time} sec.") log.info( f" Average snapshot restore speed is {avg_snap_r_speed} MiB/sec") log.info( f" Average snapshot restore csi time is {avg_snap_r_csi_time} sec." ) self.full_results.add_key("avg_snap_creation_time_insecs", avg_snap_c_time) self.full_results.add_key("avg_snap_csi_creation_time_insecs", avg_snap_csi_c_time) self.full_results.add_key("avg_snap_creation_speed", avg_snap_c_speed) self.full_results.add_key("avg_snap_restore_time_insecs", avg_snap_r_time) self.full_results.add_key("avg_snap_restore_speed", avg_snap_r_speed) self.full_results.add_key("avg_snap_restore_csi_time_insecs", avg_snap_r_csi_time) # Write the test results into the ES server self.results_path = helpers.get_full_test_logs_path(cname=self) log.info(f"Logs file path name is : {self.full_log_path}") log.info("writing results to elastic search server") if self.full_results.es_write(): res_link = self.full_results.results_link() # write the ES link to the test results in the test log. log.info(f"The result can be found at : {res_link}") self.write_result_to_file(res_link)