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