From 83ad476a6d3e071f223595bc19f3c6e5fdfdb7f6 Mon Sep 17 00:00:00 2001 From: Brad Warren Date: Thu, 23 Jul 2015 17:09:09 -0700 Subject: [PATCH] Improved logging and error handling --- acme/acme/challenges.py | 7 +- tests/MANIFEST.in | 2 +- .../configurators/apache/Dockerfile | 2 + .../configurators/apache/common.py | 39 +++-- tests/compatibility/test_driver.py | 153 ++++++++++++------ tests/compatibility/testdata/empty_cert.pem | 13 ++ tests/compatibility/testdata/rsa1024_key2.pem | 15 ++ 7 files changed, 167 insertions(+), 64 deletions(-) create mode 100644 tests/compatibility/testdata/empty_cert.pem create mode 100644 tests/compatibility/testdata/rsa1024_key2.pem diff --git a/acme/acme/challenges.py b/acme/acme/challenges.py index 723c51317..9abdbe833 100644 --- a/acme/acme/challenges.py +++ b/acme/acme/challenges.py @@ -199,10 +199,11 @@ class DVSNI(DVChallenge): def probe_cert(self, domain, **kwargs): """Probe DVSNI challenge certificate.""" - host = socket.gethostbyname(domain) - logging.debug('%s resolved to %s', domain, host) + if "host" not in kwargs: + host = socket.gethostbyname(domain) + logging.debug('%s resolved to %s', domain, host) + kwargs["host"] = host - kwargs.setdefault("host", host) kwargs.setdefault("port", self.PORT) kwargs["name"] = self.nonce_domain # TODO: try different methods? diff --git a/tests/MANIFEST.in b/tests/MANIFEST.in index 7d73674fb..be22c3801 100644 --- a/tests/MANIFEST.in +++ b/tests/MANIFEST.in @@ -1 +1 @@ -include compatibility/testdata/rsa1024_key.pem +recursive-include tests/compatibility/testdata/ * diff --git a/tests/compatibility/configurators/apache/Dockerfile b/tests/compatibility/configurators/apache/Dockerfile index 092d84ec8..da6811485 100644 --- a/tests/compatibility/configurators/apache/Dockerfile +++ b/tests/compatibility/configurators/apache/Dockerfile @@ -11,6 +11,8 @@ ENV APACHE_RUN_USER=daemon \ APACHE_LOG_DIR=/usr/local/apache2/logs COPY tests/compatibility/configurators/apache/a2enmod.sh /usr/local/bin/ +COPY tests/compatibility/testdata/rsa1024_key2.pem /usr/local/apache2/conf/ +COPY tests/compatibility/testdata/empty_cert.pem /usr/local/apache2/conf/ # Note: this only exposes the port to other docker containers. You # still have to bind to 443@host at runtime. diff --git a/tests/compatibility/configurators/apache/common.py b/tests/compatibility/configurators/apache/common.py index 036654844..e21ac61d8 100644 --- a/tests/compatibility/configurators/apache/common.py +++ b/tests/compatibility/configurators/apache/common.py @@ -7,6 +7,7 @@ import mock import zope.interface from letsencrypt import configuration +from letsencrypt import errors as le_errors from letsencrypt_apache import configurator from tests.compatibility import errors from tests.compatibility import interfaces @@ -28,14 +29,22 @@ class Proxy(configurators_common.Proxy): super(Proxy, self).__init__(args) self.le_config.apache_le_vhost_ext = "-le-ssl.conf" - self._patch = mock.patch('letsencrypt_apache.configurator.subprocess') - subprocess_mock = self._patch.start() + self._patches = list() + subprocess_patch = mock.patch( + "letsencrypt_apache.configurator.subprocess") + subprocess_mock = subprocess_patch.start() subprocess_mock.check_call = self.check_call_in_docker subprocess_mock.Popen = self.popen_in_docker + self._patches.append(subprocess_patch) - self.modules = self.version = self.test_conf = None - self._apache_configurator = None - self.server_root = self.modules = self.version = self.test_conf = None + display_patch = mock.patch( + "letsencrypt_apache.configurator.display_ops.select_vhost") + display_mock = display_patch.start() + display_mock.side_effect = le_errors.PluginError( + "Unable to determine vhost") + self._patches.append(display_mock) + + self.modules = self.server_root = self.test_conf = self.version = None self._apache_configurator = self._all_names = self._test_names = None def __getattr__(self, name): @@ -83,16 +92,21 @@ class Proxy(configurators_common.Proxy): def preprocess_config(self, server_root): # pylint: disable=anomalous-backslash-in-string, no-self-use """Prepares the configuration for use in the Docker""" + find = subprocess.Popen( ["find", server_root, "-type", "f"], stdout=subprocess.PIPE) subprocess.check_call([ - "xargs", "sed", "-e", "s/DocumentRoot.*/" - "DocumentRoot \/usr\/local\/apache2\/htdocs/I", - "-e", "s/SSLPassPhraseDialog.*/" - "SSLPassPhraseDialog builtin/I", - "-e", "s/TypesConfig.*/" - "TypesConfig \/usr\/local\/apache2\/conf\/mime.types/I", + "xargs", "sed", "-e", "s/DocumentRoot.*/DocumentRoot " + "\/usr\/local\/apache2\/htdocs/I", + "-e", "s/SSLPassPhraseDialog.*/SSLPassPhraseDialog builtin/I", + "-e", "s/TypesConfig.*/TypesConfig " + "\/usr\/local\/apache2\/conf\/mime.types/I", + "-e", "s/LoadModule/#LoadModule/I", + "-e", "s/SSLCertificateFile.*/SSLCertificateFile " + "\/usr\/local\/apache2\/conf\/empty_cert.pem/I", + "-e", "s/SSLCertificateKeyFile.*/SSLCertificateKeyFile " + "\/usr\/local\/apache2\/conf\/rsa1024_key2.pem/I", "-i"], stdin=find.stdout) def _prepare_configurator(self, server_root, config_file): @@ -111,7 +125,8 @@ class Proxy(configurators_common.Proxy): def cleanup_from_tests(self): """Performs any necessary cleanup from running plugin tests""" super(Proxy, self).cleanup_from_tests() - self._patch.stop() + for patch in self._patches: + patch.stop() def get_all_names_answer(self): """Returns the set of domain names that the plugin should find""" diff --git a/tests/compatibility/test_driver.py b/tests/compatibility/test_driver.py index 65ad36f18..90ad5ec39 100644 --- a/tests/compatibility/test_driver.py +++ b/tests/compatibility/test_driver.py @@ -28,7 +28,6 @@ tests that the plugin supports are performed. """ - PLUGINS = {"apache" : apache24.Proxy} @@ -36,44 +35,57 @@ logger = logging.getLogger(__name__) def test_authenticator(plugin, config, temp_dir): - """Tests plugin as an authenticator""" + """Tests authenticator, returning True if the tests are successful""" backup = _create_backup(config, temp_dir) achalls = _create_achalls(plugin) if not achalls: - return + # Plugin/tests support no common challenge types + return True try: responses = plugin.perform(achalls) - for i in xrange(len(responses)): - if not responses[i]: - logger.error( - "Plugin returned `None` or `False` response to challenge " - "for config `%s`", config) - elif isinstance(responses[i], challenges.DVSNIResponse): - if responses[i].simple_verify(achalls[i], - achalls[i].domain, - util.JWK.key.public_key(), - host="127.0.0.1", - port=plugin.https_port): - logger.info( - "Verification of DVSNI response for %s succeeded", - achalls[i].domain) - else: - logger.error( - "Verification of DVSNI response for %s in config '%s' " - "failed ", achalls[i].domain, config) except le_errors.Error as error: - logger.info( - "Plugin raised %s during authentication with config '%s'", - error, config) - finally: - plugin.cleanup(achalls) + logger.error("Performing challenges on %s caused an error:", config) + logger.exception(error) + return False - if _dirs_are_unequal(config, backup): - logger.error("Challenge cleanup failed for config %s", config) - else: - logger.info("Challenge cleanup succeeded") + success = True + for i in xrange(len(responses)): + if not responses[i]: + logger.error( + "Plugin failed to complete %s for %s in %s", + type(achalls[i]), achalls[i].domain, config) + success = False + elif isinstance(responses[i], challenges.DVSNIResponse): + if responses[i].simple_verify(achalls[i], + achalls[i].domain, + util.JWK.key.public_key(), + host="127.0.0.1", + port=plugin.https_port): + logger.info( + "DVSNI verification for %s succeeded", achalls[i].domain) + else: + logger.error( + "DVSNI verification for %s in %s failed", + achalls[i].domain, config) + success = False + + if success: + try: + plugin.cleanup(achalls) + except le_errors.Error as error: + logger.error("Challenge cleanup for %s caused an error:", config) + logger.exception(error) + success = False + + if _dirs_are_unequal(config, backup): + logger.error("Challenge cleanup failed for %s", config) + return False + else: + logger.info("Challenge cleanup succeeded") + + return success def _create_achalls(plugin): @@ -100,16 +112,20 @@ def test_installer(args, plugin, config, temp_dir): """Tests plugin as an installer""" backup = _create_backup(config, temp_dir) - if plugin.get_all_names().issubset(plugin.get_all_names_answer()): + names_match = plugin.get_all_names() == plugin.get_all_names_answer() + if names_match: logger.info("get_all_names test succeeded") else: - logger.error("get_all_names test failed for config `%s`", config) + logger.error("get_all_names test failed for config %s", config) domains = list(plugin.get_testable_domain_names()) - if test_deploy_cert(plugin, temp_dir, domains) and args.enhance: - test_enhancements(plugin, domains) + success = test_deploy_cert(plugin, temp_dir, domains) - test_rollback(plugin, config, backup) + if success and args.enhance: + success = test_enhancements(plugin, domains) + + good_rollback = test_rollback(plugin, config, backup) + return names_match and success and good_rollback def test_deploy_cert(plugin, temp_dir, domains): @@ -121,9 +137,15 @@ def test_deploy_cert(plugin, temp_dir, domains): OpenSSL.crypto.FILETYPE_PEM, cert)) for domain in domains: - plugin.deploy_cert(domain, cert_path, util.KEY_PATH) - plugin.save("deployed") - plugin.restart() + try: + plugin.deploy_cert(domain, cert_path, util.KEY_PATH) + except le_errors.Error as error: + logger.error("Plugin failed to deploy ceritificate for %s:", domain) + logger.exception(error) + return False + + if not _save_and_restart(plugin, "deployed"): + return False verify_cert = validator.Validator().certificate success = True @@ -139,17 +161,22 @@ def test_deploy_cert(plugin, temp_dir, domains): def test_enhancements(plugin, domains): - """Tests enhancements supported by the plugin""" + """Tests supported enhancements returning True if successful""" supported = plugin.supported_enhancements() if "redirect" not in supported: - return + return True for domain in domains: - plugin.enhance(domain, "redirect") + try: + plugin.enhance(domain, "redirect") + except le_errors.Error as error: + logger.error("Plugin failed to enable redirect for %s:", domain) + logger.exception(error) + return False - plugin.save("enhanced") - plugin.restart() + if not _save_and_restart(plugin, "enhanced"): + return False verify_redirect = functools.partial( validator.Validator().redirect, "localhost", plugin.http_port) @@ -162,15 +189,36 @@ def test_enhancements(plugin, domains): if success: logger.info("Enhancments test succeeded") + return success + + +def _save_and_restart(plugin, title=None): + """Saves and restart the plugin, returning True if no errors occurred""" + try: + plugin.save(title) + plugin.restart() + return True + except le_errors.Error as error: + logger.error("Plugin failed to save and restart server:") + logger.exception(error) + return False + def test_rollback(plugin, config, backup): """Tests the rollback checkpoints function""" - plugin.rollback_checkpoints(2) + try: + plugin.rollback_checkpoints(2) + except le_errors.Error as error: + logger.error("Plugin raised an exception during rollback:") + logger.exception(error) + return False if _dirs_are_unequal(config, backup): logger.error("Rollback failed for config `%s`", config) + return False else: logger.info("Rollback succeeded") + return True def _create_backup(config, temp_dir): @@ -249,15 +297,24 @@ def main(): try: plugin.execute_in_docker("mkdir -p /var/log/apache2") while plugin.has_more_configs(): + success = True + try: config = plugin.load_config() logger.info("Loaded configuration: %s", config) if args.auth: - test_authenticator(plugin, config, temp_dir) - if args.install: - test_installer(args, plugin, config, temp_dir) + success = test_authenticator(plugin, config, temp_dir) + if success and args.install: + success = test_installer(args, plugin, config, temp_dir) except errors.Error as error: - logger.error("Tests on config `%s` raised: %s", config, error) + logger.error("Tests on %s raised:", config) + logger.exception(error) + success = False + + if success: + logger.info("All tests on %s succeeded", config) + else: + logger.error("Tests on %s failed", config) finally: plugin.cleanup_from_tests() diff --git a/tests/compatibility/testdata/empty_cert.pem b/tests/compatibility/testdata/empty_cert.pem new file mode 100644 index 000000000..4ea812a87 --- /dev/null +++ b/tests/compatibility/testdata/empty_cert.pem @@ -0,0 +1,13 @@ +-----BEGIN CERTIFICATE----- +MIICATCCAWoCCQCvMbKu4FHZ6zANBgkqhkiG9w0BAQsFADBFMQswCQYDVQQGEwJB +VTETMBEGA1UECAwKU29tZS1TdGF0ZTEhMB8GA1UECgwYSW50ZXJuZXQgV2lkZ2l0 +cyBQdHkgTHRkMB4XDTE1MDcyMzIzMjc1MFoXDTE2MDcyMjIzMjc1MFowRTELMAkG +A1UEBhMCQVUxEzARBgNVBAgMClNvbWUtU3RhdGUxITAfBgNVBAoMGEludGVybmV0 +IFdpZGdpdHMgUHR5IEx0ZDCBnzANBgkqhkiG9w0BAQEFAAOBjQAwgYkCgYEAws3o +y46PMLM9Gr68pbex0MhdPr7Cq4rRe9BBpnOuHFdF35Ak0aPrzFwVzLlGOir94U11 +e5JYJDWJi+4FwLBRkOAfanjJ5GJ9BnEHSOdbtO+sv9uhbt+7iYOOUOngKSiJyUrM +i1THAE+B1CenxZ1KHRQCke708zkK8jVuxLeIAOMCAwEAATANBgkqhkiG9w0BAQsF +AAOBgQCC3LUP3MHk+IBmwHHZAZCX+6p4lop9SP6y6rDpWgnqEEeb9oFleHi2Rvzq +7gxl6nS5AsaSzfAygJ3zWKTwVAZyU4GOQ8QTK+nHk3+LO1X4cDbUlQfm5+YuwKDa +4LFKeovmrK6BiMLIc1J+MxUjLfCeVHYSdkZULTVXue0zif0BUA== +-----END CERTIFICATE----- diff --git a/tests/compatibility/testdata/rsa1024_key2.pem b/tests/compatibility/testdata/rsa1024_key2.pem new file mode 100644 index 000000000..03f77d903 --- /dev/null +++ b/tests/compatibility/testdata/rsa1024_key2.pem @@ -0,0 +1,15 @@ +-----BEGIN RSA PRIVATE KEY----- +MIICXAIBAAKBgQDCzejLjo8wsz0avrylt7HQyF0+vsKritF70EGmc64cV0XfkCTR +o+vMXBXMuUY6Kv3hTXV7klgkNYmL7gXAsFGQ4B9qeMnkYn0GcQdI51u076y/26Fu +37uJg45Q6eApKInJSsyLVMcAT4HUJ6fFnUodFAKR7vTzOQryNW7Et4gA4wIDAQAB +AoGAKiAU40/krwdTg2ETslJS5W8ums7tkeLnAfs69x+02vQUbA/jpmHoL70KCcdW +5GU/mWUCrsIqxUm+gL/sBosaV/TF256qUBt2qQCZTN8MbDaNSYiiMnucOfbWdIqx +Zgls6GUoXQvPic9RUoFSlgfSjo5ezz6el5ihvRMp+wbk24ECQQD3oz4hN029DSZo +Y3+flmBn77gA0BMUvLa6hmt9b3xT5U/ToCLfbmUvpx7zV1g5era2y9qt/o3UtAbW +1zCVETgzAkEAyWHv/+RnSXp8/D4YwTVWyeWi862uNBPkuLGP/0zASdwBfBK3uBls ++VumfSCtp0kt2AXXmScg1fkHdeAVT6AkkQJBAJb2XRnCrRFiwtdAULzo3zx9Vp6o +OfmaUYrEByMgo5pBYLiSFrA+jFDQgH238YCY3mnxPA517+CLHuA5rtQw+yECQCfm +gL/pyFE1tLfhsdPuNpDwL9YqLl7hJis1+zrxQRQhRCYKK16NoxrQ/u7B38ZKaIvp +tGsC5q2elszTJkXNjBECQCVE9QCVx056vHVdPWM8z3GAeV3sJQ01HLLjebTEEz6G +jH54gk+YYPp4kjCvVUykbnB58BY2n88GQt5Jj5eLuMo= +-----END RSA PRIVATE KEY-----