From 6f754dd87876486631508fecf28bf7af460d1689 Mon Sep 17 00:00:00 2001 From: Tobias Henkel Date: Sun, 3 Mar 2019 19:28:11 +0100 Subject: [PATCH] Log exception on module failure with empty stdout In the zuul_stream callback we check for 'MODULE FAILURE' and then log stdout, exception or stderr whichever we find first. However in some cases stdout exists but is empty. In this case we don't log the error reason and the user needs to look into the json log which contains the correct information. This can be easily fixed by checking if stdout is empty. Change-Id: I8019d40e2e99310eaeab03f652368dac66e1ee17 --- .../git/org_project/playbooks/command.yaml | 16 ++++++ tests/remote/test_remote_zuul_stream.py | 9 ++++ zuul/ansible/callback/zuul_stream.py | 54 +++++++------------ 3 files changed, 45 insertions(+), 34 deletions(-) diff --git a/tests/fixtures/config/remote-zuul-stream/git/org_project/playbooks/command.yaml b/tests/fixtures/config/remote-zuul-stream/git/org_project/playbooks/command.yaml index 6081351552..7839494f7d 100644 --- a/tests/fixtures/config/remote-zuul-stream/git/org_project/playbooks/command.yaml +++ b/tests/fixtures/config/remote-zuul-stream/git/org_project/playbooks/command.yaml @@ -82,3 +82,19 @@ - failed_in_loop1 - failed_in_loop2 ignore_errors: True + +- hosts: all + tasks: + - name: Remote shell task with python exception + command: echo foo + args: + chdir: /remote-shelltask/somewhere/that/does/not/exist + failed_when: false + +- hosts: localhost + tasks: + - name: Local shell task with python exception + command: echo foo + args: + chdir: /local-shelltask/somewhere/that/does/not/exist + failed_when: false diff --git a/tests/remote/test_remote_zuul_stream.py b/tests/remote/test_remote_zuul_stream.py index 91139f4a67..686a68cd91 100644 --- a/tests/remote/test_remote_zuul_stream.py +++ b/tests/remote/test_remote_zuul_stream.py @@ -133,6 +133,15 @@ class TestZuulStream(AnsibleZuulTestCase): self.assertLogLine(r'compute1 \| failed_in_loop2', text) self.assertLogLine(r'compute1 \| ok: Item: failed_in_loop2 ' r'Result: 1', text) + self.assertLogLine(r'localhost \| .*No such file or directory: .*' + r'\'/local-shelltask/somewhere/' + r'that/does/not/exist\'', text) + self.assertLogLine(r'compute1 \| .*No such file or directory: .*' + r'\'/remote-shelltask/somewhere/' + r'that/does/not/exist\'', text) + self.assertLogLine(r'controller \| .*No such file or directory: .*' + r'\'/remote-shelltask/somewhere/' + r'that/does/not/exist\'', text) self.assertLogLine( r'controller \| ok: Runtime: \d:\d\d:\d\d\.\d\d\d\d\d\d', text) self.assertLogLine('PLAY RECAP', text) diff --git a/zuul/ansible/callback/zuul_stream.py b/zuul/ansible/callback/zuul_stream.py index 36ee4650a6..966c9008ca 100644 --- a/zuul/ansible/callback/zuul_stream.py +++ b/zuul/ansible/callback/zuul_stream.py @@ -182,6 +182,20 @@ class CallbackModule(default.CallbackModule): self._log("%s | %s " % (host, ln), ts=ts) return False + def _log_module_failure(self, result, result_dict): + if 'module_stdout' in result_dict and result_dict['module_stdout']: + self._log_message( + result, status='MODULE FAILURE', + msg=result_dict['module_stdout']) + elif 'exception' in result_dict and result_dict['exception']: + self._log_message( + result, status='MODULE FAILURE', + msg=result_dict['exception']) + elif 'module_stderr' in result_dict: + self._log_message( + result, status='MODULE FAILURE', + msg=result_dict['module_stderr']) + def v2_playbook_on_start(self, playbook): self._playbook_name = os.path.splitext(playbook._file_name)[0] @@ -311,18 +325,7 @@ class CallbackModule(default.CallbackModule): # items have their own events pass elif (result_dict.get('msg') == 'MODULE FAILURE'): - if 'module_stdout' in result_dict: - self._log_message( - result, status='MODULE FAILURE', - msg=result_dict['module_stdout']) - elif 'exception' in result_dict: - self._log_message( - result, status='MODULE FAILURE', - msg=result_dict['exception']) - elif 'module_stderr' in result_dict: - self._log_message( - result, status='MODULE FAILURE', - msg=result_dict['module_stderr']) + self._log_module_failure(result, result_dict) else: self._log_message( result=result, status='ERROR', result_dict=result_dict) @@ -388,18 +391,7 @@ class CallbackModule(default.CallbackModule): pass elif (result_dict.get('msg') == 'MODULE FAILURE'): - if 'module_stdout' in result_dict: - self._log_message( - result, status='MODULE FAILURE', - msg=result_dict['module_stdout']) - elif 'exception' in result_dict: - self._log_message( - result, status='MODULE FAILURE', - msg=result_dict['exception']) - elif 'module_stderr' in result_dict: - self._log_message( - result, status='MODULE FAILURE', - msg=result_dict['module_stderr']) + self._log_module_failure(result, result_dict) elif result._task.action == 'debug': # this is a debug statement, handle it special for key in [k for k in result_dict @@ -454,11 +446,8 @@ class CallbackModule(default.CallbackModule): else: status = 'ok' - if (result_dict.get('msg') == 'MODULE FAILURE' and - 'module_stdout' in result_dict): - self._log_message( - result, status='MODULE FAILURE', - msg="Item: {item}\n{module_stdout}".format(**result_dict)) + if result_dict.get('msg') == 'MODULE FAILURE': + self._log_module_failure(result, result_dict) elif result._task.action not in ('command', 'shell', 'win_command', 'win_shell'): if 'msg' in result_dict: @@ -493,11 +482,8 @@ class CallbackModule(default.CallbackModule): result_dict = dict(result._result) self._process_result_for_localhost(result, is_task=False) - if (result_dict.get('msg') == 'MODULE FAILURE' and - 'module_stdout' in result_dict): - self._log_message( - result, status='MODULE FAILURE', - msg="Item: {item}\n{module_stdout}".format(**result_dict)) + if result_dict.get('msg') == 'MODULE FAILURE': + self._log_module_failure(result, result_dict) elif result._task.action not in ('command', 'shell', 'win_command', 'win_shell'): self._log_message(