Merge "Improved logging"
This commit is contained in:
@@ -357,7 +357,7 @@ class PackstackDrone(SshTarballTransferMixin, Drone):
|
||||
try:
|
||||
# once a remote puppet run has finished, we retrieve
|
||||
# the log file and check it for errors
|
||||
local.execute(logerrors=False)
|
||||
local.execute(log=False)
|
||||
# if we got to this point the puppet apply has finished
|
||||
return True
|
||||
except utils.ScriptRuntimeError, e:
|
||||
|
||||
@@ -356,7 +356,6 @@ def _handleAnswerFileParams(answerFile):
|
||||
preConditionValue = _handleGroupCondition(fconf, group.PRE_CONDITION, preConditionValue)
|
||||
|
||||
# Handle pre condition match with case insensitive values
|
||||
logging.info("Comparing pre- conditions, value: '%s', and match: '%s'" % (preConditionValue, group.PRE_CONDITION_MATCH))
|
||||
if preConditionValue == group.PRE_CONDITION_MATCH:
|
||||
for param in group.parameters.itervalues():
|
||||
_loadParamFromFile(fconf, "general", param.CONF_NAME)
|
||||
@@ -396,7 +395,6 @@ def _getanswerfilepath():
|
||||
msg = "A new answerfile was created in: %s" % path
|
||||
|
||||
controller.MESSAGES.append(msg)
|
||||
logging.info(msg)
|
||||
return path
|
||||
|
||||
def _handleInteractiveParams():
|
||||
@@ -414,7 +412,6 @@ def _handleInteractiveParams():
|
||||
inputLoop = True
|
||||
|
||||
# If we have a match, i.e. condition returned True, go over all params in the group
|
||||
logging.info("Comparing pre-conditions; condition: '%s', and match: '%s'" % (preConditionValue, group.PRE_CONDITION_MATCH))
|
||||
if preConditionValue == group.PRE_CONDITION_MATCH:
|
||||
while inputLoop:
|
||||
for param in group.parameters.itervalues():
|
||||
@@ -529,7 +526,6 @@ def _printAdditionalMessages():
|
||||
if len(controller.MESSAGES) > 0:
|
||||
print "\n",output_messages.INFO_ADDTIONAL_MSG
|
||||
for msg in controller.MESSAGES:
|
||||
logging.info(output_messages.INFO_ADDTIONAL_MSG_BULLET%(msg))
|
||||
print output_messages.INFO_ADDTIONAL_MSG_BULLET%(msg)
|
||||
|
||||
def _addFinalInfoMsg():
|
||||
@@ -554,7 +550,6 @@ def runSequences():
|
||||
controller.runAllSequences()
|
||||
|
||||
def _main(configFile=None):
|
||||
logging.debug("Entered main(configFile='%s')"%(configFile))
|
||||
print output_messages.INFO_HEADER
|
||||
|
||||
# Get parameters
|
||||
@@ -567,7 +562,6 @@ def _main(configFile=None):
|
||||
logging.debug(mask(controller.CONF))
|
||||
|
||||
# Start configuration stage
|
||||
logging.debug("Entered Configuration stage")
|
||||
print "\n",output_messages.INFO_INSTALL
|
||||
|
||||
# Initialize Sequences
|
||||
@@ -595,7 +589,7 @@ def remove_remote_var_dirs():
|
||||
except KeyError:
|
||||
# Nothing was added to this host yet, so we have nothing to delete
|
||||
continue
|
||||
logging.info(output_messages.INFO_REMOVE_REMOTE_VAR % (host_dir, host))
|
||||
logging.debug(output_messages.INFO_REMOVE_REMOTE_VAR % (host_dir, host))
|
||||
server = utils.ScriptRunner(host)
|
||||
server.append('rm -rf %s' % host_dir)
|
||||
try:
|
||||
@@ -703,7 +697,6 @@ def initCmdLineParser():
|
||||
"""
|
||||
|
||||
# Init parser and all general flags
|
||||
logging.debug("initiating command line option parser")
|
||||
usage = "usage: %prog [options] [--help]"
|
||||
parser = OptionParser(usage)
|
||||
parser.add_option("--gen-answer-file", help="Generate a template of an answer file, using this option excludes all other options")
|
||||
|
||||
@@ -17,7 +17,7 @@ def get_localhost_ip():
|
||||
# find nameservers
|
||||
ns_regex = re.compile('nameserver\s*(?P<ns_ip>[\d\.\:])')
|
||||
rc, resolv = execute('cat /etc/resolv.conf | grep nameserver',
|
||||
can_fail=False, use_shell=True)
|
||||
can_fail=False, use_shell=True, log=False)
|
||||
nsrvs = []
|
||||
for line in resolv.split('\n'):
|
||||
match = ns_regex.match(line.strip())
|
||||
|
||||
@@ -10,8 +10,12 @@ from ..exceptions import (ExecuteRuntimeError, ScriptRuntimeError,
|
||||
from .strings import mask_string
|
||||
|
||||
|
||||
block_fmt = ("\n============= %(title)s ==========\n%(content)s\n"
|
||||
"======== END OF %(title)s ========")
|
||||
|
||||
|
||||
def execute(cmd, workdir=None, can_fail=False, mask_list=None,
|
||||
use_shell=False):
|
||||
use_shell=False, log=True):
|
||||
"""
|
||||
Runs shell command cmd. If can_fail is set to False
|
||||
ExecuteRuntimeError is raised if command returned non-zero return
|
||||
@@ -26,19 +30,25 @@ def execute(cmd, workdir=None, can_fail=False, mask_list=None,
|
||||
else:
|
||||
masked = cmd
|
||||
masked = mask_string(masked, mask_list, repl_list)
|
||||
logging.debug("Executing command: %s" % masked)
|
||||
if log:
|
||||
logging.info("Executing command:\n%s" % masked)
|
||||
|
||||
proc = subprocess.Popen(cmd, stdout=subprocess.PIPE,
|
||||
stderr=subprocess.PIPE, cwd=workdir,
|
||||
shell=use_shell, close_fds=True)
|
||||
out, err = proc.communicate()
|
||||
logging.debug("rc: %s" % proc.returncode)
|
||||
logging.debug("stdout:\n%s" % mask_string(out, mask_list, repl_list))
|
||||
logging.debug("stderr:\n%s" % mask_string(err, mask_list, repl_list))
|
||||
masked_out = mask_string(out, mask_list, repl_list)
|
||||
masked_err = mask_string(err, mask_list, repl_list)
|
||||
if log:
|
||||
logging.debug(block_fmt % {'title': 'STDOUT', 'content': masked_out})
|
||||
|
||||
if not can_fail and proc.returncode != 0:
|
||||
msg = 'Failed to execute command: %s' % masked
|
||||
raise ExecuteRuntimeError(msg, stdout=out, stderr=err)
|
||||
if proc.returncode:
|
||||
if log:
|
||||
logging.debug(block_fmt % {'title': 'STDERR',
|
||||
'content': masked_err})
|
||||
if not can_fail:
|
||||
msg = 'Failed to execute command: %s' % masked_out
|
||||
raise ExecuteRuntimeError(msg, stdout=out, stderr=err)
|
||||
return proc.returncode, out
|
||||
|
||||
|
||||
@@ -55,10 +65,15 @@ class ScriptRunner(object):
|
||||
def clear(self):
|
||||
self.script = []
|
||||
|
||||
def execute(self, logerrors=True, maskList=None):
|
||||
maskList = maskList or []
|
||||
def execute(self, can_fail=True, mask_list=None, log=True):
|
||||
mask_list = mask_list or []
|
||||
repl_list = [("'", "'\\''")]
|
||||
script = "\n".join(self.script)
|
||||
logging.debug("# ============ ssh : %r ==========" % self.ip)
|
||||
|
||||
masked = mask_string(script, mask_list, repl_list)
|
||||
if log:
|
||||
logging.info("[%s] Executing script:\n%s" %
|
||||
(self.ip or 'localhost', masked))
|
||||
|
||||
_PIPE = subprocess.PIPE # pylint: disable=E1101
|
||||
if self.ip:
|
||||
@@ -67,32 +82,29 @@ class ScriptRunner(object):
|
||||
"root@%s" % self.ip, "bash -x"]
|
||||
else:
|
||||
cmd = ["bash", "-x"]
|
||||
obj = subprocess.Popen(cmd, stdin=_PIPE, stdout=_PIPE,
|
||||
stderr=_PIPE, close_fds=True,
|
||||
shell=False)
|
||||
obj = subprocess.Popen(cmd, stdin=_PIPE, stdout=_PIPE, stderr=_PIPE,
|
||||
close_fds=True, shell=False)
|
||||
|
||||
replace_list = [("'", "'\\''")]
|
||||
logging.debug(mask_string(script, maskList, replace_list))
|
||||
script = "function t(){ exit $? ; } \n trap t ERR \n" + script
|
||||
stdoutdata, stderrdata = obj.communicate(script)
|
||||
logging.debug("============ STDOUT ==========")
|
||||
logging.debug(mask_string(stdoutdata, maskList, replace_list))
|
||||
returncode = obj.returncode
|
||||
if returncode:
|
||||
if logerrors:
|
||||
logging.error("============= STDERR ==========")
|
||||
logging.error(mask_string(stderrdata, maskList,
|
||||
replace_list))
|
||||
out, err = obj.communicate(script)
|
||||
masked_out = mask_string(out, mask_list, repl_list)
|
||||
masked_err = mask_string(err, mask_list, repl_list)
|
||||
if log:
|
||||
logging.debug(block_fmt % {'title': 'STDOUT',
|
||||
'content': masked_out})
|
||||
|
||||
pattern = (r'^ssh\:')
|
||||
if re.search(pattern, stderrdata):
|
||||
raise NetworkError(stderrdata, stdout=stdoutdata,
|
||||
stderr=stderrdata)
|
||||
else:
|
||||
msg = 'Error running remote script: %s' % stdoutdata
|
||||
raise ScriptRuntimeError(msg, stdout=stdoutdata,
|
||||
stderr=stderrdata)
|
||||
return returncode, stdoutdata
|
||||
if obj.returncode:
|
||||
if log:
|
||||
logging.debug(block_fmt % {'title': 'STDERR',
|
||||
'content': masked_err})
|
||||
if not can_fail:
|
||||
pattern = (r'^ssh\:')
|
||||
if re.search(pattern, err):
|
||||
raise NetworkError(masked_err, stdout=out, stderr=err)
|
||||
else:
|
||||
msg = 'Failed to run remote script: %s' % masked_out
|
||||
raise ScriptRuntimeError(msg, stdout=out, stderr=err)
|
||||
return obj.returncode, out
|
||||
|
||||
def template(self, src, dst, varsdict):
|
||||
with open(src) as fp:
|
||||
@@ -115,4 +127,4 @@ class ScriptRunner(object):
|
||||
self.append("chown %s:%s %s" % (uid, gid, target))
|
||||
|
||||
def chmod(self, target, mode):
|
||||
self.append("chown %s %s" % (mode, target))
|
||||
self.append("chmod %s %s" % (mode, target))
|
||||
|
||||
@@ -150,8 +150,8 @@ def waitforpuppet(currently_running):
|
||||
log = os.path.join(basedefs.PUPPET_MANIFEST_DIR,
|
||||
os.path.basename(finished_logfile).replace(".finished", ".log"))
|
||||
local_server.append('scp -o StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null root@%s:%s %s' % (hostname, finished_logfile, log))
|
||||
# Errors are expected here if the puppet run isn't finished so we suppress logging them
|
||||
local_server.execute(logerrors=False)
|
||||
# To not pollute logs we turn of logging of command execution
|
||||
local_server.execute(log=False)
|
||||
|
||||
# If we got to this point the puppet apply has finished
|
||||
currently_running.remove((hostname, finished_logfile))
|
||||
|
||||
@@ -87,8 +87,7 @@ class ParameterTestCase(PackstackTestCaseMixin, TestCase):
|
||||
use_shell=True, mask_list=['password'])
|
||||
raise AssertionError('Masked execution failed.')
|
||||
except ExecuteRuntimeError, ex:
|
||||
should_be = ('Failed to execute command: '
|
||||
'echo "mask the %s" && exit 1' % STR_MASK)
|
||||
should_be = ('Failed to execute command: mask the %s\n' % STR_MASK)
|
||||
self.assertEqual(str(ex), should_be)
|
||||
|
||||
script = ScriptRunner()
|
||||
|
||||
Reference in New Issue
Block a user