Welcome to Software Development on Codidact!
Will you help us build our independent community of developers helping developers? We're small and trying to grow. We welcome questions about all aspects of software development, from design to code to QA and more. Got questions? Got answers? Got code you'd like someone to review? Please join us.
JSON log formatter
Here's a JSON log formatter for Python. I want to be able to log details of exceptions (and have some capability to debug-by-logs). I want to be able to log extra data in JSON format (in addition to a message string).
Is my approach sound, in general?
I distinguish between regular logging and exception logging by checking for presence of exc_info. It works, but is it the right way to do it?
Am logging the exception info that I should be logging? Am I missing anything useful?
Here's what I wrote so far. (Work in progress, and I'm not married to this design.)
class JsonLogFormatter(logging.Formatter):
def __init__(self) -> None:
super().__init__()
def format(self, record):
log_record_dict = { "time": self.formatTime(record), "level": record.levelname, "message": record.message }
if record.exc_info is not None:
log_record_dict.update( {"exception": self.formatException(record.exc_info)} )
log_record_dict.update(record.args)
return json.dumps(log_record_dict, indent=None)
Log entry in the unhandled exception hook.
class UncaughtExceptionHook:
def __init__(self, logger):
self.logger = logger
sys.excepthook = self.exception_hook # It seemd sonvenient to register the hook with the system in the ctor. Future will show if this is future-proof.
def exception_hook(self, ex_type, ex_value, ex_traceback):
self.logger.critical(f"Unhandled exception.", exc_info=(ex_type, ex_value, ex_traceback))
sys.exit(1)
Calling code.
logger.info("hello JSON log entry")
logger.info("now with an attachment", {"foo": "Lorem ipsum"} )
#deliberate exception to check the UncaughtExceptionHook
raise ValueError("deliberate exception to check the UncaughtExceptionHook" )
Resulting log entries.
{"time": "2023-05-02 15:12:46,735", "level": "INFO", "message": "hello JSON log entry"}
{"time": "2023-05-02 15:12:53,643", "level": "INFO", "message": "now with an attachment", "foo": "Lorem ipsum"}
{"time": "2023-05-02 15:12:56,086", "level": "CRITICAL", "message": "Unhandled exception.", "exception": "Traceback (most recent call last):\n File \"C:\\Program Files\\WindowsApps\\PythonSoftwareFoundation.Python.3.11_3.11.1008.0_x64__qbz5n2kfra8p0\\Lib\\runpy.py\", line 198, in _run_module_as_main\n return _run_code(code, main_globals, None,\n ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^\n File \"C:\\Program Files\\WindowsApps\\PythonSoftwareFoundation.Python.3.11_3.11.1008.0_x64__qbz5n2kfra8p0\\Lib\\runpy.py\", line 88, in _run_code\n exec(code, run_globals)\n File \"c:\\Users\\User\\.vscode\\extensions\\ms-python.python-2023.6.1\\pythonFiles\\lib\\python\\debugpy\\adapter/../..\\debugpy\\launcher/../..\\debugpy\\__main__.py\", line 39, in <module>\n cli.main()\n File \"c:\\Users\\User\\.vscode\\extensions\\ms-python.python-2023.6.1\\pythonFiles\\lib\\python\\debugpy\\adapter/../..\\debugpy\\launcher/../..\\debugpy/..\\debugpy\\server\\cli.py\", line 430, in main\n run()\n File \"c:\\Users\\User\\.vscode\\extensions\\ms-python.python-2023.6.1\\pythonFiles\\lib\\python\\debugpy\\adapter/../..\\debugpy\\launcher/../..\\debugpy/..\\debugpy\\server\\cli.py\", line 284, in run_file\n runpy.run_path(target, run_name=\"__main__\")\n File \"c:\\Users\\User\\.vscode\\extensions\\ms-python.python-2023.6.1\\pythonFiles\\lib\\python\\debugpy\\_vendored\\pydevd\\_pydevd_bundle\\pydevd_runpy.py\", line 321, in run_path\n return _run_module_code(code, init_globals, run_name,\n ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^\n File \"c:\\Users\\User\\.vscode\\extensions\\ms-python.python-2023.6.1\\pythonFiles\\lib\\python\\debugpy\\_vendored\\pydevd\\_pydevd_bundle\\pydevd_runpy.py\", line 135, in _run_module_code\n _run_code(code, mod_globals, init_globals,\n File \"c:\\Users\\User\\.vscode\\extensions\\ms-python.python-2023.6.1\\pythonFiles\\lib\\python\\debugpy\\_vendored\\pydevd\\_pydevd_bundle\\pydevd_runpy.py\", line 124, in _run_code\n exec(code, run_globals)\n File \"C:\\Users\\User\\source\\repos\\KiCAD netlist reader\\test01.py\", line 59, in <module>\n raise ValueError(\"deliberate exception to check the UncaughtExceptionHook\" )\nValueError: deliberate exception to check the UncaughtExceptionHook"}
2 answers
I'd suggest using Black to format the code. While there are a number of formatters, it helps to pick one to make the code consistent. (See https://github.com/psf/black)
The use of .update({"exception": ...}) to insert a single item into a dictionary seems a bit of avoidable overhead.
The name log_record_dict -- with a kind of type name at the end -- is something often called "Hungarian Notation". (https://en.wikipedia.org/wiki/Hungarian_notation) This is something that is often avoided in Python programming.
1 comment thread
PEP 8
Four-space indentation is the community standard. There are many strategies for wrapping long lines; I have found that it's often best to just use temporary variables to avoid wrapping lines.
Avoid pointless classes
The UncaughtExceptionHook class is a textbook example of the design Jack Diederich warns against in the provocatively-titled talk Stop Writing Classes. It really only exists to "bind" the logger to later calls of exception_hook; it doesn't conceptually represent any more than the callback function itself does, it doesn't need to modify internal state, and it only provides a single interface method. This makes it a prime candidate for refactoring to use a simple function with functools.partial. As for registering the resulting exception hook, that can be done with a simple wrapper function.
import functools, sys
def log_uncaught_exception(logger, exc_type, exc_value, exc_traceback):
exc_info = (ex_type, ex_value, ex_traceback)
logger.critical(f"Unhandled exception.", exc_info=exc_info)
sys.exit(1)
def set_logging_exception_hook(logger):
sys.excepthook = functools.partial(log_uncaught_exception, logger)
Now there is a simple imperative interface for something that looks like an imperative task, rather than an object-oriented interface for something that doesn't look at all like a modeling task.
Avoid boilerplate
JsonLogFormatter.__init__ currently doesn't do anything different from the default. There is no benefit to writing anything here; wait until there is something to specify.
Simpler dict construction
Agreed that update is overkill for adding a single key. Aside from that, dict unpacking can be used to simplify the syntax.
Putting the previous two hints together:
class JsonLogFormatter(logging.Formatter):
def format(self, record):
data = {
"time": self.formatTime(record),
"level": record.levelname,
"message": record.message
}
if record.exc_info is not None:
data["exception"] = self.formatException(record.exc_info)
return json.dumps({**data, **record.args}, indent=None)
0 comment threads
1 comment thread