Skip to content

Commit

Permalink
feat: logger (#47)
Browse files Browse the repository at this point in the history 
Reworked the way this library does  logging/warning. It utilizes the logger named `serializable` for everything, now.

---------

Signed-off-by: Jan Kowalleck <jan.kowalleck@gmail.com>
Co-authored-by: Kyle Roeschley <kyle.roeschley@ni.com>
  • Loading branch information
@jkowalleck @kroeschl
jkowalleck and kroeschl authored Jan 6, 2024
1 parent 14493ec commit 9269b0e
Show file tree
Hide file tree
Showing 5 changed files with 147 additions and 54 deletions.
40 changes: 40 additions & 0 deletions docs/examples.rst
View file
Original file line number Diff line number Diff line change
Expand Up @@ -21,3 +21,43 @@ Models used in Unit Tests
.. literalinclude:: ../tests/model.py
:language: python
:linenos:

Logging and log access
----------------------

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 stdErr
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.logger.setLevel(my_log_handler.level)
serializable.logger.propagate = False
@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())
91 changes: 49 additions & 42 deletions serializable/__init__.py
View file
Original file line number Diff line number Diff line change
Expand Up @@ -20,10 +20,7 @@
import enum
import inspect
import json
import logging
import os
import re
import warnings
from copy import copy
from decimal import Decimal
from io import StringIO, TextIOBase
Expand All @@ -48,17 +45,20 @@

from defusedxml import ElementTree as SafeElementTree # type: ignore

from ._logging import _logger, _warning_kwargs
from .formatters import BaseNameFormatter, CurrentFormatter
from .helpers import BaseHelper

if TYPE_CHECKING:
if TYPE_CHECKING: # pragma: no cover
import sys

if sys.version_info >= (3, 8):
from typing import Literal, Protocol # type:ignore[attr-defined]
else:
from typing_extensions import Literal, Protocol # type:ignore[assignment]
else:
from abc import ABC

Protocol = ABC

# `Intersection` is still not implemented, so it is interim replaced by Union for any support
Expand All @@ -73,8 +73,12 @@
# do not use typing here, or else `semantic_release` might have issues finding the variable
__version__ = '0.16.0'

logger = logging.getLogger('serializable')
logger.setLevel(logging.INFO)
# make logger publicly available, as stable API
logger = _logger
"""
The logger. The thing that captures all this module has to say.
Feel free to modify its level and attach handlers to it.
"""


class ViewType:
Expand Down Expand Up @@ -259,7 +263,7 @@ def as_json(self: Any, view_: Optional[Type[ViewType]] = None) -> str:
Internal method 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('Dumping %s to JSON with view: %s...', self, view_)
return json.dumps(self, cls=_SerializableJsonEncoder, view_=view_)

@classmethod
Expand All @@ -268,13 +272,15 @@ def from_json(cls: Type[_T], data: Dict[str, Any]) -> Optional[_T]:
Internal method that is injected into Classes that are annotated for serialization and deserialization by
``serializable``.
"""
logging.debug(f'Rendering JSON to {cls}...')
_logger.debug('Rendering JSON to %s...', 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(
'%s is not a known serializable class', klass_qualified_name,
**_warning_kwargs) # type:ignore[arg-type]
return None

if len(klass_properties) == 1:
Expand All @@ -287,7 +293,7 @@ def from_json(cls: Type[_T], data: Dict[str, Any]) -> Optional[_T]:
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('Ignoring %s when deserializing %s.%s', k, cls.__module__, cls.__qualname__)
del _data[k]
continue

Expand All @@ -300,9 +306,8 @@ def from_json(cls: Type[_T], data: Dict[str, Any]) -> Optional[_T]:
new_key = decoded_k

if new_key is None:
logger.error(
f'Unexpected key {k}/{decoded_k} in data being serialized to {cls.__module__}.{cls.__qualname__}'
)
_logger.error('Unexpected key %s/%s in data being serialized to %s.%s',
k, decoded_k, cls.__module__, cls.__qualname__)
raise ValueError(
f'Unexpected key {k}/{decoded_k} in data being serialized to {cls.__module__}.{cls.__qualname__}'
)
Expand Down Expand Up @@ -341,15 +346,16 @@ def from_json(cls: Type[_T], data: Dict[str, Any]) -> Optional[_T]:
v = str(v)
_data[k] = prop_info.concrete_type(v)
except AttributeError as e:
logging.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}')
_logger.error('There was an AttributeError deserializing JSON to %s.\n'
'The Property is: %s\n'
'The Value was: %s\n'
'Exception: %s\n',
cls, prop_info, v, e)
raise AttributeError(
f'There was an AttributeError deserializing JSON to {cls} the Property {prop_info}: {e}'
)
) from e

logging.debug(f'Creating {cls} from {_data}')
_logger.debug('Creating $s from %s', cls, _data)

return cls(**_data)

Expand All @@ -363,7 +369,7 @@ def as_xml(self: Any, view_: Optional[Type[ViewType]] = None,
Internal method that is injected into Classes that are annotated for serialization and deserialization by
``serializable``.
"""
logging.debug(f'Dumping {self} to XML with view {view_}...')
_logger.debug('Dumping %s to XML with view %s...', self, view_)

this_e_attributes = {}
klass_qualified_name = f'{self.__class__.__module__}.{self.__class__.__qualname__}'
Expand Down Expand Up @@ -500,10 +506,11 @@ def from_xml(cls: Type[_T], data: Union[TextIOBase, Element],
Internal method that is injected into Classes that are annotated for serialization and deserialization by
``serializable``.
"""
logging.debug(f'Rendering XML from {type(data)} to {cls}...')
_logger.debug('Rendering XML from %s to %s...', type(data), 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('%s.%s is not a known serializable class', cls.__module__, cls.__qualname__,
**_warning_kwargs) # type:ignore[arg-type]
return None

klass_properties = ObjectMetadataLibrary.klass_property_mappings.get(f'{cls.__module__}.{cls.__qualname__}', {})
Expand All @@ -530,7 +537,7 @@ def strip_default_namespace(s: str) -> str:
for k, v in data.attrib.items():
decoded_k = CurrentFormatter.formatter.decode(strip_default_namespace(k))
if decoded_k in klass.ignore_during_deserialization:
logger.debug(f'Ignoring {decoded_k} when deserializing {cls.__module__}.{cls.__qualname__}')
_logger.debug('Ignoring %s when deserializing %s.%s', decoded_k, cls.__module__, cls.__qualname__)
continue

if decoded_k not in klass_properties:
Expand Down Expand Up @@ -562,7 +569,7 @@ def strip_default_namespace(s: str) -> str:
for child_e in data:
decoded_k = CurrentFormatter.formatter.decode(strip_default_namespace(child_e.tag))
if decoded_k in klass.ignore_during_deserialization:
logger.debug(f'Ignoring {decoded_k} when deserializing {cls.__module__}.{cls.__qualname__}')
_logger.debug('Ignoring %s when deserializing %s.%s', decoded_k, cls.__module__, cls.__qualname__)
continue

if decoded_k not in klass_properties:
Expand All @@ -585,8 +592,7 @@ def strip_default_namespace(s: str) -> str:
raise ValueError(f'{decoded_k} is not a known Property for {cls.__module__}.{cls.__qualname__}')

try:

logger.debug(f'Handling {prop_info}')
_logger.debug('Handling %s', prop_info)

if prop_info.is_array and prop_info.xml_array_config:
array_type, nested_name = prop_info.xml_array_config
Expand Down Expand Up @@ -637,15 +643,16 @@ def strip_default_namespace(s: str) -> str:
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}'
f'The Property is: {prop_info}{os.linesep}'
f'The Value was: {v}{os.linesep}'
f'Exception: {e}{os.linesep}')
_logger.error('There was an AttributeError deserializing JSON to %s.\n'
'The Property is: %s\n'
'The Value was: %s\n'
'Exception: %s\n',
cls, prop_info, v, e)
raise AttributeError(
f'There was an AttributeError deserializing XML to {cls} the Property {prop_info}: {e}'
)
) from e

logging.debug(f'Creating {cls} from {_data}')
_logger.debug('Creating %s from %s', cls, _data)

if len(_data) == 0:
return None
Expand Down Expand Up @@ -1031,7 +1038,7 @@ def register_klass(cls, klass: Type[_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('Registering Class %s with custom name %s', qualified_class_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)
Expand Down Expand Up @@ -1224,7 +1231,7 @@ def type_mapping(type_: type) -> Callable[[_F], _F]:
"""Decorator"""

def decorate(f: _F) -> _F:
logger.debug(f'Registering {f.__module__}.{f.__qualname__} with custom type: {type_}')
_logger.debug('Registering %s.%s with custom type: %s', f.__module__, f.__qualname__, type_)
ObjectMetadataLibrary.register_property_type_mapping(
qual_name=f'{f.__module__}.{f.__qualname__}', mapped_type=type_
)
Expand All @@ -1237,7 +1244,7 @@ def include_none(view_: Optional[Type[ViewType]] = None, none_value: Optional[An
"""Decorator"""

def decorate(f: _F) -> _F:
logger.debug(f'Registering {f.__module__}.{f.__qualname__} to include None for view: {view_}')
_logger.debug('Registering %s.%s to include None for view: %s', f.__module__, f.__qualname__, view_)
ObjectMetadataLibrary.register_property_include_none(
qual_name=f'{f.__module__}.{f.__qualname__}', view_=view_, none_value=none_value
)
Expand All @@ -1250,7 +1257,7 @@ def json_name(name: str) -> Callable[[_F], _F]:
"""Decorator"""

def decorate(f: _F) -> _F:
logger.debug(f'Registering {f.__module__}.{f.__qualname__} with JSON name: {name}')
_logger.debug('Registering %s.%s with JSON name: %s', f.__module__, f.__qualname__, name)
ObjectMetadataLibrary.register_custom_json_property_name(
qual_name=f'{f.__module__}.{f.__qualname__}', json_property_name=name
)
Expand All @@ -1263,7 +1270,7 @@ def string_format(format_: str) -> Callable[[_F], _F]:
"""Decorator"""

def decorate(f: _F) -> _F:
logger.debug(f'Registering {f.__module__}.{f.__qualname__} with String Format: {format_}')
_logger.debug('Registering %s.%s with String Format: %s', f.__module__, f.__qualname__, format_)
ObjectMetadataLibrary.register_custom_string_format(
qual_name=f'{f.__module__}.{f.__qualname__}', string_format=format_
)
Expand All @@ -1276,7 +1283,7 @@ def view(view_: Type[ViewType]) -> Callable[[_F], _F]:
"""Decorator"""

def decorate(f: _F) -> _F:
logger.debug(f'Registering {f.__module__}.{f.__qualname__} with View: {view_}')
_logger.debug('Registering %s.%s with View: %s', f.__module__, f.__qualname__, view_)
ObjectMetadataLibrary.register_property_view(
qual_name=f'{f.__module__}.{f.__qualname__}', view_=view_
)
Expand All @@ -1289,7 +1296,7 @@ def xml_attribute() -> Callable[[_F], _F]:
"""Decorator"""

def decorate(f: _F) -> _F:
logger.debug(f'Registering {f.__module__}.{f.__qualname__} as XML attribute')
_logger.debug('Registering %s.%s as XML attribute', f.__module__, f.__qualname__)
ObjectMetadataLibrary.register_xml_property_attribute(qual_name=f'{f.__module__}.{f.__qualname__}')
return f

Expand All @@ -1300,7 +1307,7 @@ def xml_array(array_type: XmlArraySerializationType, child_name: str) -> Callabl
"""Decorator"""

def decorate(f: _F) -> _F:
logger.debug(f'Registering {f.__module__}.{f.__qualname__} as XML Array: {array_type}:{child_name}')
_logger.debug('Registering %s.%s as XML Array: %s:%s', f.__module__, f.__qualname__, 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
)
Expand All @@ -1313,7 +1320,7 @@ def xml_name(name: str) -> Callable[[_F], _F]:
"""Decorator"""

def decorate(f: _F) -> _F:
logger.debug(f'Registering {f.__module__}.{f.__qualname__} with XML name: {name}')
_logger.debug('Registering %s.%s with XML name: %s', f.__module__, f.__qualname__, name)
ObjectMetadataLibrary.register_custom_xml_property_name(
qual_name=f'{f.__module__}.{f.__qualname__}', xml_property_name=name
)
Expand All @@ -1326,7 +1333,7 @@ def xml_sequence(sequence: int) -> Callable[[_F], _F]:
"""Decorator"""

def decorate(f: _F) -> _F:
logger.debug(f'Registering {f.__module__}.{f.__qualname__} with XML sequence: {sequence}')
_logger.debug('Registering %s.%s with XML sequence: %s', f.__module__, f.__qualname__, sequence)
ObjectMetadataLibrary.register_xml_property_sequence(
qual_name=f'{f.__module__}.{f.__qualname__}', sequence=sequence
)
Expand Down
34 changes: 34 additions & 0 deletions serializable/_logging.py
View file
Original file line number Diff line number Diff line change
@@ -0,0 +1,34 @@
# 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.


from logging import NullHandler, getLogger
from sys import version_info

# Attention: logger's name is pseudo-public API!
# Use the package's dist-name here.
_logger = getLogger('serializable')

# This handler does nothing. It's intended to be used to avoid the
# "No handlers could be found for logger XXX" one-off warning. This is
# important for library code, which may contain code to log events.
_logger.addHandler(NullHandler())

# `logger.warning()` got additional kwarg since py38
_warning_kwargs = {'stacklevel': 2} if version_info >= (3, 8) else {}
17 changes: 8 additions & 9 deletions serializable/helpers.py
View file
Original file line number Diff line number Diff line change
Expand Up @@ -18,10 +18,11 @@
# Copyright (c) Paul Horton. All Rights Reserved.

import re
import warnings
from datetime import date, datetime
from typing import TYPE_CHECKING, Any, Optional, Type, TypeVar, Union

from ._logging import _logger, _warning_kwargs

if TYPE_CHECKING: # pragma: no cover
from xml.etree.ElementTree import Element

Expand Down Expand Up @@ -159,16 +160,14 @@ def deserialize(cls, o: Any) -> 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')
Expand Down
Loading

0 comments on commit 9269b0e

Please sign in to comment.