openstack/rally
Code Issues Proposed changes

Improve Rally Logging (part 1)

Browse Source 
- Remove translations

  Nobody is using translations for Rally and I don't think that
  anybody is going to use it. Target auditory for Rally are
  developers/operators which usually know well english.
  For me this looks like waste of resources, performance
  degradation (cause we are calling _()), complexity
  (+1 thing that you need to know)

- Pass to log already formatted strings

  It's very bad because in case of wrong formatting, it
  doesn't fail instead just writes errors to the logs,
  as well information about trace is lost, so it's super
  hard to fix it

  Log wrapper doesn't allow to use LOG anymore for
  formatting strings

  All places are fixed

- Improve logging of exceptions

LOG.exception() already logs exception, which means it's bad idea to
pass str(e) to it. Instead we should provide clear description of what
happend. Improved few places to write warnings or exceptions in case
of different level of logs. In few places just use LOG.exception

- Part of log messages were improved and simplified

Change-Id: I800995395e1a8fec61da009906430bc5001e3779
This commit is contained in:
Boris Pavlovic 2017-09-25 14:11:54 -07:00
parent 1f0985ae16
commit d98de652c1
14 changed files with 28 additions and 64 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

8
rally/plugins/common/hook/sys_call.py
View File

@ -37,18 +37,18 @@ class SysCallHook(hook.Hook):
}
def run(self):
LOG.debug("sys_call hook: Running command %s", self.config)
LOG.debug("sys_call hook: Running command %s" % self.config)
proc = subprocess.Popen(shlex.split(self.config),
stdout=subprocess.PIPE,
stderr=subprocess.PIPE,
universal_newlines=True)
out, err = proc.communicate()
LOG.debug("sys_call hook: Command %s returned %s",
self.config, proc.returncode)
LOG.debug("sys_call hook: Command %s returned %s"
% (self.config, proc.returncode))
if proc.returncode:
self.set_error(
exception_name="n/a", # no exception class
description="Subprocess returned {}".format(proc.returncode),
description="Subprocess returned %s" % proc.returncode,
details=(err or "stdout: %s" % out))
# NOTE(amaretskiy): Try to load JSON for charts,

6
rally/plugins/common/runners/rps.py
View File

@ -97,9 +97,9 @@ def _worker_process(queue, iteration_gen, timeout, times, max_concurrent,
time_gap = time.time() - start
real_rps = i / time_gap if time_gap else "Infinity"
LOG.debug("Worker: %s rps: %s (requested rps: %s)",
i, real_rps, runs_per_second(rps_cfg, start,
processes_to_start))
LOG.debug(
"Worker: %s rps: %s (requested rps: %s)" %
(i, real_rps, runs_per_second(rps_cfg, start, processes_to_start)))
# try to join latest thread(s) until it finished, or until time to
# start new thread (if we have concurrent slots available)

5
rally/plugins/common/scenarios/dummy/dummy.py
View File

@ -12,7 +12,6 @@
import random
from rally.common.i18n import _
from rally.common import utils
from rally.common import validation
from rally import exceptions
@ -25,7 +24,7 @@ from rally.task import scenario
class DummyScenarioException(exceptions.RallyException):
error_code = 530
msg_fmt = _("Dummy scenario expected exception: '%(message)s'")
msg_fmt = "Dummy scenario expected exception: '%(message)s'"
@scenario.configure(name="Dummy.failure")
@ -46,7 +45,7 @@ class DummyFailure(scenario.Scenario):
utils.interruptable_sleep(sleep)
if from_iteration <= self.context["iteration"] <= to_iteration:
if each and not self.context["iteration"] % each:
raise DummyScenarioException(_("Expected failure"))
raise DummyScenarioException("Expected failure")
@scenario.configure(name="Dummy.dummy")

3
rally/plugins/common/scenarios/requests/utils.py
View File

@ -12,7 +12,6 @@
import requests
from rally.common.i18n import _
from rally.task import atomic
from rally.task import scenario
@ -34,6 +33,6 @@ class RequestScenario(scenario.Scenario):
resp = requests.request(method, url, **kwargs)
if status_code != resp.status_code:
error_msg = _("Expected HTTP request code is `%s` actual `%s`")
error_msg = "Expected HTTP request code is `%s` actual `%s`"
raise ValueError(
error_msg % (status_code, resp.status_code))

7
rally/plugins/common/sla/failure_rate.py
View File

@ -19,7 +19,6 @@ SLA (Service-level agreement) is set of details for determining compliance
with contracted values such as maximum error rate or minimum response time.
"""
from rally.common.i18n import _
from rally import consts
from rally.task import sla
@ -63,6 +62,6 @@ class FailureRate(sla.SLA):
return self.success
def details(self):
return (_("Failure rate criteria %.2f%% <= %.2f%% <= %.2f%% - %s") %
(self.min_percent, self.error_rate, self.max_percent,
self.status()))
return ("Failure rate criteria %.2f%% <= %.2f%% <= %.2f%% - %s" %
(self.min_percent, self.error_rate,
self.max_percent, self.status()))

3
rally/plugins/common/sla/iteration_time.py
View File

@ -19,7 +19,6 @@ SLA (Service-level agreement) is set of details for determining compliance
with contracted values such as maximum error rate or minimum response time.
"""
from rally.common.i18n import _
from rally.task import sla
@ -46,5 +45,5 @@ class IterationTime(sla.SLA):
return self.success
def details(self):
return (_("Maximum seconds per iteration %.2fs <= %.2fs - %s") %
return ("Maximum seconds per iteration %.2fs <= %.2fs - %s" %
(self.max_iteration_time, self.criterion_value, self.status()))

3
rally/plugins/common/sla/max_average_duration.py
View File

@ -19,7 +19,6 @@ SLA (Service-level agreement) is set of details for determining compliance
with contracted values such as maximum error rate or minimum response time.
"""
from rally.common.i18n import _
from rally.common import streaming_algorithms
from rally.task import sla
@ -49,5 +48,5 @@ class MaxAverageDuration(sla.SLA):
return self.success
def details(self):
return (_("Average duration of one iteration %.2fs <= %.2fs - %s") %
return ("Average duration of one iteration %.2fs <= %.2fs - %s" %
(self.avg, self.criterion_value, self.status()))

7
rally/plugins/common/sla/max_average_duration_per_atomic.py
View File

@ -21,7 +21,6 @@ with contracted values such as maximum error rate or minimum response time.
import collections
from rally.common.i18n import _
from rally.common import streaming_algorithms
from rally import consts
from rally.task import sla
@ -66,9 +65,9 @@ class MaxAverageDurationPerAtomic(sla.SLA):
return self.success
def details(self):
strs = [_("Action: '%s'. %.2fs <= %.2fs") %
strs = ["Action: '%s'. %.2fs <= %.2fs" %
(atom, self.avg_by_action[atom], val)
for atom, val in self.criterion_items]
head = _("Average duration of one iteration for atomic actions:")
end = _("Status: %s") % self.status()
head = "Average duration of one iteration for atomic actions:"
end = "Status: %s" % self.status()
return "\n".join([head] + strs + [end])

3
rally/plugins/common/sla/outliers.py
View File

@ -19,7 +19,6 @@ SLA (Service-level agreement) is set of details for determining compliance
with contracted values such as maximum error rate or minimum response time.
"""
from rally.common.i18n import _
from rally.common import streaming_algorithms
from rally import consts
from rally.task import sla
@ -108,5 +107,5 @@ class Outliers(sla.SLA):
return self.success
def details(self):
return (_("Maximum number of outliers %i <= %i - %s") %
return ("Maximum number of outliers %i <= %i - %s" %
(self.outliers, self.max_outliers, self.status()))

7
rally/plugins/common/sla/performance_degradation.py
View File

@ -21,7 +21,6 @@ with contracted values such as maximum error rate or minimum response time.
from __future__ import division
from rally.common.i18n import _
from rally.common import streaming_algorithms
from rally.common import utils
from rally import consts
@ -69,6 +68,6 @@ class PerformanceDegradation(sla.SLA):
return self.success
def details(self):
return (_("Current degradation: %s%% - %s") %
(utils.format_float_to_str(self.degradation.result() or 0.0),
self.status()))
return ("Current degradation: %s%% - %s" %
(utils.format_float_to_str(self.degradation.result() or 0.0),
self.status()))

7
rally/plugins/common/validators.py
View File

@ -276,7 +276,7 @@ class RequiredContextsValidator(validation.Validator):
if isinstance(name, tuple):
if not set(name) & set(input_context):
# formatted string like: 'foo or bar or baz'
formatted_names = "'{}'".format(" or ".join(name))
formatted_names = "'%s'" % " or ".join(name)
missing_contexts.append(formatted_names)
else:
if name not in input_context:
@ -301,9 +301,8 @@ class RequiredParamOrContextValidator(validation.Validator):
self.ctx_name = ctx_name
def validate(self, context, config, plugin_cls, plugin_cfg):
msg = ("You should specify either scenario argument {} or"
" use context {}.").format(self.param_name,
self.ctx_name)
msg = ("You should specify either scenario argument %s or"
" use context %s." % (self.param_name, self.ctx_name))
if self.ctx_name in config.get("context", {}):
return

7
rally/plugins/common/verification/testr.py
View File

@ -17,7 +17,6 @@ import re
import shutil
import subprocess
from rally.common.i18n import _LE
from rally.common.io import subunit_v2
from rally.common import logging
from rally.common import utils as common_utils
@ -98,8 +97,7 @@ class TestrLauncher(manager.VerifierManager):
except (subprocess.CalledProcessError, OSError):
if os.path.exists(test_repository_dir):
shutil.rmtree(test_repository_dir)
raise exceptions.RallyException(
_LE("Failed to initialize testr."))
raise exceptions.RallyException("Failed to initialize testr.")
def install(self):
super(TestrLauncher, self).install()
@ -116,7 +114,8 @@ class TestrLauncher(manager.VerifierManager):
"""Run tests."""
testr_cmd = context["testr_cmd"]
run_args = context.get("run_args", {})
LOG.debug("Test(s) started by the command: '%s'.", " ".join(testr_cmd))
LOG.debug("Test(s) started by the command: '%s'."
% " ".join(testr_cmd))
stream = subprocess.Popen(testr_cmd, env=self.run_environ,
cwd=self.repo_dir,
stdout=subprocess.PIPE,

19
tests/hacking/checks.py
View File

@ -177,24 +177,6 @@ def check_import_of_logging(logical_line, physical_line, filename):
"use `rally.common.logging` instead.")
@skip_ignored_lines
def no_translate_debug_logs(logical_line, physical_line, filename):
"""Check for "LOG.debug(_("
As per our translation policy,
https://wiki.openstack.org/wiki/LoggingStandards#Log_Translation
we shouldn't translate debug level logs.
* This check assumes that 'LOG' is a logger.
* Use filename so we can start enforcing this in specific folders instead
of needing to do so all at once.
N311
"""
if logical_line.startswith("LOG.debug(_("):
yield(0, "N311 Don't translate debug level logs")
@skip_ignored_lines
def no_use_conf_debug_check(logical_line, physical_line, filename):
"""Check for "cfg.CONF.debug"
@ -606,7 +588,6 @@ def check_opts_import_path(logical_line, physical_line, filename):
def factory(register):
register(check_assert_methods_from_mock)
register(check_import_of_logging)
register(no_translate_debug_logs)
register(no_use_conf_debug_check)
register(assert_true_instance)
register(assert_equal_type)

7
tests/unit/test_hacking.py
View File

@ -112,13 +112,6 @@ class HackingTestCase(test.TestCase):
checkres = checks.check_import_of_logging(good, good, "fakefile")
self.assertEqual([], list(checkres))
def test_no_translate_debug_logs(self):
bad_samples = ["LOG.debug(_('foo'))"]
self._assert_bad_samples(checks.no_translate_debug_logs, bad_samples)
good_samples = ["LOG.debug('foo')", "LOG.info(_('foo'))"]
self._assert_good_samples(checks.no_translate_debug_logs, good_samples)
def test_no_use_conf_debug_check(self):
bad_samples = [
"if CONF.debug:",