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
diff --git a/src/osmo_gsm_tester/config.py b/src/osmo_gsm_tester/config.py
index 38d8e2f..20ae83e 100644
--- a/src/osmo_gsm_tester/config.py
+++ b/src/osmo_gsm_tester/config.py
@@ -95,7 +95,7 @@
         real_l = os.path.realpath(l)
         p = os.path.realpath(os.path.join(real_l, basename))
         if os.path.isfile(p):
-            log.dbg(None, log.C_CNF, 'Found config file', basename, 'as', p, 'in', l, 'which is', real_l)
+            log.dbg('Found config file', basename, 'as', p, 'in', l, 'which is', real_l, _category=log.C_CNF)
             return (p, real_l)
     if not fail_if_missing:
         return None, None
@@ -122,7 +122,7 @@
     env_path = os.getenv(env_name)
     if env_path:
         real_env_path = os.path.realpath(env_path)
-        log.dbg(None, log.C_CNF, 'Found path', label, 'as', env_path, 'in', '$' + env_name, 'which is', real_env_path)
+        log.dbg('Found path', label, 'as', env_path, 'in', '$' + env_name, 'which is', real_env_path, _category=log.C_CNF)
         return real_env_path
 
     if PATHS is None:
@@ -132,15 +132,15 @@
         for key, path in sorted(PATHS.items()):
             if not path.startswith(os.pathsep):
                 PATHS[key] = os.path.realpath(os.path.join(found_in, path))
-                log.dbg(None, log.C_CNF, paths_file + ': relative path', path, 'is', PATHS[key])
+                log.dbg(paths_file + ': relative path', path, 'is', PATHS[key], _category=log.C_CNF)
     p = PATHS.get(label)
     if p is None and not allow_unset:
         raise RuntimeError('missing configuration in %s: %r' % (PATHS_CONF, label))
 
-    log.dbg(None, log.C_CNF, 'Found path', label, 'as', p)
+    log.dbg('Found path', label, 'as', p, _category=log.C_CNF)
     if p.startswith(PATHS_TEMPDIR_STR):
         p = os.path.join(get_tempdir(), p[len(PATHS_TEMPDIR_STR):])
-        log.dbg(None, log.C_CNF, 'Path', label, 'contained', PATHS_TEMPDIR_STR, 'and becomes', p)
+        log.dbg('Path', label, 'contained', PATHS_TEMPDIR_STR, 'and becomes', p, _category=log.C_CNF)
     return p
 
 def get_state_dir():
@@ -153,20 +153,20 @@
     return Dir(get_configured_path(PATH_SCENARIOS_DIR))
 
 def read(path, validation_schema=None, if_missing_return=False):
-    with log.Origin(path):
-        if not os.path.isfile(path) and if_missing_return is not False:
-            return if_missing_return
-        with open(path, 'r') as f:
-            config = yaml.safe_load(f)
-        config = _standardize(config)
-        if validation_schema:
-            schema.validate(config, validation_schema)
-        return config
+    log.ctx(path)
+    if not os.path.isfile(path) and if_missing_return is not False:
+        return if_missing_return
+    with open(path, 'r') as f:
+        config = yaml.safe_load(f)
+    config = _standardize(config)
+    if validation_schema:
+        schema.validate(config, validation_schema)
+    return config
 
 def write(path, config):
-    with log.Origin(path):
-        with open(path, 'w') as f:
-            f.write(tostr(config))
+    log.ctx(path)
+    with open(path, 'w') as f:
+        f.write(tostr(config))
 
 def tostr(config):
     return _tostr(_standardize(config))
@@ -191,8 +191,7 @@
 
 class Scenario(log.Origin, dict):
     def __init__(self, name, path):
-        self.set_name(name)
-        self.set_log_category(log.C_TST)
+        super().__init__(log.C_TST, name)
         self.path = path
 
 def get_scenario(name, validation_schema=None):
@@ -216,8 +215,8 @@
             if dest_val is None:
                 dest[key] = val
             else:
-                with log.Origin(key=key):
-                    add(dest_val, val)
+                log.ctx(key=key)
+                add(dest_val, val)
         return
     if is_list(dest):
         if not is_list(src):
@@ -235,19 +234,19 @@
             raise ValueError('cannot combine dict with a value of type: %r' % type(src))
 
         for key, val in src.items():
+            log.ctx(key=key)
             dest_val = dest.get(key)
             if dest_val is None:
                 dest[key] = val
             else:
-                with log.Origin(key=key):
-                    combine(dest_val, val)
+                combine(dest_val, val)
         return
     if is_list(dest):
         if not is_list(src):
             raise ValueError('cannot combine list with a value of type: %r' % type(src))
         for i in range(len(src)):
-            with log.Origin(idx=i):
-                combine(dest[i], src[i])
+            log.ctx(idx=i)
+            combine(dest[i], src[i])
         return
     if dest == src:
         return
@@ -260,16 +259,16 @@
             raise ValueError('cannot combine dict with a value of type: %r' % type(src))
 
         for key, val in src.items():
+            log.ctx(key=key)
             dest_val = dest.get(key)
-            with log.Origin(key=key):
-                dest[key] = overlay(dest_val, val)
+            dest[key] = overlay(dest_val, val)
         return dest
     if is_list(dest):
         if not is_list(src):
             raise ValueError('cannot combine list with a value of type: %r' % type(src))
         for i in range(len(src)):
-            with log.Origin(idx=i):
-                dest[i] = overlay(dest[i], src[i])
+            log.ctx(key=key)
+            dest[i] = overlay(dest[i], src[i])
         return dest
     return src