1# Copyright 2017 The Chromium OS Authors. All rights reserved. 2# Use of this source code is governed by a BSD-style license that can be 3# found in the LICENSE file. 4import json 5import logging 6import os 7import random 8import time 9 10from autotest_lib.client.common_lib import error 11from autotest_lib.client.common_lib import lsbrelease_utils 12from autotest_lib.server import autotest 13from autotest_lib.server.cros.update_engine import update_engine_test 14from chromite.lib import retry_util 15 16class autoupdate_ForcedOOBEUpdate(update_engine_test.UpdateEngineTest): 17 """Runs a forced autoupdate during OOBE.""" 18 version = 1 19 20 # We override the default lsb-release file. 21 _CUSTOM_LSB_RELEASE = '/mnt/stateful_partition/etc/lsb-release' 22 23 # Version we tell the DUT it is on before update. 24 _CUSTOM_LSB_VERSION = '0.0.0.0' 25 26 # Expected hostlog events during update: 4 during rootfs 27 _ROOTFS_HOSTLOG_EVENTS = 4 28 29 30 def cleanup(self): 31 self._host.run('rm %s' % self._CUSTOM_LSB_RELEASE, ignore_status=True) 32 33 # Get the last two update_engine logs: before and after reboot. 34 files = self._host.run('ls -t -1 ' 35 '/var/log/update_engine/').stdout.splitlines() 36 for i in range(2): 37 self._host.get_file('/var/log/update_engine/%s' % files[i], 38 self.resultsdir) 39 cmd = 'update_engine_client --update_over_cellular=no' 40 retry_util.RetryException(error.AutoservRunError, 2, self._host.run, 41 cmd) 42 super(autoupdate_ForcedOOBEUpdate, self).cleanup() 43 44 def _get_chromeos_version(self): 45 """Read the ChromeOS version from /etc/lsb-release.""" 46 lsb = self._host.run('cat /etc/lsb-release').stdout 47 return lsbrelease_utils.get_chromeos_release_version(lsb) 48 49 50 def _create_hostlog_files(self): 51 """Create the two hostlog files for the update. 52 53 To ensure the update was succesful we need to compare the update 54 events against expected update events. There is a hostlog for the 55 rootfs update and for the post reboot update check. 56 """ 57 hostlog = self._omaha_devserver.get_hostlog(self._host.ip, 58 wait_for_reboot_events=True) 59 logging.info('Hostlog: %s', hostlog) 60 61 # File names to save the hostlog events to. 62 rootfs_hostlog = os.path.join(self.resultsdir, 'hostlog_rootfs') 63 reboot_hostlog = os.path.join(self.resultsdir, 'hostlog_reboot') 64 65 # Each time we reboot in the middle of an update we ping omaha again 66 # for each update event. So parse the list backwards to get the final 67 # events. 68 with open(reboot_hostlog, 'w') as outfile: 69 json.dump(hostlog[-1:], outfile) 70 with open(rootfs_hostlog, 'w') as outfile: 71 json.dump(hostlog[len(hostlog)-1-self._ROOTFS_HOSTLOG_EVENTS:-1], 72 outfile) 73 74 return rootfs_hostlog, reboot_hostlog 75 76 77 def _get_update_percentage(self): 78 """Returns the current payload downloaded percentage.""" 79 while True: 80 status = self._host.run('update_engine_client --status', 81 ignore_timeout=True, 82 timeout=10) 83 if not status: 84 continue 85 status = status.stdout.splitlines() 86 logging.debug(status) 87 if 'UPDATE_STATUS_IDLE' in status[2]: 88 raise error.TestFail('Update status was idle while trying to ' 89 'get download status.') 90 # If we call this right after reboot it may not be downloading yet. 91 if 'UPDATE_STATUS_DOWNLOADING' not in status[2]: 92 time.sleep(1) 93 continue 94 return float(status[1].partition('=')[2]) 95 96 97 def _update_continued_where_it_left_off(self, percentage): 98 """ 99 Checks that the update did not restart after an interruption. 100 101 @param percentage: The percentage the last time we checked. 102 103 @returns True if update continued. False if update restarted. 104 105 """ 106 completed = self._get_update_percentage() 107 logging.info('New value: %f, old value: %f', completed, percentage) 108 return completed >= percentage 109 110 111 def _wait_for_update_to_complete(self): 112 """Wait for the update that started to complete. 113 114 Repeated check status of update. It should move from DOWNLOADING to 115 FINALIZING to COMPLETE to IDLE. 116 """ 117 while True: 118 status = self._host.run('update_engine_client --status', 119 ignore_timeout=True, 120 timeout=10) 121 122 # During reboot, status will be None 123 if status is not None: 124 status = status.stdout.splitlines() 125 logging.debug(status) 126 if 'UPDATE_STATUS_IDLE' in status[2]: 127 break 128 time.sleep(1) 129 130 131 def _wait_for_percentage(self, percent): 132 """ 133 Waits until we reach the percentage passed as the input. 134 135 @param percent: The percentage we want to wait for. 136 """ 137 while True: 138 completed = self._get_update_percentage() 139 logging.debug('Checking if %s is greater than %s', completed, 140 percent) 141 if completed > percent: 142 break 143 time.sleep(1) 144 145 146 def run_once(self, host, full_payload=True, cellular=False, 147 interrupt=False, max_updates=1, job_repo_url=None): 148 """ 149 Runs a forced autoupdate during ChromeOS OOBE. 150 151 @param host: The DUT that we are running on. 152 @param full_payload: True for a full payload. False for delta. 153 @param cellular: True to do the update over a cellualar connection. 154 Requires that the DUT have a sim card slot. 155 @param interrupt: True to interrupt the update in the middle. 156 @param max_updates: Used to tell the test how many times it is 157 expected to ping its omaha server. 158 @param job_repo_url: Used for debugging locally. This is used to figure 159 out the current build and the devserver to use. 160 The test will read this from a host argument 161 when run in the lab. 162 163 """ 164 self._host = host 165 166 # veyron_rialto is a medical device with a different OOBE that auto 167 # completes so this test is not valid on that device. 168 if 'veyron_rialto' in self._host.get_board(): 169 raise error.TestNAError('Rialto has a custom OOBE. Skipping test.') 170 171 update_url = self.get_update_url_for_test(job_repo_url, 172 full_payload=full_payload, 173 critical_update=True, 174 cellular=cellular, 175 max_updates=max_updates) 176 logging.info('Update url: %s', update_url) 177 before = self._get_chromeos_version() 178 payload_info = None 179 if cellular: 180 cmd = 'update_engine_client --update_over_cellular=yes' 181 retry_util.RetryException(error.AutoservRunError, 2, self._host.run, 182 cmd) 183 # Get the payload's information (size, SHA256 etc) since we will be 184 # setting up our own omaha instance on the DUT. We pass this to 185 # the client test. 186 payload = self._get_payload_url(full_payload=full_payload) 187 staged_url = self._stage_payload_by_uri(payload) 188 payload_info = self._get_staged_file_info(staged_url) 189 190 # Call client test to start the forced OOBE update. 191 client_at = autotest.Autotest(self._host) 192 client_at.run_test('autoupdate_StartOOBEUpdate', image_url=update_url, 193 cellular=cellular, payload_info=payload_info, 194 full_payload=full_payload) 195 196 # Don't continue the test if the client failed for any reason. 197 client_at._check_client_test_result(self._host, 198 'autoupdate_StartOOBEUpdate') 199 200 if interrupt: 201 # Choose a random downloaded percentage to interrupt the update. 202 percent = random.uniform(0.1, 0.8) 203 logging.debug('Percent when we will interrupt: %f', percent) 204 self._wait_for_percentage(percent) 205 logging.info('We will start interrupting the update.') 206 completed = self._get_update_percentage() 207 208 # Reboot the DUT during the update. 209 self._host.reboot() 210 if not self._update_continued_where_it_left_off(completed): 211 raise error.TestFail('The update did not continue where it ' 212 'left off before rebooting.') 213 completed = self._get_update_percentage() 214 215 # Disconnect and reconnect network. 216 reconnect_test_name = 'autoupdate_DisconnectReconnectNetwork' 217 client_at.run_test(reconnect_test_name, update_url=update_url) 218 client_at._check_client_test_result(self._host, reconnect_test_name) 219 if not self._update_continued_where_it_left_off(completed): 220 raise error.TestFail('The update did not continue where it ' 221 'left off before disconnecting network.') 222 223 # Suspend / Resume 224 boot_id = self._host.get_boot_id() 225 self._host.servo.lid_close() 226 self._host.test_wait_for_sleep() 227 self._host.servo.lid_open() 228 self._host.test_wait_for_boot(boot_id) 229 if not self._update_continued_where_it_left_off(completed): 230 raise error.TestFail('The update did not continue where it ' 231 'left off after suspend/resume.') 232 233 self._wait_for_update_to_complete() 234 235 if cellular: 236 # We didn't have a devserver so we cannot check the hostlog to 237 # ensure the update completed successfully. Instead we can check 238 # that the second-to-last update engine log has the successful 239 # update message. Second to last because its the one before OOBE 240 # rebooted. 241 update_engine_files_cmd = 'ls -t -1 /var/log/update_engine/' 242 files = self._host.run(update_engine_files_cmd).stdout.splitlines() 243 before_reboot_file = self._host.run('cat /var/log/update_engine/%s' 244 % files[1]).stdout 245 self._check_for_cellular_entries_in_update_log(before_reboot_file) 246 247 success = 'Update successfully applied, waiting to reboot.' 248 update_ec = self._host.run('cat /var/log/update_engine/%s | grep ' 249 '"%s"' % (files[1], success)).exit_status 250 if update_ec != 0: 251 raise error.TestFail('We could not verify that the update ' 252 'completed successfully. Check the logs.') 253 return 254 255 # Verify that the update completed successfully by checking hostlog. 256 rootfs_hostlog, reboot_hostlog = self._create_hostlog_files() 257 self.verify_update_events(self._CUSTOM_LSB_VERSION, rootfs_hostlog) 258 self.verify_update_events(self._CUSTOM_LSB_VERSION, reboot_hostlog, 259 self._CUSTOM_LSB_VERSION) 260 261 after = self._get_chromeos_version() 262 logging.info('Successfully force updated from %s to %s.', before, after) 263