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())