1# -*- coding: utf-8 -*- 2# Copyright 2013 The ChromiumOS Authors 3# Use of this source code is governed by a BSD-style license that can be 4# found in the LICENSE file. 5 6"""Module to deal with result cache.""" 7 8 9import collections 10import glob 11import hashlib 12import heapq 13import json 14import os 15import pickle 16import re 17import tempfile 18 19from cros_utils import command_executer 20from cros_utils import misc 21from image_checksummer import ImageChecksummer 22import results_report 23import test_flag 24 25 26SCRATCH_DIR = os.path.expanduser("~/cros_scratch") 27RESULTS_FILE = "results.pickle" 28MACHINE_FILE = "machine.txt" 29AUTOTEST_TARBALL = "autotest.tbz2" 30RESULTS_TARBALL = "results.tbz2" 31PERF_RESULTS_FILE = "perf-results.txt" 32CACHE_KEYS_FILE = "cache_keys.txt" 33 34 35class PidVerificationError(Exception): 36 """Error of perf PID verification in per-process mode.""" 37 38 39class PerfDataReadError(Exception): 40 """Error of reading a perf.data header.""" 41 42 43class Result(object): 44 """Class for holding the results of a single test run. 45 46 This class manages what exactly is stored inside the cache without knowing 47 what the key of the cache is. For runs with perf, it stores perf.data, 48 perf.report, etc. The key generation is handled by the ResultsCache class. 49 """ 50 51 def __init__(self, logger, label, log_level, machine, cmd_exec=None): 52 self.chromeos_root = label.chromeos_root 53 self._logger = logger 54 self.ce = cmd_exec or command_executer.GetCommandExecuter( 55 self._logger, log_level=log_level 56 ) 57 self.temp_dir = None 58 self.label = label 59 self.results_dir = None 60 self.log_level = log_level 61 self.machine = machine 62 self.perf_data_files = [] 63 self.perf_report_files = [] 64 self.results_file = [] 65 self.turbostat_log_file = "" 66 self.cpustats_log_file = "" 67 self.cpuinfo_file = "" 68 self.top_log_file = "" 69 self.wait_time_log_file = "" 70 self.chrome_version = "" 71 self.err = None 72 self.chroot_results_dir = "" 73 self.test_name = "" 74 self.keyvals = None 75 self.board = None 76 self.suite = None 77 self.cwp_dso = "" 78 self.retval = None 79 self.out = None 80 self.top_cmds = [] 81 82 def GetTopCmds(self): 83 """Get the list of top commands consuming CPU on the machine.""" 84 return self.top_cmds 85 86 def FormatStringTopCommands(self): 87 """Get formatted string of top commands. 88 89 Get the formatted string with top commands consuming CPU on DUT machine. 90 Number of "non-chrome" processes in the list is limited to 5. 91 """ 92 format_list = [ 93 "Top commands with highest CPU usage:", 94 # Header. 95 "%20s %9s %6s %s" % ("COMMAND", "AVG CPU%", "COUNT", "HIGHEST 5"), 96 "-" * 50, 97 ] 98 if self.top_cmds: 99 # After switching to top processes we have to expand the list since there 100 # will be a lot of 'chrome' processes (up to 10, sometimes more) in the 101 # top. 102 # Let's limit the list size by the number of non-chrome processes. 103 limit_of_non_chrome_procs = 5 104 num_of_non_chrome_procs = 0 105 for topcmd in self.top_cmds: 106 print_line = "%20s %9.2f %6s %s" % ( 107 topcmd["cmd"], 108 topcmd["cpu_use_avg"], 109 topcmd["count"], 110 topcmd["top5_cpu_use"], 111 ) 112 format_list.append(print_line) 113 if not topcmd["cmd"].startswith("chrome"): 114 num_of_non_chrome_procs += 1 115 if num_of_non_chrome_procs >= limit_of_non_chrome_procs: 116 break 117 else: 118 format_list.append("[NO DATA FROM THE TOP LOG]") 119 format_list.append("-" * 50) 120 return "\n".join(format_list) 121 122 def CopyFilesTo(self, dest_dir, files_to_copy): 123 file_index = 0 124 for file_to_copy in files_to_copy: 125 if not os.path.isdir(dest_dir): 126 command = "mkdir -p %s" % dest_dir 127 self.ce.RunCommand(command) 128 dest_file = os.path.join( 129 dest_dir, 130 ("%s.%s" % (os.path.basename(file_to_copy), file_index)), 131 ) 132 ret = self.ce.CopyFiles(file_to_copy, dest_file, recursive=False) 133 if ret: 134 raise IOError("Could not copy results file: %s" % file_to_copy) 135 file_index += 1 136 137 def CopyResultsTo(self, dest_dir): 138 self.CopyFilesTo(dest_dir, self.results_file) 139 self.CopyFilesTo(dest_dir, self.perf_data_files) 140 self.CopyFilesTo(dest_dir, self.perf_report_files) 141 extra_files = [] 142 if self.top_log_file: 143 extra_files.append(self.top_log_file) 144 if self.cpuinfo_file: 145 extra_files.append(self.cpuinfo_file) 146 if extra_files: 147 self.CopyFilesTo(dest_dir, extra_files) 148 if self.results_file or self.perf_data_files or self.perf_report_files: 149 self._logger.LogOutput("Results files stored in %s." % dest_dir) 150 151 def CompressResultsTo(self, dest_dir): 152 tarball = os.path.join(self.results_dir, RESULTS_TARBALL) 153 # Test_that runs hold all output under TEST_NAME_HASHTAG/results/, 154 # while tast runs hold output under TEST_NAME/. 155 # Both ensure to be unique. 156 result_dir_name = self.test_name if self.suite == "tast" else "results" 157 results_dir = self.FindFilesInResultsDir( 158 "-name %s" % result_dir_name 159 ).split("\n")[0] 160 161 if not results_dir: 162 self._logger.LogOutput( 163 "WARNING: No results dir matching %r found" % result_dir_name 164 ) 165 return 166 167 self.CreateTarball(results_dir, tarball) 168 self.CopyFilesTo(dest_dir, [tarball]) 169 if results_dir: 170 self._logger.LogOutput( 171 "Results files compressed into %s." % dest_dir 172 ) 173 174 def GetNewKeyvals(self, keyvals_dict): 175 # Initialize 'units' dictionary. 176 units_dict = {} 177 for k in keyvals_dict: 178 units_dict[k] = "" 179 results_files = self.GetDataMeasurementsFiles() 180 for f in results_files: 181 # Make sure we can find the results file 182 if os.path.exists(f): 183 data_filename = f 184 else: 185 # Otherwise get the base filename and create the correct 186 # path for it. 187 _, f_base = misc.GetRoot(f) 188 data_filename = misc.GetOutsideChrootPath( 189 self.chromeos_root, 190 os.path.join("/tmp", self.temp_dir, f_base), 191 ) 192 if data_filename.find(".json") > 0: 193 raw_dict = dict() 194 if os.path.exists(data_filename): 195 with open( 196 data_filename, "r", encoding="utf-8" 197 ) as data_file: 198 raw_dict = json.load(data_file) 199 200 if "charts" in raw_dict: 201 raw_dict = raw_dict["charts"] 202 for k1 in raw_dict: 203 field_dict = raw_dict[k1] 204 for k2 in field_dict: 205 result_dict = field_dict[k2] 206 key = k1 + "__" + k2 207 if "value" in result_dict: 208 keyvals_dict[key] = result_dict["value"] 209 elif "values" in result_dict: 210 values = result_dict["values"] 211 if ( 212 "type" in result_dict 213 and result_dict["type"] 214 == "list_of_scalar_values" 215 and values 216 and values != "null" 217 ): 218 keyvals_dict[key] = sum(values) / float( 219 len(values) 220 ) 221 else: 222 keyvals_dict[key] = values 223 units_dict[key] = result_dict["units"] 224 else: 225 if os.path.exists(data_filename): 226 with open( 227 data_filename, "r", encoding="utf-8" 228 ) as data_file: 229 lines = data_file.readlines() 230 for line in lines: 231 tmp_dict = json.loads(line) 232 graph_name = tmp_dict["graph"] 233 graph_str = ( 234 (graph_name + "__") if graph_name else "" 235 ) 236 key = graph_str + tmp_dict["description"] 237 keyvals_dict[key] = tmp_dict["value"] 238 units_dict[key] = tmp_dict["units"] 239 240 return keyvals_dict, units_dict 241 242 def AppendTelemetryUnits(self, keyvals_dict, units_dict): 243 """keyvals_dict is the dict of key-value used to generate Crosperf reports. 244 245 units_dict is a dictionary of the units for the return values in 246 keyvals_dict. We need to associate the units with the return values, 247 for Telemetry tests, so that we can include the units in the reports. 248 This function takes each value in keyvals_dict, finds the corresponding 249 unit in the units_dict, and replaces the old value with a list of the 250 old value and the units. This later gets properly parsed in the 251 ResultOrganizer class, for generating the reports. 252 """ 253 254 results_dict = {} 255 for k in keyvals_dict: 256 # We don't want these lines in our reports; they add no useful data. 257 if not k or k == "telemetry_Crosperf": 258 continue 259 val = keyvals_dict[k] 260 units = units_dict[k] 261 new_val = [val, units] 262 results_dict[k] = new_val 263 return results_dict 264 265 def GetKeyvals(self): 266 results_in_chroot = misc.GetOutsideChrootPath( 267 self.chromeos_root, "/tmp" 268 ) 269 if not self.temp_dir: 270 self.temp_dir = tempfile.mkdtemp(dir=results_in_chroot) 271 command = f"cp -r {self.results_dir}/* {self.temp_dir}" 272 self.ce.RunCommand(command, print_to_console=False) 273 274 tmp_dir_in_chroot = misc.GetInsideChrootPath( 275 self.chromeos_root, self.temp_dir 276 ) 277 command = "./generate_test_report --no-color --csv %s" % ( 278 tmp_dir_in_chroot 279 ) 280 _, out, _ = self.ce.ChrootRunCommandWOutput( 281 self.chromeos_root, command, print_to_console=False 282 ) 283 keyvals_dict = {} 284 for line in out.splitlines(): 285 tokens = re.split("=|,", line) 286 key = tokens[-2] 287 if key.startswith(tmp_dir_in_chroot): 288 key = key[len(tmp_dir_in_chroot) + 1 :] 289 value = tokens[-1] 290 keyvals_dict[key] = value 291 292 # Check to see if there is a perf_measurements file and get the 293 # data from it if so. 294 keyvals_dict, units_dict = self.GetNewKeyvals(keyvals_dict) 295 if self.suite == "telemetry_Crosperf": 296 # For telemtry_Crosperf results, append the units to the return 297 # results, for use in generating the reports. 298 keyvals_dict = self.AppendTelemetryUnits(keyvals_dict, units_dict) 299 return keyvals_dict 300 301 def GetSamples(self): 302 actual_samples = 0 303 for perf_data_file in self.perf_data_files: 304 chroot_perf_data_file = misc.GetInsideChrootPath( 305 self.chromeos_root, perf_data_file 306 ) 307 perf_path = misc.GetOutsideChrootPath( 308 self.chromeos_root, "/usr/bin/perf" 309 ) 310 perf_file = "/usr/sbin/perf" 311 if os.path.exists(perf_path): 312 perf_file = "/usr/bin/perf" 313 314 # For each perf.data, we want to collect sample count for specific DSO. 315 # We specify exact match for known DSO type, and every sample for `all`. 316 exact_match = "" 317 if self.cwp_dso == "all": 318 exact_match = "" 319 elif self.cwp_dso == "chrome": 320 exact_match = "chrome" 321 elif self.cwp_dso == "kallsyms": 322 exact_match = "[kernel.kallsyms]" 323 else: 324 # This will need to be updated once there are more DSO types supported, 325 # if user want an exact match for the field they want. 326 exact_match = self.cwp_dso 327 328 command = ( 329 f"{perf_file} report -n -s dso -i " 330 f"{chroot_perf_data_file} 2> /dev/null" 331 ) 332 _, result, _ = self.ce.ChrootRunCommandWOutput( 333 self.chromeos_root, command 334 ) 335 # Accumulate the sample count for all matched fields. 336 # Each line looks like this: 337 # 45.42% 237210 chrome 338 # And we want the second number which is the sample count. 339 samples = 0 340 try: 341 for line in result.split("\n"): 342 attr = line.split() 343 if len(attr) == 3 and "%" in attr[0]: 344 if exact_match and exact_match != attr[2]: 345 continue 346 samples += int(attr[1]) 347 except: 348 raise RuntimeError("Cannot parse perf dso result") 349 350 actual_samples += samples 351 352 # Remove idle cycles from the accumulated sample count. 353 perf_report_file = f"{perf_data_file}.report" 354 if not os.path.exists(perf_report_file): 355 raise RuntimeError( 356 f"Missing perf report file: {perf_report_file}" 357 ) 358 359 idle_functions = { 360 "[kernel.kallsyms]": ( 361 "intel_idle", 362 "arch_cpu_idle", 363 "intel_idle", 364 "cpu_startup_entry", 365 "default_idle", 366 "cpu_idle_loop", 367 "do_idle", 368 "cpuidle_enter_state", 369 ), 370 } 371 idle_samples = 0 372 373 with open(perf_report_file, encoding="utf-8") as f: 374 try: 375 for line in f: 376 line = line.strip() 377 if not line or line[0] == "#": 378 continue 379 # Each line has the following fields, 380 # pylint: disable=line-too-long 381 # Overhead Samples Command Shared Object Symbol 382 # pylint: disable=line-too-long 383 # 1.48% 60 swapper [kernel.kallsyms] [k] intel_idle 384 # pylint: disable=line-too-long 385 # 0.00% 1 shill libshill-net.so [.] std::__1::vector<unsigned char, std::__1::allocator<unsigned char> >::vector<unsigned char const*> 386 _, samples, _, dso, _, function = line.split(None, 5) 387 388 if ( 389 dso in idle_functions 390 and function in idle_functions[dso] 391 ): 392 if self.log_level != "verbose": 393 self._logger.LogOutput( 394 "Removing %s samples from %s in %s" 395 % (samples, function, dso) 396 ) 397 idle_samples += int(samples) 398 except: 399 raise RuntimeError("Cannot parse perf report") 400 actual_samples -= idle_samples 401 return [actual_samples, "samples"] 402 403 def GetResultsDir(self): 404 if self.suite == "tast": 405 mo = re.search(r"Writing results to (\S+)", self.out) 406 else: 407 mo = re.search(r"Results placed in (\S+)", self.out) 408 if mo: 409 result = mo.group(1) 410 return result 411 raise RuntimeError("Could not find results directory.") 412 413 def FindFilesInResultsDir(self, find_args): 414 if not self.results_dir: 415 return "" 416 417 command = "find %s %s" % (self.results_dir, find_args) 418 ret, out, _ = self.ce.RunCommandWOutput(command, print_to_console=False) 419 if ret: 420 raise RuntimeError("Could not run find command!") 421 return out 422 423 def GetResultsFile(self): 424 if self.suite == "telemetry_Crosperf": 425 return self.FindFilesInResultsDir( 426 "-name histograms.json" 427 ).splitlines() 428 return self.FindFilesInResultsDir( 429 "-name results-chart.json" 430 ).splitlines() 431 432 def GetPerfDataFiles(self): 433 return self.FindFilesInResultsDir("-name perf.data").splitlines() 434 435 def GetPerfReportFiles(self): 436 return self.FindFilesInResultsDir("-name perf.data.report").splitlines() 437 438 def GetDataMeasurementsFiles(self): 439 result = self.FindFilesInResultsDir( 440 "-name perf_measurements" 441 ).splitlines() 442 if not result: 443 if self.suite == "telemetry_Crosperf": 444 result = self.FindFilesInResultsDir( 445 "-name histograms.json" 446 ).splitlines() 447 else: 448 result = self.FindFilesInResultsDir( 449 "-name results-chart.json" 450 ).splitlines() 451 return result 452 453 def GetTurbostatFile(self): 454 """Get turbostat log path string.""" 455 return self.FindFilesInResultsDir("-name turbostat.log").split("\n")[0] 456 457 def GetCpustatsFile(self): 458 """Get cpustats log path string.""" 459 return self.FindFilesInResultsDir("-name cpustats.log").split("\n")[0] 460 461 def GetCpuinfoFile(self): 462 """Get cpustats log path string.""" 463 return self.FindFilesInResultsDir("-name cpuinfo.log").split("\n")[0] 464 465 def GetTopFile(self): 466 """Get cpustats log path string.""" 467 return self.FindFilesInResultsDir("-name top.log").split("\n")[0] 468 469 def GetWaitTimeFile(self): 470 """Get wait time log path string.""" 471 return self.FindFilesInResultsDir("-name wait_time.log").split("\n")[0] 472 473 def _CheckDebugPath(self, option, path): 474 out_chroot_path = misc.GetOutsideChrootPath(self.chromeos_root, path) 475 if os.path.exists(out_chroot_path): 476 if option == "kallsyms": 477 path = os.path.join(path, "System.map-*") 478 return "--" + option + " " + path 479 else: 480 print( 481 "** WARNING **: --%s option not applied, %s does not exist" 482 % (option, out_chroot_path) 483 ) 484 return "" 485 486 def GeneratePerfReportFiles(self): 487 perf_report_files = [] 488 for perf_data_file in self.perf_data_files: 489 # Generate a perf.report and store it side-by-side with the perf.data 490 # file. 491 chroot_perf_data_file = misc.GetInsideChrootPath( 492 self.chromeos_root, perf_data_file 493 ) 494 perf_report_file = "%s.report" % perf_data_file 495 if os.path.exists(perf_report_file): 496 raise RuntimeError( 497 "Perf report file already exists: %s" % perf_report_file 498 ) 499 chroot_perf_report_file = misc.GetInsideChrootPath( 500 self.chromeos_root, perf_report_file 501 ) 502 perf_path = misc.GetOutsideChrootPath( 503 self.chromeos_root, "/usr/bin/perf" 504 ) 505 506 perf_file = "/usr/sbin/perf" 507 if os.path.exists(perf_path): 508 perf_file = "/usr/bin/perf" 509 510 debug_path = self.label.debug_path 511 512 if debug_path: 513 symfs = "--symfs " + debug_path 514 vmlinux = "--vmlinux " + os.path.join( 515 debug_path, "usr", "lib", "debug", "boot", "vmlinux" 516 ) 517 kallsyms = "" 518 print( 519 "** WARNING **: --kallsyms option not applied, no System.map-* " 520 "for downloaded image." 521 ) 522 else: 523 if self.label.image_type != "local": 524 print( 525 "** WARNING **: Using local debug info in /build, this may " 526 "not match the downloaded image." 527 ) 528 build_path = os.path.join("/build", self.board) 529 symfs = self._CheckDebugPath("symfs", build_path) 530 vmlinux_path = os.path.join( 531 build_path, "usr/lib/debug/boot/vmlinux" 532 ) 533 vmlinux = self._CheckDebugPath("vmlinux", vmlinux_path) 534 kallsyms_path = os.path.join(build_path, "boot") 535 kallsyms = self._CheckDebugPath("kallsyms", kallsyms_path) 536 537 command = "%s report -n %s %s %s -i %s --stdio > %s" % ( 538 perf_file, 539 symfs, 540 vmlinux, 541 kallsyms, 542 chroot_perf_data_file, 543 chroot_perf_report_file, 544 ) 545 if self.log_level != "verbose": 546 self._logger.LogOutput( 547 "Generating perf report...\nCMD: %s" % command 548 ) 549 exit_code = self.ce.ChrootRunCommand(self.chromeos_root, command) 550 if exit_code == 0: 551 if self.log_level != "verbose": 552 self._logger.LogOutput( 553 "Perf report generated successfully." 554 ) 555 else: 556 raise RuntimeError( 557 "Perf report not generated correctly. CMD: %s" % command 558 ) 559 560 # Add a keyval to the dictionary for the events captured. 561 perf_report_files.append( 562 misc.GetOutsideChrootPath( 563 self.chromeos_root, chroot_perf_report_file 564 ) 565 ) 566 return perf_report_files 567 568 def GatherPerfResults(self): 569 report_id = 0 570 for perf_report_file in self.perf_report_files: 571 with open(perf_report_file, "r", encoding="utf-8") as f: 572 report_contents = f.read() 573 for group in re.findall( 574 r"Events: (\S+) (\S+)", report_contents 575 ): 576 num_events = group[0] 577 event_name = group[1] 578 key = "perf_%s_%s" % (report_id, event_name) 579 value = str(misc.UnitToNumber(num_events)) 580 self.keyvals[key] = value 581 582 def PopulateFromRun(self, out, err, retval, test, suite, cwp_dso): 583 self.board = self.label.board 584 self.out = out 585 self.err = err 586 self.retval = retval 587 self.test_name = test 588 self.suite = suite 589 self.cwp_dso = cwp_dso 590 self.chroot_results_dir = self.GetResultsDir() 591 self.results_dir = misc.GetOutsideChrootPath( 592 self.chromeos_root, self.chroot_results_dir 593 ) 594 self.results_file = self.GetResultsFile() 595 self.perf_data_files = self.GetPerfDataFiles() 596 # Include all perf.report data in table. 597 self.perf_report_files = self.GeneratePerfReportFiles() 598 self.turbostat_log_file = self.GetTurbostatFile() 599 self.cpustats_log_file = self.GetCpustatsFile() 600 self.cpuinfo_file = self.GetCpuinfoFile() 601 self.top_log_file = self.GetTopFile() 602 self.wait_time_log_file = self.GetWaitTimeFile() 603 # TODO(asharif): Do something similar with perf stat. 604 605 # Grab keyvals from the directory. 606 self.ProcessResults() 607 608 def ProcessChartResults(self): 609 # Open and parse the json results file generated by telemetry/test_that. 610 if not self.results_file: 611 raise IOError("No results file found.") 612 filename = self.results_file[0] 613 if not filename.endswith(".json"): 614 raise IOError( 615 "Attempt to call json on non-json file: %s" % filename 616 ) 617 if not os.path.exists(filename): 618 raise IOError("%s does not exist" % filename) 619 620 keyvals = {} 621 with open(filename, "r", encoding="utf-8") as f: 622 raw_dict = json.load(f) 623 if "charts" in raw_dict: 624 raw_dict = raw_dict["charts"] 625 for k, field_dict in raw_dict.items(): 626 for item in field_dict: 627 keyname = k + "__" + item 628 value_dict = field_dict[item] 629 if "value" in value_dict: 630 result = value_dict["value"] 631 elif "values" in value_dict: 632 values = value_dict["values"] 633 if not values: 634 continue 635 if ( 636 "type" in value_dict 637 and value_dict["type"] == "list_of_scalar_values" 638 and values != "null" 639 ): 640 result = sum(values) / float(len(values)) 641 else: 642 result = values 643 else: 644 continue 645 units = value_dict["units"] 646 new_value = [result, units] 647 keyvals[keyname] = new_value 648 return keyvals 649 650 def ProcessTurbostatResults(self): 651 """Given turbostat_log_file non-null parse cpu stats from file. 652 653 Returns: 654 Dictionary of 'cpufreq', 'cputemp' where each 655 includes dictionary 'all': [list_of_values] 656 657 Example of the output of turbostat_log. 658 ---------------------- 659 CPU Avg_MHz Busy% Bzy_MHz TSC_MHz IRQ CoreTmp 660 - 329 12.13 2723 2393 10975 77 661 0 336 12.41 2715 2393 6328 77 662 2 323 11.86 2731 2393 4647 69 663 CPU Avg_MHz Busy% Bzy_MHz TSC_MHz IRQ CoreTmp 664 - 1940 67.46 2884 2393 39920 83 665 0 1827 63.70 2877 2393 21184 83 666 """ 667 cpustats = {} 668 read_data = "" 669 with open(self.turbostat_log_file, encoding="utf-8") as f: 670 read_data = f.readlines() 671 672 if not read_data: 673 self._logger.LogOutput("WARNING: Turbostat output file is empty.") 674 return {} 675 676 # First line always contains the header. 677 stats = read_data[0].split() 678 679 # Mandatory parameters. 680 if "CPU" not in stats: 681 self._logger.LogOutput( 682 "WARNING: Missing data for CPU# in Turbostat output." 683 ) 684 return {} 685 if "Bzy_MHz" not in stats: 686 self._logger.LogOutput( 687 "WARNING: Missing data for Bzy_MHz in Turbostat output." 688 ) 689 return {} 690 cpu_index = stats.index("CPU") 691 cpufreq_index = stats.index("Bzy_MHz") 692 cpufreq = cpustats.setdefault("cpufreq", {"all": []}) 693 694 # Optional parameters. 695 cputemp_index = -1 696 if "CoreTmp" in stats: 697 cputemp_index = stats.index("CoreTmp") 698 cputemp = cpustats.setdefault("cputemp", {"all": []}) 699 700 # Parse data starting from the second line ignoring repeating headers. 701 for st in read_data[1:]: 702 # Data represented by int or float separated by spaces. 703 numbers = st.split() 704 if not all( 705 word.replace(".", "", 1).isdigit() for word in numbers[1:] 706 ): 707 # Skip the line if data mismatch. 708 continue 709 if numbers[cpu_index] != "-": 710 # Ignore Core-specific statistics which starts with Core number. 711 # Combined statistics for all core has "-" CPU identifier. 712 continue 713 714 cpufreq["all"].append(int(numbers[cpufreq_index])) 715 if cputemp_index != -1: 716 cputemp["all"].append(int(numbers[cputemp_index])) 717 return cpustats 718 719 def ProcessTopResults(self): 720 """Given self.top_log_file process top log data. 721 722 Returns: 723 List of dictionaries with the following keyvals: 724 'cmd': command name (string), 725 'cpu_use_avg': average cpu usage (float), 726 'count': number of occurrences (int), 727 'top5_cpu_use': up to 5 highest cpu usages (descending list of floats) 728 729 Example of the top log: 730 PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND 731 4102 chronos 12 -8 3454472 238300 118188 R 41.8 6.1 0:08.37 chrome 732 375 root 0 -20 0 0 0 S 5.9 0.0 0:00.17 kworker 733 617 syslog 20 0 25332 8372 7888 S 5.9 0.2 0:00.77 systemd 734 735 PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND 736 5745 chronos 20 0 5438580 139328 67988 R 122.8 3.6 0:04.26 chrome 737 912 root -51 0 0 0 0 S 2.0 0.0 0:01.04 irq/cro 738 121 root 20 0 0 0 0 S 1.0 0.0 0:00.45 spi5 739 """ 740 all_data = "" 741 with open(self.top_log_file, encoding="utf-8") as f: 742 all_data = f.read() 743 744 if not all_data: 745 self._logger.LogOutput("WARNING: Top log file is empty.") 746 return [] 747 748 top_line_regex = re.compile( 749 r""" 750 ^\s*(?P<pid>\d+)\s+ # Group 1: PID 751 \S+\s+\S+\s+-?\d+\s+ # Ignore: user, prio, nice 752 \d+\s+\d+\s+\d+\s+ # Ignore: virt/res/shared mem 753 \S+\s+ # Ignore: state 754 (?P<cpu_use>\d+\.\d+)\s+ # Group 2: CPU usage 755 \d+\.\d+\s+\d+:\d+\.\d+\s+ # Ignore: mem usage, time 756 (?P<cmd>\S+)$ # Group 3: command 757 """, 758 re.VERBOSE, 759 ) 760 # Page represents top log data per one measurement within time interval 761 # 'top_interval'. 762 # Pages separated by empty line. 763 pages = all_data.split("\n\n") 764 # Snapshots are structured representation of the pages. 765 snapshots = [] 766 for page in pages: 767 if not page: 768 continue 769 770 # Snapshot list will contain all processes (command duplicates are 771 # allowed). 772 snapshot = [] 773 for line in page.splitlines(): 774 match = top_line_regex.match(line) 775 if match: 776 # Top line is valid, collect data. 777 process = { 778 # NOTE: One command may be represented by multiple processes. 779 "cmd": match.group("cmd"), 780 "pid": match.group("pid"), 781 "cpu_use": float(match.group("cpu_use")), 782 } 783 784 # Filter out processes with 0 CPU usage and top command. 785 if process["cpu_use"] > 0 and process["cmd"] != "top": 786 snapshot.append(process) 787 788 # If page contained meaningful data add snapshot to the list. 789 if snapshot: 790 snapshots.append(snapshot) 791 792 # Define threshold of CPU usage when Chrome is busy, i.e. benchmark is 793 # running. 794 # Ideally it should be 100% but it will be hardly reachable with 1 core. 795 # Statistics on DUT with 2-6 cores shows that chrome load of 100%, 95% and 796 # 90% equally occurs in 72-74% of all top log snapshots. 797 # Further decreasing of load threshold leads to a shifting percent of 798 # "high load" snapshots which might include snapshots when benchmark is 799 # not running. 800 # On 1-core DUT 90% chrome cpu load occurs in 55%, 95% in 33% and 100% in 2% 801 # of snapshots accordingly. 802 # Threshold of "high load" is reduced to 70% (from 90) when we switched to 803 # topstats per process. From experiment data the rest 20% are distributed 804 # among other chrome processes. 805 CHROME_HIGH_CPU_LOAD = 70 806 # Number of snapshots where chrome is heavily used. 807 high_load_snapshots = 0 808 # Total CPU use per process in ALL active snapshots. 809 cmd_total_cpu_use = collections.defaultdict(float) 810 # Top CPU usages per command. 811 cmd_top5_cpu_use = collections.defaultdict(list) 812 # List of Top Commands to be returned. 813 topcmds = [] 814 815 for snapshot_processes in snapshots: 816 # CPU usage per command, per PID in one snapshot. 817 cmd_cpu_use_per_snapshot = collections.defaultdict(dict) 818 for process in snapshot_processes: 819 cmd = process["cmd"] 820 cpu_use = process["cpu_use"] 821 pid = process["pid"] 822 cmd_cpu_use_per_snapshot[cmd][pid] = cpu_use 823 824 # Chrome processes, pid: cpu_usage. 825 chrome_processes = cmd_cpu_use_per_snapshot.get("chrome", {}) 826 chrome_cpu_use_list = chrome_processes.values() 827 828 if ( 829 chrome_cpu_use_list 830 and max(chrome_cpu_use_list) > CHROME_HIGH_CPU_LOAD 831 ): 832 # CPU usage of any of the "chrome" processes exceeds "High load" 833 # threshold which means DUT is busy running a benchmark. 834 high_load_snapshots += 1 835 for cmd, cpu_use_per_pid in cmd_cpu_use_per_snapshot.items(): 836 for pid, cpu_use in cpu_use_per_pid.items(): 837 # Append PID to the name of the command. 838 cmd_with_pid = cmd + "-" + pid 839 cmd_total_cpu_use[cmd_with_pid] += cpu_use 840 841 # Add cpu_use into command top cpu usages, sorted in descending 842 # order. 843 heapq.heappush( 844 cmd_top5_cpu_use[cmd_with_pid], round(cpu_use, 1) 845 ) 846 847 for consumer, usage in sorted( 848 cmd_total_cpu_use.items(), key=lambda x: x[1], reverse=True 849 ): 850 # Iterate through commands by descending order of total CPU usage. 851 topcmd = { 852 "cmd": consumer, 853 "cpu_use_avg": usage / high_load_snapshots, 854 "count": len(cmd_top5_cpu_use[consumer]), 855 "top5_cpu_use": heapq.nlargest(5, cmd_top5_cpu_use[consumer]), 856 } 857 topcmds.append(topcmd) 858 859 return topcmds 860 861 def ProcessCpustatsResults(self): 862 """Given cpustats_log_file non-null parse cpu data from file. 863 864 Returns: 865 Dictionary of 'cpufreq', 'cputemp' where each 866 includes dictionary of parameter: [list_of_values] 867 868 Example of cpustats.log output. 869 ---------------------- 870 /sys/devices/system/cpu/cpu0/cpufreq/cpuinfo_cur_freq 1512000 871 /sys/devices/system/cpu/cpu2/cpufreq/cpuinfo_cur_freq 2016000 872 little-cpu 41234 873 big-cpu 51234 874 875 If cores share the same policy their frequencies may always match 876 on some devices. 877 To make report concise we should eliminate redundancy in the output. 878 Function removes cpuN data if it duplicates data from other cores. 879 """ 880 881 cpustats = {} 882 read_data = "" 883 with open(self.cpustats_log_file, encoding="utf-8") as f: 884 read_data = f.readlines() 885 886 if not read_data: 887 self._logger.LogOutput("WARNING: Cpustats output file is empty.") 888 return {} 889 890 cpufreq_regex = re.compile(r"^[/\S]+/(cpu\d+)/[/\S]+\s+(\d+)$") 891 cputemp_regex = re.compile(r"^([^/\s]+)\s+(\d+)$") 892 893 for st in read_data: 894 match = cpufreq_regex.match(st) 895 if match: 896 cpu = match.group(1) 897 # CPU frequency comes in kHz. 898 freq_khz = int(match.group(2)) 899 freq_mhz = freq_khz / 1000 900 # cpufreq represents a dictionary with CPU frequency-related 901 # data from cpustats.log. 902 cpufreq = cpustats.setdefault("cpufreq", {}) 903 cpu_n_freq = cpufreq.setdefault(cpu, []) 904 cpu_n_freq.append(freq_mhz) 905 else: 906 match = cputemp_regex.match(st) 907 if match: 908 therm_type = match.group(1) 909 # The value is int, uCelsius unit. 910 temp_uc = float(match.group(2)) 911 # Round to XX.X float. 912 temp_c = round(temp_uc / 1000, 1) 913 # cputemp represents a dictionary with temperature measurements 914 # from cpustats.log. 915 cputemp = cpustats.setdefault("cputemp", {}) 916 therm_type = cputemp.setdefault(therm_type, []) 917 therm_type.append(temp_c) 918 919 # Remove duplicate statistics from cpustats. 920 pruned_stats = {} 921 for cpukey, cpuparam in cpustats.items(): 922 # Copy 'cpufreq' and 'cputemp'. 923 pruned_params = pruned_stats.setdefault(cpukey, {}) 924 for paramkey, paramvalue in sorted(cpuparam.items()): 925 # paramvalue is list of all measured data. 926 if paramvalue not in pruned_params.values(): 927 pruned_params[paramkey] = paramvalue 928 929 return pruned_stats 930 931 def ProcessHistogramsResults(self): 932 # Open and parse the json results file generated by telemetry/test_that. 933 if not self.results_file: 934 raise IOError("No results file found.") 935 filename = self.results_file[0] 936 if not filename.endswith(".json"): 937 raise IOError( 938 "Attempt to call json on non-json file: %s" % filename 939 ) 940 if not os.path.exists(filename): 941 raise IOError("%s does not exist" % filename) 942 943 keyvals = {} 944 with open(filename, encoding="utf-8") as f: 945 histograms = json.load(f) 946 value_map = {} 947 # Gets generic set values. 948 for obj in histograms: 949 if "type" in obj and obj["type"] == "GenericSet": 950 value_map[obj["guid"]] = obj["values"] 951 952 for obj in histograms: 953 if "name" not in obj or "sampleValues" not in obj: 954 continue 955 metric_name = obj["name"] 956 vals = obj["sampleValues"] 957 if isinstance(vals, list): 958 # Remove None elements from the list 959 vals = [val for val in vals if val is not None] 960 if vals: 961 result = float(sum(vals)) / len(vals) 962 else: 963 result = 0 964 else: 965 result = vals 966 unit = obj["unit"] 967 diagnostics = obj["diagnostics"] 968 # for summaries of benchmarks 969 key = metric_name 970 if key not in keyvals: 971 keyvals[key] = [[result], unit] 972 else: 973 keyvals[key][0].append(result) 974 # TODO: do we need summaries of stories? 975 # for summaries of story tags 976 if "storyTags" in diagnostics: 977 guid = diagnostics["storyTags"] 978 if guid not in value_map: 979 raise RuntimeError( 980 "Unrecognized storyTags in %s " % (obj) 981 ) 982 for story_tag in value_map[guid]: 983 key = metric_name + "__" + story_tag 984 if key not in keyvals: 985 keyvals[key] = [[result], unit] 986 else: 987 keyvals[key][0].append(result) 988 # calculate summary 989 for key in keyvals: 990 vals = keyvals[key][0] 991 unit = keyvals[key][1] 992 result = float(sum(vals)) / len(vals) 993 keyvals[key] = [result, unit] 994 return keyvals 995 996 def ReadPidFromPerfData(self): 997 """Read PIDs from perf.data files. 998 999 Extract PID from perf.data if "perf record" was running per process, 1000 i.e. with "-p <PID>" and no "-a". 1001 1002 Returns: 1003 pids: list of PIDs. 1004 1005 Raises: 1006 PerfDataReadError when perf.data header reading fails. 1007 """ 1008 cmd = ["/usr/bin/perf", "report", "--header-only", "-i"] 1009 pids = [] 1010 1011 for perf_data_path in self.perf_data_files: 1012 perf_data_path_in_chroot = misc.GetInsideChrootPath( 1013 self.chromeos_root, perf_data_path 1014 ) 1015 path_str = " ".join(cmd + [perf_data_path_in_chroot]) 1016 status, output, _ = self.ce.ChrootRunCommandWOutput( 1017 self.chromeos_root, path_str 1018 ) 1019 if status: 1020 # Error of reading a perf.data profile is fatal. 1021 raise PerfDataReadError( 1022 f"Failed to read perf.data profile: {path_str}" 1023 ) 1024 1025 # Pattern to search a line with "perf record" command line: 1026 # # cmdline : /usr/bin/perf record -e instructions -p 123" 1027 cmdline_regex = re.compile( 1028 r"^\#\scmdline\s:\s+(?P<cmd>.*perf\s+record\s+.*)$" 1029 ) 1030 # Pattern to search PID in a command line. 1031 pid_regex = re.compile(r"^.*\s-p\s(?P<pid>\d+)\s*.*$") 1032 for line in output.splitlines(): 1033 cmd_match = cmdline_regex.match(line) 1034 if cmd_match: 1035 # Found a perf command line. 1036 cmdline = cmd_match.group("cmd") 1037 # '-a' is a system-wide mode argument. 1038 if "-a" not in cmdline.split(): 1039 # It can be that perf was attached to PID and was still running in 1040 # system-wide mode. 1041 # We filter out this case here since it's not per-process. 1042 pid_match = pid_regex.match(cmdline) 1043 if pid_match: 1044 pids.append(pid_match.group("pid")) 1045 # Stop the search and move to the next perf.data file. 1046 break 1047 else: 1048 # cmdline wasn't found in the header. It's a fatal error. 1049 raise PerfDataReadError( 1050 f"Perf command line is not found in {path_str}" 1051 ) 1052 return pids 1053 1054 def VerifyPerfDataPID(self): 1055 """Verify PIDs in per-process perf.data profiles. 1056 1057 Check that at list one top process is profiled if perf was running in 1058 per-process mode. 1059 1060 Raises: 1061 PidVerificationError if PID verification of per-process perf.data profiles 1062 fail. 1063 """ 1064 perf_data_pids = self.ReadPidFromPerfData() 1065 if not perf_data_pids: 1066 # In system-wide mode there are no PIDs. 1067 self._logger.LogOutput("System-wide perf mode. Skip verification.") 1068 return 1069 1070 # PIDs will be present only in per-process profiles. 1071 # In this case we need to verify that profiles are collected on the 1072 # hottest processes. 1073 top_processes = [top_cmd["cmd"] for top_cmd in self.top_cmds] 1074 # top_process structure: <cmd>-<pid> 1075 top_pids = [top_process.split("-")[-1] for top_process in top_processes] 1076 for top_pid in top_pids: 1077 if top_pid in perf_data_pids: 1078 self._logger.LogOutput( 1079 "PID verification passed! " 1080 f"Top process {top_pid} is profiled." 1081 ) 1082 return 1083 raise PidVerificationError( 1084 f"top processes {top_processes} are missing in perf.data traces with" 1085 f" PID: {perf_data_pids}." 1086 ) 1087 1088 def ProcessResults(self, use_cache=False): 1089 # Note that this function doesn't know anything about whether there is a 1090 # cache hit or miss. It should process results agnostic of the cache hit 1091 # state. 1092 if ( 1093 self.results_file 1094 and self.suite == "telemetry_Crosperf" 1095 and "histograms.json" in self.results_file[0] 1096 ): 1097 self.keyvals = self.ProcessHistogramsResults() 1098 elif ( 1099 self.results_file 1100 and self.suite != "telemetry_Crosperf" 1101 and "results-chart.json" in self.results_file[0] 1102 ): 1103 self.keyvals = self.ProcessChartResults() 1104 else: 1105 if not use_cache: 1106 print( 1107 "\n ** WARNING **: Had to use deprecated output-method to " 1108 "collect results.\n" 1109 ) 1110 self.keyvals = self.GetKeyvals() 1111 self.keyvals["retval"] = self.retval 1112 # If we are in CWP approximation mode, we want to collect DSO samples 1113 # for each perf.data file 1114 if self.cwp_dso and self.retval == 0: 1115 self.keyvals["samples"] = self.GetSamples() 1116 # If the samples count collected from perf file is 0, we will treat 1117 # it as a failed run. 1118 if self.keyvals["samples"][0] == 0: 1119 del self.keyvals["samples"] 1120 self.keyvals["retval"] = 1 1121 # Generate report from all perf.data files. 1122 # Now parse all perf report files and include them in keyvals. 1123 self.GatherPerfResults() 1124 1125 cpustats = {} 1126 # Turbostat output has higher priority of processing. 1127 if self.turbostat_log_file: 1128 cpustats = self.ProcessTurbostatResults() 1129 # Process cpustats output only if turbostat has no data. 1130 if not cpustats and self.cpustats_log_file: 1131 cpustats = self.ProcessCpustatsResults() 1132 if self.top_log_file: 1133 self.top_cmds = self.ProcessTopResults() 1134 # Verify that PID in non system-wide perf.data and top_cmds are matching. 1135 if self.perf_data_files and self.top_cmds: 1136 self.VerifyPerfDataPID() 1137 if self.wait_time_log_file: 1138 with open(self.wait_time_log_file, encoding="utf-8") as f: 1139 wait_time = f.readline().strip() 1140 try: 1141 wait_time = float(wait_time) 1142 except ValueError: 1143 raise ValueError("Wait time in log file is not a number.") 1144 # This is for accumulating wait time for telemtry_Crosperf runs only, 1145 # for test_that runs, please refer to suite_runner. 1146 self.machine.AddCooldownWaitTime(wait_time) 1147 1148 for param_key, param in cpustats.items(): 1149 for param_type, param_values in param.items(): 1150 val_avg = sum(param_values) / len(param_values) 1151 val_min = min(param_values) 1152 val_max = max(param_values) 1153 # Average data is always included. 1154 self.keyvals["_".join([param_key, param_type, "avg"])] = val_avg 1155 # Insert min/max results only if they deviate 1156 # from average. 1157 if val_min != val_avg: 1158 self.keyvals[ 1159 "_".join([param_key, param_type, "min"]) 1160 ] = val_min 1161 if val_max != val_avg: 1162 self.keyvals[ 1163 "_".join([param_key, param_type, "max"]) 1164 ] = val_max 1165 1166 def GetChromeVersionFromCache(self, cache_dir): 1167 # Read chrome_version from keys file, if present. 1168 chrome_version = "" 1169 keys_file = os.path.join(cache_dir, CACHE_KEYS_FILE) 1170 if os.path.exists(keys_file): 1171 with open(keys_file, "r", encoding="utf-8") as f: 1172 lines = f.readlines() 1173 for l in lines: 1174 if l.startswith("Google Chrome "): 1175 chrome_version = l 1176 if chrome_version.endswith("\n"): 1177 chrome_version = chrome_version[:-1] 1178 break 1179 return chrome_version 1180 1181 def PopulateFromCacheDir(self, cache_dir, test, suite, cwp_dso): 1182 self.test_name = test 1183 self.suite = suite 1184 self.cwp_dso = cwp_dso 1185 # Read in everything from the cache directory. 1186 with open(os.path.join(cache_dir, RESULTS_FILE), "rb") as f: 1187 self.out = pickle.load(f) 1188 self.err = pickle.load(f) 1189 self.retval = pickle.load(f) 1190 1191 # Untar the tarball to a temporary directory 1192 self.temp_dir = tempfile.mkdtemp( 1193 dir=misc.GetOutsideChrootPath(self.chromeos_root, "/tmp") 1194 ) 1195 1196 command = "cd %s && tar xf %s" % ( 1197 self.temp_dir, 1198 os.path.join(cache_dir, AUTOTEST_TARBALL), 1199 ) 1200 ret = self.ce.RunCommand(command, print_to_console=False) 1201 if ret: 1202 raise RuntimeError("Could not untar cached tarball") 1203 self.results_dir = self.temp_dir 1204 self.results_file = self.GetDataMeasurementsFiles() 1205 self.perf_data_files = self.GetPerfDataFiles() 1206 self.perf_report_files = self.GetPerfReportFiles() 1207 self.chrome_version = self.GetChromeVersionFromCache(cache_dir) 1208 self.ProcessResults(use_cache=True) 1209 1210 def CleanUp(self, rm_chroot_tmp): 1211 if ( 1212 rm_chroot_tmp 1213 and self.results_dir 1214 and self.results_dir != self.temp_dir 1215 ): 1216 dirname, basename = misc.GetRoot(self.results_dir) 1217 if basename.find("test_that_results_") != -1: 1218 command = "rm -rf %s" % self.results_dir 1219 else: 1220 command = "rm -rf %s" % dirname 1221 self.ce.RunCommand(command) 1222 if self.temp_dir: 1223 command = "rm -rf %s" % self.temp_dir 1224 self.ce.RunCommand(command) 1225 1226 def CreateTarball(self, results_dir, tarball): 1227 if not results_dir.strip(): 1228 raise ValueError( 1229 "Refusing to `tar` an empty results_dir: %r" % results_dir 1230 ) 1231 1232 ret = self.ce.RunCommand( 1233 "cd %s && " 1234 "tar " 1235 "--exclude=var/spool " 1236 "--exclude=var/log " 1237 "-cjf %s ." % (results_dir, tarball) 1238 ) 1239 if ret: 1240 raise RuntimeError("Couldn't compress test output directory.") 1241 1242 def StoreToCacheDir(self, cache_dir, machine_manager, key_list): 1243 # Create the dir if it doesn't exist. 1244 temp_dir = tempfile.mkdtemp() 1245 1246 # Store to the temp directory. 1247 with open(os.path.join(temp_dir, RESULTS_FILE), "wb") as f: 1248 pickle.dump(self.out, f) 1249 pickle.dump(self.err, f) 1250 pickle.dump(self.retval, f) 1251 1252 if not test_flag.GetTestMode(): 1253 with open( 1254 os.path.join(temp_dir, CACHE_KEYS_FILE), "w", encoding="utf-8" 1255 ) as f: 1256 f.write("%s\n" % self.label.name) 1257 f.write("%s\n" % self.label.chrome_version) 1258 f.write("%s\n" % self.machine.checksum_string) 1259 for k in key_list: 1260 f.write(k) 1261 f.write("\n") 1262 1263 if self.results_dir: 1264 tarball = os.path.join(temp_dir, AUTOTEST_TARBALL) 1265 self.CreateTarball(self.results_dir, tarball) 1266 1267 # Store machine info. 1268 # TODO(asharif): Make machine_manager a singleton, and don't pass it into 1269 # this function. 1270 with open( 1271 os.path.join(temp_dir, MACHINE_FILE), "w", encoding="utf-8" 1272 ) as f: 1273 f.write(machine_manager.machine_checksum_string[self.label.name]) 1274 1275 if os.path.exists(cache_dir): 1276 command = f"rm -rf {cache_dir}" 1277 self.ce.RunCommand(command) 1278 1279 parent_dir = os.path.dirname(cache_dir) 1280 command = f"mkdir -p {parent_dir} && " 1281 command += f"chmod g+x {temp_dir} && " 1282 command += f"mv {temp_dir} {cache_dir}" 1283 ret = self.ce.RunCommand(command) 1284 if ret: 1285 command = f"rm -rf {temp_dir}" 1286 self.ce.RunCommand(command) 1287 raise RuntimeError( 1288 "Could not move dir %s to dir %s" % (temp_dir, cache_dir) 1289 ) 1290 1291 @classmethod 1292 def CreateFromRun( 1293 cls, 1294 logger, 1295 log_level, 1296 label, 1297 machine, 1298 out, 1299 err, 1300 retval, 1301 test, 1302 suite="telemetry_Crosperf", 1303 cwp_dso="", 1304 ): 1305 if suite == "telemetry": 1306 result = TelemetryResult(logger, label, log_level, machine) 1307 else: 1308 result = cls(logger, label, log_level, machine) 1309 result.PopulateFromRun(out, err, retval, test, suite, cwp_dso) 1310 return result 1311 1312 @classmethod 1313 def CreateFromCacheHit( 1314 cls, 1315 logger, 1316 log_level, 1317 label, 1318 machine, 1319 cache_dir, 1320 test, 1321 suite="telemetry_Crosperf", 1322 cwp_dso="", 1323 ): 1324 if suite == "telemetry": 1325 result = TelemetryResult(logger, label, log_level, machine) 1326 else: 1327 result = cls(logger, label, log_level, machine) 1328 try: 1329 result.PopulateFromCacheDir(cache_dir, test, suite, cwp_dso) 1330 1331 except RuntimeError as e: 1332 logger.LogError("Exception while using cache: %s" % e) 1333 return None 1334 return result 1335 1336 1337class TelemetryResult(Result): 1338 """Class to hold the results of a single Telemetry run.""" 1339 1340 def PopulateFromRun(self, out, err, retval, test, suite, cwp_dso): 1341 self.out = out 1342 self.err = err 1343 self.retval = retval 1344 1345 self.ProcessResults() 1346 1347 # pylint: disable=arguments-differ 1348 def ProcessResults(self): 1349 # The output is: 1350 # url,average_commit_time (ms),... 1351 # www.google.com,33.4,21.2,... 1352 # We need to convert to this format: 1353 # {"www.google.com:average_commit_time (ms)": "33.4", 1354 # "www.google.com:...": "21.2"} 1355 # Added note: Occasionally the output comes back 1356 # with "JSON.stringify(window.automation.GetResults())" on 1357 # the first line, and then the rest of the output as 1358 # described above. 1359 1360 lines = self.out.splitlines() 1361 self.keyvals = {} 1362 1363 if lines: 1364 if lines[0].startswith("JSON.stringify"): 1365 lines = lines[1:] 1366 1367 if not lines: 1368 return 1369 labels = lines[0].split(",") 1370 for line in lines[1:]: 1371 fields = line.split(",") 1372 if len(fields) != len(labels): 1373 continue 1374 for i in range(1, len(labels)): 1375 key = "%s %s" % (fields[0], labels[i]) 1376 value = fields[i] 1377 self.keyvals[key] = value 1378 self.keyvals["retval"] = self.retval 1379 1380 def PopulateFromCacheDir(self, cache_dir, test, suite, cwp_dso): 1381 self.test_name = test 1382 self.suite = suite 1383 self.cwp_dso = cwp_dso 1384 with open(os.path.join(cache_dir, RESULTS_FILE), "rb") as f: 1385 self.out = pickle.load(f) 1386 self.err = pickle.load(f) 1387 self.retval = pickle.load(f) 1388 1389 self.chrome_version = super( 1390 TelemetryResult, self 1391 ).GetChromeVersionFromCache(cache_dir) 1392 self.ProcessResults() 1393 1394 1395class CacheConditions(object): 1396 """Various Cache condition values, for export.""" 1397 1398 # Cache hit only if the result file exists. 1399 CACHE_FILE_EXISTS = 0 1400 1401 # Cache hit if the checksum of cpuinfo and totalmem of 1402 # the cached result and the new run match. 1403 MACHINES_MATCH = 1 1404 1405 # Cache hit if the image checksum of the cached result and the new run match. 1406 CHECKSUMS_MATCH = 2 1407 1408 # Cache hit only if the cached result was successful 1409 RUN_SUCCEEDED = 3 1410 1411 # Never a cache hit. 1412 FALSE = 4 1413 1414 # Cache hit if the image path matches the cached image path. 1415 IMAGE_PATH_MATCH = 5 1416 1417 # Cache hit if the uuid of hard disk mataches the cached one 1418 1419 SAME_MACHINE_MATCH = 6 1420 1421 1422class ResultsCache(object): 1423 """Class to handle the cache for storing/retrieving test run results. 1424 1425 This class manages the key of the cached runs without worrying about what 1426 is exactly stored (value). The value generation is handled by the Results 1427 class. 1428 """ 1429 1430 CACHE_VERSION = 6 1431 1432 def __init__(self): 1433 # Proper initialization happens in the Init function below. 1434 self.chromeos_image = None 1435 self.chromeos_root = None 1436 self.test_name = None 1437 self.iteration = None 1438 self.test_args = None 1439 self.profiler_args = None 1440 self.board = None 1441 self.cache_conditions = None 1442 self.machine_manager = None 1443 self.machine = None 1444 self._logger = None 1445 self.ce = None 1446 self.label = None 1447 self.share_cache = None 1448 self.suite = None 1449 self.log_level = None 1450 self.show_all = None 1451 self.run_local = None 1452 self.cwp_dso = None 1453 1454 def Init( 1455 self, 1456 chromeos_image, 1457 chromeos_root, 1458 test_name, 1459 iteration, 1460 test_args, 1461 profiler_args, 1462 machine_manager, 1463 machine, 1464 board, 1465 cache_conditions, 1466 logger_to_use, 1467 log_level, 1468 label, 1469 share_cache, 1470 suite, 1471 show_all_results, 1472 run_local, 1473 cwp_dso, 1474 ): 1475 self.chromeos_image = chromeos_image 1476 self.chromeos_root = chromeos_root 1477 self.test_name = test_name 1478 self.iteration = iteration 1479 self.test_args = test_args 1480 self.profiler_args = profiler_args 1481 self.board = board 1482 self.cache_conditions = cache_conditions 1483 self.machine_manager = machine_manager 1484 self.machine = machine 1485 self._logger = logger_to_use 1486 self.ce = command_executer.GetCommandExecuter( 1487 self._logger, log_level=log_level 1488 ) 1489 self.label = label 1490 self.share_cache = share_cache 1491 self.suite = suite 1492 self.log_level = log_level 1493 self.show_all = show_all_results 1494 self.run_local = run_local 1495 self.cwp_dso = cwp_dso 1496 1497 def GetCacheDirForRead(self): 1498 matching_dirs = [] 1499 for glob_path in self.FormCacheDir(self.GetCacheKeyList(True)): 1500 matching_dirs += glob.glob(glob_path) 1501 1502 if matching_dirs: 1503 # Cache file found. 1504 return matching_dirs[0] 1505 return None 1506 1507 def GetCacheDirForWrite(self, get_keylist=False): 1508 cache_path = self.FormCacheDir(self.GetCacheKeyList(False))[0] 1509 if get_keylist: 1510 args_str = "%s_%s_%s" % ( 1511 self.test_args, 1512 self.profiler_args, 1513 self.run_local, 1514 ) 1515 version, image = results_report.ParseChromeosImage( 1516 self.label.chromeos_image 1517 ) 1518 keylist = [ 1519 version, 1520 image, 1521 self.label.board, 1522 self.machine.name, 1523 self.test_name, 1524 str(self.iteration), 1525 args_str, 1526 ] 1527 return cache_path, keylist 1528 return cache_path 1529 1530 def FormCacheDir(self, list_of_strings): 1531 cache_key = " ".join(list_of_strings) 1532 cache_dir = misc.GetFilenameFromString(cache_key) 1533 if self.label.cache_dir: 1534 cache_home = os.path.abspath( 1535 os.path.expanduser(self.label.cache_dir) 1536 ) 1537 cache_path = [os.path.join(cache_home, cache_dir)] 1538 else: 1539 cache_path = [os.path.join(SCRATCH_DIR, cache_dir)] 1540 1541 if self.share_cache: 1542 for path in [x.strip() for x in self.share_cache.split(",")]: 1543 if os.path.exists(path): 1544 cache_path.append(os.path.join(path, cache_dir)) 1545 else: 1546 self._logger.LogFatal( 1547 "Unable to find shared cache: %s" % path 1548 ) 1549 1550 return cache_path 1551 1552 def GetCacheKeyList(self, read): 1553 if read and CacheConditions.MACHINES_MATCH not in self.cache_conditions: 1554 machine_checksum = "*" 1555 else: 1556 machine_checksum = self.machine_manager.machine_checksum[ 1557 self.label.name 1558 ] 1559 if ( 1560 read 1561 and CacheConditions.CHECKSUMS_MATCH not in self.cache_conditions 1562 ): 1563 checksum = "*" 1564 elif self.label.image_type == "trybot": 1565 checksum = hashlib.md5( 1566 self.label.chromeos_image.encode("utf-8") 1567 ).hexdigest() 1568 elif self.label.image_type == "official": 1569 checksum = "*" 1570 else: 1571 checksum = ImageChecksummer().Checksum(self.label, self.log_level) 1572 1573 if ( 1574 read 1575 and CacheConditions.IMAGE_PATH_MATCH not in self.cache_conditions 1576 ): 1577 image_path_checksum = "*" 1578 else: 1579 image_path_checksum = hashlib.md5( 1580 self.chromeos_image.encode("utf-8") 1581 ).hexdigest() 1582 1583 machine_id_checksum = "" 1584 if ( 1585 read 1586 and CacheConditions.SAME_MACHINE_MATCH not in self.cache_conditions 1587 ): 1588 machine_id_checksum = "*" 1589 else: 1590 if self.machine and self.machine.name in self.label.remote: 1591 machine_id_checksum = self.machine.machine_id_checksum 1592 else: 1593 for machine in self.machine_manager.GetMachines(self.label): 1594 if machine.name == self.label.remote[0]: 1595 machine_id_checksum = machine.machine_id_checksum 1596 break 1597 1598 temp_test_args = "%s %s %s" % ( 1599 self.test_args, 1600 self.profiler_args, 1601 self.run_local, 1602 ) 1603 test_args_checksum = hashlib.md5( 1604 temp_test_args.encode("utf-8") 1605 ).hexdigest() 1606 return ( 1607 image_path_checksum, 1608 self.test_name, 1609 str(self.iteration), 1610 test_args_checksum, 1611 checksum, 1612 machine_checksum, 1613 machine_id_checksum, 1614 str(self.CACHE_VERSION), 1615 ) 1616 1617 def ReadResult(self): 1618 if CacheConditions.FALSE in self.cache_conditions: 1619 cache_dir = self.GetCacheDirForWrite() 1620 command = "rm -rf %s" % (cache_dir,) 1621 self.ce.RunCommand(command) 1622 return None 1623 cache_dir = self.GetCacheDirForRead() 1624 1625 if not cache_dir: 1626 return None 1627 1628 if not os.path.isdir(cache_dir): 1629 return None 1630 1631 if self.log_level == "verbose": 1632 self._logger.LogOutput( 1633 "Trying to read from cache dir: %s" % cache_dir 1634 ) 1635 result = Result.CreateFromCacheHit( 1636 self._logger, 1637 self.log_level, 1638 self.label, 1639 self.machine, 1640 cache_dir, 1641 self.test_name, 1642 self.suite, 1643 self.cwp_dso, 1644 ) 1645 if not result: 1646 return None 1647 1648 if ( 1649 result.retval == 0 1650 or CacheConditions.RUN_SUCCEEDED not in self.cache_conditions 1651 ): 1652 return result 1653 1654 return None 1655 1656 def StoreResult(self, result): 1657 cache_dir, keylist = self.GetCacheDirForWrite(get_keylist=True) 1658 result.StoreToCacheDir(cache_dir, self.machine_manager, keylist) 1659 1660 1661class MockResultsCache(ResultsCache): 1662 """Class for mock testing, corresponding to ResultsCache class.""" 1663 1664 # FIXME: pylint complains about this mock init method, we should probably 1665 # replace all Mock classes in Crosperf with simple Mock.mock(). 1666 # pylint: disable=arguments-differ 1667 def Init(self, *args): 1668 pass 1669 1670 def ReadResult(self): 1671 return None 1672 1673 def StoreResult(self, result): 1674 pass 1675 1676 1677class MockResult(Result): 1678 """Class for mock testing, corresponding to Result class.""" 1679 1680 def PopulateFromRun(self, out, err, retval, test, suite, cwp_dso): 1681 self.out = out 1682 self.err = err 1683 self.retval = retval 1684