def test_make_condensed_debug_msg_exc_info(self):
""" Test handling exc_info param. """
# Full debug message
full_debug_msg = re.compile(
r"^\[.+@.+\] ValueError:.+ValueError msg.+raise ValueError"
r"\('ValueError msg'\).+test_common_helpers.+`$")
test_full_debug_msg = make_condensed_debug_msg(
(ValueError, 'ValueError msg', self.sample_traceback))
# self.assertTrue(full_debug_msg.findall(test_full_debug_msg))
self.assertRegexpMatches(text=test_full_debug_msg,
expected_regexp=full_debug_msg)
# No traceback provided
no_traceback_msg = re.compile(
r"^\[.+@.+\] ValueError:.+ValueError msg.+"
r"\<no traceback\>.+test_common_helpers.+`$")
test_no_traceback_msg = make_condensed_debug_msg(
(ValueError, 'ValueError msg', None))
self.assertRegexpMatches(text=test_no_traceback_msg,
expected_regexp=no_traceback_msg)
# 3x none in the tuple
nones_tuple_msg = re.compile(
r"^\[.+@.+\] \<no exc\>:.+\<no msg\>.+"
r"\<no traceback\>.+test_common_helpers.+`$")
test_nones_tuple_msg = make_condensed_debug_msg((None, None, None))
self.assertRegexpMatches(text=test_nones_tuple_msg,
expected_regexp=nones_tuple_msg)
# exc_info param not provided, executed without exception handling
sys.exc_clear()
normal_msg = re.compile(r"^\[.+@.+\] \<no exc\>:.+\<no msg\>.+"
r"\<no traceback\>.+test_common_helpers.+`$")
test_normal_msg = make_condensed_debug_msg()
self.assertRegexpMatches(text=test_normal_msg,
expected_regexp=normal_msg)
# exc_info param not provided, executed in a except block
try:
raise ValueError('ValueError msg')
except ValueError:
except_debug_msg = re.compile(
r"^\[.+@.+\] ValueError:.+ValueError msg.+raise "
r"ValueError\('ValueError msg'\).+"
r"test_common_helpers.+`$")
test_except_debug_msg = make_condensed_debug_msg()
self.assertTrue(except_debug_msg.findall(test_except_debug_msg))
def error_callback(exc):
try:
exc_info = sys.exc_info()
assert exc_info[1] is exc
error_msg = make_condensed_debug_msg(exc_info)
error_fifo.put_nowait(error_msg)
finally:
# (to break any traceback-related reference cycle)
exc_info = None
def logging_configured(suffix=None):
configure_logging(suffix)
try:
yield
except SystemExit as exc:
if exc.code:
_LOGGER.critical(
"SystemExit(%r) occurred (debug info: %s). Exiting...",
exc.code,
make_condensed_debug_msg(),
exc_info=True)
dump_condensed_debug_msg()
else:
_LOGGER.info("SystemExit(%r) occurred. Exiting...", exc.code)
raise
except KeyboardInterrupt:
_LOGGER.warning("KeyboardInterrupt occurred. Exiting...")
sys.exit(1)
except:
_LOGGER.critical('Irrecoverable problem (debug info: %s). Exiting...',
make_condensed_debug_msg(),
exc_info=True)
dump_condensed_debug_msg()
raise
def _report_critical_exception_after_commit():
debug_msg = None
try:
exc_info = sys.exc_info()
debug_msg = make_condensed_debug_msg(exc_info)
LOGGER.critical(
'Most probably, some Auth DB changes *have been* committed '
'*but* the corresponding Audit Log entries have *not* been '
'emitted (!!!) because of an exception. Debug message: %s.',
debug_msg,
exc_info=exc_info)
except:
dump_condensed_debug_msg(
'EXCEPTION WHEN TRYING TO LOG AUDIT LOG CRITICAL EXCEPTION!')
raise
finally:
# noinspection PyUnusedLocal
exc_info = None # (<- breaking traceback-related reference cycle, if any)
dump_condensed_debug_msg('AUDIT LOG CRITICAL EXCEPTION!',
debug_msg=(debug_msg
or '[UNKNOWN EXCEPTION]'))
def test_make_condensed_debug_msg(self):
"""Test if parts of debug msg are cut to proper lengths."""
# char_limit for testing purposes
test_limit = 20
try:
try:
raise ValueError('very long exception message'
'for test purposes')
except ValueError:
exc_info = sys.exc_info()
exc_no_tb = (exc_info[0], exc_info[1], None)
exc_no_msg = (exc_info[0], None, exc_info[2])
# Test total_limit param
self.assertLessEqual(
len(make_condensed_debug_msg(exc_info,
total_limit=test_limit)),
test_limit)
# Test exc_str with no message
temp_debug_msg = make_condensed_debug_msg(exc_no_msg)
exc_str_regexp = re.compile(r': \<no msg\> \<\<\= ')
self.assertRegexpMatches(text=temp_debug_msg,
expected_regexp=exc_str_regexp)
# Test exc_str with message
temp_debug_msg = make_condensed_debug_msg(exc_info,
exc_str_limit=test_limit)
expected_msg_regex = re.compile(r': .+ \<\<\= ')
extracted_msg = expected_msg_regex.findall(temp_debug_msg)[0][2:-5]
self.assertLessEqual(len(extracted_msg), test_limit)
# Test tb_str_limit with no traceback
temp_debug_msg = make_condensed_debug_msg(exc_no_tb,
tb_str_limit=test_limit)
tb_regexp = re.compile(r'\<\<\= \<no traceback\> \<\-\(\*\)\-')
self.assertRegexpMatches(text=temp_debug_msg,
expected_regexp=tb_regexp)
# Test tb_str with traceback
temp_debug_msg = make_condensed_debug_msg(exc_info,
tb_str_limit=test_limit)
tb_regexp = re.compile(r'\<\<\= .+ \<\-\(\*\)\-')
extracted_tb = tb_regexp.findall(temp_debug_msg)[0][4:-7]
self.assertLessEqual(len(extracted_tb), test_limit)
# Check stack_str_limit param
temp_debug_msg = make_condensed_debug_msg(
exc_info, stack_str_limit=test_limit)
stack_str = temp_debug_msg[temp_debug_msg.rfind('<-(*)- ') + 7:]
self.assertLessEqual(len(stack_str), test_limit)
# Check alternative cut_indicator
alt_cut_ind = '[-]'
self.assertTrue(alt_cut_ind in make_condensed_debug_msg(
total_limit=100, cut_indicator=alt_cut_ind))
finally:
exc_info = exc_no_msg = None # avoiding keeping reference cycles
def log_debug_info_on_http_exc(http_exc):
code = getattr(http_exc, 'code', None)
if not isinstance(code, (int, long)) or not 200 <= code < 500:
LOGGER.error('Condensed debug info related to %r:\n%s', http_exc,
make_condensed_debug_msg())