openstack
/
oslo.concurrency
Code Issues Proposed changes

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 b612a9c8d9
2 changed files with 89 additions and 2 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

32
oslo/concurrency/processutils.py
View File

@ -116,6 +116,16 @@ 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?
Possible values are None=default,
'final', or 'all'. None implies no logging on
errors. The values 'final' and 'all' are relevant
when multiple attempts of command execution are
requested using the 'attempts' parameter. If
'final' is specified then only log an error on
the last attempt, and 'all' requires logging on
each occurence of an error.
:type log_errors: string.
:returns: (stdout, stderr) from process execution
:raises: :class:`UnknownArgumentError` on
receiving unknown arguments
@ -132,6 +142,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 +153,10 @@ def execute(*cmd, **kwargs):
if kwargs:
raise UnknownArgumentError(_('Got unknown keyword args: %r') % kwargs)
if log_errors not in [None, '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 +212,24 @@ 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):
format = _('%(desc)r\ncommand: %(cmd)r\n'
'exit code: %(code)r\nstdout: %(stdout)r\n'
'stderr: %(stderr)r')
LOG.log(loglevel, format, {"desc": err.description,
"cmd": err.cmd,
"code": err.exit_code,
"stdout": err.stdout,
"stderr": 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:

59
tests/unit/test_processutils.py
View File

@ -16,8 +16,10 @@
from __future__ import print_function
import errno
import logging
import multiprocessing
import os
import stat
import tempfile
import fixtures
@ -26,6 +28,8 @@ from oslotest import base as test_base
import six
from oslo.concurrency import processutils
PROCESS_EXECUTION_ERROR_LOGGING_TEST = """#!/bin/bash
exit 41"""
class UtilsTest(test_base.BaseTestCase):
@ -218,6 +222,61 @@ grep foo
self.assertIn('SUPER_UNIQUE_VAR=The answer is 42', out)
class ProcessExecutionErrorLoggingTest(test_base.BaseTestCase):
def setUp(self):
super(ProcessExecutionErrorLoggingTest, self).setUp()
self.tmpfilename = self.create_tempfiles(
[["process_execution_error_logging_test",
PROCESS_EXECUTION_ERROR_LOGGING_TEST]],
ext='bash')[0]
os.chmod(self.tmpfilename, (stat.S_IRWXU + stat.S_IRGRP +
stat.S_IXGRP + stat.S_IROTH +
stat.S_IXOTH))
def _test_and_check(self, log_errors=None, attempts=None):
fixture = self.useFixture(fixtures.FakeLogger(level=logging.DEBUG))
if attempts is None:
err = self.assertRaises(processutils.ProcessExecutionError,
processutils.execute,
self.tmpfilename,
log_errors=log_errors)
else:
err = self.assertRaises(processutils.ProcessExecutionError,
processutils.execute,
self.tmpfilename,
log_errors=log_errors,
attempts=attempts)
self.assertEqual(41, err.exit_code)
self.assertIn(self.tmpfilename, fixture.output)
def test_with_invalid_log_errors(self):
self.assertRaises(processutils.InvalidArgumentError,
processutils.execute,
self.tmpfilename,
log_errors='invalid')
def test_with_log_errors_NONE(self):
self._test_and_check(log_errors=None, attempts=None)
def test_with_log_errors_final(self):
self._test_and_check(log_errors='final', attempts=None)
def test_with_log_errors_all(self):
self._test_and_check(log_errors='all', attempts=None)
def test_multiattempt_with_log_errors_NONE(self):
self._test_and_check(log_errors=None, attempts=3)
def test_multiattempt_with_log_errors_final(self):
self._test_and_check(log_errors='final', attempts=3)
def test_multiattempt_with_log_errors_all(self):
self._test_and_check(log_errors='all', attempts=3)
def fake_execute(*cmd, **kwargs):
return 'stdout', 'stderr'