diff --git a/pyproject.toml b/pyproject.toml index f0b1a78..9341230 100644 --- a/pyproject.toml +++ b/pyproject.toml @@ -1,6 +1,6 @@ [project] name = "bunyan-formatter" -version = "1.0.0" +version = "0.1.0" description = "Bunyan Formatter for Python" dependencies = [] readme = "README.md" diff --git a/src/bunyan_formatter/logger.py b/src/bunyan_formatter/logger.py index 2b1f797..9d54779 100644 --- a/src/bunyan_formatter/logger.py +++ b/src/bunyan_formatter/logger.py @@ -2,21 +2,46 @@ import json import logging import socket import time +import traceback from logging import Formatter, LogRecord 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): - 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: super().__init__() self.project_name = project_name @@ -24,8 +49,6 @@ class BunyanFormatter(Formatter): self.hostname = socket.gethostname() def format(self, record: LogRecord) -> str: - hostname = socket.gethostname() - file_path = Path(record.pathname) try: relative_path = file_path.relative_to(self.project_root) @@ -36,9 +59,9 @@ class BunyanFormatter(Formatter): "v": 0, "name": self.project_name, "msg": record.getMessage(), - "level": self.LEVEL_MAP.get(record.levelno, record.levelno), + "level": LEVEL_MAP.get(record.levelno, record.levelno), "levelname": record.levelname, - "hostname": hostname, + "hostname": self.hostname, "pid": record.process, "time": self.formatTime(record), "target": record.name, @@ -46,6 +69,15 @@ class BunyanFormatter(Formatter): "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) 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) s = f"{t}.{int(record.msecs):03d}Z" 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 + ], + } diff --git a/tests/test_formatter.py b/tests/test_formatter.py index cee03e7..54b6920 100644 --- a/tests/test_formatter.py +++ b/tests/test_formatter.py @@ -1,6 +1,8 @@ import json import logging -from logging import LogRecord +from datetime import datetime +from io import StringIO +from logging import LogRecord, StreamHandler from pathlib import Path from typing import Optional from unittest import TestCase @@ -10,7 +12,11 @@ from bunyan_formatter import BunyanFormatter 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_root = Path("/path/to/project") 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: 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, mock_gethostname: Optional[Mock]) -> None: - if mock_gethostname is None: - raise ValueError("mock_gethostname should not be None") - - mock_gethostname.return_value = "test_host" + def test_format_basic(self) -> None: record = self.create_log_record(logging.INFO, "Test message", "/path/to/project/test.py") formatted = self.formatter.format(record) @@ -56,11 +57,7 @@ class TestBunyanFormatter(TestCase): log_entry = json.loads(formatted) assert log_entry["file"] == "/path/outside/project/test.py" - @patch("socket.gethostname") - 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" + def test_format_hostname_consistency(self) -> None: 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") @@ -84,3 +81,126 @@ class TestBunyanFormatter(TestCase): datetime.strptime(log_entry["time"], "%Y-%m-%dT%H:%M:%S.%fZ") except ValueError: 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