From 2ad9a9b27a0eaf6a1e256727caf14106da07c626 Mon Sep 17 00:00:00 2001 From: rexlee8776 Date: Wed, 13 Sep 2017 08:29:08 +0000 Subject: improve logging, clear using print Change-Id: I744353f631cf1771d75f750543e8612f81be71ee Signed-off-by: rexlee8776 --- yardstick/__init__.py | 4 +-- yardstick/benchmark/contexts/heat.py | 8 +++--- yardstick/benchmark/core/plugin.py | 10 +++---- yardstick/benchmark/core/task.py | 32 ++++++++++------------ yardstick/benchmark/runners/duration.py | 5 ++-- .../benchmark/scenarios/lib/create_keypair.py | 2 +- yardstick/benchmark/scenarios/networking/ping.py | 2 +- yardstick/cmd/commands/task.py | 6 ++-- yardstick/orchestrator/heat.py | 14 +++++----- 9 files changed, 40 insertions(+), 43 deletions(-) diff --git a/yardstick/__init__.py b/yardstick/__init__.py index c1010d98c..b673e7c4a 100644 --- a/yardstick/__init__.py +++ b/yardstick/__init__.py @@ -16,9 +16,7 @@ from yardstick.common import utils as yardstick_utils yardstick_utils.makedirs(constants.LOG_DIR) LOG_FILE = os.path.join(constants.LOG_DIR, 'yardstick.log') -LOG_FORMATTER = ('%(asctime)s ' - '%(name)s %(filename)s:%(lineno)d ' - '%(levelname)s %(message)s') +LOG_FORMATTER = '%(asctime)s [%(levelname)s] %(name)s %(filename)s:%(lineno)d %(message)s' _LOG_FORMATTER = logging.Formatter(LOG_FORMATTER) _LOG_STREAM_HDLR = logging.StreamHandler() diff --git a/yardstick/benchmark/contexts/heat.py b/yardstick/benchmark/contexts/heat.py index 575467f8f..0802c9a64 100644 --- a/yardstick/benchmark/contexts/heat.py +++ b/yardstick/benchmark/contexts/heat.py @@ -295,7 +295,7 @@ class HeatContext(Context): def deploy(self): """deploys template into a stack using cloud""" - print("Deploying context '%s'" % self.name) + LOG.info("Deploying context '%s' START", self.name) heat_template = HeatTemplate(self.name, self.template_file, self.heat_parameters) @@ -325,7 +325,7 @@ class HeatContext(Context): server.public_ip = \ self.stack.outputs[server.floating_ip["stack_name"]] - print("Context '%s' deployed" % self.name) + LOG.info("Deploying context '%s' DONE", self.name) def add_server_port(self, server): # TODO(hafe) can only handle one internal network for now @@ -364,10 +364,10 @@ class HeatContext(Context): def undeploy(self): """undeploys stack from cloud""" if self.stack: - print("Undeploying context '%s'" % self.name) + LOG.info("Undeploying context '%s' START", self.name) self.stack.delete() self.stack = None - print("Context '%s' undeployed" % self.name) + LOG.info("Undeploying context '%s' DONE", self.name) if os.path.exists(self.key_filename): try: diff --git a/yardstick/benchmark/core/plugin.py b/yardstick/benchmark/core/plugin.py index 24f1b6b25..56ecd29d9 100644 --- a/yardstick/benchmark/core/plugin.py +++ b/yardstick/benchmark/core/plugin.py @@ -38,19 +38,19 @@ class Plugin(object): plugins, deployment = parser.parse_plugin() plugin_name = plugins.get("name") - print("Installing plugin: %s" % plugin_name) + LOG.info("Installing plugin: %s", plugin_name) - LOG.info("Executing _install_setup()") + LOG.debug("Executing _install_setup()") self._install_setup(plugin_name, deployment) - LOG.info("Executing _run()") + LOG.debug("Executing _run()") self._run(plugin_name) total_end_time = time.time() - LOG.info("total finished in %d secs", + LOG.info("Total finished in %d secs", total_end_time - total_start_time) - print("Done, exiting") + LOG.info("Plugin %s Done, exiting", plugin_name) def remove(self, args): """Remove a plugin.""" diff --git a/yardstick/benchmark/core/task.py b/yardstick/benchmark/core/task.py index a49a2cb71..9fc097d42 100644 --- a/yardstick/benchmark/core/task.py +++ b/yardstick/benchmark/core/task.py @@ -97,8 +97,8 @@ class Task(object): # pragma: no cover task_args = [args.task_args] task_args_fnames = [args.task_args_file] - LOG.info("\ntask_files:%s, \ntask_args:%s, \ntask_args_fnames:%s", - task_files, task_args, task_args_fnames) + LOG.debug("task_files:%s, task_args:%s, task_args_fnames:%s", + task_files, task_args, task_args_fnames) if args.parse_only: sys.exit(0) @@ -139,7 +139,7 @@ class Task(object): # pragma: no cover context.undeploy() self.contexts = [] one_task_end_time = time.time() - LOG.info("task %s finished in %d secs", task_files[i], + LOG.info("Task %s finished in %d secs", task_files[i], one_task_end_time - one_task_start_time) result = self._get_format_result(testcases) @@ -148,14 +148,13 @@ class Task(object): # pragma: no cover self._generate_reporting(result) total_end_time = time.time() - LOG.info("total finished in %d secs", + LOG.info("Total finished in %d secs", total_end_time - total_start_time) scenario = scenarios[0] - print("To generate report execute => yardstick report generate ", - scenario['task_id'], scenario['tc']) - - print("Done, exiting") + LOG.info("To generate report, execute command " + "'yardstick report generate %(task_id)s %(tc)s'", scenario) + LOG.info("Task ALL DONE, exiting") return result def _generate_reporting(self, result): @@ -163,7 +162,7 @@ class Task(object): # pragma: no cover with open(constants.REPORTING_FILE, 'w') as f: f.write(env.from_string(report_template).render(result)) - LOG.info('yardstick reporting generate in %s', constants.REPORTING_FILE) + LOG.info("Report can be found in '%s'", constants.REPORTING_FILE) def _set_log(self): log_format = '%(asctime)s %(name)s %(filename)s:%(lineno)d %(levelname)s %(message)s' @@ -265,7 +264,7 @@ class Task(object): # pragma: no cover raise RuntimeError self.outputs.update(runner.get_output()) result.extend(runner.get_result()) - print("Runner ended, output in", output_file) + LOG.info("Runner ended, output in %s", output_file) else: # run serially for scenario in scenarios: @@ -277,7 +276,7 @@ class Task(object): # pragma: no cover raise RuntimeError self.outputs.update(runner.get_output()) result.extend(runner.get_result()) - print("Runner ended, output in", output_file) + LOG.info("Runner ended, output in %s", output_file) # Abort background runners for runner in background_runners: @@ -302,7 +301,7 @@ class Task(object): # pragma: no cover base_runner.Runner.terminate_all() if self.contexts: - print("Undeploying all contexts") + LOG.info("Undeploying all contexts") for context in self.contexts[::-1]: context.undeploy() @@ -365,7 +364,7 @@ class Task(object): # pragma: no cover context_cfg["nodes"]) runner = base_runner.Runner.get(runner_cfg) - print("Starting runner of type '%s'" % runner_cfg["type"]) + LOG.info("Starting runner of type '%s'", runner_cfg["type"]) runner.run(scenario_cfg, context_cfg) return runner @@ -477,7 +476,7 @@ class TaskParser(object): # pragma: no cover def parse_task(self, task_id, task_args=None, task_args_file=None): """parses the task file and return an context and scenario instances""" - print("Parsing task config:", self.path) + LOG.info("Parsing task config: %s", self.path) try: kw = {} @@ -494,10 +493,9 @@ class TaskParser(object): # pragma: no cover input_task = f.read() rendered_task = TaskTemplate.render(input_task, **kw) except Exception as e: - print("Failed to render template:\n%(task)s\n%(err)s\n" - % {"task": input_task, "err": e}) + LOG.exception('Failed to render template:\n%s\n', input_task) raise e - print("Input task is:\n%s\n" % rendered_task) + LOG.debug("Input task is:\n%s\n", rendered_task) cfg = yaml_load(rendered_task) except IOError as ioerror: diff --git a/yardstick/benchmark/runners/duration.py b/yardstick/benchmark/runners/duration.py index 69d744562..c2c6a8f19 100644 --- a/yardstick/benchmark/runners/duration.py +++ b/yardstick/benchmark/runners/duration.py @@ -40,7 +40,8 @@ def _worker_process(queue, cls, method_name, scenario_cfg, interval = runner_cfg.get("interval", 1) duration = runner_cfg.get("duration", 60) - LOG.info("worker START, duration %d sec, class %s", duration, cls) + LOG.info("Worker START, duration is %ds", duration) + LOG.debug("class is %s", cls) runner_cfg['runner_id'] = os.getpid() @@ -95,7 +96,7 @@ def _worker_process(queue, cls, method_name, scenario_cfg, if (errors and sla_action is None) or \ (time.time() - start > duration or aborted.is_set()): - LOG.info("worker END") + LOG.info("Worker END") break benchmark.teardown() diff --git a/yardstick/benchmark/scenarios/lib/create_keypair.py b/yardstick/benchmark/scenarios/lib/create_keypair.py index 2185bfa5d..f5b1fff7a 100644 --- a/yardstick/benchmark/scenarios/lib/create_keypair.py +++ b/yardstick/benchmark/scenarios/lib/create_keypair.py @@ -47,7 +47,7 @@ class CreateKeypair(base.Scenario): rsa_key = paramiko.RSAKey.generate(bits=2048, progress_func=None) rsa_key.write_private_key_file(self.key_filename) - print("Writing %s ..." % self.key_filename) + LOG.info("Writing key_file %s ...", self.key_filename) with open(self.key_filename + ".pub", "w") as pubkey_file: pubkey_file.write( "%s %s\n" % (rsa_key.get_name(), rsa_key.get_base64())) diff --git a/yardstick/benchmark/scenarios/networking/ping.py b/yardstick/benchmark/scenarios/networking/ping.py index 6a7927de4..3bade73e2 100644 --- a/yardstick/benchmark/scenarios/networking/ping.py +++ b/yardstick/benchmark/scenarios/networking/ping.py @@ -67,7 +67,7 @@ class Ping(base.Scenario): else: target_vm = self.scenario_cfg['target'] - LOG.debug("ping '%s' '%s'", options, dest) + LOG.debug("ping %s %s", options, dest) with open(self.target_script, "r") as stdin_file: exit_status, stdout, stderr = self.connection.execute( "/bin/sh -s {0} {1}".format(dest, options), diff --git a/yardstick/cmd/commands/task.py b/yardstick/cmd/commands/task.py index bd5447836..e2e8bf67d 100644 --- a/yardstick/cmd/commands/task.py +++ b/yardstick/cmd/commands/task.py @@ -51,7 +51,7 @@ class TaskCommands(object): # pragma: no cover self.output_file = param.output_file result = {} - + LOG.info('Task START') try: result = Task().start(param, **kwargs) except Exception as e: @@ -59,9 +59,9 @@ class TaskCommands(object): # pragma: no cover LOG.exception("") if result.get('result', {}).get('criteria') == 'PASS': - LOG.info('Task Success') + LOG.info('Task SUCCESS') else: - LOG.info('Task Failed') + LOG.info('Task FAILED') raise RuntimeError('Task Failed') def _write_error_data(self, error): diff --git a/yardstick/orchestrator/heat.py b/yardstick/orchestrator/heat.py index 8c7b1e429..455ddc34e 100644 --- a/yardstick/orchestrator/heat.py +++ b/yardstick/orchestrator/heat.py @@ -89,14 +89,14 @@ class HeatStack(HeatObject): if self.uuid is None: return - log.info("Deleting stack '%s', uuid:%s", self.name, self.uuid) + log.info("Deleting stack '%s' START, uuid:%s", self.name, self.uuid) heat = self.heat_client template = heat.stacks.get(self.uuid) start_time = time.time() template.delete() for status in iter(self.status, u'DELETE_COMPLETE'): - log.debug("stack state %s", status) + log.debug("Deleting stack state: %s", status) if status == u'DELETE_FAILED': raise RuntimeError( heat.stacks.get(self.uuid).stack_status_reason) @@ -104,7 +104,7 @@ class HeatStack(HeatObject): time.sleep(2) end_time = time.time() - log.info("Deleted stack '%s' in %d secs", self.name, + log.info("Deleting stack '%s' DONE in %d secs", self.name, end_time - start_time) self.uuid = None @@ -599,7 +599,7 @@ name (i.e. %s).\ :param: timeout: timeout in seconds for Heat create, default 3600s :type timeout: int """ - log.info("Creating stack '%s'", self.name) + log.info("Creating stack '%s' START", self.name) # create stack early to support cleanup, e.g. ctrl-c while waiting stack = HeatStack(self.name) @@ -613,13 +613,13 @@ name (i.e. %s).\ if not block: self.outputs = stack.outputs = {} end_time = time.time() - log.info("Created stack '%s' in %.3e secs", + log.info("Creating stack '%s' DONE in %d secs", self.name, end_time - start_time) return stack time_limit = start_time + timeout for status in iter(self.status, self.HEAT_CREATE_COMPLETE_STATUS): - log.debug("stack state %s", status) + log.debug("Creating stack state: %s", status) if status == u'CREATE_FAILED': stack_status_reason = heat_client.stacks.get(self.uuid).stack_status_reason heat_client.stacks.delete(self.uuid) @@ -631,7 +631,7 @@ name (i.e. %s).\ end_time = time.time() outputs = heat_client.stacks.get(self.uuid).outputs - log.info("Created stack '%s' in %.3e secs", + log.info("Creating stack '%s' DONE in %d secs", self.name, end_time - start_time) # keep outputs as unicode -- cgit 1.2.3-korg