fix(formatter): custom fields

This commit is contained in:
Kristofers Solo 2024-09-12 15:21:59 +03:00
parent ad7db29ac1
commit 44ffa512a1
3 changed files with 207 additions and 28 deletions

View File

@ -1,6 +1,6 @@
[project] [project]
name = "bunyan-formatter" name = "bunyan-formatter"
version = "1.0.0" version = "0.1.0"
description = "Bunyan Formatter for Python" description = "Bunyan Formatter for Python"
dependencies = [] dependencies = []
readme = "README.md" readme = "README.md"

View File

@ -2,21 +2,46 @@ import json
import logging import logging
import socket import socket
import time import time
import traceback
from logging import Formatter, LogRecord from logging import Formatter, LogRecord
from pathlib import Path from pathlib import Path
from typing import ClassVar, Optional from typing import Any, Optional
DEFAULT_FIELDS = {
"name",
"msg",
"args",
"levelname",
"levelno",
"pathname",
"filename",
"module",
"exc_info",
"exc_text",
"stack_info",
"lineno",
"funcName",
"created",
"msecs",
"relativeCreated",
"thread",
"threadName",
"processName",
"process",
"taskName",
}
LEVEL_MAP = {
logging.NOTSET: 10,
logging.DEBUG: 20,
logging.INFO: 30,
logging.WARNING: 40,
logging.ERROR: 50,
logging.CRITICAL: 60,
}
class BunyanFormatter(Formatter): class BunyanFormatter(Formatter):
LEVEL_MAP: ClassVar[dict[int, int]] = {
logging.NOTSET: 10,
logging.DEBUG: 20,
logging.INFO: 30,
logging.WARNING: 40,
logging.ERROR: 50,
logging.CRITICAL: 60,
}
def __init__(self, project_name: str, project_root: Path) -> None: def __init__(self, project_name: str, project_root: Path) -> None:
super().__init__() super().__init__()
self.project_name = project_name self.project_name = project_name
@ -24,8 +49,6 @@ class BunyanFormatter(Formatter):
self.hostname = socket.gethostname() self.hostname = socket.gethostname()
def format(self, record: LogRecord) -> str: def format(self, record: LogRecord) -> str:
hostname = socket.gethostname()
file_path = Path(record.pathname) file_path = Path(record.pathname)
try: try:
relative_path = file_path.relative_to(self.project_root) relative_path = file_path.relative_to(self.project_root)
@ -36,9 +59,9 @@ class BunyanFormatter(Formatter):
"v": 0, "v": 0,
"name": self.project_name, "name": self.project_name,
"msg": record.getMessage(), "msg": record.getMessage(),
"level": self.LEVEL_MAP.get(record.levelno, record.levelno), "level": LEVEL_MAP.get(record.levelno, record.levelno),
"levelname": record.levelname, "levelname": record.levelname,
"hostname": hostname, "hostname": self.hostname,
"pid": record.process, "pid": record.process,
"time": self.formatTime(record), "time": self.formatTime(record),
"target": record.name, "target": record.name,
@ -46,6 +69,15 @@ class BunyanFormatter(Formatter):
"file": str(relative_path), "file": str(relative_path),
} }
# Handle extra fields
extra_fields = {k: v for k, v in record.__dict__.items() if k not in DEFAULT_FIELDS}
if extra_fields:
log_entry["extra"] = extra_fields
# Handle exception information
if record.exc_info and all(record.exc_info):
log_entry["err"] = self._format_exception(record)
return json.dumps(log_entry) return json.dumps(log_entry)
def formatTime(self, record: LogRecord, datefmt: Optional[str] = None) -> str: # noqa: N802 def formatTime(self, record: LogRecord, datefmt: Optional[str] = None) -> str: # noqa: N802
@ -56,3 +88,30 @@ class BunyanFormatter(Formatter):
t = time.strftime("%Y-%m-%dT%H:%M:%S", ct) t = time.strftime("%Y-%m-%dT%H:%M:%S", ct)
s = f"{t}.{int(record.msecs):03d}Z" s = f"{t}.{int(record.msecs):03d}Z"
return s return s
def _format_exception(self, record: LogRecord) -> dict[str, Any]:
exc_info = record.exc_info
if exc_info is None or len(exc_info) != 3:
return {}
exc_type, exc_value, exc_traceback = exc_info
if exc_type is None or exc_value is None or exc_traceback is None:
return {}
stack = traceback.extract_tb(exc_traceback)
return {
"message": str(exc_value),
"name": getattr(exc_type, "__name__", "UnknownException"),
"stack": [
{
"file": frame.filename,
"line": frame.lineno,
"function": frame.name,
"text": frame.line.strip() if frame.line is not None else "",
}
for frame in stack
],
}

View File

@ -1,6 +1,8 @@
import json import json
import logging import logging
from logging import LogRecord from datetime import datetime
from io import StringIO
from logging import LogRecord, StreamHandler
from pathlib import Path from pathlib import Path
from typing import Optional from typing import Optional
from unittest import TestCase from unittest import TestCase
@ -10,7 +12,11 @@ from bunyan_formatter import BunyanFormatter
class TestBunyanFormatter(TestCase): class TestBunyanFormatter(TestCase):
def setUp(self) -> None: @patch("socket.gethostname")
def setUp(self, mock_gethostname: Optional[Mock]) -> None:
if mock_gethostname is None:
raise ValueError("mock_gethostname should not be None")
mock_gethostname.return_value = "test_host"
self.project_name = "test_project" self.project_name = "test_project"
self.project_root = Path("/path/to/project") self.project_root = Path("/path/to/project")
self.formatter = BunyanFormatter(self.project_name, self.project_root) self.formatter = BunyanFormatter(self.project_name, self.project_root)
@ -18,12 +24,7 @@ class TestBunyanFormatter(TestCase):
def create_log_record(self, level: int, msg: str, pathname: str) -> LogRecord: def create_log_record(self, level: int, msg: str, pathname: str) -> LogRecord:
return LogRecord(name="test_logger", level=level, pathname=pathname, lineno=42, msg=msg, args=(), exc_info=None) return LogRecord(name="test_logger", level=level, pathname=pathname, lineno=42, msg=msg, args=(), exc_info=None)
@patch("socket.gethostname") def test_format_basic(self) -> None:
def test_format_basic(self, mock_gethostname: Optional[Mock]) -> None:
if mock_gethostname is None:
raise ValueError("mock_gethostname should not be None")
mock_gethostname.return_value = "test_host"
record = self.create_log_record(logging.INFO, "Test message", "/path/to/project/test.py") record = self.create_log_record(logging.INFO, "Test message", "/path/to/project/test.py")
formatted = self.formatter.format(record) formatted = self.formatter.format(record)
@ -56,11 +57,7 @@ class TestBunyanFormatter(TestCase):
log_entry = json.loads(formatted) log_entry = json.loads(formatted)
assert log_entry["file"] == "/path/outside/project/test.py" assert log_entry["file"] == "/path/outside/project/test.py"
@patch("socket.gethostname") def test_format_hostname_consistency(self) -> None:
def test_format_hostname_consistency(self, mock_gethostname: Optional[Mock]) -> None:
if mock_gethostname is None:
raise ValueError("mock_gethostname should not be None")
mock_gethostname.return_value = "test_host"
record1 = self.create_log_record(logging.INFO, "Message 1", "/path/to/project/test1.py") record1 = self.create_log_record(logging.INFO, "Message 1", "/path/to/project/test1.py")
record2 = self.create_log_record(logging.INFO, "Message 2", "/path/to/project/test2.py") record2 = self.create_log_record(logging.INFO, "Message 2", "/path/to/project/test2.py")
@ -84,3 +81,126 @@ class TestBunyanFormatter(TestCase):
datetime.strptime(log_entry["time"], "%Y-%m-%dT%H:%M:%S.%fZ") datetime.strptime(log_entry["time"], "%Y-%m-%dT%H:%M:%S.%fZ")
except ValueError: except ValueError:
self.fail("Time is not in the correct format") self.fail("Time is not in the correct format")
def test_format_exception(self) -> None:
logger = logging.getLogger("test_logger")
logger.setLevel(logging.DEBUG)
stream = StringIO()
handler = StreamHandler(stream)
handler.setFormatter(self.formatter)
logger.addHandler(handler)
try:
raise ValueError("Test error")
except ValueError:
logger.exception("An error occurred")
# Get the last logged message
last_message = handler.stream.getvalue().splitlines()[-1]
log_entry = json.loads(last_message)
assert log_entry["v"] == 0
assert log_entry["name"] == self.project_name
assert log_entry["msg"] == "An error occurred"
assert log_entry["level"] == 50
assert log_entry["levelname"] == "ERROR"
assert log_entry["hostname"] == "test_host"
assert log_entry["target"] == "test_logger"
assert "err" in log_entry
assert "message" in log_entry["err"]
assert "name" in log_entry["err"]
assert "stack" in log_entry["err"]
def test_format_custom_fields(self) -> None:
logger = logging.getLogger("test_logger")
logger.setLevel(logging.DEBUG)
stream = StringIO()
handler = StreamHandler(stream)
handler.setFormatter(self.formatter)
logger.addHandler(handler)
logger.info("User logged in", extra={"username": "john_doe", "ip_address": "192.168.1.100"})
# Get the last logged message
last_message = handler.stream.getvalue().splitlines()[-1]
log_entry = json.loads(last_message)
assert log_entry["v"] == 0
assert log_entry["name"] == self.project_name
assert log_entry["msg"] == "User logged in"
assert log_entry["level"] == 30
assert log_entry["levelname"] == "INFO"
assert log_entry["target"] == "test_logger"
assert "extra" in log_entry
assert log_entry["extra"]["username"] == "john_doe"
assert log_entry["extra"]["ip_address"] == "192.168.1.100"
def test_format_nested_custom_fields(self) -> None:
logger = logging.getLogger("test_logger")
logger.setLevel(logging.DEBUG)
stream = StringIO()
handler = StreamHandler(stream)
handler.setFormatter(self.formatter)
logger.addHandler(handler)
nested_data = {
"user": {"id": 123, "email": "user@example.com"},
"action": "login",
"timestamp": datetime.now().isoformat(),
}
logger.info("Complex action performed", extra={"data": nested_data})
# Get the last logged message
last_message = handler.stream.getvalue().splitlines()[-1]
log_entry = json.loads(last_message)
assert log_entry["v"] == 0
assert log_entry["name"] == self.project_name
assert log_entry["msg"] == "Complex action performed"
assert log_entry["level"] == 30
assert log_entry["levelname"] == "INFO"
assert log_entry["target"] == "test_logger"
assert "extra" in log_entry
assert "data" in log_entry["extra"]
assert isinstance(log_entry["extra"]["data"], dict)
assert log_entry["extra"]["data"]["user"]["id"] == 123
assert log_entry["extra"]["data"]["user"]["email"] == "user@example.com"
assert log_entry["extra"]["data"]["action"] == "login"
assert "timestamp" in log_entry["extra"]["data"]
def test_format_exception_with_custom_fields(self) -> None:
logger = logging.getLogger("test_logger")
logger.setLevel(logging.DEBUG)
stream = StringIO()
handler = StreamHandler(stream)
handler.setFormatter(self.formatter)
logger.addHandler(handler)
try:
raise ValueError("Test error")
except ValueError:
logger.exception("An error occurred", extra={"error_code": "E001", "user_id": 456})
# Get the last logged message
last_message = handler.stream.getvalue().splitlines()[-1]
log_entry = json.loads(last_message)
assert log_entry["v"] == 0
assert log_entry["name"] == self.project_name
assert log_entry["msg"] == "An error occurred"
assert log_entry["level"] == 50
assert log_entry["levelname"] == "ERROR"
assert log_entry["hostname"] == "test_host"
assert log_entry["target"] == "test_logger"
assert "err" in log_entry
assert "message" in log_entry["err"]
assert "name" in log_entry["err"]
assert "stack" in log_entry["err"]
assert "extra" in log_entry
assert log_entry["extra"]["error_code"] == "E001"
assert log_entry["extra"]["user_id"] == 456