# HG changeset patch # User RhodeCode Admin # Date 2023-08-07 12:03:11 # Node ID 23926495bf2a686ad3b77ef7ab892e6d95764251 # Parent de59bf7001cd1634393e2847f873ecee8bac75a4 exc_tracking: always nice format tb for core exceptions diff --git a/rhodecode/config/middleware.py b/rhodecode/config/middleware.py --- a/rhodecode/config/middleware.py +++ b/rhodecode/config/middleware.py @@ -48,7 +48,7 @@ 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 @@ 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 @@ 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: diff --git a/rhodecode/lib/exc_tracking.py b/rhodecode/lib/exc_tracking.py --- a/rhodecode/lib/exc_tracking.py +++ b/rhodecode/lib/exc_tracking.py @@ -16,6 +16,7 @@ # 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 @@ 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 @@ 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 @@ 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 @@ 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 @@ 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 @@ 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 @@ 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 @@ 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