def append_exec_measurements(self, key, measurements): """Unpacks a measurements dict into the Results instance""" # Consistently format monotonic time doubles wallclock_times = format_raw_exec_results( measurements["wallclock_times"]) self.wallclock_times[key].append(wallclock_times) self.core_cycle_counts[key].append(measurements["core_cycle_counts"]) self.aperf_counts[key].append(measurements["aperf_counts"]) self.mperf_counts[key].append(measurements["mperf_counts"])
def append_exec_measurements(self, key, measurements, flag): """Unpacks a measurements dict into the Results instance""" # Only a subset of flags can arise at this time. assert flag in ("C", "E", "T") # Consistently format monotonic time doubles wallclock_times = format_raw_exec_results( measurements["wallclock_times"]) self.pexec_flags[key].append(flag) self.wallclock_times[key].append(wallclock_times) self.core_cycle_counts[key].append(measurements["core_cycle_counts"]) self.aperf_counts[key].append(measurements["aperf_counts"]) self.mperf_counts[key].append(measurements["mperf_counts"])
def test_format_raw(): assert format_raw_exec_results([]) == [] data = [1.33333344444, 4.555555666] expected = [1.333333, 4.555556] assert format_raw_exec_results(data) == expected
def run(self): """Benchmark execution starts here""" jobs_left = len(self) if jobs_left == 0: debug("Krun started with an empty queue of jobs") if not self.started_by_init: util.log_and_mail(self.mailer, debug, "Benchmarking started", "Benchmarking started.\nLogging to %s" % self.log_path, bypass_limiter=True) if self.reboot and not self.started_by_init: # Reboot before first benchmark (dumps results file). info("Reboot prior to first execution") self._reboot() if self.reboot and self.started_by_init and jobs_left > 0: debug("Waiting %s seconds for the system to come up." % str(STARTUP_WAIT_SECONDS)) if self.dry_run: info("SIMULATED: time.sleep (would have waited %s seconds)." % STARTUP_WAIT_SECONDS) else: time.sleep(STARTUP_WAIT_SECONDS) # Important that the dmesg is collected after the above startup wait. # Otherwise we get spurious dmesg changes. self.platform.collect_starting_dmesg() while True: self.platform.wait_for_temperature_sensors() jobs_left = len(self) if jobs_left == 0: break # Run the user's pre-process-execution commands util.run_shell_cmd_list(self.config.PRE_EXECUTION_CMDS, extra_env=self._make_pre_post_cmd_env()) job = self.next_job() # We collect rough execution times separate from real results. The # reason for this is that, even if a benchmark crashes it takes # time and we need to account for this when making estimates. A # crashing benchmark will give an empty list of iteration times, # meaning we can't use 'raw_exec_result' below for estimates. exec_start_time = time.time() raw_exec_result = job.run(self.mailer, self.dry_run) exec_end_time = time.time() exec_result = util.format_raw_exec_results(raw_exec_result) if not exec_result and not self.dry_run: self.results.error_flag = True self.results.data[job.key].append(exec_result) eta_info = exec_end_time - exec_start_time if self.reboot: # Add time taken to wait for system to come up if we are in # reboot mode. eta_info += STARTUP_WAIT_SECONDS self.add_eta_info(job.key, eta_info) info("%d executions left in scheduler queue" % (jobs_left - 1)) # We dump the json after each experiment so we can monitor the # json file mid-run. It is overwritten each time. self.results.write_to_file() self.jobs_done += 1 # Run the user's post-process-execution commands with updated # ETA estimates. Important that this happens *after* dumping # results, as the user is likely copying intermediate results to # another host. util.run_shell_cmd_list(self.config.POST_EXECUTION_CMDS, extra_env=self._make_pre_post_cmd_env()) tfmt = self.get_overall_time_estimate_formatter() if self.eta_avail == self.jobs_done: # We just found out roughly how long the session has left, mail out. msg = "ETA for current session now known: %s" % tfmt.finish_str util.log_and_mail(self.mailer, debug, "ETA for Current Session Available", msg, bypass_limiter=True) info("{:<25s}: {} ({} from now)".format("Estimated completion", tfmt.finish_str, tfmt.delta_str)) try: job = self.next_job(peek=True) except ScheduleEmpty: pass # no next job else: # print info about the next job info("Next execution is '%s(%d)' (%s variant) under '%s'" % (job.benchmark, job.parameter, job.variant, job.vm_name)) tfmt = self.get_exec_estimate_time_formatter(job.key) info("{:<35s}: {} ({} from now)".format( "Estimated completion (next execution)", tfmt.finish_str, tfmt.delta_str)) if (self.eta_avail is not None) and (self.jobs_done < self.eta_avail): info("Executions until ETA known: %s" % self.jobs_until_eta_known()) if self.platform.check_dmesg_for_changes(): self.results.error_flag = True if self.reboot and len(self) > 0: info("Reboot in preparation for next execution") self._reboot() self.platform.save_power() info("Done: Results dumped to %s" % self.config.results_filename()) err_msg = "Errors/warnings occurred -- read the log!" if self.results.error_flag: warn(err_msg) msg = "Session completed. Log file at: '%s'" % (self.log_path) if self.results.error_flag: msg += "\n\n%s" % err_msg if self.reboot: msg += "\n\nDon't forget to disable Krun at boot." util.log_and_mail(self.mailer, info, "Benchmarks Complete", msg, bypass_limiter=True)
def run(self): """Benchmark execution starts here""" jobs_left = len(self) if jobs_left == 0: debug("Krun started with an empty queue of jobs") if not self.started_by_init: util.log_and_mail(self.mailer, debug, "Benchmarking started", "Benchmarking started.\nLogging to %s" % self.log_path, bypass_limiter=True) if self.reboot and not self.started_by_init: # Reboot before first benchmark (dumps results file). info("Reboot prior to first execution") self._reboot() if self.reboot and self.started_by_init and jobs_left > 0: debug("Waiting %s seconds for the system to come up." % str(STARTUP_WAIT_SECONDS)) if self.dry_run: info("SIMULATED: time.sleep (would have waited %s seconds)." % STARTUP_WAIT_SECONDS) else: time.sleep(STARTUP_WAIT_SECONDS) # Important that the dmesg is collected after the above startup wait. # Otherwise we get spurious dmesg changes. self.platform.collect_starting_dmesg() while True: self.platform.wait_for_temperature_sensors() jobs_left = len(self) if jobs_left == 0: break # Run the user's pre-process-execution commands util.run_shell_cmd_list( self.config.PRE_EXECUTION_CMDS, extra_env=self._make_pre_post_cmd_env() ) job = self.next_job() # We collect rough execution times separate from real results. The # reason for this is that, even if a benchmark crashes it takes # time and we need to account for this when making estimates. A # crashing benchmark will give an empty list of iteration times, # meaning we can't use 'raw_exec_result' below for estimates. exec_start_time = time.time() raw_exec_result = job.run(self.mailer, self.dry_run) exec_end_time = time.time() exec_result = util.format_raw_exec_results(raw_exec_result) if not exec_result and not self.dry_run: self.results.error_flag = True self.results.data[job.key].append(exec_result) eta_info = exec_end_time - exec_start_time if self.reboot: # Add time taken to wait for system to come up if we are in # reboot mode. eta_info += STARTUP_WAIT_SECONDS self.add_eta_info(job.key, eta_info) info("%d executions left in scheduler queue" % (jobs_left - 1)) # We dump the json after each experiment so we can monitor the # json file mid-run. It is overwritten each time. self.results.write_to_file() self.jobs_done += 1 # Run the user's post-process-execution commands with updated # ETA estimates. Important that this happens *after* dumping # results, as the user is likely copying intermediate results to # another host. util.run_shell_cmd_list( self.config.POST_EXECUTION_CMDS, extra_env=self._make_pre_post_cmd_env() ) tfmt = self.get_overall_time_estimate_formatter() if self.eta_avail == self.jobs_done: # We just found out roughly how long the session has left, mail out. msg = "ETA for current session now known: %s" % tfmt.finish_str util.log_and_mail(self.mailer, debug, "ETA for Current Session Available", msg, bypass_limiter=True) info("{:<25s}: {} ({} from now)".format( "Estimated completion", tfmt.finish_str, tfmt.delta_str)) try: job = self.next_job(peek=True) except ScheduleEmpty: pass # no next job else: # print info about the next job info("Next execution is '%s(%d)' (%s variant) under '%s'" % (job.benchmark, job.parameter, job.variant, job.vm_name)) tfmt = self.get_exec_estimate_time_formatter(job.key) info("{:<35s}: {} ({} from now)".format( "Estimated completion (next execution)", tfmt.finish_str, tfmt.delta_str)) if (self.eta_avail is not None) and (self.jobs_done < self.eta_avail): info("Executions until ETA known: %s" % self.jobs_until_eta_known()) if self.platform.check_dmesg_for_changes(): self.results.error_flag = True if self.reboot and len(self) > 0: info("Reboot in preparation for next execution") self._reboot() self.platform.save_power() info("Done: Results dumped to %s" % self.config.results_filename()) err_msg = "Errors/warnings occurred -- read the log!" if self.results.error_flag: warn(err_msg) msg = "Session completed. Log file at: '%s'" % (self.log_path) if self.results.error_flag: msg += "\n\n%s" % err_msg if self.reboot: msg += "\n\nDon't forget to disable Krun at boot." util.log_and_mail(self.mailer, info, "Benchmarks Complete", msg, bypass_limiter=True)