Improved the log.assertion() and unreachable() functions to send a deeper traceback when reporting by email, rather than just the last stack frame.

levkowetz · levkowetz · commit 7b3ce6e79536 · 2017-03-13T05:37:02.000Z
- Legacy-Id: 12999
diff --git a/ietf/utils/log.py b/ietf/utils/log.py
@@ -53,41 +53,64 @@ def log(msg):
 
 logger = logging.getLogger('django')
 
+def build_traceback(stack):
+    """
+    Build something that looks sufficiently like a traceback to be passed to a
+    logging.logger as the exc_info argument.
+    """
+    class Traceback():
+        pass
+    next = None
+    for frame_record in stack:
+        fr_frame, fr_filename, fr_lineno, fr_funcname, fr_context, fr_context_this = frame_record
+        tb = Traceback()
+        tb.tb_frame = fr_frame
+        tb.tb_lasti = fr_frame.f_lasti
+        tb.tb_lineno = fr_lineno
+        tb.tb_next = next
+        next = tb
+        # Stop traceback at _get_response() -- we don't want to see the
+        # middleware, debug server, or wsgi internals when the exception
+        # occurs in our app code, below _get_response():
+        if fr_funcname == '_get_response' and fr_filename.endswith('django/core/handlers/base.py'):
+            break
+    return tb
+
 def assertion(statement):
     """
     This acts like an assertion.  It uses the django logger in order to send
     the failed assertion and a backtrace as for an internal server error.
 
     """
-    class Traceback():
-        pass
-    frame = inspect.stack()[1][0]
+    stack = inspect.stack()[1:]
+    frame = stack[0][0]
     value = eval(statement, frame.f_globals, frame.f_locals)
     if not value:
         if settings.DEBUG is True or settings.SERVER_MODE == 'test':
             raise AssertionError("Assertion '%s' failed." % (statement,))
         else:
             # build a simulated traceback object
-            tb = Traceback()
-            tb.tb_frame = frame
-            tb.tb_lasti = None
-            tb.tb_lineno = frame.f_lineno
-            tb.tb_next = None
-            logger.error("Assertion '%s' failed.", statement, exc_info=(AssertionError, statement, tb))
+            tb = build_traceback(stack)
+            # provide extra info if available
+            extra = {}
+            for key in [ 'request', 'status_code', ]:
+                if key in frame.f_locals:
+                    extra[key] = frame.f_locals[key]
+            logger.error("Assertion '%s' failed.", statement, exc_info=(AssertionError, statement, tb), extra=extra)
 
 def unreachable():
     "Raises an assertion or sends traceback to admins if executed."
-    class Traceback():
-        pass
-    frame = inspect.stack()[1][0]
+    stack = inspect.stack()[1:]
+    frame = stack[0][0]
     if settings.DEBUG is True or settings.SERVER_MODE == 'test':
         raise AssertionError("Arrived at code in %s() which was marked unreachable." % frame.f_code.co_name)
     else:
         # build a simulated traceback object
-        tb = Traceback()
-        tb.tb_frame = frame
-        tb.tb_lasti = None
-        tb.tb_lineno = frame.f_lineno
-        tb.tb_next = None
-        logger.error("Arrived at code in %s() which was marked unreachable.", frame.f_code.co_name, exc_info=(AssertionError, frame.f_code.co_name, tb))
+        tb = build_traceback(stack)
+        # provide extra info if available
+        extra = {}
+        for key in [ 'request', 'status_code', ]:
+            if key in frame.f_locals:
+                extra[key] = frame.f_locals[key]
+        logger.error("Arrived at code in %s() which was marked unreachable.", frame.f_code.co_name, exc_info=(AssertionError, frame.f_code.co_name, tb), extra=extra)
     
