graphics_dEQP.py revision ce4ce2601e62cf5d04ed7eb06da7badda2b21c32
1# Copyright 2014 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 5import bz2 6import glob 7import json 8import logging 9import os 10import re 11import shutil 12import tempfile 13import time 14import xml.etree.ElementTree as et 15from autotest_lib.client.bin import test, utils 16from autotest_lib.client.common_lib import error 17from autotest_lib.client.cros import cros_logging, service_stopper 18from autotest_lib.client.cros.graphics import graphics_utils 19 20 21class graphics_dEQP(test.test): 22 """Run the drawElements Quality Program test suite. 23 """ 24 version = 1 25 _services = None 26 _hasty = False 27 _hasty_batch_size = 100 # Batch size in hasty mode. 28 _shard_number = 0 29 _shard_count = 1 30 _board = None 31 _cpu_type = None 32 _gpu_type = None 33 _surface = None 34 _filter = None 35 _width = 256 # Use smallest width for which all tests run/pass. 36 _height = 256 # Use smallest height for which all tests run/pass. 37 _timeout = 70 # Larger than twice the dEQP watchdog timeout at 30s. 38 _test_names = None 39 _test_names_file = None 40 _log_path = None # Location for detailed test output logs (in /tmp/). 41 _debug = False # Analyze kernel messages. 42 _log_reader = None # Reader to analyze (kernel) messages log. 43 _log_filter = re.compile('.* .* kernel:') # kernel messages filter. 44 _env = None # environment for test processes 45 DEQP_MODULES = { 46 'dEQP-EGL': 'egl', 47 'dEQP-GLES2': 'gles2', 48 'dEQP-GLES3': 'gles3', 49 'dEQP-GLES31': 'gles31', 50 'dEQP-VK': 'vk', 51 } 52 53 TEST_RESULT_FILTER = [ 54 'pass', 'notsupported', 'internalerror', 'qualitywarning', 55 'compatibilitywarning', 'skipped' 56 ] 57 58 def initialize(self): 59 self._api_helper = graphics_utils.GraphicsApiHelper() 60 self._board = utils.get_board() 61 self._cpu_type = utils.get_cpu_soc_family() 62 self._gpu_type = utils.get_gpu_family() 63 64 # deqp may depend on libraries that are present only on test images. 65 # Those libraries are installed in /usr/local. 66 self._env = os.environ.copy() 67 old_ld_path = self._env.get('LD_LIBRARY_PATH', '') 68 if old_ld_path: 69 self._env['LD_LIBRARY_PATH'] = '/usr/local/lib:/usr/local/lib64:' + old_ld_path 70 else: 71 self._env['LD_LIBRARY_PATH'] = '/usr/local/lib:/usr/local/lib64' 72 73 self._services = service_stopper.ServiceStopper(['ui', 'powerd']) 74 # Valid choices are fbo and pbuffer. The latter avoids dEQP assumptions. 75 self._surface = 'pbuffer' 76 77 def cleanup(self): 78 if self._services: 79 self._services.restore_services() 80 81 def _parse_test_results(self, result_filename, 82 test_results=None, failing_test=None): 83 """Handles result files with one or more test results. 84 85 @param result_filename: log file to parse. 86 @param test_results: Result parsed will be appended to it. 87 @param failing_test: Tests considered failed will append to it. 88 89 @return: dictionary of parsed test results. 90 """ 91 xml = '' 92 xml_start = False 93 xml_complete = False 94 xml_bad = False 95 result = 'ParseTestResultFail' 96 97 if test_results is None: 98 test_results = {} 99 100 if not os.path.isfile(result_filename): 101 return test_results 102 103 with open(result_filename) as result_file: 104 for line in result_file.readlines(): 105 # If the test terminates early, the XML will be incomplete 106 # and should not be parsed. 107 if line.startswith('#terminateTestCaseResult'): 108 result = line.strip().split()[1] 109 xml_bad = True 110 # Will only see #endTestCaseResult if the test does not 111 # terminate early. 112 elif line.startswith('#endTestCaseResult'): 113 xml_complete = True 114 elif xml_start: 115 xml += line 116 elif line.startswith('#beginTestCaseResult'): 117 # If we see another begin before an end then something is 118 # wrong. 119 if xml_start: 120 xml_bad = True 121 else: 122 xml_start = True 123 124 if xml_complete or xml_bad: 125 if xml_complete: 126 myparser = et.XMLParser(encoding='ISO-8859-1') 127 root = et.fromstring(xml, parser=myparser) 128 test_case = root.attrib['CasePath'] 129 result = root.find('Result').get('StatusCode').strip() 130 xml_complete = False 131 test_results[result] = test_results.get(result, 0) + 1 132 if (result.lower() not in self.TEST_RESULT_FILTER and 133 failing_test != None): 134 failing_test.append(test_case) 135 xml_bad = False 136 xml_start = False 137 result = 'ParseTestResultFail' 138 xml = '' 139 140 return test_results 141 142 def _load_not_passing_cases(self, test_filter): 143 """Load all test cases that are in non-'Pass' expectations.""" 144 not_passing_cases = [] 145 expectations_dir = os.path.join(self.bindir, 'expectations', 146 self._gpu_type) 147 subset_spec = '%s.*' % test_filter 148 subset_paths = glob.glob(os.path.join(expectations_dir, subset_spec)) 149 for subset_file in subset_paths: 150 # Filter against extra hasty failures only in hasty mode. 151 if (not '.Pass.bz2' in subset_file and 152 (self._hasty or '.hasty.' not in subset_file)): 153 not_passing_cases.extend( 154 bz2.BZ2File(subset_file).read().splitlines()) 155 not_passing_cases.sort() 156 return not_passing_cases 157 158 def _translate_name_to_api(self, name): 159 """Translate test_names or test_filter to api.""" 160 test_prefix = name.split('.')[0] 161 if test_prefix in self.DEQP_MODULES: 162 api = self.DEQP_MODULES[test_prefix] 163 else: 164 raise error.TestFail('Failed: Invalid test name: %s' % name) 165 return api 166 167 def _get_executable(self, api): 168 """Return the executable path of the api.""" 169 return self._api_helper.get_deqp_executable(api) 170 171 def _can_run(self, api): 172 """Check if specific api is supported in this board.""" 173 return api in self._api_helper.get_supported_apis() 174 175 def _bootstrap_new_test_cases(self, test_filter): 176 """Ask dEQP for all test cases and removes non-Pass'ing ones. 177 178 This function will query dEQP for test cases and remove all cases that 179 are not in 'Pass'ing expectations from the list. This can be used 180 incrementally updating failing/hangin tests over several runs. 181 182 @param test_filter: string like 'dEQP-GLES2.info', 'dEQP-GLES3.stress'. 183 184 @return: List of dEQP tests to run. 185 """ 186 test_cases = [] 187 api = self._translate_name_to_api(test_filter) 188 if self._can_run(api): 189 executable = self._get_executable(api) 190 else: 191 return test_cases 192 193 # Must be in the executable directory when running for it to find it's 194 # test data files! 195 os.chdir(os.path.dirname(executable)) 196 197 not_passing_cases = self._load_not_passing_cases(test_filter) 198 # We did not find passing cases in expectations. Assume everything else 199 # that is there should not be run this time. 200 expectations_dir = os.path.join(self.bindir, 'expectations', 201 self._gpu_type) 202 subset_spec = '%s.*' % test_filter 203 subset_paths = glob.glob(os.path.join(expectations_dir, subset_spec)) 204 for subset_file in subset_paths: 205 # Filter against hasty failures only in hasty mode. 206 if self._hasty or '.hasty.' not in subset_file: 207 not_passing_cases.extend( 208 bz2.BZ2File(subset_file).read().splitlines()) 209 210 # Now ask dEQP executable nicely for whole list of tests. Needs to be 211 # run in executable directory. Output file is plain text file named 212 # e.g. 'dEQP-GLES2-cases.txt'. 213 command = ('%s ' 214 '--deqp-runmode=txt-caselist ' 215 '--deqp-surface-type=%s ' 216 '--deqp-gl-config-name=rgba8888d24s8ms0 ' % (executable, 217 self._surface)) 218 logging.info('Running command %s', command) 219 utils.run(command, 220 env=self._env, 221 timeout=60, 222 stderr_is_expected=False, 223 ignore_status=False, 224 stdin=None) 225 226 # Now read this caselist file. 227 caselist_name = '%s-cases.txt' % test_filter.split('.')[0] 228 caselist_file = os.path.join(os.path.dirname(executable), caselist_name) 229 if not os.path.isfile(caselist_file): 230 raise error.TestFail('Failed: No caselist file at %s!' % 231 caselist_file) 232 233 # And remove non-Pass'ing expectations from caselist. 234 caselist = open(caselist_file).read().splitlines() 235 # Contains lines like "TEST: dEQP-GLES2.capability" 236 test_cases = [] 237 match = 'TEST: %s' % test_filter 238 logging.info('Bootstrapping test cases matching "%s".', match) 239 for case in caselist: 240 if case.startswith(match): 241 case = case.split('TEST: ')[1] 242 test_cases.append(case) 243 244 test_cases = list(set(test_cases) - set(not_passing_cases)) 245 if not test_cases: 246 raise error.TestFail('Failed: Unable to bootstrap %s!' % test_filter) 247 248 test_cases.sort() 249 return test_cases 250 251 def _get_test_cases_from_names_file(self): 252 # Assume master file comes with '-master.txt' suffix, 253 # Ex. gles2-master.txt, gles31-master.txt, vk-master.txt 254 basename = os.path.basename(self._test_names_file) 255 groups = re.match(r'(.*)-master\.txt$', basename) 256 if groups is None: 257 logging.warning('File name \'%s\' could not be recognized.' % 258 basename) 259 else: 260 api = groups.group(1) 261 if not api in self._api_helper.get_supported_apis(): 262 logging.warning('\'%s\' is not supported in this board' % api) 263 return [] 264 265 file_path = os.path.join(self.bindir, self._test_names_file) 266 test_cases = [line.rstrip('\n') for line in open(file_path)] 267 return [test for test in test_cases if test and not test.isspace()] 268 269 def _get_test_cases(self, test_filter, subset): 270 """Gets the test cases for 'Pass', 'Fail' etc. expectations. 271 272 This function supports bootstrapping of new GPU families and dEQP 273 binaries. In particular if there are not 'Pass' expectations found for 274 this GPU family it will query the dEQP executable for a list of all 275 available tests. It will then remove known non-'Pass'ing tests from 276 this list to avoid getting into hangs/crashes etc. 277 278 @param test_filter: string like 'dEQP-GLES2.info', 'dEQP-GLES3.stress'. 279 @param subset: string from 'Pass', 'Fail', 'Timeout' etc. 280 281 @return: List of dEQP tests to run. 282 """ 283 expectations_dir = os.path.join(self.bindir, 'expectations', 284 self._gpu_type) 285 subset_name = '%s.%s.bz2' % (test_filter, subset) 286 subset_path = os.path.join(expectations_dir, subset_name) 287 if not os.path.isfile(subset_path): 288 if subset == 'NotPass': 289 # TODO(ihf): Running hasty and NotPass together is an invitation 290 # for trouble (stability). Decide if it should be disallowed. 291 return self._load_not_passing_cases(test_filter) 292 if subset != 'Pass': 293 raise error.TestFail('Failed: No subset file found for %s!' % 294 subset_path) 295 # Ask dEQP for all cases and remove the failing ones. 296 return self._bootstrap_new_test_cases(test_filter) 297 298 test_cases = bz2.BZ2File(subset_path).read().splitlines() 299 if not test_cases: 300 raise error.TestFail( 301 'Failed: No test cases found in subset file %s!' % subset_path) 302 return test_cases 303 304 def run_tests_individually(self, test_cases): 305 """Runs tests as isolated from each other, but slowly. 306 307 This function runs each test case separately as a command. 308 This means a new context for each test etc. Failures will be more 309 isolated, but runtime quite high due to overhead. 310 311 @param test_cases: List of dEQP test case strings. 312 313 @return: dictionary of test results. 314 """ 315 test_results = {} 316 width = self._width 317 height = self._height 318 319 i = 0 320 for test_case in test_cases: 321 i += 1 322 logging.info('[%d/%d] TestCase: %s', i, len(test_cases), test_case) 323 result_prefix = os.path.join(self._log_path, test_case) 324 log_file = '%s.log' % result_prefix 325 debug_file = '%s.debug' % result_prefix 326 api = self._translate_name_to_api(test_case) 327 if not self._can_run(api): 328 result = 'Skipped' 329 logging.info('Skipping on %s: %s', self._gpu_type, test_case) 330 else: 331 executable = self._get_executable(api) 332 command = ('%s ' 333 '--deqp-case=%s ' 334 '--deqp-surface-type=%s ' 335 '--deqp-gl-config-name=rgba8888d24s8ms0 ' 336 '--deqp-log-images=disable ' 337 '--deqp-watchdog=enable ' 338 '--deqp-surface-width=%d ' 339 '--deqp-surface-height=%d ' 340 '--deqp-log-filename=%s' % ( 341 executable, 342 test_case, 343 self._surface, 344 width, 345 height, 346 log_file) 347 ) 348 logging.debug('Running single: %s', command) 349 350 # Must be in the executable directory when running for it to find it's 351 # test data files! 352 os.chdir(os.path.dirname(executable)) 353 354 # Must initialize because some errors don't repopulate 355 # run_result, leaving old results. 356 run_result = {} 357 start_time = time.time() 358 try: 359 run_result = utils.run(command, 360 env=self._env, 361 timeout=self._timeout, 362 stderr_is_expected=False, 363 ignore_status=True) 364 result_counts = self._parse_test_results(log_file) 365 if result_counts: 366 result = result_counts.keys()[0] 367 else: 368 result = 'Unknown' 369 except error.CmdTimeoutError: 370 result = 'TestTimeout' 371 except error.CmdError: 372 result = 'CommandFailed' 373 except Exception: 374 result = 'UnexpectedError' 375 end_time = time.time() 376 377 if self._debug: 378 # Collect debug info and save to json file. 379 output_msgs = { 380 'start_time': start_time, 381 'end_time': end_time, 382 'stdout': [], 383 'stderr': [], 384 'dmesg': [] 385 } 386 logs = self._log_reader.get_logs() 387 self._log_reader.set_start_by_current() 388 output_msgs['dmesg'] = [ 389 msg for msg in logs.splitlines() 390 if self._log_filter.match(msg) 391 ] 392 if run_result: 393 output_msgs['stdout'] = run_result.stdout.splitlines() 394 output_msgs['stderr'] = run_result.stderr.splitlines() 395 with open(debug_file, 'w') as fd: 396 json.dump( 397 output_msgs, 398 fd, 399 indent=4, 400 separators=(',', ' : '), 401 sort_keys=True) 402 403 logging.info('Result: %s', result) 404 test_results[result] = test_results.get(result, 0) + 1 405 406 return test_results 407 408 def run_tests_hasty(self, test_cases, failing_test=None): 409 """Runs tests as quickly as possible. 410 411 This function runs all the test cases, but does not isolate tests and 412 may take shortcuts/not run all tests to provide maximum coverage at 413 minumum runtime. 414 415 @param test_cases: List of dEQP test case strings. 416 @param failing_test: Test considered failed will append to it. 417 418 @return: dictionary of test results. 419 """ 420 # TODO(ihf): It saves half the test time to use 32*32 but a few tests 421 # fail as they need surfaces larger than 200*200. 422 width = self._width 423 height = self._height 424 results = {} 425 426 # All tests combined less than 1h in hasty. 427 batch_timeout = min(3600, self._timeout * self._hasty_batch_size) 428 num_test_cases = len(test_cases) 429 430 # We are dividing the number of tests into several shards but run them 431 # in smaller batches. We start and end at multiples of batch_size 432 # boundaries. 433 shard_start = self._hasty_batch_size * ( 434 (self._shard_number * (num_test_cases / self._shard_count)) / 435 self._hasty_batch_size) 436 shard_end = self._hasty_batch_size * (( 437 (self._shard_number + 1) * (num_test_cases / self._shard_count)) / 438 self._hasty_batch_size) 439 # The last shard will be slightly larger than the others. Extend it to 440 # cover all test cases avoiding rounding problems with the integer 441 # arithmetics done to compute shard_start and shard_end. 442 if self._shard_number + 1 == self._shard_count: 443 shard_end = num_test_cases 444 445 for batch in xrange(shard_start, shard_end, self._hasty_batch_size): 446 batch_to = min(batch + self._hasty_batch_size, shard_end) 447 batch_cases = '\n'.join(test_cases[batch:batch_to]) 448 # This assumes all tests in the batch are kicked off via the same 449 # executable. 450 api = self._translate_name_to_api(test_cases[batch]) 451 if not self._can_run(api): 452 logging.info('Skipping tests on %s: %s', self._gpu_type, 453 batch_cases) 454 else: 455 executable = self._get_executable(api) 456 log_file = os.path.join(self._log_path, 457 '%s_hasty_%d.log' % (self._filter, batch)) 458 command = ('%s ' 459 '--deqp-stdin-caselist ' 460 '--deqp-surface-type=%s ' 461 '--deqp-gl-config-name=rgba8888d24s8ms0 ' 462 '--deqp-log-images=disable ' 463 '--deqp-visibility=hidden ' 464 '--deqp-watchdog=enable ' 465 '--deqp-surface-width=%d ' 466 '--deqp-surface-height=%d ' 467 '--deqp-log-filename=%s' % ( 468 executable, 469 self._surface, 470 width, 471 height, 472 log_file) 473 ) 474 475 logging.info('Running tests %d...%d out of %d:\n%s\n%s', 476 batch + 1, batch_to, num_test_cases, command, 477 batch_cases) 478 479 # Must be in the executable directory when running for it to 480 # find it's test data files! 481 os.chdir(os.path.dirname(executable)) 482 483 try: 484 utils.run(command, 485 env=self._env, 486 timeout=batch_timeout, 487 stderr_is_expected=False, 488 ignore_status=False, 489 stdin=batch_cases) 490 except Exception: 491 pass 492 # We are trying to handle all errors by parsing the log file. 493 results = self._parse_test_results(log_file, results, 494 failing_test) 495 logging.info(results) 496 return results 497 498 def run_once(self, opts=None): 499 options = dict(filter='', 500 test_names='', # e.g., dEQP-GLES3.info.version, 501 # dEQP-GLES2.functional, 502 # dEQP-GLES3.accuracy.texture, etc. 503 test_names_file='', 504 timeout=self._timeout, 505 subset_to_run='Pass', # Pass, Fail, Timeout, NotPass... 506 hasty='False', 507 shard_number='0', 508 shard_count='1', 509 debug='False') 510 if opts is None: 511 opts = [] 512 options.update(utils.args_to_dict(opts)) 513 logging.info('Test Options: %s', options) 514 515 self._hasty = (options['hasty'] == 'True') 516 self._timeout = int(options['timeout']) 517 self._test_names_file = options['test_names_file'] 518 self._test_names = options['test_names'] 519 self._shard_number = int(options['shard_number']) 520 self._shard_count = int(options['shard_count']) 521 self._debug = (options['debug'] == 'True') 522 if not (self._test_names_file or self._test_names): 523 self._filter = options['filter'] 524 if not self._filter: 525 raise error.TestFail('Failed: No dEQP test filter specified') 526 527 # Some information to help post-process logs into blacklists later. 528 logging.info('ChromeOS BOARD = %s', self._board) 529 logging.info('ChromeOS CPU family = %s', self._cpu_type) 530 logging.info('ChromeOS GPU family = %s', self._gpu_type) 531 532 # Create a place to put detailed test output logs. 533 filter_name = self._filter or os.path.basename(self._test_names_file) 534 logging.info('dEQP test filter = %s', filter_name) 535 self._log_path = os.path.join(tempfile.gettempdir(), '%s-logs' % 536 filter_name) 537 shutil.rmtree(self._log_path, ignore_errors=True) 538 os.mkdir(self._log_path) 539 540 self._services.stop_services() 541 # Load either tests specified by test_names_file, test_names or filter. 542 test_cases = [] 543 if self._test_names_file: 544 test_cases = self._get_test_cases_from_names_file() 545 elif self._test_names: 546 test_cases = [] 547 for name in self._test_names.split(','): 548 test_cases.extend(self._get_test_cases(name, 'Pass')) 549 elif self._filter: 550 test_cases = self._get_test_cases(self._filter, 551 options['subset_to_run']) 552 553 if self._debug: 554 # LogReader works on /var/log/messages by default. 555 self._log_reader = cros_logging.LogReader() 556 self._log_reader.set_start_by_current() 557 558 test_results = {} 559 if self._hasty: 560 logging.info('Running in hasty mode.') 561 failing_test = [] 562 test_results = self.run_tests_hasty(test_cases, failing_test) 563 564 logging.info("Failing Tests: %s", str(failing_test)) 565 else: 566 logging.info('Running each test individually.') 567 test_results = self.run_tests_individually(test_cases) 568 569 logging.info('Test results:') 570 logging.info(test_results) 571 self.write_perf_keyval(test_results) 572 573 test_count = 0 574 test_failures = 0 575 test_passes = 0 576 test_skipped = 0 577 for result in test_results: 578 test_count += test_results[result] 579 if result.lower() in ['pass']: 580 test_passes += test_results[result] 581 if result.lower() not in self.TEST_RESULT_FILTER: 582 test_failures += test_results[result] 583 if result.lower() in ['skipped']: 584 test_skipped += test_results[result] 585 # The text "Completed all tests." is used by the process_log.py script 586 # and should always appear at the end of a completed test run. 587 logging.info( 588 'Completed all tests. Saw %d tests, %d passes and %d failures.', 589 test_count, test_passes, test_failures) 590 591 if self._filter and test_count == 0 and options[ 592 'subset_to_run'] != 'NotPass': 593 logging.warning('No test cases found for filter: %s!', self._filter) 594 595 if test_failures: 596 raise error.TestFail('Failed: on %s %d/%d tests failed.' % 597 (self._gpu_type, test_failures, test_count)) 598 if test_skipped > 0: 599 raise error.TestFail('Failed: on %s %d tests skipped, %d passes' % 600 (self._gpu_type, test_skipped, test_passes)) 601