Log stdout, stderr and command on execute() error

It would help debugging considerably if a failure in execute()
generated a message (at a client specified logging level). Such a
message, generated by execute() would only occur if the user requested
it by specifying a parameter (log_errors), and execute() were to throw
an exception. As an example, this change would address the issue being
addressed in bug 1340124 for the Trove project only.

DocImpact: New parameter added to processutils.execute().  The
possible values of the log_errors parameter are 'all' or 'final'. The
default value of None implies no logging. If it is set to 'final',
stdout and stderr are logged on the final failure. If it is set to
'all', stdout and stderr are logged on every failure.

Originally-submitted-in: If8180e042e1a05374ef705f5873cc0981243619f

Change-Id: Id9e94bd8d009b8f134f0b681da5dec5717d662ff
DocImpact:
Closes-Bug: #1342857
Suggested-By: Peter Stachowski <peter@tesora.com>
Reported-By: Ionuț Arțăriși <iartarisi@suse.cz>
This commit is contained in:
Amrith Kumar 2014-08-14 01:06:23 -04:00
parent 37b90eda3e
commit d15dc6903b
2 changed files with 111 additions and 2 deletions

View File

@ -116,6 +116,8 @@ def execute(*cmd, **kwargs):
:type shell: boolean
:param loglevel: log level for execute commands.
:type loglevel: int. (Should be logging.DEBUG or logging.INFO)
:param log_errors: Should stdout and stderr be logged on error?
:type log_errors: string. (default, None ...: off, 'final', 'all')
:returns: (stdout, stderr) from process execution
:raises: :class:`UnknownArgumentError` on
receiving unknown arguments
@ -132,6 +134,7 @@ def execute(*cmd, **kwargs):
root_helper = kwargs.pop('root_helper', '')
shell = kwargs.pop('shell', False)
loglevel = kwargs.pop('loglevel', logging.DEBUG)
log_errors = kwargs.pop('log_errors', None)
if isinstance(check_exit_code, bool):
ignore_exit_code = not check_exit_code
@ -142,6 +145,10 @@ def execute(*cmd, **kwargs):
if kwargs:
raise UnknownArgumentError(_('Got unknown keyword args: %r') % kwargs)
if log_errors and log_errors not in ['all', 'final']:
raise InvalidArgumentError(_('Got invalid arg log_errors: %r') %
log_errors)
if run_as_root and hasattr(os, 'geteuid') and os.geteuid() != 0:
if not root_helper:
raise NoRootWrapSpecified(
@ -197,11 +204,21 @@ def execute(*cmd, **kwargs):
stderr=stderr,
cmd=' '.join(cmd))
return result
except ProcessExecutionError:
except ProcessExecutionError as err:
# if we want to always log the errors or if this is
# the final attempt that failed and we want to log that.
if log_errors == 'all' or (log_errors == 'final' and not attempts):
LOG.log(loglevel, _('%r'), err.description)
LOG.log(loglevel, _('command: %r'), err.cmd)
LOG.log(loglevel, _('exit_code: %r'), err.exit_code)
LOG.log(loglevel, _('stdout: %r'), err.stdout)
LOG.log(loglevel, _('stderr: %r'), err.stderr)
if not attempts:
LOG.log(loglevel, _('%r failed. Out of retries.'), cmd)
raise
else:
LOG.log(loglevel, '%r failed. Retrying.', cmd)
LOG.log(loglevel, _('%r failed. Retrying.'), cmd)
if delay_on_retry:
greenthread.sleep(random.randint(20, 200) / 100.0)
finally:

View File

@ -218,6 +218,98 @@ grep foo
self.assertIn('SUPER_UNIQUE_VAR=The answer is 42', out)
class ProcessExecutionErrorLoggingTest(test_base.BaseTestCase):
def setUp(self):
super(ProcessExecutionErrorLoggingTest, self).setUp()
fd, self.tmpfilename = tempfile.mkstemp()
fp = os.fdopen(fd, 'w+')
fp.write('#!/bin/bash\n')
fp.write('exit 41\n')
fp.close()
os.chmod(self.tmpfilename, 0o755)
def test_with_invalid_log_errors(self):
self.assertRaises(processutils.InvalidArgumentError,
processutils.execute,
self.tmpfilename,
log_errors='invalid')
def test_with_default_log_errors(self):
err = self.assertRaises(processutils.ProcessExecutionError,
processutils.execute,
self.tmpfilename)
self.assertEqual(41, err.exit_code)
def test_with_log_errors_NONE(self):
err = self.assertRaises(processutils.ProcessExecutionError,
processutils.execute,
self.tmpfilename,
log_errors=None)
self.assertEqual(41, err.exit_code)
def test_with_log_errors_final(self):
err = self.assertRaises(processutils.ProcessExecutionError,
processutils.execute,
self.tmpfilename,
log_errors='final')
self.assertEqual(41, err.exit_code)
def test_with_log_errors_all(self):
err = self.assertRaises(processutils.ProcessExecutionError,
processutils.execute,
self.tmpfilename,
log_errors='all')
self.assertEqual(41, err.exit_code)
def test_multiattempt_with_invalid_log_errors(self):
self.assertRaises(processutils.InvalidArgumentError,
processutils.execute,
self.tmpfilename,
log_errors='invalid',
attempts=3)
def test_multiattempt_with_default_log_errors(self):
err = self.assertRaises(processutils.ProcessExecutionError,
processutils.execute,
self.tmpfilename,
attempts=3)
self.assertEqual(41, err.exit_code)
def test_multiattempt_with_log_errors_NONE(self):
err = self.assertRaises(processutils.ProcessExecutionError,
processutils.execute,
self.tmpfilename,
log_errors=None,
attempts=3)
self.assertEqual(41, err.exit_code)
def test_multiattempt_with_log_errors_final(self):
err = self.assertRaises(processutils.ProcessExecutionError,
processutils.execute,
self.tmpfilename,
log_errors='final',
attempts=3)
self.assertEqual(41, err.exit_code)
def test_multiattempt_with_log_errors_all(self):
err = self.assertRaises(processutils.ProcessExecutionError,
processutils.execute,
self.tmpfilename,
log_errors='all',
attempts=3)
self.assertEqual(41, err.exit_code)
def fake_execute(*cmd, **kwargs):
return 'stdout', 'stderr'