From 89655940e65a7e3fabe4fe8a2ca49527a3094221 Mon Sep 17 00:00:00 2001 From: wym_libra Date: Tue, 13 Oct 2015 16:19:01 +0800 Subject: [PATCH] add error handling when given failing script calls JIRA:YARDSTICK-100 Change-Id: I1986b5e443abf186ef9c0235b66ada26c8574af1 Signed-off-by: wym_libra --- yardstick/benchmark/runners/base.py | 93 ++++++++++++++++++++++++++++--------- 1 file changed, 70 insertions(+), 23 deletions(-) mode change 100644 => 100755 yardstick/benchmark/runners/base.py diff --git a/yardstick/benchmark/runners/base.py b/yardstick/benchmark/runners/base.py old mode 100644 new mode 100755 index 265e5d158..c3fe6b104 --- a/yardstick/benchmark/runners/base.py +++ b/yardstick/benchmark/runners/base.py @@ -12,6 +12,7 @@ import logging import multiprocessing import subprocess import time +import traceback log = logging.getLogger(__name__) @@ -43,13 +44,33 @@ def _output_serializer_main(filename, queue): dispatcher.record_result_data(record) +def _execute_shell_command(command): + '''execute shell script with error handling''' + exitcode = 0 + output = [] + try: + output = subprocess.check_output(command, shell=True) + except Exception: + exitcode = -1 + output = traceback.format_exc() + log.error("exec command '%s' error:\n " % command) + log.error(traceback.format_exc()) + + return exitcode, output + + def _single_action(seconds, command, queue): '''entrypoint for the single action process''' log.debug("single action, fires after %d seconds (from now)", seconds) time.sleep(seconds) log.debug("single action: executing command: '%s'", command) - data = subprocess.check_output(command, shell=True) - log.debug("\n%s" % data) + ret_code, data = _execute_shell_command(command) + if ret_code < 0: + log.error("single action error! command:%s" % command) + queue.put({'single-action-data': data}) + return + log.debug("single action data: \n%s" % data) + queue.put({'single-action-data': data}) def _periodic_action(interval, command, queue): @@ -60,8 +81,13 @@ def _periodic_action(interval, command, queue): time.sleep(interval) time_spent += interval log.debug("periodic action, executing command: '%s'", command) - data = subprocess.check_output(command, shell=True) - log.debug("\n%s" % data) + ret_code, data = _execute_shell_command(command) + if ret_code < 0: + log.error("periodic action error! command:%s", command) + queue.put({'periodic-action-data': data}) + break + log.debug("periodic action data: \n%s" % data) + queue.put({'periodic-action-data': data}) class Runner(object): @@ -102,27 +128,43 @@ class Runner(object): return Runner.get_cls(config["type"])(config, Runner.queue) + @staticmethod + def release_dump_process(): + '''Release the dumper process''' + log.debug("Stopping dump process") + if Runner.dump_process: + Runner.queue.put('_TERMINATE_') + Runner.dump_process.join() + Runner.dump_process = None + @staticmethod def release(runner): '''Release the runner''' Runner.runners.remove(runner) + # if this was the last runner, stop the output serializer subprocess if len(Runner.runners) == 0: - log.debug("Stopping dump process") - Runner.queue.put('_TERMINATE_') - Runner.dump_process.join() + Runner.release_dump_process() @staticmethod def terminate_all(): '''Terminate all runners (subprocesses)''' log.debug("Terminating all runners") + + # release dumper process as some errors before any runner is created + if len(Runner.runners) == 0: + Runner.release_dump_process() + return + for runner in Runner.runners: + log.debug("Terminating runner: %s", runner) + if runner.process: + runner.process.terminate() + runner.process.join() if runner.periodic_action_process: log.debug("Terminating periodic action process") runner.periodic_action_process.terminate() runner.periodic_action_process = None - runner.process.terminate() - runner.process.join() Runner.release(runner) def __init__(self, config, queue): @@ -130,27 +172,21 @@ class Runner(object): self.config = config self.periodic_action_process = None self.result_queue = queue + self.process = None Runner.runners.append(self) - def run_pre_start_action(self): - '''run a potentially configured pre-start action''' - if "pre-start-action" in self.config: - command = self.config["pre-start-action"]["command"] - log.debug("pre start action: command: '%s'" % command) - data = subprocess.check_output(command, shell=True) - log.debug("pre-start data: \n%s" % data) - output = "{'pre-start-action-data': %s}" % data - self.result_queue.put(output) - def run_post_stop_action(self): '''run a potentially configured post-stop action''' if "post-stop-action" in self.config: command = self.config["post-stop-action"]["command"] log.debug("post stop action: command: '%s'" % command) - data = subprocess.check_output(command, shell=True) + ret_code, data = _execute_shell_command(command) + if ret_code < 0: + log.error("post action error! command:%s", command) + self.result_queue.put({'post-stop-action-data': data}) + return log.debug("post-stop data: \n%s" % data) - output = "{'post-stop-action-data': %s}" % data - self.result_queue.put(output) + self.result_queue.put({'post-stop-action-data': data}) def run(self, scenario_type, scenario_cfg): class_name = base_scenario.Scenario.get(scenario_type) @@ -161,7 +197,17 @@ class Runner(object): self.config['object'] = class_name - self.run_pre_start_action() + # run a potentially configured pre-start action + if "pre-start-action" in self.config: + command = self.config["pre-start-action"]["command"] + log.debug("pre start action: command: '%s'" % command) + ret_code, data = _execute_shell_command(command) + if ret_code < 0: + log.error("pre-start action error! command:%s", command) + self.result_queue.put({'pre-start-action-data': data}) + return + log.debug("pre-start data: \n%s" % data) + self.result_queue.put({'pre-start-action-data': data}) if "single-shot-action" in self.config: single_action_process = multiprocessing.Process( @@ -188,5 +234,6 @@ class Runner(object): if self.periodic_action_process: self.periodic_action_process.terminate() self.periodic_action_process = None + self.run_post_stop_action() return self.process.exitcode -- 2.16.6