client/cros/cros_ui_test.py

   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 glob, logging, os, re, shutil, subprocess, sys, time
   6
   7 import auth_server, common, constants, cros_logging, cros_ui, cryptohome
   8 import dns_server, login, ownership, pyauto_test
   9 from autotest_lib.client.bin import utils
  10 from autotest_lib.client.common_lib import error
  11
  12 class UITest(pyauto_test.PyAutoTest):
  13     """Base class for tests that drive some portion of the user interface.
  14
  15     By default subclasses will use the default remote credentials before
  16     the run_once method is invoked, and will log out at the completion
  17     of the test case even if an exception is thrown.
  18
  19     Subclasses can opt out of the automatic login by setting the member
  20     variable 'auto_login' to False.
  21
  22     Subclasses can log in with arbitrary credentials by passing
  23     the 'creds' parameter in their control file.  See the documentation of
  24     UITest.initialize for more details.
  25
  26     If your subclass overrides the initialize() or cleanup() methods, it
  27     should make sure to invoke this class' version of those methods as well.
  28     The standard super(...) function cannot be used for this, since the base
  29     test class is not a 'new style' Python class.
  30     """
  31     version = 1
  32
  33     skip_oobe = True
  34     auto_login = True
  35     fake_owner = True
  36     username = None
  37     password = None
  38
  39     # Processes that we know crash and are willing to ignore.
  40     crash_blacklist = []
  41
  42     # ftrace-related files.
  43     _ftrace_process_fork_event_enable_file = \
  44         '/sys/kernel/debug/tracing/events/sched/sched_process_fork/enable'
  45     _ftrace_process_fork_event_filter_file = \
  46         '/sys/kernel/debug/tracing/events/sched/sched_process_fork/filter'
  47     _ftrace_signal_generate_event_enable_file = \
  48         '/sys/kernel/debug/tracing/events/signal/signal_generate/enable'
  49     _ftrace_signal_generate_event_filter_file = \
  50         '/sys/kernel/debug/tracing/events/signal/signal_generate/filter'
  51     _ftrace_trace_file = '/sys/kernel/debug/tracing/trace'
  52
  53     _last_chrome_log = ''
  54
  55
  56     def start_authserver(self, authenticator=None):
  57         """Spin up a local mock of the Google Accounts server, then spin up
  58         a local fake DNS server and tell the networking stack to use it.  This
  59         will trick Chrome into talking to our mock when we login.
  60         Subclasses can override this method to change this behavior.
  61         """
  62         self._authServer = auth_server.GoogleAuthServer(
  63             authenticator=authenticator)
  64         self._authServer.run()
  65         self._dnsServer = dns_server.LocalDns()
  66         self._dnsServer.run()
  67
  68
  69     def stop_authserver(self):
  70         """Tears down fake dns and fake Google Accounts server.  If your
  71         subclass does not create these objects, you will want to override this
  72         method as well.
  73         """
  74         if hasattr(self, '_authServer'):
  75             self._authServer.stop()
  76             del self._authServer
  77         if hasattr(self, '_dnsServer'):
  78             try:
  79                 self._dnsServer.stop()
  80             except utils.TimeoutError as err:
  81                 raise error.TestWarn(err)
  82             del self._dnsServer
  83
  84
  85     def start_chrome_event_tracing(self):
  86         """Start tracing events of a chrome process being created or receiving a
  87         signal.
  88         """
  89         try:
  90             # Clear the trace buffer.
  91             utils.open_write_close(self._ftrace_trace_file, '')
  92
  93             # Trace only chrome process creation events, which we may later use
  94             # to determine if a chrome process is killed by its parent.
  95             utils.open_write_close(
  96                 self._ftrace_process_fork_event_filter_file,
  97                 'child_comm==chrome')
  98             # Trace only chrome processes receiving any signal except for
  99             # the uninteresting SIGPROF (sig 27 on x86 and arm).
 100             utils.open_write_close(
 101                 self._ftrace_signal_generate_event_filter_file,
 102                 'comm==chrome && sig!=27')
 103
 104             # Enable the process_fork event tracing.
 105             utils.open_write_close(
 106                 self._ftrace_process_fork_event_enable_file, '1')
 107             # Enable the signal_generate event tracing.
 108             utils.open_write_close(
 109                 self._ftrace_signal_generate_event_enable_file, '1')
 110         except IOError as err:
 111             logging.warning('Failed to start chrome signal tracing: %s', err)
 112
 113
 114     def stop_chrome_event_tracing(self):
 115         """Stop tracing events of a chrome process being created or receiving a
 116         signal.
 117         """
 118         try:
 119             # Disable the process_fork event tracing.
 120             utils.open_write_close(
 121                 self._ftrace_process_fork_event_enable_file, '0')
 122             # Disable the signal_generate event tracing.
 123             utils.open_write_close(
 124                 self._ftrace_signal_generate_event_enable_file, '0')
 125
 126             # Clear the process_fork event filter.
 127             utils.open_write_close(
 128                 self._ftrace_process_fork_event_filter_file, '0')
 129             # Clear the signal_generate event filter.
 130             utils.open_write_close(
 131                 self._ftrace_signal_generate_event_filter_file, '0')
 132
 133             # Dump the trace buffer to a log file.
 134             trace_file = os.path.join(self.resultsdir, 'chrome_event_trace')
 135             trace_data = utils.read_file(self._ftrace_trace_file)
 136             utils.open_write_close(trace_file, trace_data)
 137         except IOError as err:
 138             logging.warning('Failed to stop chrome signal tracing: %s', err)
 139
 140
 141     def start_tcpdump(self, iface):
 142         """Start tcpdump process, if not running already."""
 143         if not hasattr(self, '_tcpdump'):
 144             self._tcpdump = subprocess.Popen(
 145                 ['tcpdump', '-i', iface, '-vv'], stdout=subprocess.PIPE,
 146                 stderr=subprocess.STDOUT)
 147
 148
 149     def stop_tcpdump(self, fname_prefix):
 150         """Stop tcpdump process and save output to a new file."""
 151         if hasattr(self, '_tcpdump'):
 152             self._tcpdump.terminate()
 153             # Save output to a new file
 154             next_index = len(glob.glob(
 155                 os.path.join(self.resultsdir, '%s-*' % fname_prefix)))
 156             tcpdump_file = os.path.join(
 157                 self.resultsdir, '%s-%d' % (fname_prefix, next_index))
 158             logging.info('Saving tcpdump output to %s' % tcpdump_file)
 159             utils.open_write_close(tcpdump_file, self._tcpdump.communicate()[0])
 160             del self._tcpdump
 161
 162
 163     def __log_all_processes(self, fname_prefix):
 164         """Log all processes to a file.
 165
 166         Args:
 167             fname_prefix: Prefix of the log file.
 168         """
 169         try:
 170             next_index = len(glob.glob(
 171                 os.path.join(self.resultsdir, '%s-*' % fname_prefix)))
 172             log_file = os.path.join(
 173                 self.resultsdir, '%s-%d' % (fname_prefix, next_index))
 174             utils.open_write_close(log_file, utils.system_output('ps -eF'))
 175         except (error.CmdError, IOError, OSError) as err:
 176             logging.warning('Failed to log all processes: %s', err)
 177
 178
 179     def __perform_ui_diagnostics(self):
 180         """Save diagnostic logs about UI.
 181
 182         This includes the output of:
 183           $ initctl status ui
 184           $ ps auxwww
 185         """
 186         output_file = os.path.join(self.resultsdir, 'ui_diagnostics.txt')
 187         with open(output_file, 'w') as output_fd:
 188             print >> output_fd, time.asctime(), '\n'
 189             cmd = 'initctl status ui'
 190             print >> output_fd, '$ %s' % cmd
 191             print >> output_fd, utils.system_output(cmd), '\n'
 192             cmd = 'ps auxwww'
 193             print >> output_fd, '$ %s' % cmd
 194             print >> output_fd, utils.system_output(cmd), '\n'
 195         logging.info('Saved UI diagnostics to %s' % output_file)
 196
 197
 198     def __generate_coredumps(self, names):
 199         """Generate core dump files in results dir for given processes.
 200
 201         Note that the coredumps are forced via SIGBUS and the processes will be
 202         terminated. Ideally we should use gdb gcore to create dumps
 203         non-intrusively. However, the current dumps generated by gcore could not
 204         be properly read back by gdb, i.e. no reasonable symbolized stack could
 205         be generated.
 206
 207         Args:
 208             names: A list of process names that need to be dumped.
 209         """
 210
 211         # Get all pids of named processes.
 212         pids = []
 213         for name in names:
 214             # Get pids of given name, slice [1:] to skip ps's first line 'PID'
 215             pids = pids + [ pid.strip() for pid in utils.system_output(
 216                 'ps -C %s -o pid' % name).splitlines()[1:]]
 217         logging.info('Will force core dumps for the following pid: %s' %
 218             ' '.join(pids))
 219
 220         # Stop all processes so that forcing dump would change their state.
 221         for pid in pids:
 222             utils.system('kill -STOP %s' % pid)
 223
 224         # Force core dump.
 225         for pid in pids:
 226             utils.system('kill -BUS %s' % pid)
 227
 228         # Resume to let the core dump finish.
 229         for pid in reversed(pids):
 230             utils.system('kill -CONT %s' % pid)
 231
 232
 233     def initialize(self, creds=None, is_creating_owner=False,
 234                    extra_chrome_flags=[], subtract_extra_chrome_flags=[],
 235                    *args, **kwargs):
 236         """Overridden from test.initialize() to log out and (maybe) log in.
 237
 238         If self.auto_login is True, this will automatically log in using the
 239         credentials specified by 'creds' at startup, otherwise login will not
 240         happen.
 241
 242         Regardless of the state of self.auto_login, the self.username and
 243         self.password properties will be set to the credentials specified
 244         by 'creds'.
 245
 246         Authentication is not performed against live servers.  Instead, we spin
 247         up a local DNS server that will lie and say that all sites resolve to
 248         127.0.0.1.  The DNS server tells flimflam via DBus that it should be
 249         used to resolve addresses.  We then spin up a local httpd that will
 250         respond to queries at the Google Accounts endpoints.  We clear the DNS
 251         setting and tear down these servers in cleanup().
 252
 253         Args:
 254             creds: String specifying the credentials for this test case.  Can
 255                 be a named set of credentials as defined by
 256                 constants.CREDENTIALS, or a 'username:password' pair.
 257                 Defaults to None -- browse without signing-in.
 258             is_creating_owner: If the test case is creating a new device owner.
 259             extra_chrome_flags: Extra chrome flags to pass to chrome, if any.
 260             subtract_extra_chrome_flags: Remove default flags passed to chrome
 261                 by pyauto, if any.
 262         """
 263         # Mark /var/log/messages now; we'll run through all subsequent
 264         # log messages at the end of the test and log info about processes that
 265         # crashed.
 266         self._log_reader = cros_logging.LogReader()
 267         self._log_reader.set_start_by_current()
 268
 269         if creds:
 270             self.start_authserver()
 271
 272         # Run tcpdump on 'lo' interface to investigate network
 273         # issues in the lab during login.
 274         self.start_tcpdump(iface='lo')
 275
 276         # Log all processes so that we can correlate PIDs to processes in
 277         # the chrome signal trace.
 278         self.__log_all_processes('processes--before-tracing')
 279
 280         # Start event tracing related to chrome processes.
 281         self.start_chrome_event_tracing()
 282
 283         # We yearn for Chrome coredumps...
 284         open(constants.CHROME_CORE_MAGIC_FILE, 'w').close()
 285
 286         # The UI must be taken down to ensure that no stale state persists.
 287         cros_ui.stop()
 288         (self.username, self.password) = self.__resolve_creds(creds)
 289         # Ensure there's no stale cryptohome from previous tests.
 290         try:
 291             cryptohome.remove_all_vaults()
 292         except cryptohome.ChromiumOSError as err:
 293             logging.error(err)
 294
 295         # Fake ownership unless the test is explicitly testing owner creation.
 296         if not is_creating_owner:
 297             logging.info('Faking ownership...')
 298             ownership.fake_ownership()
 299             self.fake_owner = True
 300         else:
 301             logging.info('Erasing stale owner state.')
 302             ownership.clear_ownership_files()
 303             self.fake_owner = False
 304
 305         try:
 306             cros_ui.start()
 307         except:
 308             self.__perform_ui_diagnostics()
 309             if not login.wait_for_browser_exit('Chrome crashed during login'):
 310               self.__generate_coredumps([constants.BROWSER])
 311             raise
 312
 313         # Save name of the last chrome log before our test started.
 314         log_files = glob.glob(constants.CHROME_LOG_DIR + '/chrome_*')
 315         self._last_chrome_log = max(log_files) if log_files else ''
 316
 317         pyauto_test.PyAutoTest.initialize(
 318             self, auto_login=False,
 319             extra_chrome_flags=extra_chrome_flags,
 320             subtract_extra_chrome_flags=subtract_extra_chrome_flags,
 321             *args, **kwargs)
 322         if self.skip_oobe or self.auto_login:
 323             self.pyauto.SkipToLogin()
 324         if self.auto_login:
 325             self.login(self.username, self.password)
 326             if is_creating_owner:
 327                 login.wait_for_ownership()
 328
 329
 330     def __resolve_creds(self, creds):
 331         """Map credential identifier to username, password and type.
 332         Args:
 333           creds: credential identifier to resolve.
 334
 335         Returns:
 336           A (username, password) tuple.
 337         """
 338         if not creds:
 339             return [None, None]  # Browse without signing-in.
 340         if creds[0] == '$':
 341             if creds not in constants.CREDENTIALS:
 342                 raise error.TestFail('Unknown credentials: %s' % creds)
 343
 344             (name, passwd) = constants.CREDENTIALS[creds]
 345             return [cryptohome.canonicalize(name), passwd]
 346
 347         (name, passwd) = creds.split(':')
 348         return [cryptohome.canonicalize(name), passwd]
 349
 350
 351     def take_screenshot(self, fname_prefix, format='png'):
 352       """Take screenshot and save to a new file in the results dir.
 353
 354       Args:
 355         fname_prefix: prefix for the output fname
 356         format:       string indicating file format ('png', 'jpg', etc)
 357
 358       Returns:
 359         the path of the saved screenshot file
 360       """
 361       next_index = len(glob.glob(
 362           os.path.join(self.resultsdir, '%s-*.%s' % (fname_prefix, format))))
 363       screenshot_file = os.path.join(
 364           self.resultsdir, '%s-%d.%s' % (fname_prefix, next_index, format))
 365       logging.info('Saving screenshot to %s.' % screenshot_file)
 366
 367       old_exc_type = sys.exc_info()[0]
 368       try:
 369           utils.system('DISPLAY=:0.0 XAUTHORITY=/home/chronos/.Xauthority '
 370                        '/usr/local/bin/import -window root -depth 8 %s' %
 371                        screenshot_file)
 372       except Exception as err:
 373           # Do not raise an exception if the screenshot fails while processing
 374           # another exception.
 375           if old_exc_type is None:
 376               raise
 377           logging.error(err)
 378
 379       return screenshot_file
 380
 381
 382     def login(self, username=None, password=None):
 383         """Log in with a set of credentials.
 384
 385         This method is called from UITest.initialize(), so you won't need it
 386         unless your testcase has cause to log in multiple times.  This
 387         DOES NOT affect self.username or self.password.
 388
 389         If username and self.username are not defined, logs in as guest.
 390
 391         Forces a log out if already logged in.
 392         Blocks until login is complete.
 393
 394         Args:
 395             username: username to log in as, defaults to self.username.
 396             password: password to log in with, defaults to self.password.
 397
 398         Raises:
 399             error.TestError, if login has an error
 400         """
 401         if self.logged_in():
 402             self.logout()
 403
 404         uname = username or self.username
 405         passwd = password or self.password
 406
 407         try:
 408             screenshot_name = 'login-success-screenshot'
 409             if uname:  # Regular login
 410                 login_error = self.pyauto.Login(username=uname,
 411                                                 password=passwd)
 412                 if login_error:
 413                     screenshot_name = 'login-error-screenshot'
 414                     raise error.TestFail(
 415                         'Error during login (%s, %s): %s.  See the file named '
 416                         '%s.png in the results folder.' % (uname, passwd,
 417                         login_error, screenshot_name))
 418             else:  # Login as guest
 419                 self.pyauto.LoginAsGuest()
 420                 logging.info('Logged in as guest.')
 421             if not self.logged_in():
 422                 screenshot_name = 'login-bizarre-fail-screenshot'
 423                 raise error.TestFail('Login was successful, but logged_in() '
 424                                      'returned False. This should not happen. '
 425                                      'Please check the file named %s.png '
 426                                      'located in the results folder.' %
 427                                      screenshot_name)
 428         except Exception as err:
 429             if isinstance(err, error.AutotestError):
 430                 raise  # Do not modify our own errors.
 431
 432             screenshot_name = 'login-fail-screenshot'
 433             raise error.TestFail('Exception raised during login: %s. See the '
 434                                  'file named %s.png in the results folder.' %
 435                                  (err, screenshot_name))
 436         finally:
 437             self.take_screenshot(fname_prefix=screenshot_name)
 438             self.stop_tcpdump(fname_prefix='tcpdump-lo--till-login')
 439
 440         logging.info('Logged in as %s.  You can verify with the '
 441                      'file named %s.png located in the results '
 442                      'folder.' % (uname, screenshot_name))
 443
 444     def logged_in(self):
 445         return self.pyauto.GetLoginInfo()['is_logged_in']
 446
 447
 448     def logout(self):
 449         """Log out.
 450
 451         This method is called from UITest.cleanup(), so you won't need it
 452         unless your testcase needs to test functionality while logged out.
 453         """
 454         if not self.logged_in():
 455             return
 456         self._save_logs_from_cryptohome()
 457
 458         try:
 459             cros_ui.restart(self.pyauto.Logout)
 460         except:
 461             self.__perform_ui_diagnostics()
 462             if not login.wait_for_browser_exit('Chrome crashed during logout'):
 463               self.__generate_coredumps([constants.BROWSER])
 464             raise
 465
 466
 467     def _save_logs_from_cryptohome(self):
 468         """Recover dirs from cryptohome in case another test run wipes."""
 469         try:
 470             for dir in constants.CRYPTOHOME_DIRS_TO_RECOVER:
 471                 dir_path = os.path.join(constants.CRYPTOHOME_MOUNT_PT, dir)
 472                 if os.path.isdir(dir_path):
 473                     target = os.path.join(self.resultsdir,
 474                                           '%s-%f' % (dir, time.time()))
 475                     logging.debug('Saving %s to %s.', dir_path, target)
 476                     shutil.copytree(src=dir_path, dst=target, symlinks=True)
 477         except (IOError, OSError, shutil.Error) as err:
 478             logging.error(err)
 479
 480
 481     def validate_basic_policy(self, basic_policy):
 482         # Pull in protobuf definitions.
 483         sys.path.append(self.srcdir)
 484         from device_management_backend_pb2 import PolicyFetchResponse
 485         from device_management_backend_pb2 import PolicyData
 486         from chrome_device_policy_pb2 import ChromeDeviceSettingsProto
 487         from chrome_device_policy_pb2 import UserWhitelistProto
 488
 489         response_proto = PolicyFetchResponse()
 490         response_proto.ParseFromString(basic_policy)
 491         ownership.assert_has_policy_data(response_proto)
 492
 493         poldata = PolicyData()
 494         poldata.ParseFromString(response_proto.policy_data)
 495         ownership.assert_has_device_settings(poldata)
 496         ownership.assert_username(poldata, self.username)
 497
 498         polval = ChromeDeviceSettingsProto()
 499         polval.ParseFromString(poldata.policy_value)
 500         ownership.assert_new_users(polval, True)
 501         ownership.assert_users_on_whitelist(polval, (self.username,))
 502
 503
 504     def __log_crashed_processes(self, processes):
 505         """Runs through the log watched by |watcher| to see if a crash was
 506         reported for any process names not listed in |processes|. SIGABRT
 507         crashes in chrome or supplied-chrome during ui restart are ignored.
 508         """
 509         ui_restart_begin_regex = re.compile(cros_ui.UI_RESTART_ATTEMPT_MSG)
 510         crash_regex = re.compile(
 511             'Received crash notification for ([-\w]+).+ (sig \d+)')
 512         ui_restart_end_regex = re.compile(cros_ui.UI_RESTART_COMPLETE_MSG)
 513
 514         in_restart = False
 515         for line in self._log_reader.get_logs().splitlines():
 516             if ui_restart_begin_regex.search(line):
 517                 in_restart = True
 518             elif ui_restart_end_regex.search(line):
 519                 in_restart = False
 520             else:
 521                 match = crash_regex.search(line)
 522                 if (match and not match.group(1) in processes and
 523                     not (in_restart and
 524                          (match.group(1) == constants.BROWSER or
 525                           match.group(1) == 'supplied_chrome') and
 526                          match.group(2) == 'sig 6')):
 527                     self.job.record('INFO', self.tagged_testname,
 528                                     line[match.start():])
 529
 530
 531     def execute(self, iterations=None, test_length=None,
 532                 profile_only=None, _get_time=time.time,
 533                 postprocess_profiled_run=None, constraints=(), *args, **kwargs):
 534         """Wrapper around execute to take a screenshot for any exception."""
 535         try:
 536             super(UITest, self).execute(iterations=iterations,
 537                                         test_length=test_length,
 538                                         profile_only=profile_only,
 539                                         _get_time=_get_time,
 540                                         postprocess_profiled_run=
 541                                           postprocess_profiled_run,
 542                                         constraints=constraints,
 543                                         *args, **kwargs)
 544         except:
 545             self.take_screenshot(fname_prefix='test-fail-screenshot')
 546             raise
 547
 548
 549     def cleanup(self):
 550         """Overridden from pyauto_test.cleanup() to log out and restart
 551            session_manager when the test is complete.
 552         """
 553         try:
 554             # Save all chrome logs created during the test.
 555             try:
 556                 for fullpath in glob.glob(
 557                     constants.CHROME_LOG_DIR + '/chrome_*'):
 558                     if os.path.isfile(fullpath) and \
 559                         not os.path.islink(fullpath) and \
 560                         fullpath > self._last_chrome_log:  # ignore old logs
 561                         shutil.copy2(fullpath, self.resultsdir)
 562
 563             except (IOError, OSError) as err:
 564                 logging.error(err)
 565
 566             self._save_logs_from_cryptohome()
 567             pyauto_test.PyAutoTest.cleanup(self)
 568
 569             if os.path.isfile(constants.CRYPTOHOMED_LOG):
 570                 try:
 571                     base = os.path.basename(constants.CRYPTOHOMED_LOG)
 572                     shutil.copy(constants.CRYPTOHOMED_LOG,
 573                                 os.path.join(self.resultsdir, base))
 574                 except (IOError, OSError) as err:
 575                     logging.error(err)
 576
 577             if self.fake_owner:
 578                 logging.info('Erasing fake owner state.')
 579                 ownership.clear_ownership_files()
 580
 581             self.__log_crashed_processes(self.crash_blacklist)
 582
 583             if os.path.isfile(constants.CHROME_CORE_MAGIC_FILE):
 584                 os.unlink(constants.CHROME_CORE_MAGIC_FILE)
 585         finally:
 586             self.stop_chrome_event_tracing()
 587             self.__log_all_processes('processes--after-tracing')
 588             self.stop_tcpdump(fname_prefix='tcpdump-lo--till-end')
 589             self.stop_authserver()
 590
 591
 592     def get_auth_endpoint_misses(self):
 593         if hasattr(self, '_authServer'):
 594             return self._authServer.get_endpoint_misses()
 595         else:
 596             return {}