SP-4660 Measure boot time

Signed-off-by: Maarit Härkönen <[email protected]>

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_ssh_to_nixos_menu'],
+                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,80 @@ 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_ssh_to_nixos_menu':[],
+                '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_ssh_to_nixos_menu'].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]))
+
+        # for key in data.keys():
+        #     data[key] = data[key][-40:]
+        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_ssh_to_nixos_menu'], marker='o', linestyle='-', color='b')
+        plt.yticks(fontsize=14)
+        plt.title('Time from ssh to nixos menu', 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 +728,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):

Robot-Framework/lib/performance_thresholds.py

@@ -21,5 +21,11 @@
         'rd': 20,
         'rd_lenovo-x1': 200
     },
+    'boot_time': {
+        'time_to_bootup': 60,
+        'time_to_respond_to_ssh': 40,
+        'time_to_respond_to_ping': 40,
+        'time_to_desktop_after_nixos_menu': 100
+    },
     'iperf': 10
 }

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
-
+
+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}

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

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}
+
+

Robot-Framework/test-suites/performance-tests/boot_time_test.robot

@@ -0,0 +1,111 @@
+# 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_NIXOS_MENU}  ${thresholds}[boot_time][time_to_desktop_after_nixos_menu]
+
+
+*** 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
+    Log  <img src="${DEVICE}_${TEST NAME}.png" alt="Soft Boot Times" width="1200">    HTML
+
+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
+    Log  <img src="${DEVICE}_${TEST NAME}.png" alt="Hard Boot Times" width="1200">    HTML
+
+*** Keywords ***
+
+Get Boot times
+    [Documentation]  Collect boot times from device
+    [Arguments]  ${bootype}=soft
+    ${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_ssh_to_nixos_menu}  Execute Command  ${cmd2}  # uptime
+    ${nixos_menu_timestamp}  Subtract Time From Time  ${current_timestamp}  ${time_from_ssh_to_nixos_menu}
+    ${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_NIXOS_MENU}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_ssh_to_nixos_menu  ${time_from_ssh_to_nixos_menu}
+    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}
+    IF  '${bootype}' == '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_NIXOS_MENU}
+
+
+*** Keywords ***
+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}