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/selftest/log_test.py b/selftest/log_test.py
index 7670c8e..9136906 100755
--- a/selftest/log_test.py
+++ b/selftest/log_test.py
@@ -32,20 +32,20 @@
log.set_all_levels(None)
print('- Testing global log functions')
-log.log('<origin>', log.C_TST, 'from log.log()')
-log.dbg('<origin>', log.C_TST, 'from log.dbg(), not seen')
+log.log('from log.log()', _origin='<origin>', _category=log.C_TST)
+log.dbg('from log.dbg(), not seen', _origin='<origin>', _category=log.C_TST)
log.set_level(log.C_TST, log.L_DBG)
-log.dbg('<origin>', log.C_TST, 'from log.dbg()')
+log.dbg('from log.dbg()', _origin='<origin>', _category=log.C_TST)
log.set_level(log.C_TST, log.L_LOG)
-log.err('<origin>', log.C_TST, 'from log.err()')
+log.err('from log.err()', _origin='<origin>', _category=log.C_TST)
print('- Testing log.Origin functions')
class LogTest(log.Origin):
- pass
+ def __init__(self, *name_items, **detail_items):
+ super().__init__(log.C_TST, *name_items, **detail_items)
-t = LogTest()
-t.set_log_category(log.C_TST)
-t.set_name('some', 'name', some="detail")
+t = LogTest('some', 'name', some="detail")
+
t.log("hello log")
t.err("hello err")
@@ -86,10 +86,10 @@
log.style_change(origin=True)
t.dbg("add origin")
+# some space to keep source line numbers identical to previous code
+
print('- Testing origin_width')
-t = LogTest()
-t.set_log_category(log.C_TST)
-t.set_name('shortname')
+t = LogTest('shortname')
log.style(origin_width=23, time_fmt=fake_time)
t.log("origin str set to 23 chars")
t.set_name('very long name', some='details', and_some=(3, 'things', 'in a tuple'))
@@ -97,16 +97,16 @@
t.dbg("long origin str dbg")
t.err("long origin str err")
+
print('- Testing log.Origin with omitted info')
t = LogTest()
-t.set_log_category(log.C_TST)
t.log("hello log, name implicit from class name")
-t = LogTest()
-t.set_name('explicit_name')
+t = LogTest('explicit_name')
+t._set_log_category(None)
t.log("hello log, no category set")
-
t = LogTest()
+t._set_log_category(None)
t.log("hello log, no category nor name set")
t.dbg("hello log, no category nor name set, not seen")
log.set_level(log.C_DEFAULT, log.L_DBG)
@@ -117,47 +117,37 @@
class Thing(log.Origin):
def __init__(self, some_path):
- self.set_log_category(log.C_TST)
- self.set_name(some_path)
+ super().__init__(log.C_TST, some_path)
def say(self, msg):
print(msg)
-#log.style_change(trace=True)
+ def l1(self):
+ level2 = Thing('level2')
+ level2.l2()
-with Thing('print_redirected'):
- print("Not throwing an exception in 'with:' works.")
+ def l2(self):
+ level3 = Thing('level3')
+ level3.l3(self)
-def l1():
- level1 = Thing('level1')
- with level1:
- l2()
-
-def l2():
- level2 = Thing('level2')
- with level2:
- l3(level2)
-
-def l3(level2):
- level3 = Thing('level3')
- with level3:
+ def l3(self, level2):
print('nested print just prints')
- level3.log('nested log()')
+ self.log('nested log()')
level2.log('nested l2 log() from within l3 scope')
raise ValueError('bork')
try:
- l1()
+ level1 = Thing('level1')
+ level1.l1()
except Exception:
log.log_exn()
-print('- Enter the same Origin context twice')
+print('- Disallow origin loops')
try:
t = Thing('foo')
- with t:
- with t:
- raise RuntimeError('this should not be reached')
-except AssertionError:
+ t._set_parent(t)
+ raise RuntimeError('this should not be reached')
+except log.OriginLoopError:
print('disallowed successfully')
pass