mirror of
https://github.com/certbot/certbot.git
synced 2026-07-28 00:24:35 +02:00
So merging the study from @bmw and me, here is what happened. Each invocation of `certbot.logger.post_arg_parse_setup` create a file handler on `letsencrypt.log`. This function also set an atexit handler invoking `logger.shutdown()`, that have the effect to close all logger file handler not already closed at this point. This method is supposed to be called when a python process is close to exit, because it makes all logger unable to write new logs on any handler. Before #6667 and this PR, for tests, the atexit handle would be triggered only at the end of the pytest process. It means that each test that launches `certbot.logger.post_arg_parse_setup` add a new file handler. These tests were typically connecting the file handler on a `letsencrypt.log` located in a temporary directory, and this directory and content was wipped out at each test tearDown. As a consequence, the file handles, not cleared from the logger, were accumulating in the logger, with all of them connected to a deleted file log, except the last one that was just created by the current test. Considering the number of tests concerned, there were ~300 file handler at the end of pytest execution. One can see that, on prior #6667, by calling `print(logger.getLogger().handlers` on the `tearDown` of these tests, and see the array growing at each test execution. Even if this represent a memory leak, this situation was not really a problem on Linux: because a file can be deleted before it is closed, it was only meaning that a given invocation of `logger.debug` for instance, during the tests, was written in 300 log files. The overhead is negligeable. On Windows however, the file handlers were failing because you cannot delete a file before it is closed. It was one of the reason for #6667, that added a call to `logging.shutdown()` at each test tearDown, with the consequence to close all file handlers. At this point, Linux is not happy anymore. Any call to `logger.warn` will generate an error for each closed file handler. As a file handler is added for each test, the number of errors grows on each test, following an arithmetical suite divergence. On `test_sdists.py`, that is using the bare setuptools test suite without output capturing, we can see the damages. The total output takes 216000 lines, and 23000 errors are generated. A decent machine can support this load, but a not a small AWS instance, that is crashing during the execution. Even with pytest, the captured output and the memory leak become so large that segfaults are generated. On the current PR, the problem is solved, by resetting the file handlers array on the logging system on each test tearDown. So each fileHandler is properly closed, and removed from the stack. They do not participate anymore in the logging system, and can be garbage collected. Then we stay on always one file handler opened at any time, and tests can succeed on AWS instances. For the record, here is all the places where the logging system is called and fail if there is still file handlers closed but not cleaned (extracted from the original huge output before correction): ``` Logged from file account.py, line 116 Logged from file account.py, line 178 Logged from file client.py, line 166 Logged from file client.py, line 295 Logged from file client.py, line 415 Logged from file client.py, line 422 Logged from file client.py, line 480 Logged from file client.py, line 503 Logged from file client.py, line 540 Logged from file client.py, line 601 Logged from file client.py, line 622 Logged from file client.py, line 750 Logged from file cli.py, line 220 Logged from file cli.py, line 226 Logged from file crypto_util.py, line 101 Logged from file crypto_util.py, line 127 Logged from file crypto_util.py, line 147 Logged from file crypto_util.py, line 261 Logged from file crypto_util.py, line 283 Logged from file crypto_util.py, line 307 Logged from file crypto_util.py, line 336 Logged from file disco.py, line 116 Logged from file disco.py, line 124 Logged from file disco.py, line 134 Logged from file disco.py, line 138 Logged from file disco.py, line 141 Logged from file dns_common_lexicon.py, line 45 Logged from file dns_common_lexicon.py, line 61 Logged from file dns_common_lexicon.py, line 67 Logged from file dns_common.py, line 316 Logged from file dns_common.py, line 64 Logged from file eff.py, line 60 Logged from file eff.py, line 73 Logged from file error_handler.py, line 105 Logged from file error_handler.py, line 110 Logged from file error_handler.py, line 87 Logged from file hooks.py, line 248 Logged from file main.py, line 1071 Logged from file main.py, line 1075 Logged from file main.py, line 1189 Logged from file ops.py, line 122 Logged from file ops.py, line 325 Logged from file ops.py, line 338 Logged from file reporter.py, line 55 Logged from file selection.py, line 110 Logged from file selection.py, line 118 Logged from file selection.py, line 123 Logged from file selection.py, line 176 Logged from file selection.py, line 231 Logged from file selection.py, line 310 Logged from file selection.py, line 66 Logged from file standalone.py, line 101 Logged from file standalone.py, line 88 Logged from file standalone.py, line 97 Logged from file standalone.py, line 98 Logged from file storage.py, line 52 Logged from file storage.py, line 59 Logged from file storage.py, line 75 Logged from file util.py, line 56 Logged from file webroot.py, line 165 Logged from file webroot.py, line 186 Logged from file webroot.py, line 187 Logged from file webroot.py, line 204 Logged from file webroot.py, line 223 Logged from file webroot.py, line 234 Logged from file webroot.py, line 235 Logged from file webroot.py, line 237 Logged from file webroot.py, line 91 ``` * Reapply #6667 * Make setuptools delegates tests execution to pytest, like in acme module. * Clean handlers at each tearDown to avoid memory leaks. * Update changelog
435 lines
15 KiB
Python
435 lines
15 KiB
Python
"""Test utilities.
|
|
|
|
.. warning:: This module is not part of the public API.
|
|
|
|
"""
|
|
import logging
|
|
import os
|
|
import pkg_resources
|
|
import shutil
|
|
import stat
|
|
import tempfile
|
|
import unittest
|
|
import sys
|
|
from multiprocessing import Process, Event
|
|
|
|
from cryptography.hazmat.backends import default_backend
|
|
from cryptography.hazmat.primitives import serialization
|
|
import mock
|
|
import OpenSSL
|
|
import josepy as jose
|
|
import six
|
|
from six.moves import reload_module # pylint: disable=import-error
|
|
|
|
from certbot import constants
|
|
from certbot import interfaces
|
|
from certbot import storage
|
|
from certbot import configuration
|
|
from certbot import lock
|
|
from certbot import util
|
|
|
|
from certbot.display import util as display_util
|
|
|
|
|
|
def vector_path(*names):
|
|
"""Path to a test vector."""
|
|
return pkg_resources.resource_filename(
|
|
__name__, os.path.join('testdata', *names))
|
|
|
|
|
|
def load_vector(*names):
|
|
"""Load contents of a test vector."""
|
|
# luckily, resource_string opens file in binary mode
|
|
data = pkg_resources.resource_string(
|
|
__name__, os.path.join('testdata', *names))
|
|
# Try at most to convert CRLF to LF when data is text
|
|
try:
|
|
return data.decode().replace('\r\n', '\n').encode()
|
|
except ValueError:
|
|
# Failed to process the file with standard encoding.
|
|
# Most likely not a text file, return its bytes untouched.
|
|
return data
|
|
|
|
|
|
def _guess_loader(filename, loader_pem, loader_der):
|
|
_, ext = os.path.splitext(filename)
|
|
if ext.lower() == '.pem':
|
|
return loader_pem
|
|
elif ext.lower() == '.der':
|
|
return loader_der
|
|
else: # pragma: no cover
|
|
raise ValueError("Loader could not be recognized based on extension")
|
|
|
|
|
|
def load_cert(*names):
|
|
"""Load certificate."""
|
|
loader = _guess_loader(
|
|
names[-1], OpenSSL.crypto.FILETYPE_PEM, OpenSSL.crypto.FILETYPE_ASN1)
|
|
return OpenSSL.crypto.load_certificate(loader, load_vector(*names))
|
|
|
|
|
|
def load_csr(*names):
|
|
"""Load certificate request."""
|
|
loader = _guess_loader(
|
|
names[-1], OpenSSL.crypto.FILETYPE_PEM, OpenSSL.crypto.FILETYPE_ASN1)
|
|
return OpenSSL.crypto.load_certificate_request(loader, load_vector(*names))
|
|
|
|
|
|
def load_comparable_csr(*names):
|
|
"""Load ComparableX509 certificate request."""
|
|
return jose.ComparableX509(load_csr(*names))
|
|
|
|
|
|
def load_rsa_private_key(*names):
|
|
"""Load RSA private key."""
|
|
loader = _guess_loader(names[-1], serialization.load_pem_private_key,
|
|
serialization.load_der_private_key)
|
|
return jose.ComparableRSAKey(loader(
|
|
load_vector(*names), password=None, backend=default_backend()))
|
|
|
|
|
|
def load_pyopenssl_private_key(*names):
|
|
"""Load pyOpenSSL private key."""
|
|
loader = _guess_loader(
|
|
names[-1], OpenSSL.crypto.FILETYPE_PEM, OpenSSL.crypto.FILETYPE_ASN1)
|
|
return OpenSSL.crypto.load_privatekey(loader, load_vector(*names))
|
|
|
|
|
|
def skip_unless(condition, reason): # pragma: no cover
|
|
"""Skip tests unless a condition holds.
|
|
|
|
This implements the basic functionality of unittest.skipUnless
|
|
which is only available on Python 2.7+.
|
|
|
|
:param bool condition: If ``False``, the test will be skipped
|
|
:param str reason: the reason for skipping the test
|
|
|
|
:rtype: callable
|
|
:returns: decorator that hides tests unless condition is ``True``
|
|
|
|
"""
|
|
if hasattr(unittest, "skipUnless"):
|
|
return unittest.skipUnless(condition, reason)
|
|
elif condition:
|
|
return lambda cls: cls
|
|
else:
|
|
return lambda cls: None
|
|
|
|
|
|
def make_lineage(config_dir, testfile):
|
|
"""Creates a lineage defined by testfile.
|
|
|
|
This creates the archive, live, and renewal directories if
|
|
necessary and creates a simple lineage.
|
|
|
|
:param str config_dir: path to the configuration directory
|
|
:param str testfile: configuration file to base the lineage on
|
|
|
|
:returns: path to the renewal conf file for the created lineage
|
|
:rtype: str
|
|
|
|
"""
|
|
lineage_name = testfile[:-len('.conf')]
|
|
|
|
conf_dir = os.path.join(
|
|
config_dir, constants.RENEWAL_CONFIGS_DIR)
|
|
archive_dir = os.path.join(
|
|
config_dir, constants.ARCHIVE_DIR, lineage_name)
|
|
live_dir = os.path.join(
|
|
config_dir, constants.LIVE_DIR, lineage_name)
|
|
|
|
for directory in (archive_dir, conf_dir, live_dir,):
|
|
if not os.path.exists(directory):
|
|
os.makedirs(directory)
|
|
|
|
sample_archive = vector_path('sample-archive')
|
|
for kind in os.listdir(sample_archive):
|
|
shutil.copyfile(os.path.join(sample_archive, kind),
|
|
os.path.join(archive_dir, kind))
|
|
|
|
for kind in storage.ALL_FOUR:
|
|
os.symlink(os.path.join(archive_dir, '{0}1.pem'.format(kind)),
|
|
os.path.join(live_dir, '{0}.pem'.format(kind)))
|
|
|
|
conf_path = os.path.join(config_dir, conf_dir, testfile)
|
|
with open(vector_path(testfile)) as src:
|
|
with open(conf_path, 'w') as dst:
|
|
dst.writelines(
|
|
line.replace('MAGICDIR', config_dir) for line in src)
|
|
|
|
return conf_path
|
|
|
|
|
|
def patch_get_utility(target='zope.component.getUtility'):
|
|
"""Patch zope.component.getUtility to use a special mock IDisplay.
|
|
|
|
The mock IDisplay works like a regular mock object, except it also
|
|
also asserts that methods are called with valid arguments.
|
|
|
|
:param str target: path to patch
|
|
|
|
:returns: mock zope.component.getUtility
|
|
:rtype: mock.MagicMock
|
|
|
|
"""
|
|
return mock.patch(target, new_callable=_create_get_utility_mock)
|
|
|
|
|
|
def patch_get_utility_with_stdout(target='zope.component.getUtility',
|
|
stdout=None):
|
|
"""Patch zope.component.getUtility to use a special mock IDisplay.
|
|
|
|
The mock IDisplay works like a regular mock object, except it also
|
|
also asserts that methods are called with valid arguments.
|
|
|
|
The `message` argument passed to the IDisplay methods is passed to
|
|
stdout's write method.
|
|
|
|
:param str target: path to patch
|
|
:param object stdout: object to write standard output to; it is
|
|
expected to have a `write` method
|
|
|
|
:returns: mock zope.component.getUtility
|
|
:rtype: mock.MagicMock
|
|
|
|
"""
|
|
stdout = stdout if stdout else six.StringIO()
|
|
|
|
freezable_mock = _create_get_utility_mock_with_stdout(stdout)
|
|
return mock.patch(target, new=freezable_mock)
|
|
|
|
|
|
class FreezableMock(object):
|
|
"""Mock object with the ability to freeze attributes.
|
|
|
|
This class works like a regular mock.MagicMock object, except
|
|
attributes and behavior set before the object is frozen cannot
|
|
be changed during tests.
|
|
|
|
If a func argument is provided to the constructor, this function
|
|
is called first when an instance of FreezableMock is called,
|
|
followed by the usual behavior defined by MagicMock. The return
|
|
value of func is ignored.
|
|
|
|
"""
|
|
def __init__(self, frozen=False, func=None, return_value=mock.sentinel.DEFAULT):
|
|
self._frozen_set = set() if frozen else {'freeze', }
|
|
self._func = func
|
|
self._mock = mock.MagicMock()
|
|
if return_value != mock.sentinel.DEFAULT:
|
|
self.return_value = return_value
|
|
self._frozen = frozen
|
|
|
|
def freeze(self):
|
|
"""Freeze object preventing further changes."""
|
|
self._frozen = True
|
|
|
|
def __call__(self, *args, **kwargs):
|
|
if self._func is not None:
|
|
self._func(*args, **kwargs)
|
|
return self._mock(*args, **kwargs)
|
|
|
|
def __getattribute__(self, name):
|
|
if name == '_frozen':
|
|
try:
|
|
return object.__getattribute__(self, name)
|
|
except AttributeError:
|
|
return False
|
|
elif name in ('return_value', 'side_effect',):
|
|
return getattr(object.__getattribute__(self, '_mock'), name)
|
|
elif name == '_frozen_set' or name in self._frozen_set:
|
|
return object.__getattribute__(self, name)
|
|
else:
|
|
return getattr(object.__getattribute__(self, '_mock'), name)
|
|
|
|
def __setattr__(self, name, value):
|
|
""" Before it is frozen, attributes are set on the FreezableMock
|
|
instance and added to the _frozen_set. Attributes in the _frozen_set
|
|
cannot be changed after the FreezableMock is frozen. In this case,
|
|
they are set on the underlying _mock.
|
|
|
|
In cases of return_value and side_effect, these attributes are always
|
|
passed through to the instance's _mock and added to the _frozen_set
|
|
before the object is frozen.
|
|
|
|
"""
|
|
if self._frozen:
|
|
if name in self._frozen_set:
|
|
raise AttributeError('Cannot change frozen attribute ' + name)
|
|
else:
|
|
return setattr(self._mock, name, value)
|
|
|
|
if name != '_frozen_set':
|
|
self._frozen_set.add(name)
|
|
|
|
if name in ('return_value', 'side_effect'):
|
|
return setattr(self._mock, name, value)
|
|
|
|
else:
|
|
return object.__setattr__(self, name, value)
|
|
|
|
|
|
def _create_get_utility_mock():
|
|
display = FreezableMock()
|
|
for name in interfaces.IDisplay.names(): # pylint: disable=no-member
|
|
if name != 'notification':
|
|
frozen_mock = FreezableMock(frozen=True, func=_assert_valid_call)
|
|
setattr(display, name, frozen_mock)
|
|
display.freeze()
|
|
return FreezableMock(frozen=True, return_value=display)
|
|
|
|
|
|
def _create_get_utility_mock_with_stdout(stdout):
|
|
def _write_msg(message, *unused_args, **unused_kwargs):
|
|
"""Write to message to stdout.
|
|
"""
|
|
if message:
|
|
stdout.write(message)
|
|
|
|
def mock_method(*args, **kwargs):
|
|
"""
|
|
Mock function for IDisplay methods.
|
|
"""
|
|
_assert_valid_call(args, kwargs)
|
|
_write_msg(*args, **kwargs)
|
|
|
|
|
|
display = FreezableMock()
|
|
for name in interfaces.IDisplay.names(): # pylint: disable=no-member
|
|
if name == 'notification':
|
|
frozen_mock = FreezableMock(frozen=True,
|
|
func=_write_msg)
|
|
setattr(display, name, frozen_mock)
|
|
else:
|
|
frozen_mock = FreezableMock(frozen=True,
|
|
func=mock_method)
|
|
setattr(display, name, frozen_mock)
|
|
display.freeze()
|
|
|
|
return FreezableMock(frozen=True, return_value=display)
|
|
|
|
|
|
def _assert_valid_call(*args, **kwargs):
|
|
assert_args = [args[0] if args else kwargs['message']]
|
|
|
|
assert_kwargs = {}
|
|
assert_kwargs['default'] = kwargs.get('default', None)
|
|
assert_kwargs['cli_flag'] = kwargs.get('cli_flag', None)
|
|
assert_kwargs['force_interactive'] = kwargs.get('force_interactive', False)
|
|
|
|
# pylint: disable=star-args
|
|
display_util.assert_valid_call(*assert_args, **assert_kwargs)
|
|
|
|
|
|
class TempDirTestCase(unittest.TestCase):
|
|
"""Base test class which sets up and tears down a temporary directory"""
|
|
|
|
def setUp(self):
|
|
"""Execute before test"""
|
|
self.tempdir = tempfile.mkdtemp()
|
|
|
|
def tearDown(self):
|
|
"""Execute after test"""
|
|
# Cleanup opened resources after a test. This is usually done through atexit handlers in
|
|
# Certbot, but during tests, atexit will not run registered functions before tearDown is
|
|
# called and instead will run them right before the entire test process exits.
|
|
# It is a problem on Windows, that does not accept to clean resources before closing them.
|
|
logging.shutdown()
|
|
# Remove logging handlers that have been closed so they won't be
|
|
# accidentally used in future tests.
|
|
logging.getLogger().handlers = []
|
|
util._release_locks() # pylint: disable=protected-access
|
|
|
|
def handle_rw_files(_, path, __):
|
|
"""Handle read-only files, that will fail to be removed on Windows."""
|
|
os.chmod(path, stat.S_IWRITE)
|
|
os.remove(path)
|
|
shutil.rmtree(self.tempdir, onerror=handle_rw_files)
|
|
|
|
|
|
class ConfigTestCase(TempDirTestCase):
|
|
"""Test class which sets up a NamespaceConfig object."""
|
|
def setUp(self):
|
|
super(ConfigTestCase, self).setUp()
|
|
self.config = configuration.NamespaceConfig(
|
|
mock.MagicMock(**constants.CLI_DEFAULTS)
|
|
)
|
|
self.config.verb = "certonly"
|
|
self.config.config_dir = os.path.join(self.tempdir, 'config')
|
|
self.config.work_dir = os.path.join(self.tempdir, 'work')
|
|
self.config.logs_dir = os.path.join(self.tempdir, 'logs')
|
|
self.config.cert_path = constants.CLI_DEFAULTS['auth_cert_path']
|
|
self.config.fullchain_path = constants.CLI_DEFAULTS['auth_chain_path']
|
|
self.config.chain_path = constants.CLI_DEFAULTS['auth_chain_path']
|
|
self.config.server = "https://example.com"
|
|
|
|
|
|
def _handle_lock(event_in, event_out, path):
|
|
"""
|
|
Acquire a file lock on given path, then wait to release it. This worker is coordinated
|
|
using events to signal when the lock should be acquired and released.
|
|
:param multiprocessing.Event event_in: event object to signal when to release the lock
|
|
:param multiprocessing.Event event_out: event object to signal when the lock is acquired
|
|
:param path: the path to lock
|
|
"""
|
|
if os.path.isdir(path):
|
|
my_lock = lock.lock_dir(path)
|
|
else:
|
|
my_lock = lock.LockFile(path)
|
|
try:
|
|
event_out.set()
|
|
assert event_in.wait(timeout=20), 'Timeout while waiting to release the lock.'
|
|
finally:
|
|
my_lock.release()
|
|
|
|
|
|
def lock_and_call(callback, path_to_lock):
|
|
"""
|
|
Grab a lock on path_to_lock from a foreign process then execute the callback.
|
|
:param callable callback: object to call after acquiring the lock
|
|
:param str path_to_lock: path to file or directory to lock
|
|
"""
|
|
# Reload certbot.util module to reset internal _LOCKS dictionary.
|
|
reload_module(util)
|
|
|
|
emit_event = Event()
|
|
receive_event = Event()
|
|
process = Process(target=_handle_lock, args=(emit_event, receive_event, path_to_lock))
|
|
process.start()
|
|
|
|
# Wait confirmation that lock is acquired
|
|
assert receive_event.wait(timeout=10), 'Timeout while waiting to acquire the lock.'
|
|
# Execute the callback
|
|
callback()
|
|
# Trigger unlock from foreign process
|
|
emit_event.set()
|
|
|
|
# Wait for process termination
|
|
process.join(timeout=10)
|
|
assert process.exitcode == 0
|
|
|
|
|
|
def skip_on_windows(reason):
|
|
"""Decorator to skip permanently a test on Windows. A reason is required."""
|
|
def wrapper(function):
|
|
"""Wrapped version"""
|
|
return unittest.skipIf(sys.platform == 'win32', reason)(function)
|
|
return wrapper
|
|
|
|
|
|
def broken_on_windows(function):
|
|
"""Decorator to skip temporarily a broken test on Windows."""
|
|
reason = 'Test is broken and ignored on windows but should be fixed.'
|
|
return unittest.skipIf(
|
|
sys.platform == 'win32'
|
|
and os.environ.get('SKIP_BROKEN_TESTS_ON_WINDOWS', 'true') == 'true',
|
|
reason)(function)
|
|
|
|
|
|
def temp_join(path):
|
|
"""
|
|
Return the given path joined to the tempdir path for the current platform
|
|
Eg.: 'cert' => /tmp/cert (Linux) or 'C:\\Users\\currentuser\\AppData\\Temp\\cert' (Windows)
|
|
"""
|
|
return os.path.join(tempfile.gettempdir(), path)
|