def test_debug(self):
if __debug__:
self.skipTest("__debug__ is True")
if 'FBASE_TRACE' in os.environ:
del os.environ['FBASE_TRACE']
ctx = Traced(self)
trace_manager.flags = (TraceFlag.ACTIVE | TraceFlag.FAIL
| TraceFlag.BEFORE | TraceFlag.AFTER)
with self.assertLogs(level='DEBUG') as log:
traced()(ctx.traced_noparam_noresult)()
self.verify_func(log.records, 'traced_noparam_noresult', True)
def test_add_traced(self):
"Default settings only, events: FAIL"
def verify(
records,
func_name,
params: str = '',
result: str = None,
outcome: str = ('log_failed', '<--')) -> None:
self.assertGreaterEqual(len(records), 2)
self.verify_func(records, func_name)
rec = records.pop(0)
self.assertEqual(rec.name, 'trace')
self.assertEqual(rec.levelno, LogLevel.DEBUG)
self.assertEqual(rec.args, ())
self.assertEqual(rec.filename, 'trace.py')
self.assertEqual(rec.module, 'trace')
self.assertEqual(rec.funcName, outcome[0])
self.assertEqual(rec.topic, 'trace')
self.assertEqual(rec.agent, 'Traced')
self.assertEqual(rec.context, UNDEFINED)
self.assertTrue(
rec.message.startswith(f'{outcome[1]} {func_name}'))
self.assertTrue(rec.message.endswith(f'{result}'))
self.assertEqual(trace_manager.flags,
TraceFlag.ACTIVE | TraceFlag.FAIL)
add_trace(Traced, 'traced_noparam_noresult')
add_trace(Traced, 'traced_noparam_result')
add_trace(Traced, 'traced_param_noresult')
add_trace(Traced, 'traced_param_result')
add_trace(Traced, 'traced_raises')
ctx = Traced(self)
# traced_noparam_noresult
with self.assertLogs(level='DEBUG') as log:
ctx.traced_noparam_noresult()
self.verify_func(log.records, 'traced_noparam_noresult', True)
# traced_noparam_result
with self.assertLogs(level='DEBUG') as log:
ctx.traced_noparam_result()
self.verify_func(log.records, 'traced_noparam_result', True)
# traced_param_noresult
with self.assertLogs(level='DEBUG') as log:
ctx.traced_param_noresult(1, 2, kw_only='NO-DEFAULT')
self.verify_func(log.records, 'traced_param_noresult', True)
# traced_param_result
with self.assertLogs(level='DEBUG') as log:
ctx.traced_param_result(1, 2, kw_only='NO-DEFAULT')
self.verify_func(log.records, 'traced_param_result', True)
# traced_raises
with self.assertLogs(level='DEBUG') as log:
with self.assertRaises(Error):
traced()(ctx.traced_raises)()
verify(log.records, 'traced_raises', result='Error: No cookies left')
def test_env(self):
ctx = Traced(self)
trace_manager.flags = (TraceFlag.ACTIVE | TraceFlag.FAIL
| TraceFlag.BEFORE | TraceFlag.AFTER)
with self.assertLogs(level='DEBUG') as log:
traced()(ctx.traced_noparam_noresult)()
self.assertEqual(len(log.records), 3)
os.environ['FBASE_TRACE'] = 'off'
with self.assertLogs(level='DEBUG') as log:
traced()(ctx.traced_noparam_noresult)()
self.verify_func(log.records, 'traced_noparam_noresult', True)
del os.environ['FBASE_TRACE']
def test_topic(self):
def verify(records, topic: str) -> None:
self.assertEqual(len(records), 3)
self.assertEqual(records.pop(0).topic, topic)
records.pop(0)
self.assertEqual(records.pop(0).topic, topic)
ctx = Traced(self)
trace_manager.flags |= (TraceFlag.FAIL | TraceFlag.BEFORE
| TraceFlag.AFTER)
#
with self.assertLogs(level='DEBUG') as log:
traced(topic='fun')(ctx.traced_noparam_noresult)()
verify(log.records, 'fun')
def test_level(self):
def verify(records, level) -> None:
self.assertEqual(len(records), 3)
self.assertEqual(records.pop(0).levelno, level)
records.pop(0)
self.assertEqual(records.pop(0).levelno, level)
ctx = Traced(self)
trace_manager.flags |= (TraceFlag.FAIL | TraceFlag.BEFORE
| TraceFlag.AFTER)
#
with self.assertLogs(level='DEBUG') as log:
traced(level=LogLevel.INFO)(ctx.traced_noparam_noresult)()
verify(log.records, LogLevel.INFO)
def test_custom_msg(self):
def verify(records,
msg_before: str,
msg_after_start: str,
msg_after_end: str = '') -> None:
self.assertEqual(len(records), 3)
rec = records.pop(0)
self.assertEqual(rec.message, msg_before)
records.pop(0)
rec = records.pop(0)
self.assertTrue(rec.message.startswith(msg_after_start))
self.assertTrue(rec.message.endswith(msg_after_end))
ctx = Traced(self)
trace_manager.flags |= (TraceFlag.FAIL | TraceFlag.BEFORE
| TraceFlag.AFTER)
#
with self.assertLogs(level='DEBUG') as log:
d = traced(msg_before=
'ENTER {_fname_} ({pos_only}, {pos}, {kw}, {kw_only})')
d(ctx.traced_param_noresult)(1, 2, kw_only='NO-DEFAULT')
verify(log.records,
'ENTER traced_param_noresult (1, 2, KW, NO-DEFAULT)',
'<<< traced_param_noresult')
with self.assertLogs(level='DEBUG') as log:
d = traced(msg_after='EXIT {_fname_}: {_result_}')
d(ctx.traced_param_noresult)(1, 2, kw_only='NO-DEFAULT')
verify(
log.records,
">>> traced_param_noresult(pos_only=1, pos=2, kw='KW', kw_only='NO-DEFAULT')",
'EXIT traced_param_noresult: None', '')
d = traced(
msg_before='ENTER {_fname_} ({pos_only}, {pos}, {kw}, {kw_only})',
msg_after='EXIT {_fname_}: {_result_}')
with self.assertLogs(level='DEBUG') as log:
d(ctx.traced_param_noresult)(1, 2, kw_only='NO-DEFAULT')
verify(log.records,
'ENTER traced_param_noresult (1, 2, KW, NO-DEFAULT)',
'EXIT traced_param_noresult: None', '')
with self.assertLogs(level='DEBUG') as log:
d = traced(msg_before='ENTER {_fname_} ()',
msg_after='EXIT {_fname_}: {_result_}',
msg_failed='!!! {_fname_}: {_exc_}')
with self.assertRaises(Error):
d(ctx.traced_raises)()
verify(log.records, 'ENTER traced_raises ()',
'!!! traced_raises: Error: No cookies left', '')
def test_max_param_length(self):
def verify(records, message: str, result: str = 'Result: OK') -> None:
self.assertEqual(len(records), 3)
self.assertEqual(records.pop(0).message, message)
records.pop(0)
self.assertTrue(records.pop(0).message.endswith(result))
ctx = Traced(self)
trace_manager.flags |= (TraceFlag.FAIL | TraceFlag.BEFORE
| TraceFlag.AFTER)
#
with self.assertLogs(level='DEBUG') as log:
traced(max_param_length=10)(ctx.traced_param_result)(
'123456789', '0123456789' * 10)
verify(
log.records,
">>> traced_param_result(pos_only='123456789', pos='0123456789..[90]', kw='KW', kw_only='KW_ONLY')"
)
#
with self.assertLogs(level='DEBUG') as log:
traced(max_param_length=10)(ctx.traced_long_result)()
verify(log.records, '>>> traced_long_result()',
'Result: 0123456789..[90]')
def test_forced(self):
def verify(records,
msg_before: str,
msg_after_start: str,
msg_after_end: str = '') -> None:
self.assertEqual(len(records), 3)
rec = records.pop(0)
self.assertEqual(rec.message, msg_before)
records.pop(0)
rec = records.pop(0)
self.assertTrue(rec.message.startswith(msg_after_start))
self.assertTrue(rec.message.endswith(msg_after_end))
ctx = Traced(self)
trace_manager.flags = (TraceFlag.FAIL | TraceFlag.BEFORE
| TraceFlag.AFTER)
with self.assertLogs(level='DEBUG') as log:
traced()(ctx.traced_noparam_noresult)()
self.verify_func(log.records, 'traced_noparam_noresult', True)
#
with self.assertLogs(level='DEBUG') as log:
traced(flags=TraceFlag.ACTIVE)(ctx.traced_noparam_noresult)()
verify(log.records, '>>> traced_noparam_noresult()',
'<<< traced_noparam_noresult')
def test_agent_ctx(self):
def verify(records, agent, ctx) -> None:
self.assertEqual(len(records), 3)
rec = records.pop(0)
self.assertEqual(rec.agent, agent)
self.assertEqual(rec.context, ctx)
records.pop(0)
rec = records.pop(0)
self.assertEqual(rec.agent, agent)
self.assertEqual(rec.context, ctx)
ctx = Traced(self)
trace_manager.flags |= (TraceFlag.FAIL | TraceFlag.BEFORE
| TraceFlag.AFTER)
#
with self.assertLogs(level='DEBUG') as log:
traced(agent=UNDEFINED,
context=UNDEFINED)(ctx.traced_noparam_noresult)()
verify(log.records, UNDEFINED, UNDEFINED)
ctx.log_context = '<CONTEXT>'
ctx._logging_id_ = '<AGENT>'
with self.assertLogs(level='DEBUG') as log:
traced()(ctx.traced_noparam_noresult)()
verify(log.records, '<AGENT>', '<CONTEXT>')
def test_extra(self):
def foo(bar=''):
return f'Foo{bar}!'
def verify(records, msg_before: str, msg_after: str) -> None:
self.assertEqual(len(records), 3)
self.assertEqual(records.pop(0).message, msg_before)
records.pop(0)
self.assertEqual(records.pop(0).message, msg_after)
ctx = Traced(self)
trace_manager.flags |= (TraceFlag.FAIL | TraceFlag.BEFORE
| TraceFlag.AFTER)
#
with self.assertLogs(level='DEBUG') as log:
d = traced(
msg_before='>>> {_fname_} ({foo()}, {foo(kw)}, {foo(kw_only)})',
msg_after='<<< {_fname_}: {foo(_result_)}',
extra={'foo': foo})
d(ctx.traced_param_noresult)(1, 2, kw_only='bar')
verify(log.records,
'>>> traced_param_noresult (Foo!, FooKW!, Foobar!)',
'<<< traced_param_noresult: FooNone!')
def test_aab(self):
"Default decorator settings, all events"
def verify(
records,
func_name: str,
params: str = '',
result: str = '',
outcome: str = ('log_after', '<<<')) -> None:
self.assertEqual(len(records), 3)
rec: LogRecord = records.pop(0)
self.assertEqual(rec.name, 'trace')
self.assertEqual(rec.levelno, LogLevel.DEBUG)
self.assertEqual(rec.args, ())
self.assertEqual(rec.filename, 'trace.py')
self.assertEqual(rec.module, 'trace')
self.assertEqual(rec.funcName, 'log_before')
self.assertEqual(rec.topic, 'trace')
self.assertEqual(rec.agent, 'Traced')
self.assertEqual(rec.context, UNDEFINED)
self.assertEqual(rec.message, f'>>> {func_name}({params})')
#
self.verify_func(records, func_name)
#
rec = records.pop(0)
self.assertEqual(rec.name, 'trace')
self.assertEqual(rec.levelno, LogLevel.DEBUG)
self.assertEqual(rec.args, ())
self.assertEqual(rec.filename, 'trace.py')
self.assertEqual(rec.module, 'trace')
self.assertEqual(rec.funcName, outcome[0])
self.assertEqual(rec.topic, 'trace')
self.assertEqual(rec.agent, 'Traced')
self.assertEqual(rec.context, UNDEFINED)
self.assertTrue(
rec.message.startswith(f'{outcome[1]} {func_name}'))
self.assertTrue(rec.message.endswith(f'{result}'))
ctx = Traced(self)
trace_manager.flags |= (TraceFlag.FAIL | TraceFlag.BEFORE
| TraceFlag.AFTER)
# traced_noparam_noresult
with self.assertLogs(level='DEBUG') as log:
traced()(ctx.traced_noparam_noresult)()
verify(log.records, 'traced_noparam_noresult')
# traced_noparam_result
with self.assertLogs(level='DEBUG') as log:
traced()(ctx.traced_noparam_result)()
verify(log.records, 'traced_noparam_result', result='OK')
# traced_param_noresult
with self.assertLogs(level='DEBUG') as log:
traced()(ctx.traced_param_noresult)(1, 2, kw_only='NO-DEFAULT')
verify(log.records, 'traced_param_noresult',
"pos_only=1, pos=2, kw='KW', kw_only='NO-DEFAULT'")
# traced_param_noresult
with self.assertLogs(level='DEBUG') as log:
traced()(ctx.traced_param_result)(1, 2, kw_only='NO-DEFAULT')
verify(log.records, 'traced_param_result',
"pos_only=1, pos=2, kw='KW', kw_only='NO-DEFAULT'", 'OK')
# traced_raises
with self.assertLogs(level='DEBUG') as log:
with self.assertRaises(Error):
traced()(ctx.traced_raises)()
verify(log.records,
'traced_raises',
result='Error: No cookies left',
outcome=('log_failed', '<--'))
