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
This commit is contained in:
Tobias Henkel 2019-03-03 19:28:11 +01:00
parent f72682f477
commit 6f754dd878
No known key found for this signature in database
GPG Key ID: 03750DEC158E5FA2
3 changed files with 45 additions and 34 deletions

View File

@ -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

View File

@ -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)

View File

@ -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(