diff --git a/.github/workflows/test-suite.yml b/.github/workflows/test-suite.yml index f4b3b41..de88c91 100644 --- a/.github/workflows/test-suite.yml +++ b/.github/workflows/test-suite.yml @@ -33,18 +33,18 @@ jobs: needs: [lint] runs-on: "${{ matrix.os }}" strategy: + fail-fast: false # allow tests to run on all platforms matrix: python-version: - - "pypy-3.7" - "pypy-3.8" - "pypy-3.9" - "pypy-3.10" - - "3.7" - "3.8" - "3.9" - "3.10" - "3.11" - "3.12" + - "3.13-dev" os: - ubuntu-latest - windows-latest diff --git a/CHANGELOG.md b/CHANGELOG.md index 33a0ca9..9cc7dd6 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -4,6 +4,33 @@ All notable changes to this project will be documented in this file. The format is based on [Keep a Changelog](https://keepachangelog.com/en/1.0.0/), and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0.html). +## [3.1.0.rc1](https://github.com/nhairs/python-json-logger/compare/v3.0.1...v3.1.0.rc1) - 2023-05-03 + +This splits common funcitonality out to allow supporting other JSON encoders. Although this is a large refactor, backwards compatibility has been maintained. + +### Added +- `.core` - more details below. +- Orjson encoder support via `.orjson.OrjsonFormatter`. +- MsgSpec encoder support via `.msgspec.MsgspecFormatter`. + +### Changed +- `.jsonlogger` has been moved to `.json` with core functionality moved to `.core`. +- `.core.BaseJsonFormatter` properly supports all `logging.Formatter` arguments: + - `fmt` is unchanged. + - `datefmt` is unchanged. + - `style` can now support non-standard arguments by setting `validate` to `False` + - `validate` allows non-standard `style` arguments or prevents calling `validate` on standard `style` arguments. + - `default` is ignored. + +### Deprecated +- `.jsonlogger` is now `.json` +- `.jsonlogger.RESERVED_ATTRS` is now `.core.RESERVED_ATTRS`. +- `.jsonlogger.merge_record_extra` is now `.core.merge_record_extra`. + +### Removed +- Python 3.7 support dropped +- `.jsonlogger.JsonFormatter._str_to_fn` replaced with `.core.str_to_object`. + ## [3.0.1](https://github.com/nhairs/python-json-logger/compare/v3.0.0...v3.0.1) - 2023-04-01 ### Fixes diff --git a/README.md b/README.md index c7369b9..75bca3f 100644 --- a/README.md +++ b/README.md @@ -26,7 +26,7 @@ Until the PEP 541 request is complete you will need to install directly from git To install from releases: ```shell -# 3.0.0 wheel +# e.g. 3.0.0 wheel pip install 'python-json-logger@https://github.com/nhairs/python-json-logger/releases/download/v3.0.0/python_json_logger-3.0.0-py3-none-any.whl' ``` @@ -53,38 +53,30 @@ pip install -e . ## Usage +Python JSON Logger provides `logging.Formatter`s that encode the logged message into JSON. Although a variety of JSON encoders are supported, in the following examples we will use the `pythonjsonlogger.json.JsonFormatter` which uses the the `json` module from the standard library. + ### Integrating with Python's logging framework -Json outputs are provided by the JsonFormatter logging formatter. You can add the custom formatter like below: +To produce JSON output, attach the formatter to a logging handler: ```python import logging - from pythonjsonlogger import jsonlogger + from pythonjsonlogger.json import JsonFormatter logger = logging.getLogger() logHandler = logging.StreamHandler() - formatter = jsonlogger.JsonFormatter() + formatter = JsonFormatter() logHandler.setFormatter(formatter) logger.addHandler(logHandler) ``` -### Customizing fields - -The fmt parser can also be overidden if you want to have required fields that differ from the default of just `message`. +### Output fields -These two invocations are equivalent: +You can control the logged fields by setting the `fmt` argument when creating the formatter. By default formatters will follow the same `style` of `fmt` as the `logging` module: `%`, `$`, and `{`. All [`LogRecord` attributes](https://docs.python.org/3/library/logging.html#logrecord-attributes) can be output using their name. ```python -class CustomJsonFormatter(jsonlogger.JsonFormatter): - def parse(self): - return self._fmt.split(';') - -formatter = CustomJsonFormatter('one;two') - -# is equivalent to: - -formatter = jsonlogger.JsonFormatter('%(one)s %(two)s') +formatter = JsonFormatter("{message}{asctime}{exc_info}", style="{") ``` You can also add extra fields to your json output by specifying a dict in place of message, as well as by specifying an `extra={}` argument. @@ -94,9 +86,9 @@ Contents of these dictionaries will be added at the root level of the entry and You can also use the `add_fields` method to add to or generally normalize the set of default set of fields, it is called for every log event. For example, to unify default fields with those provided by [structlog](http://www.structlog.org/) you could do something like this: ```python -class CustomJsonFormatter(jsonlogger.JsonFormatter): +class CustomJsonFormatter(JsonFormatter): def add_fields(self, log_record, record, message_dict): - super(CustomJsonFormatter, self).add_fields(log_record, record, message_dict) + super().add_fields(log_record, record, message_dict) if not log_record.get('timestamp'): # this doesn't use record.created, so it is slightly off now = datetime.utcnow().strftime('%Y-%m-%dT%H:%M:%S.%fZ') @@ -105,32 +97,55 @@ class CustomJsonFormatter(jsonlogger.JsonFormatter): log_record['level'] = log_record['level'].upper() else: log_record['level'] = record.levelname + return formatter = CustomJsonFormatter('%(timestamp)s %(level)s %(name)s %(message)s') ``` Items added to the log record will be included in *every* log message, no matter what the format requires. -### Adding custom object serialization +You can also override the `process_log_record` method to modify fields before they are serialized to JSON. + +```python +class SillyFormatter(JsonFormatter): + def process_log_record(log_record): + new_record = {k[::-1]: v for k, v in log_record.items()} + return new_record +``` + +#### Supporting custom styles + +It is possible to support custom `style`s by setting `validate=False` and overriding the `parse` method. + +For example: + +```python +class CommaSupport(JsonFormatter): + def parse(self) -> list[str]: + if isinstance(self._style, str) and self._style == ",": + return self._fmt.split(",") + return super().parse() + +formatter = CommaSupport("message,asctime", style=",", validate=False) +``` + +### Custom object serialization + +Most formatters support `json_default` which is used to control how objects are serialized. For custom handling of object serialization you can specify default json object translator or provide a custom encoder ```python -def json_translate(obj): +def my_default(obj): if isinstance(obj, MyClass): return {"special": obj.special} -formatter = jsonlogger.JsonFormatter(json_default=json_translate, - json_encoder=json.JSONEncoder) -logHandler.setFormatter(formatter) - -logger.info({"special": "value", "run": 12}) -logger.info("classic message", extra={"special": "value", "run": 12}) +formatter = JsonFormatter(json_default=my_default) ``` ### Using a Config File -To use the module with a config file using the [`fileConfig` function](https://docs.python.org/3/library/logging.config.html#logging.config.fileConfig), use the class `pythonjsonlogger.jsonlogger.JsonFormatter`. Here is a sample config file. +To use the module with a config file using the [`fileConfig` function](https://docs.python.org/3/library/logging.config.html#logging.config.fileConfig), use the class `pythonjsonlogger.json.JsonFormatter`. Here is a sample config file. ```ini [loggers] @@ -161,6 +176,13 @@ format = %(message)s class = pythonjsonlogger.jsonlogger.JsonFormatter ``` +### Alternate JSON Encoders + +The following JSON encoders are also supported: + +- [orjson](https://github.com/ijl/orjson) - `pythonjsonlogger.orjon.OrjsonFormatter` +- [msgspec](https://github.com/jcrist/msgspec) - `pythonjsonlogger.msgspec.MsgspecFormatter` + ## Example Output Sample JSON with a full formatter (basically the log message from the unit test). Every log message will appear on 1 line like a typical logger. @@ -180,7 +202,7 @@ Sample JSON with a full formatter (basically the log message from the unit test) "msecs": 506.24799728393555, "pathname": "tests/tests.py", "lineno": 60, - "asctime": ["12-05-05 22:11:08,506248"], + "asctime": "12-05-05 22:11:08,506248", "message": "testing logging format", "filename": "tests.py", "levelname": "INFO", diff --git a/pylintrc b/pylintrc index c2f821e..79541d9 100644 --- a/pylintrc +++ b/pylintrc @@ -3,7 +3,7 @@ # A comma-separated list of package or module names from where C extensions may # be loaded. Extensions are loading into the active Python interpreter and may # run arbitrary code. -extension-pkg-whitelist= +extension-pkg-whitelist=orjson # Add files or directories to the blacklist. They should be base names, not # paths. diff --git a/pyproject.toml b/pyproject.toml index 63266ee..b9e004f 100644 --- a/pyproject.toml +++ b/pyproject.toml @@ -4,18 +4,21 @@ build-backend = "setuptools.build_meta" [project] name = "python-json-logger" -version = "3.0.1" +version = "3.1.0.rc1" description = "JSON Log Formatter for the Python Logging Package" authors = [ {name = "Zakaria Zajac", email = "zak@madzak.com"}, + {name = "Nicholas Hairs", email = "info+python-json-logger@nicholashairs.com"}, ] maintainers = [ {name = "Nicholas Hairs", email = "info+python-json-logger@nicholashairs.com"}, ] # Dependency Information -requires-python = ">=3.7" -# dependencies = [] +requires-python = ">=3.8" +dependencies = [ + "typing_extensions", +] # Extra information readme = "README.md" @@ -26,7 +29,6 @@ classifiers = [ "License :: OSI Approved :: BSD License", "Operating System :: OS Independent", "Programming Language :: Python :: 3 :: Only", - "Programming Language :: Python :: 3.7", "Programming Language :: Python :: 3.8", "Programming Language :: Python :: 3.9", "Programming Language :: Python :: 3.10", @@ -41,15 +43,18 @@ classifiers = [ GitHub = "https://github.com/nhairs/python-json-logger" [project.optional-dependencies] -lint = [ +dev = [ + ## Optional but required for dev + "orjson;implementation_name!='pypy' and python_version<'3.13'", + "msgspec;implementation_name!='pypy' and python_version<'3.13'", + ## Lint "validate-pyproject[all]", "black", "pylint", "mypy", -] - -test = [ + ## Test "pytest", + "freezegun", ] [tool.setuptools.packages.find] diff --git a/src/pythonjsonlogger/__init__.py b/src/pythonjsonlogger/__init__.py index e69de29..ed3ae60 100644 --- a/src/pythonjsonlogger/__init__.py +++ b/src/pythonjsonlogger/__init__.py @@ -0,0 +1,40 @@ +### IMPORTS +### ============================================================================ +## Future + +## Standard Library +import warnings + +## Installed + +## Application +import pythonjsonlogger.json + +### CONSTANTS +### ============================================================================ +try: + import orjson + + ORJSON_AVAILABLE = True +except ImportError: + ORJSON_AVAILABLE = False + + +try: + import msgspec + + MSGSPEC_AVAILABLE = True +except ImportError: + MSGSPEC_AVAILABLE = False + + +### DEPRECATED COMPATIBILITY +### ============================================================================ +def __getattr__(name: str): + if name == "jsonlogger": + warnings.warn( + "pythonjsonlogger.jsonlogger has been moved to pythonjsonlogger.json", + DeprecationWarning, + ) + return pythonjsonlogger.json + raise AttributeError(f"module {__name__} has no attribute {name}") diff --git a/src/pythonjsonlogger/core.py b/src/pythonjsonlogger/core.py new file mode 100644 index 0000000..b38c27f --- /dev/null +++ b/src/pythonjsonlogger/core.py @@ -0,0 +1,342 @@ +"""Core functionality shared by all JSON loggers""" + +### IMPORTS +### ============================================================================ +## Future +from __future__ import annotations + +## Standard Library +from datetime import datetime, timezone +import importlib +import logging +import re +import sys +from typing import Optional, Union, Callable, List, Dict, Container, Any, Sequence + +if sys.version_info >= (3, 10): + from typing import TypeAlias +else: + from typing_extensions import TypeAlias + +## Installed + +## Application + + +### CONSTANTS +### ============================================================================ +# skip natural LogRecord attributes +# http://docs.python.org/library/logging.html#logrecord-attributes +# Changed in 3.0.0, is now list[str] instead of tuple[str, ...] +RESERVED_ATTRS: List[str] = [ + "args", + "asctime", + "created", + "exc_info", + "exc_text", + "filename", + "funcName", + "levelname", + "levelno", + "lineno", + "module", + "msecs", + "message", + "msg", + "name", + "pathname", + "process", + "processName", + "relativeCreated", + "stack_info", + "thread", + "threadName", +] + +if sys.version_info >= (3, 12): + # taskName added in python 3.12 + RESERVED_ATTRS.append("taskName") + RESERVED_ATTRS.sort() + + +STYLE_STRING_TEMPLATE_REGEX = re.compile(r"\$\{(.+?)\}", re.IGNORECASE) +STYLE_STRING_FORMAT_REGEX = re.compile(r"\{(.+?)\}", re.IGNORECASE) +STYLE_PERCENT_REGEX = re.compile(r"%\((.+?)\)", re.IGNORECASE) + +## Type Aliases +## ----------------------------------------------------------------------------- +OptionalCallableOrStr: TypeAlias = Optional[Union[Callable, str]] +LogRecord: TypeAlias = Dict[str, Any] + + +### FUNCTIONS +### ============================================================================ +def str_to_object(obj: Any) -> Any: + """Import strings to an object, leaving non-strings as-is. + + Args: + obj: the object or string to process + + *New in 3.1* + """ + + if not isinstance(obj, str): + return obj + + module_name, attribute_name = obj.rsplit(".", 1) + return getattr(importlib.import_module(module_name), attribute_name) + + +def merge_record_extra( + record: logging.LogRecord, + target: Dict, + reserved: Container[str], + rename_fields: Optional[Dict[str, str]] = None, +) -> Dict: + """ + Merges extra attributes from LogRecord object into target dictionary + + Args: + record: logging.LogRecord + target: dict to update + reserved: dict or list with reserved keys to skip + rename_fields: an optional dict, used to rename field names in the output. + e.g. Rename `levelname` to `log.level`: `{'levelname': 'log.level'}` + + *Changed in 3.1*: `reserved` is now `Container[str]`. + """ + if rename_fields is None: + rename_fields = {} + for key, value in record.__dict__.items(): + # this allows to have numeric keys + if key not in reserved and not (hasattr(key, "startswith") and key.startswith("_")): + target[rename_fields.get(key, key)] = value + return target + + +### CLASSES +### ============================================================================ +class BaseJsonFormatter(logging.Formatter): + """Base class for pythonjsonlogger formatters + + Must not be used directly + + *New in 3.1* + """ + + _style: Union[logging.PercentStyle, str] # type: ignore[assignment] + + ## Parent Methods + ## ------------------------------------------------------------------------- + # pylint: disable=too-many-arguments,super-init-not-called + def __init__( + self, + fmt: Optional[str] = None, + datefmt: Optional[str] = None, + style: str = "%", + validate: bool = True, + *, + prefix: str = "", + rename_fields: Optional[Dict[str, str]] = None, + static_fields: Optional[Dict[str, Any]] = None, + reserved_attrs: Optional[Sequence[str]] = None, + timestamp: Union[bool, str] = False, + defaults: Optional[Dict[str, Any]] = None, + ) -> None: + """ + Args: + fmt: string representing fields to log + datefmt: format to use when formatting `asctime` field + style: how to extract log fields from `fmt` + validate: validate `fmt` against style, if implementing a custom `style` you + must set this to `False`. + defaults: ignored - kept for compatibility with python 3.10+ + prefix: an optional string prefix added at the beginning of + the formatted string + rename_fields: an optional dict, used to rename field names in the output. + Rename message to @message: {'message': '@message'} + static_fields: an optional dict, used to add fields with static values to all logs + reserved_attrs: an optional list of fields that will be skipped when + outputting json log record. Defaults to all log record attributes: + http://docs.python.org/library/logging.html#logrecord-attributes + timestamp: an optional string/boolean field to add a timestamp when + outputting the json log record. If string is passed, timestamp will be added + to log record using string as key. If True boolean is passed, timestamp key + will be "timestamp". Defaults to False/off. + + *Changed in 3.1*: you can now use custom values for style by setting validate to `False`. + The value is stored in `self._style` as a string. The `parse` method will need to be + overridden in order to support the new style. + """ + ## logging.Formatter compatibility + ## --------------------------------------------------------------------- + # Note: validate added in 3.8 + # Note: defaults added in 3.10 + if style in logging._STYLES: + _style = logging._STYLES[style][0](fmt) # type: ignore[operator] + if validate: + _style.validate() + self._style = _style + self._fmt = _style._fmt + + elif not validate: + self._style = style + self._fmt = fmt + + else: + raise ValueError(f"Style must be one of: {','.join(logging._STYLES.keys())}") + + self.datefmt = datefmt + + ## JSON Logging specific + ## --------------------------------------------------------------------- + self.prefix = prefix + self.rename_fields = rename_fields if rename_fields is not None else {} + self.static_fields = static_fields if static_fields is not None else {} + self.reserved_attrs = set(reserved_attrs if reserved_attrs is not None else RESERVED_ATTRS) + self.timestamp = timestamp + + self._required_fields = self.parse() + self._skip_fields = set(self._required_fields) + self._skip_fields.update(self.reserved_attrs) + return + + def format(self, record: logging.LogRecord) -> str: + """Formats a log record and serializes to json + + Args: + record: the record to format + """ + message_dict: Dict[str, Any] = {} + # TODO: logging.LogRecord.msg and logging.LogRecord.message in typeshed + # are always type of str. We shouldn't need to override that. + if isinstance(record.msg, dict): + message_dict = record.msg + record.message = "" + else: + record.message = record.getMessage() + # only format time if needed + if "asctime" in self._required_fields: + record.asctime = self.formatTime(record, self.datefmt) + + # Display formatted exception, but allow overriding it in the + # user-supplied dict. + if record.exc_info and not message_dict.get("exc_info"): + message_dict["exc_info"] = self.formatException(record.exc_info) + if not message_dict.get("exc_info") and record.exc_text: + message_dict["exc_info"] = record.exc_text + # Display formatted record of stack frames + # default format is a string returned from :func:`traceback.print_stack` + if record.stack_info and not message_dict.get("stack_info"): + message_dict["stack_info"] = self.formatStack(record.stack_info) + + log_record: LogRecord = {} + self.add_fields(log_record, record, message_dict) + log_record = self.process_log_record(log_record) + + return self.serialize_log_record(log_record) + + ## JSON Formatter Specific Methods + ## ------------------------------------------------------------------------- + def parse(self) -> List[str]: + """Parses format string looking for substitutions + + This method is responsible for returning a list of fields (as strings) + to include in all log messages. + + You can support custom styles by overriding this method. + + Returns: + list of fields to be extracted and serialized + """ + if isinstance(self._style, logging.StringTemplateStyle): + formatter_style_pattern = STYLE_STRING_TEMPLATE_REGEX + + elif isinstance(self._style, logging.StrFormatStyle): + formatter_style_pattern = STYLE_STRING_FORMAT_REGEX + + elif isinstance(self._style, logging.PercentStyle): + # PercentStyle is parent class of StringTemplateStyle and StrFormatStyle + # so it must be checked last. + formatter_style_pattern = STYLE_PERCENT_REGEX + + else: + raise ValueError(f"Style {self._style!r} is not supported") + + if self._fmt: + return formatter_style_pattern.findall(self._fmt) + + return [] + + def serialize_log_record(self, log_record: LogRecord) -> str: + """Returns the final representation of the log record. + + Args: + log_record: the log record + """ + return self.prefix + self.jsonify_log_record(log_record) + + def add_fields( + self, + log_record: Dict[str, Any], + record: logging.LogRecord, + message_dict: Dict[str, Any], + ) -> None: + """Extract fields from a LogRecord for logging + + This method can be overridden to implement custom logic for adding fields. + + Args: + log_record: data that will be logged + record: the record to extract data from + message_dict: ??? + """ + for field in self._required_fields: + log_record[field] = record.__dict__.get(field) + + log_record.update(self.static_fields) + log_record.update(message_dict) + merge_record_extra( + record, + log_record, + reserved=self._skip_fields, + rename_fields=self.rename_fields, + ) + + if self.timestamp: + # TODO: Can this use isinstance instead? + # pylint: disable=unidiomatic-typecheck + key = self.timestamp if type(self.timestamp) == str else "timestamp" + log_record[key] = datetime.fromtimestamp(record.created, tz=timezone.utc) + + self._perform_rename_log_fields(log_record) + return + + def _perform_rename_log_fields(self, log_record: Dict[str, Any]) -> None: + for old_field_name, new_field_name in self.rename_fields.items(): + log_record[new_field_name] = log_record[old_field_name] + del log_record[old_field_name] + return + + # Child Methods + # .......................................................................... + def jsonify_log_record(self, log_record: LogRecord) -> str: + """Convert this log record into a JSON string. + + Child classes MUST override this method. + + Args: + log_record: the data to serialize + """ + raise NotImplementedError() + + def process_log_record(self, log_record: LogRecord) -> LogRecord: + """Custom processing of the log record. + + Child classes can override this method to alter the log record before it + is serialized. + + Args: + log_record: incoming data + """ + return log_record diff --git a/src/pythonjsonlogger/json.py b/src/pythonjsonlogger/json.py new file mode 100644 index 0000000..9d14a1d --- /dev/null +++ b/src/pythonjsonlogger/json.py @@ -0,0 +1,116 @@ +"""JSON formatter using the standard library's `json` for encoding. + +Module contains the `JsonFormatter` and a custom `JsonEncoder` which supports a greater +variety of types. +""" + +### IMPORTS +### ============================================================================ +## Future +from __future__ import annotations + +## Standard Library +from datetime import date, datetime, time +from inspect import istraceback +import json +import traceback +from typing import Any, Callable, Optional, Union +import warnings + +## Application +from . import core + + +### CLASSES +### ============================================================================ +class JsonEncoder(json.JSONEncoder): + """A custom encoder extending the default JSONEncoder + + Refs: + - https://docs.python.org/3/library/json.html + """ + + def default(self, o: Any) -> Any: + if isinstance(o, (date, datetime, time)): + return self.format_datetime_obj(o) + + if istraceback(o): + return "".join(traceback.format_tb(o)).strip() + + # pylint: disable=unidiomatic-typecheck + if type(o) == Exception or isinstance(o, Exception) or type(o) == type: + return str(o) + + try: + return super().default(o) + + except TypeError: + try: + return str(o) + + except Exception: # pylint: disable=broad-exception-caught + return None + + def format_datetime_obj(self, o): + """Format datetime objects found in self.default + + This allows subclasses to change the datetime format without understanding the + internals of the default method. + """ + return o.isoformat() + + +class JsonFormatter(core.BaseJsonFormatter): + """JSON formatter using the standard library's `json` for encoding""" + + def __init__( + self, + *args, + json_default: core.OptionalCallableOrStr = None, + json_encoder: core.OptionalCallableOrStr = None, + json_serializer: Union[Callable, str] = json.dumps, + json_indent: Optional[Union[int, str]] = None, + json_ensure_ascii: bool = True, + **kwargs, + ) -> None: + """ + Args: + json_default: a function for encoding non-standard objects + as outlined in https://docs.python.org/3/library/json.html + json_encoder: optional custom encoder + json_serializer: a :meth:`json.dumps`-compatible callable + that will be used to serialize the log record. + json_indent: indent parameter for json.dumps + json_ensure_ascii: ensure_ascii parameter for json.dumps + """ + super().__init__(*args, **kwargs) + + self.json_default = core.str_to_object(json_default) + self.json_encoder = core.str_to_object(json_encoder) + self.json_serializer = core.str_to_object(json_serializer) + self.json_indent = json_indent + self.json_ensure_ascii = json_ensure_ascii + if not self.json_encoder and not self.json_default: + self.json_encoder = JsonEncoder + return + + def jsonify_log_record(self, log_record: core.LogRecord) -> str: + return self.json_serializer( + log_record, + default=self.json_default, + cls=self.json_encoder, + indent=self.json_indent, + ensure_ascii=self.json_ensure_ascii, + ) + + +### DEPRECATED COMPATIBILITY +### ============================================================================ +def __getattr__(name: str): + if name == "RESERVED_ATTRS": + warnings.warn( + "RESERVED_ATTRS has been moved to pythonjsonlogger.core", + DeprecationWarning, + ) + return core.RESERVED_ATTRS + raise AttributeError(f"module {__name__} has no attribute {name}") diff --git a/src/pythonjsonlogger/jsonlogger.py b/src/pythonjsonlogger/jsonlogger.py deleted file mode 100644 index 349564a..0000000 --- a/src/pythonjsonlogger/jsonlogger.py +++ /dev/null @@ -1,304 +0,0 @@ -""" -This library is provided to allow standard python logging -to output log data as JSON formatted strings -""" - -import logging -import json -import re -import traceback -import importlib -from datetime import date, datetime, time, timezone -import sys -from typing import Any, Callable, Dict, List, Optional, Tuple, Union - -from inspect import istraceback - -from collections import OrderedDict - -# skip natural LogRecord attributes -# http://docs.python.org/library/logging.html#logrecord-attributes -# Changed in 3.0.0, is now list[str] instead of tuple[str, ...] -RESERVED_ATTRS: List[str] = [ - "args", - "asctime", - "created", - "exc_info", - "exc_text", - "filename", - "funcName", - "levelname", - "levelno", - "lineno", - "module", - "msecs", - "message", - "msg", - "name", - "pathname", - "process", - "processName", - "relativeCreated", - "stack_info", - "thread", - "threadName", -] - -if sys.version_info >= (3, 12): - # taskName added in python 3.12 - RESERVED_ATTRS.append("taskName") - RESERVED_ATTRS.sort() - -OptionalCallableOrStr = Optional[Union[Callable, str]] - - -def merge_record_extra( - record: logging.LogRecord, - target: Dict, - reserved: Union[Dict, List], - rename_fields: Optional[Dict[str, str]] = None, -) -> Dict: - """ - Merges extra attributes from LogRecord object into target dictionary - - :param record: logging.LogRecord - :param target: dict to update - :param reserved: dict or list with reserved keys to skip - :param rename_fields: an optional dict, used to rename field names in the output. - Rename levelname to log.level: {'levelname': 'log.level'} - """ - if rename_fields is None: - rename_fields = {} - for key, value in record.__dict__.items(): - # this allows to have numeric keys - if key not in reserved and not (hasattr(key, "startswith") and key.startswith("_")): - target[rename_fields.get(key, key)] = value - return target - - -class JsonEncoder(json.JSONEncoder): - """ - A custom encoder extending the default JSONEncoder - """ - - def default(self, o: Any) -> Any: - if isinstance(o, (date, datetime, time)): - return self.format_datetime_obj(o) - - if istraceback(o): - return "".join(traceback.format_tb(o)).strip() - - # pylint: disable=unidiomatic-typecheck - if type(o) == Exception or isinstance(o, Exception) or type(o) == type: - return str(o) - - try: - return super().default(o) - - except TypeError: - try: - return str(o) - - except Exception: # pylint: disable=broad-exception-caught - return None - - def format_datetime_obj(self, o): - """Format datetime objects found in self.default - - This allows subclasses to change the datetime format without understanding the - internals of the default method. - """ - return o.isoformat() - - -class JsonFormatter(logging.Formatter): - """ - A custom formatter to format logging records as json strings. - Extra values will be formatted as str() if not supported by - json default encoder - """ - - # pylint: disable=too-many-arguments - def __init__( - self, - *args: Any, - json_default: OptionalCallableOrStr = None, - json_encoder: OptionalCallableOrStr = None, - json_serializer: Union[Callable, str] = json.dumps, - json_indent: Optional[Union[int, str]] = None, - json_ensure_ascii: bool = True, - prefix: str = "", - rename_fields: Optional[dict] = None, - static_fields: Optional[dict] = None, - reserved_attrs: Union[Tuple[str, ...], List[str], None] = None, - timestamp: Union[bool, str] = False, - **kwargs: Any, - ) -> None: - """ - :param json_default: a function for encoding non-standard objects - as outlined in https://docs.python.org/3/library/json.html - :param json_encoder: optional custom encoder - :param json_serializer: a :meth:`json.dumps`-compatible callable - that will be used to serialize the log record. - :param json_indent: indent parameter for json.dumps - :param json_ensure_ascii: ensure_ascii parameter for json.dumps - :param prefix: an optional string prefix added at the beginning of - the formatted string - :param rename_fields: an optional dict, used to rename field names in the output. - Rename message to @message: {'message': '@message'} - :param static_fields: an optional dict, used to add fields with static values to all logs - :param reserved_attrs: an optional list of fields that will be skipped when - outputting json log record. Defaults to all log record attributes: - http://docs.python.org/library/logging.html#logrecord-attributes - :param timestamp: an optional string/boolean field to add a timestamp when - outputting the json log record. If string is passed, timestamp will be added - to log record using string as key. If True boolean is passed, timestamp key - will be "timestamp". Defaults to False/off. - """ - self.json_default = self._str_to_fn(json_default) - self.json_encoder = self._str_to_fn(json_encoder) - self.json_serializer = self._str_to_fn(json_serializer) - self.json_indent = json_indent - self.json_ensure_ascii = json_ensure_ascii - self.prefix = prefix - self.rename_fields = rename_fields or {} - self.static_fields = static_fields or {} - if reserved_attrs is None: - reserved_attrs = RESERVED_ATTRS - self.reserved_attrs = dict(zip(reserved_attrs, reserved_attrs)) - self.timestamp = timestamp - - # super(JsonFormatter, self).__init__(*args, **kwargs) - logging.Formatter.__init__(self, *args, **kwargs) - if not self.json_encoder and not self.json_default: - self.json_encoder = JsonEncoder - - self._required_fields = self.parse() - self._skip_fields = dict(zip(self._required_fields, self._required_fields)) - self._skip_fields.update(self.reserved_attrs) - return - - def _str_to_fn(self, fn_as_str): - """ - If the argument is not a string, return whatever was passed in. - Parses a string such as package.module.function, imports the module - and returns the function. - - :param fn_as_str: The string to parse. If not a string, return it. - """ - if not isinstance(fn_as_str, str): - return fn_as_str - - path, _, function = fn_as_str.rpartition(".") - module = importlib.import_module(path) - return getattr(module, function) - - def parse(self) -> List[str]: - """ - Parses format string looking for substitutions - - This method is responsible for returning a list of fields (as strings) - to include in all log messages. - """ - if isinstance(self._style, logging.StringTemplateStyle): - formatter_style_pattern = re.compile(r"\$\{(.+?)\}", re.IGNORECASE) - elif isinstance(self._style, logging.StrFormatStyle): - formatter_style_pattern = re.compile(r"\{(.+?)\}", re.IGNORECASE) - # PercentStyle is parent class of StringTemplateStyle and StrFormatStyle so - # it needs to be checked last. - elif isinstance(self._style, logging.PercentStyle): - formatter_style_pattern = re.compile(r"%\((.+?)\)", re.IGNORECASE) - else: - raise ValueError(f"Invalid format: {self._fmt!r}") - - if self._fmt: - return formatter_style_pattern.findall(self._fmt) - return [] - - def add_fields( - self, - log_record: Dict[str, Any], - record: logging.LogRecord, - message_dict: Dict[str, Any], - ) -> None: - """ - Override this method to implement custom logic for adding fields. - """ - for field in self._required_fields: - log_record[field] = record.__dict__.get(field) - - log_record.update(self.static_fields) - log_record.update(message_dict) - merge_record_extra( - record, - log_record, - reserved=self._skip_fields, - rename_fields=self.rename_fields, - ) - - if self.timestamp: - # TODO: Can this use isinstance instead? - # pylint: disable=unidiomatic-typecheck - key = self.timestamp if type(self.timestamp) == str else "timestamp" - log_record[key] = datetime.fromtimestamp(record.created, tz=timezone.utc) - - self._perform_rename_log_fields(log_record) - return - - def _perform_rename_log_fields(self, log_record: Dict[str, Any]) -> None: - for old_field_name, new_field_name in self.rename_fields.items(): - log_record[new_field_name] = log_record[old_field_name] - del log_record[old_field_name] - return - - def process_log_record(self, log_record: Dict[str, Any]) -> Dict[str, Any]: - """ - Override this method to implement custom logic - on the possibly ordered dictionary. - """ - return log_record - - def jsonify_log_record(self, log_record: Dict[str, Any]) -> str: - """Returns a json string of the log record.""" - return self.json_serializer( - log_record, - default=self.json_default, - cls=self.json_encoder, - indent=self.json_indent, - ensure_ascii=self.json_ensure_ascii, - ) - - def serialize_log_record(self, log_record: Dict[str, Any]) -> str: - """Returns the final representation of the log record.""" - return self.prefix + self.jsonify_log_record(log_record) - - def format(self, record: logging.LogRecord) -> str: - """Formats a log record and serializes to json""" - message_dict: Dict[str, Any] = {} - # TODO: logging.LogRecord.msg and logging.LogRecord.message in typeshed - # are always type of str. We shouldn't need to override that. - if isinstance(record.msg, dict): - message_dict = record.msg - record.message = "" - else: - record.message = record.getMessage() - # only format time if needed - if "asctime" in self._required_fields: - record.asctime = self.formatTime(record, self.datefmt) - - # Display formatted exception, but allow overriding it in the - # user-supplied dict. - if record.exc_info and not message_dict.get("exc_info"): - message_dict["exc_info"] = self.formatException(record.exc_info) - if not message_dict.get("exc_info") and record.exc_text: - message_dict["exc_info"] = record.exc_text - # Display formatted record of stack frames - # default format is a string returned from :func:`traceback.print_stack` - if record.stack_info and not message_dict.get("stack_info"): - message_dict["stack_info"] = self.formatStack(record.stack_info) - - log_record: Dict[str, Any] = OrderedDict() - self.add_fields(log_record, record, message_dict) - log_record = self.process_log_record(log_record) - - return self.serialize_log_record(log_record) diff --git a/src/pythonjsonlogger/msgspec.py b/src/pythonjsonlogger/msgspec.py new file mode 100644 index 0000000..e711224 --- /dev/null +++ b/src/pythonjsonlogger/msgspec.py @@ -0,0 +1,43 @@ +### IMPORTS +### ============================================================================ +## Future +from __future__ import annotations + +## Standard Library + +## Installed +import msgspec.json + +## Application +from . import core + + +### CLASSES +### ============================================================================ +class MsgspecFormatter(core.BaseJsonFormatter): + """JSON formatter using msgspec.json for encoding. + + Refs: + - https://jcristharif.com/msgspec/api.html#msgspec.json.Encoder + """ + + # pylint: disable=too-many-arguments + def __init__( + self, + *args, + json_default: core.OptionalCallableOrStr = None, + **kwargs, + ) -> None: + """ + Args: + json_default: a function for encoding non-standard objects see: `msgspec.json.Encode:enc_hook` + """ + super().__init__(*args, **kwargs) + + self.json_default = core.str_to_object(json_default) + self._encoder = msgspec.json.Encoder(enc_hook=self.json_default) + return + + def jsonify_log_record(self, log_record: core.LogRecord) -> str: + """Returns a json string of the log record.""" + return self._encoder.encode(log_record).decode("utf8") diff --git a/src/pythonjsonlogger/orjson.py b/src/pythonjsonlogger/orjson.py new file mode 100644 index 0000000..4c5dbab --- /dev/null +++ b/src/pythonjsonlogger/orjson.py @@ -0,0 +1,51 @@ +### IMPORTS +### ============================================================================ +## Future +from __future__ import annotations + +## Standard Library + +## Installed +import orjson + +## Application +from . import core + + +### CLASSES +### ============================================================================ +class OrjsonFormatter(core.BaseJsonFormatter): + """JSON formatter using orjson for encoding. + + Refs: + - https://github.com/ijl/orjson + """ + + # pylint: disable=too-many-arguments + def __init__( + self, + *args, + json_default: core.OptionalCallableOrStr = None, + json_indent: bool = False, + **kwargs, + ) -> None: + """ + Args: + json_default: a function for encoding non-standard objects see: + https://github.com/ijl/orjson#default + json_indent: indent output with 2 spaces. see: + https://github.com/ijl/orjson#opt_indent_2 + """ + super().__init__(*args, **kwargs) + + self.json_default = core.str_to_object(json_default) + self.json_indent = json_indent + return + + def jsonify_log_record(self, log_record: core.LogRecord) -> str: + """Returns a json string of the log record.""" + opt = orjson.OPT_NON_STR_KEYS + if self.json_indent: + opt |= orjson.OPT_INDENT_2 + + return orjson.dumps(log_record, default=self.json_default, option=opt).decode("utf8") diff --git a/tests/test_deprecation.py b/tests/test_deprecation.py new file mode 100644 index 0000000..ad4c988 --- /dev/null +++ b/tests/test_deprecation.py @@ -0,0 +1,28 @@ +### IMPORTS +### ============================================================================ +## Future +from __future__ import annotations + +## Standard Library + +## Installed +import pytest + +## Application +import pythonjsonlogger + + +### TESTS +### ============================================================================ +def test_jsonlogger_deprecated(): + with pytest.deprecated_call(): + pythonjsonlogger.jsonlogger + return + + +def test_jsonlogger_reserved_attrs_deprecated(): + with pytest.deprecated_call(): + # Note: We use json instead of jsonlogger as jsonlogger will also produce + # a DeprecationWarning and we specifically want the one for RESERVED_ATTRS + pythonjsonlogger.json.RESERVED_ATTRS + return diff --git a/tests/test_formatters.py b/tests/test_formatters.py new file mode 100644 index 0000000..9bd908b --- /dev/null +++ b/tests/test_formatters.py @@ -0,0 +1,407 @@ +### IMPORTS +### ============================================================================ +## Future +from __future__ import annotations + +## Standard Library +from dataclasses import dataclass +import datetime +import io +import json +import logging +import sys +import traceback +from typing import Any, Generator + +## Installed +from freezegun import freeze_time +import pytest + +## Application +import pythonjsonlogger +from pythonjsonlogger.core import RESERVED_ATTRS, BaseJsonFormatter, merge_record_extra +from pythonjsonlogger.json import JsonFormatter + +if pythonjsonlogger.ORJSON_AVAILABLE: + from pythonjsonlogger.orjson import OrjsonFormatter + +if pythonjsonlogger.MSGSPEC_AVAILABLE: + from pythonjsonlogger.msgspec import MsgspecFormatter + +### SETUP +### ============================================================================ +ALL_FORMATTERS: list[type[BaseJsonFormatter]] = [JsonFormatter] +if pythonjsonlogger.ORJSON_AVAILABLE: + ALL_FORMATTERS.append(OrjsonFormatter) +if pythonjsonlogger.MSGSPEC_AVAILABLE: + ALL_FORMATTERS.append(MsgspecFormatter) + +_LOGGER_COUNT = 0 + + +@dataclass +class LoggingEnvironment: + logger: logging.Logger + buffer: io.StringIO + handler: logging.Handler + + def set_formatter(self, formatter: BaseJsonFormatter) -> None: + self.handler.setFormatter(formatter) + return + + def load_json(self) -> Any: + return json.loads(self.buffer.getvalue()) + + +@pytest.fixture +def env() -> Generator[LoggingEnvironment, None, None]: + global _LOGGER_COUNT # pylint: disable=global-statement + _LOGGER_COUNT += 1 + logger = logging.getLogger(f"pythonjsonlogger.tests.{_LOGGER_COUNT}") + logger.setLevel(logging.DEBUG) + buffer = io.StringIO() + handler = logging.StreamHandler(buffer) + logger.addHandler(handler) + yield LoggingEnvironment(logger=logger, buffer=buffer, handler=handler) + logger.removeHandler(handler) + logger.setLevel(logging.NOTSET) + buffer.close() + return + + +def get_traceback_from_exception_followed_by_log_call(env_: LoggingEnvironment) -> str: + try: + raise Exception("test") + except Exception: + env_.logger.exception("hello") + str_traceback = traceback.format_exc() + # Formatter removes trailing new line + if str_traceback.endswith("\n"): + str_traceback = str_traceback[:-1] + return str_traceback + + +### TESTS +### ============================================================================ +def test_merge_record_extra(): + record = logging.LogRecord( + "name", level=1, pathname="", lineno=1, msg="Some message", args=None, exc_info=None + ) + output = merge_record_extra(record, target={"foo": "bar"}, reserved=[]) + assert output["foo"] == "bar" + assert output["msg"] == "Some message" + return + + +## Common Formatter Tests +## ----------------------------------------------------------------------------- +@pytest.mark.parametrize("class_", ALL_FORMATTERS) +def test_default_format(env: LoggingEnvironment, class_: type[BaseJsonFormatter]): + env.set_formatter(class_()) + + msg = "testing logging format" + env.logger.info(msg) + + log_json = env.load_json() + + assert log_json["message"] == msg + return + + +@pytest.mark.parametrize("class_", ALL_FORMATTERS) +def test_percentage_format(env: LoggingEnvironment, class_: type[BaseJsonFormatter]): + env.set_formatter( + class_( + # All kind of different styles to check the regex + "[%(levelname)8s] %(message)s %(filename)s:%(lineno)d %(asctime)" + ) + ) + + msg = "testing logging format" + env.logger.info(msg) + log_json = env.load_json() + + assert log_json["message"] == msg + assert log_json.keys() == {"levelname", "message", "filename", "lineno", "asctime"} + return + + +@pytest.mark.parametrize("class_", ALL_FORMATTERS) +def test_rename_base_field(env: LoggingEnvironment, class_: type[BaseJsonFormatter]): + env.set_formatter(class_(rename_fields={"message": "@message"})) + + msg = "testing logging format" + env.logger.info(msg) + log_json = env.load_json() + + assert log_json["@message"] == msg + return + + +@pytest.mark.parametrize("class_", ALL_FORMATTERS) +def test_rename_nonexistent_field(env: LoggingEnvironment, class_: type[BaseJsonFormatter]): + env.set_formatter(class_(rename_fields={"nonexistent_key": "new_name"})) + + stderr_watcher = io.StringIO() + sys.stderr = stderr_watcher + env.logger.info("testing logging rename") + sys.stderr == sys.__stderr__ + + assert "KeyError: 'nonexistent_key'" in stderr_watcher.getvalue() + return + + +@pytest.mark.parametrize("class_", ALL_FORMATTERS) +def test_add_static_fields(env: LoggingEnvironment, class_: type[BaseJsonFormatter]): + env.set_formatter(class_(static_fields={"log_stream": "kafka"})) + + msg = "testing static fields" + env.logger.info(msg) + log_json = env.load_json() + + assert log_json["log_stream"] == "kafka" + assert log_json["message"] == msg + return + + +@pytest.mark.parametrize("class_", ALL_FORMATTERS) +def test_format_keys(env: LoggingEnvironment, class_: type[BaseJsonFormatter]): + supported_keys = [ + "asctime", + "created", + "filename", + "funcName", + "levelname", + "levelno", + "lineno", + "module", + "msecs", + "message", + "name", + "pathname", + "process", + "processName", + "relativeCreated", + "thread", + "threadName", + ] + + log_format = lambda x: [f"%({i:s})s" for i in x] + custom_format = " ".join(log_format(supported_keys)) + + env.set_formatter(class_(custom_format)) + + msg = "testing logging format" + env.logger.info(msg) + log_json = env.load_json() + + for key in supported_keys: + assert key in log_json + return + + +@pytest.mark.parametrize("class_", ALL_FORMATTERS) +def test_unknown_format_key(env: LoggingEnvironment, class_: type[BaseJsonFormatter]): + env.set_formatter(class_("%(unknown_key)s %(message)s")) + env.logger.info("testing unknown logging format") + # make sure no error occurs + return + + +@pytest.mark.parametrize("class_", ALL_FORMATTERS) +def test_log_dict(env: LoggingEnvironment, class_: type[BaseJsonFormatter]): + env.set_formatter(class_()) + + msg = {"text": "testing logging", "num": 1, 5: "9", "nested": {"more": "data"}} + env.logger.info(msg) + log_json = env.load_json() + + assert log_json["text"] == msg["text"] + assert log_json["num"] == msg["num"] + assert log_json["5"] == msg[5] + assert log_json["nested"] == msg["nested"] + assert log_json["message"] == "" + return + + +@pytest.mark.parametrize("class_", ALL_FORMATTERS) +def test_log_extra(env: LoggingEnvironment, class_: type[BaseJsonFormatter]): + env.set_formatter(class_()) + + extra = {"text": "testing logging", "num": 1, 5: "9", "nested": {"more": "data"}} + env.logger.info("hello", extra=extra) # type: ignore[arg-type] + log_json = env.load_json() + + assert log_json["text"] == extra["text"] + assert log_json["num"] == extra["num"] + assert log_json["5"] == extra[5] + assert log_json["nested"] == extra["nested"] + assert log_json["message"] == "hello" + return + + +@pytest.mark.parametrize("class_", ALL_FORMATTERS) +def test_custom_logic_adds_field(env: LoggingEnvironment, class_: type[BaseJsonFormatter]): + class CustomJsonFormatter(class_): # type: ignore[valid-type,misc] + + def process_log_record(self, log_record): + log_record["custom"] = "value" + return super().process_log_record(log_record) + + env.set_formatter(CustomJsonFormatter()) + env.logger.info("message") + log_json = env.load_json() + + assert log_json["custom"] == "value" + return + + +@pytest.mark.parametrize("class_", ALL_FORMATTERS) +def test_exc_info(env: LoggingEnvironment, class_: type[BaseJsonFormatter]): + env.set_formatter(class_()) + + expected_value = get_traceback_from_exception_followed_by_log_call(env) + log_json = env.load_json() + + assert log_json["exc_info"] == expected_value + return + + +@pytest.mark.parametrize("class_", ALL_FORMATTERS) +def test_exc_info_renamed(env: LoggingEnvironment, class_: type[BaseJsonFormatter]): + env.set_formatter(class_("%(exc_info)s", rename_fields={"exc_info": "stack_trace"})) + + expected_value = get_traceback_from_exception_followed_by_log_call(env) + log_json = env.load_json() + + assert log_json["stack_trace"] == expected_value + assert "exc_info" not in log_json + return + + +@pytest.mark.parametrize("class_", ALL_FORMATTERS) +def test_custom_object_serialization(env: LoggingEnvironment, class_: type[BaseJsonFormatter]): + def encode_complex(z): + if isinstance(z, complex): + return (z.real, z.imag) + raise TypeError(f"Object of type {type(z)} is no JSON serializable") + + env.set_formatter(class_(json_default=encode_complex)) # type: ignore[call-arg] + + env.logger.info("foo", extra={"special": complex(3, 8)}) + log_json = env.load_json() + + assert log_json["special"] == [3.0, 8.0] + return + + +@pytest.mark.parametrize("class_", ALL_FORMATTERS) +def test_rename_reserved_attrs(env: LoggingEnvironment, class_: type[BaseJsonFormatter]): + log_format = lambda x: [f"%({i:s})s" for i in x] + reserved_attrs_map = { + "exc_info": "error.type", + "exc_text": "error.message", + "funcName": "log.origin.function", + "levelname": "log.level", + "module": "log.origin.file.name", + "processName": "process.name", + "threadName": "process.thread.name", + "msg": "log.message", + } + + custom_format = " ".join(log_format(reserved_attrs_map.keys())) + reserved_attrs = [ + attr for attr in RESERVED_ATTRS if attr not in list(reserved_attrs_map.keys()) + ] + env.set_formatter( + class_(custom_format, reserved_attrs=reserved_attrs, rename_fields=reserved_attrs_map) + ) + + env.logger.info("message") + log_json = env.load_json() + + # Note: this check is fragile if we make the following changes in the future (we might): + # - renaming fields no longer requires the field to be present (#6) + # - we add the ability (and data above) to rename a field to an existing field name + # e.g. {"exc_info": "trace_original", "@custom_trace": "exc_info"} + for old_name, new_name in reserved_attrs_map.items(): + assert new_name in log_json + assert old_name not in log_json + return + + +@freeze_time(datetime.datetime(2017, 7, 14, 2, 40)) +@pytest.mark.parametrize("class_", ALL_FORMATTERS) +def test_default_encoder_with_timestamp(env: LoggingEnvironment, class_: type[BaseJsonFormatter]): + if pythonjsonlogger.ORJSON_AVAILABLE and class_ is OrjsonFormatter: + # https://github.com/ijl/orjson/issues/481 + pytest.xfail() + + if pythonjsonlogger.MSGSPEC_AVAILABLE and class_ is MsgspecFormatter: + # https://github.com/jcrist/msgspec/issues/678 + pytest.xfail() + + env.set_formatter(class_(timestamp=True)) + + env.logger.info("Hello") + print(env.buffer.getvalue()) + log_json = env.load_json() + + assert log_json["timestamp"] == "2017-07-14T02:40:00+00:00" + return + + +## JsonFormatter Specific +## ----------------------------------------------------------------------------- +def test_json_default_encoder(env: LoggingEnvironment): + env.set_formatter(JsonFormatter()) + + msg = { + "adate": datetime.datetime(1999, 12, 31, 23, 59), + "otherdate": datetime.date(1789, 7, 14), + "otherdatetime": datetime.datetime(1789, 7, 14, 23, 59), + "otherdatetimeagain": datetime.datetime(1900, 1, 1), + } + env.logger.info(msg) + log_json = env.load_json() + + assert log_json["adate"] == "1999-12-31T23:59:00" + assert log_json["otherdate"] == "1789-07-14" + assert log_json["otherdatetime"] == "1789-07-14T23:59:00" + assert log_json["otherdatetimeagain"] == "1900-01-01T00:00:00" + return + + +def test_json_custom_default(env: LoggingEnvironment): + def custom(o): + return "very custom" + + env.set_formatter(JsonFormatter(json_default=custom)) + + msg = {"adate": datetime.datetime(1999, 12, 31, 23, 59), "normal": "value"} + env.logger.info(msg) + log_json = env.load_json() + + assert log_json["adate"] == "very custom" + assert log_json["normal"] == "value" + return + + +def test_json_ensure_ascii_true(env: LoggingEnvironment): + env.set_formatter(JsonFormatter()) + env.logger.info("Привет") + + # Note: we don't use env.load_json as we want to know the raw output + msg = env.buffer.getvalue().split('"message": "', 1)[1].split('"', 1)[0] + assert msg == r"\u041f\u0440\u0438\u0432\u0435\u0442" + return + + +def test_json_ensure_ascii_false(env: LoggingEnvironment): + env.set_formatter(JsonFormatter(json_ensure_ascii=False)) + env.logger.info("Привет") + + # Note: we don't use env.load_json as we want to know the raw output + msg = env.buffer.getvalue().split('"message": "', 1)[1].split('"', 1)[0] + assert msg == "Привет" + return diff --git a/tests/test_jsonlogger.py b/tests/test_jsonlogger.py deleted file mode 100644 index abd04ba..0000000 --- a/tests/test_jsonlogger.py +++ /dev/null @@ -1,309 +0,0 @@ -import datetime -import logging -from io import StringIO -import json -import random -import sys -import traceback -import unittest -import unittest.mock - -sys.path.append("src/python-json-logger") -from pythonjsonlogger import jsonlogger - - -class TestJsonLogger(unittest.TestCase): - def setUp(self): - self.log = logging.getLogger(f"logging-test-{random.randint(1, 101)}") - self.log.setLevel(logging.DEBUG) - self.buffer = StringIO() - - self.log_handler = logging.StreamHandler(self.buffer) - self.log.addHandler(self.log_handler) - - def test_default_format(self): - fr = jsonlogger.JsonFormatter() - self.log_handler.setFormatter(fr) - - msg = "testing logging format" - self.log.info(msg) - log_json = json.loads(self.buffer.getvalue()) - - self.assertEqual(log_json["message"], msg) - - def test_percentage_format(self): - fr = jsonlogger.JsonFormatter( - # All kind of different styles to check the regex - "[%(levelname)8s] %(message)s %(filename)s:%(lineno)d %(asctime)" - ) - self.log_handler.setFormatter(fr) - - msg = "testing logging format" - self.log.info(msg) - log_json = json.loads(self.buffer.getvalue()) - - self.assertEqual(log_json["message"], msg) - self.assertEqual(log_json.keys(), {"levelname", "message", "filename", "lineno", "asctime"}) - - def test_rename_base_field(self): - fr = jsonlogger.JsonFormatter(rename_fields={"message": "@message"}) - self.log_handler.setFormatter(fr) - - msg = "testing logging format" - self.log.info(msg) - log_json = json.loads(self.buffer.getvalue()) - - self.assertEqual(log_json["@message"], msg) - - def test_rename_nonexistent_field(self): - fr = jsonlogger.JsonFormatter(rename_fields={"nonexistent_key": "new_name"}) - self.log_handler.setFormatter(fr) - - stderr_watcher = StringIO() - sys.stderr = stderr_watcher - self.log.info("testing logging rename") - - self.assertTrue("KeyError: 'nonexistent_key'" in stderr_watcher.getvalue()) - - def test_add_static_fields(self): - fr = jsonlogger.JsonFormatter(static_fields={"log_stream": "kafka"}) - - self.log_handler.setFormatter(fr) - - msg = "testing static fields" - self.log.info(msg) - log_json = json.loads(self.buffer.getvalue()) - - self.assertEqual(log_json["log_stream"], "kafka") - self.assertEqual(log_json["message"], msg) - - def test_format_keys(self): - supported_keys = [ - "asctime", - "created", - "filename", - "funcName", - "levelname", - "levelno", - "lineno", - "module", - "msecs", - "message", - "name", - "pathname", - "process", - "processName", - "relativeCreated", - "thread", - "threadName", - ] - - log_format = lambda x: [f"%({i:s})s" for i in x] - custom_format = " ".join(log_format(supported_keys)) - - fr = jsonlogger.JsonFormatter(custom_format) - self.log_handler.setFormatter(fr) - - msg = "testing logging format" - self.log.info(msg) - log_msg = self.buffer.getvalue() - log_json = json.loads(log_msg) - - for supported_key in supported_keys: - if supported_key in log_json: - self.assertTrue(True) - - def test_unknown_format_key(self): - fr = jsonlogger.JsonFormatter("%(unknown_key)s %(message)s") - - self.log_handler.setFormatter(fr) - msg = "testing unknown logging format" - try: - self.log.info(msg) - except Exception: - self.assertTrue(False, "Should succeed") - - def test_log_adict(self): - fr = jsonlogger.JsonFormatter() - self.log_handler.setFormatter(fr) - - msg = {"text": "testing logging", "num": 1, 5: "9", "nested": {"more": "data"}} - - self.log.info(msg) - log_json = json.loads(self.buffer.getvalue()) - self.assertEqual(log_json.get("text"), msg["text"]) - self.assertEqual(log_json.get("num"), msg["num"]) - self.assertEqual(log_json.get("5"), msg[5]) - self.assertEqual(log_json.get("nested"), msg["nested"]) - self.assertEqual(log_json["message"], "") - - def test_log_extra(self): - fr = jsonlogger.JsonFormatter() - self.log_handler.setFormatter(fr) - - extra = {"text": "testing logging", "num": 1, 5: "9", "nested": {"more": "data"}} - self.log.info("hello", extra=extra) - log_json = json.loads(self.buffer.getvalue()) - self.assertEqual(log_json.get("text"), extra["text"]) - self.assertEqual(log_json.get("num"), extra["num"]) - self.assertEqual(log_json.get("5"), extra[5]) - self.assertEqual(log_json.get("nested"), extra["nested"]) - self.assertEqual(log_json["message"], "hello") - - def test_json_default_encoder(self): - fr = jsonlogger.JsonFormatter() - self.log_handler.setFormatter(fr) - - msg = { - "adate": datetime.datetime(1999, 12, 31, 23, 59), - "otherdate": datetime.date(1789, 7, 14), - "otherdatetime": datetime.datetime(1789, 7, 14, 23, 59), - "otherdatetimeagain": datetime.datetime(1900, 1, 1), - } - self.log.info(msg) - log_json = json.loads(self.buffer.getvalue()) - self.assertEqual(log_json.get("adate"), "1999-12-31T23:59:00") - self.assertEqual(log_json.get("otherdate"), "1789-07-14") - self.assertEqual(log_json.get("otherdatetime"), "1789-07-14T23:59:00") - self.assertEqual(log_json.get("otherdatetimeagain"), "1900-01-01T00:00:00") - - @unittest.mock.patch("time.time", return_value=1500000000.0) - def test_json_default_encoder_with_timestamp(self, time_mock): - fr = jsonlogger.JsonFormatter(timestamp=True) - self.log_handler.setFormatter(fr) - - self.log.info("Hello") - - self.assertTrue(time_mock.called) - log_json = json.loads(self.buffer.getvalue()) - self.assertEqual(log_json.get("timestamp"), "2017-07-14T02:40:00+00:00") - - def test_json_custom_default(self): - def custom(o): - return "very custom" - - fr = jsonlogger.JsonFormatter(json_default=custom) - self.log_handler.setFormatter(fr) - - msg = {"adate": datetime.datetime(1999, 12, 31, 23, 59), "normal": "value"} - self.log.info(msg) - log_json = json.loads(self.buffer.getvalue()) - self.assertEqual(log_json.get("adate"), "very custom") - self.assertEqual(log_json.get("normal"), "value") - - def test_json_custom_logic_adds_field(self): - class CustomJsonFormatter(jsonlogger.JsonFormatter): - - def process_log_record(self, log_record): - log_record["custom"] = "value" - # Old Style "super" since Python 2.6's logging.Formatter is old - # style - return jsonlogger.JsonFormatter.process_log_record(self, log_record) - - self.log_handler.setFormatter(CustomJsonFormatter()) - self.log.info("message") - log_json = json.loads(self.buffer.getvalue()) - self.assertEqual(log_json.get("custom"), "value") - - def get_traceback_from_exception_followed_by_log_call(self) -> str: - try: - raise Exception("test") - except Exception: - self.log.exception("hello") - str_traceback = traceback.format_exc() - # Formatter removes trailing new line - if str_traceback.endswith("\n"): - str_traceback = str_traceback[:-1] - - return str_traceback - - def test_exc_info(self): - fr = jsonlogger.JsonFormatter() - self.log_handler.setFormatter(fr) - expected_value = self.get_traceback_from_exception_followed_by_log_call() - - log_json = json.loads(self.buffer.getvalue()) - self.assertEqual(log_json.get("exc_info"), expected_value) - - def test_exc_info_renamed(self): - fr = jsonlogger.JsonFormatter("%(exc_info)s", rename_fields={"exc_info": "stack_trace"}) - self.log_handler.setFormatter(fr) - expected_value = self.get_traceback_from_exception_followed_by_log_call() - - log_json = json.loads(self.buffer.getvalue()) - self.assertEqual(log_json.get("stack_trace"), expected_value) - self.assertEqual(log_json.get("exc_info"), None) - - def test_ensure_ascii_true(self): - fr = jsonlogger.JsonFormatter() - self.log_handler.setFormatter(fr) - self.log.info("Привет") - msg = self.buffer.getvalue().split('"message": "', 1)[1].split('"', 1)[0] - self.assertEqual(msg, r"\u041f\u0440\u0438\u0432\u0435\u0442") - - def test_ensure_ascii_false(self): - fr = jsonlogger.JsonFormatter(json_ensure_ascii=False) - self.log_handler.setFormatter(fr) - self.log.info("Привет") - msg = self.buffer.getvalue().split('"message": "', 1)[1].split('"', 1)[0] - self.assertEqual(msg, "Привет") - - def test_custom_object_serialization(self): - def encode_complex(z): - if isinstance(z, complex): - return (z.real, z.imag) - else: - type_name = z.__class__.__name__ - raise TypeError(f"Object of type '{type_name}' is no JSON serializable") - - formatter = jsonlogger.JsonFormatter( - json_default=encode_complex, json_encoder=json.JSONEncoder - ) - self.log_handler.setFormatter(formatter) - - value = { - "special": complex(3, 8), - } - - self.log.info(" message", extra=value) - msg = self.buffer.getvalue() - self.assertEqual(msg, '{"message": " message", "special": [3.0, 8.0]}\n') - - def test_rename_reserved_attrs(self): - log_format = lambda x: [f"%({i:s})s" for i in x] - reserved_attrs_map = { - "exc_info": "error.type", - "exc_text": "error.message", - "funcName": "log.origin.function", - "levelname": "log.level", - "module": "log.origin.file.name", - "processName": "process.name", - "threadName": "process.thread.name", - "msg": "log.message", - } - - custom_format = " ".join(log_format(reserved_attrs_map.keys())) - reserved_attrs = [ - _ for _ in jsonlogger.RESERVED_ATTRS if _ not in list(reserved_attrs_map.keys()) - ] - formatter = jsonlogger.JsonFormatter( - custom_format, reserved_attrs=reserved_attrs, rename_fields=reserved_attrs_map - ) - self.log_handler.setFormatter(formatter) - self.log.info("message") - - msg = self.buffer.getvalue() - self.assertEqual( - msg, - '{"error.type": null, "error.message": null, "log.origin.function": "test_rename_reserved_attrs", "log.level": "INFO", "log.origin.file.name": "test_jsonlogger", "process.name": "MainProcess", "process.thread.name": "MainThread", "log.message": "message"}\n', - ) - - def test_merge_record_extra(self): - record = logging.LogRecord( - "name", level=1, pathname="", lineno=1, msg="Some message", args=None, exc_info=None - ) - output = jsonlogger.merge_record_extra(record, target=dict(foo="bar"), reserved=[]) - self.assertIn("foo", output) - self.assertIn("msg", output) - self.assertEqual(output["foo"], "bar") - self.assertEqual(output["msg"], "Some message") diff --git a/tox.ini b/tox.ini index 946be58..31ce42b 100644 --- a/tox.ini +++ b/tox.ini @@ -1,35 +1,34 @@ [tox] requires = tox>=3 -envlist = lint, type, pypy{37,38,39,310}, py{37,38,39,310,311,312} +envlist = lint, type, pypy{38,39,310}, py{38,39,310,311,312,313} [gh-actions] python = - pypy-3.7: pypy37 pypy-3.8: pypy38 pypy-3.9: pypy39 pypy-3.10: pypy310 - 3.7: py37 3.8: py38 3.9: py39 3.10: py310 3.11: py311 3.12: py312 + 3.13: py313 [testenv] description = run unit tests -extras = test +extras = dev commands = pytest tests [testenv:format] description = run formatters -extras = lint +extras = dev commands = black src tests [testenv:lint] description = run linters -extras = lint +extras = dev commands = validate-pyproject pyproject.toml black --check --diff src tests