From e6bd120d58565879e1e6133e08bb95e92505684c Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Maarit=20H=C3=A4rk=C3=B6nen?= Date: Wed, 21 Aug 2024 11:50:39 +0300 Subject: [PATCH] SP-4660 Measure boot time MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Signed-off-by: Maarit Härkönen --- .../lib/PerformanceDataProcessing.py | 87 ++++++++++++++ Robot-Framework/lib/performance_thresholds.py | 6 + .../resources/common_keywords.resource | 7 +- .../resources/device_control.resource | 10 ++ .../test-suites/boot-test/boot_test.robot | 6 +- .../performance-tests/boot_time_test.robot | 108 ++++++++++++++++++ 6 files changed, 219 insertions(+), 5 deletions(-) create mode 100644 Robot-Framework/test-suites/performance-tests/boot_time_test.robot diff --git a/Robot-Framework/lib/PerformanceDataProcessing.py b/Robot-Framework/lib/PerformanceDataProcessing.py index 66cbf7a..05325db 100644 --- a/Robot-Framework/lib/PerformanceDataProcessing.py +++ b/Robot-Framework/lib/PerformanceDataProcessing.py @@ -92,6 +92,16 @@ def write_fileio_data_to_csv(self, test_name, data): self.device] self._write_to_csv(test_name, data) + @keyword("Write Boot time to csv") + def write_boot_time_to_csv(self, test_name, boot_data): + data = [self.build_number, + boot_data['time_from_nixos_menu_tos_ssh'], + boot_data['time_from_reboot_to_desktop_available'], + boot_data['response_to_ping'], + boot_data['response_to_ssh'], + self.device] + self._write_to_csv(test_name, data) + def truncate(self, list, significant_figures): truncated_list = [] for item in list: @@ -577,6 +587,78 @@ def read_fileio_data_csv_and_plot(self, test_name): plt.savefig(f'../test-suites/{self.device}_{test_name}.png') return statistics + @keyword("Read Bootime CSV and Plot") + def read_bootime_csv_and_plot(self, test_name): + data = { + 'build_numbers': [], + 'time_from_nixos_menu_tos_ssh':[], + 'time_from_reboot_to_desktop_available':[], + 'response_to_ping':[], + 'response_to_ssh':[], + } + with open(f"{self.data_dir}{self.device}_{test_name}.csv", 'r') as csvfile: + csvreader = csv.reader(csvfile) + logging.info("Reading data from csv file..." ) + logging.info(f"{self.data_dir}{self.device}_{test_name}.csv") + build_counter = {} # To keep track of duplicate builds + for row in csvreader: + print("row on", row) + if row[-1] == self.device: + build = str(row[0]) + if build in build_counter: + build_counter[build] += 1 + modified_build = f"{build}-{build_counter[build]}" + else: + build_counter[build] = 0 + modified_build = build + data['build_numbers'].append(modified_build) + data['time_from_nixos_menu_tos_ssh'].append(float(row[1])) + data['time_from_reboot_to_desktop_available'].append(float(row[2])) + data['response_to_ping'].append(float(row[3])) + data['response_to_ssh'].append(float(row[4])) + + plt.figure(figsize=(20, 10)) + plt.set_loglevel('WARNING') + plt.subplot(4, 1, 1) + plt.ticklabel_format(axis='y', style='plain') + plt.plot(data['build_numbers'], data['time_from_nixos_menu_tos_ssh'], marker='o', linestyle='-', color='b') + plt.yticks(fontsize=14) + plt.title('Time from nixos menu to ssh', loc='right', fontweight="bold", fontsize=16) + plt.ylabel('seconds', fontsize=12) + plt.grid(True) + plt.xticks(data['build_numbers'], rotation=45, fontsize=14) + + plt.subplot(4, 1, 2) + plt.ticklabel_format(axis='y', style='plain') + plt.plot(data['build_numbers'], data['time_from_reboot_to_desktop_available'], marker='o', linestyle='-', color='b') + plt.yticks(fontsize=14) + plt.title('Time since reboot to desktop avaialble', loc='right', fontweight="bold", fontsize=16) + plt.ylabel('seconds', fontsize=12) + plt.grid(True) + plt.xticks(data['build_numbers'], rotation=45, fontsize=14) + + plt.subplot(4, 1, 3) + plt.ticklabel_format(axis='y', style='plain') + plt.plot(data['build_numbers'], data['response_to_ping'], marker='o', linestyle='-', color='b') + plt.yticks(fontsize=14) + plt.title('Response to ping', loc='right', fontweight="bold", fontsize=16) + plt.ylabel('seconds', fontsize=12) + plt.grid(True) + plt.xticks(data['build_numbers'], rotation=45, fontsize=14) + + plt.subplot(4, 1, 4) + plt.ticklabel_format(axis='y', style='plain') + plt.plot(data['build_numbers'], data['response_to_ssh'], marker='o', linestyle='-', color='b') + plt.yticks(fontsize=14) + plt.title('Response to ssh', loc='right', fontweight="bold", fontsize=16) + plt.ylabel('seconds', fontsize=12) + plt.grid(True) + plt.xticks(data['build_numbers'], rotation=45, fontsize=14) + plt.suptitle(f'{test_name}\n(build type: {self.build_type}, device: {self.device})', fontsize=18, fontweight='bold') + + plt.tight_layout() + plt.savefig(f'../test-suites/{self.device}_{test_name}.png') + def extract_numeric_part(self, build_identifier): parts = build_identifier.split('-') base_number = int(''.join(filter(str.isdigit, parts[0]))) @@ -644,6 +726,11 @@ def save_cpu_data(self, test_name, cpu_data): self.write_cpu_to_csv(test_name, cpu_data) return self.read_cpu_csv_and_plot(test_name) + @keyword("Save Boot time Data") + def save_boot_time_data(self, test_name, boot_data): + + self.write_boot_time_to_csv(test_name, boot_data) + return self.read_bootime_csv_and_plot(test_name) @keyword def save_memory_data(self, test_name, memory_data): diff --git a/Robot-Framework/lib/performance_thresholds.py b/Robot-Framework/lib/performance_thresholds.py index 85394c1..5e5be01 100644 --- a/Robot-Framework/lib/performance_thresholds.py +++ b/Robot-Framework/lib/performance_thresholds.py @@ -21,5 +21,11 @@ 'rd': 40, 'rd_lenovo-x1': 420 }, + 'boot_time': { + 'time_to_bootup': 60, + 'time_to_respond_to_ssh': 40, + 'time_to_respond_to_ping': 40, + 'time_to_desktop_after_reboot': 100 + }, 'iperf': 10 } diff --git a/Robot-Framework/resources/common_keywords.resource b/Robot-Framework/resources/common_keywords.resource index aa5edc3..2cac671 100644 --- a/Robot-Framework/resources/common_keywords.resource +++ b/Robot-Framework/resources/common_keywords.resource @@ -18,4 +18,9 @@ Check that the application was started END Should Not Be Empty ${app_pids} ${app_name} is not started Log To Console ${app_name} is started - \ No newline at end of file + +Check If Ping Fails + [Documentation] Check that ping is not getting response from host + # ${out} Run and Return RC ping ${DEVICE_IP_ADDRESS} -c 1 + ${result} Run Process ping ${DEVICE_IP_ADDRESS} -c1 timeout=1s + Should Not Be Equal ${result.rc} ${0} \ No newline at end of file diff --git a/Robot-Framework/resources/device_control.resource b/Robot-Framework/resources/device_control.resource index 00460d0..e052778 100644 --- a/Robot-Framework/resources/device_control.resource +++ b/Robot-Framework/resources/device_control.resource @@ -29,3 +29,13 @@ Reboot LenovoX1 END Log To Console Turning device on... Press Button ${DEVICE}-ON + +Soft Reboot Device + [Documentation] Reboot device from command line + ${device_is_available} Ping Host ${DEVICE_IP_ADDRESS} + IF ${device_is_available} + Connect to ghaf host + ${output} Execute Command reboot sudo=True sudo_password=${password} + Log ${output} + Log To Console Rebooting device from command line + END diff --git a/Robot-Framework/test-suites/boot-test/boot_test.robot b/Robot-Framework/test-suites/boot-test/boot_test.robot index 43aedc4..efeba21 100644 --- a/Robot-Framework/test-suites/boot-test/boot_test.robot +++ b/Robot-Framework/test-suites/boot-test/boot_test.robot @@ -153,7 +153,5 @@ Check If Device Is Up END END -Check If Ping Fails - [Documentation] Check that ping is not getting response from host - ${out} Run and Return RC ping ${DEVICE_IP_ADDRESS} -c 1 - Should Be Equal ${out} ${1} + + diff --git a/Robot-Framework/test-suites/performance-tests/boot_time_test.robot b/Robot-Framework/test-suites/performance-tests/boot_time_test.robot new file mode 100644 index 0000000..f694f06 --- /dev/null +++ b/Robot-Framework/test-suites/performance-tests/boot_time_test.robot @@ -0,0 +1,108 @@ +# SPDX-FileCopyrightText: 2022-2024 Technology Innovation Institute (TII) +# SPDX-License-Identifier: Apache-2.0 + +*** Settings *** +Documentation Testing target device bootup time. +Force Tags ssh_boot_test performance +Resource ../../resources/serial_keywords.resource +Resource ../../resources/common_keywords.resource +Resource ../../resources/ssh_keywords.resource +Resource ../../resources/device_control.resource +Resource ../../config/variables.robot +Variables ../../lib/performance_thresholds.py +Library ../../lib/PerformanceDataProcessing.py ${DEVICE} ${BUILD_ID} ${JOB} +Library DateTime +Library Collections + + +*** Variables *** +${BOOT_TIME} ${thresholds}[boot_time][time_to_bootup] +${TIME_TO_RESPOND_TO_SSH} ${thresholds}[boot_time][time_to_respond_to_ssh] +${TIME_TO_RESPOND_TO_PING} ${thresholds}[boot_time][time_to_respond_to_ping] +${TIME_TO_DESKTOP_AFTER_REBOOT} ${thresholds}[boot_time][time_to_desktop_after_reboot] + + +*** Test Cases *** + +Measure Soft Boot Time + [Documentation] Measure how long it takes to device to boot up with soft reboot + [Tags] SP-T197 lenovo-x1 + Soft Reboot Device + Wait Until Keyword Succeeds 25s 2s Check If Ping Fails + Get Boot times + +Measure Hard Boot Time + [Documentation] Measure how long it takes to device to boot up with hard reboot + [Tags] SP-T192 lenovo-x1 + Press Button ${DEVICE}-OFF + Wait Until Keyword Succeeds 15s 2s Check If Ping Fails + Sleep 5 # Wait until switchbot has pressed and returned button + Press Button ${DEVICE}-ON + Get Boot times hard image_name=Hard Boot Times + + +*** Keywords *** +Get Boot times + [Documentation] Collect boot times from device + [Arguments] ${boot_type}=soft ${image_name}=Soft Boot Times + ${ping_response} Set Variable False + ${ssh_response} Set Variable False + ${cmd1} Catenate SEPARATOR=\n current_timestamp=$(expr $(date '+%s%N') / 1000000000) + ... echo $current_timestamp + ${cmd2} Catenate SEPARATOR=\n since_nixos_menu=$(awk '{print $1}' /proc/uptime) + ... echo $since_nixos_menu + ${cmd3} Catenate SEPARATOR=\n + ... welcome_note=$(date -d "$(journalctl --output=short-iso | grep gui-vm | grep "Welcome" | tail -1 | awk '{print $1}')" "+%s") + ... echo $welcome_note + ${cmd4} Catenate SEPARATOR=\n + ... bar_configured_note=$(date -d "$(journalctl --output=short-iso | grep "Bar configured" | tail -1 | awk '{print $1}')" "+%s") + ... echo $bar_configured_note + + ${start_time} DateTime.Get Current Date + Log to console Start checking ping and ssh response + WHILE not (${ping_response} and ${ssh_response}) limit=${BOOT_TIME} seconds + ${connection} Open Connection ${DEVICE_IP_ADDRESS} port=22 prompt=\$ timeout=2 + ${ssh_response} Run Keyword And Return Status Login username=${LOGIN} password=${PASSWORD} + ${ssh_end_time} IF ${ssh_response} DateTime.Get Current Date ELSE Set Variable False + ${ping_response} IF not ${ping_response} Ping Host ${DEVICE_IP_ADDRESS} + ${ping_end_time} IF ${ping_response} DateTime.Get Current Date ELSE Set Variable False + END + Connect to ghaf host + ${current_timestamp} Execute Command ${cmd1} + ${time_from_nixos_menu_tos_ssh} Execute Command ${cmd2} # uptime + ${nixos_menu_timestamp} Subtract Time From Time ${current_timestamp} ${time_from_nixos_menu_tos_ssh} + ${start_time_epoc} Convert Date ${start_time} epoch + + Connect to netvm + Connect to VM ${GUI_VM} + ${time_from_reboot_to_desktop_available} Run Keyword And Continue On Failure + ... Wait Until Keyword Succeeds ${TIME_TO_DESKTOP_AFTER_REBOOT}s 1s Check Log For Notification ${cmd4} ${start_time_epoc} + + ${ping_response_seconds} IF ${ping_response} DateTime.Subtract Date From Date ${ping_end_time} ${start_time} exclude_millis=True + ${ssh_response_seconds} IF ${ssh_response} DateTime.Subtract Date From Date ${ssh_end_time} ${start_time} exclude_millis=True + + &{final_results} Create Dictionary + Set To Dictionary ${final_results} time_from_nixos_menu_tos_ssh ${time_from_nixos_menu_tos_ssh} + Set To Dictionary ${final_results} time_from_reboot_to_desktop_available ${time_from_reboot_to_desktop_available} + Set To Dictionary ${final_results} response_to_ping ${ping_response_seconds} + Set To Dictionary ${final_results} response_to_ssh ${ssh_response_seconds} + Save Boot time Data ${TEST NAME} ${final_results} + Log ${image_name} HTML + IF '${boot_type}' == 'soft' + Run Keyword And Continue On Failure Should Be True ${ping_response_seconds} <= ${TIME_TO_RESPOND_TO_PING} + Run Keyword And Continue On Failure Should Be True ${ssh_response_seconds} <= ${TIME_TO_RESPOND_TO_SSH} + ELSE + Run Keyword And Continue On Failure Should Be True ${ping_response_seconds} <= ${${TIME_TO_RESPOND_TO_PING} + 10} + Run Keyword And Continue On Failure Should Be True ${ssh_response_seconds} <= ${${TIME_TO_RESPOND_TO_SSH} + 10} + END + Should Be True ${time_from_reboot_to_desktop_available} <= ${TIME_TO_DESKTOP_AFTER_REBOOT} + +Check Log For Notification + [Documentation] Check that correct notification is available in journalctl + [Arguments] ${command} ${current_time} + ${notification} Execute Command ${command} + Should Not Be Empty ${notification} + ${time} Subtract Time From Time ${notification} ${current_time} + Should Be True 0 < ${time} < 120 + + RETURN ${time}