Karthikeyan Singaravelan <[email protected]> added the comment:
I think I have found the bug. When we call setLevel then to clear the cache
value of Logger objects `logging.Logger.manager.loggerDict.values()`
(https://github.com/python/cpython/blob/9c18b1ae527346bc178250ad1ca07bffdacde5dd/Lib/logging/__init__.py#L1265)
is called but since somewhere you have called
`logging.Logger.manager.loggerDict.clear()` before changing the level and hence
it doesn't iterate through the dict to clear the logger object cache. This is
not present in 3.6 since there is no Logger._cache and works fine.
Don't do logging.Logger.manager.loggerDict.clear() and you can see logging
enabled for error as False because while doing setLevel we clear the cache of
Logger objects of logging.Logger.manager.loggerDict.values()
➜ cpython git:(master) ✗ cat bpo34269.py
import sys
import logging
logger1 = logging.getLogger('abc')
logger2 = logging.getLogger('cde')
logger1.setLevel(logging.ERROR)
logger2.setLevel(logging.ERROR)
print("logging error : ", logger1.isEnabledFor(logging.ERROR))
print("logger dict : ", logging.Logger.manager.loggerDict)
print("Not clearing logging dict ")
# logging.Logger.manager.loggerDict.clear()
print("logger dict : ", logging.Logger.manager.loggerDict)
print("logging enabled for error : ", logger1.isEnabledFor(logging.ERROR))
if sys.version_info >= (3,7): # Print cache only for python 3.7 and above
# Since we clear logging.Logger.manager.loggerDict.clear() the cache is not
reset
print("Cache ", logger1._cache)
print("Setting to critical")
logger1.setLevel(logging.CRITICAL)
if sys.version_info >= (3,7):
print("Cache after setting to critical ", logger1._cache)
print("logging enabled for error : ", logger1.isEnabledFor(logging.ERROR))
➜ cpython git:(master) ✗ ./python.exe bpo34269.py
logging error : True
logger dict : {'abc': <Logger abc (ERROR)>, 'cde': <Logger cde (ERROR)>}
Not clearing logging dict
logger dict : {'abc': <Logger abc (ERROR)>, 'cde': <Logger cde (ERROR)>}
logging enabled for error : True
Cache {40: True}
Setting to critical
Cache after setting to critical {}
logging enabled for error : False
call logging.Logger.manager.loggerDict.clear() and you can see logging enabled
for error as True because while doing setLevel we clear the cache of Logger
objects of logging.Logger.manager.loggerDict.values() will be empty.
➜ cpython git:(master) ✗ cat bpo34269.py
import sys
import logging
logger1 = logging.getLogger('abc')
logger2 = logging.getLogger('cde')
logger1.setLevel(logging.ERROR)
logger2.setLevel(logging.ERROR)
print("logging error : ", logger1.isEnabledFor(logging.ERROR))
print("logger dict : ", logging.Logger.manager.loggerDict)
print("clearing logging dict ")
logging.Logger.manager.loggerDict.clear()
print("logger dict : ", logging.Logger.manager.loggerDict)
print("logging enabled for error : ", logger1.isEnabledFor(logging.ERROR))
if sys.version_info >= (3,7):
# Since we clear logging.Logger.manager.loggerDict.clear() the cache is not
reset
print("Cache ", logger1._cache)
print("Setting to critical")
logger1.setLevel(logging.CRITICAL)
if sys.version_info >= (3,7):
print("Cache after setting to critical ", logger1._cache)
print("logging enabled for error : ", logger1.isEnabledFor(logging.ERROR))
➜ cpython git:(master) ✗ ./python.exe bpo34269.py
logging error : True
logger dict : {'abc': <Logger abc (ERROR)>, 'cde': <Logger cde (ERROR)>}
clearing logging dict
logger dict : {}
logging enabled for error : True
Cache {40: True}
Setting to critical
Cache after setting to critical {40: True} # Cache is not cleared due to
logging.Logger.manager.loggerDict.clear()
logging enabled for error : True # True not False
Above script on Python 3.6 there is no Logger._cache and hence there is no
cache invalidation to be done though logging.Logger.manager.loggerDict.clear()
is called.
➜ cpython git:(master) ✗ python3.6 bpo34269.py
logging error : True
logger dict : {'abc': <Logger abc (ERROR)>, 'cde': <Logger cde (ERROR)>}
clearing logging dict
logger dict : {}
logging enabled for error : True
Setting to critical
logging enabled for error : False # False since there is no cache
I have attached the test file that reproduces this. I think this is a bug. I
don't know how to fix it since we can restrict the user from calling
`logging.Logger.manager.loggerDict.clear()` and depend on it for cache
invalidation. Either this can be documented but I think there might be old code
depending on this. I am adding original reviewers to see if they can add some
thoughts on this. Feel free to unassign yourself. I will check for a fix for
this in the meantime with the above test case so that it can make it to next
Python 3.7 bug fix release. @Thomas.Waldmann for the moment I think from the
above disabling the loggerDict.clear() call will make tests pass.
Thanks
----------
nosy: +pitrou, vinay.sajip, vstinner
Added file: https://bugs.python.org/file47721/bpo34269.py
_______________________________________
Python tracker <[email protected]>
<https://bugs.python.org/issue34269>
_______________________________________
_______________________________________________
Python-bugs-list mailing list
Unsubscribe:
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com