1#!/usr/bin/python 2# 3# Copyright (c) 2012 The Chromium OS Authors. All rights reserved. 4# Use of this source code is governed by a BSD-style license that can be 5# found in the LICENSE file. 6 7 8"""Tool for running suites of tests and waiting for completion. 9 10The desired test suite will be scheduled with autotest. By default, 11this tool will block until the job is complete, printing a summary 12at the end. Error conditions result in exceptions. 13 14This is intended for use only with Chrome OS test suits that leverage the 15dynamic suite infrastructure in server/cros/dynamic_suite.py. 16 17This script exits with one of the following codes: 180 - OK: Suite finished successfully 191 - ERROR: Test(s) failed, or hits its own timeout 202 - WARNING: Test(s) raised a warning or passed on retry, none failed/timed out. 213 - INFRA_FAILURE: Infrastructure related issues, e.g. 22 * Lab is down 23 * Too many duts (defined as a constant) in repair failed status 24 * Suite job issues, like bug in dynamic suite, 25 user aborted the suite, lose a drone/all devservers/rpc server, 26 0 tests ran, etc. 27 * provision failed 28 TODO(fdeng): crbug.com/413918, reexamine treating all provision 29 failures as INFRA failures. 304 - SUITE_TIMEOUT: Suite timed out, some tests ran, 31 none failed by the time the suite job was aborted. This will cover, 32 but not limited to, the following cases: 33 * A devserver failure that manifests as a timeout 34 * No DUTs available midway through a suite 35 * Provision/Reset/Cleanup took longer time than expected for new image 36 * A regression in scheduler tick time. 375- BOARD_NOT_AVAILABLE: If there is no host for the requested board/pool. 386- INVALID_OPTIONS: If options are not valid. 39""" 40 41import argparse 42import ast 43from collections import namedtuple 44from datetime import datetime 45from datetime import timedelta 46import getpass 47import json 48import logging 49import os 50import re 51import sys 52import time 53 54import common 55from chromite.lib import buildbot_annotations as annotations 56 57from autotest_lib.client.common_lib import control_data 58from autotest_lib.client.common_lib import error 59from autotest_lib.client.common_lib import global_config, enum 60from autotest_lib.client.common_lib import priorities 61from autotest_lib.client.common_lib import time_utils 62from autotest_lib.client.common_lib.cros import retry 63from autotest_lib.frontend.afe.json_rpc import proxy 64from autotest_lib.server import site_utils 65from autotest_lib.server import utils 66from autotest_lib.server.cros import provision 67from autotest_lib.server.cros.dynamic_suite import constants 68from autotest_lib.server.cros.dynamic_suite import frontend_wrappers 69from autotest_lib.server.cros.dynamic_suite import reporting 70from autotest_lib.server.cros.dynamic_suite import reporting_utils 71from autotest_lib.server.cros.dynamic_suite import tools 72from autotest_lib.site_utils import diagnosis_utils 73from autotest_lib.site_utils import job_overhead 74 75CONFIG = global_config.global_config 76 77_DEFAULT_AUTOTEST_INSTANCE = CONFIG.get_config_value( 78 'SERVER', 'hostname', type=str) 79_URL_PATTERN = CONFIG.get_config_value('CROS', 'log_url_pattern', type=str) 80 81# Return code that will be sent back to autotest_rpc_server.py 82RETURN_CODES = enum.Enum( 83 'OK', 'ERROR', 'WARNING', 'INFRA_FAILURE', 'SUITE_TIMEOUT', 84 'BOARD_NOT_AVAILABLE', 'INVALID_OPTIONS') 85# The severity of return code. If multiple codes 86# apply, the script should always return the severest one. 87# E.g. if we have a test failure and the suite also timed out, 88# we should return 'ERROR'. 89SEVERITY = {RETURN_CODES.OK: 0, 90 RETURN_CODES.WARNING: 1, 91 RETURN_CODES.SUITE_TIMEOUT: 2, 92 RETURN_CODES.INFRA_FAILURE: 3, 93 RETURN_CODES.ERROR: 4} 94 95# Minimum RPC timeout setting for calls expected to take long time, e.g., 96# create_suite_job. If default socket time (socket.getdefaulttimeout()) is 97# None or greater than this value, the default will be used. 98# The value here is set to be the same as the timeout for the RetryingAFE object 99# so long running RPCs can wait long enough before being aborted. 100_MIN_RPC_TIMEOUT = 600 101 102# Number of days back to search for existing job. 103_SEARCH_JOB_MAX_DAYS = 14 104 105 106def get_worse_code(code1, code2): 107 """Compare the severity of two codes and return the worse code. 108 109 @param code1: An enum value of RETURN_CODES 110 @param code2: An enum value of RETURN_CODES 111 112 @returns: the more severe one between code1 and code2. 113 114 """ 115 return code1 if SEVERITY[code1] >= SEVERITY[code2] else code2 116 117 118def bool_str(x): 119 """Boolean string type for option arguments. 120 121 @param x: string representation of boolean value. 122 123 """ 124 if x == 'True': 125 return True 126 elif x == 'False': 127 return False 128 else: 129 raise argparse.ArgumentTypeError( 130 '%s is not one of True or False' % (x,)) 131 132 133def _get_priority_value(x): 134 """Convert a priority representation to its int value. 135 136 Priorities can be described either by an int value (possibly as a string) 137 or a name string. This function coerces both forms to an int value. 138 139 This function is intended for casting command line arguments during 140 parsing. 141 142 @param x: priority value as an int, int string, or name string 143 144 @returns: int value of priority 145 """ 146 try: 147 return int(x) 148 except ValueError: 149 try: 150 return priorities.Priority.get_value(x) 151 except AttributeError: 152 raise argparse.ArgumentTypeError( 153 'Unknown priority level %s. Try one of %s.' 154 % (x, ', '.join(priorities.Priority.names))) 155 156 157def make_parser(): 158 """Make ArgumentParser instance for run_suite.py.""" 159 parser = argparse.ArgumentParser( 160 usage="%(prog)s [options]") 161 parser.add_argument("-b", "--board", dest="board") 162 parser.add_argument("-i", "--build", dest="build") 163 parser.add_argument( 164 "-w", "--web", dest="web", default=None, 165 help="Address of a webserver to receive suite requests.") 166 parser.add_argument( 167 '--firmware_rw_build', dest='firmware_rw_build', default=None, 168 help='Firmware build to be installed in dut RW firmware.') 169 parser.add_argument( 170 '--firmware_ro_build', dest='firmware_ro_build', default=None, 171 help='Firmware build to be installed in dut RO firmware.') 172 parser.add_argument( 173 '--test_source_build', dest='test_source_build', default=None, 174 help=('Build that contains the test code, ' 175 'e.g., it can be the value of `--build`, ' 176 '`--firmware_rw_build` or `--firmware_ro_build` ' 177 'arguments. Default is None, that is, use the test ' 178 'code from `--build` (CrOS image)')) 179 # This should just be a boolean flag, but the autotest "proxy" code 180 # can't handle flags that don't take arguments. 181 parser.add_argument( 182 "-n", "--no_wait", dest="no_wait", default=False, type=bool_str, 183 help='Must pass "True" or "False" if used.') 184 # If you really want no pool, --pool="" will do it. USE WITH CARE. 185 parser.add_argument("-p", "--pool", dest="pool", default="suites") 186 parser.add_argument("-s", "--suite_name", dest="name") 187 parser.add_argument("-a", "--afe_timeout_mins", type=int, 188 dest="afe_timeout_mins", default=30) 189 parser.add_argument("-t", "--timeout_mins", type=int, 190 dest="timeout_mins", default=1440) 191 parser.add_argument("-x", "--max_runtime_mins", type=int, 192 dest="max_runtime_mins", default=1440) 193 parser.add_argument("-d", "--delay_sec", type=int, 194 dest="delay_sec", default=10) 195 parser.add_argument("-m", "--mock_job_id", dest="mock_job_id", 196 help="Attach to existing job id for already running " 197 "suite, and creates report.") 198 # NOTE(akeshet): This looks similar to --no_wait, but behaves differently. 199 # --no_wait is passed in to the suite rpc itself and affects the suite, 200 # while this does not. 201 parser.add_argument("-c", "--create_and_return", dest="create_and_return", 202 action="store_true", 203 help="Create the suite and print the job id, then " 204 "finish immediately.") 205 parser.add_argument("-u", "--num", dest="num", type=int, default=None, 206 help="Run on at most NUM machines.") 207 # Same boolean flag issue applies here. 208 parser.add_argument( 209 "-f", "--file_bugs", dest="file_bugs", default=False, type=bool_str, 210 help=('File bugs on test failures. Must pass "True" or ' 211 '"False" if used.')) 212 parser.add_argument("-l", "--bypass_labstatus", dest="bypass_labstatus", 213 action="store_true", help='Bypass lab status check.') 214 # We allow either a number or a string for the priority. This way, if you 215 # know what you're doing, one can specify a custom priority level between 216 # other levels. 217 parser.add_argument("-r", "--priority", dest="priority", 218 type=_get_priority_value, 219 default=priorities.Priority.DEFAULT, 220 action="store", 221 help="Priority of suite. Either numerical value, or " 222 "one of (" + ", ".join(priorities.Priority.names) 223 + ").") 224 parser.add_argument( 225 '--retry', dest='retry', default=False, type=bool_str, action='store', 226 help='Enable test retry. Must pass "True" or "False" if used.') 227 parser.add_argument('--max_retries', dest='max_retries', default=None, 228 type=int, action='store', help='Maximum retries' 229 'allowed at suite level. No limit if not specified.') 230 parser.add_argument('--minimum_duts', dest='minimum_duts', type=int, 231 default=0, action='store', 232 help='Check that the pool has at least such many ' 233 'healthy machines, otherwise suite will not run. ' 234 'Default to 0.') 235 parser.add_argument('--suite_min_duts', dest='suite_min_duts', type=int, 236 default=0, action='store', 237 help='Preferred minimum number of machines. Scheduler ' 238 'will prioritize on getting such many machines for ' 239 'the suite when it is competing with another suite ' 240 'that has a higher priority but already got minimum ' 241 'machines it needs. Default to 0.') 242 parser.add_argument("--suite_args", dest="suite_args", 243 default=None, action="store", 244 help="Argument string for suite control file.") 245 parser.add_argument('--offload_failures_only', 246 dest='offload_failures_only', type=bool_str, 247 action='store', default=False, 248 help='Only enable gs_offloading for failed tests. ' 249 'Successful tests will be deleted. Must pass "True"' 250 ' or "False" if used.') 251 parser.add_argument('--use_suite_attr', dest='use_suite_attr', 252 action='store_true', default=False, 253 help='Advanced. Run the suite based on ATTRIBUTES of ' 254 'control files, rather than SUITE.') 255 parser.add_argument('--json_dump', dest='json_dump', action='store_true', 256 default=False, 257 help='Dump the output of run_suite to stdout.') 258 parser.add_argument( 259 '--run_prod_code', dest='run_prod_code', 260 action='store_true', default=False, 261 help='Run the test code that lives in prod aka the test ' 262 'code currently on the lab servers.') 263 parser.add_argument( 264 '--delay_minutes', type=int, default=0, 265 help=('Delay the creation of test jobs for a given ' 266 'number of minutes. This argument can be used to ' 267 'force provision jobs being delayed, which helps ' 268 'to distribute loads across devservers.')) 269 parser.add_argument( 270 '--skip_duts_check', dest='skip_duts_check', action='store_true', 271 default=False, help='If True, skip minimum available DUTs check') 272 parser.add_argument( 273 '--job_keyvals', dest='job_keyvals', type=ast.literal_eval, 274 action='store', default=None, 275 help='A dict of job keyvals to be inject to suite control file') 276 parser.add_argument( 277 '--test_args', dest='test_args', type=ast.literal_eval, 278 action='store', default=None, 279 help=('A dict of args passed all the way to each individual test that ' 280 'will be actually ran.')) 281 parser.add_argument( 282 '--require_logfile', action='store_true', 283 help=('Stream logs of run_suite.py to a local file named ' 284 'run_suite-<build name>.log.')) 285 286 # Used for monitoring purposes, to measure no-op swarming proxy latency. 287 parser.add_argument('--do_nothing', action='store_true', 288 help=argparse.SUPPRESS) 289 290 # Used when lab/job status checking is needed. Currently its only user is 291 # suite scheduler v2. 292 parser.add_argument( 293 '--pre_check', action='store_true', 294 help=('Check lab and job status before kicking off a suite. Used by ' 295 'suite scheduler v2.')) 296 297 return parser 298 299 300def verify_and_clean_options(options): 301 """Verify the validity of options. 302 303 @param options: The parsed options to verify. 304 305 @returns: True if verification passes, False otherwise. 306 307 """ 308 if options.mock_job_id and ( 309 not options.build or not options.name or not options.board): 310 print ('When using -m, need to specify build, board and suite ' 311 'name which you have used for creating the original job') 312 return False 313 else: 314 if not options.build: 315 print 'Need to specify which build to use' 316 return False 317 if not options.board: 318 print 'Need to specify board' 319 return False 320 if not options.name: 321 print 'Need to specify suite name' 322 return False 323 if options.num is not None and options.num < 1: 324 print 'Number of machines must be more than 0, if specified.' 325 return False 326 if not options.retry and options.max_retries is not None: 327 print 'max_retries can only be used with --retry=True' 328 return False 329 if options.use_suite_attr and options.suite_args is not None: 330 print ('The new suite control file cannot parse the suite_args: %s.' 331 'Please not specify any suite_args here.' % options.suite_args) 332 return False 333 if options.no_wait and options.retry: 334 print 'Test retry is not available when using --no_wait=True' 335 # Default to use the test code in CrOS build. 336 if not options.test_source_build and options.build: 337 options.test_source_build = options.build 338 return True 339 340 341def change_options_for_suite_attr(options): 342 """Change options to be prepared to run the suite_attr_wrapper. 343 344 If specify 'use_suite_attr' from the cmd line, it indicates to run the 345 new style suite control file, suite_attr_wrapper. Then, change the 346 options.name to 'suite_attr_wrapper', change the options.suite_args to 347 include the arguments needed by suite_attr_wrapper. 348 349 @param options: The verified options. 350 351 @returns: The changed options. 352 353 """ 354 # Convert the suite_name to attribute boolean expression. 355 if type(options.name) is str: 356 attr_filter_val = 'suite:%s' % options.name 357 else: 358 attr_filter_val = ' or '.join(['suite:%s' % x for x in options.name]) 359 360 # change the suite_args to be a dict of arguments for suite_attr_wrapper 361 # if suite_args is not None, store the values in 'other_args' of the dict 362 args_dict = {} 363 args_dict['attr_filter'] = attr_filter_val 364 options.suite_args = str(args_dict) 365 options.name = 'suite_attr_wrapper' 366 367 return options 368 369 370class TestResult(object): 371 372 """Represents the result of a TestView.""" 373 374 def __init__(self, test_view, retry_count=0): 375 """Initialize instance. 376 377 @param test_view: TestView instance. 378 @param retry_count: Retry count for test. Optional. 379 """ 380 self.name = test_view.get_testname() 381 self.status = test_view['status'] 382 self.reason = test_view['reason'] 383 self.retry_count = retry_count 384 385 _PRETTY_STATUS_MAP = { 386 'GOOD': '[ PASSED ]', 387 'TEST_NA': '[ INFO ]', 388 } 389 390 @property 391 def _pretty_status(self): 392 """Pretty status string.""" 393 return self._PRETTY_STATUS_MAP.get(self.status, '[ FAILED ]') 394 395 def log_using(self, log_function, name_column_width): 396 """Log the test result using the given log function. 397 398 @param log_function: Log function to use. Example: logging.info 399 @param name_column_width: Width of name column for formatting. 400 """ 401 padded_name = self.name.ljust(name_column_width) 402 log_function('%s%s', padded_name, self._pretty_status) 403 if self.status != 'GOOD': 404 log_function('%s %s: %s', padded_name, self.status, self.reason) 405 if self.retry_count > 0: 406 log_function('%s retry_count: %s', padded_name, self.retry_count) 407 408 409def get_original_suite_name(suite_name, suite_args): 410 """Get the original suite name when running suite_attr_wrapper. 411 412 @param suite_name: the name of the suite launched in afe. When it is 413 suite_attr_wrapper, the suite that actually running is 414 specified in the suite_args. 415 @param suite_args: the parsed option which contains the original suite name. 416 417 @returns: the original suite name. 418 419 """ 420 if suite_name == 'suite_attr_wrapper': 421 attrs = ast.literal_eval(suite_args).get('attr_filter', '') 422 suite_list = ([x[6:] for x in re.split('[() ]', attrs) 423 if x and x.startswith('suite:')]) 424 return suite_list[0] if suite_list else suite_name 425 return suite_name 426 427 428class LogLink(object): 429 """Information needed to record a link in the logs. 430 431 Depending on context and the information provided at 432 construction time, the link may point to either to log files for 433 a job, or to a bug filed for a failure in the job. 434 435 @var anchor The link text. 436 @var url The link url. 437 @var bug_id Id of a bug to link to, or None. 438 """ 439 440 # A list of tests that don't get retried so skip the dashboard. 441 _SKIP_RETRY_DASHBOARD = ['provision'] 442 443 _BUG_LINK_PREFIX = 'Auto-Bug' 444 _LOG_LINK_PREFIX = 'Test-Logs' 445 446 447 def __init__(self, anchor, server, job_string, bug_info=None, reason=None, 448 retry_count=0, testname=None): 449 """Initialize the LogLink by generating the log URL. 450 451 @param anchor The link text. 452 @param server The hostname of the server this suite ran on. 453 @param job_string The job whose logs we'd like to link to. 454 @param bug_info Info about the bug, if one was filed. 455 @param reason A string representing the reason of failure if any. 456 @param retry_count How many times the test has been retried. 457 @param testname Optional Arg that supplies the testname. 458 """ 459 self.anchor = anchor 460 self.url = _URL_PATTERN % (server, job_string) 461 self.reason = reason 462 self.retry_count = retry_count 463 self.testname = testname 464 if bug_info: 465 self.bug_id, self.bug_count = bug_info 466 else: 467 self.bug_id = None 468 self.bug_count = None 469 470 471 @property 472 def bug_url(self): 473 """URL of associated bug.""" 474 if self.bug_id: 475 return reporting_utils.link_crbug(self.bug_id) 476 else: 477 return None 478 479 480 @property 481 def _bug_count_text(self): 482 """Return bug count as human friendly text.""" 483 if self.bug_count is None: 484 bug_info = 'unknown number of reports' 485 elif self.bug_count == 1: 486 bug_info = 'new report' 487 else: 488 bug_info = '%s reports' % self.bug_count 489 return bug_info 490 491 492 def GenerateBuildbotLinks(self): 493 """Generate a link formatted to meet buildbot expectations. 494 495 If there is a bug associated with this link, report a link to the bug 496 and a link to the job logs; otherwise report a link to the job logs. 497 498 @return A generator of links formatted for the buildbot log annotator. 499 """ 500 if self.bug_url: 501 yield self._get_link_to_bug() 502 yield self._get_link_to_job_logs() 503 504 505 def _get_link_to_bug(self): 506 """Return buildbot link to bug. 507 508 @return A link formatted for the buildbot log annotator. 509 """ 510 info_strings = self._get_info_strings() 511 info_strings.append(self._bug_count_text) 512 anchor_text = self._format_anchor_text(self._BUG_LINK_PREFIX, 513 info_strings) 514 return annotations.StepLink(anchor_text, self.bug_url) 515 516 517 def _get_link_to_job_logs(self): 518 """Return buildbot link to job logs. 519 520 @return A link formatted for the buildbot log annotator. 521 """ 522 anchor_text = self._format_anchor_text(self._LOG_LINK_PREFIX, 523 self._get_info_strings()) 524 return annotations.StepLink(anchor_text, self.url) 525 526 527 def _get_info_strings(self): 528 """Return a list of info strings for _format_anchor_text().""" 529 info_strings = [] 530 if self.retry_count > 0: 531 info_strings.append('retry_count: %d' % self.retry_count) 532 if self.reason: 533 info_strings.append(self.reason) 534 return info_strings 535 536 537 def _format_anchor_text(self, prefix, info_strings): 538 """Format anchor text given a prefix and info strings. 539 540 @param prefix The prefix of the anchor text. 541 @param info_strings Iterable of strings. 542 @return A anchor_text with the right prefix and info strings. 543 """ 544 return '[{prefix}]: {anchor}: {info}'.format( 545 prefix=prefix, 546 anchor=self.anchor.strip(), 547 info=', '.join(info_strings)) 548 549 @property 550 def text_link(self): 551 """Link to the job's logs, for consumption by a human. 552 553 @return A link formatted for human readability. 554 """ 555 return '%s %s' % (self.anchor, self.url) 556 557 def GenerateWmatrixRetryLink(self): 558 """Generate a link to the wmatrix retry dashboard. 559 560 @return A link formatted for the buildbot log annotator. 561 """ 562 if not self.testname or self.testname in self._SKIP_RETRY_DASHBOARD: 563 return None 564 return annotations.StepLink( 565 text='[Flake-Dashboard]: %s' % self.testname, 566 url=reporting_utils.link_retry_url(self.testname)) 567 568 def GenerateWmatrixHistoryLink(self): 569 """Generate a link to the wmatrix test history dashboard. 570 571 @return A link formatted for the buildbot log annotator. 572 """ 573 if not self.testname or self.testname in self._SKIP_RETRY_DASHBOARD: 574 return None 575 return annotations.StepLink( 576 text='[Test-History]: %s' % self.testname, 577 url=reporting_utils.link_test_history(self.testname)) 578 579 580class Timings(object): 581 """Timings for important events during a suite. 582 583 All timestamps are datetime.datetime objects. 584 585 @var suite_job_id: the afe job id of the suite job for which 586 we are recording the timing for. 587 @var download_start_time: the time the devserver starts staging 588 the build artifacts. Recorded in create_suite_job. 589 @var payload_end_time: the time when the artifacts only necessary to start 590 installsing images onto DUT's are staged. 591 Recorded in create_suite_job. 592 @var artifact_end_time: the remaining artifacts are downloaded after we kick 593 off the reimaging job, at which point we record 594 artifact_end_time. Recorded in dynamic_suite.py. 595 @var suite_start_time: the time the suite started. 596 @var tests_start_time: the time the first test started running. 597 @var tests_end_time: the time the last test finished running. 598 """ 599 600 def __init__(self, suite_job_id): 601 self.suite_job_id = suite_job_id 602 # Timings related to staging artifacts on devserver. 603 self.download_start_time = None 604 self.payload_end_time = None 605 self.artifact_end_time = None 606 607 # The test_start_time, but taken off the view that corresponds to the 608 # suite instead of an individual test. 609 self.suite_start_time = None 610 611 # Earliest and Latest tests in the set of TestViews passed to us. 612 self.tests_start_time = None 613 self.tests_end_time = None 614 615 616 def RecordTiming(self, view): 617 """Given a test report view, extract and record pertinent time info. 618 619 get_detailed_test_views() returns a list of entries that provide 620 info about the various parts of a suite run. This method can take 621 any one of these entries and look up timestamp info we might want 622 and record it. 623 624 If timestamps are unavailable, datetime.datetime.min/max will be used. 625 626 @param view: A TestView object. 627 """ 628 start_candidate = datetime.min 629 end_candidate = datetime.max 630 if view['test_started_time']: 631 start_candidate = time_utils.time_string_to_datetime( 632 view['test_started_time']) 633 if view['test_finished_time']: 634 end_candidate = time_utils.time_string_to_datetime( 635 view['test_finished_time']) 636 637 if view.get_testname() == TestView.SUITE_JOB: 638 self.suite_start_time = start_candidate 639 else: 640 self._UpdateFirstTestStartTime(start_candidate) 641 self._UpdateLastTestEndTime(end_candidate) 642 if view['afe_job_id'] == self.suite_job_id and 'job_keyvals' in view: 643 keyvals = view['job_keyvals'] 644 self.download_start_time = time_utils.time_string_to_datetime( 645 keyvals.get(constants.DOWNLOAD_STARTED_TIME), 646 handle_type_error=True) 647 648 self.payload_end_time = time_utils.time_string_to_datetime( 649 keyvals.get(constants.PAYLOAD_FINISHED_TIME), 650 handle_type_error=True) 651 652 self.artifact_end_time = time_utils.time_string_to_datetime( 653 keyvals.get(constants.ARTIFACT_FINISHED_TIME), 654 handle_type_error=True) 655 656 657 def _UpdateFirstTestStartTime(self, candidate): 658 """Update self.tests_start_time, iff candidate is an earlier time. 659 660 @param candidate: a datetime.datetime object. 661 """ 662 if not self.tests_start_time or candidate < self.tests_start_time: 663 self.tests_start_time = candidate 664 665 666 def _UpdateLastTestEndTime(self, candidate): 667 """Update self.tests_end_time, iff candidate is a later time. 668 669 @param candidate: a datetime.datetime object. 670 """ 671 if not self.tests_end_time or candidate > self.tests_end_time: 672 self.tests_end_time = candidate 673 674 675 def __str__(self): 676 return ('\n' 677 'Suite timings:\n' 678 'Downloads started at %s\n' 679 'Payload downloads ended at %s\n' 680 'Suite started at %s\n' 681 'Artifact downloads ended (at latest) at %s\n' 682 'Testing started at %s\n' 683 'Testing ended at %s\n' % (self.download_start_time, 684 self.payload_end_time, 685 self.suite_start_time, 686 self.artifact_end_time, 687 self.tests_start_time, 688 self.tests_end_time)) 689 690 691def instance_for_pool(pool_name): 692 """ 693 Return the hostname of the server that should be used to service a suite 694 for the specified pool. 695 696 @param pool_name: The pool (without 'pool:' to schedule the suite against. 697 @return: The correct host that should be used to service this suite run. 698 """ 699 return CONFIG.get_config_value( 700 'POOL_INSTANCE_SHARDING', pool_name, 701 default=_DEFAULT_AUTOTEST_INSTANCE) 702 703 704class TestView(object): 705 """Represents a test view and provides a set of helper functions.""" 706 707 708 SUITE_JOB = 'Suite job' 709 INFRA_TESTS = ['provision'] 710 711 712 def __init__(self, view, afe_job, suite_name, build, user, 713 solo_test_run=False): 714 """Init a TestView object representing a tko test view. 715 716 @param view: A dictionary representing a tko test view. 717 @param afe_job: An instance of frontend.afe.models.Job 718 representing the job that kicked off the test. 719 @param suite_name: The name of the suite 720 that the test belongs to. 721 @param build: The build for which the test is run. 722 @param user: The user for which the test is run. 723 @param solo_test_run: This is a solo test run not part of a suite. 724 """ 725 self.view = view 726 self.afe_job = afe_job 727 self.suite_name = suite_name 728 self.build = build 729 self.is_suite_view = afe_job.parent_job is None and not solo_test_run 730 # This is the test name that will be shown in the output. 731 self.testname = None 732 self.user = user 733 734 # The case that a job was aborted before it got a chance to run 735 # usually indicates suite has timed out (unless aborted by user). 736 # In this case, the abort reason will be None. 737 # Update the reason with proper information. 738 if (self.is_relevant_suite_view() and 739 not self.get_testname() == self.SUITE_JOB and 740 self.view['status'] == 'ABORT' and 741 not self.view['reason']): 742 self.view['reason'] = 'Timed out, did not run.' 743 744 745 def __getitem__(self, key): 746 """Overload __getitem__ so that we can still use [] 747 748 @param key: A key of the tko test view. 749 750 @returns: The value of an attribute in the view. 751 752 """ 753 return self.view[key] 754 755 756 def __iter__(self): 757 """Overload __iter__ so that it supports 'in' operator.""" 758 return iter(self.view) 759 760 761 def get_testname(self): 762 """Get test name that should be shown in the output. 763 764 Formalize the test_name we got from the test view. 765 766 Remove 'build/suite' prefix if any. 767 768 If one runs a test in control file via the following code, 769 job.runtest('my_Test', tag='tag') 770 for most of the cases, view['test_name'] would look like 'my_Test.tag'. 771 If this is the case, this method will just return the original 772 test name, i.e. 'my_Test.tag'. 773 774 There are four special cases. 775 1) A test view is for the suite job's SERVER_JOB. 776 In this case, this method will return 'Suite job'. 777 778 2) A test view is of a child job or a solo test run not part of a 779 suite, and for a SERVER_JOB or CLIENT_JOB. 780 In this case, we will take the job name, remove the build/suite 781 prefix from the job name, and append the rest to 'SERVER_JOB' 782 or 'CLIENT_JOB' as a prefix. So the names returned by this 783 method will look like: 784 'Telemetry Smoothness Measurement_SERVER_JOB' 785 'dummy_Pass_SERVER_JOB' 786 'dummy_Fail_SERVER_JOB' 787 788 3) A test view is of a suite job and its status is ABORT. 789 In this case, the view['test_name'] is the child job's name. 790 For instance, 791 'lumpy-release/R35-5712.0.0/perf_v2/ 792 Telemetry Smoothness Measurement' 793 'lumpy-release/R35-5712.0.0/dummy/dummy_Pass' 794 'lumpy-release/R35-5712.0.0/dummy/dummy_Fail' 795 The above names will be converted to the following: 796 'Telemetry Smoothness Measurement' 797 'dummy_Pass' 798 'dummy_Fail' 799 800 4) A test view's status is of a suite job and its status is TEST_NA. 801 In this case, the view['test_name'] is the NAME field of the control 802 file. For instance, 803 'Telemetry Smoothness Measurement' 804 'dummy_Pass' 805 'dummy_Fail' 806 This method will not modify these names. 807 808 @returns: Test name after normalization. 809 810 """ 811 if self.testname is not None: 812 return self.testname 813 814 if (self.is_suite_view and 815 self.view['test_name'].startswith('SERVER_JOB')): 816 # Rename suite job's SERVER_JOB to 'Suite job'. 817 self.testname = self.SUITE_JOB 818 return self.testname 819 820 if (self.view['test_name'].startswith('SERVER_JOB') or 821 self.view['test_name'].startswith('CLIENT_JOB')): 822 # Append job name as a prefix for SERVER_JOB and CLIENT_JOB 823 testname= '%s_%s' % (self.view['job_name'], self.view['test_name']) 824 else: 825 testname = self.view['test_name'] 826 # Remove the build and suite name from testname if any. 827 self.testname = tools.get_test_name( 828 self.build, self.suite_name, testname) 829 return self.testname 830 831 832 def is_relevant_suite_view(self): 833 """Checks whether this is a suite view we should care about. 834 835 @returns: True if it is relevant. False otherwise. 836 """ 837 return (self.get_testname() == self.SUITE_JOB or 838 (self.is_suite_view and 839 not self.view['test_name'].startswith('CLIENT_JOB') and 840 not self.view['subdir'])) 841 842 843 def is_test(self): 844 """Return whether the view is for an actual test. 845 846 @returns True if the view is for an actual test. 847 False if the view is for SERVER_JOB or CLIENT_JOB. 848 849 """ 850 return not (self.view['test_name'].startswith('SERVER_JOB') or 851 self.view['test_name'].startswith('CLIENT_JOB')) 852 853 854 def is_retry(self): 855 """Check whether the view is for a retry. 856 857 @returns: True, if the view is for a retry; False otherwise. 858 859 """ 860 return self.view['job_keyvals'].get('retry_original_job_id') is not None 861 862 863 def hit_timeout(self): 864 """Check whether the corresponding job has hit its own timeout. 865 866 Note this method should not be called for those test views 867 that belongs to a suite job and are determined as irrelevant 868 by is_relevant_suite_view. This is because they are associated 869 to the suite job, whose job start/finished time make no sense 870 to an irrelevant test view. 871 872 @returns: True if the corresponding afe job has hit timeout. 873 False otherwise. 874 """ 875 if (self.is_relevant_suite_view() and 876 self.get_testname() != self.SUITE_JOB): 877 # Any relevant suite test view except SUITE_JOB 878 # did not hit its own timeout because it was not ever run. 879 return False 880 start = (datetime.strptime( 881 self.view['job_started_time'], time_utils.TIME_FMT) 882 if self.view['job_started_time'] else None) 883 end = (datetime.strptime( 884 self.view['job_finished_time'], time_utils.TIME_FMT) 885 if self.view['job_finished_time'] else None) 886 if not start or not end: 887 return False 888 else: 889 return ((end - start).total_seconds()/60.0 890 > self.afe_job.max_runtime_mins) 891 892 893 def is_aborted(self): 894 """Check if the view was aborted. 895 896 For suite job and child job test views, we check job keyval 897 'aborted_by' and test status. 898 899 For relevant suite job test views, we only check test status 900 because the suite job keyval won't make sense to individual 901 test views. 902 903 @returns: True if the test was as aborted, False otherwise. 904 905 """ 906 907 if (self.is_relevant_suite_view() and 908 self.get_testname() != self.SUITE_JOB): 909 return self.view['status'] == 'ABORT' 910 else: 911 return (bool(self.view['job_keyvals'].get('aborted_by')) and 912 self.view['status'] in ['ABORT', 'RUNNING']) 913 914 915 def is_in_fail_status(self): 916 """Check if the given test's status corresponds to a failure. 917 918 @returns: True if the test's status is FAIL or ERROR. False otherwise. 919 920 """ 921 # All the statuses tests can have when they fail. 922 return self.view['status'] in ['FAIL', 'ERROR', 'ABORT'] 923 924 925 def is_infra_test(self): 926 """Check whether this is a test that only lab infra is concerned. 927 928 @returns: True if only lab infra is concerned, False otherwise. 929 930 """ 931 return self.get_testname() in self.INFRA_TESTS 932 933 934 def get_buildbot_link_reason(self): 935 """Generate the buildbot link reason for the test. 936 937 @returns: A string representing the reason. 938 939 """ 940 return ('%s: %s' % (self.view['status'], self.view['reason']) 941 if self.view['reason'] else self.view['status']) 942 943 944 def get_job_id_owner_str(self): 945 """Generate the job_id_owner string for a test. 946 947 @returns: A string which looks like 135036-username 948 949 """ 950 return '%s-%s' % (self.view['afe_job_id'], self.user) 951 952 953 def get_bug_info(self, suite_job_keyvals): 954 """Get the bug info from suite_job_keyvals. 955 956 If a bug has been filed for the test, its bug info (bug id and counts) 957 will be stored in the suite job's keyvals. This method attempts to 958 retrieve bug info of the test from |suite_job_keyvals|. It will return 959 None if no bug info is found. No need to check bug info if the view is 960 SUITE_JOB. 961 962 @param suite_job_keyvals: The job keyval dictionary of the suite job. 963 All the bug info about child jobs are stored in 964 suite job's keyvals. 965 966 @returns: None if there is no bug info, or a pair with the 967 id of the bug, and the count of the number of 968 times the bug has been seen. 969 970 """ 971 if self.get_testname() == self.SUITE_JOB: 972 return None 973 if (self.view['test_name'].startswith('SERVER_JOB') or 974 self.view['test_name'].startswith('CLIENT_JOB')): 975 # Append job name as a prefix for SERVER_JOB and CLIENT_JOB 976 testname= '%s_%s' % (self.view['job_name'], self.view['test_name']) 977 else: 978 testname = self.view['test_name'] 979 980 return tools.get_test_failure_bug_info( 981 suite_job_keyvals, self.view['afe_job_id'], 982 testname) 983 984 985 def should_display_buildbot_link(self): 986 """Check whether a buildbot link should show for this view. 987 988 For suite job view, show buildbot link if it fails. 989 For normal test view, 990 show buildbot link if it is a retry 991 show buildbot link if it hits its own timeout. 992 show buildbot link if it fails. This doesn't 993 include the case where it was aborted but has 994 not hit its own timeout (most likely it was aborted because 995 suite has timed out). 996 997 @returns: True if we should show the buildbot link. 998 False otherwise. 999 """ 1000 is_bad_status = (self.view['status'] != 'GOOD' and 1001 self.view['status'] != 'TEST_NA') 1002 if self.get_testname() == self.SUITE_JOB: 1003 return is_bad_status 1004 else: 1005 if self.is_retry(): 1006 return True 1007 if is_bad_status: 1008 return not self.is_aborted() or self.hit_timeout() 1009 1010 1011 def get_control_file_attributes(self): 1012 """Get the attributes from the control file of the test. 1013 1014 @returns: A list of test attribute or None. 1015 """ 1016 control_file = self.afe_job.control_file 1017 attributes = None 1018 if control_file: 1019 cd = control_data.parse_control_string(control_file) 1020 attributes = list(cd.attributes) 1021 return attributes 1022 1023 1024 def override_afe_job_id(self, afe_job_id): 1025 """Overrides the AFE job id for the test. 1026 1027 @param afe_job_id: The new AFE job id to use. 1028 """ 1029 self.view['afe_job_id'] = afe_job_id 1030 1031 1032def log_buildbot_links(log_func, links): 1033 """Output buildbot links to log. 1034 1035 @param log_func: Logging function to use. 1036 @param links: Iterable of LogLink instances. 1037 """ 1038 for link in links: 1039 for generated_link in link.GenerateBuildbotLinks(): 1040 log_func(generated_link) 1041 wmatrix_retry_link = link.GenerateWmatrixRetryLink() 1042 if wmatrix_retry_link: 1043 log_func(wmatrix_retry_link) 1044 wmatrix_history_link = link.GenerateWmatrixHistoryLink() 1045 if wmatrix_history_link: 1046 log_func(wmatrix_history_link) 1047 1048 1049class _ReturnCodeComputer(object): 1050 1051 def __init__(self, ignore_test_results=False): 1052 """Initialize instance. 1053 1054 If ignore_test_results is True, don't check the test jobs for 1055 failure. 1056 """ 1057 self._ignore_test_results = ignore_test_results 1058 1059 def __call__(self, test_views): 1060 """Compute the exit code based on test results.""" 1061 code = RETURN_CODES.OK 1062 tests_passed_after_retry = False 1063 1064 for v in test_views: 1065 # The order of checking each case is important. 1066 if v.get_testname() == TestView.SUITE_JOB: 1067 if v.is_aborted() and v.hit_timeout(): 1068 current_code = RETURN_CODES.SUITE_TIMEOUT 1069 elif v.is_in_fail_status(): 1070 current_code = RETURN_CODES.INFRA_FAILURE 1071 elif v['status'] == 'WARN': 1072 current_code = RETURN_CODES.WARNING 1073 else: 1074 current_code = RETURN_CODES.OK 1075 elif self._ignore_test_results: 1076 pass 1077 else: 1078 if v.is_aborted() and v.is_relevant_suite_view(): 1079 # The test was aborted before started 1080 # This gurantees that the suite has timed out. 1081 current_code = RETURN_CODES.SUITE_TIMEOUT 1082 elif v.is_aborted() and not v.hit_timeout(): 1083 # The test was aborted, but 1084 # not due to a timeout. This is most likely 1085 # because the suite has timed out, but may 1086 # also because it was aborted by the user. 1087 # Since suite timing out is determined by checking 1088 # the suite job view, we simply ignore this view here. 1089 current_code = RETURN_CODES.OK 1090 elif v.is_in_fail_status(): 1091 # The test job failed. 1092 if v.is_infra_test(): 1093 current_code = RETURN_CODES.INFRA_FAILURE 1094 else: 1095 current_code = RETURN_CODES.ERROR 1096 elif v['status'] == 'WARN': 1097 # The test/suite job raised a wanrning. 1098 current_code = RETURN_CODES.WARNING 1099 elif v.is_retry(): 1100 # The test is a passing retry. 1101 current_code = RETURN_CODES.WARNING 1102 tests_passed_after_retry = True 1103 else: 1104 current_code = RETURN_CODES.OK 1105 code = get_worse_code(code, current_code) 1106 1107 return code, _get_return_msg(code, tests_passed_after_retry) 1108 1109 1110def _get_return_msg(code, tests_passed_after_retry): 1111 """Return the proper message for a given return code. 1112 1113 @param code: An enum value of RETURN_CODES 1114 @param test_passed_after_retry: True/False, indicating 1115 whether there are test(s) that have passed after retry. 1116 1117 @returns: A string, representing the message. 1118 1119 """ 1120 if code == RETURN_CODES.INFRA_FAILURE: 1121 return 'Suite job failed or provisioning failed.' 1122 elif code == RETURN_CODES.SUITE_TIMEOUT: 1123 return ('Some test(s) was aborted before running,' 1124 ' suite must have timed out.') 1125 elif code == RETURN_CODES.WARNING: 1126 if tests_passed_after_retry: 1127 return 'Some test(s) passed after retry.' 1128 else: 1129 return 'Some test(s) raised a warning.' 1130 elif code == RETURN_CODES.ERROR: 1131 return 'Some test(s) failed.' 1132 else: 1133 return '' 1134 1135 1136class ResultCollector(object): 1137 """Collect test results of a suite or a single test run. 1138 1139 Once a suite job has finished, use this class to collect test results. 1140 `run` is the core method that is to be called first. Then the caller 1141 could retrieve information like return code, return message, is_aborted, 1142 and timings by accessing the collector's public attributes. And output 1143 the test results and links by calling the 'output_*' methods. 1144 1145 Here is a overview of what `run` method does. 1146 1147 1) Collect the suite job's results from tko_test_view_2. 1148 For the suite job, we only pull test views without a 'subdir'. 1149 A NULL subdir indicates that the test was _not_ executed. This could be 1150 that no child job was scheduled for this test or the child job got 1151 aborted before starts running. 1152 (Note 'SERVER_JOB'/'CLIENT_JOB' are handled specially) 1153 1154 2) Collect the child jobs' results from tko_test_view_2. 1155 For child jobs, we pull all the test views associated with them. 1156 (Note 'SERVER_JOB'/'CLIENT_JOB' are handled specially) 1157 1158 3) Generate web and buildbot links. 1159 4) Compute timings of the suite run. 1160 5) Compute the return code based on test results. 1161 1162 @var _instance_server: The hostname of the server that is used 1163 to service the suite. 1164 @var _afe: The afe rpc client. 1165 @var _tko: The tko rpc client. 1166 @var _build: The build for which the suite is run, 1167 e.g. 'lumpy-release/R35-5712.0.0' 1168 @var _board: The target board for which the suite is run, 1169 e.g., 'lumpy', 'link'. 1170 @var _suite_name: The suite name, e.g. 'bvt', 'dummy'. 1171 @var _suite_job_id: The job id of the suite for which we are going to 1172 collect results. 1173 @var _original_suite_name: The suite name we record timing would be 1174 different from _suite_name when running 1175 suite_attr_wrapper. 1176 @var _return_code_function: Called to return what the overall result of 1177 the suite is. 1178 @var _suite_views: A list of TestView objects, representing relevant 1179 test views of the suite job. 1180 @var _child_views: A list of TestView objects, representing test views 1181 of the child jobs. 1182 @var _test_views: A list of TestView objects, representing all test views 1183 from _suite_views and _child_views. 1184 @var _web_links: A list of web links pointing to the results of jobs. 1185 @var buildbot_links: A list of buildbot links for non-passing tests. 1186 @var _solo_test_run: True if this is a single test run. 1187 @var return_code: The exit code that should be returned by run_suite. 1188 @var return_message: Any message that should be displayed to explain 1189 the return code. 1190 @var is_aborted: Whether the suite was aborted or not. 1191 True, False or None (aborting status is unknown yet) 1192 @var timings: A Timing object that records the suite's timings. 1193 1194 """ 1195 1196 1197 def __init__(self, instance_server, afe, tko, build, board, 1198 suite_name, suite_job_id, 1199 return_code_function, 1200 original_suite_name=None, 1201 user=None, solo_test_run=False): 1202 self._instance_server = instance_server 1203 self._afe = afe 1204 self._tko = tko 1205 self._build = build 1206 self._board = board 1207 self._suite_name = suite_name 1208 self._suite_job_id = suite_job_id 1209 self._original_suite_name = original_suite_name or suite_name 1210 self._return_code_function = return_code_function 1211 self._suite_views = [] 1212 self._child_views = [] 1213 self._test_views = [] 1214 self._retry_counts = {} 1215 self._missing_results = {} 1216 self._web_links = [] 1217 self.buildbot_links = [] 1218 self._num_child_jobs = 0 1219 self.return_code = None 1220 self.return_message = '' 1221 self.is_aborted = None 1222 self.timings = None 1223 self._user = user or getpass.getuser() 1224 self._solo_test_run = solo_test_run 1225 1226 1227 def _fetch_relevant_test_views_of_suite(self): 1228 """Fetch relevant test views of the suite job. 1229 1230 For the suite job, there will be a test view for SERVER_JOB, and views 1231 for results of its child jobs. For example, assume we've created 1232 a suite job (afe_job_id: 40) that runs dummy_Pass, dummy_Fail, 1233 dummy_Pass.bluetooth. Assume dummy_Pass was aborted before running while 1234 dummy_Path.bluetooth got TEST_NA as no duts have bluetooth. 1235 So the suite job's test views would look like 1236 _____________________________________________________________________ 1237 test_idx| job_idx|test_name |subdir |afe_job_id|status 1238 10 | 1000 |SERVER_JOB |---- |40 |GOOD 1239 11 | 1000 |dummy_Pass |NULL |40 |ABORT 1240 12 | 1000 |dummy_Fail.Fail |41-onwer/...|40 |FAIL 1241 13 | 1000 |dummy_Fail.Error |42-owner/...|40 |ERROR 1242 14 | 1000 |dummy_Pass.bluetooth|NULL |40 |TEST_NA 1243 1244 For a suite job, we only care about 1245 a) The test view for the suite job's SERVER_JOB 1246 b) The test views for real tests without a subdir. A NULL subdir 1247 indicates that a test didn't get executed. 1248 So, for the above example, we only keep test views whose test_idxs 1249 are 10, 11, 14. 1250 1251 @returns: A list of TestView objects, representing relevant 1252 test views of the suite job. 1253 1254 """ 1255 suite_job = self._afe.get_jobs(id=self._suite_job_id)[0] 1256 views = self._tko.run(call='get_detailed_test_views', 1257 afe_job_id=self._suite_job_id) 1258 relevant_views = [] 1259 for v in views: 1260 v = TestView(v, suite_job, self._suite_name, self._build, self._user, 1261 solo_test_run=self._solo_test_run) 1262 if v.is_relevant_suite_view(): 1263 # If the test doesn't have results in TKO and is being 1264 # displayed in the suite view instead of the child view, 1265 # then afe_job_id is incorrect and from the suite. 1266 # Override it based on the AFE job id which was missing 1267 # results. 1268 # TODO: This is likely inaccurate if a test has multiple 1269 # tries which all fail TKO parse stage. 1270 if v['test_name'] in self._missing_results: 1271 v.override_afe_job_id( 1272 self._missing_results[v['test_name']][0]) 1273 relevant_views.append(v) 1274 return relevant_views 1275 1276 1277 def _compute_retry_count(self, view): 1278 """Return how many times the test has been retried. 1279 1280 @param view: A TestView instance. 1281 @returns: An int value indicating the retry count. 1282 1283 """ 1284 old_job = view['job_keyvals'].get('retry_original_job_id') 1285 count = 0 1286 while old_job: 1287 count += 1 1288 views = self._tko.run( 1289 call='get_detailed_test_views', afe_job_id=old_job) 1290 old_job = (views[0]['job_keyvals'].get('retry_original_job_id') 1291 if views else None) 1292 return count 1293 1294 1295 def _fetch_test_views_of_child_jobs(self, jobs=None): 1296 """Fetch test views of child jobs. 1297 1298 @returns: A tuple (child_views, retry_counts, missing_results) 1299 child_views is list of TestView objects, representing 1300 all valid views. 1301 retry_counts is a dictionary that maps test_idx to retry 1302 counts. It only stores retry counts that are greater than 0. 1303 missing_results is a dictionary that maps test names to 1304 lists of job ids. 1305 1306 """ 1307 child_views = [] 1308 retry_counts = {} 1309 missing_results = {} 1310 child_jobs = jobs or self._afe.get_jobs(parent_job_id=self._suite_job_id) 1311 if child_jobs: 1312 self._num_child_jobs = len(child_jobs) 1313 for job in child_jobs: 1314 views = [TestView(v, job, self._suite_name, self._build, self._user) 1315 for v in self._tko.run( 1316 call='get_detailed_test_views', afe_job_id=job.id, 1317 invalid=0)] 1318 if len(views) == 0: 1319 missing_results.setdefault(job.name, []).append(job.id) 1320 contains_test_failure = any( 1321 v.is_test() and v['status'] != 'GOOD' for v in views) 1322 for v in views: 1323 if (v.is_test() or 1324 v['status'] != 'GOOD' and not contains_test_failure): 1325 # For normal test view, just keep it. 1326 # For SERVER_JOB or CLIENT_JOB, only keep it 1327 # if it fails and no other test failure. 1328 child_views.append(v) 1329 retry_count = self._compute_retry_count(v) 1330 if retry_count > 0: 1331 retry_counts[v['test_idx']] = retry_count 1332 return child_views, retry_counts, missing_results 1333 1334 1335 def _generate_web_and_buildbot_links(self): 1336 """Generate web links and buildbot links.""" 1337 # TODO(fdeng): If a job was aborted before it reaches Running 1338 # state, we read the test view from the suite job 1339 # and thus this method generates a link pointing to the 1340 # suite job's page for the aborted job. Need a fix. 1341 self._web_links = [] 1342 self.buildbot_links = [] 1343 # Bug info are stored in the suite job's keyvals. 1344 if self._solo_test_run: 1345 suite_job_keyvals = {} 1346 else: 1347 suite_job_keyvals = self._suite_views[0]['job_keyvals'] 1348 for v in self._test_views: 1349 retry_count = self._retry_counts.get(v['test_idx'], 0) 1350 bug_info = v.get_bug_info(suite_job_keyvals) 1351 job_id_owner = v.get_job_id_owner_str() 1352 link = LogLink( 1353 anchor=v.get_testname(), 1354 server=self._instance_server, 1355 job_string=job_id_owner, 1356 bug_info=bug_info, retry_count=retry_count, 1357 testname=v.get_testname()) 1358 self._web_links.append(link) 1359 1360 if v.should_display_buildbot_link(): 1361 link.reason = v.get_buildbot_link_reason() 1362 self.buildbot_links.append(link) 1363 1364 1365 def _record_timings(self): 1366 """Record suite timings.""" 1367 self.timings = Timings(self._suite_job_id) 1368 for v in self._test_views: 1369 self.timings.RecordTiming(v) 1370 1371 1372 def _compute_return_code(self): 1373 """Compute the exit code based on test results.""" 1374 return_code, message = self._return_code_function(self._test_views) 1375 self.return_code = return_code 1376 self.return_message = message 1377 1378 1379 def _make_test_results(self): 1380 """Make TestResults for collected tests. 1381 1382 @returns: List of TestResult instances. 1383 """ 1384 test_results = [] 1385 for test_view in self._test_views: 1386 test_result = TestResult( 1387 test_view=test_view, 1388 retry_count=self._retry_counts.get(test_view['test_idx'], 0)) 1389 test_results.append(test_result) 1390 return test_results 1391 1392 1393 def output_results(self): 1394 """Output test results, timings and web links.""" 1395 # Output test results 1396 test_results = self._make_test_results() 1397 max_name_length = max(len(test_result.name) 1398 for test_result in test_results) 1399 for test_result in test_results: 1400 test_result.log_using(logging.info, max_name_length + 3) 1401 # Output suite timings 1402 logging.info(self.timings) 1403 # Output links to test logs 1404 logging.info('\nLinks to test logs:') 1405 for link in self._web_links: 1406 logging.info(link.text_link) 1407 logging.info('\n') 1408 1409 1410 def get_results_dict(self): 1411 """Write test results, timings and web links into a dict. 1412 1413 @returns: A dict of results in the format like: 1414 { 1415 'tests': { 1416 'test_1': {'status': 'PASSED', 'attributes': [1,2], ...} 1417 'test_2': {'status': 'FAILED', 'attributes': [1],...} 1418 } 1419 'suite_timings': { 1420 'download_start': '1998-07-17 00:00:00', 1421 'payload_download_end': '1998-07-17 00:00:05', 1422 ... 1423 } 1424 } 1425 """ 1426 output_dict = {} 1427 tests_dict = output_dict.setdefault('tests', {}) 1428 for v in self._test_views: 1429 test_name = v.get_testname() 1430 test_info = tests_dict.setdefault(test_name, {}) 1431 test_info.update({ 1432 'status': v['status'], 1433 'attributes': v.get_control_file_attributes() or list(), 1434 'reason': v['reason'], 1435 'retry_count': self._retry_counts.get(v['test_idx'], 0), 1436 }) 1437 # For aborted test, the control file will not be parsed and thus 1438 # fail to get the attributes info. Therefore, the subsystems the 1439 # abort test testing will be missing. For this case, we will assume 1440 # the aborted test will test all subsystems, set subsystem:default. 1441 if (test_info['status'] == 'ABORT' and 1442 not any('subsystem:' in a for a in test_info['attributes'])): 1443 test_info['attributes'].append('subsystem:default') 1444 1445 # Write the links to test logs into the |tests_dict| of |output_dict|. 1446 # For test whose status is not 'GOOD', the link is also buildbot_link. 1447 for link in self._web_links: 1448 test_name = link.anchor.strip() 1449 test_info = tests_dict.get(test_name) 1450 if test_info: 1451 test_info['link_to_logs'] = link.url 1452 # Write the wmatrix link into the dict. 1453 if link in self.buildbot_links and link.testname: 1454 test_info['wmatrix_link'] \ 1455 = reporting_utils.link_retry_url(link.testname) 1456 # Write the bug url into the dict. 1457 if link.bug_id: 1458 test_info['bug_url'] = link.bug_url 1459 1460 # Write the suite timings into |output_dict| 1461 timings = self.timings 1462 if timings is not None: 1463 time_dict = output_dict.setdefault('suite_timings', {}) 1464 time_dict.update({ 1465 'download_start' : str(timings.download_start_time), 1466 'payload_download_end' : str(timings.payload_end_time), 1467 'suite_start' : str(timings.suite_start_time), 1468 'artifact_download_end' : str(timings.artifact_end_time), 1469 'tests_start' : str(timings.tests_start_time), 1470 'tests_end' : str(timings.tests_end_time), 1471 }) 1472 1473 output_dict['suite_job_id'] = self._suite_job_id 1474 1475 return output_dict 1476 1477 1478 def run(self): 1479 """Collect test results. 1480 1481 This method goes through the following steps: 1482 Fetch relevent test views of the suite job. 1483 Fetch test views of child jobs 1484 Check whether the suite was aborted. 1485 Generate links. 1486 Calculate suite timings. 1487 Compute return code based on the test result. 1488 1489 """ 1490 if self._solo_test_run: 1491 self._test_views, self._retry_counts, self._missing_results = ( 1492 self._fetch_test_views_of_child_jobs( 1493 jobs=self._afe.get_jobs(id=self._suite_job_id))) 1494 else: 1495 self._child_views, self._retry_counts, self._missing_results = ( 1496 self._fetch_test_views_of_child_jobs()) 1497 self._suite_views = self._fetch_relevant_test_views_of_suite() 1498 self._test_views = self._suite_views + self._child_views 1499 # For hostless job in Starting status, there is no test view associated. 1500 # This can happen when a suite job in Starting status is aborted. When 1501 # the scheduler hits some limit, e.g., max_hostless_jobs_per_drone, 1502 # max_jobs_started_per_cycle, a suite job can stays in Starting status. 1503 if not self._test_views: 1504 self.return_code = RETURN_CODES.INFRA_FAILURE 1505 self.return_message = 'No test view was found.' 1506 return 1507 self.is_aborted = any([view['job_keyvals'].get('aborted_by') 1508 for view in self._suite_views]) 1509 self._generate_web_and_buildbot_links() 1510 self._record_timings() 1511 self._compute_return_code() 1512 1513 1514 def gather_timing_stats(self): 1515 """Collect timing related statistics.""" 1516 # Record suite runtime in metadata db. 1517 # Some failure modes can leave times unassigned, report sentinel value 1518 # in that case. 1519 runtime_in_secs = -1 1520 if (self.timings.tests_end_time is not None and 1521 self.timings.suite_start_time is not None): 1522 runtime_in_secs = (self.timings.tests_end_time - 1523 self.timings.suite_start_time).total_seconds() 1524 1525 job_overhead.record_suite_runtime(self._suite_job_id, self._suite_name, 1526 self._board, self._build, self._num_child_jobs, runtime_in_secs) 1527 1528 1529 1530def _make_builds_from_options(options): 1531 """Create a dict of builds for creating a suite job. 1532 1533 The returned dict maps version label prefixes to build names. Together, 1534 each key-value pair describes a complete label. 1535 1536 @param options: SimpleNamespace from argument parsing. 1537 1538 @return: dict mapping version label prefixes to build names 1539 """ 1540 builds = {} 1541 if options.build: 1542 prefix = provision.get_version_label_prefix(options.build) 1543 builds[prefix] = options.build 1544 if options.firmware_rw_build: 1545 builds[provision.FW_RW_VERSION_PREFIX] = options.firmware_rw_build 1546 if options.firmware_ro_build: 1547 builds[provision.FW_RO_VERSION_PREFIX] = options.firmware_ro_build 1548 return builds 1549 1550 1551@retry.retry(error.StageControlFileFailure, timeout_min=10) 1552def create_suite(afe, options): 1553 """Create a suite with retries. 1554 1555 @param afe: The afe object to insert the new suite job into. 1556 @param options: The options to use in creating the suite. 1557 1558 @return: The afe_job_id of the new suite job. 1559 """ 1560 logging.info('%s Submitted create_suite_job rpc', 1561 diagnosis_utils.JobTimer.format_time(datetime.now())) 1562 return afe.run( 1563 'create_suite_job', 1564 name=options.name, 1565 board=options.board, 1566 builds=_make_builds_from_options(options), 1567 test_source_build=options.test_source_build, 1568 check_hosts=not options.no_wait, 1569 pool=options.pool, 1570 num=options.num, 1571 file_bugs=options.file_bugs, 1572 priority=options.priority, 1573 suite_args=options.suite_args, 1574 wait_for_results=not options.no_wait, 1575 timeout_mins=options.timeout_mins + options.delay_minutes, 1576 max_runtime_mins=options.max_runtime_mins + options.delay_minutes, 1577 job_retry=options.retry, 1578 max_retries=options.max_retries, 1579 suite_min_duts=options.suite_min_duts, 1580 offload_failures_only=options.offload_failures_only, 1581 run_prod_code=options.run_prod_code, 1582 delay_minutes=options.delay_minutes, 1583 job_keyvals=options.job_keyvals, 1584 test_args=options.test_args, 1585 ) 1586 1587 1588class SuiteResult(namedtuple('SuiteResult', ['return_code', 'output_dict'])): 1589 """Result of running a suite to return.""" 1590 1591 def __new__(cls, return_code, output_dict): 1592 output_dict = output_dict.copy() 1593 output_dict['return_cde'] = return_code 1594 return super(SuiteResult, cls).__new__(cls, return_code, output_dict) 1595 1596 1597def _run_suite(options): 1598 """ 1599 run_suite script without exception handling. 1600 1601 @param options: The parsed options. 1602 1603 @returns: A tuple contains the return_code of run_suite and the dictionary 1604 of the output. 1605 1606 """ 1607 # If indicate to use the new style suite control file, convert the args 1608 if options.use_suite_attr: 1609 options = change_options_for_suite_attr(options) 1610 1611 log_name = _get_log_name(options) 1612 utils.setup_logging(logfile=log_name) 1613 1614 if not options.bypass_labstatus and not options.web: 1615 utils.check_lab_status(options.build) 1616 1617 afe = _create_afe(options) 1618 instance_server = afe.server 1619 1620 rpc_helper = diagnosis_utils.RPCHelper(afe) 1621 is_real_time = True 1622 if options.mock_job_id: 1623 job_id = int(options.mock_job_id) 1624 existing_job = afe.get_jobs(id=job_id, finished=True) 1625 if existing_job: 1626 is_real_time = False 1627 else: 1628 existing_job = afe.get_jobs(id=job_id) 1629 if existing_job: 1630 job_created_on = time_utils.date_string_to_epoch_time( 1631 existing_job[0].created_on) 1632 else: 1633 raise utils.TestLabException('Failed to retrieve job: %d' % job_id) 1634 else: 1635 try: 1636 rpc_helper.check_dut_availability(options.board, options.pool, 1637 options.minimum_duts, 1638 options.skip_duts_check) 1639 job_id = create_suite(afe, options) 1640 job_created_on = time.time() 1641 except diagnosis_utils.NotEnoughDutsError as e: 1642 e.add_suite_name(options.name) 1643 e.add_build(options.test_source_build) 1644 pool_health_bug = reporting.PoolHealthBug(e) 1645 bug_id = reporting.Reporter().report(pool_health_bug).bug_id 1646 if bug_id is not None: 1647 logging.info(annotations.StepLink( 1648 text='Pool Health Bug', 1649 url=reporting_utils.link_crbug(bug_id))) 1650 e.add_bug_id(bug_id) 1651 raise e 1652 except (error.CrosDynamicSuiteException, 1653 error.RPCException, proxy.JSONRPCException) as e: 1654 logging.exception('Error Message: %s', e) 1655 return SuiteResult(RETURN_CODES.INFRA_FAILURE, 1656 {'return_message': str(e)}) 1657 except AttributeError: 1658 return SuiteResult(RETURN_CODES.INVALID_OPTIONS, {}) 1659 1660 job_timer = diagnosis_utils.JobTimer( 1661 job_created_on, float(options.timeout_mins)) 1662 job_url = reporting_utils.link_job(job_id, 1663 instance_server=instance_server) 1664 logging.info('%s Created suite job: %s', 1665 job_timer.format_time(job_timer.job_created_time), 1666 job_url) 1667 logging.info(annotations.StepLink( 1668 text='Link to suite', 1669 url=job_url)) 1670 1671 if options.create_and_return: 1672 msg = '--create_and_return was specified, terminating now.' 1673 logging.info(msg) 1674 return SuiteResult(RETURN_CODES.OK, {'return_message':msg}) 1675 1676 if options.no_wait: 1677 return _handle_job_nowait(job_id, options, instance_server) 1678 else: 1679 return _handle_job_wait(afe, job_id, options, job_timer, is_real_time) 1680 1681 1682def _get_log_name(options): 1683 """Return local log file's name. 1684 1685 @param options: Parsed options. 1686 1687 @return log_name, a string file name. 1688 """ 1689 if options.require_logfile: 1690 # options.build is verified to exist in verify_options. 1691 # convert build name from containing / to containing only _. 1692 log_name = 'run_suite-%s.log' % options.build.replace('/', '_') 1693 log_dir = os.path.join(common.autotest_dir, 'logs') 1694 if os.path.exists(log_dir): 1695 log_name = os.path.join(log_dir, log_name) 1696 1697 return log_name 1698 else: 1699 return None 1700 1701 1702def _create_afe(options): 1703 """Return an afe instance based on options. 1704 1705 @param options Parsed options. 1706 1707 @return afe, an AFE instance. 1708 """ 1709 instance_server = (options.web if options.web else 1710 instance_for_pool(options.pool)) 1711 afe = frontend_wrappers.RetryingAFE(server=instance_server, 1712 timeout_min=options.afe_timeout_mins, 1713 delay_sec=options.delay_sec) 1714 logging.info('Autotest instance created: %s', instance_server) 1715 return afe 1716 1717 1718def _handle_job_wait(afe, job_id, options, job_timer, is_real_time): 1719 """Handle suite job synchronously. 1720 1721 @param afe AFE instance. 1722 @param job_id Suite job id. 1723 @param options Parsed options. 1724 @param job_timer JobTimer for suite job. 1725 @param is_real_time Whether or not to handle job timeout. 1726 1727 @return SuiteResult of suite job. 1728 """ 1729 rpc_helper = diagnosis_utils.RPCHelper(afe) 1730 instance_server = afe.server 1731 while not afe.get_jobs(id=job_id, finished=True): 1732 _poke_buildbot_with_output(afe, job_id, job_timer) 1733 if job_timer.debug_output_timer.poll(): 1734 logging.info('The suite job has another %s till timeout.', 1735 job_timer.timeout_hours - job_timer.elapsed_time()) 1736 time.sleep(10) 1737 logging.info('%s Suite job is finished.', 1738 diagnosis_utils.JobTimer.format_time(datetime.now())) 1739 # For most cases, ResultCollector should be able to determine whether 1740 # a suite has timed out by checking information in the test view. 1741 # However, occationally tko parser may fail on parsing the 1742 # job_finished time from the job's keyval file. So we add another 1743 # layer of timeout check in run_suite. We do the check right after 1744 # the suite finishes to make it as accurate as possible. 1745 # There is a minor race condition here where we might have aborted 1746 # for some reason other than a timeout, and the job_timer thinks 1747 # it's a timeout because of the jitter in waiting for results. 1748 # The consequence would be that run_suite exits with code 1749 # SUITE_TIMEOUT while it should have returned INFRA_FAILURE 1750 # instead, which should happen very rarely. 1751 # Note the timeout will have no sense when using -m option. 1752 is_suite_timeout = job_timer.is_suite_timeout() 1753 1754 # Extract the original suite name to record timing. 1755 original_suite_name = get_original_suite_name(options.name, 1756 options.suite_args) 1757 # Start collecting test results. 1758 logging.info('%s Start collecting test results and dump them to json.', 1759 diagnosis_utils.JobTimer.format_time(datetime.now())) 1760 TKO = frontend_wrappers.RetryingTKO(server=instance_server, 1761 timeout_min=options.afe_timeout_mins, 1762 delay_sec=options.delay_sec) 1763 collector = ResultCollector(instance_server=instance_server, 1764 afe=afe, tko=TKO, build=options.build, 1765 board=options.board, 1766 suite_name=options.name, 1767 suite_job_id=job_id, 1768 # TODO(ayatane): It needs to be possible 1769 # for provision suite to pass if only a 1770 # few tests fail. Otherwise, a single 1771 # failing test will be reported as 1772 # failure even if the suite reports 1773 # success. 1774 return_code_function=_ReturnCodeComputer( 1775 ignore_test_results=(options.name 1776 == 'provision'), 1777 ), 1778 original_suite_name=original_suite_name) 1779 collector.run() 1780 # Dump test outputs into json. 1781 output_dict = collector.get_results_dict() 1782 output_dict['autotest_instance'] = instance_server 1783 if not options.json_dump: 1784 collector.output_results() 1785 code = collector.return_code 1786 return_message = collector.return_message 1787 if is_real_time: 1788 # Do not record stats if the suite was aborted (either by a user 1789 # or through the golo rpc). 1790 # Also do not record stats if is_aborted is None, indicating 1791 # aborting status is unknown yet. 1792 if collector.is_aborted == False: 1793 logging.info('%s Gathering timing stats for the suite job.', 1794 diagnosis_utils.JobTimer.format_time(datetime.now())) 1795 collector.gather_timing_stats() 1796 1797 if collector.is_aborted == True and is_suite_timeout: 1798 # There are two possible cases when a suite times out. 1799 # 1. the suite job was aborted due to timing out 1800 # 2. the suite job succeeded, but some child jobs 1801 # were already aborted before the suite job exited. 1802 # The case 2 was handled by ResultCollector, 1803 # here we handle case 1. 1804 old_code = code 1805 code = get_worse_code( 1806 code, RETURN_CODES.SUITE_TIMEOUT) 1807 if old_code != code: 1808 return_message = 'Suite job timed out.' 1809 logging.info('Upgrade return code from %s to %s ' 1810 'because suite job has timed out.', 1811 RETURN_CODES.get_string(old_code), 1812 RETURN_CODES.get_string(code)) 1813 1814 logging.info('\n %s Attempting to display pool info: %s', 1815 diagnosis_utils.JobTimer.format_time(datetime.now()), 1816 options.pool) 1817 try: 1818 # Add some jitter to make up for any latency in 1819 # aborting the suite or checking for results. 1820 cutoff = job_timer.timeout_hours + timedelta(hours=0.3) 1821 rpc_helper.diagnose_pool( 1822 options.board, options.pool, cutoff) 1823 except proxy.JSONRPCException: 1824 logging.warning('Unable to display pool info.') 1825 1826 # And output return message. 1827 if return_message: 1828 logging.info('Reason: %s', return_message) 1829 output_dict['return_message'] = return_message 1830 1831 logging.info('\n %s Output below this line is for buildbot consumption:', 1832 diagnosis_utils.JobTimer.format_time(datetime.now())) 1833 log_buildbot_links(logging.info, collector.buildbot_links) 1834 return SuiteResult(code, output_dict) 1835 1836 1837def _handle_job_nowait(job_id, options, instance_server): 1838 """Handle suite job asynchronously. 1839 1840 @param job_id Suite job id. 1841 @param options Parsed options. 1842 @param instance_server Autotest instance hostname. 1843 1844 @return SuiteResult of suite job. 1845 """ 1846 logging.info('Created suite job: %r', job_id) 1847 link = LogLink(options.name, instance_server, 1848 '%s-%s' % (job_id, getpass.getuser())) 1849 for generate_link in link.GenerateBuildbotLinks(): 1850 logging.info(generate_link) 1851 logging.info('--no_wait specified; Exiting.') 1852 return SuiteResult(RETURN_CODES.OK, 1853 {'return_message': '--no_wait specified; Exiting.'}) 1854 1855 1856def _should_run(options): 1857 """Check whether the suite should be run based on lab/job status checking. 1858 1859 @param options Parsed options. 1860 """ 1861 try: 1862 site_utils.check_lab_status(options.test_source_build) 1863 except site_utils.TestLabException as ex: 1864 logging.exception('Lab is closed or build is blocked. Skipping ' 1865 'suite %s, board %s, build %s: %s', 1866 options.name, options.board, 1867 options.test_source_build, str(ex)) 1868 return False 1869 1870 start_time = str(datetime.now() - 1871 timedelta(days=_SEARCH_JOB_MAX_DAYS)) 1872 afe = _create_afe(options) 1873 return not afe.get_jobs( 1874 name__istartswith=options.test_source_build, 1875 name__iendswith='control.'+options.name, 1876 created_on__gte=start_time, 1877 min_rpc_timeout=_MIN_RPC_TIMEOUT) 1878 1879 1880def _poke_buildbot_with_output(afe, job_id, job_timer): 1881 """Poke buildbot so it doesn't timeout from silence. 1882 1883 @param afe AFE instance. 1884 @param job_id Suite job id. 1885 @param job_timer JobTimer for suite job. 1886 """ 1887 rpc_helper = diagnosis_utils.RPCHelper(afe) 1888 # Note that this call logs output, preventing buildbot's 1889 # 9000 second silent timeout from kicking in. Let there be no 1890 # doubt, this is a hack. The timeout is from upstream buildbot and 1891 # this is the easiest work around. 1892 if job_timer.first_past_halftime(): 1893 rpc_helper.diagnose_job(job_id, afe.server) 1894 1895 1896 1897def _run_task(options): 1898 """Perform this script's function minus setup. 1899 1900 Boilerplate like argument parsing, logging, output formatting happen 1901 elsewhere. 1902 1903 Returns a SuiteResult instance. 1904 1905 TODO(ayatane): The try/except should be moved into _run_suite(). 1906 Good luck trying to figure out which function calls are supposed to 1907 raise which of the exceptions. 1908 """ 1909 try: 1910 return _run_suite(options) 1911 except diagnosis_utils.BoardNotAvailableError as e: 1912 result = SuiteResult( 1913 RETURN_CODES.BOARD_NOT_AVAILABLE, 1914 {'return_message': 'Skipping testing: %s' % e.message}) 1915 logging.info(result.output_dict['return_message']) 1916 return result 1917 except utils.TestLabException as e: 1918 result = SuiteResult( 1919 RETURN_CODES.INFRA_FAILURE, 1920 {'return_message': 'TestLabException: %s' % e}) 1921 logging.exception(result.output_dict['return_message']) 1922 return result 1923 1924 1925class _ExceptionHandler(object): 1926 """Global exception handler replacement.""" 1927 1928 def __init__(self, dump_json): 1929 """Initialize instance. 1930 1931 @param dump_json: Whether to print a JSON dump of the result dict to 1932 stdout. 1933 """ 1934 self._should_dump_json = dump_json 1935 1936 def __call__(self, exc_type, value, traceback): 1937 if self._should_dump_json: 1938 _dump_json({'return_message': ('Unhandled run_suite exception: %s' 1939 % value)}) 1940 sys.exit(RETURN_CODES.INFRA_FAILURE) 1941 1942 1943def main(): 1944 """Entry point.""" 1945 utils.verify_not_root_user() 1946 1947 parser = make_parser() 1948 options = parser.parse_args() 1949 if options.do_nothing: 1950 return 0 1951 1952 sys.exceptionhandler = _ExceptionHandler(dump_json=options.json_dump) 1953 if options.json_dump: 1954 logging.disable(logging.CRITICAL) 1955 1956 options_okay = verify_and_clean_options(options) 1957 if not options_okay: 1958 parser.print_help() 1959 result = SuiteResult( 1960 RETURN_CODES.INVALID_OPTIONS, 1961 {'return_code': RETURN_CODES.INVALID_OPTIONS}) 1962 elif options.pre_check and not _should_run(options): 1963 logging.info('Lab is closed, OR build %s is blocked, OR suite ' 1964 '%s for this build has already been kicked off ' 1965 'once in past %d days.', 1966 options.test_source_build, options.name, 1967 _SEARCH_JOB_MAX_DAYS) 1968 result = SuiteResult( 1969 RETURN_CODES.ERROR, 1970 {'return_message': ("Lab is closed OR other reason" 1971 " (see code, it's complicated)")}) 1972 else: 1973 result = _run_task(options) 1974 1975 if options.json_dump: 1976 _dump_json(result.output_dict) 1977 1978 logging.info('Will return from run_suite with status: %s', 1979 RETURN_CODES.get_string(result.return_code)) 1980 return result.return_code 1981 1982 1983def _dump_json(obj): 1984 """Write obj JSON to stdout.""" 1985 output_json = json.dumps(obj, sort_keys=True) 1986 sys.stdout.write('#JSON_START#%s#JSON_END#' % output_json.strip()) 1987 1988 1989if __name__ == "__main__": 1990 sys.exit(main()) 1991