Home | History | Annotate | Download | only in autoupdate_EndToEndTest
      1 # Copyright (c) 2012 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.
      4 
      5 import collections
      6 import json
      7 import logging
      8 import os
      9 import socket
     10 import time
     11 import urllib2
     12 import urlparse
     13 
     14 from autotest_lib.client.bin import utils as client_utils
     15 from autotest_lib.client.common_lib import error, global_config
     16 from autotest_lib.client.common_lib.cros import autoupdater, dev_server
     17 from autotest_lib.server import afe_utils, autotest, hosts, test
     18 from autotest_lib.server.cros.dynamic_suite import tools
     19 
     20 
     21 def _wait(secs, desc=None):
     22     """Emits a log message and sleeps for a given number of seconds."""
     23     msg = 'Waiting %s seconds' % secs
     24     if desc:
     25         msg += ' (%s)' % desc
     26     logging.info(msg)
     27     time.sleep(secs)
     28 
     29 
     30 class ExpectedUpdateEventChainFailed(error.TestFail):
     31     """Raised if we fail to receive an expected event in a chain."""
     32 
     33 class RequiredArgumentMissing(error.TestError):
     34     """Raised if the test is missing a required argument."""
     35 
     36 
     37 # Update event types.
     38 EVENT_TYPE_DOWNLOAD_COMPLETE = '1'
     39 EVENT_TYPE_INSTALL_COMPLETE = '2'
     40 EVENT_TYPE_UPDATE_COMPLETE = '3'
     41 EVENT_TYPE_DOWNLOAD_STARTED = '13'
     42 EVENT_TYPE_DOWNLOAD_FINISHED = '14'
     43 EVENT_TYPE_REBOOTED_AFTER_UPDATE = '54'
     44 
     45 # Update event results.
     46 EVENT_RESULT_ERROR = '0'
     47 EVENT_RESULT_SUCCESS = '1'
     48 EVENT_RESULT_SUCCESS_REBOOT = '2'
     49 EVENT_RESULT_UPDATE_DEFERRED = '9'
     50 
     51 # Omaha event types/results, from update_engine/omaha_request_action.h
     52 # These are stored in dict form in order to easily print out the keys.
     53 EVENT_TYPE_DICT = {
     54         EVENT_TYPE_DOWNLOAD_COMPLETE: 'download_complete',
     55         EVENT_TYPE_INSTALL_COMPLETE: 'install_complete',
     56         EVENT_TYPE_UPDATE_COMPLETE: 'update_complete',
     57         EVENT_TYPE_DOWNLOAD_STARTED: 'download_started',
     58         EVENT_TYPE_DOWNLOAD_FINISHED: 'download_finished',
     59         EVENT_TYPE_REBOOTED_AFTER_UPDATE: 'rebooted_after_update'
     60 }
     61 
     62 EVENT_RESULT_DICT = {
     63         EVENT_RESULT_ERROR: 'error',
     64         EVENT_RESULT_SUCCESS: 'success',
     65         EVENT_RESULT_SUCCESS_REBOOT: 'success_reboot',
     66         EVENT_RESULT_UPDATE_DEFERRED: 'update_deferred'
     67 }
     68 
     69 
     70 def snippet(text):
     71     """Returns the text with start/end snip markers around it.
     72 
     73     @param text: The snippet text.
     74 
     75     @return The text with start/end snip markers around it.
     76     """
     77     snip = '---8<---' * 10
     78     start = '-- START -'
     79     end = '-- END -'
     80     return ('%s%s\n%s\n%s%s' %
     81             (start, snip[len(start):], text, end, snip[len(end):]))
     82 
     83 
     84 class ExpectedUpdateEvent(object):
     85     """Defines an expected event in an update process."""
     86 
     87     _ATTR_NAME_DICT_MAP = {
     88             'event_type': EVENT_TYPE_DICT,
     89             'event_result': EVENT_RESULT_DICT,
     90     }
     91 
     92     _VALID_TYPES = set(EVENT_TYPE_DICT.keys())
     93     _VALID_RESULTS = set(EVENT_RESULT_DICT.keys())
     94 
     95     def __init__(self, event_type=None, event_result=None, version=None,
     96                  previous_version=None, on_error=None):
     97         """Initializes an event expectation.
     98 
     99         @param event_type: Expected event type.
    100         @param event_result: Expected event result code.
    101         @param version: Expected reported image version.
    102         @param previous_version: Expected reported previous image version.
    103         @param on_error: This is either an object to be returned when a received
    104                          event mismatches the expectation, or a callable used
    105                          for generating one. In the latter case, takes as
    106                          input two attribute dictionaries (expected and actual)
    107                          and an iterable of mismatched keys. If None, a generic
    108                          message is returned.
    109         """
    110         if event_type and event_type not in self._VALID_TYPES:
    111             raise ValueError('event_type %s is not valid.' % event_type)
    112 
    113         if event_result and event_result not in self._VALID_RESULTS:
    114             raise ValueError('event_result %s is not valid.' % event_result)
    115 
    116         self._expected_attrs = {
    117             'event_type': event_type,
    118             'event_result': event_result,
    119             'version': version,
    120             'previous_version': previous_version,
    121         }
    122         self._on_error = on_error
    123 
    124 
    125     @staticmethod
    126     def _attr_val_str(attr_val, helper_dict, default=None):
    127         """Returns an enriched attribute value string, or default."""
    128         if not attr_val:
    129             return default
    130 
    131         s = str(attr_val)
    132         if helper_dict:
    133             s += ':%s' % helper_dict.get(attr_val, 'unknown')
    134 
    135         return s
    136 
    137 
    138     def _attr_name_and_values(self, attr_name, expected_attr_val,
    139                               actual_attr_val=None):
    140         """Returns an attribute name, expected and actual value strings.
    141 
    142         This will return (name, expected, actual); the returned value for
    143         actual will be None if its respective input is None/empty.
    144 
    145         """
    146         helper_dict = self._ATTR_NAME_DICT_MAP.get(attr_name)
    147         expected_attr_val_str = self._attr_val_str(expected_attr_val,
    148                                                    helper_dict,
    149                                                    default='any')
    150         actual_attr_val_str = self._attr_val_str(actual_attr_val, helper_dict)
    151 
    152         return attr_name, expected_attr_val_str, actual_attr_val_str
    153 
    154 
    155     def _attrs_to_str(self, attrs_dict):
    156         return ' '.join(['%s=%s' %
    157                          self._attr_name_and_values(attr_name, attr_val)[0:2]
    158                          for attr_name, attr_val in attrs_dict.iteritems()])
    159 
    160 
    161     def __str__(self):
    162         return self._attrs_to_str(self._expected_attrs)
    163 
    164 
    165     def verify(self, actual_event):
    166         """Verify the attributes of an actual event.
    167 
    168         @param actual_event: a dictionary containing event attributes
    169 
    170         @return An error message, or None if all attributes as expected.
    171 
    172         """
    173         mismatched_attrs = [
    174                 attr_name for attr_name, expected_attr_val
    175                 in self._expected_attrs.iteritems()
    176                 if (expected_attr_val and
    177                     not self._verify_attr(attr_name, expected_attr_val,
    178                                           actual_event.get(attr_name)))]
    179         if not mismatched_attrs:
    180             return None
    181         if callable(self._on_error):
    182             return self._on_error(self._expected_attrs, actual_event,
    183                                   mismatched_attrs)
    184         if self._on_error is None:
    185             return ('Received event (%s) does not match expectation (%s)' %
    186                     (self._attrs_to_str(actual_event), self))
    187         return self._on_error
    188 
    189 
    190     def _verify_attr(self, attr_name, expected_attr_val, actual_attr_val):
    191         """Verifies that an actual log event attributes matches expected on.
    192 
    193         @param attr_name: name of the attribute to verify
    194         @param expected_attr_val: expected attribute value
    195         @param actual_attr_val: actual attribute value
    196 
    197         @return True if actual value is present and matches, False otherwise.
    198 
    199         """
    200         # None values are assumed to be missing and non-matching.
    201         if actual_attr_val is None:
    202             logging.error('No value found for %s (expected %s)',
    203                           *self._attr_name_and_values(attr_name,
    204                                                       expected_attr_val)[0:2])
    205             return False
    206 
    207         # We allow expected version numbers (e.g. 2940.0.0) to be contained in
    208         # actual values (2940.0.0-a1); this is necessary for the test to pass
    209         # with developer / non-release images.
    210         if (actual_attr_val == expected_attr_val or
    211             ('version' in attr_name and expected_attr_val in actual_attr_val)):
    212             return True
    213 
    214         return False
    215 
    216 
    217     def get_attrs(self):
    218         """Returns a dictionary of expected attributes."""
    219         return dict(self._expected_attrs)
    220 
    221 
    222 class ExpectedUpdateEventChain(object):
    223     """Defines a chain of expected update events."""
    224     def __init__(self):
    225         self._expected_events_chain = []
    226 
    227 
    228     def add_event(self, expected_events, timeout, on_timeout=None):
    229         """Adds an expected event to the chain.
    230 
    231         @param expected_events: The ExpectedEvent, or a list thereof, to wait
    232                                 for. If a list is passed, it will wait for *any*
    233                                 of the provided events, but only one of those.
    234         @param timeout: A timeout (in seconds) to wait for the event.
    235         @param on_timeout: An error string to use if the event times out. If
    236                            None, a generic message is used.
    237         """
    238         if isinstance(expected_events, ExpectedUpdateEvent):
    239             expected_events = [expected_events]
    240         self._expected_events_chain.append(
    241                 (expected_events, timeout, on_timeout))
    242 
    243 
    244     @staticmethod
    245     def _format_event_with_timeout(expected_events, timeout):
    246         """Returns a string representation of the event, with timeout."""
    247         until = 'within %s seconds' % timeout if timeout else 'indefinitely'
    248         return '%s, %s' % (' OR '.join(map(str, expected_events)), until)
    249 
    250 
    251     def __str__(self):
    252         return ('[%s]' %
    253                 ', '.join(
    254                     [self._format_event_with_timeout(expected_events, timeout)
    255                      for expected_events, timeout, _
    256                      in self._expected_events_chain]))
    257 
    258 
    259     def __repr__(self):
    260         return str(self._expected_events_chain)
    261 
    262 
    263     def verify(self, get_next_event):
    264         """Verifies that an actual stream of events complies.
    265 
    266         @param get_next_event: a function returning the next event
    267 
    268         @raises ExpectedUpdateEventChainFailed if we failed to verify an event.
    269 
    270         """
    271         for expected_events, timeout, on_timeout in self._expected_events_chain:
    272             logging.info('Expecting %s',
    273                          self._format_event_with_timeout(expected_events,
    274                                                          timeout))
    275             err_msg = self._verify_event_with_timeout(
    276                     expected_events, timeout, on_timeout, get_next_event)
    277             if err_msg is not None:
    278                 logging.error('Failed expected event: %s', err_msg)
    279                 raise ExpectedUpdateEventChainFailed(err_msg)
    280 
    281 
    282     @staticmethod
    283     def _verify_event_with_timeout(expected_events, timeout, on_timeout,
    284                                    get_next_event):
    285         """Verify an expected event occurs within a given timeout.
    286 
    287         @param expected_events: the list of possible events expected next
    288         @param timeout: specified in seconds
    289         @param on_timeout: A string to return if timeout occurs, or None.
    290         @param get_next_event: function returning the next event in a stream
    291 
    292         @return None if event complies, an error string otherwise.
    293 
    294         """
    295         base_timestamp = curr_timestamp = time.time()
    296         expired_timestamp = base_timestamp + timeout
    297         while curr_timestamp <= expired_timestamp:
    298             new_event = get_next_event()
    299             if new_event:
    300                 logging.info('Event received after %s seconds',
    301                              round(curr_timestamp - base_timestamp, 1))
    302                 results = [event.verify(new_event) for event in expected_events]
    303                 return None if None in results else ' AND '.join(results)
    304 
    305             # No new events, sleep for one second only (so we don't miss
    306             # events at the end of the allotted timeout).
    307             time.sleep(1)
    308             curr_timestamp = time.time()
    309 
    310         logging.error('Timeout expired')
    311         if on_timeout is None:
    312             return ('Waiting for event %s timed out after %d seconds' %
    313                     (' OR '.join(map(str, expected_events)), timeout))
    314         return on_timeout
    315 
    316 
    317 class UpdateEventLogVerifier(object):
    318     """Verifies update event chains on a devserver update log."""
    319     def __init__(self, event_log_url, url_request_timeout=None):
    320         self._event_log_url = event_log_url
    321         self._url_request_timeout = url_request_timeout
    322         self._event_log = []
    323         self._num_consumed_events = 0
    324 
    325 
    326     def verify_expected_events_chain(self, expected_event_chain):
    327         """Verify a given event chain.
    328 
    329         @param expected_event_chain: instance of expected event chain.
    330 
    331         @raises ExpectedUpdateEventChainFailed if we failed to verify the an
    332                 event.
    333         """
    334         expected_event_chain.verify(self._get_next_log_event)
    335 
    336 
    337     def _get_next_log_event(self):
    338         """Returns the next event in an event log.
    339 
    340         Uses the URL handed to it during initialization to obtain the host log
    341         from a devserver. If new events are encountered, the first of them is
    342         consumed and returned.
    343 
    344         @return The next new event in the host log, as reported by devserver;
    345                 None if no such event was found or an error occurred.
    346 
    347         """
    348         # (Re)read event log from devserver, if necessary.
    349         if len(self._event_log) <= self._num_consumed_events:
    350             try:
    351                 if self._url_request_timeout:
    352                     conn = urllib2.urlopen(self._event_log_url,
    353                                            timeout=self._url_request_timeout)
    354                 else:
    355                     conn = urllib2.urlopen(self._event_log_url)
    356             except urllib2.URLError, e:
    357                 logging.warning('Failed to read event log url: %s', e)
    358                 return None
    359             except socket.timeout, e:
    360                 logging.warning('Timed out reading event log url: %s', e)
    361                 return None
    362 
    363             event_log_resp = conn.read()
    364             conn.close()
    365             self._event_log = json.loads(event_log_resp)
    366 
    367         # Return next new event, if one is found.
    368         if len(self._event_log) > self._num_consumed_events:
    369             new_event = {
    370                     key: str(val) for key, val
    371                     in self._event_log[self._num_consumed_events].iteritems()
    372             }
    373             self._num_consumed_events += 1
    374             logging.info('Consumed new event: %s', new_event)
    375             return new_event
    376 
    377 
    378 class OmahaDevserverFailedToStart(error.TestError):
    379     """Raised when a omaha devserver fails to start."""
    380 
    381 
    382 class OmahaDevserver(object):
    383     """Spawns a test-private devserver instance."""
    384     # How long to wait for a devserver to start.
    385     _WAIT_FOR_DEVSERVER_STARTED_SECONDS = 30
    386 
    387     # How long to sleep (seconds) between checks to see if a devserver is up.
    388     _WAIT_SLEEP_INTERVAL = 1
    389 
    390     # Max devserver execution time (seconds); used with timeout(1) to ensure we
    391     # don't have defunct instances hogging the system.
    392     _DEVSERVER_TIMELIMIT_SECONDS = 12 * 60 * 60
    393 
    394 
    395     def __init__(self, omaha_host, devserver_dir, update_payload_staged_url):
    396         """Starts a private devserver instance, operating at Omaha capacity.
    397 
    398         @param omaha_host: host address where the devserver is spawned.
    399         @param devserver_dir: path to the devserver source directory
    400         @param update_payload_staged_url: URL to provision for update requests.
    401 
    402         """
    403         if not update_payload_staged_url:
    404             raise error.TestError('Missing update payload url')
    405 
    406         self._omaha_host = omaha_host
    407         self._devserver_pid = 0
    408         self._devserver_port = 0  # Determined later from devserver portfile.
    409         self._devserver_dir = devserver_dir
    410         self._update_payload_staged_url = update_payload_staged_url
    411 
    412         self._devserver_ssh = hosts.SSHHost(self._omaha_host,
    413                                             user=os.environ['USER'])
    414 
    415         # Temporary files for various devserver outputs.
    416         self._devserver_logfile = None
    417         self._devserver_stdoutfile = None
    418         self._devserver_portfile = None
    419         self._devserver_pidfile = None
    420         self._devserver_static_dir = None
    421 
    422 
    423     def _cleanup_devserver_files(self):
    424         """Cleans up the temporary devserver files."""
    425         for filename in (self._devserver_logfile, self._devserver_stdoutfile,
    426                          self._devserver_portfile, self._devserver_pidfile):
    427             if filename:
    428                 self._devserver_ssh.run('rm -f %s' % filename,
    429                                         ignore_status=True)
    430 
    431         if self._devserver_static_dir:
    432             self._devserver_ssh.run('rm -rf %s' % self._devserver_static_dir,
    433                                     ignore_status=True)
    434 
    435 
    436     def _create_tempfile_on_devserver(self, label, dir=False):
    437         """Creates a temporary file/dir on the devserver and returns its path.
    438 
    439         @param label: Identifier for the file context (string, no whitespaces).
    440         @param dir: If True, create a directory instead of a file.
    441 
    442         @raises test.TestError: If we failed to invoke mktemp on the server.
    443         @raises OmahaDevserverFailedToStart: If tempfile creation failed.
    444         """
    445         remote_cmd = 'mktemp --tmpdir devserver-%s.XXXXXX' % label
    446         if dir:
    447             remote_cmd += ' --directory'
    448 
    449         try:
    450             result = self._devserver_ssh.run(remote_cmd, ignore_status=True)
    451         except error.AutoservRunError as e:
    452             self._log_and_raise_remote_ssh_error(e)
    453         if result.exit_status != 0:
    454             raise OmahaDevserverFailedToStart(
    455                     'Could not create a temporary %s file on the devserver, '
    456                     'error output: "%s"' % (label, result.stderr))
    457         return result.stdout.strip()
    458 
    459     @staticmethod
    460     def _log_and_raise_remote_ssh_error(e):
    461         """Logs failure to ssh remote, then raises a TestError."""
    462         logging.debug('Failed to ssh into the devserver: %s', e)
    463         logging.error('If you are running this locally it means you did not '
    464                       'configure ssh correctly.')
    465         raise error.TestError('Failed to ssh into the devserver: %s' % e)
    466 
    467 
    468     def _read_int_from_devserver_file(self, filename):
    469         """Reads and returns an integer value from a file on the devserver."""
    470         return int(self._get_devserver_file_content(filename).strip())
    471 
    472 
    473     def _wait_for_devserver_to_start(self):
    474         """Waits until the devserver starts within the time limit.
    475 
    476         Infers and sets the devserver PID and serving port.
    477 
    478         Raises:
    479             OmahaDevserverFailedToStart: If the time limit is reached and we
    480                                          cannot connect to the devserver.
    481         """
    482         # Compute the overall timeout.
    483         deadline = time.time() + self._WAIT_FOR_DEVSERVER_STARTED_SECONDS
    484 
    485         # First, wait for port file to be filled and determine the server port.
    486         logging.warning('Waiting for devserver to start up.')
    487         while time.time() < deadline:
    488             try:
    489                 self._devserver_pid = self._read_int_from_devserver_file(
    490                         self._devserver_pidfile)
    491                 self._devserver_port = self._read_int_from_devserver_file(
    492                         self._devserver_portfile)
    493                 logging.info('Devserver pid is %d, serving on port %d',
    494                              self._devserver_pid, self._devserver_port)
    495                 break
    496             except Exception:  # Couldn't read file or corrupt content.
    497                 time.sleep(self._WAIT_SLEEP_INTERVAL)
    498         else:
    499             try:
    500                 self._devserver_ssh.run_output('uptime')
    501             except error.AutoservRunError as e:
    502                 logging.debug('Failed to run uptime on the devserver: %s', e)
    503             raise OmahaDevserverFailedToStart(
    504                     'The test failed to find the pid/port of the omaha '
    505                     'devserver after %d seconds. Check the dumped devserver '
    506                     'logs and devserver load for more information.' %
    507                     self._WAIT_FOR_DEVSERVER_STARTED_SECONDS)
    508 
    509         # Check that the server is reponsding to network requests.
    510         logging.warning('Waiting for devserver to accept network requests.')
    511         url = 'http://%s' % self.get_netloc()
    512         while time.time() < deadline:
    513             if dev_server.ImageServer.devserver_healthy(url, timeout_min=0.1):
    514                 break
    515 
    516             # TODO(milleral): Refactor once crbug.com/221626 is resolved.
    517             time.sleep(self._WAIT_SLEEP_INTERVAL)
    518         else:
    519             raise OmahaDevserverFailedToStart(
    520                     'The test failed to establish a connection to the omaha '
    521                     'devserver it set up on port %d. Check the dumped '
    522                     'devserver logs for more information.' %
    523                     self._devserver_port)
    524 
    525 
    526     def start_devserver(self):
    527         """Starts the devserver and confirms it is up.
    528 
    529         Raises:
    530             test.TestError: If we failed to spawn the remote devserver.
    531             OmahaDevserverFailedToStart: If the time limit is reached and we
    532                                          cannot connect to the devserver.
    533         """
    534         update_payload_url_base, update_payload_path = self._split_url(
    535                 self._update_payload_staged_url)
    536 
    537         # Allocate temporary files for various server outputs.
    538         self._devserver_logfile = self._create_tempfile_on_devserver('log')
    539         self._devserver_stdoutfile = self._create_tempfile_on_devserver(
    540                 'stdout')
    541         self._devserver_portfile = self._create_tempfile_on_devserver('port')
    542         self._devserver_pidfile = self._create_tempfile_on_devserver('pid')
    543         self._devserver_static_dir = self._create_tempfile_on_devserver(
    544                 'static', dir=True)
    545 
    546         # Invoke the Omaha/devserver on the remote server. Will attempt to kill
    547         # it with a SIGTERM after a predetermined timeout has elapsed, followed
    548         # by SIGKILL if not dead within 30 seconds from the former signal.
    549         cmdlist = [
    550                 'timeout', '-s', 'TERM', '-k', '30',
    551                 str(self._DEVSERVER_TIMELIMIT_SECONDS),
    552                 '%s/devserver.py' % self._devserver_dir,
    553                 '--payload=%s' % update_payload_path,
    554                 '--port=0',
    555                 '--pidfile=%s' % self._devserver_pidfile,
    556                 '--portfile=%s' % self._devserver_portfile,
    557                 '--logfile=%s' % self._devserver_logfile,
    558                 '--remote_payload',
    559                 '--urlbase=%s' % update_payload_url_base,
    560                 '--max_updates=1',
    561                 '--host_log',
    562                 '--static_dir=%s' % self._devserver_static_dir,
    563                 '--critical_update',
    564         ]
    565         remote_cmd = '( %s ) </dev/null >%s 2>&1 &' % (
    566                 ' '.join(cmdlist), self._devserver_stdoutfile)
    567 
    568         logging.info('Starting devserver with %r', remote_cmd)
    569         try:
    570             self._devserver_ssh.run_output(remote_cmd)
    571         except error.AutoservRunError as e:
    572             self._log_and_raise_remote_ssh_error(e)
    573 
    574         try:
    575             self._wait_for_devserver_to_start()
    576         except OmahaDevserverFailedToStart:
    577             self._kill_remote_process()
    578             self._dump_devserver_log()
    579             self._cleanup_devserver_files()
    580             raise
    581 
    582 
    583     def _kill_remote_process(self):
    584         """Kills the devserver and verifies it's down; clears the remote pid."""
    585         def devserver_down():
    586             """Ensure that the devserver process is down."""
    587             return not self._remote_process_alive()
    588 
    589         if devserver_down():
    590             return
    591 
    592         for signal in 'SIGTERM', 'SIGKILL':
    593             remote_cmd = 'kill -s %s %s' % (signal, self._devserver_pid)
    594             self._devserver_ssh.run(remote_cmd)
    595             try:
    596                 client_utils.poll_for_condition(
    597                         devserver_down, sleep_interval=1, desc='devserver down')
    598                 break
    599             except client_utils.TimeoutError:
    600                 logging.warning('Could not kill devserver with %s.', signal)
    601         else:
    602             logging.warning('Failed to kill devserver, giving up.')
    603 
    604         self._devserver_pid = None
    605 
    606 
    607     def _remote_process_alive(self):
    608         """Tests whether the remote devserver process is running."""
    609         if not self._devserver_pid:
    610             return False
    611         remote_cmd = 'test -e /proc/%s' % self._devserver_pid
    612         result = self._devserver_ssh.run(remote_cmd, ignore_status=True)
    613         return result.exit_status == 0
    614 
    615 
    616     def get_netloc(self):
    617         """Returns the netloc (host:port) of the devserver."""
    618         if not (self._devserver_pid and self._devserver_port):
    619             raise error.TestError('No running omaha/devserver')
    620 
    621         return '%s:%s' % (self._omaha_host, self._devserver_port)
    622 
    623 
    624     def get_update_url(self):
    625         """Returns the update_url you can use to update via this server."""
    626         return urlparse.urlunsplit(('http', self.get_netloc(), '/update',
    627                                     '', ''))
    628 
    629 
    630     def _get_devserver_file_content(self, filename):
    631         """Returns the content of a file on the devserver."""
    632         return self._devserver_ssh.run_output('cat %s' % filename,
    633                                               stdout_tee=None)
    634 
    635 
    636     def _get_devserver_log(self):
    637         """Obtain the devserver output."""
    638         return self._get_devserver_file_content(self._devserver_logfile)
    639 
    640 
    641     def _get_devserver_stdout(self):
    642         """Obtain the devserver output in stdout and stderr."""
    643         return self._get_devserver_file_content(self._devserver_stdoutfile)
    644 
    645 
    646     def _dump_devserver_log(self, logging_level=logging.ERROR):
    647         """Dump the devserver log to the autotest log.
    648 
    649         @param logging_level: logging level (from logging) to log the output.
    650         """
    651         logging.log(logging_level, "Devserver stdout and stderr:\n" +
    652                     snippet(self._get_devserver_stdout()))
    653         logging.log(logging_level, "Devserver log file:\n" +
    654                     snippet(self._get_devserver_log()))
    655 
    656 
    657     @staticmethod
    658     def _split_url(url):
    659         """Splits a URL into the URL base and path."""
    660         split_url = urlparse.urlsplit(url)
    661         url_base = urlparse.urlunsplit(
    662                 (split_url.scheme, split_url.netloc, '', '', ''))
    663         url_path = split_url.path
    664         return url_base, url_path.lstrip('/')
    665 
    666 
    667     def stop_devserver(self):
    668         """Kill remote process and wait for it to die, dump its output."""
    669         if not self._devserver_pid:
    670             logging.error('No running omaha/devserver.')
    671             return
    672 
    673         logging.info('Killing omaha/devserver')
    674         self._kill_remote_process()
    675         logging.debug('Final devserver log before killing')
    676         self._dump_devserver_log(logging.DEBUG)
    677         self._cleanup_devserver_files()
    678 
    679 
    680 class TestPlatform(object):
    681     """An interface and factory for platform-dependent functionality."""
    682 
    683     # Named tuple containing urls for staged urls needed for test.
    684     # source_url: url to find the update payload for the source image.
    685     # source_stateful_url: url to find the stateful payload for the source
    686     #                      image.
    687     # target_url: url to find the update payload for the target image.
    688     # target_stateful_url: url to find the stateful payload for the target
    689     #                      image.
    690     StagedURLs = collections.namedtuple(
    691             'StagedURLs',
    692             ['source_url', 'source_stateful_url', 'target_url',
    693              'target_stateful_url'])
    694 
    695 
    696     def __init__(self):
    697         assert False, 'Cannot instantiate this interface'
    698 
    699 
    700     @staticmethod
    701     def create(host):
    702         """Returns a TestPlatform implementation based on the host type.
    703 
    704         *DO NOT* override this method.
    705 
    706         @param host: a host object representing the DUT
    707 
    708         @return A TestPlatform implementation.
    709         """
    710         os_type = host.get_os_type()
    711         if os_type == 'cros':
    712             return ChromiumOSTestPlatform(host)
    713         if os_type == 'brillo':
    714             return BrilloTestPlatform(host)
    715 
    716         raise error.TestError('Unknown OS type reported by host: %s' % os_type)
    717 
    718 
    719     def initialize(self, autotest_devserver, devserver_dir):
    720         """Initialize the object.
    721 
    722         @param autotest_devserver: Instance of client.common_lib.dev_server to
    723                                    use to reach the devserver instance for this
    724                                    build.
    725         @param devserver_dir: Path to devserver source tree.
    726         """
    727         raise NotImplementedError
    728 
    729 
    730     def prep_artifacts(self, test_conf):
    731         """Prepares update artifacts for the test.
    732 
    733         The test config must include 'source_payload_uri' and
    734         'target_payload_uri'. In addition, it may include platform-specific
    735         values as determined by the test control file.
    736 
    737         @param test_conf: Dictionary containing the test configuration.
    738 
    739         @return A tuple of staged URLs.
    740 
    741         @raise error.TestError on failure.
    742         """
    743         raise NotImplementedError
    744 
    745 
    746     def reboot_device(self):
    747         """Reboots the device."""
    748         raise NotImplementedError
    749 
    750 
    751     def prep_device_for_update(self, source_release):
    752         """Prepares the device for update.
    753 
    754         @param source_release: Source release version (string), or None.
    755 
    756         @raise error.TestError on failure.
    757         """
    758         raise NotImplementedError
    759 
    760 
    761     def get_active_slot(self):
    762         """Returns the active boot slot of the device."""
    763         raise NotImplementedError
    764 
    765 
    766     def start_update_perf(self, bindir):
    767         """Starts performance monitoring (if available).
    768 
    769         @param bindir: Directory containing test binary files.
    770         """
    771         raise NotImplementedError
    772 
    773 
    774     def stop_update_perf(self):
    775         """Stops performance monitoring and returns data (if available).
    776 
    777         @return Dictionary containing performance attributes.
    778         """
    779         raise NotImplementedError
    780 
    781 
    782     def trigger_update(self, omaha_devserver):
    783         """Kicks off an update.
    784 
    785         @param omaha_devserver: OmahaDevserver instance.
    786         """
    787         raise NotImplementedError
    788 
    789 
    790     def finalize_update(self):
    791         """Performs post-update procedures."""
    792         raise NotImplementedError
    793 
    794 
    795     def get_update_log(self, num_lines):
    796         """Returns the update log.
    797 
    798         @param num_lines: Number of log lines to return (tail), zero for all.
    799 
    800         @return String containing the last |num_lines| from the update log.
    801         """
    802         raise NotImplementedError
    803 
    804 
    805     def check_device_after_update(self, target_release):
    806         """Runs final sanity checks.
    807 
    808         @param target_release: Target release version (string), or None.
    809 
    810         @raise error.TestError on failure.
    811         """
    812         raise NotImplementedError
    813 
    814 
    815 class ChromiumOSTestPlatform(TestPlatform):
    816     """A TestPlatform implementation for Chromium OS."""
    817 
    818     _STATEFUL_UPDATE_FILENAME = 'stateful.tgz'
    819     _LOGINABLE_MINIMUM_RELEASE = 5110
    820 
    821     def __init__(self, host):
    822         self._host = host
    823         self._autotest_devserver = None
    824         self._devserver_dir = None
    825         self._staged_urls = None
    826         self._perf_mon_pid = None
    827 
    828 
    829     def _stage_payload(self, devserver_label, filename, archive_url=None):
    830         """Stage the given payload onto the devserver.
    831 
    832         Works for either a stateful or full/delta test payload. Expects the
    833         gs_path or a combo of devserver_label + filename.
    834 
    835         @param devserver_label: The build name e.g. x86-mario-release/<version>.
    836                                 If set, assumes default gs archive bucket and
    837                                 requires filename to be specified.
    838         @param filename: In conjunction with devserver_label, if just specifying
    839                          the devserver label name, this is which file are you
    840                          downloading.
    841         @param archive_url: An optional GS archive location, if not using the
    842                             devserver's default.
    843 
    844         @return URL of the staged payload on the server.
    845 
    846         @raise error.TestError if there's a problem with staging.
    847 
    848         """
    849         try:
    850             self._autotest_devserver.stage_artifacts(
    851                     image=devserver_label, files=[filename],
    852                     archive_url=archive_url)
    853             return self._autotest_devserver.get_staged_file_url(filename,
    854                                                                 devserver_label)
    855         except dev_server.DevServerException, e:
    856             raise error.TestError('Failed to stage payload: %s' % e)
    857 
    858 
    859     def _stage_payload_by_uri(self, payload_uri):
    860         """Stage a payload based on its GS URI.
    861 
    862         This infers the build's label, filename and GS archive from the
    863         provided GS URI.
    864 
    865         @param payload_uri: The full GS URI of the payload.
    866 
    867         @return URL of the staged payload on the server.
    868 
    869         @raise error.TestError if there's a problem with staging.
    870 
    871         """
    872         archive_url, _, filename = payload_uri.rpartition('/')
    873         devserver_label = urlparse.urlsplit(archive_url).path.strip('/')
    874         return self._stage_payload(devserver_label, filename,
    875                                    archive_url=archive_url)
    876 
    877 
    878     @staticmethod
    879     def _payload_to_update_url(payload_url):
    880         """Given a update or stateful payload url, returns the update url."""
    881         # We want to transform it to the correct omaha url which is
    882         # <hostname>/update/...LABEL.
    883         base_url = payload_url.rpartition('/')[0]
    884         return base_url.replace('/static/', '/update/')
    885 
    886 
    887     def _get_stateful_uri(self, build_uri):
    888         """Returns a complete GS URI of a stateful update given a build path."""
    889         return '/'.join([build_uri.rstrip('/'), self._STATEFUL_UPDATE_FILENAME])
    890 
    891 
    892     def _payload_to_stateful_uri(self, payload_uri):
    893         """Given a payload GS URI, returns the corresponding stateful URI."""
    894         build_uri = payload_uri.rpartition('/')[0]
    895         if build_uri.endswith('payloads'):
    896             build_uri = build_uri.rpartition('/')[0]
    897         return self._get_stateful_uri(build_uri)
    898 
    899 
    900     def _update_via_test_payloads(self, omaha_host, payload_url, stateful_url,
    901                                   clobber):
    902         """Given the following update and stateful urls, update the DUT.
    903 
    904         Only updates the rootfs/stateful if the respective url is provided.
    905 
    906         @param omaha_host: If updating rootfs, redirect updates through this
    907             host. Should be None iff payload_url is None.
    908         @param payload_url: If set, the specified url to find the update
    909             payload.
    910         @param stateful_url: If set, the specified url to find the stateful
    911             payload.
    912         @param clobber: If True, do a clean install of stateful.
    913         """
    914         def perform_update(url, is_stateful):
    915             """Perform a rootfs/stateful update using given URL.
    916 
    917             @param url: URL to update from.
    918             @param is_stateful: Whether this is a stateful or rootfs update.
    919             """
    920             if url:
    921                 updater = autoupdater.ChromiumOSUpdater(url, host=self._host)
    922                 if is_stateful:
    923                     updater.update_stateful(clobber=clobber)
    924                 else:
    925                     updater.update_image()
    926 
    927         # We create a OmahaDevserver to redirect blah.bin to update/. This
    928         # allows us to use any payload filename to serve an update.
    929         temp_devserver = None
    930         try:
    931             if payload_url:
    932                 temp_devserver = OmahaDevserver(
    933                         omaha_host, self._devserver_dir, payload_url)
    934                 temp_devserver.start_devserver()
    935                 payload_url = temp_devserver.get_update_url()
    936 
    937             stateful_url = self._payload_to_update_url(stateful_url)
    938 
    939             perform_update(payload_url, False)
    940             perform_update(stateful_url, True)
    941         finally:
    942             if temp_devserver:
    943                 temp_devserver.stop_devserver()
    944 
    945 
    946     def _install_source_version(self, devserver_hostname, image_url,
    947                                 stateful_url):
    948         """Prepare the specified host with the image given by the urls.
    949 
    950         @param devserver_hostname: If updating rootfs, redirect updates
    951                                    through this host. Should be None iff
    952                                    image_url is None.
    953         @param image_url: If set, the specified url to find the source image
    954                           or full payload for the source image.
    955         @param stateful_url: If set, the specified url to find the stateful
    956                              payload.
    957         """
    958         try:
    959             # Reboot to get us into a clean state.
    960             self._host.reboot()
    961             # Since we are installing the source image of the test, clobber
    962             # stateful.
    963             self._update_via_test_payloads(devserver_hostname, image_url,
    964                                            stateful_url, True)
    965             self._host.reboot()
    966         except OmahaDevserverFailedToStart as e:
    967             logging.fatal('Failed to start private devserver for installing '
    968                           'the source image (%s) on the DUT', image_url)
    969             raise error.TestError(
    970                     'Failed to start private devserver for installing the '
    971                     'source image on the DUT: %s' % e)
    972         except error.AutoservRunError as e:
    973             logging.fatal('Error re-imaging or rebooting the DUT with the '
    974                           'source image from %s', image_url)
    975             raise error.TestError('Failed to install the source image or '
    976                                   'reboot the DUT: %s' % e)
    977 
    978 
    979     def _stage_artifacts_onto_devserver(self, test_conf):
    980         """Stages artifacts that will be used by the test onto the devserver.
    981 
    982         @param test_conf: a dictionary containing test configuration values
    983 
    984         @return a StagedURLs tuple containing the staged urls.
    985         """
    986         logging.info('Staging images onto autotest devserver (%s)',
    987                      self._autotest_devserver.url())
    988 
    989         staged_source_url = None
    990         staged_source_stateful_url = None
    991         try:
    992             source_payload_uri = test_conf['source_payload_uri']
    993         except KeyError:
    994             # TODO(garnold) Remove legacy key support once control files on all
    995             # release branches have caught up.
    996             source_payload_uri = test_conf['source_image_uri']
    997         if source_payload_uri:
    998             staged_source_url = self._stage_payload_by_uri(source_payload_uri)
    999 
   1000             # In order to properly install the source image using a full
   1001             # payload we'll also need the stateful update that comes with it.
   1002             # In general, tests may have their source artifacts in a different
   1003             # location than their payloads. This is determined by whether or
   1004             # not the source_archive_uri attribute is set; if it isn't set,
   1005             # then we derive it from the dirname of the source payload.
   1006             source_archive_uri = test_conf.get('source_archive_uri')
   1007             if source_archive_uri:
   1008                 source_stateful_uri = self._get_stateful_uri(source_archive_uri)
   1009             else:
   1010                 source_stateful_uri = self._payload_to_stateful_uri(
   1011                         source_payload_uri)
   1012 
   1013             staged_source_stateful_url = self._stage_payload_by_uri(
   1014                     source_stateful_uri)
   1015 
   1016             # Log source image URLs.
   1017             logging.info('Source full payload from %s staged at %s',
   1018                          source_payload_uri, staged_source_url)
   1019             if staged_source_stateful_url:
   1020                 logging.info('Source stateful update from %s staged at %s',
   1021                              source_stateful_uri, staged_source_stateful_url)
   1022 
   1023         target_payload_uri = test_conf['target_payload_uri']
   1024         staged_target_url = self._stage_payload_by_uri(target_payload_uri)
   1025         target_stateful_uri = None
   1026         staged_target_stateful_url = None
   1027         target_archive_uri = test_conf.get('target_archive_uri')
   1028         if target_archive_uri:
   1029             target_stateful_uri = self._get_stateful_uri(target_archive_uri)
   1030         else:
   1031             # Attempt to get the job_repo_url to find the stateful payload for
   1032             # the target image.
   1033             job_repo_url = afe_utils.get_host_attribute(
   1034                     self._host, self._host.job_repo_url_attribute)
   1035             if not job_repo_url:
   1036                 target_stateful_uri = self._payload_to_stateful_uri(
   1037                     target_payload_uri)
   1038             else:
   1039                 _, devserver_label = tools.get_devserver_build_from_package_url(
   1040                         job_repo_url)
   1041                 staged_target_stateful_url = self._stage_payload(
   1042                         devserver_label, self._STATEFUL_UPDATE_FILENAME)
   1043 
   1044         if not staged_target_stateful_url and target_stateful_uri:
   1045             staged_target_stateful_url = self._stage_payload_by_uri(
   1046                     target_stateful_uri)
   1047 
   1048         # Log target payload URLs.
   1049         logging.info('%s test payload from %s staged at %s',
   1050                      test_conf['update_type'], target_payload_uri,
   1051                      staged_target_url)
   1052         logging.info('Target stateful update from %s staged at %s',
   1053                      target_stateful_uri or 'standard location',
   1054                      staged_target_stateful_url)
   1055 
   1056         return self.StagedURLs(staged_source_url, staged_source_stateful_url,
   1057                                staged_target_url, staged_target_stateful_url)
   1058 
   1059 
   1060     def _run_login_test(self, release_string):
   1061         """Runs login_LoginSuccess test if it is supported by the release."""
   1062         # Only do login tests with recent builds, since they depend on
   1063         # some binary compatibility with the build itself.
   1064         # '5116.0.0' -> ('5116', '0', '0') -> 5116
   1065         if not release_string:
   1066             logging.info('No release provided, skipping login test.')
   1067         elif int(release_string.split('.')[0]) > self._LOGINABLE_MINIMUM_RELEASE:
   1068             # Login, to prove we can before/after the update.
   1069             logging.info('Attempting to login (release %s).', release_string)
   1070 
   1071             client_at = autotest.Autotest(self._host)
   1072             client_at.run_test('login_LoginSuccess', arc_mode='enabled')
   1073         else:
   1074             logging.info('Not attempting login test because %s is older than '
   1075                          '%d.', release_string, self._LOGINABLE_MINIMUM_RELEASE)
   1076 
   1077 
   1078     def _start_perf_mon(self, bindir):
   1079         """Starts monitoring performance and resource usage on a DUT.
   1080 
   1081         Call _stop_perf_mon() with the returned PID to stop monitoring
   1082         and collect the results.
   1083 
   1084         @param bindir: Directoy containing monitoring script.
   1085 
   1086         @return The PID of the newly created DUT monitoring process.
   1087         """
   1088         # We can't assume much about the source image so we copy the
   1089         # performance monitoring script to the DUT directly.
   1090         path = os.path.join(bindir, 'update_engine_performance_monitor.py')
   1091         self._host.send_file(path, '/tmp')
   1092         cmd = 'python /tmp/update_engine_performance_monitor.py --start-bg'
   1093         return int(self._host.run(cmd).stdout)
   1094 
   1095 
   1096     def _stop_perf_mon(self, perf_mon_pid):
   1097         """Stops monitoring performance and resource usage on a DUT.
   1098 
   1099         @param perf_mon_pid: the PID returned from _start_perf_mon().
   1100 
   1101         @return Dictionary containing performance attributes, or None if
   1102                 unavailable.
   1103         """
   1104         # Gracefully handle problems with performance monitoring by
   1105         # just returning None.
   1106         try:
   1107             cmd = ('python /tmp/update_engine_performance_monitor.py '
   1108                    '--stop-bg=%d') % perf_mon_pid
   1109             perf_json_txt = self._host.run(cmd).stdout
   1110             return json.loads(perf_json_txt)
   1111         except Exception as e:
   1112             logging.warning('Failed to parse output from '
   1113                             'update_engine_performance_monitor.py: %s', e)
   1114         return None
   1115 
   1116 
   1117     # Interface overrides.
   1118     #
   1119     def initialize(self, autotest_devserver, devserver_dir):
   1120         self._autotest_devserver = autotest_devserver
   1121         self._devserver_dir = devserver_dir
   1122 
   1123 
   1124     def reboot_device(self):
   1125         self._host.reboot()
   1126 
   1127 
   1128     def prep_artifacts(self, test_conf):
   1129         self._staged_urls = self._stage_artifacts_onto_devserver(test_conf)
   1130         return self._staged_urls
   1131 
   1132 
   1133     def prep_device_for_update(self, source_release):
   1134         # Install the source version onto the DUT.
   1135         if self._staged_urls.source_url:
   1136             logging.info('Installing a source image on the DUT')
   1137             devserver_hostname = urlparse.urlparse(
   1138                     self._autotest_devserver.url()).hostname
   1139             self._install_source_version(devserver_hostname,
   1140                                          self._staged_urls.source_url,
   1141                                          self._staged_urls.source_stateful_url)
   1142 
   1143         # Make sure we can login before the update.
   1144         self._run_login_test(source_release)
   1145 
   1146 
   1147     def get_active_slot(self):
   1148         return self._host.run('rootdev -s').stdout.strip()
   1149 
   1150 
   1151     def start_update_perf(self, bindir):
   1152         if self._perf_mon_pid is None:
   1153             self._perf_mon_pid = self._start_perf_mon(bindir)
   1154 
   1155 
   1156     def stop_update_perf(self):
   1157         perf_data = None
   1158         if self._perf_mon_pid is not None:
   1159             perf_data = self._stop_perf_mon(self._perf_mon_pid)
   1160             self._perf_mon_pid = None
   1161 
   1162         return perf_data
   1163 
   1164 
   1165     def trigger_update(self, omaha_devserver):
   1166         updater = autoupdater.ChromiumOSUpdater(
   1167                 omaha_devserver.get_update_url(), host=self._host)
   1168         updater.trigger_update()
   1169 
   1170 
   1171     def finalize_update(self):
   1172         self._update_via_test_payloads(
   1173                 None, None, self._staged_urls.target_stateful_url, False)
   1174 
   1175 
   1176     def get_update_log(self, num_lines):
   1177         return self._host.run_output(
   1178                 'tail -n %d /var/log/update_engine.log' % num_lines,
   1179                 stdout_tee=None)
   1180 
   1181 
   1182     def check_device_after_update(self, target_release):
   1183         # Make sure we can login after update.
   1184         self._run_login_test(target_release)
   1185 
   1186 
   1187 class BrilloTestPlatform(TestPlatform):
   1188     """A TestPlatform implementation for Brillo."""
   1189 
   1190     _URL_DEFAULT_PORT = 80
   1191     _DUT_LOCALHOST = '127.0.0.1'
   1192 
   1193     def __init__(self, host):
   1194         self._host = host
   1195         self._autotest_devserver = None
   1196         self._devserver_dir = None
   1197         self._staged_urls = None
   1198         self._forwarding_ports = set()
   1199 
   1200 
   1201     @classmethod
   1202     def _get_host_port(cls, url):
   1203         """Returns the host and port values from a given URL.
   1204 
   1205         @param url: The URL from which the values are extracted.
   1206 
   1207         @return A pair consisting of the host and port strings.
   1208         """
   1209         host, _, port = urlparse.urlsplit(url).netloc.partition(':')
   1210         return host, port or str(cls._URL_DEFAULT_PORT)
   1211 
   1212 
   1213     def _install_rev_forwarding(self, port=None):
   1214         """Installs reverse forwarding rules via ADB.
   1215 
   1216         @param port: The TCP port we want forwarded; if None, installs all
   1217                      previously configured ports.
   1218         """
   1219         ports = self._forwarding_ports if port is None else [port]
   1220         for port in ports:
   1221             port_spec = 'tcp:%s' % port
   1222             self._host.add_forwarding(port_spec, port_spec, reverse=True)
   1223 
   1224 
   1225     def _add_rev_forwarding(self, url):
   1226         """Configures reverse port forwarding and adjusts the given URL.
   1227 
   1228         This extracts the port from the URL, adds it to the set of configured
   1229         forwarding ports, installs it to the DUT, then returns the adjusted URL
   1230         for use by the DUT.
   1231 
   1232         @param url: The URL for which we need to establish forwarding.
   1233 
   1234         @return: The adjusted URL for use on the DUT.
   1235         """
   1236         if url:
   1237             host, port = self._get_host_port(url)
   1238             if port not in self._forwarding_ports:
   1239                 self._forwarding_ports.add(port)
   1240                 self._install_rev_forwarding(port=port)
   1241             url = url.replace(host, self._DUT_LOCALHOST, 1)
   1242         return url
   1243 
   1244 
   1245     def _remove_rev_forwarding(self, url=None):
   1246         """Removes a reverse port forwarding.
   1247 
   1248         @param url: The URL for which forwarding was established; if None,
   1249                     removes all previously configured ports.
   1250         """
   1251         ports = set()
   1252         if url is None:
   1253             ports.update(self._forwarding_ports)
   1254         else:
   1255             _, port = self._get_host_port(url)
   1256             if port in self._forwarding_ports:
   1257                 ports.add(port)
   1258 
   1259         # TODO(garnold) Enable once ADB port removal is fixed (b/24771474):
   1260         # for port in ports:
   1261         #     self._host.remove_forwarding(src='tcp:%s' % port, reverse=True)
   1262 
   1263         self._forwarding_ports.difference_update(ports)
   1264 
   1265 
   1266     def _install_source_version(self, devserver_hostname, payload_url):
   1267         """Installs a source version onto the test device.
   1268 
   1269         @param devserver_hostname: Redirect updates through this host.
   1270         @param payload_url: URL of staged payload for installing a source image.
   1271         """
   1272         try:
   1273             # Start a private Omaha server and update the DUT.
   1274             temp_devserver = None
   1275             url = None
   1276             try:
   1277                 temp_devserver = OmahaDevserver(
   1278                         devserver_hostname, self._devserver_dir, payload_url)
   1279                 temp_devserver.start_devserver()
   1280                 url = self._add_rev_forwarding(temp_devserver.get_update_url())
   1281                 updater = autoupdater.BrilloUpdater(url, host=self._host)
   1282                 updater.update_image()
   1283             finally:
   1284                 if url:
   1285                     self._remove_rev_forwarding(url)
   1286                 if temp_devserver:
   1287                     temp_devserver.stop_devserver()
   1288 
   1289             # Reboot the DUT.
   1290             self.reboot_device()
   1291         except OmahaDevserverFailedToStart as e:
   1292             logging.fatal('Failed to start private devserver for installing '
   1293                           'the source payload (%s) on the DUT', payload_url)
   1294             raise error.TestError(
   1295                     'Failed to start private devserver for installing the '
   1296                     'source image on the DUT: %s' % e)
   1297         except error.AutoservRunError as e:
   1298             logging.fatal('Error re-imaging or rebooting the DUT with the '
   1299                           'source image from %s', payload_url)
   1300             raise error.TestError('Failed to install the source image or '
   1301                                   'reboot the DUT: %s' % e)
   1302 
   1303 
   1304     # Interface overrides.
   1305     #
   1306     def initialize(self, autotest_devserver, devserver_dir):
   1307         self._autotest_devserver = autotest_devserver
   1308         self._devserver_dir = devserver_dir
   1309 
   1310 
   1311     def reboot_device(self):
   1312         self._host.reboot()
   1313         self._install_rev_forwarding()
   1314 
   1315 
   1316     def prep_artifacts(self, test_conf):
   1317         # TODO(garnold) Currently we don't stage anything and assume that the
   1318         # provided URLs are of pre-staged payloads. We should implement staging
   1319         # support once a release scheme for Brillo is finalized.
   1320         self._staged_urls = self.StagedURLs(
   1321                 self._add_rev_forwarding(test_conf['source_payload_uri']), None,
   1322                 self._add_rev_forwarding(test_conf['target_payload_uri']), None)
   1323         return self._staged_urls
   1324 
   1325 
   1326     def prep_device_for_update(self, source_release):
   1327         # Install the source version onto the DUT.
   1328         if self._staged_urls.source_url:
   1329             logging.info('Installing a source image on the DUT')
   1330             devserver_hostname = urlparse.urlparse(
   1331                     self._autotest_devserver.url()).hostname
   1332             self._install_source_version(devserver_hostname,
   1333                                          self._staged_urls.source_url)
   1334 
   1335 
   1336     def get_active_slot(self):
   1337         return self._host.run('rootdev -s /system').stdout.strip()
   1338 
   1339 
   1340     def start_update_perf(self, bindir):
   1341         pass
   1342 
   1343 
   1344     def stop_update_perf(self):
   1345         pass
   1346 
   1347 
   1348     def trigger_update(self, omaha_devserver):
   1349         url = self._add_rev_forwarding(omaha_devserver.get_update_url())
   1350         updater = autoupdater.BrilloUpdater(url, host=self._host)
   1351         updater.trigger_update()
   1352 
   1353 
   1354     def finalize_update(self):
   1355         pass
   1356 
   1357 
   1358     def get_update_log(self, num_lines):
   1359         return self._host.run_output(
   1360                 'logcat -d -s update_engine | tail -n %d' % num_lines,
   1361                 stdout_tee=None)
   1362 
   1363 
   1364     def check_device_after_update(self, target_release):
   1365         self._remove_rev_forwarding()
   1366         # TODO(garnold) Port forwarding removal is broken in ADB (b/24771474).
   1367         # Instead we reboot the device, which has the side-effect of flushing
   1368         # all forwarding rules. Once fixed, the following should be removed.
   1369         self.reboot_device()
   1370 
   1371 
   1372 class autoupdate_EndToEndTest(test.test):
   1373     """Complete update test between two Chrome OS releases.
   1374 
   1375     Performs an end-to-end test of updating a ChromeOS device from one version
   1376     to another. The test performs the following steps:
   1377 
   1378       1. Stages the source (full) and target update payload on the central
   1379          devserver.
   1380       2. Spawns a private Omaha-like devserver instance, configured to return
   1381          the target (update) payload URL in response for an update check.
   1382       3. Reboots the DUT.
   1383       4. Installs a source image on the DUT (if provided) and reboots to it.
   1384       5. Triggers an update check at the DUT.
   1385       6. Watches as the DUT obtains an update and applies it.
   1386       7. Reboots and repeats steps 5-6, ensuring that the next update check
   1387          shows the new image version.
   1388 
   1389     Some notes on naming:
   1390       devserver: Refers to a machine running the Chrome OS Update Devserver.
   1391       autotest_devserver: An autotest wrapper to interact with a devserver.
   1392                           Can be used to stage artifacts to a devserver. While
   1393                           this can also be used to update a machine, we do not
   1394                           use it for that purpose in this test as we manage
   1395                           updates with out own devserver instances (see below).
   1396       omaha_devserver: This test's wrapper of a devserver running for the
   1397                        purposes of emulating omaha. This test controls the
   1398                        lifetime of this devserver instance and is separate
   1399                        from the autotest lab's devserver's instances which are
   1400                        only used for staging and hosting artifacts (because they
   1401                        scale). These are run on the same machines as the actual
   1402                        autotest devservers which are used for staging but on
   1403                        different ports.
   1404       *staged_url's: In this case staged refers to the fact that these items
   1405                      are available to be downloaded statically from these urls
   1406                      e.g. 'localhost:8080/static/my_file.gz'. These are usually
   1407                      given after staging an artifact using a autotest_devserver
   1408                      though they can be re-created given enough assumptions.
   1409       *update_url's: Urls refering to the update RPC on a given omaha devserver.
   1410                      Since we always use an instantiated omaha devserver to run
   1411                      updates, these will always reference an existing instance
   1412                      of an omaha devserver that we just created for the purposes
   1413                      of updating.
   1414       devserver_hostname: At the start of each test, we choose a devserver
   1415                           machine in the lab for the test. We use the devserver
   1416                           instance there (access by autotest_devserver) to stage
   1417                           artifacts. However, we also use the same host to start
   1418                           omaha devserver instances for updating machines with
   1419                           (that reference the staged paylaods on the autotest
   1420                           devserver instance). This hostname refers to that
   1421                           machine we are using (since it's always the same for
   1422                           both staging/omaha'ing).
   1423 
   1424     """
   1425     version = 1
   1426 
   1427     # Timeout periods, given in seconds.
   1428     _WAIT_AFTER_SHUTDOWN_SECONDS = 10
   1429     _WAIT_AFTER_UPDATE_SECONDS = 20
   1430     _WAIT_FOR_USB_INSTALL_SECONDS = 4 * 60
   1431     _WAIT_FOR_MP_RECOVERY_SECONDS = 8 * 60
   1432     _WAIT_FOR_INITIAL_UPDATE_CHECK_SECONDS = 12 * 60
   1433     # TODO(sosa): Investigate why this needs to be so long (this used to be
   1434     # 120 and regressed).
   1435     _WAIT_FOR_DOWNLOAD_STARTED_SECONDS = 4 * 60
   1436     _WAIT_FOR_DOWNLOAD_COMPLETED_SECONDS = 10 * 60
   1437     _WAIT_FOR_UPDATE_COMPLETED_SECONDS = 4 * 60
   1438     _WAIT_FOR_UPDATE_CHECK_AFTER_REBOOT_SECONDS = 15 * 60
   1439     _DEVSERVER_HOSTLOG_REQUEST_TIMEOUT_SECONDS = 30
   1440 
   1441     # Logs and their whereabouts.
   1442     _WHERE_UPDATE_LOG = ('update_engine log (in sysinfo or on the DUT, also '
   1443                          'included in the test log)')
   1444     _WHERE_OMAHA_LOG = 'Omaha-devserver log (included in the test log)'
   1445 
   1446 
   1447     def initialize(self):
   1448         """Sets up variables that will be used by test."""
   1449         self._host = None
   1450         self._omaha_devserver = None
   1451         self._source_image_installed = False
   1452 
   1453         self._devserver_dir = global_config.global_config.get_config_value(
   1454                 'CROS', 'devserver_dir', default=None)
   1455         if self._devserver_dir is None:
   1456             raise error.TestError(
   1457                     'Path to devserver source tree not provided; please define '
   1458                     'devserver_dir under [CROS] in your shadow_config.ini')
   1459 
   1460 
   1461     def cleanup(self):
   1462         """Kill the omaha devserver if it's still around."""
   1463         if self._omaha_devserver:
   1464             self._omaha_devserver.stop_devserver()
   1465 
   1466         self._omaha_devserver = None
   1467 
   1468 
   1469     def _dump_update_engine_log(self, test_platform):
   1470         """Dumps relevant AU error log."""
   1471         try:
   1472             error_log = test_platform.get_update_log(80)
   1473             logging.error('Dumping snippet of update_engine log:\n%s',
   1474                           snippet(error_log))
   1475         except Exception:
   1476             # Mute any exceptions we get printing debug logs.
   1477             pass
   1478 
   1479 
   1480     def _report_perf_data(self, perf_data):
   1481         """Reports performance and resource data.
   1482 
   1483         Currently, performance attributes are expected to include 'rss_peak'
   1484         (peak memory usage in bytes).
   1485 
   1486         @param perf_data: A dictionary containing performance attributes.
   1487         """
   1488         rss_peak = perf_data.get('rss_peak')
   1489         if rss_peak:
   1490             rss_peak_kib = rss_peak / 1024
   1491             logging.info('Peak memory (RSS) usage on DUT: %d KiB', rss_peak_kib)
   1492             self.output_perf_value(description='mem_usage_peak',
   1493                                    value=int(rss_peak_kib),
   1494                                    units='KiB',
   1495                                    higher_is_better=False)
   1496         else:
   1497             logging.warning('No rss_peak key in JSON returned by '
   1498                             'update_engine_performance_monitor.py')
   1499 
   1500 
   1501     def _error_initial_check(self, expected, actual, mismatched_attrs):
   1502         if 'version' in mismatched_attrs:
   1503             err_msg = ('Initial update check was received but the reported '
   1504                        'version is different from what was expected.')
   1505             if self._source_image_installed:
   1506                 err_msg += (' The source payload we installed was probably '
   1507                             'incorrect or corrupt.')
   1508             else:
   1509                 err_msg += (' The DUT is probably not running the correct '
   1510                             'source image.')
   1511             return err_msg
   1512 
   1513         return 'A test bug occurred; inspect the test log.'
   1514 
   1515 
   1516     def _error_intermediate(self, expected, actual, mismatched_attrs, action,
   1517                             problem):
   1518         if 'event_result' in mismatched_attrs:
   1519             event_result = actual.get('event_result')
   1520             reported = (('different than expected (%s)' %
   1521                          EVENT_RESULT_DICT[event_result])
   1522                         if event_result else 'missing')
   1523             return ('The updater reported result code is %s. This could be an '
   1524                     'updater bug or a connectivity problem; check the %s. For '
   1525                     'a detailed log of update events, check the %s.' %
   1526                     (reported, self._WHERE_UPDATE_LOG, self._WHERE_OMAHA_LOG))
   1527         if 'event_type' in mismatched_attrs:
   1528             event_type = actual.get('event_type')
   1529             reported = ('different (%s)' % EVENT_TYPE_DICT[event_type]
   1530                         if event_type else 'missing')
   1531             return ('Expected the updater to %s (%s) but received event type '
   1532                     'is %s. This could be an updater %s; check the '
   1533                     '%s. For a detailed log of update events, check the %s.' %
   1534                     (action, EVENT_TYPE_DICT[expected['event_type']], reported,
   1535                      problem, self._WHERE_UPDATE_LOG, self._WHERE_OMAHA_LOG))
   1536         if 'version' in mismatched_attrs:
   1537             return ('The updater reported an unexpected version despite '
   1538                     'previously reporting the correct one. This is most likely '
   1539                     'a bug in update engine; check the %s.' %
   1540                     self._WHERE_UPDATE_LOG)
   1541 
   1542         return 'A test bug occurred; inspect the test log.'
   1543 
   1544 
   1545     def _error_download_started(self, expected, actual, mismatched_attrs):
   1546         return self._error_intermediate(expected, actual, mismatched_attrs,
   1547                                         'begin downloading',
   1548                                         'bug, crash or provisioning error')
   1549 
   1550 
   1551     def _error_download_finished(self, expected, actual, mismatched_attrs):
   1552         return self._error_intermediate(expected, actual, mismatched_attrs,
   1553                                         'finish downloading', 'bug or crash')
   1554 
   1555 
   1556     def _error_update_complete(self, expected, actual, mismatched_attrs):
   1557         return self._error_intermediate(expected, actual, mismatched_attrs,
   1558                                         'complete the update', 'bug or crash')
   1559 
   1560 
   1561     def _error_reboot_after_update(self, expected, actual, mismatched_attrs):
   1562         if 'event_result' in mismatched_attrs:
   1563             event_result = actual.get('event_result')
   1564             reported = ('different (%s)' % EVENT_RESULT_DICT[event_result]
   1565                         if event_result else 'missing')
   1566             return ('The updater was expected to reboot (%s) but reported '
   1567                     'result code is %s. This could be a failure to reboot, an '
   1568                     'updater bug or a connectivity problem; check the %s and '
   1569                     'the system log. For a detailed log of update events, '
   1570                     'check the %s.' %
   1571                     (EVENT_RESULT_DICT[expected['event_result']], reported,
   1572                      self._WHERE_UPDATE_LOG, self._WHERE_OMAHA_LOG))
   1573         if 'event_type' in mismatched_attrs:
   1574             event_type = actual.get('event_type')
   1575             reported = ('different (%s)' % EVENT_TYPE_DICT[event_type]
   1576                         if event_type else 'missing')
   1577             return ('Expected to successfully reboot into the new image (%s) '
   1578                     'but received event type is %s. This probably means that '
   1579                     'the new image failed to verify after reboot, possibly '
   1580                     'because the payload is corrupt. This might also be an '
   1581                     'updater bug or crash; check the %s. For a detailed log of '
   1582                     'update events, check the %s.' %
   1583                     (EVENT_TYPE_DICT[expected['event_type']], reported,
   1584                      self._WHERE_UPDATE_LOG, self._WHERE_OMAHA_LOG))
   1585         if 'version' in mismatched_attrs:
   1586             return ('The DUT rebooted after the update but reports a different '
   1587                     'image version than the one expected. This probably means '
   1588                     'that the payload we applied was incorrect or corrupt.')
   1589         if 'previous_version' in mismatched_attrs:
   1590             return ('The DUT rebooted after the update and reports the '
   1591                     'expected version. However, it reports a previous version '
   1592                     'that is different from the one previously reported. This '
   1593                     'is most likely a bug in update engine; check the %s.' %
   1594                     self._WHERE_UPDATE_LOG)
   1595 
   1596         return 'A test bug occurred; inspect the test log.'
   1597 
   1598 
   1599     def _timeout_err(self, desc, timeout, event_type=None):
   1600         if event_type is not None:
   1601             desc += ' (%s)' % EVENT_TYPE_DICT[event_type]
   1602         return ('Failed to receive %s within %d seconds. This could be a '
   1603                 'problem with the updater or a connectivity issue. For more '
   1604                 'details, check the %s.' %
   1605                 (desc, timeout, self._WHERE_UPDATE_LOG))
   1606 
   1607 
   1608     def run_update_test(self, test_platform, test_conf):
   1609         """Runs the actual update test once preconditions are met.
   1610 
   1611         @param test_platform: TestPlatform implementation.
   1612         @param test_conf: A dictionary containing test configuration values
   1613 
   1614         @raises ExpectedUpdateEventChainFailed if we failed to verify an update
   1615                 event.
   1616         """
   1617 
   1618         # Record the active root partition.
   1619         source_active_slot = test_platform.get_active_slot()
   1620         logging.info('Source active slot: %s', source_active_slot)
   1621 
   1622         source_release = test_conf['source_release']
   1623         target_release = test_conf['target_release']
   1624 
   1625         # Start the performance monitoring process on the DUT.
   1626         test_platform.start_update_perf(self.bindir)
   1627         try:
   1628             # Trigger an update.
   1629             test_platform.trigger_update(self._omaha_devserver)
   1630 
   1631             # Track update progress.
   1632             omaha_netloc = self._omaha_devserver.get_netloc()
   1633             omaha_hostlog_url = urlparse.urlunsplit(
   1634                     ['http', omaha_netloc, '/api/hostlog',
   1635                      'ip=' + self._host.ip, ''])
   1636             logging.info('Polling update progress from omaha/devserver: %s',
   1637                          omaha_hostlog_url)
   1638             log_verifier = UpdateEventLogVerifier(
   1639                     omaha_hostlog_url,
   1640                     self._DEVSERVER_HOSTLOG_REQUEST_TIMEOUT_SECONDS)
   1641 
   1642             # Verify chain of events in a successful update process.
   1643             chain = ExpectedUpdateEventChain()
   1644             chain.add_event(
   1645                     ExpectedUpdateEvent(
   1646                         version=source_release,
   1647                         on_error=self._error_initial_check),
   1648                     self._WAIT_FOR_INITIAL_UPDATE_CHECK_SECONDS,
   1649                     on_timeout=self._timeout_err(
   1650                             'an initial update check',
   1651                             self._WAIT_FOR_INITIAL_UPDATE_CHECK_SECONDS))
   1652             chain.add_event(
   1653                     ExpectedUpdateEvent(
   1654                         event_type=EVENT_TYPE_DOWNLOAD_STARTED,
   1655                         event_result=EVENT_RESULT_SUCCESS,
   1656                         version=source_release,
   1657                         on_error=self._error_download_started),
   1658                     self._WAIT_FOR_DOWNLOAD_STARTED_SECONDS,
   1659                     on_timeout=self._timeout_err(
   1660                             'a download started notification',
   1661                             self._WAIT_FOR_DOWNLOAD_STARTED_SECONDS,
   1662                             event_type=EVENT_TYPE_DOWNLOAD_STARTED))
   1663             chain.add_event(
   1664                     ExpectedUpdateEvent(
   1665                         event_type=EVENT_TYPE_DOWNLOAD_FINISHED,
   1666                         event_result=EVENT_RESULT_SUCCESS,
   1667                         version=source_release,
   1668                         on_error=self._error_download_finished),
   1669                     self._WAIT_FOR_DOWNLOAD_COMPLETED_SECONDS,
   1670                     on_timeout=self._timeout_err(
   1671                             'a download finished notification',
   1672                             self._WAIT_FOR_DOWNLOAD_COMPLETED_SECONDS,
   1673                             event_type=EVENT_TYPE_DOWNLOAD_FINISHED))
   1674             chain.add_event(
   1675                     ExpectedUpdateEvent(
   1676                         event_type=EVENT_TYPE_UPDATE_COMPLETE,
   1677                         event_result=EVENT_RESULT_SUCCESS,
   1678                         version=source_release,
   1679                         on_error=self._error_update_complete),
   1680                     self._WAIT_FOR_UPDATE_COMPLETED_SECONDS,
   1681                     on_timeout=self._timeout_err(
   1682                             'an update complete notification',
   1683                             self._WAIT_FOR_UPDATE_COMPLETED_SECONDS,
   1684                             event_type=EVENT_TYPE_UPDATE_COMPLETE))
   1685 
   1686             log_verifier.verify_expected_events_chain(chain)
   1687 
   1688             # Wait after an update completion (safety margin).
   1689             _wait(self._WAIT_AFTER_UPDATE_SECONDS, 'after update completion')
   1690         finally:
   1691             # Terminate perf monitoring process and collect its output.
   1692             perf_data = test_platform.stop_update_perf()
   1693             if perf_data:
   1694                 self._report_perf_data(perf_data)
   1695 
   1696         # Only update the stateful partition (the test updated the rootfs).
   1697         test_platform.finalize_update()
   1698 
   1699         # Reboot the DUT after the update.
   1700         test_platform.reboot_device()
   1701 
   1702         # Trigger a second update check (again, test vs MP).
   1703         test_platform.trigger_update(self._omaha_devserver)
   1704 
   1705         # Observe post-reboot update check, which should indicate that the
   1706         # image version has been updated.
   1707         chain = ExpectedUpdateEventChain()
   1708         expected_events = [
   1709             ExpectedUpdateEvent(
   1710                 event_type=EVENT_TYPE_UPDATE_COMPLETE,
   1711                 event_result=EVENT_RESULT_SUCCESS_REBOOT,
   1712                 version=target_release,
   1713                 previous_version=source_release,
   1714                 on_error=self._error_reboot_after_update),
   1715             # Newer versions send a "rebooted_after_update" message after reboot
   1716             # with the previous version instead of another "update_complete".
   1717             ExpectedUpdateEvent(
   1718                 event_type=EVENT_TYPE_REBOOTED_AFTER_UPDATE,
   1719                 event_result=EVENT_RESULT_SUCCESS,
   1720                 version=target_release,
   1721                 previous_version=source_release,
   1722                 on_error=self._error_reboot_after_update),
   1723         ]
   1724         chain.add_event(
   1725                 expected_events,
   1726                 self._WAIT_FOR_UPDATE_CHECK_AFTER_REBOOT_SECONDS,
   1727                 on_timeout=self._timeout_err(
   1728                         'a successful reboot notification',
   1729                         self._WAIT_FOR_UPDATE_CHECK_AFTER_REBOOT_SECONDS,
   1730                         event_type=EVENT_TYPE_UPDATE_COMPLETE))
   1731 
   1732         log_verifier.verify_expected_events_chain(chain)
   1733 
   1734         # Make sure we're using a different slot after the update.
   1735         target_active_slot = test_platform.get_active_slot()
   1736         if target_active_slot == source_active_slot:
   1737             err_msg = 'The active image slot did not change after the update.'
   1738             if None in (source_release, target_release):
   1739                 err_msg += (' The DUT likely rebooted into the old image, which '
   1740                             'probably means that the payload we applied was '
   1741                             'corrupt. But since we did not check the source '
   1742                             'and/or target version we cannot say for sure.')
   1743             elif source_release == target_release:
   1744                 err_msg += (' Given that the source and target versions are '
   1745                             'identical, the DUT likely rebooted into the old '
   1746                             'image. This probably means that the payload we '
   1747                             'applied was corrupt.')
   1748             else:
   1749                 err_msg += (' This is strange since the DUT reported the '
   1750                             'correct target version. This is probably a system '
   1751                             'bug; check the DUT system log.')
   1752             raise error.TestFail(err_msg)
   1753 
   1754         logging.info('Target active slot changed as expected: %s',
   1755                      target_active_slot)
   1756 
   1757         logging.info('Update successful, test completed')
   1758 
   1759 
   1760     # TODO(garnold) Remove the use_servo argument once control files on all
   1761     # release branches have caught up.
   1762     def run_once(self, host, test_conf, use_servo=False):
   1763         """Performs a complete auto update test.
   1764 
   1765         @param host: a host object representing the DUT
   1766         @param test_conf: a dictionary containing test configuration values
   1767         @param use_servo: DEPRECATED
   1768 
   1769         @raise error.TestError if anything went wrong with setting up the test;
   1770                error.TestFail if any part of the test has failed.
   1771 
   1772         """
   1773 
   1774         self._host = host
   1775 
   1776         # Find a devserver to use. We first try to pick a devserver with the
   1777         # least load. In case all devservers' load are higher than threshold,
   1778         # fall back to the old behavior by picking a devserver based on the
   1779         # payload URI, with which ImageServer.resolve will return a random
   1780         # devserver based on the hash of the URI.
   1781         # The picked devserver needs to respect the location of the host if
   1782         # `prefer_local_devserver` is set to True or `restricted_subnets` is
   1783         # set.
   1784         hostname = self._host.hostname if self._host else None
   1785         least_loaded_devserver = dev_server.get_least_loaded_devserver(
   1786                 hostname=hostname)
   1787         if least_loaded_devserver:
   1788             logging.debug('Choose the least loaded devserver: %s',
   1789                           least_loaded_devserver)
   1790             autotest_devserver = dev_server.ImageServer(least_loaded_devserver)
   1791         else:
   1792             logging.warning('No devserver meets the maximum load requirement. '
   1793                             'Pick a random devserver to use.')
   1794             autotest_devserver = dev_server.ImageServer.resolve(
   1795                     test_conf['target_payload_uri'], host.hostname)
   1796         devserver_hostname = urlparse.urlparse(
   1797                 autotest_devserver.url()).hostname
   1798 
   1799         # Obtain a test platform implementation.
   1800         test_platform = TestPlatform.create(host)
   1801         test_platform.initialize(autotest_devserver, self._devserver_dir)
   1802 
   1803         # Stage source images and update payloads onto a devserver.
   1804         staged_urls = test_platform.prep_artifacts(test_conf)
   1805         self._source_image_installed = bool(staged_urls.source_url)
   1806 
   1807         # Prepare the DUT (install source version etc).
   1808         test_platform.prep_device_for_update(test_conf['source_release'])
   1809 
   1810         self._omaha_devserver = OmahaDevserver(
   1811                 devserver_hostname, self._devserver_dir,
   1812                 staged_urls.target_url)
   1813         self._omaha_devserver.start_devserver()
   1814 
   1815         try:
   1816             self.run_update_test(test_platform, test_conf)
   1817         except ExpectedUpdateEventChainFailed:
   1818             self._dump_update_engine_log(test_platform)
   1819             raise
   1820 
   1821         test_platform.check_device_after_update(test_conf['target_release'])
   1822