Created
April 2, 2020 18:53
-
-
Save sethrh/331cadc538051cb0c0eb1de001a3b70f to your computer and use it in GitHub Desktop.
txaio.aio logging bug example
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
''' | |
To run: | |
$ python3.7 -m venv txaio-test | |
$ . txaio-test/bin/activate | |
(txaio-test) $ pip install txaio | |
Collecting txaio | |
Downloading https://files.pythonhosted.org/packages/4f/82/0cd8d81d57e55a598cd4cef10c6e971dbcaf437e4f138dc1624cf7c1388e/txaio-20.4.1-py2.py3-none-any.whl | |
Installing collected packages: txaio | |
Successfully installed txaio-20.4.1 | |
(txaio-test) $ python txaio-test.py | |
''' | |
import logging | |
import txaio | |
txaio.use_asyncio() | |
log = txaio.make_logger() | |
print("A logger's log level can't be changed after txaio.start_logging() is called. " | |
"If you start in info mode, you can't change to debug. " | |
"So if framework code calls start_logging('info') for you, you can't change it " | |
"to 'debug' later. ") | |
# txaio.start_logging(level='debug') | |
txaio.start_logging() | |
print("By default, the log level is 'info'") | |
print("log.debug is", log.debug) | |
log.debug("Test debug") # doesn't log | |
log.info("Test info") # logs | |
log.warn("Test warn") # logs | |
print("Set the global log level to 'warn'") | |
txaio.set_global_log_level('warn') | |
print("log.debug is", log.debug) | |
log.debug("Test debug") # doesn't log | |
log.info("Test info") # doesn't log | |
log.warn("Test warn") # logs | |
print("Set the global log level to 'debug'") | |
txaio.set_global_log_level('debug') | |
print("log.debug is", log.debug) | |
log.debug("Test debug") # doesn't log | |
log.info("Test info") # logs | |
log.warn("Test warn") # logs | |
print("txaio.set_global_log_level calls _set_log_level, but _set_log_level " | |
"doesn't call setLogLevel on log._logger.") | |
print("log._logger.isEnabledFor(logging.DEBUG)", log._logger.isEnabledFor(logging.DEBUG)) # False | |
# Directly setting the log level on the embedded logger solves the problem | |
# log._logger.setLevel(logging.DEBUG) | |
# print("log.debug is", log.debug) | |
# log.debug("Debug") | |
from txaio.aio import log_levels, _no_op, _log, functools | |
level_to_stdlib = { | |
'critical': logging.CRITICAL, | |
'error': logging.ERROR, | |
'warn': logging.WARNING, | |
'info': logging.INFO, | |
'debug': logging.DEBUG, | |
'trace': logging.DEBUG, | |
} | |
print("One fix is to update _set_log_level so that it calls _logger.setLevel") | |
def patched_set_log_level(self, level): | |
target_level = log_levels.index(level) | |
# this binds either _log or _no_op above to this instance, | |
# depending on the desired level. | |
for (idx, name) in enumerate(log_levels): | |
if idx <= target_level: | |
log_method = functools.partial(_log, self, name) | |
else: | |
log_method = _no_op | |
setattr(self, name, log_method) | |
self._log_level = level | |
self._logger.setLevel(level_to_stdlib[level]) | |
# bind patched_set_log_level to our log instance | |
log._set_log_level = patched_set_log_level.__get__(log) | |
print("Not that it's patched, try setting the global log level to 'debug' again") | |
txaio.set_global_log_level('debug') | |
print("log.debug is", log.debug) | |
print("log._logger.isEnabledFor(logging.DEBUG)", log._logger.isEnabledFor(logging.DEBUG)) # True | |
log.debug("Test debug") # logs | |
log.info("Test info") # logs | |
log.warn("Test warn") # logs | |
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment