diff --git a/CHANGELOG.md b/CHANGELOG.md index 7744e3745..ce7eac2e9 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -14,6 +14,8 @@ Certbot adheres to [Semantic Versioning](https://semver.org/). warnings described at https://github.com/certbot/josepy/issues/13. * Apache plugin now respects CERTBOT_DOCS environment variable when adding command line defaults. +* The running of manual plugin hooks is now always included in Certbot's log + output. * Tests execution for certbot, certbot-apache and certbot-nginx packages now relies on pytest. ### Fixed diff --git a/certbot/hooks.py b/certbot/hooks.py index d5239a437..7d2e42fcd 100644 --- a/certbot/hooks.py +++ b/certbot/hooks.py @@ -93,8 +93,7 @@ def _run_pre_hook_if_necessary(command): if command in executed_pre_hooks: logger.info("Pre-hook command already run, skipping: %s", command) else: - logger.info("Running pre-hook command: %s", command) - _run_hook(command) + _run_hook("pre-hook", command) executed_pre_hooks.add(command) @@ -126,8 +125,7 @@ def post_hook(config): _run_eventually(cmd) # certonly / run elif cmd: - logger.info("Running post-hook command: %s", cmd) - _run_hook(cmd) + _run_hook("post-hook", cmd) post_hooks = [] # type: List[str] @@ -149,8 +147,7 @@ def _run_eventually(command): def run_saved_post_hooks(): """Run any post hooks that were saved up in the course of the 'renew' verb""" for cmd in post_hooks: - logger.info("Running post-hook command: %s", cmd) - _run_hook(cmd) + _run_hook("post-hook", cmd) def deploy_hook(config, domains, lineage_path): @@ -220,23 +217,30 @@ def _run_deploy_hook(command, domains, lineage_path, dry_run): os.environ["RENEWED_DOMAINS"] = " ".join(domains) os.environ["RENEWED_LINEAGE"] = lineage_path - logger.info("Running deploy-hook command: %s", command) - _run_hook(command) + _run_hook("deploy-hook", command) -def _run_hook(shell_cmd): +def _run_hook(cmd_name, shell_cmd): """Run a hook command. - :returns: stderr if there was any""" + :param str cmd_name: the user facing name of the hook being run + :param shell_cmd: shell command to execute + :type shell_cmd: `list` of `str` or `str` - err, _ = execute(shell_cmd) + :returns: stderr if there was any""" + err, _ = execute(cmd_name, shell_cmd) return err -def execute(shell_cmd): +def execute(cmd_name, shell_cmd): """Run a command. + :param str cmd_name: the user facing name of the hook being run + :param shell_cmd: shell command to execute + :type shell_cmd: `list` of `str` or `str` + :returns: `tuple` (`str` stderr, `str` stdout)""" + logger.info("Running %s command: %s", cmd_name, shell_cmd) # universal_newlines causes Popen.communicate() # to return str objects instead of bytes in Python 3 @@ -245,12 +249,12 @@ def execute(shell_cmd): out, err = cmd.communicate() base_cmd = os.path.basename(shell_cmd.split(None, 1)[0]) if out: - logger.info('Output from %s:\n%s', base_cmd, out) + logger.info('Output from %s command %s:\n%s', cmd_name, base_cmd, out) if cmd.returncode != 0: - logger.error('Hook command "%s" returned error code %d', - shell_cmd, cmd.returncode) + logger.error('%s command "%s" returned error code %d', + cmd_name, shell_cmd, cmd.returncode) if err: - logger.error('Error output from %s:\n%s', base_cmd, err) + logger.error('Error output from %s command %s:\n%s', cmd_name, base_cmd, err) return (err, out) diff --git a/certbot/plugins/manual.py b/certbot/plugins/manual.py index 8723a1c62..123a5bfea 100644 --- a/certbot/plugins/manual.py +++ b/certbot/plugins/manual.py @@ -202,7 +202,7 @@ permitted by DNS standards.) os.environ.pop('CERTBOT_KEY_PATH', None) os.environ.pop('CERTBOT_SNI_DOMAIN', None) os.environ.update(env) - _, out = hooks.execute(self.conf('auth-hook')) + _, out = self._execute_hook('auth-hook') env['CERTBOT_AUTH_OUTPUT'] = out.strip() self.env[achall] = env @@ -243,5 +243,8 @@ permitted by DNS standards.) if 'CERTBOT_TOKEN' not in env: os.environ.pop('CERTBOT_TOKEN', None) os.environ.update(env) - hooks.execute(self.conf('cleanup-hook')) + self._execute_hook('cleanup-hook') self.reverter.recovery_routine() + + def _execute_hook(self, hook_name): + return hooks.execute(self.option_name(hook_name), self.conf(hook_name)) diff --git a/certbot/tests/hook_test.py b/certbot/tests/hook_test.py index f5bb0c8b5..90f639958 100644 --- a/certbot/tests/hook_test.py +++ b/certbot/tests/hook_test.py @@ -121,7 +121,7 @@ class PreHookTest(HookTest): def _test_nonrenew_common(self): mock_execute = self._call_with_mock_execute(self.config) - mock_execute.assert_called_once_with(self.config.pre_hook) + mock_execute.assert_called_once_with("pre-hook", self.config.pre_hook) self._test_no_executions_common() def test_no_hooks(self): @@ -137,21 +137,21 @@ class PreHookTest(HookTest): def test_renew_disabled_dir_hooks(self): self.config.directory_hooks = False mock_execute = self._call_with_mock_execute(self.config) - mock_execute.assert_called_once_with(self.config.pre_hook) + mock_execute.assert_called_once_with("pre-hook", self.config.pre_hook) self._test_no_executions_common() def test_renew_no_overlap(self): self.config.verb = "renew" mock_execute = self._call_with_mock_execute(self.config) - mock_execute.assert_any_call(self.dir_hook) - mock_execute.assert_called_with(self.config.pre_hook) + mock_execute.assert_any_call("pre-hook", self.dir_hook) + mock_execute.assert_called_with("pre-hook", self.config.pre_hook) self._test_no_executions_common() def test_renew_with_overlap(self): self.config.pre_hook = self.dir_hook self.config.verb = "renew" mock_execute = self._call_with_mock_execute(self.config) - mock_execute.assert_called_once_with(self.dir_hook) + mock_execute.assert_called_once_with("pre-hook", self.dir_hook) self._test_no_executions_common() def _test_no_executions_common(self): @@ -193,7 +193,7 @@ class PostHookTest(HookTest): for verb in ("certonly", "run",): self.config.verb = verb mock_execute = self._call_with_mock_execute(self.config) - mock_execute.assert_called_once_with(self.config.post_hook) + mock_execute.assert_called_once_with("post-hook", self.config.post_hook) self.assertFalse(self._get_eventually()) def test_cert_only_and_run_without_hook(self): @@ -277,12 +277,12 @@ class RunSavedPostHooksTest(HookTest): calls = mock_execute.call_args_list for actual_call, expected_arg in zip(calls, self.eventually): - self.assertEqual(actual_call[0][0], expected_arg) + self.assertEqual(actual_call[0][1], expected_arg) def test_single(self): self.eventually = ["foo"] mock_execute = self._call_with_mock_execute_and_eventually() - mock_execute.assert_called_once_with(self.eventually[0]) + mock_execute.assert_called_once_with("post-hook", self.eventually[0]) class RenewalHookTest(HookTest): @@ -360,7 +360,7 @@ class DeployHookTest(RenewalHookTest): self.config.deploy_hook = "foo" mock_execute = self._call_with_mock_execute( self.config, domains, lineage) - mock_execute.assert_called_once_with(self.config.deploy_hook) + mock_execute.assert_called_once_with("deploy-hook", self.config.deploy_hook) class RenewHookTest(RenewalHookTest): @@ -384,7 +384,7 @@ class RenewHookTest(RenewalHookTest): self.config.directory_hooks = False mock_execute = self._call_with_mock_execute( self.config, ["example.org"], "/foo/bar") - mock_execute.assert_called_once_with(self.config.renew_hook) + mock_execute.assert_called_once_with("deploy-hook", self.config.renew_hook) @mock.patch("certbot.hooks.logger") def test_dry_run(self, mock_logger): @@ -408,13 +408,13 @@ class RenewHookTest(RenewalHookTest): self.config.renew_hook = self.dir_hook mock_execute = self._call_with_mock_execute( self.config, ["example.net", "example.org"], "/foo/bar") - mock_execute.assert_called_once_with(self.dir_hook) + mock_execute.assert_called_once_with("deploy-hook", self.dir_hook) def test_no_overlap(self): mock_execute = self._call_with_mock_execute( self.config, ["example.org"], "/foo/bar") - mock_execute.assert_any_call(self.dir_hook) - mock_execute.assert_called_with(self.config.renew_hook) + mock_execute.assert_any_call("deploy-hook", self.dir_hook) + mock_execute.assert_called_with("deploy-hook", self.config.renew_hook) class ExecuteTest(unittest.TestCase): @@ -433,18 +433,22 @@ class ExecuteTest(unittest.TestCase): def _test_common(self, returncode, stdout, stderr): given_command = "foo" + given_name = "foo-hook" with mock.patch("certbot.hooks.Popen") as mock_popen: mock_popen.return_value.communicate.return_value = (stdout, stderr) mock_popen.return_value.returncode = returncode with mock.patch("certbot.hooks.logger") as mock_logger: - self.assertEqual(self._call(given_command), (stderr, stdout)) + self.assertEqual(self._call(given_name, given_command), (stderr, stdout)) executed_command = mock_popen.call_args[1].get( "args", mock_popen.call_args[0][0]) self.assertEqual(executed_command, given_command) + mock_logger.info.assert_any_call("Running %s command: %s", + given_name, given_command) if stdout: - self.assertTrue(mock_logger.info.called) + mock_logger.info.assert_any_call(mock.ANY, mock.ANY, + mock.ANY, stdout) if stderr or returncode: self.assertTrue(mock_logger.error.called)