Commit 87edb77c authored by Xavier Thompson's avatar Xavier Thompson

[fix] Adapt to setuptools>=65.6.0 logging on root

INFO logs from setuptools which were previously not emitted because
setuptool's ad-hoc legacy logger defaulted to WARNING and above may
now be emitted because setuptools now logs to the root logger, thus
the global root logger's level configuration applied.

This caused undesired 'root: <some setuptools info>' messages to be
emitted and caused many tests to fail due to unexpected outputs.
parent ceb23e98
......@@ -1275,21 +1275,33 @@ class Buildout(DictMixin):
timeout)
def _setup_logging(self):
root_logger = logging.getLogger()
self._logger = logging.getLogger('zc.buildout')
handler = logging.StreamHandler(sys.stdout)
# Note that setuptols >= 65.6.0 emits INFO logs directly to the root.
log_format = self['buildout']['log-format']
if not log_format:
# No format specified. Use different formatter for buildout
# and other modules, showing logger name except for buildout
log_format = '%(name)s: %(message)s'
buildout_handler = logging.StreamHandler(sys.stdout)
buildout_handler.setFormatter(logging.Formatter('%(message)s'))
self._logger.propagate = False
self._logger.addHandler(buildout_handler)
handler.setFormatter(logging.Formatter(log_format))
root_logger.addHandler(handler)
generic_log_format = log_format or '%(name)s: %(message)s'
buildout_log_format = log_format or '%(message)s'
root_logger = logging.getLogger()
self._logger = buildout_logger = logging.getLogger('zc.buildout')
# root-specific WARNING handler because setuptools>=65.6.0 logs to root
root_handler = logging.StreamHandler(sys.stdout)
root_handler.setLevel(logging.WARNING)
root_handler.addFilter(lambda record: record.name == 'root')
root_handler.setFormatter(logging.Formatter(generic_log_format))
root_logger.addHandler(root_handler)
# generic handler for third-party logs
generic_handler = logging.StreamHandler(sys.stdout)
generic_handler.addFilter(lambda record: record.name != 'root')
generic_handler.setFormatter(logging.Formatter(generic_log_format))
root_logger.addHandler(generic_handler)
# buildout handler for buildout logs
buildout_handler = logging.StreamHandler(sys.stdout)
buildout_handler.setFormatter(logging.Formatter(buildout_log_format))
buildout_logger.propagate = False
buildout_logger.addHandler(buildout_handler)
level = self['buildout']['log-level']
if level in ('DEBUG', 'INFO', 'WARNING', 'ERROR', 'CRITICAL'):
......
......@@ -615,6 +615,8 @@ normalize_open_in_generated_script = (
not_found = (re.compile(r'Not found: [^\n]+/(\w|\.)+/\r?\n'), '')
root_logger_messages = (re.compile(r'^(root: )+', re.MULTILINE), '')
python27_warning = (re.compile(r'DEPRECATION: Python 2.7 reached the end of its '
'life on January 1st, 2020. Please upgrade your Python as Python 2.7 is no '
'longer maintained. A future version of pip will drop support for Python '
......
......@@ -4005,6 +4005,7 @@ def test_suite():
zc.buildout.testing.normalize_script,
zc.buildout.testing.normalize_egg_py,
zc.buildout.testing.not_found,
zc.buildout.testing.root_logger_messages,
zc.buildout.testing.adding_find_link,
zc.buildout.testing.python27_warning,
zc.buildout.testing.python27_warning_2,
......@@ -4056,6 +4057,7 @@ def test_suite():
zc.buildout.testing.normalize_script,
zc.buildout.testing.normalize_egg_py,
zc.buildout.testing.not_found,
zc.buildout.testing.root_logger_messages,
zc.buildout.testing.adding_find_link,
zc.buildout.testing.easyinstall_deprecated,
zc.buildout.testing.setuptools_deprecated,
......@@ -4098,6 +4100,7 @@ def test_suite():
zc.buildout.testing.normalize_endings,
zc.buildout.testing.normalize_exception_type_for_python_2_and_3,
zc.buildout.testing.not_found,
zc.buildout.testing.root_logger_messages,
zc.buildout.testing.adding_find_link,
zc.buildout.testing.easyinstall_deprecated,
zc.buildout.testing.setuptools_deprecated,
......@@ -4125,6 +4128,7 @@ def test_suite():
zc.buildout.testing.normalize_script,
zc.buildout.testing.normalize_egg_py,
zc.buildout.testing.not_found,
zc.buildout.testing.root_logger_messages,
zc.buildout.testing.adding_find_link,
zc.buildout.testing.easyinstall_deprecated,
zc.buildout.testing.setuptools_deprecated,
......@@ -4161,6 +4165,7 @@ def test_suite():
zc.buildout.testing.normalize_open_in_generated_script,
zc.buildout.testing.adding_find_link,
zc.buildout.testing.not_found,
zc.buildout.testing.root_logger_messages,
zc.buildout.testing.python27_warning,
zc.buildout.testing.python27_warning_2,
zc.buildout.testing.easyinstall_deprecated,
......@@ -4190,6 +4195,7 @@ def test_suite():
checker=renormalizing.RENormalizing([
zc.buildout.testing.normalize_exception_type_for_python_2_and_3,
zc.buildout.testing.not_found,
zc.buildout.testing.root_logger_messages,
zc.buildout.testing.adding_find_link,
zc.buildout.testing.easyinstall_deprecated,
zc.buildout.testing.setuptools_deprecated,
......@@ -4214,6 +4220,7 @@ def test_suite():
zc.buildout.testing.normalize_egg_py,
zc.buildout.testing.normalize___pycache__,
zc.buildout.testing.not_found,
zc.buildout.testing.root_logger_messages,
zc.buildout.testing.normalize_exception_type_for_python_2_and_3,
zc.buildout.testing.adding_find_link,
zc.buildout.testing.python27_warning,
......@@ -4272,6 +4279,7 @@ def test_suite():
zc.buildout.testing.normalize_script,
zc.buildout.testing.normalize_egg_py,
zc.buildout.testing.not_found,
zc.buildout.testing.root_logger_messages,
zc.buildout.testing.adding_find_link,
zc.buildout.testing.easyinstall_deprecated,
zc.buildout.testing.setuptools_deprecated,
......@@ -4296,7 +4304,12 @@ def test_suite():
),
])
),
doctest.DocFileSuite('testing_bugfix.txt'),
doctest.DocFileSuite('testing_bugfix.txt',
checker=renormalizing.RENormalizing([
zc.buildout.testing.not_found,
zc.buildout.testing.root_logger_messages,
])
),
]
docdir = os.path.join(ancestor(__file__, 5), 'doc')
......@@ -4362,6 +4375,7 @@ def test_suite():
zc.buildout.testing.normalize_endings,
zc.buildout.testing.normalize_script,
zc.buildout.testing.not_found,
zc.buildout.testing.root_logger_messages,
normalize_bang,
zc.buildout.testing.adding_find_link,
(re.compile('Downloading.*setuptools.*egg\n'), ''),
......
......@@ -74,6 +74,7 @@ def test_suite():
zc.buildout.testing.normalize_egg_py,
zc.buildout.testing.normalize___pycache__,
zc.buildout.testing.not_found,
zc.buildout.testing.root_logger_messages,
zc.buildout.testing.normalize_exception_type_for_python_2_and_3,
zc.buildout.testing.adding_find_link,
zc.buildout.testing.python27_warning,
......
......@@ -402,6 +402,7 @@ def test_suite():
zc.buildout.testing.normalize_egg_py,
zc.buildout.testing.normalize___pycache__,
zc.buildout.testing.not_found,
zc.buildout.testing.root_logger_messages,
zc.buildout.testing.normalize_exception_type_for_python_2_and_3,
zc.buildout.testing.adding_find_link,
zc.buildout.testing.python27_warning,
......
......@@ -4,9 +4,9 @@ Bug fixes in zc.buildout.testing
Logging handler which did not get deleted
-----------------------------------------
The buildout testing set up runs a buildout which adds a
The buildout testing set up runs a buildout which adds two
``logging.StreamHandler`` to the root logger. But tear down did not
remove it. This can disturb other tests of packages reusing
remove them. This can disturb other tests of packages reusing
zc.buildout.testing.
The handlers before calling set up are:
......@@ -16,19 +16,19 @@ The handlers before calling set up are:
>>> logging.getLogger().handlers # doctest: +ELLIPSIS
[<...NullHandler...>]
After calling it, a ``logging.StreamHandler`` was added:
After calling it, two ``logging.StreamHandler`` were added:
>>> import zc.buildout.testing
>>> import doctest
>>> test = doctest.DocTestParser().get_doctest(
... '>>> x', {}, 'foo', 'foo.py', 0)
>>> zc.buildout.testing.buildoutSetUp(test)
>>> len(logging.getLogger().handlers) == count + 1
>>> len(logging.getLogger().handlers) == count + 2
True
>>> logging.getLogger().handlers # doctest: +ELLIPSIS +NORMALIZE_WHITESPACE
[<...NullHandler...StreamHandler...>]
[<...NullHandler...StreamHandler...StreamHandler...>]
But tear down removes the new logging handler:
But tear down removes the new logging handlers:
>>> zc.buildout.testing.buildoutTearDown(test)
>>> len(logging.getLogger().handlers) == count
......
......@@ -49,6 +49,7 @@ def test_suite():
zc.buildout.tests.normalize_bang,
zc.buildout.tests.normalize_S,
zc.buildout.testing.not_found,
zc.buildout.testing.root_logger_messages,
zc.buildout.testing.python27_warning,
zc.buildout.testing.python27_warning_2,
zc.buildout.testing.easyinstall_deprecated,
......@@ -71,6 +72,7 @@ def test_suite():
zc.buildout.testing.normalize_path,
zc.buildout.testing.normalize_endings,
zc.buildout.testing.not_found,
zc.buildout.testing.root_logger_messages,
zc.buildout.testing.python27_warning,
zc.buildout.testing.python27_warning_2,
zc.buildout.testing.easyinstall_deprecated,
......@@ -98,6 +100,7 @@ def test_suite():
zc.buildout.testing.normalize_path,
zc.buildout.testing.normalize_endings,
zc.buildout.testing.not_found,
zc.buildout.testing.root_logger_messages,
# Setuptools may emit this warning if it hasn't yet indexed
# the index page of the test package index (at <index-url>)
# because it starts by looking at <index-url>/<package-name>
......@@ -118,6 +121,7 @@ def test_suite():
zc.buildout.tests.normalize_bang,
zc.buildout.tests.normalize_S,
zc.buildout.testing.not_found,
zc.buildout.testing.root_logger_messages,
zc.buildout.testing.python27_warning,
zc.buildout.testing.python27_warning_2,
zc.buildout.testing.easyinstall_deprecated,
......@@ -139,6 +143,7 @@ def test_suite():
zc.buildout.testing.normalize_path,
zc.buildout.testing.normalize_endings,
zc.buildout.testing.not_found,
zc.buildout.testing.root_logger_messages,
zc.buildout.testing.python27_warning,
zc.buildout.testing.python27_warning_2,
zc.buildout.testing.easyinstall_deprecated,
......
Markdown is supported
0%
or
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment