Merge "Log stdout, stderr and command on execute() error"

This commit is contained in:
Jenkins 2014-09-08 11:01:04 +00:00 committed by Gerrit Code Review
commit 4e7a576227
2 changed files with 100 additions and 3 deletions

View File

@ -82,6 +82,10 @@ def _subprocess_setup():
signal.signal(signal.SIGPIPE, signal.SIG_DFL)
LOG_ALL_ERRORS = 1
LOG_FINAL_ERROR = 2
def execute(*cmd, **kwargs):
"""Helper method to shell out and execute a command through subprocess.
@ -116,10 +120,23 @@ 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,
LOG_FINAL_ERROR, or LOG_ALL_ERRORS. None
implies no logging on errors. The values
LOG_FINAL_ERROR and LOG_ALL_ERRORS are
relevant when multiple attempts of command
execution are requested using the
'attempts' parameter. If LOG_FINAL_ERROR
is specified then only log an error on the
last attempt, and LOG_ALL_ERRORS requires
logging on each occurence of an error.
:type log_errors: integer.
:returns: (stdout, stderr) from process execution
:raises: :class:`UnknownArgumentError` on
receiving unknown arguments
:raises: :class:`ProcessExecutionError`
"""
process_input = kwargs.pop('process_input', None)
@ -132,6 +149,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 +160,10 @@ def execute(*cmd, **kwargs):
if kwargs:
raise UnknownArgumentError(_('Got unknown keyword args: %r') % kwargs)
if log_errors not in [None, LOG_ALL_ERRORS, LOG_FINAL_ERROR]:
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(
@ -199,11 +221,25 @@ def execute(*cmd, **kwargs):
stderr=sanitized_stderr,
cmd=sanitized_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 == LOG_ALL_ERRORS or (
log_errors == LOG_FINAL_ERROR 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. Not Retrying.'), err.cmd)
raise
else:
LOG.log(loglevel, _('%r failed. Retrying.'), sanitized_cmd)
LOG.log(loglevel, _('%r failed. Retrying.'), err.cmd)
if delay_on_retry:
greenthread.sleep(random.randint(20, 200) / 100.0)
finally:

View File

@ -19,15 +19,17 @@ import errno
import logging
import multiprocessing
import os
import stat
import tempfile
import fixtures
import mock
from oslotest import base as test_base
import six
import stat
from oslo.concurrency import processutils
PROCESS_EXECUTION_ERROR_LOGGING_TEST = """#!/bin/bash
exit 41"""
TEST_EXCEPTION_AND_MASKING_SCRIPT = """#!/bin/bash
# This is to test stdout and stderr
@ -252,6 +254,65 @@ grep foo
self.assertNotIn('secret', str(err))
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))
kwargs = {}
if log_errors:
kwargs.update({"log_errors": log_errors})
if attempts:
kwargs.update({"attempts": attempts})
err = self.assertRaises(processutils.ProcessExecutionError,
processutils.execute,
self.tmpfilename,
**kwargs)
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=processutils.LOG_FINAL_ERROR,
attempts=None)
def test_with_log_errors_all(self):
self._test_and_check(log_errors=processutils.LOG_ALL_ERRORS,
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=processutils.LOG_FINAL_ERROR,
attempts=3)
def test_multiattempt_with_log_errors_all(self):
self._test_and_check(log_errors=processutils.LOG_ALL_ERRORS,
attempts=3)
def fake_execute(*cmd, **kwargs):
return 'stdout', 'stderr'