refactor!: Log 5xx error to error log instead of error snapshot
Also move log_error function to right location
This commit is contained in:
Ankush Menat
parent
92c24d9abb
commit
b9f000e1f9
4 changed files with 43 additions and 274 deletions
|
|
@ -2213,41 +2213,6 @@ def logger(
|
|||
)
|
||||
|
||||
|
||||
def log_error(title=None, message=None, reference_doctype=None, reference_name=None):
|
||||
"""Log error to Error Log"""
|
||||
# Parameter ALERT:
|
||||
# the title and message may be swapped
|
||||
# the better API for this is log_error(title, message), and used in many cases this way
|
||||
# this hack tries to be smart about whats a title (single line ;-)) and fixes it
|
||||
|
||||
traceback = None
|
||||
if message:
|
||||
if "\n" in title: # traceback sent as title
|
||||
traceback, title = title, message
|
||||
else:
|
||||
traceback = message
|
||||
|
||||
title = title or "Error"
|
||||
traceback = as_unicode(traceback or get_traceback(with_context=True))
|
||||
|
||||
if not db:
|
||||
print(f"Failed to log error in db: {title}")
|
||||
return
|
||||
|
||||
error_log = get_doc(
|
||||
doctype="Error Log",
|
||||
error=traceback,
|
||||
method=title,
|
||||
reference_doctype=reference_doctype,
|
||||
reference_name=reference_name,
|
||||
)
|
||||
|
||||
if flags.read_only:
|
||||
error_log.deferred_insert()
|
||||
else:
|
||||
return error_log.insert(ignore_permissions=True)
|
||||
|
||||
|
||||
def get_desk_link(doctype, name):
|
||||
html = (
|
||||
'<a href="/app/Form/{doctype}/{name}" style="font-weight: bold;">{doctype_local} {name}</a>'
|
||||
|
|
@ -2439,6 +2404,8 @@ def validate_and_sanitize_search_inputs(fn):
|
|||
return wrapper
|
||||
|
||||
|
||||
from frappe.utils.error import log_error # noqa: backward compatibility
|
||||
|
||||
if _tune_gc:
|
||||
# generational GC gets triggered after certain allocs (g0) which is 700 by default.
|
||||
# This number is quite small for frappe where a single query can potentially create 700+
|
||||
|
|
|
|||
|
|
@ -22,7 +22,7 @@ from frappe import _
|
|||
from frappe.auth import SAFE_HTTP_METHODS, UNSAFE_HTTP_METHODS, HTTPRequest
|
||||
from frappe.middlewares import StaticDataMiddleware
|
||||
from frappe.utils import cint, get_site_name, sanitize_html
|
||||
from frappe.utils.error import make_error_snapshot
|
||||
from frappe.utils.error import log_error_snapshot
|
||||
from frappe.website.serve import get_response
|
||||
|
||||
local_manager = LocalManager(frappe.local)
|
||||
|
|
@ -346,7 +346,7 @@ def handle_exception(e):
|
|||
frappe.local.login_manager.clear_cookies()
|
||||
|
||||
if http_status_code >= 500:
|
||||
make_error_snapshot(e)
|
||||
log_error_snapshot(e)
|
||||
|
||||
if return_as_message:
|
||||
response = get_response("message", http_status_code=http_status_code)
|
||||
|
|
|
|||
|
|
@ -214,7 +214,6 @@ scheduler_events = {
|
|||
"hourly": [
|
||||
"frappe.model.utils.link_count.update_link_count",
|
||||
"frappe.model.utils.user_settings.sync_user_settings",
|
||||
"frappe.utils.error.collect_error_snapshots",
|
||||
"frappe.desk.page.backups.backups.delete_downloadable_backups",
|
||||
"frappe.deferred_insert.save_to_db",
|
||||
"frappe.desk.form.document_follow.send_hourly_updates",
|
||||
|
|
|
|||
|
|
@ -1,17 +1,10 @@
|
|||
# Copyright (c) 2015, Maxwell Morais and contributors
|
||||
# License: MIT. See LICENSE
|
||||
|
||||
import datetime
|
||||
import functools
|
||||
import inspect
|
||||
import json
|
||||
import linecache
|
||||
import os
|
||||
import sys
|
||||
import traceback
|
||||
|
||||
import frappe
|
||||
from frappe.utils import cstr, encode
|
||||
|
||||
EXCLUDE_EXCEPTIONS = (
|
||||
frappe.AuthenticationError,
|
||||
|
|
@ -37,194 +30,57 @@ def _is_ldap_exception(e):
|
|||
return False
|
||||
|
||||
|
||||
def make_error_snapshot(exception):
|
||||
if frappe.conf.disable_error_snapshot:
|
||||
def log_error(
|
||||
title=None, message=None, reference_doctype=None, reference_name=None, *, defer_insert=False
|
||||
):
|
||||
"""Log error to Error Log"""
|
||||
# Parameter ALERT:
|
||||
# the title and message may be swapped
|
||||
# the better API for this is log_error(title, message), and used in many cases this way
|
||||
# this hack tries to be smart about whats a title (single line ;-)) and fixes it
|
||||
|
||||
traceback = None
|
||||
if message:
|
||||
if "\n" in title: # traceback sent as title
|
||||
traceback, title = title, message
|
||||
else:
|
||||
traceback = message
|
||||
|
||||
title = title or "Error"
|
||||
traceback = frappe.as_unicode(traceback or frappe.get_traceback(with_context=True))
|
||||
|
||||
if not frappe.db:
|
||||
print(f"Failed to log error in db: {title}")
|
||||
return
|
||||
|
||||
error_log = frappe.get_doc(
|
||||
doctype="Error Log",
|
||||
error=traceback,
|
||||
method=title,
|
||||
reference_doctype=reference_doctype,
|
||||
reference_name=reference_name,
|
||||
)
|
||||
|
||||
if frappe.flags.read_only or defer_insert:
|
||||
error_log.deferred_insert()
|
||||
else:
|
||||
return error_log.insert(ignore_permissions=True)
|
||||
|
||||
|
||||
def log_error_snapshot(exception: Exception):
|
||||
|
||||
if isinstance(exception, EXCLUDE_EXCEPTIONS) or _is_ldap_exception(exception):
|
||||
return
|
||||
|
||||
logger = frappe.logger(with_more_info=True)
|
||||
|
||||
try:
|
||||
error_id = "{timestamp:s}-{ip:s}-{hash:s}".format(
|
||||
timestamp=cstr(datetime.datetime.now()),
|
||||
ip=frappe.local.request_ip or "127.0.0.1",
|
||||
hash=frappe.generate_hash(length=3),
|
||||
)
|
||||
snapshot_folder = get_error_snapshot_path()
|
||||
frappe.create_folder(snapshot_folder)
|
||||
|
||||
snapshot_file_path = os.path.join(snapshot_folder, f"{error_id}.json")
|
||||
snapshot = get_snapshot(exception)
|
||||
|
||||
with open(encode(snapshot_file_path), "wb") as error_file:
|
||||
error_file.write(encode(frappe.as_json(snapshot)))
|
||||
|
||||
logger.error(f"New Exception collected with id: {error_id}")
|
||||
|
||||
log_error(title=str(exception), defer_insert=True)
|
||||
logger.error("New Exception collected in error log")
|
||||
except Exception as e:
|
||||
logger.error(f"Could not take error snapshot: {e}", exc_info=True)
|
||||
|
||||
|
||||
def get_snapshot(exception, context=10):
|
||||
import pydoc
|
||||
|
||||
"""
|
||||
Return a dict describing a given traceback (based on cgitb.text)
|
||||
"""
|
||||
|
||||
etype, evalue, etb = sys.exc_info()
|
||||
if isinstance(etype, type):
|
||||
etype = etype.__name__
|
||||
|
||||
# creates a snapshot dict with some basic information
|
||||
|
||||
s = {
|
||||
"pyver": "Python {version:s}: {executable:s} (prefix: {prefix:s})".format(
|
||||
version=sys.version.split(maxsplit=1)[0], executable=sys.executable, prefix=sys.prefix
|
||||
),
|
||||
"timestamp": cstr(datetime.datetime.now()),
|
||||
"traceback": traceback.format_exc(),
|
||||
"frames": [],
|
||||
"etype": cstr(etype),
|
||||
"evalue": cstr(repr(evalue)),
|
||||
"exception": {},
|
||||
"locals": {},
|
||||
}
|
||||
|
||||
# start to process frames
|
||||
records = inspect.getinnerframes(etb, 5)
|
||||
|
||||
for frame, file, lnum, func, lines, index in records:
|
||||
file = file and os.path.abspath(file) or "?"
|
||||
args, varargs, varkw, locals = inspect.getargvalues(frame)
|
||||
call = ""
|
||||
|
||||
if func != "?":
|
||||
call = inspect.formatargvalues(
|
||||
args, varargs, varkw, locals, formatvalue=lambda value: f"={pydoc.text.repr(value)}"
|
||||
)
|
||||
|
||||
# basic frame information
|
||||
f = {"file": file, "func": func, "call": call, "lines": {}, "lnum": lnum}
|
||||
|
||||
def reader(lnum=[lnum]): # noqa
|
||||
try:
|
||||
# B023: function is evaluated immediately, binding not necessary
|
||||
return linecache.getline(file, lnum[0]) # noqa: B023
|
||||
finally:
|
||||
lnum[0] += 1
|
||||
|
||||
vars = _scanvars(reader, frame, locals)
|
||||
|
||||
# if it is a view, replace with generated code
|
||||
# if file.endswith('html'):
|
||||
# lmin = lnum > context and (lnum - context) or 0
|
||||
# lmax = lnum + context
|
||||
# lines = code.split("\n")[lmin:lmax]
|
||||
# index = min(context, lnum) - 1
|
||||
|
||||
if index is not None:
|
||||
i = lnum - index
|
||||
for line in lines:
|
||||
f["lines"][i] = line.rstrip()
|
||||
i += 1
|
||||
|
||||
# dump local variable (referenced in current line only)
|
||||
f["dump"] = {}
|
||||
for name, where, value in vars:
|
||||
if name in f["dump"]:
|
||||
continue
|
||||
if value is not __UNDEF__:
|
||||
if where == "global":
|
||||
name = f"global {name:s}"
|
||||
elif where != "local":
|
||||
name = where + " " + name.split(".")[-1]
|
||||
f["dump"][name] = pydoc.text.repr(value)
|
||||
else:
|
||||
f["dump"][name] = "undefined"
|
||||
|
||||
s["frames"].append(f)
|
||||
|
||||
# add exception type, value and attributes
|
||||
if isinstance(evalue, BaseException):
|
||||
for name in dir(evalue):
|
||||
if name != "messages" and not name.startswith("__"):
|
||||
value = pydoc.text.repr(getattr(evalue, name))
|
||||
s["exception"][name] = encode(value)
|
||||
|
||||
# add all local values (of last frame) to the snapshot
|
||||
for name, value in locals.items():
|
||||
s["locals"][name] = value if isinstance(value, str) else pydoc.text.repr(value)
|
||||
|
||||
return s
|
||||
|
||||
|
||||
def collect_error_snapshots():
|
||||
"""Scheduled task to collect error snapshots from files and push into Error Snapshot table"""
|
||||
if frappe.conf.disable_error_snapshot:
|
||||
return
|
||||
|
||||
try:
|
||||
path = get_error_snapshot_path()
|
||||
if not os.path.exists(path):
|
||||
return
|
||||
|
||||
for fname in os.listdir(path):
|
||||
fullpath = os.path.join(path, fname)
|
||||
|
||||
try:
|
||||
with open(fullpath) as filedata:
|
||||
data = json.load(filedata)
|
||||
|
||||
except ValueError:
|
||||
# empty file
|
||||
os.remove(fullpath)
|
||||
continue
|
||||
|
||||
for field in ["locals", "exception", "frames"]:
|
||||
data[field] = frappe.as_json(data[field])
|
||||
|
||||
doc = frappe.new_doc("Error Snapshot")
|
||||
doc.update(data)
|
||||
doc.save()
|
||||
|
||||
frappe.db.commit()
|
||||
|
||||
os.remove(fullpath)
|
||||
|
||||
clear_old_snapshots()
|
||||
|
||||
except Exception as e:
|
||||
make_error_snapshot(e)
|
||||
|
||||
# prevent creation of unlimited error snapshots
|
||||
raise
|
||||
|
||||
|
||||
def clear_old_snapshots():
|
||||
"""Clear snapshots that are older than a month"""
|
||||
from frappe.query_builder import DocType, Interval
|
||||
from frappe.query_builder.functions import Now
|
||||
|
||||
ErrorSnapshot = DocType("Error Snapshot")
|
||||
frappe.db.delete(ErrorSnapshot, filters=(ErrorSnapshot.creation < (Now() - Interval(months=1))))
|
||||
|
||||
path = get_error_snapshot_path()
|
||||
today = datetime.datetime.now()
|
||||
|
||||
for file in os.listdir(path):
|
||||
p = os.path.join(path, file)
|
||||
ctime = datetime.datetime.fromtimestamp(os.path.getctime(p))
|
||||
if (today - ctime).days > 31:
|
||||
os.remove(os.path.join(path, p))
|
||||
|
||||
|
||||
def get_error_snapshot_path():
|
||||
return frappe.get_site_path("error-snapshots")
|
||||
|
||||
|
||||
def get_default_args(func):
|
||||
"""Get default arguments of a function from its signature."""
|
||||
signature = inspect.signature(func)
|
||||
|
|
@ -270,56 +126,3 @@ def raise_error_on_no_output(error_message, error_type=None, keep_quiet=None):
|
|||
return wrapper_raise_error_on_no_output
|
||||
|
||||
return decorator_raise_error_on_no_output
|
||||
|
||||
|
||||
# Vendored from cgitb standard library reused under PSF License:
|
||||
# https://github.com/python/cpython/blob/main/LICENSE
|
||||
|
||||
|
||||
import keyword
|
||||
import tokenize
|
||||
|
||||
__UNDEF__ = [] # a special sentinel object
|
||||
|
||||
|
||||
def _scanvars(reader, frame, locals):
|
||||
"""Scan one logical line of Python and look up values of variables used."""
|
||||
vars, lasttoken, parent, prefix, value = [], None, None, "", __UNDEF__
|
||||
for ttype, token, start, end, line in tokenize.generate_tokens(reader):
|
||||
if ttype == tokenize.NEWLINE:
|
||||
break
|
||||
if ttype == tokenize.NAME and token not in keyword.kwlist:
|
||||
if lasttoken == ".":
|
||||
if parent is not __UNDEF__:
|
||||
value = getattr(parent, token, __UNDEF__)
|
||||
vars.append((prefix + token, prefix, value))
|
||||
else:
|
||||
where, value = _lookup(token, frame, locals)
|
||||
vars.append((token, where, value))
|
||||
elif token == ".":
|
||||
prefix += lasttoken + "."
|
||||
parent = value
|
||||
else:
|
||||
parent, prefix = None, ""
|
||||
lasttoken = token
|
||||
return vars
|
||||
|
||||
|
||||
def _lookup(name, frame, locals):
|
||||
"""Find the value for a given name in the given environment."""
|
||||
if name in locals:
|
||||
return "local", locals[name]
|
||||
if name in frame.f_globals:
|
||||
return "global", frame.f_globals[name]
|
||||
if "__builtins__" in frame.f_globals:
|
||||
builtins = frame.f_globals["__builtins__"]
|
||||
if type(builtins) is type({}): # noqa
|
||||
if name in builtins:
|
||||
return "builtin", builtins[name]
|
||||
else:
|
||||
if hasattr(builtins, name):
|
||||
return "builtin", getattr(builtins, name)
|
||||
return None, __UNDEF__
|
||||
|
||||
|
||||
# end: vendored code
|
||||
|
|
|
|||
Loading…
Add table
Reference in a new issue