diff --git a/docs/index.rst b/docs/index.rst index 42488df..28626f4 100644 --- a/docs/index.rst +++ b/docs/index.rst @@ -35,6 +35,7 @@ See also: getting-started customising-structure formatters + logging support changelog diff --git a/docs/logging.rst b/docs/logging.rst new file mode 100644 index 0000000..9e8e457 --- /dev/null +++ b/docs/logging.rst @@ -0,0 +1,39 @@ +Logging +==================================================== + +This library utilizes an own instance of `Logger`_, which you may access and add handlers to. + +.. _logger: https://docs.python.org/3/library/logging.html#logger-objects + + +.. code-block:: python + :caption: Example: send all logs messages to the console + + import sys + import logging + import serializable + + my_log_handler = logging.StreamHandler(sys.stderr) + my_log_handler.setLevel(logging.DEBUG) + my_log_handler.setFormatter(logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s')) + serializable.LOGGER.addHandler(my_log_handler) + + + @serializable.serializable_class + class Chapter: + + def __init__(self, *, number: int, title: str) -> None: + self._number = number + self._title = title + + @property + def number(self) -> int: + return self._number + + @property + def title(self) -> str: + return self._title + + + moby_dick_c1 = Chapter(number=1, title='Loomings') + print(moby_dick_c1.as_json()) diff --git a/serializable/__init__.py b/serializable/__init__.py index f64c74d..a310cf9 100644 --- a/serializable/__init__.py +++ b/serializable/__init__.py @@ -16,15 +16,14 @@ # # SPDX-License-Identifier: Apache-2.0 # Copyright (c) Paul Horton. All Rights Reserved. + import enum import functools import inspect import json -import logging import os import re import typing # noqa: F401 -import warnings from copy import copy from decimal import Decimal from io import StringIO, TextIOWrapper @@ -40,6 +39,7 @@ else: from typing_extensions import Protocol # type: ignore +from ._logging import _LOGGER, _warning_kwargs from .formatters import BaseNameFormatter, CurrentFormatter from .helpers import BaseHelper @@ -47,8 +47,8 @@ # do not use typing here, or else `semantic_release` might have issues finding the variable __version__ = '0.12.0' -logger = logging.getLogger('serializable') -logger.setLevel(logging.INFO) +# make logger publicly available, as stable API +LOGGER = _LOGGER _F = TypeVar("_F", bound=Callable[..., Any]) _T = TypeVar('_T', bound='_Klass') @@ -227,7 +227,7 @@ def _as_json(self: _T, view_: Optional[Type[Any]] = None) -> str: Internal function that is injected into Classes that are annotated for serialization and deserialization by ``serializable``. """ - logging.debug(f'Dumping {self} to JSON with view: {view_}...') + _LOGGER.debug(f'Dumping {self} to JSON with view: {view_}...') return json.dumps(self, cls=_SerializableJsonEncoder, view_=view_) @@ -236,13 +236,15 @@ def _from_json(cls: Type[_T], data: Dict[str, Any]) -> object: Internal function that is injected into Classes that are annotated for serialization and deserialization by ``serializable``. """ - logging.debug(f'Rendering JSON to {cls}...') + _LOGGER.debug(f'Rendering JSON to {cls}...') klass_qualified_name = f'{cls.__module__}.{cls.__qualname__}' klass = ObjectMetadataLibrary.klass_mappings.get(klass_qualified_name, None) klass_properties = ObjectMetadataLibrary.klass_property_mappings.get(klass_qualified_name, {}) if klass is None: - warnings.warn(f'{klass_qualified_name} is not a known serializable class', stacklevel=2) + _LOGGER.warning( + f'{klass_qualified_name} is not a known serializable class', + ) return None if len(klass_properties) == 1: @@ -255,7 +257,7 @@ def _from_json(cls: Type[_T], data: Dict[str, Any]) -> object: for k, v in data.items(): decoded_k = CurrentFormatter.formatter.decode(property_name=k) if decoded_k in klass.ignore_during_deserialization: - logger.debug(f'Ignoring {k} when deserializing {cls.__module__}.{cls.__qualname__}') + _LOGGER.debug(f'Ignoring {k} when deserializing {cls.__module__}.{cls.__qualname__}') del _data[k] continue @@ -268,7 +270,7 @@ def _from_json(cls: Type[_T], data: Dict[str, Any]) -> object: new_key = decoded_k if new_key is None: - logger.error( + _LOGGER.error( f'Unexpected key {k}/{decoded_k} in data being serialized to {cls.__module__}.{cls.__qualname__}' ) raise ValueError( @@ -306,7 +308,7 @@ def _from_json(cls: Type[_T], data: Dict[str, Any]) -> object: else: _data[k] = prop_info.concrete_type(v) except AttributeError as e: - logging.error(f'There was an AttributeError deserializing JSON to {cls}.{os.linesep}' + _LOGGER.error(f'There was an AttributeError deserializing JSON to {cls}.{os.linesep}' f'The Property is: {prop_info}{os.linesep}' f'The Value was: {v}{os.linesep}' f'Exception: {e}{os.linesep}') @@ -314,14 +316,14 @@ def _from_json(cls: Type[_T], data: Dict[str, Any]) -> object: f'There was an AttributeError deserializing JSON to {cls} the Property {prop_info}: {e}' ) - logging.debug(f'Creating {cls} from {_data}') + _LOGGER.debug(f'Creating {cls} from {_data}') return cls(**_data) def _as_xml(self: _T, view_: Optional[Type[_T]] = None, as_string: bool = True, element_name: Optional[str] = None, xmlns: Optional[str] = None) -> Union[Element, str]: - logging.debug(f'Dumping {self} to XML with view {view_}...') + _LOGGER.debug(f'Dumping {self} to XML with view {view_}...') this_e_attributes = {} klass_qualified_name = f'{self.__module__}.{self.__class__.__qualname__}' @@ -445,10 +447,12 @@ def _as_xml(self: _T, view_: Optional[Type[_T]] = None, as_string: bool = True, def _from_xml(cls: Type[_T], data: Union[TextIOWrapper, Element], default_namespace: Optional[str] = None) -> object: - logging.debug(f'Rendering XML from {type(data)} to {cls}...') + _LOGGER.debug(f'Rendering XML from {type(data)} to {cls}...') klass = ObjectMetadataLibrary.klass_mappings.get(f'{cls.__module__}.{cls.__qualname__}', None) if klass is None: - warnings.warn(f'{cls.__module__}.{cls.__qualname__} is not a known serializable class', stacklevel=2) + _LOGGER.warning( + f'{cls.__module__}.{cls.__qualname__} is not a known serializable class', + **_warning_kwargs) # type:ignore[arg-type] return None klass_properties = ObjectMetadataLibrary.klass_property_mappings.get(f'{cls.__module__}.{cls.__qualname__}', {}) @@ -471,7 +475,7 @@ def _from_xml(cls: Type[_T], data: Union[TextIOWrapper, Element], for k, v in data.attrib.items(): decoded_k = CurrentFormatter.formatter.decode(property_name=k) if decoded_k in klass.ignore_during_deserialization: - logger.debug(f'Ignoring {decoded_k} when deserializing {cls.__module__}.{cls.__qualname__}') + _LOGGER.debug(f'Ignoring {decoded_k} when deserializing {cls.__module__}.{cls.__qualname__}') continue if decoded_k not in klass_properties: @@ -505,7 +509,7 @@ def _from_xml(cls: Type[_T], data: Union[TextIOWrapper, Element], decoded_k = CurrentFormatter.formatter.decode(property_name=child_e_tag_name) if decoded_k in klass.ignore_during_deserialization: - logger.debug(f'Ignoring {decoded_k} when deserializing {cls.__module__}.{cls.__qualname__}') + _LOGGER.debug(f'Ignoring {decoded_k} when deserializing {cls.__module__}.{cls.__qualname__}') continue if decoded_k not in klass_properties: @@ -529,7 +533,7 @@ def _from_xml(cls: Type[_T], data: Union[TextIOWrapper, Element], try: - logger.debug(f'Handling {prop_info}') + _LOGGER.debug(f'Handling {prop_info}') if prop_info.is_array and prop_info.xml_array_config: array_type, nested_name = prop_info.xml_array_config @@ -578,7 +582,7 @@ def _from_xml(cls: Type[_T], data: Union[TextIOWrapper, Element], else: _data[decoded_k] = prop_info.concrete_type(child_e.text) except AttributeError as e: - logging.error(f'There was an AttributeError deserializing JSON to {cls}.{os.linesep}' + _LOGGER.error(f'There was an AttributeError deserializing JSON to {cls}.{os.linesep}' f'The Property is: {prop_info}{os.linesep}' f'The Value was: {v}{os.linesep}' f'Exception: {e}{os.linesep}') @@ -586,7 +590,7 @@ def _from_xml(cls: Type[_T], data: Union[TextIOWrapper, Element], f'There was an AttributeError deserializing XML to {cls} the Property {prop_info}: {e}' ) - logging.debug(f'Creating {cls} from {_data}') + _LOGGER.debug(f'Creating {cls} from {_data}') if len(_data) == 0: return None @@ -970,7 +974,7 @@ def register_klass(cls, klass: _T, custom_name: Optional[str], qualified_class_name = f'{klass.__module__}.{klass.__qualname__}' cls.klass_property_mappings.update({qualified_class_name: {}}) - logging.debug(f'Registering Class {qualified_class_name} with custom name {custom_name}') + _LOGGER.debug(f'Registering Class {qualified_class_name} with custom name {custom_name}') for name, o in inspect.getmembers(klass, ObjectMetadataLibrary.is_property): qualified_property_name = f'{qualified_class_name}.{name}' prop_arg_specs = inspect.getfullargspec(o.fget) @@ -1127,7 +1131,7 @@ def type_mapping(type_: _T) -> Callable[[_F], _F]: """ def outer(f: _F) -> _F: - logger.debug(f'Registering {f.__module__}.{f.__qualname__} with custom type: {type_}') + _LOGGER.debug(f'Registering {f.__module__}.{f.__qualname__} with custom type: {type_}') ObjectMetadataLibrary.register_property_type_mapping( qual_name=f'{f.__module__}.{f.__qualname__}', mapped_type=type_ ) @@ -1143,7 +1147,7 @@ def inner(*args: Any, **kwargs: Any) -> Any: def include_none(view_: Optional[Type[_T]] = None, none_value: Optional[Any] = None) -> Callable[[_F], _F]: def outer(f: _F) -> _F: - logger.debug(f'Registering {f.__module__}.{f.__qualname__} to include None for view: {view_}') + _LOGGER.debug(f'Registering {f.__module__}.{f.__qualname__} to include None for view: {view_}') ObjectMetadataLibrary.register_property_include_none( qual_name=f'{f.__module__}.{f.__qualname__}', view_=view_, none_value=none_value ) @@ -1159,7 +1163,7 @@ def inner(*args: Any, **kwargs: Any) -> Any: def json_name(name: str) -> Callable[[_F], _F]: def outer(f: _F) -> _F: - logger.debug(f'Registering {f.__module__}.{f.__qualname__} with JSON name: {name}') + _LOGGER.debug(f'Registering {f.__module__}.{f.__qualname__} with JSON name: {name}') ObjectMetadataLibrary.register_custom_json_property_name( qual_name=f'{f.__module__}.{f.__qualname__}', json_property_name=name ) @@ -1175,7 +1179,7 @@ def inner(*args: Any, **kwargs: Any) -> Any: def string_format(format_: str) -> Callable[[_F], _F]: def outer(f: _F) -> _F: - logger.debug(f'Registering {f.__module__}.{f.__qualname__} with String Format: {format_}') + _LOGGER.debug(f'Registering {f.__module__}.{f.__qualname__} with String Format: {format_}') ObjectMetadataLibrary.register_custom_string_format( qual_name=f'{f.__module__}.{f.__qualname__}', string_format=format_ ) @@ -1191,7 +1195,7 @@ def inner(*args: Any, **kwargs: Any) -> Any: def view(view_: ViewType) -> Callable[[_F], _F]: def outer(f: _F) -> _F: - logger.debug(f'Registering {f.__module__}.{f.__qualname__} with View: {view_}') + _LOGGER.debug(f'Registering {f.__module__}.{f.__qualname__} with View: {view_}') ObjectMetadataLibrary.register_property_view( qual_name=f'{f.__module__}.{f.__qualname__}', view_=view_ ) @@ -1207,7 +1211,7 @@ def inner(*args: Any, **kwargs: Any) -> Any: def xml_attribute() -> Callable[[_F], _F]: def outer(f: _F) -> _F: - logger.debug(f'Registering {f.__module__}.{f.__qualname__} as XML attribute') + _LOGGER.debug(f'Registering {f.__module__}.{f.__qualname__} as XML attribute') ObjectMetadataLibrary.register_xml_property_attribute(qual_name=f'{f.__module__}.{f.__qualname__}') @functools.wraps(f) @@ -1221,7 +1225,7 @@ def inner(*args: Any, **kwargs: Any) -> Any: def xml_array(array_type: XmlArraySerializationType, child_name: str) -> Callable[[_F], _F]: def outer(f: _F) -> _F: - logger.debug(f'Registering {f.__module__}.{f.__qualname__} as XML Array: {array_type}:{child_name}') + _LOGGER.debug(f'Registering {f.__module__}.{f.__qualname__} as XML Array: {array_type}:{child_name}') ObjectMetadataLibrary.register_xml_property_array_config( qual_name=f'{f.__module__}.{f.__qualname__}', array_type=array_type, child_name=child_name ) @@ -1237,7 +1241,7 @@ def inner(*args: Any, **kwargs: Any) -> Any: def xml_name(name: str) -> Callable[[_F], _F]: def outer(f: _F) -> _F: - logger.debug(f'Registering {f.__module__}.{f.__qualname__} with XML name: {name}') + _LOGGER.debug(f'Registering {f.__module__}.{f.__qualname__} with XML name: {name}') ObjectMetadataLibrary.register_custom_xml_property_name( qual_name=f'{f.__module__}.{f.__qualname__}', xml_property_name=name ) @@ -1253,7 +1257,7 @@ def inner(*args: Any, **kwargs: Any) -> Any: def xml_sequence(sequence: int) -> Callable[[_F], _F]: def outer(f: _F) -> _F: - logger.debug(f'Registering {f.__module__}.{f.__qualname__} with XML sequence: {sequence}') + _LOGGER.debug(f'Registering {f.__module__}.{f.__qualname__} with XML sequence: {sequence}') ObjectMetadataLibrary.register_xml_property_sequence( qual_name=f'{f.__module__}.{f.__qualname__}', sequence=sequence ) diff --git a/serializable/_logging.py b/serializable/_logging.py new file mode 100644 index 0000000..a0751ff --- /dev/null +++ b/serializable/_logging.py @@ -0,0 +1,27 @@ +# encoding: utf-8 + +# This file is part of py-serializable +# +# Licensed under the Apache License, Version 2.0 (the "License"); +# you may not use this file except in compliance with the License. +# You may obtain a copy of the License at +# +# http://www.apache.org/licenses/LICENSE-2.0 +# +# Unless required by applicable law or agreed to in writing, software +# distributed under the License is distributed on an "AS IS" BASIS, +# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +# See the License for the specific language governing permissions and +# limitations under the License. +# +# SPDX-License-Identifier: Apache-2.0 +# Copyright (c) Paul Horton. All Rights Reserved. + +import logging +from sys import version_info + +_LOGGER = logging.getLogger(f'{__name__}.LOGGER') +_LOGGER.setLevel(logging.DEBUG) + +# logger.warning() got additional kwarg since py38 +_warning_kwargs = {'stacklevel': 2} if version_info >= (3, 8) else {} diff --git a/serializable/helpers.py b/serializable/helpers.py index c678f62..d03ee8b 100644 --- a/serializable/helpers.py +++ b/serializable/helpers.py @@ -17,11 +17,12 @@ # SPDX-License-Identifier: Apache-2.0 # Copyright (c) Paul Horton. All Rights Reserved. import re -import warnings from abc import ABC, abstractmethod from datetime import date, datetime from typing import Any +from ._logging import _LOGGER, _warning_kwargs + class BaseHelper(ABC): @@ -75,16 +76,14 @@ def deserialize(cls, o: object) -> date: if str(o).endswith('Z'): o = str(o)[:-1] - warnings.warn( - 'Potential data loss will occur: dates with timezones not supported in Python', UserWarning, - stacklevel=2 - ) + _LOGGER.warning( + 'Potential data loss will occur: dates with timezones not supported in Python', + **_warning_kwargs) # type:ignore[arg-type] if '+' in str(o): o = str(o)[:str(o).index('+')] - warnings.warn( - 'Potential data loss will occur: dates with timezones not supported in Python', UserWarning, - stacklevel=2 - ) + _LOGGER.warning( + 'Potential data loss will occur: dates with timezones not supported in Python', + **_warning_kwargs) # type:ignore[arg-type] return date.fromisoformat(str(o)) except ValueError: raise ValueError(f'Date string supplied ({o}) is not a supported ISO Format') diff --git a/tests/test_helpers.py b/tests/test_helpers.py index 8fb650d..baf12f0 100644 --- a/tests/test_helpers.py +++ b/tests/test_helpers.py @@ -20,6 +20,7 @@ from datetime import date, datetime, timedelta, timezone from unittest import TestCase +from serializable import LOGGER from serializable.helpers import Iso8601Date, XsdDate, XsdDateTime @@ -60,25 +61,37 @@ def test_deserialize_valid_1(self) -> None: ) def test_deserialize_valid_2(self) -> None: - with self.assertWarns(UserWarning): + with self.assertLogs(LOGGER) as logs: self.assertEqual( XsdDate.deserialize(o="2001-10-26+02:00"), date(year=2001, month=10, day=26) ) + self.assertIn( + 'WARNING:serializable._logging.LOGGER:' + 'Potential data loss will occur: dates with timezones not supported in Python', + logs.output) def test_deserialize_valid_3(self) -> None: - with self.assertWarns(UserWarning): + with self.assertLogs(LOGGER) as logs: self.assertEqual( XsdDate.deserialize(o="2001-10-26Z"), date(year=2001, month=10, day=26) ) + self.assertIn( + 'WARNING:serializable._logging.LOGGER:' + 'Potential data loss will occur: dates with timezones not supported in Python', + logs.output) def test_deserialize_valid_4(self) -> None: - with self.assertWarns(UserWarning): + with self.assertLogs(LOGGER) as logs: self.assertEqual( XsdDate.deserialize(o="2001-10-26+00:00"), date(year=2001, month=10, day=26) ) + self.assertIn( + 'WARNING:serializable._logging.LOGGER:' + 'Potential data loss will occur: dates with timezones not supported in Python', + logs.output) def test_deserialize_valid_5(self) -> None: self.assertEqual(