1
0
mirror of https://github.com/EDCD/EDMarketConnector.git synced 2025-04-18 09:57:40 +03:00

Merge pull request #1045 from A-UNDERSCORE-D/fix/1044-qualname-may-not-exist

Fix classvar logging errors
This commit is contained in:
Athanasius 2021-05-10 15:02:47 +01:00 committed by GitHub
commit f9f2c2a09c
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
2 changed files with 119 additions and 52 deletions

View File

@ -41,9 +41,11 @@ import logging.handlers
import os import os
import pathlib import pathlib
import tempfile import tempfile
from contextlib import suppress
# So that any warning about accessing a protected member is only in one place. # So that any warning about accessing a protected member is only in one place.
from sys import _getframe as getframe from sys import _getframe as getframe
from threading import get_native_id as thread_native_id from threading import get_native_id as thread_native_id
from traceback import print_exc
from typing import TYPE_CHECKING, Tuple, cast from typing import TYPE_CHECKING, Tuple, cast
from config import appcmdname, appname, config from config import appcmdname, appname, config
@ -85,7 +87,10 @@ logging.Logger.trace = lambda self, message, *args, **kwargs: self._log( # type
) )
if TYPE_CHECKING: if TYPE_CHECKING:
from types import FrameType
# Fake type that we can use here to tell type checkers that trace exists # Fake type that we can use here to tell type checkers that trace exists
class LoggerMixin(logging.Logger): class LoggerMixin(logging.Logger):
"""LoggerMixin is a fake class that tells type checkers that trace exists on a given type.""" """LoggerMixin is a fake class that tells type checkers that trace exists on a given type."""
@ -318,65 +323,83 @@ class EDMCContextFilter(logging.Filter):
# We've given up, so just return '??' to signal we couldn't get the info # We've given up, so just return '??' to signal we couldn't get the info
return '??', '??', module_name return '??', '??', module_name
try:
args, _, _, value_dict = inspect.getargvalues(frame)
if len(args) and args[0] in ('self', 'cls'):
frame_class: 'object' = value_dict[args[0]]
args, _, _, value_dict = inspect.getargvalues(frame) if frame_class:
if len(args) and args[0] in ('self', 'cls'): # See https://en.wikipedia.org/wiki/Name_mangling#Python for how name mangling works.
frame_class: 'object' = value_dict[args[0]] # For more detail, see _Py_Mangle in CPython's Python/compile.c.
name = frame_info.function
class_name = frame_class.__class__.__name__.lstrip("_")
if name.startswith("__") and not name.endswith("__") and class_name:
name = f'_{class_name}{frame_info.function}'
if frame_class: # Find __qualname__ of the caller
# See https://en.wikipedia.org/wiki/Name_mangling#Python for how name mangling works. fn = inspect.getattr_static(frame_class, name, None)
# For more detail, see _Py_Mangle in CPython's Python/compile.c. if fn is None:
name = frame_info.function # For some reason getattr_static cant grab this. Try and grab it with getattr, bail out
class_name = frame_class.__class__.__name__.lstrip("_") # if we get a RecursionError indicating a property
if name.startswith("__") and not name.endswith("__") and class_name: try:
name = f'_{class_name}{frame_info.function}' fn = getattr(frame_class, name, None)
except RecursionError:
print(
"EDMCLogging:EDMCContextFilter:caller_attributes():"
"Failed to get attribute for function info. Bailing out"
)
# class_name is better than nothing for __qualname__
return class_name, class_name, module_name
# Find __qualname__ of the caller if fn is not None:
fn = inspect.getattr_static(frame_class, name, None) if isinstance(fn, property):
if fn is None: class_name = str(frame_class)
# For some reason getattr_static cant grab this. Try and grab it with getattr, bail out # If somehow you make your __class__ or __class__.__qualname__ recursive,
# if we get a RecursionError indicating a property # I'll be impressed.
try: if hasattr(frame_class, '__class__') and hasattr(frame_class.__class__, "__qualname__"):
fn = getattr(frame_class, name, None) class_name = frame_class.__class__.__qualname__
except RecursionError: caller_qualname = f"{class_name}.{name}(property)"
print(
"EDMCLogging:EDMCContextFilter:caller_attributes():"
"Failed to get attribute for function info. Bailing out"
)
# class_name is better than nothing for __qualname__
return class_name, class_name, module_name
if fn is not None: else:
if isinstance(fn, property): caller_qualname = f"<property {name} on {class_name}>"
class_name = str(frame_class)
# If somehow you make your __class__ or __class__.__qualname__ recursive, I'll be impressed.
if hasattr(frame_class, '__class__') and hasattr(frame_class.__class__, "__qualname__"):
class_name = frame_class.__class__.__qualname__
caller_qualname = f"{class_name}.{name}(property)"
else: elif hasattr(fn, '__qualname__') and fn.__qualname__:
caller_qualname = f"<property {name} on {class_name}>" caller_qualname = fn.__qualname__
elif fn.__qualname__: # Find containing class name(s) of caller, if any
caller_qualname = fn.__qualname__ if (
frame_class.__class__ and hasattr(frame_class.__class__, '__qualname__')
and frame_class.__class__.__qualname__
):
caller_class_names = frame_class.__class__.__qualname__
# Find containing class name(s) of caller, if any # It's a call from the top level module file
if frame_class.__class__ and frame_class.__class__.__qualname__: elif frame_info.function == '<module>':
caller_class_names = frame_class.__class__.__qualname__ caller_class_names = '<none>'
caller_qualname = value_dict['__name__']
# It's a call from the top level module file elif frame_info.function != '':
elif frame_info.function == '<module>': caller_class_names = '<none>'
caller_class_names = '<none>' caller_qualname = frame_info.function
caller_qualname = value_dict['__name__']
elif frame_info.function != '': module_name = cls.munge_module_name(frame_info, module_name)
caller_class_names = '<none>'
caller_qualname = frame_info.function
module_name = cls.munge_module_name(frame_info, module_name) except Exception as e:
print('ALERT! Something went VERY wrong in handling finding info to log')
print('ALERT! Information is as follows')
with suppress(Exception):
# https://docs.python.org/3.7/library/inspect.html#the-interpreter-stack print(f'ALERT! {e=}')
del frame print_exc()
print(f'ALERT! {frame=}')
with suppress(Exception):
print(f'ALERT! {fn=}') # type: ignore
with suppress(Exception):
print(f'ALERT! {cls=}')
finally: # Ensure this always happens
# https://docs.python.org/3.7/library/inspect.html#the-interpreter-stack
del frame
if caller_qualname == '': if caller_qualname == '':
print('ALERT! Something went wrong with finding caller qualname for logging!') print('ALERT! Something went wrong with finding caller qualname for logging!')
@ -398,19 +421,19 @@ class EDMCContextFilter(logging.Filter):
# Go up through stack frames until we find the first with a # Go up through stack frames until we find the first with a
# type(f_locals.self) of logging.Logger. This should be the start # type(f_locals.self) of logging.Logger. This should be the start
# of the frames internal to logging. # of the frames internal to logging.
frame: 'frame' = getframe(0) frame: 'FrameType' = getframe(0)
while frame: while frame:
if isinstance(frame.f_locals.get('self'), logging.Logger): if isinstance(frame.f_locals.get('self'), logging.Logger):
frame = frame.f_back # Want to start on the next frame below frame = cast('FrameType', frame.f_back) # Want to start on the next frame below
break break
frame = frame.f_back frame = cast('FrameType', frame.f_back)
# Now continue up through frames until we find the next one where # Now continue up through frames until we find the next one where
# that is *not* true, as it should be the call site of the logger # that is *not* true, as it should be the call site of the logger
# call # call
while frame: while frame:
if not isinstance(frame.f_locals.get('self'), logging.Logger): if not isinstance(frame.f_locals.get('self'), logging.Logger):
break # We've found the frame we want break # We've found the frame we want
frame = frame.f_back frame = cast('FrameType', frame.f_back)
return frame return frame
@classmethod @classmethod

View File

@ -0,0 +1,44 @@
import sys
sys.path += "../" # Dont ask me why for this one it breaks, it just does.
from typing import TYPE_CHECKING # noqa: E402
from EDMCLogging import get_plugin_logger # noqa: E402
if TYPE_CHECKING:
from _pytest.logging import LogCaptureFixture
logger = get_plugin_logger('EDMCLogging.py')
class ClassVarLogger:
"""Test class with logger attached."""
@classmethod
def set_logger(cls, logger):
"""Set the passed logger onto the _class_."""
ClassVarLogger.logger = logger
def log_stuff(msg: str):
"""Wrapper logger func."""
ClassVarLogger.logger.debug(msg) # type: ignore # its there
def test_class_logger(caplog: 'LogCaptureFixture'):
"""
Test that logging from a class variable doesn't explode.
In writting a plugin that uses a class variable to hold the logger, EDMCLoggings cleverness to extract data
regarding the qualified name of a function falls flat, as a class variable does not have a qualname, and at the time
we did not check for its existence before using it.
"""
ClassVarLogger.set_logger(logger)
ClassVarLogger.logger.debug('test') # type: ignore # its there
ClassVarLogger.logger.info('test2') # type: ignore # its there
log_stuff('test3') # type: ignore # its there
# Dont move these, it relies on the line numbres.
assert 'EDMarketConnector.EDMCLogging.py:test_logging_classvar.py:37 test' in caplog.text
assert 'EDMarketConnector.EDMCLogging.py:test_logging_classvar.py:38 test2' in caplog.text
assert 'EDMarketConnector.EDMCLogging.py:test_logging_classvar.py:25 test3' in caplog.text