exc-tracking: use more rich style tracebacks.

vcsserver/base.py

@@ -17,7 +17,6 b''
 import os
 import sys
 import tempfile
-import traceback
 import logging
 import urllib.parse
 
@@ -27,7 +26,7 b' from vcsserver import exceptions'
 from vcsserver.exceptions import NoContentException
 from vcsserver.hgcompat import archival
 from vcsserver.str_utils import safe_bytes
-
+from vcsserver.lib.exc_tracking import format_exc
 log = logging.getLogger(__name__)
 
 
@@ -72,12 +71,12 b' def raise_from_original(new_type, org_ex'
     """
     Raise a new exception type with original args and traceback.
     """
-
-    exc_type, exc_value, exc_traceback = sys.exc_info()
+    exc_info = sys.exc_info()
+    exc_type, exc_value, exc_traceback = exc_info
     new_exc = new_type(*exc_value.args)
 
     # store the original traceback into the new exc
-    new_exc._org_exc_tb = traceback.format_tb(exc_traceback)
+    new_exc._org_exc_tb = format_exc(exc_info)
 
     try:
         raise new_exc.with_traceback(exc_traceback)

vcsserver/http_main.py

@@ -23,7 +23,6 b' import logging'
 import uuid
 import time
 import wsgiref.util
-import traceback
 import tempfile
 import psutil
 
@@ -62,7 +61,7 b' from vcsserver.git_lfs.app import GIT_LF'
 from vcsserver.echo_stub import remote_wsgi as remote_wsgi_stub
 from vcsserver.echo_stub.echo_app import EchoApp
 from vcsserver.exceptions import HTTPRepoLocked, HTTPRepoBranchProtected
-from vcsserver.lib.exc_tracking import store_exception
+from vcsserver.lib.exc_tracking import store_exception, format_exc
 from vcsserver.server import VcsServer
 
 strict_vcs = True
@@ -410,8 +409,7 b' class HTTPApplication(object):'
             if should_store_exc:
                 store_exception(id(exc_info), exc_info, request_path=request.path)
 
-            tb_info = ''.join(
-                traceback.format_exception(exc_type, exc_value, exc_traceback))
+            tb_info = format_exc(exc_info)
 
             type_ = e.__class__.__name__
             if type_ not in self.ALLOWED_EXCEPTIONS:
@@ -669,11 +667,10 b' class HTTPApplication(object):'
 
         traceback_info = 'unavailable'
         if request.exc_info:
-            exc_type, exc_value, exc_tb = request.exc_info
-            traceback_info = ''.join(traceback.format_exception(exc_type, exc_value, exc_tb))
+            traceback_info = format_exc(request.exc_info)
 
         log.error(
-            'error occurred handling this request for path: %s, \n tb: %s',
+            'error occurred handling this request for path: %s, \n%s',
             request.path, traceback_info)
 
         statsd = request.registry.statsd

vcsserver/lib/exc_tracking.py

@@ -18,11 +18,13 b''
 
 import os
 import time
+import sys
 import datetime
 import msgpack
 import logging
 import traceback
 import tempfile
+import glob
 
 log = logging.getLogger(__name__)
 
@@ -31,7 +33,7 b" global_prefix = 'vcsserver'"
 exc_store_dir_name = 'rc_exception_store_v1'
 
 
-def exc_serialize(exc_id, tb, exc_type):
+def exc_serialize(exc_id, tb, exc_type, extra_data=None):
 
     data = {
         'version': 'v1',
@@ -41,6 +43,8 b' def exc_serialize(exc_id, tb, exc_type):'
         'exc_message': tb,
         'exc_type': exc_type,
     }
+    if extra_data:
+        data.update(extra_data)
     return msgpack.packb(data), data
 
 
@@ -48,10 +52,19 b' 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
+
+    if _exc_store is not None:
+        # quick global cache
+        return _exc_store
+
     import vcsserver as app
 
     exc_store_dir = app.CONFIG.get('exception_tracker.store_path', '') or tempfile.gettempdir()
@@ -61,16 +74,76 b' def get_exc_store():'
     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_info, prefix, request_path=''):
-    exc_type, exc_value, exc_traceback = exc_info
+def get_detailed_tb(exc_info):
+    from io import StringIO
+
+    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=StringIO()
+    )
+
+    exc = rich_tb.Traceback.extract(*exc_info, show_locals=True)
+
+    tb_rich = rich_tb.Traceback(
+        trace=exc,
+        width=160,
+        extra_lines=3,
+        theme=None,
+        word_wrap=False,
+        show_locals=False,
+        max_frames=100
+    )
+
+    formatted_locals = ""
 
-    tb = ''.join(traceback.format_exception(
-        exc_type, exc_value, exc_traceback, None))
+    # 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
+
 
-    detailed_tb = getattr(exc_value, '_org_exc_tb', 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))
+    
+    detailed_tb = getattr(exc_value, "_org_exc_tb", None)
 
     if detailed_tb:
         remote_tb = detailed_tb
@@ -78,19 +151,37 b' def _store_exception(exc_id, exc_info, p'
             remote_tb = [detailed_tb]
 
         tb += (
-            '\n+++ BEG SOURCE EXCEPTION +++\n\n'
-            '{}\n'
-            '+++ END SOURCE EXCEPTION +++\n'
-            ''.format('\n'.join(remote_tb))
+            "\n+++ BEG SOURCE EXCEPTION +++\n\n"
+            "{}\n"
+            "+++ END SOURCE EXCEPTION +++\n"
+            "".format("\n".join(remote_tb))
         )
 
         # Avoid that remote_tb also appears in the frame
         del remote_tb
 
+    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=''):
+    """
+    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 = '{}_{}_{}'.format(exc_id, prefix, org_data['exc_timestamp'])
     exc_store_path = get_exc_store()
-    exc_data, org_data = exc_serialize(exc_id, tb, exc_type_name)
-    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)
@@ -100,7 +191,7 b' def _store_exception(exc_id, exc_info, p'
 
     log.error(
         'error occurred handling this request.\n'
-        'Path: `%s`, tb: %s',
+        'Path: `%s`, %s',
         request_path, tb)
 
 
@@ -113,8 +204,12 b' def store_exception(exc_id, exc_info, pr'
     """
 
     try:
+        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)
+        return exc_id, exc_type_name
     except Exception:
         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.
@@ -129,16 +224,12 b' def _find_exc_file(exc_id, prefix=global'
         # search without a prefix
         exc_id = f'{exc_id}'
 
-    # we need to search the store for such start pattern as above
-    for fname in os.listdir(exc_store_path):
-        if fname.startswith(exc_id):
-            exc_id = os.path.join(exc_store_path, fname)
-            break
-        continue
-    else:
-        exc_id = None
+    found_exc_id = None
+    matches = glob.glob(os.path.join(exc_store_path, exc_id) + '*')
+    if matches:
+        found_exc_id = matches[0]
 
-    return exc_id
+    return found_exc_id
 
 
 def _read_exception(exc_id, prefix):
@@ -170,3 +261,7 b' def delete_exception(exc_id, prefix=glob'
         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
+
+
+def generate_id():
+    return id(object())

vcsserver/remote/hg.py

@@ -18,9 +18,9 b' import binascii'
 import io
 import logging
 import stat
+import sys
 import urllib.request
 import urllib.parse
-import traceback
 import hashlib
 
 from hgext import largefiles, rebase, purge
@@ -33,19 +33,54 b' from mercurial.error import AmbiguousPre'
 
 import vcsserver
 from vcsserver import exceptions
-from vcsserver.base import RepoFactory, obfuscate_qs, raise_from_original, store_archive_in_cache, ArchiveNode, BytesEnvelope, \
-    BinaryEnvelope
+from vcsserver.base import (
+    RepoFactory,
+    obfuscate_qs,
+    raise_from_original,
+    store_archive_in_cache,
+    ArchiveNode,
+    BytesEnvelope,
+    BinaryEnvelope,
+)
 from vcsserver.hgcompat import (
-    archival, bin, clone, config as hgconfig, diffopts, hex, get_ctx,
-    hg_url as url_parser, httpbasicauthhandler, httpdigestauthhandler,
-    makepeer, instance, match, memctx, exchange, memfilectx, nullrev, hg_merge,
-    patch, peer, revrange, ui, hg_tag, Abort, LookupError, RepoError,
-    RepoLookupError, InterventionRequired, RequirementError,
-    alwaysmatcher, patternmatcher, hgutil, hgext_strip)
+    archival,
+    bin,
+    clone,
+    config as hgconfig,
+    diffopts,
+    hex,
+    get_ctx,
+    hg_url as url_parser,
+    httpbasicauthhandler,
+    httpdigestauthhandler,
+    makepeer,
+    instance,
+    match,
+    memctx,
+    exchange,
+    memfilectx,
+    nullrev,
+    hg_merge,
+    patch,
+    peer,
+    revrange,
+    ui,
+    hg_tag,
+    Abort,
+    LookupError,
+    RepoError,
+    RepoLookupError,
+    InterventionRequired,
+    RequirementError,
+    alwaysmatcher,
+    patternmatcher,
+    hgutil,
+    hgext_strip,
+)
 from vcsserver.str_utils import ascii_bytes, ascii_str, safe_str, safe_bytes
 from vcsserver.vcs_base import RemoteBase
 from vcsserver.config import hooks as hooks_config
-
+from vcsserver.lib.exc_tracking import format_exc
 
 log = logging.getLogger(__name__)
 
@@ -736,15 +771,15 b' class HgRemote(RemoteBase):'
                     rev = rev + -1
             try:
                 ctx = self._get_ctx(repo, rev)
-            except (AmbiguousPrefixLookupError) as e:
+            except AmbiguousPrefixLookupError:
                 e = RepoLookupError(rev)
-                e._org_exc_tb = traceback.format_exc()
+                e._org_exc_tb = format_exc(sys.exc_info())
                 raise exceptions.LookupException(e)(rev)
             except (TypeError, RepoLookupError, binascii.Error) as e:
-                e._org_exc_tb = traceback.format_exc()
+                e._org_exc_tb = format_exc(sys.exc_info())
                 raise exceptions.LookupException(e)(rev)
             except LookupError as e:
-                e._org_exc_tb = traceback.format_exc()
+                e._org_exc_tb = format_exc(sys.exc_info())
                 raise exceptions.LookupException(e)(e.name)
 
             if not both: