def test_audit_differs0001(self, monkeypatch, mock_platform, caplog,
no_results_instantiation_check):
"""Check that if the audit differs, a crash occurs"""
make_reboot_raise(monkeypatch)
no_envlogs(monkeypatch)
config = Config(os.path.join(TEST_DIR, "example.krun"))
krun.util.assign_platform(config, mock_platform)
emulate_first_reboot(mock_platform, config)
results_path = config.results_filename()
# mutate the audit, so it won't match later
results = Results(config, mock_platform, results_file=results_path)
results.audit._audit["wibble"] = "wut"
results.write_to_file()
sched = ExecutionScheduler(config,
mock_platform.mailer,
mock_platform,
dry_run=True)
with pytest.raises(krun.util.FatalKrunError):
sched.run()
expect = "This is only valid if the machine you are using is identical"
assert expect in caplog.text
os.unlink(sched.manifest.path)
os.unlink(results_path)
def __init__(self,
config,
mailer,
platform,
resume=False,
reboot=False,
dry_run=False,
started_by_init=False):
self.mailer = mailer
self.config = config
self.work_deque = deque()
self.eta_avail = 0
self.jobs_done = 0
self.platform = platform
self.resume = resume
self.reboot = reboot
self.dry_run = dry_run
self.started_by_init = started_by_init
if resume:
self.results = Results(self.config,
platform,
results_file=self.config.results_filename())
else:
self.results = Results(self.config, platform)
self.log_path = self.config.log_filename(self.resume)
def emulate_first_reboot(platform, config):
platform.starting_temperatures = platform.take_temperature_readings()
manifest = ManifestManager(config, platform, new_file=True)
manifest.set_starting_temperatures(platform.starting_temperatures)
results = Results(config, platform)
results.write_to_file()
return manifest
def test_audit_differs0001(self, monkeypatch, mock_platform, caplog):
"""Check that if the audit differs, a crash occurs"""
make_reboot_raise(monkeypatch)
no_envlogs(monkeypatch)
config = Config(os.path.join(TEST_DIR, "example.krun"))
krun.util.assign_platform(config, mock_platform)
emulate_first_reboot(mock_platform, config, monkeypatch)
results_path = config.results_filename()
# mutate the audit, so it won't match later
results = Results(config, mock_platform, results_file=results_path)
results.audit._audit["wibble"] = "wut"
results.write_to_file()
sched = ExecutionScheduler(config, mock_platform.mailer, mock_platform,
dry_run=True)
with pytest.raises(krun.util.FatalKrunError):
sched.run()
expect = "This is only valid if the machine you are using is identical"
assert expect in caplog.text()
os.unlink(sched.manifest.path)
os.unlink(results_path)
def main(parser):
args = parser.parse_args()
if args.dump is not None:
if not args.filename.endswith(".json.bz2"):
usage(parser)
else:
results = Results(None, None, results_file=args.filename)
if args.dump == "config" or "audit":
text = unicode(results.__getattribute__(args.dump))
else:
text = json.dumps(results.__getattribute__(args.dump),
sort_keys=True, indent=2)
# String data read in from JSON are unicode objects. This matters
# for us as some data in the audit includes unicode characters.
# If it does, a simple print no longer suffices if the system
# locale is (e.g.) ASCII. In this case print will raise an
# exception. The correct thing to do is to encode() the unicode to
# the system locale.
print(text.encode(locale.getpreferredencoding()))
sys.exit(0)
if not args.filename.endswith(".krun"):
usage(parser)
try:
if os.stat(args.filename).st_size <= 0:
util.fatal('Krun configuration file %s is empty.' % args.filename)
except OSError:
util.fatal('Krun configuration file %s does not exist.' % args.filename)
config = Config(args.filename)
if args.info:
# Info mode doesn't run the experiment.
# Just prints some metrics and exits.
util.print_session_info(config)
return
if args.strip_results:
util.strip_results(config, args.strip_results)
return
attach_log_file(config, args.resume)
debug("Krun invoked with arguments: %s" % sys.argv)
mail_recipients = config.MAIL_TO
if type(mail_recipients) is not list:
util.fatal("MAIL_TO config should be a list")
mailer = Mailer(mail_recipients, max_mails=config.MAX_MAILS)
try:
inner_main(mailer, config, args)
except util.FatalKrunError as e:
subject = "Fatal Krun Exception"
mailer.send(subject, e.args[0], bypass_limiter=True)
util.run_shell_cmd_list(config.POST_EXECUTION_CMDS)
raise e
def test_eq(self, mock_platform):
results = Results(None,
None,
results_file="krun/tests/quick_results.json.bz2")
assert results == results
assert not results == None
assert not results == \
Results(Config("krun/tests/example.krun"), mock_platform)
def emulate_first_reboot(platform, config, monkeypatch):
no_results_instantiation_check(monkeypatch)
platform.starting_temperatures = platform.take_temperature_readings()
manifest = ManifestManager(config, platform, new_file=True)
manifest.set_starting_temperatures(platform.starting_temperatures)
results = Results(config, platform)
results.write_to_file()
return manifest
def test_dump_config(self, no_results_instantiation_check):
"""Simulates krun.py --dump-config RESULTS_FILE.json.bz2
"""
res_path = os.path.join(TEST_DIR, "quick_results.json.bz2")
conf_path = os.path.join(TEST_DIR, "quick.krun")
results = Results(None, None, results_file=res_path)
with open(conf_path) as fp:
config = fp.read()
assert config == results.dump("config")
def strip_results(config, key_spec):
from krun.platform import detect_platform
from krun.results import Results
platform = detect_platform(None)
results = Results(config, platform, results_file=config.results_filename())
n_removed = results.strip_results(key_spec)
if n_removed > 0:
results.write_to_file()
info("Removed %d result keys" % n_removed)
def test_dump_config(self, no_results_instantiation_check):
"""Simulates krun.py --dump-config RESULTS_FILE.json.bz2
"""
res_path = os.path.join(TEST_DIR, "quick_results.json.bz2")
conf_path = os.path.join(TEST_DIR, "quick.krun")
results = Results(None, None, results_file=res_path)
with open(conf_path) as fp:
config = fp.read()
assert config == results.dump("config")
def strip_results(config, key_spec):
from krun.platform import detect_platform
from krun.results import Results
platform = detect_platform(None)
results = Results(config, platform,
results_file=config.results_filename())
n_removed = results.strip_results(key_spec)
if n_removed > 0:
results.write_to_file()
info("Removed %d result keys" % n_removed)
def fake_results(mock_platform, no_results_instantiation_check):
results = Results(None, mock_platform)
mock_platform.num_cpus = 2
mock_platform.num_per_core_measurements = 2
results.eta_estimates = {"bench:vm:variant": [1., 1.]}
results.wallclock_times = {"bench:vm:variant": [[2., 2.], [2., 2.]]}
results.core_cycle_counts = {
"bench:vm:variant": [[[3., 3.], [
3.,
3.,
]], [[3., 3.], [3., 3.]]]
}
results.aperf_counts = {
"bench:vm:variant": [[[4., 4.], [
4.,
4.,
]], [[4., 4.], [4., 4.]]]
}
results.mperf_counts = {
"bench:vm:variant": [[[5., 5.], [
5.,
5.,
]], [[5., 5.], [5., 5.]]]
}
results.pexec_flags = {"bench:vm:variant": ["C", "T"]}
return results
def test_run_schedule0005(self, mock_platform, monkeypatch,
no_results_instantiation_check):
def dummy_execjob_run(self, mailer, dryrun=False):
return self.empty_measurements, {}, "E" # pretend jobs fail
monkeypatch.setattr(ExecutionJob, 'run', dummy_execjob_run)
config = Config(os.path.join(TEST_DIR, "example.krun"))
n_reboots, sched = run_with_captured_reboots(config, mock_platform,
monkeypatch)
assert n_reboots == 8 # 2 benchmarks, 2 vms, 2 execs
results = Results(config,
mock_platform,
results_file=config.results_filename())
type_check_results(results)
assert len(results.wallclock_times) == 4 # 2 benchmarks, 2 vms
for key, execs in results.wallclock_times.iteritems():
assert len(execs) == 2
for _exec in execs:
assert len(_exec) == 0 # due to error
os.unlink(config.results_filename())
os.unlink(sched.manifest.path)
def test_write_results_to_disk(self, mock_platform):
config = Config("krun/tests/example.krun")
out_file = "krun/tests/example_results.json.bz2"
results0 = Results(config, mock_platform)
results0.audit = dict()
results0.starting_temperatures = [4355, 9879]
results0.data = {u"dummy:Java:default-java": [[1.000726]]}
results0.eta_estimates = {u"dummy:Java:default-java": [1.1]}
results0.reboots = 5
results0.error_flag = False
results0.write_to_file()
results1 = Results(config, None, results_file=out_file)
assert results0 == results1
# Clean-up generated file.
os.unlink(out_file)
def to_strip():
from krun.platform import detect_platform
from krun.results import Results
path = os.path.join(TEST_DIR, "quick.krun")
config = Config(path)
platform = detect_platform(None)
results = Results(config, platform, results_file=config.results_filename())
return results
def test_error_flag_persists0002(self, monkeypatch, mock_platform,
no_results_instantiation_check):
"""Check a changed dmesg will correctly set the error flag"""
make_reboot_raise(monkeypatch)
no_envlogs(monkeypatch)
# pretend dmesg changes
def dummy_check_for_dmesg_changes(self):
return True
monkeypatch.setattr(mock_platform, 'check_dmesg_for_changes',
dummy_check_for_dmesg_changes)
config = Config(os.path.join(TEST_DIR, "example.krun"))
krun.util.assign_platform(config, mock_platform)
emulate_first_reboot(mock_platform, config)
results_path = config.results_filename()
# To start, the error flag is not set
results = Results(config, mock_platform, results_file=results_path)
assert not results.error_flag
# run an execution where the dmesg changes
sched = ExecutionScheduler(config,
mock_platform.mailer,
mock_platform,
dry_run=True)
try:
sched.run()
except _TestReboot:
pass
else:
assert False
# reload results and check the error flag is now set
results = Results(config, mock_platform, results_file=results_path)
assert results.error_flag
os.unlink(sched.manifest.path)
os.unlink(results_path)
def test_error_flag_persists0001(self, monkeypatch, mock_platform,
no_results_instantiation_check):
"""Check a failing exec will correctly set the error flag"""
make_reboot_raise(monkeypatch)
no_envlogs(monkeypatch)
# pretend exec fails
def dummy_job_run(self, mailer, dry):
measurements = self.make_empty_measurement()
return measurements, None, 'E' # measurements, instr_data, flag
monkeypatch.setattr(ExecutionJob, 'run', dummy_job_run)
config = Config(os.path.join(TEST_DIR, "example.krun"))
krun.util.assign_platform(config, mock_platform)
emulate_first_reboot(mock_platform, config)
results_path = config.results_filename()
# To start, the error flag is not set
results = Results(config, mock_platform, results_file=results_path)
assert not results.error_flag
# run a (failing) execution, which will dump the results file
sched = ExecutionScheduler(config,
mock_platform.mailer,
mock_platform,
dry_run=True)
try:
sched.run()
except _TestReboot:
pass
else:
assert False
# reload results and check the error flag is now set
results = Results(config, mock_platform, results_file=results_path)
assert results.error_flag
os.unlink(sched.manifest.path)
os.unlink(results_path)
def __init__(self, config, mailer, platform,
resume=False, reboot=False, dry_run=False,
started_by_init=False):
self.mailer = mailer
self.config = config
self.work_deque = deque()
self.eta_avail = 0
self.jobs_done = 0
self.platform = platform
self.resume = resume
self.reboot = reboot
self.dry_run = dry_run
self.started_by_init = started_by_init
if resume:
self.results = Results(self.config, platform,
results_file=self.config.results_filename())
else:
self.results = Results(self.config, platform)
self.log_path = self.config.log_filename(self.resume)
def test_run_schedule0002(self, mock_platform, monkeypatch):
config = Config(os.path.join(TEST_DIR, "example.krun"))
n_reboots, sched = run_with_captured_reboots(config, mock_platform,
monkeypatch)
assert n_reboots == 8 # 2 benchmarks, 2 vms, 2 execs
results = Results(config, mock_platform,
results_file=config.results_filename())
type_check_results(results)
assert len(results.wallclock_times) == 4 # 2 benchmarks, 2 vms
for key, execs in results.wallclock_times.iteritems():
assert len(execs) == 2
for _exec in execs:
assert len(_exec) == 0 # due to dry run
os.unlink(config.results_filename())
os.unlink(sched.manifest.path)
def test_run_schedule(self, monkeypatch, mock_platform):
json_file = os.path.join(TEST_DIR, "example_results.json.bz2")
def dummy_shell_cmd(text):
pass
monkeypatch.setattr(subprocess, 'call', dummy_shell_cmd)
monkeypatch.setattr(krun.util, 'run_shell_cmd', dummy_shell_cmd)
config = Config(os.path.join(TEST_DIR, "example.krun"))
krun.util.assign_platform(config, mock_platform)
sched = ExecutionScheduler(config,
mock_platform.mailer,
mock_platform,
resume=False,
reboot=False,
dry_run=True,
started_by_init=False)
sched.build_schedule()
assert len(sched) == 8
sched.run()
assert len(sched) == 0
results = Results(Config(os.path.join(TEST_DIR, "example.krun")),
mock_platform,
results_file=json_file)
for k, execs in results.data.iteritems():
assert type(execs) is list
for one_exec in execs:
assert type(one_exec) is list
assert all([type(x) is float for x in one_exec])
for k, execs in results.eta_estimates.iteritems():
assert type(execs) is list
assert all([type(x) is float for x in execs])
assert type(results.starting_temperatures) is dict
assert type(results.reboots) is int
assert type(results.audit) is type(Audit(dict()))
assert type(results.config) is type(Config())
assert type(results.error_flag) is bool
os.unlink(json_file)
def fake_results(mock_platform, no_results_instantiation_check):
results = Results(None, mock_platform)
mock_platform.num_cpus = 2
mock_platform.num_per_core_measurements = 2
results.eta_estimates = {"bench:vm:variant": [1., 1.]}
results.wallclock_times = {"bench:vm:variant": [[2., 2.], [2., 2.]]}
results.core_cycle_counts = {"bench:vm:variant":
[[[3., 3.], [3., 3.,]], [[3., 3.], [3., 3.]]]}
results.aperf_counts = {"bench:vm:variant":
[[[4., 4.], [4., 4.,]], [[4., 4.], [4., 4.]]]}
results.mperf_counts = {"bench:vm:variant":
[[[5., 5.], [5., 5.,]], [[5., 5.], [5., 5.]]]}
return results
def test_run_schedule0001(self, monkeypatch, mock_platform):
config = Config(os.path.join(TEST_DIR, "one_exec.krun"))
n_reboots, sched = run_with_captured_reboots(config, mock_platform,
monkeypatch)
assert sched.manifest.total_num_execs == 1
assert sched.manifest.num_execs_left == 0
assert n_reboots == 1
results = Results(config, mock_platform,
results_file=config.results_filename())
type_check_results(results)
assert len(results.wallclock_times) == 1 # 1 benchmark, 1 vm
for key, execs in results.wallclock_times.iteritems():
assert len(execs) == 1
for _exec in execs:
assert len(_exec) == 0 # due to dry run
os.unlink(config.results_filename())
os.unlink(sched.manifest.path)
def test_read_results_from_disk(self):
config = Config("krun/tests/quick.krun")
results = Results(None,
None,
results_file="krun/tests/quick_results.json.bz2")
expected = {
u'nbody:CPython:default-python': [[0.022256]],
u'dummy:CPython:default-python': [[1.005115]],
u'nbody:Java:default-java': [[26.002632]],
u'dummy:Java:default-java': [[1.000941]]
}
assert results.config == config
assert results.audit[u'uname'] == u'Linux'
assert results.audit[u'debian_version'] == u'jessie/sid'
assert results.data == expected
assert results.starting_temperatures == {"x": 3333, "y": 4444}
assert results.eta_estimates == \
{
u'nbody:CPython:default-python': [0.022256],
u'dummy:CPython:default-python': [1.005115],
u'nbody:Java:default-java': [26.002632],
u'dummy:Java:default-java': [1.000941]
}
def test_run_schedule0004(self, mock_platform, monkeypatch,
no_results_instantiation_check):
config = Config(os.path.join(TEST_DIR, "example_skip_1vm.krun"))
n_reboots, sched = run_with_captured_reboots(config, mock_platform,
monkeypatch)
assert n_reboots == 4 # 2 benchmarks, 2 vms, 2 execs, one VM skipped
results = Results(config,
mock_platform,
results_file=config.results_filename())
type_check_results(results)
assert len(results.wallclock_times) == 4 # 2 benchmarks, 2 vms
for key, execs in results.wallclock_times.iteritems():
if "CPython" in key:
assert len(execs) == 0
else:
assert len(execs) == 2
for _exec in execs:
assert len(_exec) == 0 # due to dry run
os.unlink(config.results_filename())
os.unlink(sched.manifest.path)
def test_write_results_to_disk(self, mock_platform,
no_results_instantiation_check):
config = Config("krun/tests/example.krun")
mock_platform.num_cpus = 4
mock_platform.num_per_core_measurements = mock_platform.num_cpus
out_file = "krun/tests/example_results.json.bz2"
results0 = Results(config, mock_platform)
results0.audit = dict()
results0.starting_temperatures = [4355, 9879]
results0.wallclock_times = {u"dummy:Java:default-java": [[1.000726]]}
results0.eta_estimates = {u"dummy:Java:default-java": [1.1]}
results0.core_cycle_counts = {
u"dummy:Java:default-java": [[[2], [3], [4], [5]]]
}
results0.aperf_counts = {
u"dummy:Java:default-java": [[[3], [4], [5], [6]]]
}
results0.mperf_counts = {
u"dummy:Java:default-java": [[[4], [5], [6], [7]]]
}
results0.reboots = 5
results0.error_flag = False
results0.write_to_file()
results1 = Results(config, None, results_file=out_file)
assert results0 == results1
# Clean-up generated file.
os.unlink(out_file)
def test_write_results_to_disk(self, mock_platform):
config = Config("krun/tests/example.krun")
out_file = "krun/tests/example_results.json.bz2"
results0 = Results(config, mock_platform)
results0.audit = dict()
results0.starting_temperatures = [4355, 9879]
results0.data = {u"dummy:Java:default-java": [[1.000726]]}
results0.eta_estimates = {u"dummy:Java:default-java": [1.1]}
results0.reboots = 5
results0.error_flag = False
results0.write_to_file()
results1 = Results(config, None, results_file=out_file)
assert results0 == results1
# Clean-up generated file.
os.unlink(out_file)
def main(parser):
args = parser.parse_args()
if args.dump is not None:
if not args.filename.endswith(".json.bz2"):
usage(parser)
else:
Results.ok_to_instantiate = True
results = Results(None, None, results_file=args.filename)
text = results.dump(args.dump)
# String data read in from JSON are unicode objects. This matters
# for us as some data in the audit includes unicode characters.
# If it does, a simple print no longer suffices if the system
# locale is (e.g.) ASCII. In this case print will raise an
# exception. The correct thing to do is to encode() the unicode to
# the system locale.
print(text.encode(locale.getpreferredencoding()))
sys.exit(0)
if not args.filename.endswith(".krun"):
usage(parser)
try:
if os.stat(args.filename).st_size <= 0:
util.fatal('Krun configuration file %s is empty.' % args.filename)
except OSError:
util.fatal('Krun configuration file %s does not exist.' % args.filename)
config = Config(args.filename)
if args.info:
# Info mode doesn't run the experiment.
# Just prints some metrics and exits.
util.print_session_info(config)
return
manifest_filename = ManifestManager.get_filename(config)
on_first_invocation = not (os.path.isfile(manifest_filename) and
os.stat(manifest_filename).st_size > 0)
log_file = config.log_filename()
if on_first_invocation and os.path.exists(log_file):
util.fatal("Log file '%s' already exists. "
"Move the file away before running Krun." % log_file)
attach_log_file(config, not on_first_invocation)
debug("Krun invoked with arguments: %s" % sys.argv)
mail_recipients = config.MAIL_TO
if type(mail_recipients) is not list:
util.fatal("MAIL_TO config should be a list")
mailer = Mailer(mail_recipients, max_mails=config.MAX_MAILS)
try:
inner_main(mailer, on_first_invocation, config, args)
except Exception as exn:
error_info = sys.exc_info()
subject = "Fatal Krun Exception"
lines = ["Fatal Krun error: %s\n" % str(error_info[1])]
for frame in traceback.format_tb(error_info[2]):
lines.append(frame)
msg = "".join(lines)
util.log_and_mail(mailer, debug, subject, msg, bypass_limiter=True)
raise exn
def test_write_results_to_disk(self, mock_platform,
no_results_instantiation_check):
config = Config("krun/tests/example.krun")
mock_platform.num_cpus = 4
mock_platform.num_per_core_measurements = mock_platform.num_cpus
out_file = "krun/tests/example_results.json.bz2"
results0 = Results(config, mock_platform)
results0.audit = dict()
results0.starting_temperatures = [4355, 9879]
results0.wallclock_times = {u"dummy:Java:default-java": [[1.000726]]}
results0.eta_estimates = {u"dummy:Java:default-java": [1.1]}
results0.core_cycle_counts = {u"dummy:Java:default-java": [[[2], [3], [4], [5]]]}
results0.aperf_counts = {u"dummy:Java:default-java": [[[3], [4], [5], [6]]]}
results0.mperf_counts = {u"dummy:Java:default-java": [[[4], [5], [6], [7]]]}
results0.reboots = 5
results0.error_flag = False
results0.write_to_file()
results1 = Results(config, None, results_file=out_file)
assert results0 == results1
# Clean-up generated file.
os.unlink(out_file)
def inner_main(mailer, config, args):
out_file = config.results_filename()
out_file_exists = os.path.exists(out_file)
if out_file_exists and not os.path.isfile(out_file):
util.fatal(
"Output file '%s' exists but is not a regular file" % out_file)
if out_file_exists and not args.resume:
util.fatal("Output file '%s' already exists. "
"Either resume the session (--resume) or "
"move the file away" % out_file)
if not out_file_exists and args.resume:
util.fatal("No results file to resume. Expected '%s'" % out_file)
if args.started_by_init and not args.reboot:
util.fatal("--started-by-init makes no sense without --reboot")
if args.started_by_init and not args.resume:
util.fatal("--started-by-init makes no sense without --resume")
if args.develop:
warn("Developer mode enabled. Results will not be reliable.")
# Initialise platform instance and assign to VM defs.
# This needs to be done early, so VM sanity checks can run.
platform = detect_platform(mailer)
if not args.develop:
debug("Checking platform preliminaries")
platform.check_preliminaries()
else:
# Needed to skip the use of certain tools and techniques.
# E.g. switching user.
warn("Not checking platform prerequisites due to developer mode")
platform.developer_mode = True
platform.collect_audit()
# If the user has asked for resume-mode, the current platform must
# be an identical machine to the current one.
error_msg = ("You have asked Krun to resume an interrupted benchmark. " +
"This is only valid if the machine you are using is " +
"identical to the one on which the last results were " +
"gathered, which is not the case.")
current = None
if args.resume:
# output file must exist, due to check above
assert(out_file_exists)
current = Results(config, platform, results_file=out_file)
from krun.audit import Audit
if not Audit(platform.audit) == current.audit:
util.fatal(error_msg)
debug("Using pre-recorded initial temperature readings")
platform.starting_temperatures = current.starting_temperatures
else:
# Touch the config file to update its mtime. This is required
# by resume-mode which uses the mtime to determine the name of
# the log file, should this benchmark be resumed.
_, _, rc = util.run_shell_cmd("touch " + args.filename)
if rc != 0:
util.fatal("Could not touch config file: " + args.filename)
info(("Wait %s secs to allow system to cool prior to "
"collecting initial temperature readings") %
config.TEMP_READ_PAUSE)
if args.develop or args.dry_run:
info("SIMULATED: time.sleep(%s)" % config.TEMP_READ_PAUSE)
else:
time.sleep(config.TEMP_READ_PAUSE)
debug("Taking fresh initial temperature readings")
platform.starting_temperatures = platform.take_temperature_readings()
# Assign platform to VM defs -- needs to happen early for sanity checks
util.assign_platform(config, platform)
sanity_checks(config, platform)
# Build job queue -- each job is an execution
sched = ExecutionScheduler(config,
mailer,
platform,
resume=args.resume,
reboot=args.reboot,
dry_run=args.dry_run,
started_by_init=args.started_by_init)
sched.build_schedule()
sched.run()
class ExecutionScheduler(object):
"""Represents our entire benchmarking session"""
def __init__(self,
config,
mailer,
platform,
resume=False,
reboot=False,
dry_run=False,
started_by_init=False):
self.mailer = mailer
self.config = config
self.work_deque = deque()
self.eta_avail = 0
self.jobs_done = 0
self.platform = platform
self.resume = resume
self.reboot = reboot
self.dry_run = dry_run
self.started_by_init = started_by_init
if resume:
self.results = Results(self.config,
platform,
results_file=self.config.results_filename())
else:
self.results = Results(self.config, platform)
self.log_path = self.config.log_filename(self.resume)
def set_eta_avail(self):
"""call after adding job before eta should become available"""
self.eta_avail = len(self)
def jobs_until_eta_known(self):
return self.eta_avail - self.jobs_done
def add_job(self, job):
self.work_deque.append(job)
def remove_job_by_key(self, key):
for job in self.work_deque:
if job.key == key:
job_to_remove = job
break
else:
raise JobMissingError(key)
debug("Removed %s from schedule" % key)
self.work_deque.remove(job_to_remove)
def next_job(self, peek=False):
try:
job = self.work_deque.popleft()
if peek:
self.work_deque.appendleft(job)
return job
except IndexError:
raise ScheduleEmpty() # we are done
def __len__(self):
return len(self.work_deque)
def get_estimated_exec_duration(self, key):
previous_exec_times = self.results.eta_estimates.get(key)
if previous_exec_times:
return mean(previous_exec_times)
else:
return None # we don't know
def get_estimated_overall_duration(self):
etas = [j.get_estimated_exec_duration() for j in self.work_deque]
if None in etas:
return None # we don't know
return sum(etas)
def get_exec_estimate_time_formatter(self, key):
return TimeEstimateFormatter(self.get_estimated_exec_duration(key))
def get_overall_time_estimate_formatter(self):
return TimeEstimateFormatter(self.get_estimated_overall_duration())
def add_eta_info(self, key, exec_time):
self.results.eta_estimates[key].append(exec_time)
def build_schedule(self):
"""Builds a queue of process execution jobs.
Returns two sets: non_skipped_keys, skipped_keys"""
skipped_keys, non_skipped_keys = set(), set()
one_exec_scheduled = False
eta_avail_job = None
for exec_n in xrange(self.config.N_EXECUTIONS):
for vm_name, vm_info in self.config.VMS.items():
for bmark, param in self.config.BENCHMARKS.items():
for variant in vm_info["variants"]:
job = ExecutionJob(self, vm_name, vm_info, bmark,
variant, param)
if not self.config.should_skip(job.key):
non_skipped_keys |= set([job.key])
if one_exec_scheduled and not eta_avail_job:
# first job of second executions eta becomes known.
eta_avail_job = job
self.set_eta_avail()
self.add_job(job)
else:
skipped_keys |= set([job.key])
if not one_exec_scheduled:
debug("%s is in skip list. Not scheduling." %
job.key)
one_exec_scheduled = True
self.expected_reboots = len(self)
# Resume mode: if previous results are available, remove the
# jobs from the schedule which have already been executed, and
# add the results to this object, ready to be saved to a Json file.
if self.resume:
self._remove_previous_execs_from_schedule()
# Sanity check ETA estimates
for key, exec_data in self.results.data.iteritems():
got_len = len(self.results.eta_estimates[key])
expect_len = len(exec_data)
if expect_len != got_len:
msg = "ETA estimates didn't tally with results: "
msg += "key=%s, expect_len=%d, got_len=%d " % \
(key, expect_len, got_len)
msg += "data[%s]=%s; " % (key, str(self.results.data[key]))
msg += "eta[%s]=%s" % \
(key, str(self.results.eta_estimates[key]))
util.log_and_mail(self.mailer,
error,
"Fatal Krun Error",
msg,
bypass_limiter=True,
exit=True)
return non_skipped_keys, skipped_keys
def _remove_previous_execs_from_schedule(self):
for key in self.results.data:
num_completed_jobs = self.results.jobs_completed(key)
if num_completed_jobs > 0:
try:
debug("%s has already been run %d times." %
(key, num_completed_jobs))
for _ in range(num_completed_jobs):
self.remove_job_by_key(key)
self.jobs_done += 1
except JobMissingError as excn:
tup = (excn.key, self.config.filename,
self.config.results_filename())
msg = ("Failed to resume benchmarking session\n." +
"The execution %s appears in results " +
"file: %s, but not in config file: %s." % tup)
util.fatal(msg)
def _make_pre_post_cmd_env(self):
"""Prepare an environment dict for pre/post execution hooks"""
jobs_until_eta_known = self.jobs_until_eta_known()
if jobs_until_eta_known > 0:
eta_val = "Unknown. Known in %d process executions." % \
self.jobs_until_eta_known()
else:
eta_val = self.get_overall_time_estimate_formatter().finish_str
return {
"KRUN_RESULTS_FILE": self.config.results_filename(),
"KRUN_LOG_FILE": self.config.log_filename(resume=True),
"KRUN_ETA_DATUM": now_str(),
"KRUN_ETA_VALUE": eta_val,
}
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 _reboot(self):
self.results.reboots += 1
debug("About to execute reboot: %g, expecting %g in total." %
(self.results.reboots, self.expected_reboots))
# Dump the results file. This may already have been done, but we
# have changed self.nreboots, which needs to be written out.
self.results.write_to_file()
if self.results.reboots > self.expected_reboots:
util.fatal(("HALTING now to prevent an infinite reboot loop: " +
"INVARIANT num_reboots <= num_jobs violated. " +
"Krun was about to execute reboot number: %g. " +
"%g jobs have been completed, %g are left to go.") %
(self.results.reboots, self.jobs_done, len(self)))
if self.dry_run:
info("SIMULATED: reboot (restarting Krun in-place)")
args = sys.argv
if not self.started_by_init:
args.extend(["--resume", "--started-by-init"])
debug("Simulated reboot with args: " + " ".join(args))
os.execv(args[0], args) # replace myself
assert False # unreachable
else:
subprocess.call(self.platform.get_reboot_cmd())
def inner_main(mailer, on_first_invocation, config, args):
out_file = config.results_filename()
out_file_exists = os.path.exists(out_file)
instr_dir = util.get_instr_json_dir(config)
instr_dir_exists = os.path.exists(instr_dir)
envlog_dir = util.get_envlog_dir(config)
envlog_dir_exists = os.path.exists(envlog_dir)
if out_file_exists and not os.path.isfile(out_file):
util.fatal(
"Output file '%s' exists but is not a regular file" % out_file)
if out_file_exists and on_first_invocation:
util.fatal("Output results file '%s' already exists. "
"Move the file away before running Krun." % out_file)
if instr_dir_exists and on_first_invocation:
util.fatal("Instrumentation dir '%s' exists." % instr_dir)
if envlog_dir_exists and on_first_invocation:
util.fatal("Env log dir '%s' exists." % envlog_dir)
if not out_file_exists and not on_first_invocation:
util.fatal("No results file to resume. Expected '%s'" % out_file)
# Initialise platform instance and assign to VM defs.
# This needs to be done early, so VM sanity checks can run.
platform = detect_platform(mailer, config)
platform.quick_mode = args.quick
platform.no_user_change = args.no_user_change
platform.no_tickless_check = args.no_tickless_check
platform.no_pstate_check = args.no_pstate_check
platform.hardware_reboots = args.hardware_reboots
# Create the instrumentation directory if required
if on_first_invocation:
# We only want make a dir if >=1 VM is in instrumentation mode.
for vm in config.VMS.itervalues():
if vm['vm_def'].instrument:
util.make_instr_dir(config)
break
debug("Checking platform preliminaries")
platform.check_preliminaries()
# Make a bit of noise if this is a virtualised environment
if platform.is_virtual():
warn("This appears to be a virtualised host. The results will be flawed. "
"Use bare-metal for reliable results!")
platform.collect_audit()
# At this point the config file is OK, and on-disk state is consistent,
# so let's daemonise (if requested).
if args.daemonise:
util.daemonise()
if not on_first_invocation:
# output file must exist, due to check above
assert(out_file_exists)
debug("Using pre-recorded initial temperature readings")
manifest = ManifestManager(config, platform)
platform_temps = {}
for sensor, tup in manifest.starting_temperatures.iteritems():
platform_temps[sensor] = tup[1]
platform.starting_temperatures = platform_temps
else:
manifest = ManifestManager(config, platform, new_file=True)
if manifest.num_execs_left == 0:
# No executions, or all skipped
fatal("Empty schedule!")
try:
info(("Wait %s secs to allow system to cool prior to "
"collecting initial temperature readings") %
config.TEMP_READ_PAUSE)
# This part is wrapped in hooks, so that if daemons or networking are
# taken down for process executions, then the initial temperature
# reading gets the same treatment.
util.run_shell_cmd_list(config.PRE_EXECUTION_CMDS,)
platform.sleep(config.TEMP_READ_PAUSE)
debug("Taking fresh initial temperature readings")
platform.starting_temperatures = platform.take_temperature_readings()
manifest.set_starting_temperatures(platform.starting_temperatures)
# Write out an empty results file. After the initial reboot Krun
# will expect this to exist.
Results.ok_to_instantiate = True
results = Results(config, platform)
results.write_to_file()
except:
raise
finally:
util.run_shell_cmd_list(config.POST_EXECUTION_CMDS,)
log_path = config.log_filename(resume=False)
util.log_and_mail(mailer, debug,
"Benchmarking started",
"Benchmarking started.\nLogging to %s" %
log_path, bypass_limiter=True)
util.reboot(manifest, platform)
# Assign platform to VM defs -- needs to happen early for sanity checks
util.assign_platform(config, platform)
sanity_checks(config, platform)
# Build job queue -- each job is an execution
sched = ExecutionScheduler(config,
mailer,
platform,
dry_run=args.dry_run)
sched.run()
def inner_main(mailer, on_first_invocation, config, args):
out_file = config.results_filename()
out_file_exists = os.path.exists(out_file)
instr_dir = util.get_instr_json_dir(config)
instr_dir_exists = os.path.exists(instr_dir)
envlog_dir = util.get_envlog_dir(config)
envlog_dir_exists = os.path.exists(envlog_dir)
if out_file_exists and not os.path.isfile(out_file):
util.fatal("Output file '%s' exists but is not a regular file" %
out_file)
if out_file_exists and on_first_invocation:
util.fatal("Output results file '%s' already exists. "
"Move the file away before running Krun." % out_file)
if instr_dir_exists and on_first_invocation:
util.fatal("Instrumentation dir '%s' exists." % instr_dir)
if envlog_dir_exists and on_first_invocation:
util.fatal("Env log dir '%s' exists." % envlog_dir)
if not out_file_exists and not on_first_invocation:
util.fatal("No results file to resume. Expected '%s'" % out_file)
# Initialise platform instance and assign to VM defs.
# This needs to be done early, so VM sanity checks can run.
platform = detect_platform(mailer, config)
platform.quick_mode = args.quick
platform.no_user_change = args.no_user_change
platform.no_tickless_check = args.no_tickless_check
platform.no_pstate_check = args.no_pstate_check
platform.hardware_reboots = args.hardware_reboots
# Create the instrumentation directory if required
if on_first_invocation:
# We only want make a dir if >=1 VM is in instrumentation mode.
for vm in config.VMS.itervalues():
if vm['vm_def'].instrument:
util.make_instr_dir(config)
break
debug("Checking platform preliminaries")
platform.check_preliminaries()
# Make a bit of noise if this is a virtualised environment
if platform.is_virtual():
warn(
"This appears to be a virtualised host. The results will be flawed. "
"Use bare-metal for reliable results!")
platform.collect_audit()
# At this point the config file is OK, and on-disk state is consistent,
# so let's daemonise (if requested).
if args.daemonise:
util.daemonise()
if not on_first_invocation:
# output file must exist, due to check above
assert (out_file_exists)
debug("Using pre-recorded initial temperature readings")
manifest = ManifestManager(config, platform)
platform_temps = {}
for sensor, tup in manifest.starting_temperatures.iteritems():
platform_temps[sensor] = tup[1]
platform.starting_temperatures = platform_temps
else:
manifest = ManifestManager(config, platform, new_file=True)
if manifest.num_execs_left == 0:
# No executions, or all skipped
fatal("Empty schedule!")
try:
info(("Wait %s secs to allow system to cool prior to "
"collecting initial temperature readings") %
config.TEMP_READ_PAUSE)
# This part is wrapped in hooks, so that if daemons or networking are
# taken down for process executions, then the initial temperature
# reading gets the same treatment.
util.run_shell_cmd_list(config.PRE_EXECUTION_CMDS, )
platform.sleep(config.TEMP_READ_PAUSE)
debug("Taking fresh initial temperature readings")
platform.starting_temperatures = platform.take_temperature_readings(
)
manifest.set_starting_temperatures(platform.starting_temperatures)
# Write out an empty results file. After the initial reboot Krun
# will expect this to exist.
Results.ok_to_instantiate = True
results = Results(config, platform)
results.write_to_file()
except:
raise
finally:
util.run_shell_cmd_list(config.POST_EXECUTION_CMDS, )
log_path = config.log_filename(resume=False)
util.log_and_mail(mailer,
debug,
"Benchmarking started",
"Benchmarking started.\nLogging to %s" % log_path,
bypass_limiter=True)
util.reboot(manifest, platform)
# Assign platform to VM defs -- needs to happen early for sanity checks
util.assign_platform(config, platform)
sanity_checks(config, platform)
# Build job queue -- each job is an execution
sched = ExecutionScheduler(config, mailer, platform, dry_run=args.dry_run)
sched.run()
def main(parser):
args = parser.parse_args()
if args.dump is not None:
if not args.filename.endswith(".json.bz2"):
usage(parser)
else:
Results.ok_to_instantiate = True
results = Results(None, None, results_file=args.filename)
text = results.dump(args.dump)
# String data read in from JSON are unicode objects. This matters
# for us as some data in the audit includes unicode characters.
# If it does, a simple print no longer suffices if the system
# locale is (e.g.) ASCII. In this case print will raise an
# exception. The correct thing to do is to encode() the unicode to
# the system locale.
print(text.encode(locale.getpreferredencoding()))
sys.exit(0)
if not args.filename.endswith(".krun"):
usage(parser)
try:
if os.stat(args.filename).st_size <= 0:
util.fatal('Krun configuration file %s is empty.' % args.filename)
except OSError:
util.fatal('Krun configuration file %s does not exist.' %
args.filename)
config = Config(args.filename)
if args.info:
# Info mode doesn't run the experiment.
# Just prints some metrics and exits.
util.print_session_info(config)
return
manifest_filename = ManifestManager.get_filename(config)
on_first_invocation = not (os.path.isfile(manifest_filename)
and os.stat(manifest_filename).st_size > 0)
log_file = config.log_filename()
if on_first_invocation and os.path.exists(log_file):
util.fatal("Log file '%s' already exists. "
"Move the file away before running Krun." % log_file)
attach_log_file(config, not on_first_invocation)
debug("Krun invoked with arguments: %s" % sys.argv)
mail_recipients = config.MAIL_TO
if type(mail_recipients) is not list:
util.fatal("MAIL_TO config should be a list")
mailer = Mailer(mail_recipients, max_mails=config.MAX_MAILS)
try:
inner_main(mailer, on_first_invocation, config, args)
except Exception as exn:
error_info = sys.exc_info()
subject = "Fatal Krun Exception"
lines = ["Fatal Krun error: %s\n" % str(error_info[1])]
for frame in traceback.format_tb(error_info[2]):
lines.append(frame)
msg = "".join(lines)
util.log_and_mail(mailer, debug, subject, msg, bypass_limiter=True)
raise exn
def run(self):
"""Benchmark execution starts here"""
# In reboot mode, wait for the system to come up before we proceed
if self.platform.hardware_reboots:
debug("Waiting %s seconds for the system to come up." %
str(STARTUP_WAIT_SECONDS))
self.platform.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()
assert self.manifest.num_execs_left > 0
self.platform.wait_for_temperature_sensors()
bench, vm, variant = self.manifest.next_exec_key.split(":")
key_pexec_idx = self.manifest.next_exec_key_index()
job = ExecutionJob(self, vm, self.config.VMS[vm], bench, variant,
self.config.BENCHMARKS[bench], key_pexec_idx)
# Default to error state. This is the value the finally block will see
# if an exception is raised inside the try block, otherwise it is
# re-assigned based on the result of running the benchmark.
flag = 'E'
# Run the pre-exec commands, the benchmark and the post-exec commands.
# These are wrapped in a try/except, so that the post-exec commands
# are always executed, even if an exception has occurred. We only
# reboot /after/ the post-exec commands have completed.
results = None
try:
# Run the user's pre-process-execution commands. We can't put an
# ETA estimate in the environment for the pre-commands as we have
# not (and should not) load the results file into memory yet.
#
# It might seem tempting to move this outside the try block, to
# ensure that post-hooks are only run if pre-hooks ran. We don't,
# thus avoiding the case where only *part* of the pre-hooks run,
# but the post-hooks then don't run.
util.run_shell_cmd_list(self.config.PRE_EXECUTION_CMDS,)
# 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()
measurements, instr_data, flag = job.run(self.mailer, self.dry_run)
exec_end_time = time.time()
# Only now is it OK to load the results file into memory.
Results.ok_to_instantiate = True
results = Results(self.config, self.platform,
results_file=self.config.results_filename())
# Bail early if the process execution needs to be re-run.
if flag == "O":
util.run_shell_cmd_list(
self.config.POST_EXECUTION_CMDS,
extra_env=self._make_post_cmd_env(results)
)
info("Rebooting to re-run previous process execution")
util.reboot(self.manifest, self.platform, update_count=False)
# reboot() does not return
raise RuntimeError("reached unreachable code!")
# Store new result.
results.append_exec_measurements(job.key, measurements, flag)
# Store instrumentation data in a separate file
if job.vm_info["vm_def"].instrument:
key_exec_num = self.manifest.completed_exec_counts[job.key]
util.dump_instr_json(job.key, key_exec_num, self.config, instr_data)
eta_info = exec_end_time - exec_start_time
if self.platform.hardware_reboots:
# Add time taken to wait for system to come up if we are in
# hardware-reboot mode.
eta_info += STARTUP_WAIT_SECONDS
results.eta_estimates[job.key].append(eta_info)
self.manifest.update(flag)
except Exception:
raise
finally:
# 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.
# _make_post_cmd_env() needs the results to make an ETA. If an
# exception occurred in the above try block, there's a chance that
# they have not have been loaded.
if results is None:
Results.ok_to_instantiate = True
results = Results(self.config, self.platform,
results_file=self.config.results_filename())
# If errors occured, set error flag in results file
if self.platform.check_dmesg_for_changes(self.manifest) or \
flag == 'E':
results.error_flag = True
results.write_to_file()
util.run_shell_cmd_list(
self.config.POST_EXECUTION_CMDS,
extra_env=self._make_post_cmd_env(results)
)
tfmt = self.get_overall_time_estimate_formatter(results)
if self.manifest.eta_avail_idx == self.manifest.next_exec_idx:
# 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 (whole session)", tfmt.finish_str,
tfmt.delta_str))
info("%d executions left in scheduler queue" % self.manifest.num_execs_left)
if self.manifest.num_execs_left > 0 and \
self.manifest.eta_avail_idx > self.manifest.next_exec_idx:
info("Executions until ETA known: %s" %
(self.manifest.eta_avail_idx -
self.manifest.next_exec_idx))
# Although it would have been nice to have checked this prior to
# running the execution, it depends on the results file, which we
# should not load prior to the process execution.
util.check_audit_unchanged(results, self.platform)
assert self.manifest.num_execs_left >= 0
if self.manifest.num_execs_left > 0:
# print info about the next job
benchmark, vm_name, variant = \
self.manifest.next_exec_key.split(":")
info("Next execution is '%s(%d)' (%s variant) under '%s'" %
(benchmark, self.config.BENCHMARKS[benchmark], variant, vm_name))
tfmt = self.get_exec_estimate_time_formatter(job.key, results)
info("{:<35s}: {} ({} from now)".format(
"Estimated completion (next execution)",
tfmt.finish_str,
tfmt.delta_str))
info("Reboot in preparation for next execution")
util.reboot(self.manifest, self.platform)
elif self.manifest.num_execs_left == 0:
self.platform.save_power()
if self.config.ENABLE_PINNING:
self.platform.clear_cpu_pinning()
info("Done: Results dumped to %s" % self.config.results_filename())
err_msg = "Errors/warnings occurred -- read the log!"
if results.error_flag:
warn(err_msg)
msg = "Session completed. Log file at: '%s'" % (self.log_path)
if results.error_flag:
msg += "\n\n%s" % err_msg
msg += "\n\nDon't forget to disable Krun at boot."
util.log_and_mail(self.mailer, info, "Benchmarks Complete", msg,
bypass_limiter=True)
class ExecutionScheduler(object):
"""Represents our entire benchmarking session"""
def __init__(self, config, mailer, platform,
resume=False, reboot=False, dry_run=False,
started_by_init=False):
self.mailer = mailer
self.config = config
self.work_deque = deque()
self.eta_avail = 0
self.jobs_done = 0
self.platform = platform
self.resume = resume
self.reboot = reboot
self.dry_run = dry_run
self.started_by_init = started_by_init
if resume:
self.results = Results(self.config, platform,
results_file=self.config.results_filename())
else:
self.results = Results(self.config, platform)
self.log_path = self.config.log_filename(self.resume)
def set_eta_avail(self):
"""call after adding job before eta should become available"""
self.eta_avail = len(self)
def jobs_until_eta_known(self):
return self.eta_avail - self.jobs_done
def add_job(self, job):
self.work_deque.append(job)
def remove_job_by_key(self, key):
for job in self.work_deque:
if job.key == key:
job_to_remove = job
break
else:
raise JobMissingError(key)
debug("Removed %s from schedule" % key)
self.work_deque.remove(job_to_remove)
def next_job(self, peek=False):
try:
job = self.work_deque.popleft()
if peek:
self.work_deque.appendleft(job)
return job
except IndexError:
raise ScheduleEmpty() # we are done
def __len__(self):
return len(self.work_deque)
def get_estimated_exec_duration(self, key):
previous_exec_times = self.results.eta_estimates.get(key)
if previous_exec_times:
return mean(previous_exec_times)
else:
return None # we don't know
def get_estimated_overall_duration(self):
etas = [j.get_estimated_exec_duration() for j in self.work_deque]
if None in etas:
return None # we don't know
return sum(etas)
def get_exec_estimate_time_formatter(self, key):
return TimeEstimateFormatter(self.get_estimated_exec_duration(key))
def get_overall_time_estimate_formatter(self):
return TimeEstimateFormatter(self.get_estimated_overall_duration())
def add_eta_info(self, key, exec_time):
self.results.eta_estimates[key].append(exec_time)
def build_schedule(self):
"""Builds a queue of process execution jobs.
Returns two sets: non_skipped_keys, skipped_keys"""
skipped_keys, non_skipped_keys = set(), set()
one_exec_scheduled = False
eta_avail_job = None
for exec_n in xrange(self.config.N_EXECUTIONS):
for vm_name, vm_info in self.config.VMS.items():
for bmark, param in self.config.BENCHMARKS.items():
for variant in vm_info["variants"]:
job = ExecutionJob(self, vm_name, vm_info, bmark, variant, param)
if not self.config.should_skip(job.key):
non_skipped_keys |= set([job.key])
if one_exec_scheduled and not eta_avail_job:
# first job of second executions eta becomes known.
eta_avail_job = job
self.set_eta_avail()
self.add_job(job)
else:
skipped_keys |= set([job.key])
if not one_exec_scheduled:
debug("%s is in skip list. Not scheduling." %
job.key)
one_exec_scheduled = True
self.expected_reboots = len(self)
# Resume mode: if previous results are available, remove the
# jobs from the schedule which have already been executed, and
# add the results to this object, ready to be saved to a Json file.
if self.resume:
self._remove_previous_execs_from_schedule()
# Sanity check ETA estimates
for key, exec_data in self.results.data.iteritems():
got_len = len(self.results.eta_estimates[key])
expect_len = len(exec_data)
if expect_len != got_len:
msg = "ETA estimates didn't tally with results: "
msg += "key=%s, expect_len=%d, got_len=%d " % \
(key, expect_len, got_len)
msg += "data[%s]=%s; " % (key, str(self.results.data[key]))
msg += "eta[%s]=%s" % \
(key, str(self.results.eta_estimates[key]))
util.log_and_mail(self.mailer, error,
"Fatal Krun Error",
msg, bypass_limiter=True, exit=True)
return non_skipped_keys, skipped_keys
def _remove_previous_execs_from_schedule(self):
for key in self.results.data:
num_completed_jobs = self.results.jobs_completed(key)
if num_completed_jobs > 0:
try:
debug("%s has already been run %d times." %
(key, num_completed_jobs))
for _ in range(num_completed_jobs):
self.remove_job_by_key(key)
self.jobs_done += 1
except JobMissingError as excn:
tup = (excn.key, self.config.filename,
self.config.results_filename())
msg = ("Failed to resume benchmarking session\n." +
"The execution %s appears in results " +
"file: %s, but not in config file: %s." % tup)
util.fatal(msg)
def _make_pre_post_cmd_env(self):
"""Prepare an environment dict for pre/post execution hooks"""
jobs_until_eta_known = self.jobs_until_eta_known()
if jobs_until_eta_known > 0:
eta_val = "Unknown. Known in %d process executions." % \
self.jobs_until_eta_known()
else:
eta_val = self.get_overall_time_estimate_formatter().finish_str
return {
"KRUN_RESULTS_FILE": self.config.results_filename(),
"KRUN_LOG_FILE": self.config.log_filename(resume=True),
"KRUN_ETA_DATUM": now_str(),
"KRUN_ETA_VALUE": eta_val,
}
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 _reboot(self):
self.results.reboots += 1
debug("About to execute reboot: %g, expecting %g in total." %
(self.results.reboots, self.expected_reboots))
# Dump the results file. This may already have been done, but we
# have changed self.nreboots, which needs to be written out.
self.results.write_to_file()
if self.results.reboots > self.expected_reboots:
util.fatal(("HALTING now to prevent an infinite reboot loop: " +
"INVARIANT num_reboots <= num_jobs violated. " +
"Krun was about to execute reboot number: %g. " +
"%g jobs have been completed, %g are left to go.") %
(self.results.reboots, self.jobs_done, len(self)))
if self.dry_run:
info("SIMULATED: reboot (restarting Krun in-place)")
args = sys.argv
if not self.started_by_init:
args.extend(["--resume", "--started-by-init"])
debug("Simulated reboot with args: " + " ".join(args))
os.execv(args[0], args) # replace myself
assert False # unreachable
else:
subprocess.call(self.platform.get_reboot_cmd())