summaryrefslogtreecommitdiffstats
path: root/src/osmo_gsm_tester/suite.py
diff options
context:
space:
mode:
authorNeels Hofmeyr <nhofmeyr@sysmocom.de>2017-06-10 01:18:27 +0200
committerNeels Hofmeyr <nhofmeyr@sysmocom.de>2017-06-13 13:32:01 +0200
commit1a7a3f0e4318bccbd3ed177d5b07fa3618d06868 (patch)
tree7ff22b29e37be6cdd8ad2b2737cfe2fee2aa01dc /src/osmo_gsm_tester/suite.py
parent0e57aadd280ec40bd3b8754f6169fc507b1b25bf (diff)
fix and refactor logging: drop 'with', simplify
With the recent fix of the junit report related issues, another issue arose: the 'with log.Origin' was changed to disallow __enter__ing an object twice to fix problems, now still code would fail because it tries to do 'with' on the same object twice. The only reason is to ensure that logging is associated with a given object. Instead of complicating even more, implement differently. Refactor logging to simplify use: drop the 'with Origin' style completely, and instead use the python stack to determine which objects are created by which, and which object to associate a log statement with. The new way: we rely on the convention that each class instance has a local 'self' referencing the object instance. If we need to find an origin as a new object's parent, or to associate a log message with, we traverse each stack frame, fetching the first local 'self' object that is a log.Origin class instance. How to use: Simply call log.log() anywhere, and it finds an Origin object to log for, from the stack. Alternatively call self.log() for any Origin() object to skip the lookup. Create classes as child class of log.Origin and make sure to call super().__init__(category, name). This constructor will magically find a parent Origin on the stack. When an exception happens, we first escalate the exception up through call scopes to where ever it is handled by log.log_exn(). This then finds an Origin object in the traceback's stack frames, no need to nest in 'with' scopes. Hence the 'with log.Origin' now "happens implicitly", we can write pure natural python code, no more hassles with scope ordering. Furthermore, any frame can place additional logging information in a frame by calling log.ctx(). This is automatically inserted in the ancestry associated with a log statement / exception. Change-Id: I5f9b53150f2bb6fa9d63ce27f0806f0ca6a45e90
Diffstat (limited to 'src/osmo_gsm_tester/suite.py')
-rw-r--r--src/osmo_gsm_tester/suite.py91
1 files changed, 43 insertions, 48 deletions
diff --git a/src/osmo_gsm_tester/suite.py b/src/osmo_gsm_tester/suite.py
index 55f81b1..eeaf7df 100644
--- a/src/osmo_gsm_tester/suite.py
+++ b/src/osmo_gsm_tester/suite.py
@@ -49,9 +49,8 @@ class SuiteDefinition(log.Origin):
def __init__(self, suite_dir):
- self.set_log_category(log.C_CNF)
self.suite_dir = suite_dir
- self.set_name(os.path.basename(self.suite_dir))
+ super().__init__(log.C_CNF, os.path.basename(self.suite_dir))
self.read_conf()
def read_conf(self):
@@ -78,12 +77,10 @@ class Test(log.Origin):
FAIL = 'FAIL'
def __init__(self, suite_run, test_basename):
- self.suite_run = suite_run
self.basename = test_basename
+ super().__init__(log.C_TST, self.basename)
+ self.suite_run = suite_run
self.path = os.path.join(self.suite_run.definition.suite_dir, self.basename)
- super().__init__(self.path)
- self.set_name(self.basename)
- self.set_log_category(log.C_TST)
self.status = Test.UNKNOWN
self.start_timestamp = 0
self.duration = 0
@@ -92,16 +89,15 @@ class Test(log.Origin):
def run(self):
try:
- with self:
- log.large_separator(self.suite_run.trial.name(), self.suite_run.name(), self.name(), sublevel=3)
- self.status = Test.UNKNOWN
- self.start_timestamp = time.time()
- test.setup(self.suite_run, self, ofono_client, sys.modules[__name__], event_loop)
- with self.redirect_stdout():
- util.run_python_file('%s.%s' % (self.suite_run.definition.name(), self.basename),
- self.path)
- if self.status == Test.UNKNOWN:
- self.set_pass()
+ log.large_separator(self.suite_run.trial.name(), self.suite_run.name(), self.name(), sublevel=3)
+ self.status = Test.UNKNOWN
+ self.start_timestamp = time.time()
+ test.setup(self.suite_run, self, ofono_client, sys.modules[__name__], event_loop)
+ with self.redirect_stdout():
+ util.run_python_file('%s.%s' % (self.suite_run.definition.name(), self.basename),
+ self.path)
+ if self.status == Test.UNKNOWN:
+ self.set_pass()
except Exception as e:
if hasattr(e, 'msg'):
msg = e.msg
@@ -110,14 +106,14 @@ class Test(log.Origin):
if isinstance(e, AssertionError):
# AssertionError lacks further information on what was
# asserted. Find the line where the code asserted:
- msg += log.get_src_from_tb(sys.exc_info()[2])
+ msg += log.get_src_from_exc_info(sys.exc_info())
# add source file information to failure report
if hasattr(e, 'origins'):
msg += ' [%s]' % e.origins
tb_str = traceback.format_exc()
if isinstance(e, resource.NoResourceExn):
tb_str += self.suite_run.resource_status_str()
- self.set_fail(type(e).__name__, msg, tb_str)
+ self.set_fail(type(e).__name__, msg, tb_str, log.get_src_from_exc_info())
except BaseException as e:
# when the program is aborted by a signal (like Ctrl-C), escalate to abort all.
self.err('TEST RUN ABORTED: %s' % type(e).__name__)
@@ -129,7 +125,7 @@ class Test(log.Origin):
return '%s:%s' % (self._name, l)
return super().name()
- def set_fail(self, fail_type, fail_message, tb_str=None):
+ def set_fail(self, fail_type, fail_message, tb_str=None, src=4):
self.status = Test.FAIL
self.duration = time.time() - self.start_timestamp
self.fail_type = fail_type
@@ -140,9 +136,9 @@ class Test(log.Origin):
tb_str = ''.join(traceback.format_stack()[:-1])
self.fail_tb = tb_str
- self.err('%s: %s' % (self.fail_type, self.fail_message))
+ self.err('%s: %s' % (self.fail_type, self.fail_message), _src=src)
if self.fail_tb:
- self.trace(self.fail_tb)
+ self.log(self.fail_tb, _level=log.L_TRACEBACK)
self.log('Test FAILED (%.1f sec)' % self.duration)
def set_pass(self):
@@ -171,11 +167,10 @@ class SuiteRun(log.Origin):
_processes = None
def __init__(self, trial, suite_scenario_str, suite_definition, scenarios=[]):
+ super().__init__(log.C_TST, suite_scenario_str)
self.trial = trial
self.definition = suite_definition
self.scenarios = scenarios
- self.set_name(suite_scenario_str)
- self.set_log_category(log.C_TST)
self.resources_pool = resource.ResourcesPool()
self.status = SuiteRun.UNKNOWN
self.load_tests()
@@ -201,18 +196,18 @@ class SuiteRun(log.Origin):
self.status = SuiteRun.UNKNOWN
def combined(self, conf_name):
- self.dbg(combining=conf_name)
- with log.Origin(combining_scenarios=conf_name):
- combination = copy.deepcopy(self.definition.conf.get(conf_name) or {})
- self.dbg(definition_conf=combination)
- for scenario in self.scenarios:
- with scenario:
- c = scenario.get(conf_name)
- self.dbg(scenario=scenario.name(), conf=c)
- if c is None:
- continue
- config.combine(combination, c)
- return combination
+ log.dbg(combining=conf_name)
+ log.ctx(combining_scenarios=conf_name)
+ combination = copy.deepcopy(self.definition.conf.get(conf_name) or {})
+ log.dbg(definition_conf=combination)
+ for scenario in self.scenarios:
+ log.ctx(combining_scenarios=conf_name, scenario=scenario.name())
+ c = scenario.get(conf_name)
+ log.dbg(scenario=scenario.name(), conf=c)
+ if c is None:
+ continue
+ config.combine(combination, c)
+ return combination
def resource_requirements(self):
if self._resource_requirements is None:
@@ -232,19 +227,18 @@ class SuiteRun(log.Origin):
def run_tests(self, names=None):
try:
- with self:
- log.large_separator(self.trial.name(), self.name(), sublevel=2)
- self.mark_start()
- event_loop.register_poll_func(self.poll)
- if not self.reserved_resources:
- self.reserve_resources()
- for test in self.tests:
- if names and not test.name() in names:
- test.set_skip()
- continue
- test.run()
+ log.large_separator(self.trial.name(), self.name(), sublevel=2)
+ self.mark_start()
+ event_loop.register_poll_func(self.poll)
+ if not self.reserved_resources:
+ self.reserve_resources()
+ for test in self.tests:
+ if names and not test.name() in names:
+ test.set_skip()
+ continue
+ test.run()
except Exception:
- self.log_exn()
+ log.log_exn()
except BaseException as e:
# when the program is aborted by a signal (like Ctrl-C), escalate to abort all.
self.err('SUITE RUN ABORTED: %s' % type(e).__name__)
@@ -355,7 +349,8 @@ class SuiteRun(log.Origin):
if process.terminated():
process.log_stdout_tail()
process.log_stderr_tail()
- process.raise_exn('Process ended prematurely')
+ log.ctx(process)
+ raise log.Error('Process ended prematurely')
def prompt(self, *msgs, **msg_details):
'ask for user interaction. Do not use in tests that should run automatically!'