exc_tracking: always nice format tb for core exceptions

rhodecode/config/middleware.py

@@ -48,7 +48,7 b' from rhodecode.lib.middleware.appenlight'
 from rhodecode.lib.middleware.https_fixup import HttpsFixup
 from rhodecode.lib.plugins.utils import register_rhodecode_plugin
 from rhodecode.lib.utils2 import AttributeDict
-from rhodecode.lib.exc_tracking import store_exception
+from rhodecode.lib.exc_tracking import store_exception, format_exc
 from rhodecode.subscribers import (
     scan_repositories_if_enabled, write_js_routes_if_enabled,
     write_metadata_if_needed, write_usage_data)
@@ -190,7 +190,6 b' def not_found_view(request):'
 def error_handler(exception, request):
     import rhodecode
     from rhodecode.lib import helpers
-    from rhodecode.lib.utils2 import str2bool
 
     rhodecode_title = rhodecode.CONFIG.get('rhodecode_title') or 'RhodeCode'
 
@@ -202,8 +201,10 b' def error_handler(exception, request):'
         base_response = VCSServerUnavailable()
 
     if is_http_error(base_response):
-        log.exception(
-            'error occurred handling this request for path: %s', request.path)
+        traceback_info = format_exc(request.exc_info)
+        log.error(
+            'error occurred handling this request for path: %s, \n%s',
+            request.path, traceback_info)
 
     error_explanation = base_response.explanation or str(base_response)
     if base_response.status_code == 404:

rhodecode/lib/exc_tracking.py

@@ -16,6 +16,7 b''
 # RhodeCode Enterprise Edition, including its added features, Support services,
 # and proprietary license terms, please see https://rhodecode.com/licenses/
 
+import io
 import os
 import time
 import sys
@@ -29,19 +30,18 b' import glob'
 log = logging.getLogger(__name__)
 
 # NOTE: Any changes should be synced with exc_tracking at vcsserver.lib.exc_tracking
-global_prefix = 'rhodecode'
-exc_store_dir_name = 'rc_exception_store_v1'
+global_prefix = "rhodecode"
+exc_store_dir_name = "rc_exception_store_v1"
 
 
 def exc_serialize(exc_id, tb, exc_type, extra_data=None):
-
     data = {
-        'version': 'v1',
-        'exc_id': exc_id,
-        'exc_utc_date': datetime.datetime.utcnow().isoformat(),
-        'exc_timestamp': repr(time.time()),
-        'exc_message': tb,
-        'exc_type': exc_type,
+        "version": "v1",
+        "exc_id": exc_id,
+        "exc_utc_date": datetime.datetime.utcnow().isoformat(),
+        "exc_timestamp": repr(time.time()),
+        "exc_message": tb,
+        "exc_type": exc_type,
     }
     if extra_data:
         data.update(extra_data)
@@ -51,69 +51,27 b' def exc_serialize(exc_id, tb, exc_type, '
 def exc_unserialize(tb):
     return msgpack.unpackb(tb)
 
+
 _exc_store = None
 
 
-def get_exc_store():
-    """
-    Get and create exception store if it's not existing
-    """
-    global _exc_store
+def maybe_send_exc_email(exc_id, exc_type_name, send_email):
+    from pyramid.threadlocal import get_current_request
     import rhodecode as app
 
-    if _exc_store is not None:
-        # quick global cache
-        return _exc_store
-
-    exc_store_dir = app.CONFIG.get('exception_tracker.store_path', '') or tempfile.gettempdir()
-    _exc_store_path = os.path.join(exc_store_dir, exc_store_dir_name)
-
-    _exc_store_path = os.path.abspath(_exc_store_path)
-    if not os.path.isdir(_exc_store_path):
-        os.makedirs(_exc_store_path)
-        log.debug('Initializing exceptions store at %s', _exc_store_path)
-        _exc_store = _exc_store_path
-
-    return _exc_store_path
-
-
-def _store_exception(exc_id, exc_type_name, exc_traceback, prefix, send_email=None):
-    """
-    Low level function to store exception in the exception tracker
-    """
-    from pyramid.threadlocal import get_current_request
-    import rhodecode as app
     request = get_current_request()
-    extra_data = {}
-    # NOTE(marcink): store request information into exc_data
-    if request:
-        extra_data['client_address'] = getattr(request, 'client_addr', '')
-        extra_data['user_agent'] = getattr(request, 'user_agent', '')
-        extra_data['method'] = getattr(request, 'method', '')
-        extra_data['url'] = getattr(request, 'url', '')
-
-    exc_store_path = get_exc_store()
-    exc_data, org_data = exc_serialize(exc_id, exc_traceback, exc_type_name, extra_data=extra_data)
-
-    exc_pref_id = '{}_{}_{}'.format(exc_id, prefix, org_data['exc_timestamp'])
-    if not os.path.isdir(exc_store_path):
-        os.makedirs(exc_store_path)
-    stored_exc_path = os.path.join(exc_store_path, exc_pref_id)
-    with open(stored_exc_path, 'wb') as f:
-        f.write(exc_data)
-    log.debug('Stored generated exception %s as: %s', exc_id, stored_exc_path)
 
     if send_email is None:
         # NOTE(marcink): read app config unless we specify explicitly
-        send_email = app.CONFIG.get('exception_tracker.send_email', False)
+        send_email = app.CONFIG.get("exception_tracker.send_email", False)
 
-    mail_server = app.CONFIG.get('smtp_server') or None
+    mail_server = app.CONFIG.get("smtp_server") or None
     send_email = send_email and mail_server
     if send_email and request:
         try:
             send_exc_email(request, exc_id, exc_type_name)
         except Exception:
-            log.exception('Failed to send exception email')
+            log.exception("Failed to send exception email")
             exc_info = sys.exc_info()
             store_exception(id(exc_info), exc_info, send_email=False)
 
@@ -126,41 +84,164 b' def send_exc_email(request, exc_id, exc_'
     from rhodecode.lib.base import attach_context_attributes
     from rhodecode.model.notification import EmailNotificationModel
 
-    recipients = aslist(app.CONFIG.get('exception_tracker.send_email_recipients', ''))
-    log.debug('Sending Email exception to: `%s`', recipients or 'all super admins')
+    recipients = aslist(app.CONFIG.get("exception_tracker.send_email_recipients", ""))
+    log.debug("Sending Email exception to: `%s`", recipients or "all super admins")
 
     # NOTE(marcink): needed for email template rendering
     user_id = None
-    if hasattr(request, 'user'):
+    if hasattr(request, "user"):
         user_id = request.user.user_id
     attach_context_attributes(TemplateArgs(), request, user_id=user_id, is_api=True)
 
     email_kwargs = {
-        'email_prefix': app.CONFIG.get('exception_tracker.email_prefix', '') or '[RHODECODE ERROR]',
-        'exc_url': request.route_url('admin_settings_exception_tracker_show', exception_id=exc_id),
-        'exc_id': exc_id,
-        'exc_type_name': exc_type_name,
-        'exc_traceback': read_exception(exc_id, prefix=None),
+        "email_prefix": app.CONFIG.get("exception_tracker.email_prefix", "")
+        or "[RHODECODE ERROR]",
+        "exc_url": request.route_url(
+            "admin_settings_exception_tracker_show", exception_id=exc_id
+        ),
+        "exc_id": exc_id,
+        "exc_type_name": exc_type_name,
+        "exc_traceback": read_exception(exc_id, prefix=None),
     }
 
     (subject, email_body, email_body_plaintext) = EmailNotificationModel().render_email(
-        EmailNotificationModel.TYPE_EMAIL_EXCEPTION, **email_kwargs)
+        EmailNotificationModel.TYPE_EMAIL_EXCEPTION, **email_kwargs
+    )
+
+    run_task(tasks.send_email, recipients, subject, email_body_plaintext, email_body)
+
+
+def get_exc_store():
+    """
+    Get and create exception store if it's not existing
+    """
+    global _exc_store
 
-    run_task(tasks.send_email, recipients, subject,
-             email_body_plaintext, email_body)
+    if _exc_store is not None:
+        # quick global cache
+        return _exc_store
+
+    import rhodecode as app
+
+    exc_store_dir = (
+        app.CONFIG.get("exception_tracker.store_path", "") or tempfile.gettempdir()
+    )
+    _exc_store_path = os.path.join(exc_store_dir, exc_store_dir_name)
+
+    _exc_store_path = os.path.abspath(_exc_store_path)
+    if not os.path.isdir(_exc_store_path):
+        os.makedirs(_exc_store_path)
+        log.debug("Initializing exceptions store at %s", _exc_store_path)
+        _exc_store = _exc_store_path
+
+    return _exc_store_path
 
 
-def _prepare_exception(exc_info):
-    exc_type, exc_value, exc_traceback = exc_info
-    exc_type_name = exc_type.__name__
+def get_detailed_tb(exc_info):
+    try:
+        from pip._vendor.rich import (
+            traceback as rich_tb,
+            scope as rich_scope,
+            console as rich_console,
+        )
+    except ImportError:
+        try:
+            from rich import (
+                traceback as rich_tb,
+                scope as rich_scope,
+                console as rich_console,
+            )
+        except ImportError:
+            return None
+
+    console = rich_console.Console(width=160, file=io.StringIO())
+
+    exc = rich_tb.Traceback.extract(*exc_info, show_locals=True)
 
-    tb = ''.join(traceback.format_exception(
-        exc_type, exc_value, exc_traceback, None))
+    tb_rich = rich_tb.Traceback(
+        trace=exc,
+        width=160,
+        extra_lines=3,
+        theme=None,
+        word_wrap=False,
+        show_locals=False,
+        max_frames=100,
+    )
 
-    return exc_type_name, tb
+    # last_stack = exc.stacks[-1]
+    # last_frame = last_stack.frames[-1]
+    # if last_frame and last_frame.locals:
+    #     console.print(
+    #         rich_scope.render_scope(
+    #             last_frame.locals,
+    #             title=f'{last_frame.filename}:{last_frame.lineno}'))
+
+    console.print(tb_rich)
+    formatted_locals = console.file.getvalue()
+
+    return formatted_locals
 
 
-def store_exception(exc_id, exc_info, prefix=global_prefix, send_email=None):
+def get_request_metadata(request=None) -> dict:
+    request_metadata = {}
+    if not request:
+        from pyramid.threadlocal import get_current_request
+
+        request = get_current_request()
+
+    # NOTE(marcink): store request information into exc_data
+    if request:
+        request_metadata["client_address"] = getattr(request, "client_addr", "")
+        request_metadata["user_agent"] = getattr(request, "user_agent", "")
+        request_metadata["method"] = getattr(request, "method", "")
+        request_metadata["url"] = getattr(request, "url", "")
+    return request_metadata
+
+
+def format_exc(exc_info):
+    exc_type, exc_value, exc_traceback = exc_info
+    tb = "++ TRACEBACK ++\n\n"
+    tb += "".join(traceback.format_exception(exc_type, exc_value, exc_traceback, None))
+
+    locals_tb = get_detailed_tb(exc_info)
+    if locals_tb:
+        tb += f"\n+++ DETAILS +++\n\n{locals_tb}\n" ""
+    return tb
+
+
+def _store_exception(exc_id, exc_info, prefix, request_path='', send_email=None):
+    """
+    Low level function to store exception in the exception tracker
+    """
+
+    extra_data = {}
+    extra_data.update(get_request_metadata())
+
+    exc_type, exc_value, exc_traceback = exc_info
+    tb = format_exc(exc_info)
+
+    exc_type_name = exc_type.__name__
+    exc_data, org_data = exc_serialize(exc_id, tb, exc_type_name, extra_data=extra_data)
+
+    exc_pref_id = f"{exc_id}_{prefix}_{org_data['exc_timestamp']}"
+    exc_store_path = get_exc_store()
+    if not os.path.isdir(exc_store_path):
+        os.makedirs(exc_store_path)
+    stored_exc_path = os.path.join(exc_store_path, exc_pref_id)
+    with open(stored_exc_path, "wb") as f:
+        f.write(exc_data)
+    log.debug("Stored generated exception %s as: %s", exc_id, stored_exc_path)
+
+    if request_path:
+        log.error(
+            'error occurred handling this request.\n'
+            'Path: `%s`, %s',
+            request_path, tb)
+
+    maybe_send_exc_email(exc_id, exc_type_name, send_email)
+
+
+def store_exception(exc_id, exc_info, prefix=global_prefix, request_path='', send_email=None):
     """
     Example usage::
 
@@ -169,12 +250,16 b' def store_exception(exc_id, exc_info, pr'
     """
 
     try:
-        exc_type_name, exc_traceback = _prepare_exception(exc_info)
-        _store_exception(exc_id=exc_id, exc_type_name=exc_type_name,
-                         exc_traceback=exc_traceback, prefix=prefix, send_email=send_email)
+        exc_type = exc_info[0]
+        exc_type_name = exc_type.__name__
+
+        _store_exception(
+            exc_id=exc_id, exc_info=exc_info, prefix=prefix, request_path=request_path,
+            send_email=send_email
+        )
         return exc_id, exc_type_name
     except Exception:
-        log.exception('Failed to store exception `%s` information', exc_id)
+        log.exception("Failed to store exception `%s` information", exc_id)
         # there's no way this can fail, it will crash server badly if it does.
         pass
 
@@ -182,13 +267,13 b' def store_exception(exc_id, exc_info, pr'
 def _find_exc_file(exc_id, prefix=global_prefix):
     exc_store_path = get_exc_store()
     if prefix:
-        exc_id = f'{exc_id}_{prefix}'
+        exc_id = f"{exc_id}_{prefix}"
     else:
         # search without a prefix
-        exc_id = f'{exc_id}'
+        exc_id = f"{exc_id}"
 
     found_exc_id = None
-    matches = glob.glob(os.path.join(exc_store_path, exc_id) + '*')
+    matches = glob.glob(os.path.join(exc_store_path, exc_id) + "*")
     if matches:
         found_exc_id = matches[0]
 
@@ -198,10 +283,10 b' def _find_exc_file(exc_id, prefix=global'
 def _read_exception(exc_id, prefix):
     exc_id_file_path = _find_exc_file(exc_id=exc_id, prefix=prefix)
     if exc_id_file_path:
-        with open(exc_id_file_path, 'rb') as f:
+        with open(exc_id_file_path, "rb") as f:
             return exc_unserialize(f.read())
     else:
-        log.debug('Exception File `%s` not found', exc_id_file_path)
+        log.debug("Exception File `%s` not found", exc_id_file_path)
     return None
 
 
@@ -209,7 +294,7 b' def read_exception(exc_id, prefix=global'
     try:
         return _read_exception(exc_id=exc_id, prefix=prefix)
     except Exception:
-        log.exception('Failed to read exception `%s` information', exc_id)
+        log.exception("Failed to read exception `%s` information", exc_id)
         # there's no way this can fail, it will crash server badly if it does.
     return None
 
@@ -221,7 +306,7 b' def delete_exception(exc_id, prefix=glob'
             os.remove(exc_id_file_path)
 
     except Exception:
-        log.exception('Failed to remove exception `%s` information', exc_id)
+        log.exception("Failed to remove exception `%s` information", exc_id)
         # there's no way this can fail, it will crash server badly if it does.
         pass