def run_individual_task(self, task, *args, **kwargs):
LOG.info("-" * 60)
LOG.info("Starting task %s" % task)
try:
test_time = kwargs['db'][kwargs['tool_name']][task]
except KeyError:
LOG.info("You must update the database time tests. "
"There is no time for %s", task)
else:
exp_time = utils.seconds_to_humantime(test_time)
LOG.info("Expected time to complete the test: %s ", exp_time)
self._run_ostf_on_docker(task)
LOG.info("-" * 60)
def run_batch(self, tasks, *args, **kwargs):
with self.store('rally.log', 'tempest.log'):
tool_name = kwargs["tool_name"]
all_time = kwargs["all_time"]
elapsed_time = kwargs["elapsed_time"]
# Note (ayasakov): the database execution time of each test.
# In the first run for each test tool calculate the multiplier,
# which shows the difference of execution time between testing
# on our cloud and the current cloud.
db = kwargs.get('db')
first_run = True
multiplier = 1.0
test_time = 0
all_time -= elapsed_time
self.create_cirros_image()
self._setup_rally_on_docker()
# NOTE(ogrytsenko): only test-suites are discoverable for tempest
if not kwargs.get('run_by_name'):
cid = self.container_id
tasks, missing = self.discovery(cid).match(tasks)
self.test_not_found.extend(missing)
t = []
tempest_task_results_details = {}
LOG.info("Time start: %s UTC\n" % str(datetime.datetime.utcnow()))
for task in tasks:
LOG.info("-" * 60)
task = task.replace(' ', '')
if kwargs.get('event').is_set():
LOG.info("Keyboard interrupt. Set %s won't start" % task)
break
time_start = datetime.datetime.utcnow()
LOG.info('Running %s tempest set' % task)
LOG.debug("Time start: %s UTC" % str(time_start))
if not CONF.times.update:
try:
test_time = db[tool_name][task]
except KeyError:
test_time = 0
exp_time = utils.seconds_to_humantime(test_time *
multiplier)
msg = "Expected time to complete %s: %s"
if not test_time:
LOG.debug(msg, task, exp_time)
else:
LOG.info(msg, task, exp_time)
self.run_individual_task(task, *args, **kwargs)
time_end = datetime.datetime.utcnow()
time = time_end - time_start
LOG.debug("Time end: %s UTC" % str(time_end))
if CONF.times.update:
if tool_name in db.keys():
db[tool_name].update({task: time.seconds})
else:
db.update({tool_name: {task: time.seconds}})
else:
if first_run:
first_run = False
if test_time:
multiplier = float(time.seconds) / float(test_time)
all_time -= test_time
persent = 1.0
if kwargs["all_time"]:
persent -= float(all_time) / float(kwargs["all_time"])
persent = int(persent * 100)
persent = 100 if persent > 100 else persent
line = 'Completed %s' % persent + '%'
time_str = utils.seconds_to_humantime(all_time *
multiplier)
if all_time and multiplier:
line += ' and remaining time %s' % time_str
LOG.info(line)
LOG.info("-" * 60)
t.append(self.task['test_cases'].keys())
tempest_task_results_details[task] = {
# overall number of tests in suit
"tests": self.task.get("tests", 0),
"test_succeed": self.task.get("success", 0),
"test_failed": self.task.get("failures", 0),
"test_skipped": self.task.get("skipped", 0),
"expected_failures": self.task.get("expected_failures", 0)
}
if self.failed_cases > CONF.tempest.max_failed_tests:
LOG.info('*LIMIT OF FAILED TESTS EXCEEDED! STOP RUNNING.*')
self.failure_indicator = \
TempestError.FAILED_TEST_LIMIT_EXCESS
break
if CONF.times.update:
with open(TIMES_DB_PATH, "w") as f:
json.dump(db, f)
LOG.info("\nTime end: %s UTC" % str(datetime.datetime.utcnow()))
self.cleanup_toolbox()
self.cleanup_cirros_image()
return {"test_failures": self.test_failures,
"test_success": self.test_success,
"test_not_found": self.test_not_found,
"time_of_tests": self.time_of_tests,
"tempest_tests_details": tempest_task_results_details,
}
def _exec_tests(self, test_plan, **kwargs):
elapsed_time_by_group = dict()
dispatch_result = {}
with open(TIMES_DB_PATH, 'r') as fd:
db = json.load(fd)
if not CONF.times.update:
for key in test_plan.keys():
batch = [x for x in (''.join(test_plan[key].split()
).split(',')) if x]
elapsed_time_by_group[key] = self.all_time
for test in batch:
test = test.replace(' ', '')
try:
self.all_time += db[key][test]
except KeyError:
LOG.info("You must update the database time tests. "
"There is no time for %s", test)
msg = "Expected time to complete all the tests: %s\n"
time_str = utils.seconds_to_humantime(self.all_time)
if self.all_time == 0:
LOG.debug(msg, time_str)
else:
LOG.info(msg, time_str)
for key in test_plan:
if self.ctx.terminate_event.is_set():
LOG.info("Catch Keyboard interrupt. "
"No more tests will be launched")
break
if CONF.times.update:
elapsed_time_by_group[key] = 0
# FIXME(dbogun): rewrite timesdb implementation
# We must reload timesdb because plugin (probably) update id
with open(TIMES_DB_PATH, 'rt') as fd:
db = json.load(fd)
dispatch_result[key] = {}
try:
spawn_point = os.path.dirname(__file__)
path_to_runner = os.path.join(spawn_point, self.plugin_dir,
key, "runner.py")
module = imp.load_source("runner" + key, path_to_runner)
except IOError as e:
LOG.debug("Looks like there is no such runner: %s.", key)
dispatch_result[key]['major_crash'] = 1
LOG.error("The following exception has been caught: %s", e)
LOG.debug(traceback.format_exc())
self.failure_indicator = CAError.RUNNER_LOAD_ERROR
except Exception:
dispatch_result[key]['major_crash'] = 1
LOG.error("Something went wrong. "
"Please check mcvconsoler logs")
LOG.debug(traceback.format_exc())
self.failure_indicator = CAError.RUNNER_LOAD_ERROR
else:
path = os.path.join(self.results_dir, key)
os.mkdir(path)
factory = getattr(module, CONF[key]['runner'])
runner = factory(context.Context(
self.ctx,
work_dir=utils.WorkDir(
path, parent=self.ctx.work_dir_global)))
batch = test_plan[key]
if isinstance(batch, basestring):
batch = [batch]
LOG.debug("Running {batch} for {key}"
.format(batch=len(batch),
key=key))
try:
run_failures = runner.run_batch(
batch,
compute=1,
event=self.ctx.terminate_event,
scenario=self.scenario,
tool_name=key,
db=db,
all_time=self.all_time,
elapsed_time=elapsed_time_by_group[key],
**kwargs
)
if len(run_failures['test_failures']) > 0:
if self.failure_indicator == CAError.NO_ERROR:
self.failure_indicator = runner.failure_indicator
else:
self.failure_indicator = \
ComplexError.SOME_SUITES_FAILED
except subprocess.CalledProcessError as e:
if e.returncode == 127:
LOG.debug(("It looks like you are trying to use a "
"wrong runner. No tests will be run in "
"this group this time. Reply %s"), e)
self.failure_indicator = CAError.WRONG_RUNNER
except Exception:
self.failure_indicator = CAError.UNKNOWN_EXCEPTION
LOG.error("Something went wrong. "
"Please check mcvconsoler logs")
LOG.debug(traceback.format_exc())
else:
dispatch_result[key]['results'] = run_failures
dispatch_result[key]['batch'] = batch
return dispatch_result
def run_batch(self, tasks, *args, **kwargs):
"""Runs a bunch of tasks."""
tool_name = kwargs["tool_name"]
all_time = kwargs["all_time"]
elapsed_time = kwargs["elapsed_time"]
try:
max_failed_tests = CONF[tool_name]['max_failed_tests']
except NoSuchOptError:
max_failed_tests = config.DEFAULT_FAILED_TEST_LIMIT
LOG.debug("The following tests will be run:")
LOG.debug("\n".join(tasks))
failures = 0
# Note(ayasakov): the database execution time of each test.
# In the first run for each test tool calculate the multiplier,
# which shows the difference of execution time between testing
# on our cloud and the current cloud.
db = kwargs.get('db')
first_run = True
multiplier = 1.0
current_time = 0
all_time -= elapsed_time
self._validate_test_params(**kwargs)
for task in tasks:
LOG.info("-" * 60)
if kwargs.get('event').is_set():
LOG.info("Caught keyboard interrupt. "
"Task %s won't start", task)
break
time_start = datetime.datetime.utcnow()
LOG.debug("Running task %s", task)
LOG.debug("Time start: %s UTC", time_start)
if not CONF.times.update:
try:
current_time = db[tool_name][task]
except KeyError:
current_time = 0
msg = "Expected time to complete %s: %s"
t = utils.seconds_to_humantime(current_time * multiplier)
if not current_time:
LOG.debug(msg, task, t)
else:
LOG.info(msg, task, t)
# FIXME(dbogun): sort out exceptions handling
try:
if self.run_individual_task(task, *args, **kwargs):
self.test_success.append(task)
else:
failures += 1
except Exception:
failures += 1
LOG.debug(traceback.format_exc())
time_end = datetime.datetime.utcnow()
duration = time_end - time_start
duration = duration.total_seconds()
LOG.debug("Time end: %s UTC" % str(time_end))
if CONF.times.update:
if tool_name in db.keys():
db[tool_name].update({task: int(duration)})
else:
db.update({tool_name: {task: int(duration)}})
else:
if first_run:
first_run = False
if current_time:
multiplier = duration / current_time
all_time -= current_time
percent = 1.0
if kwargs["all_time"]:
percent -= float(all_time) / float(kwargs["all_time"])
percent = int(percent * 100)
percent = 100 if percent > 100 else percent
line = 'Completed {} %'.format(percent)
if all_time and multiplier:
t = utils.seconds_to_humantime(all_time * multiplier)
line = '{} and remaining time {}'.format(line, t)
LOG.info(line)
LOG.info("-" * 60)
if failures >= max_failed_tests:
LOG.info('*LIMIT OF FAILED TESTS EXCEEDED! STOP RUNNING.*')
self.failure_indicator = self.get_error_code(tool_name)
break
if CONF.times.update:
with open(config.TIMES_DB_PATH, "w") as f:
json.dump(db, f)
return {"test_failures": self.test_failures,
"test_success": self.test_success,
"test_not_found": self.test_not_found,
"test_skipped": self.test_skipped,
"time_of_tests": self.time_of_tests,
"test_without_report": self.test_without_report}
