def result(self):
resultReports = []
resultComponentStatus = []
while not self.resultQueue.empty():
res = self.resultQueue.get()
if res[0] == self.EXECUTION_COMMAND:
resultReports.append(res[1])
elif res[0] == ActionQueue.STATUS_COMMAND:
resultComponentStatus.append(res[1])
# Building report for command in progress
if self.commandInProgress is not None:
try:
tmpout = open(self.commandInProgress['tmpout'], 'r').read()
tmperr = open(self.commandInProgress['tmperr'], 'r').read()
except Exception, err:
logger.warn(err)
tmpout = '...'
tmperr = '...'
grep = Grep()
output = grep.tail(tmpout, Grep.OUTPUT_LAST_LINES)
inprogress = {
'role': self.commandInProgress['role'],
'actionId': self.commandInProgress['actionId'],
'taskId': self.commandInProgress['taskId'],
'stdout': grep.filterMarkup(output),
'clusterName': self.commandInProgress['clusterName'],
'stderr': tmperr,
'exitCode': 777,
'serviceName': self.commandInProgress['serviceName'],
'status': 'IN_PROGRESS',
'roleCommand': self.commandInProgress['roleCommand']
}
resultReports.append(inprogress)
def __init__(self, tmpDir, config): self.grep = Grep() self.event = threading.Event() self.python_process_has_been_killed = False self.tmpDir = tmpDir self.config = config pass
class PythonExecutor(object):
"""
Performs functionality for executing python scripts.
Warning: class maintains internal state. As a result, instances should not be
used as a singleton for a concurrent execution of python scripts
"""
NO_ERROR = "none"
def __init__(self, tmpDir, config):
self.grep = Grep()
self.event = threading.Event()
self.python_process_has_been_killed = False
self.tmpDir = tmpDir
self.config = config
pass
def open_subprocess_files(self, tmpoutfile, tmperrfile, override_output_files):
if override_output_files: # Recreate files
tmpout = open(tmpoutfile, 'w')
tmperr = open(tmperrfile, 'w')
else: # Append to files
tmpout = open(tmpoutfile, 'a')
tmperr = open(tmperrfile, 'a')
return tmpout, tmperr
def run_file(self, script, script_params, tmpoutfile, tmperrfile,
timeout, tmpstructedoutfile, callback, task_id,
override_output_files = True, handle = None, log_info_on_failure=True):
"""
Executes the specified python file in a separate subprocess.
Method returns only when the subprocess is finished.
Params arg is a list of script parameters
Timeout meaning: how many seconds should pass before script execution
is forcibly terminated
override_output_files option defines whether stdout/stderr files will be
recreated or appended.
The structured out file, however, is preserved during multiple invocations that use the same file.
"""
pythonCommand = self.python_command(script, script_params)
logger.debug("Running command " + pprint.pformat(pythonCommand))
if handle is None:
tmpout, tmperr = self.open_subprocess_files(tmpoutfile, tmperrfile, override_output_files)
process = self.launch_python_subprocess(pythonCommand, tmpout, tmperr)
# map task_id to pid
callback(task_id, process.pid)
logger.debug("Launching watchdog thread")
self.event.clear()
self.python_process_has_been_killed = False
thread = Thread(target = self.python_watchdog_func, args = (process, timeout))
thread.start()
# Waiting for the process to be either finished or killed
process.communicate()
self.event.set()
thread.join()
result = self.prepare_process_result(process.returncode, tmpoutfile, tmperrfile, tmpstructedoutfile, timeout=timeout)
if log_info_on_failure and result['exitcode']:
self.on_failure(pythonCommand, result)
return result
else:
holder = Holder(pythonCommand, tmpoutfile, tmperrfile, tmpstructedoutfile, handle)
background = BackgroundThread(holder, self)
background.start()
return {"exitcode": 777}
def on_failure(self, pythonCommand, result):
"""
Log some useful information after task failure.
"""
logger.info("Command " + pprint.pformat(pythonCommand) + " failed with exitcode=" + str(result['exitcode']))
if OSCheck.is_windows_family():
cmd_list = ["WMIC path win32_process get Caption,Processid,Commandline", "netstat -an"]
else:
cmd_list = ["ps faux", "netstat -tulpn"]
shell_runner = shellRunner()
for cmd in cmd_list:
ret = shell_runner.run(cmd)
logger.info("Command '{0}' returned {1}. {2}{3}".format(cmd, ret["exitCode"], ret["error"], ret["output"]))
def prepare_process_result(self, returncode, tmpoutfile, tmperrfile, tmpstructedoutfile, timeout=None):
out, error, structured_out = self.read_result_from_files(tmpoutfile, tmperrfile, tmpstructedoutfile)
if self.python_process_has_been_killed:
error = str(error) + "\n Python script has been killed due to timeout" + \
(" after waiting %s secs" % str(timeout) if timeout else "")
returncode = 999
result = self.condenseOutput(out, error, returncode, structured_out)
logger.debug("Result: %s" % result)
return result
def read_result_from_files(self, out_path, err_path, structured_out_path):
out = open(out_path, 'r').read()
error = open(err_path, 'r').read()
try:
with open(structured_out_path, 'r') as fp:
structured_out = json.load(fp)
except Exception:
if os.path.exists(structured_out_path):
errMsg = 'Unable to read structured output from ' + structured_out_path
structured_out = {
'msg' : errMsg
}
logger.warn(structured_out)
else:
structured_out = {}
return out, error, structured_out
def preexec_fn(self):
os.setpgid(0, 0)
def launch_python_subprocess(self, command, tmpout, tmperr):
"""
Creates subprocess with given parameters. This functionality was moved to separate method
to make possible unit testing
"""
close_fds = None if OSCheck.get_os_family() == OSConst.WINSRV_FAMILY else True
command_env = dict(os.environ)
if OSCheck.get_os_family() == OSConst.WINSRV_FAMILY:
command_env["PYTHONPATH"] = os.pathsep.join(sys.path)
for k, v in command_env.iteritems():
command_env[k] = str(v)
return subprocess.Popen(command,
stdout=tmpout,
stderr=tmperr, close_fds=close_fds, env=command_env, preexec_fn=self.preexec_fn)
def isSuccessfull(self, returncode):
return not self.python_process_has_been_killed and returncode == 0
def python_command(self, script, script_params):
#we need manually pass python executable on windows because sys.executable will return service wrapper
python_binary = os.environ['PYTHON_EXE'] if 'PYTHON_EXE' in os.environ else sys.executable
python_command = [python_binary, script] + script_params
return python_command
def condenseOutput(self, stdout, stderr, retcode, structured_out):
log_lines_count = self.config.get('heartbeat', 'log_lines_count')
result = {
"exitcode": retcode,
"stdout": self.grep.tail(stdout, log_lines_count) if log_lines_count else stdout,
"stderr": self.grep.tail(stderr, log_lines_count) if log_lines_count else stderr,
"structuredOut" : structured_out
}
return result
def python_watchdog_func(self, python, timeout):
self.event.wait(timeout)
if python.returncode is None:
logger.error("Subprocess timed out and will be killed")
shell.kill_process_with_children(python.pid)
self.python_process_has_been_killed = True
pass
class PythonExecutor(object):
"""
Performs functionality for executing python scripts.
Warning: class maintains internal state. As a result, instances should not be
used as a singleton for a concurrent execution of python scripts
"""
NO_ERROR = "none"
def __init__(self, tmp_dir, config):
self.logger = logging.getLogger()
self.grep = Grep()
self.event = threading.Event()
self.python_process_has_been_killed = False
self.tmpDir = tmp_dir
self.config = config
self.log_max_symbols_size = self.config.log_max_symbols_size
def open_subprocess32_files(self,
tmp_out_file,
tmp_err_file,
override_output_files,
backup_log_files=True):
mode = "w" if override_output_files else "a"
if override_output_files and backup_log_files:
self.back_up_log_file_if_exists(tmp_out_file)
self.back_up_log_file_if_exists(tmp_err_file)
return open(tmp_out_file, mode), open(tmp_err_file, mode)
def back_up_log_file_if_exists(self, file_path):
if os.path.isfile(file_path):
counter = 0
while True:
# Find backup name that is not used yet (saves logs from multiple command retries)
backup_name = file_path + "." + str(counter)
if not os.path.isfile(backup_name):
break
counter += 1
os.rename(file_path, backup_name)
def run_file(self,
script,
script_params,
tmp_out_file,
tmp_err_file,
timeout,
tmp_structed_outfile,
callback,
task_id,
override_output_files=True,
backup_log_files=True,
handle=None,
log_info_on_failure=True):
"""
Executes the specified python file in a separate subprocess32.
Method returns only when the subprocess32 is finished.
Params arg is a list of script parameters
Timeout meaning: how many seconds should pass before script execution
is forcibly terminated
override_output_files option defines whether stdout/stderr files will be
recreated or appended.
The structured out file, however, is preserved during multiple invocations that use the same file.
"""
python_command = self.python_command(script, script_params)
if self.logger.isEnabledFor(logging.DEBUG):
self.logger.debug("Running command %s",
pprint.pformat(python_command))
def background_executor():
logger = logging.getLogger()
process_out, process_err = self.open_subprocess32_files(
tmp_out_file, tmp_err_file, True)
logger.debug("Starting process command %s", python_command)
p = self.launch_python_subprocess32(python_command, process_out,
process_err)
logger.debug("Process has been started. Pid = %s", p.pid)
handle.pid = p.pid
handle.status = BackgroundCommandExecutionHandle.RUNNING_STATUS
handle.on_background_command_started(handle.command['taskId'],
p.pid)
p.communicate()
handle.exitCode = p.returncode
process_condensed_result = self.prepare_process_result(
p.returncode, tmp_out_file, tmp_err_file, tmp_structed_outfile)
logger.debug("Calling callback with args %s",
process_condensed_result)
handle.on_background_command_complete_callback(
process_condensed_result, handle)
logger.debug("Exiting from thread for holder pid %s", handle.pid)
if handle is None:
tmpout, tmperr = self.open_subprocess32_files(
tmp_out_file, tmp_err_file, override_output_files,
backup_log_files)
process = self.launch_python_subprocess32(python_command, tmpout,
tmperr)
# map task_id to pid
callback(task_id, process.pid)
self.logger.debug("Launching watchdog thread")
self.event.clear()
self.python_process_has_been_killed = False
thread = threading.Thread(target=self.python_watchdog_func,
args=(process, timeout))
thread.start()
# Waiting for the process to be either finished or killed
process.communicate()
self.event.set()
thread.join()
result = self.prepare_process_result(process.returncode,
tmp_out_file,
tmp_err_file,
tmp_structed_outfile,
timeout=timeout)
if log_info_on_failure and result['exitcode']:
self.on_failure(python_command, result)
return result
else:
background = threading.Thread(target=background_executor, args=())
background.start()
return {"exitcode": 777}
def on_failure(self, python_command, result):
"""
Log some useful information after task failure.
"""
pass
#logger.info("Command %s failed with exitcode=%s", pprint.pformat(pythonCommand), result['exitcode'])
#log_process_information(logger)
def prepare_process_result(self,
returncode,
tmpoutfile,
tmperrfile,
tmpstructedoutfile,
timeout=None):
out, error, structured_out = self.read_result_from_files(
tmpoutfile, tmperrfile, tmpstructedoutfile)
if self.python_process_has_been_killed:
error = "{error}\nPython script has been killed due to timeout{timeout_details}".format(
error=error,
timeout_details=""
if not timeout else " after waiting {} secs".format(timeout))
returncode = 999
result = self.condense_output(out, error, returncode, structured_out)
self.logger.debug("Result: %s", result)
return result
def read_result_from_files(self, out_path, err_path, structured_out_path):
out = open(out_path, 'r').read()
error = open(err_path, 'r').read()
try:
with open(structured_out_path, 'r') as fp:
structured_out = json.load(fp)
except (TypeError, ValueError):
structured_out = {
"msg":
"Unable to read structured output from " + structured_out_path
}
self.logger.warn(structured_out)
except (OSError, IOError):
structured_out = {}
return out, error, structured_out
def launch_python_subprocess32(self, command, tmpout, tmperr):
"""
Creates subprocess32 with given parameters. This functionality was moved to separate method
to make possible unit testing
"""
command_env = dict(os.environ)
return subprocess32.Popen(command,
stdout=tmpout,
stderr=tmperr,
close_fds=True,
env=command_env,
preexec_fn=lambda: os.setpgid(0, 0))
def is_successful(self, return_code):
return not self.python_process_has_been_killed and return_code == 0
def python_command(self, script, script_params):
"""
:type script str
:type script_params list|set
"""
python_command = [sys.executable, script] + script_params
return python_command
def condense_output(self, stdout, stderr, ret_code, structured_out):
return {
"exitcode":
ret_code,
"stdout":
self.grep.tail_by_symbols(stdout, self.log_max_symbols_size)
if self.log_max_symbols_size else stdout,
"stderr":
self.grep.tail_by_symbols(stderr, self.log_max_symbols_size)
if self.log_max_symbols_size else stderr,
"structuredOut":
structured_out
}
def python_watchdog_func(self, process, timeout):
self.event.wait(timeout)
if process.returncode is None:
self.logger.error(
"Executed command with pid {} timed out and will be killed".
format(process.pid))
shell.kill_process_with_children(process.pid)
self.python_process_has_been_killed = True
class PythonExecutor(object):
"""
Performs functionality for executing python scripts.
Warning: class maintains internal state. As a result, instances should not be
used as a singleton for a concurrent execution of python scripts
"""
NO_ERROR = "none"
def __init__(self, tmpDir, config):
self.grep = Grep()
self.event = threading.Event()
self.python_process_has_been_killed = False
self.tmpDir = tmpDir
self.config = config
pass
def open_subprocess_files(self, tmpoutfile, tmperrfile,
override_output_files):
if override_output_files: # Recreate files
tmpout = open(tmpoutfile, 'w')
tmperr = open(tmperrfile, 'w')
else: # Append to files
tmpout = open(tmpoutfile, 'a')
tmperr = open(tmperrfile, 'a')
return tmpout, tmperr
def run_file(self,
script,
script_params,
tmpoutfile,
tmperrfile,
timeout,
tmpstructedoutfile,
callback,
task_id,
override_output_files=True,
handle=None,
log_info_on_failure=True):
"""
Executes the specified python file in a separate subprocess.
Method returns only when the subprocess is finished.
Params arg is a list of script parameters
Timeout meaning: how many seconds should pass before script execution
is forcibly terminated
override_output_files option defines whether stdout/stderr files will be
recreated or appended.
The structured out file, however, is preserved during multiple invocations that use the same file.
"""
pythonCommand = self.python_command(script, script_params)
logger.debug("Running command " + pprint.pformat(pythonCommand))
if handle is None:
tmpout, tmperr = self.open_subprocess_files(
tmpoutfile, tmperrfile, override_output_files)
process = self.launch_python_subprocess(pythonCommand, tmpout,
tmperr)
# map task_id to pid
callback(task_id, process.pid)
logger.debug("Launching watchdog thread")
self.event.clear()
self.python_process_has_been_killed = False
thread = Thread(target=self.python_watchdog_func,
args=(process, timeout))
thread.start()
# Waiting for the process to be either finished or killed
process.communicate()
self.event.set()
thread.join()
result = self.prepare_process_result(process.returncode,
tmpoutfile,
tmperrfile,
tmpstructedoutfile,
timeout=timeout)
if log_info_on_failure and result['exitcode']:
self.on_failure(pythonCommand, result)
return result
else:
holder = Holder(pythonCommand, tmpoutfile, tmperrfile,
tmpstructedoutfile, handle)
background = BackgroundThread(holder, self)
background.start()
return {"exitcode": 777}
def on_failure(self, pythonCommand, result):
"""
Log some useful information after task failure.
"""
logger.info("Command " + pprint.pformat(pythonCommand) +
" failed with exitcode=" + str(result['exitcode']))
if OSCheck.is_windows_family():
cmd_list = [
"WMIC path win32_process get Caption,Processid,Commandline",
"netstat -an"
]
else:
cmd_list = ["ps faux", "netstat -tulpn"]
shell_runner = shellRunner()
for cmd in cmd_list:
ret = shell_runner.run(cmd)
logger.info("Command '{0}' returned {1}. {2}{3}".format(
cmd, ret["exitCode"], ret["error"], ret["output"]))
def prepare_process_result(self,
returncode,
tmpoutfile,
tmperrfile,
tmpstructedoutfile,
timeout=None):
out, error, structured_out = self.read_result_from_files(
tmpoutfile, tmperrfile, tmpstructedoutfile)
if self.python_process_has_been_killed:
error = str(error) + "\n Python script has been killed due to timeout" + \
(" after waiting %s secs" % str(timeout) if timeout else "")
returncode = 999
result = self.condenseOutput(out, error, returncode, structured_out)
logger.debug("Result: %s" % result)
return result
def read_result_from_files(self, out_path, err_path, structured_out_path):
out = open(out_path, 'r').read()
error = open(err_path, 'r').read()
try:
with open(structured_out_path, 'r') as fp:
structured_out = json.load(fp)
except Exception:
if os.path.exists(structured_out_path):
errMsg = 'Unable to read structured output from ' + structured_out_path
structured_out = {'msg': errMsg}
logger.warn(structured_out)
else:
structured_out = {}
return out, error, structured_out
def launch_python_subprocess(self, command, tmpout, tmperr):
"""
Creates subprocess with given parameters. This functionality was moved to separate method
to make possible unit testing
"""
close_fds = None if OSCheck.get_os_family(
) == OSConst.WINSRV_FAMILY else True
command_env = dict(os.environ)
if OSCheck.get_os_family() == OSConst.WINSRV_FAMILY:
command_env["PYTHONPATH"] = os.pathsep.join(sys.path)
for k, v in command_env.iteritems():
command_env[k] = str(v)
return subprocess.Popen(command,
stdout=tmpout,
stderr=tmperr,
close_fds=close_fds,
env=command_env)
def isSuccessfull(self, returncode):
return not self.python_process_has_been_killed and returncode == 0
def python_command(self, script, script_params):
#we need manually pass python executable on windows because sys.executable will return service wrapper
python_binary = os.environ[
'PYTHON_EXE'] if 'PYTHON_EXE' in os.environ else sys.executable
python_command = [python_binary, script] + script_params
return python_command
def condenseOutput(self, stdout, stderr, retcode, structured_out):
log_lines_count = self.config.get('heartbeat', 'log_lines_count')
result = {
"exitcode":
retcode,
"stdout":
self.grep.tail(stdout, log_lines_count)
if log_lines_count else stdout,
"stderr":
self.grep.tail(stderr, log_lines_count)
if log_lines_count else stderr,
"structuredOut":
structured_out
}
return result
def python_watchdog_func(self, python, timeout):
self.event.wait(timeout)
if python.returncode is None:
logger.error("Subprocess timed out and will be killed")
shell.kill_process_with_children(python.pid)
self.python_process_has_been_killed = True
pass
class PythonExecutor:
"""
Performs functionality for executing python scripts.
Warning: class maintains internal state. As a result, instances should not be
used as a singleton for a concurrent execution of python scripts
"""
NO_ERROR = "none"
grep = Grep()
event = threading.Event()
python_process_has_been_killed = False
def __init__(self, tmpDir, config):
self.tmpDir = tmpDir
self.config = config
pass
def run_file(self,
script,
script_params,
tmpoutfile,
tmperrfile,
timeout,
tmpstructedoutfile,
override_output_files=True):
"""
Executes the specified python file in a separate subprocess.
Method returns only when the subprocess is finished.
Params arg is a list of script parameters
Timeout meaning: how many seconds should pass before script execution
is forcibly terminated
override_output_files option defines whether stdout/stderr files will be
recreated or appended
"""
if override_output_files: # Recreate files
tmpout = open(tmpoutfile, 'w')
tmperr = open(tmperrfile, 'w')
else: # Append to files
tmpout = open(tmpoutfile, 'a')
tmperr = open(tmperrfile, 'a')
script_params += [tmpstructedoutfile]
pythonCommand = self.python_command(script, script_params)
logger.info("Running command " + pprint.pformat(pythonCommand))
process = self.launch_python_subprocess(pythonCommand, tmpout, tmperr)
logger.debug("Launching watchdog thread")
self.event.clear()
self.python_process_has_been_killed = False
thread = Thread(target=self.python_watchdog_func,
args=(process, timeout))
thread.start()
# Waiting for the process to be either finished or killed
process.communicate()
self.event.set()
thread.join()
# Building results
error = self.NO_ERROR
returncode = process.returncode
out = open(tmpoutfile, 'r').read()
error = open(tmperrfile, 'r').read()
try:
with open(tmpstructedoutfile, 'r') as fp:
structured_out = json.load(fp)
except Exception:
if os.path.exists(tmpstructedoutfile):
errMsg = 'Unable to read structured output from ' + tmpstructedoutfile
structured_out = {'msg': errMsg}
logger.warn(structured_out)
else:
structured_out = '{}'
if self.python_process_has_been_killed:
error = str(
error) + "\n Python script has been killed due to timeout"
returncode = 999
result = self.condenseOutput(out, error, returncode, structured_out)
logger.info("Result: %s" % result)
return result
def launch_python_subprocess(self, command, tmpout, tmperr):
"""
Creates subprocess with given parameters. This functionality was moved to separate method
to make possible unit testing
"""
return subprocess.Popen(command,
stdout=tmpout,
stderr=tmperr,
close_fds=True)
def isSuccessfull(self, returncode):
return not self.python_process_has_been_killed and returncode == 0
def python_command(self, script, script_params):
python_binary = sys.executable
python_command = [python_binary, script] + script_params
return python_command
def condenseOutput(self, stdout, stderr, retcode, structured_out):
grep = self.grep
result = {
"exitcode": retcode,
"stdout": grep.tail(stdout, grep.OUTPUT_LAST_LINES),
"stderr": grep.tail(stderr, grep.OUTPUT_LAST_LINES),
"structuredOut": structured_out
}
return result
def python_watchdog_func(self, python, timeout):
self.event.wait(timeout)
if python.returncode is None:
logger.error("Subprocess timed out and will be killed")
shell.kill_process_with_children(python.pid)
self.python_process_has_been_killed = True
pass
class PuppetExecutor:
""" Class that executes the commands that come from the server using puppet.
This is the class that provides the pluggable point for executing the puppet"""
# How many seconds will pass before running puppet is terminated on timeout
PUPPET_TIMEOUT_SECONDS = 600
grep = Grep()
event = threading.Event()
last_puppet_has_been_killed = False
NO_ERROR = "none"
def __init__(self, puppetModule, puppetInstall, facterInstall, tmpDir,
config):
self.puppetModule = puppetModule
self.puppetInstall = puppetInstall
self.facterInstall = facterInstall
self.tmpDir = tmpDir
self.reposInstalled = False
self.config = config
self.modulesdir = self.puppetModule + "/modules"
def configureEnviron(self, environ):
if not self.config.has_option("puppet", "ruby_home"):
return environ
ruby_home = self.config.get("puppet", "ruby_home")
if os.path.exists(ruby_home):
"""Only update ruby home if the config is configured"""
path = os.environ["PATH"]
if not ruby_home in path:
environ[
"PATH"] = ruby_home + os.path.sep + "bin" + ":" + environ[
"PATH"]
environ["MY_RUBY_HOME"] = ruby_home
return environ
def getPuppetBinary(self):
puppetbin = os.path.join(self.puppetInstall, "bin", "puppet")
if os.path.exists(puppetbin):
return puppetbin
else:
logger.info("Using default puppet on the host : " + puppetbin +
" does not exist.")
return "puppet"
def discardInstalledRepos(self):
"""
Makes agent to forget about installed repos.
So the next call of generate_repo_manifests() will definitely
install repos again
"""
self.reposInstalled = False
def generate_repo_manifests(self, command, tmpDir, modulesdir, taskId):
# Hack to only create the repo files once
manifest_list = []
if not self.reposInstalled:
repoInstaller = RepoInstaller(command, tmpDir, modulesdir, taskId,
self.config)
manifest_list = repoInstaller.generate_repo_manifests()
return manifest_list
def puppetCommand(self, sitepp):
modules = self.puppetModule
puppetcommand = [
self.getPuppetBinary(), "apply", "--confdir=" + modules,
"--detailed-exitcodes", sitepp
]
return puppetcommand
def facterLib(self):
return self.facterInstall + "/lib/"
pass
def puppetLib(self):
return self.puppetInstall + "/lib"
pass
def condenseOutput(self, stdout, stderr, retcode):
grep = self.grep
if stderr == self.NO_ERROR:
result = grep.tail(stdout, grep.OUTPUT_LAST_LINES)
else:
result = grep.grep(stdout, "fail", grep.ERROR_LAST_LINES_BEFORE,
grep.ERROR_LAST_LINES_AFTER)
if result is None: # Second try
result = grep.grep(stdout, "err", grep.ERROR_LAST_LINES_BEFORE,
grep.ERROR_LAST_LINES_AFTER)
filteredresult = grep.filterMarkup(result)
return filteredresult
def isSuccessfull(self, returncode):
return not self.last_puppet_has_been_killed and (returncode == 0
or returncode == 2)
def run_manifest(self, command, file, tmpoutfile, tmperrfile):
result = {}
taskId = 0
if command.has_key("taskId"):
taskId = command['taskId']
puppetEnv = os.environ
#Install repos
repo_manifest_list = self.generate_repo_manifests(
command, self.tmpDir, self.modulesdir, taskId)
puppetFiles = list(repo_manifest_list)
puppetFiles.append(file)
#Run all puppet commands, from manifest generator and for repos installation
#Appending outputs and errors, exitcode - maximal from all
for puppetFile in puppetFiles:
self.runPuppetFile(puppetFile, result, puppetEnv, tmpoutfile,
tmperrfile)
# Check if one of the puppet command fails and error out
if not self.isSuccessfull(result["exitcode"]):
break
if self.isSuccessfull(result["exitcode"]):
# Check if all the repos were installed or not and reset the flag
self.reposInstalled = True
logger.info("ExitCode : " + str(result["exitcode"]))
return result
def runCommand(self, command, tmpoutfile, tmperrfile):
taskId = 0
if command.has_key("taskId"):
taskId = command['taskId']
siteppFileName = os.path.join(self.tmpDir,
"site-" + str(taskId) + ".pp")
generateManifest(command, siteppFileName, self.modulesdir, self.config)
result = self.run_manifest(command, siteppFileName, tmpoutfile,
tmperrfile)
return result
def runPuppetFile(self, puppetFile, result, puppetEnv, tmpoutfile,
tmperrfile):
""" Run the command and make sure the output gets propagated"""
puppetcommand = self.puppetCommand(puppetFile)
rubyLib = ""
if os.environ.has_key("RUBYLIB"):
rubyLib = os.environ["RUBYLIB"]
logger.debug("RUBYLIB from Env " + rubyLib)
if not (self.facterLib() in rubyLib):
rubyLib = rubyLib + ":" + self.facterLib()
if not (self.puppetLib() in rubyLib):
rubyLib = rubyLib + ":" + self.puppetLib()
tmpout = open(tmpoutfile, 'w')
tmperr = open(tmperrfile, 'w')
puppetEnv["RUBYLIB"] = rubyLib
puppetEnv = self.configureEnviron(puppetEnv)
logger.debug("Setting RUBYLIB as: " + rubyLib)
logger.info("Running command " + pprint.pformat(puppetcommand))
puppet = self.lauch_puppet_subprocess(puppetcommand, tmpout, tmperr,
puppetEnv)
logger.debug("Launching watchdog thread")
self.event.clear()
self.last_puppet_has_been_killed = False
thread = Thread(target=self.puppet_watchdog_func, args=(puppet, ))
thread.start()
# Waiting for process to finished or killed
puppet.communicate()
self.event.set()
thread.join()
# Building results
error = self.NO_ERROR
returncode = 0
if not self.isSuccessfull(puppet.returncode):
returncode = puppet.returncode
error = open(tmperrfile, 'r').read()
logging.error("Error running puppet: \n" + str(error))
pass
if self.last_puppet_has_been_killed:
error = str(error) + "\n Puppet has been killed due to timeout"
returncode = 999
if result.has_key("stderr"):
result["stderr"] = result["stderr"] + os.linesep + str(error)
else:
result["stderr"] = str(error)
puppetOutput = open(tmpoutfile, 'r').read()
logger.debug("Output from puppet :\n" + puppetOutput)
logger.info("Puppet exit code is " + str(returncode))
if result.has_key("exitcode"):
result["exitcode"] = max(returncode, result["exitcode"])
else:
result["exitcode"] = returncode
condensed = self.condenseOutput(puppetOutput, error, returncode)
if result.has_key("stdout"):
result["stdout"] = result["stdout"] + os.linesep + str(condensed)
else:
result["stdout"] = str(condensed)
return result
def lauch_puppet_subprocess(self, puppetcommand, tmpout, tmperr,
puppetEnv):
"""
Creates subprocess with given parameters. This functionality was moved to separate method
to make possible unit testing
"""
return subprocess.Popen(puppetcommand,
stdout=tmpout,
stderr=tmperr,
env=puppetEnv)
def puppet_watchdog_func(self, puppet):
self.event.wait(self.PUPPET_TIMEOUT_SECONDS)
if puppet.returncode is None:
logger.error("Task timed out and will be killed")
self.runShellKillPgrp(puppet)
self.last_puppet_has_been_killed = True
pass
def runShellKillPgrp(self, puppet):
shell.killprocessgrp(puppet.pid)
class CommandStatusDict():
"""
Holds results for all commands that are being executed or have finished
execution (but are not yet reported). Implementation is thread-safe.
Dict format:
task_id -> (command, cmd_report)
"""
def __init__(self, callback_action):
"""
callback_action is called every time when status of some command is
updated
"""
self.current_state = {} # Contains all statuses
self.callback_action = callback_action
self.lock = threading.RLock()
def put_command_status(self, command, new_report, wakeupController=True):
"""
Stores new version of report for command (replaces previous)
"""
if 'taskId' in command:
key = command['taskId']
else: # Status command reports has no task id
key = id(command)
with self.lock: # Synchronized
self.current_state[key] = (command, new_report)
# Usually, status commands are not reported immediately
if wakeupController:
self.callback_action()
def generate_report(self):
"""
Generates status reports about commands that are IN_PROGRESS, COMPLETE or
FAILED. Statuses for COMPLETE or FAILED commands are forgotten after
generation
"""
from ActionQueue import ActionQueue
with self.lock: # Synchronized
resultReports = []
resultComponentStatus = []
for key, item in self.current_state.items():
command = item[0]
report = item[1]
logger.debug("report inside generate report is: " +
str(report))
if command['commandType'] == ActionQueue.EXECUTION_COMMAND:
if (report['status']) != ActionQueue.IN_PROGRESS_STATUS:
resultReports.append(report)
# Removing complete/failed command status from dict
del self.current_state[key]
else:
in_progress_report = \
self.generate_in_progress_report(command, report)
resultReports.append(in_progress_report)
elif command['commandType'] == ActionQueue.STATUS_COMMAND:
resultComponentStatus.append(report)
# Component status is useful once, removing it
del self.current_state[key]
result = {
'reports': resultReports,
'componentStatus': resultComponentStatus
}
logger.debug("result from generate report: " + str(result))
return result
def generate_in_progress_report(self, command, report):
"""
Reads stdout/stderr for IN_PROGRESS command from disk file
and populates other fields of report.
"""
from ActionQueue import ActionQueue
try:
tmpout = open(report['tmpout'], 'r').read()
tmperr = open(report['tmperr'], 'r').read()
except Exception, err:
logger.warn(err)
tmpout = '...'
tmperr = '...'
try:
with open(report['structuredOut'], 'r') as fp:
tmpstructuredout = json.load(fp)
except Exception:
tmpstructuredout = '{}'
grep = Grep()
output = grep.tail(tmpout, Grep.OUTPUT_LAST_LINES)
inprogress = self.generate_report_template(command)
reportResult = CommandStatusDict.shouldReportResult(command)
inprogress.update({
'stdout': grep.filterMarkup(output),
'stderr': tmperr,
'structuredOut': tmpstructuredout,
Constants.EXIT_CODE: 777,
'status': ActionQueue.IN_PROGRESS_STATUS,
'reportResult': reportResult
})
return inprogress
import sys
from SearchAndReplace import SearchAndReplace
from Grep import Grep
from InterfaceRenamer import LocalInterfaceRenamer, ExportedInterfaceRenamer, ExistingSymbolCache
directories = sys.argv
grep = Grep()
search_and_replace = SearchAndReplace(grep, directories)
existing_symbol_cache = ExistingSymbolCache(search_and_replace)
renamers = [
LocalInterfaceRenamer(search_and_replace, existing_symbol_cache),
ExportedInterfaceRenamer(search_and_replace, existing_symbol_cache),
]
existing_symbol_cache.warmup()
for renamer in renamers:
renamer.refactor_all()
class CommandStatusDict():
"""
Holds results for all commands that are being executed or have finished
execution (but are not yet reported). Implementation is thread-safe.
Dict format:
task_id -> (command, cmd_report)
"""
def __init__(self, callback_action):
"""
callback_action is called every time when status of some command is
updated
"""
self.current_state = {} # Contains all statuses
self.callback_action = callback_action
self.lock = threading.RLock()
def put_command_status(self, command, new_report):
"""
Stores new version of report for command (replaces previous)
"""
if 'taskId' in command:
key = command['taskId']
status_command = False
else: # Status command reports has no task id
key = id(command)
status_command = True
with self.lock: # Synchronized
self.current_state[key] = (command, new_report)
if not status_command:
self.callback_action()
def update_command_status(self, command, delta):
"""
Updates status of command without replacing (overwrites with delta value)
"""
if 'taskId' in command:
key = command['taskId']
status_command = False
else: # Status command reports has no task id
key = id(command)
status_command = True
with self.lock: # Synchronized
self.current_state[key][1].update(delta)
if not status_command:
self.callback_action()
def get_command_status(self, taskId):
with self.lock:
c = copy.copy(self.current_state[taskId][1])
return c
def generate_report(self):
"""
Generates status reports about commands that are IN_PROGRESS, COMPLETE or
FAILED. Statuses for COMPLETE or FAILED commands are forgotten after
generation
"""
from ActionQueue import ActionQueue
with self.lock: # Synchronized
resultReports = []
resultComponentStatus = []
for key, item in self.current_state.items():
command = item[0]
report = item[1]
if command ['commandType'] in [ActionQueue.EXECUTION_COMMAND, ActionQueue.BACKGROUND_EXECUTION_COMMAND]:
if (report['status']) != ActionQueue.IN_PROGRESS_STATUS:
resultReports.append(report)
# Removing complete/failed command status from dict
del self.current_state[key]
else:
in_progress_report = self.generate_in_progress_report(command, report)
resultReports.append(in_progress_report)
elif command ['commandType'] == ActionQueue.STATUS_COMMAND:
resultComponentStatus.append(report)
# Component status is useful once, removing it
del self.current_state[key]
elif command ['commandType'] in [ActionQueue.AUTO_EXECUTION_COMMAND]:
logger.debug("AUTO_EXECUTION_COMMAND task deleted %s", command['commandId'])
del self.current_state[key]
pass
result = {
'reports': resultReports,
'componentStatus': resultComponentStatus
}
return result
def generate_in_progress_report(self, command, report):
"""
Reads stdout/stderr for IN_PROGRESS command from disk file
and populates other fields of report.
"""
from ActionQueue import ActionQueue
try:
tmpout = open(report['tmpout'], 'r').read()
tmperr = open(report['tmperr'], 'r').read()
except Exception, err:
logger.warn(err)
tmpout = '...'
tmperr = '...'
try:
tmpstructuredout = open(report['structuredOut'], 'r').read()
except Exception:
tmpstructuredout = '{}'
grep = Grep()
output = grep.tail(tmpout, Grep.OUTPUT_LAST_LINES)
inprogress = self.generate_report_template(command)
inprogress.update({
'stdout': output,
'stderr': tmperr,
'structuredOut': tmpstructuredout,
'exitCode': 777,
'status': ActionQueue.IN_PROGRESS_STATUS,
})
return inprogress
class PythonExecutor:
# How many seconds will pass before running puppet is terminated on timeout
PYTHON_TIMEOUT_SECONDS = 600
NO_ERROR = "none"
grep = Grep()
event = threading.Event()
python_process_has_been_killed = False
def __init__(self, tmpDir, config):
self.tmpDir = tmpDir
self.config = config
pass
def run_file(self, command, file, tmpoutfile, tmperrfile):
"""
Executes the specified python file in a separate subprocess.
Method returns only when the subprocess is finished.
"""
tmpout = open(tmpoutfile, 'w')
tmperr = open(tmperrfile, 'w')
pythonCommand = self.pythonCommand(file)
logger.info("Running command " + pprint.pformat(pythonCommand))
process = self.lauch_python_subprocess(pythonCommand, tmpout, tmperr)
logger.debug("Launching watchdog thread")
self.event.clear()
self.python_process_has_been_killed = False
thread = Thread(target = self.python_watchdog_func, args = (process, ))
thread.start()
# Waiting for process to finished or killed
process.communicate()
self.event.set()
thread.join()
# Building results
error = self.NO_ERROR
returncode = process.returncode
out = open(tmpoutfile, 'r').read()
error = open(tmperrfile, 'r').read()
if self.python_process_has_been_killed:
error = str(error) + "\n Puppet has been killed due to timeout"
returncode = 999
result = self.condenseOutput(out, error, returncode)
logger.info("Result: %s" % result)
return result
def lauch_python_subprocess(self, command, tmpout, tmperr):
"""
Creates subprocess with given parameters. This functionality was moved to separate method
to make possible unit testing
"""
return subprocess.Popen(command,
stdout=tmpout,
stderr=tmperr)
def isSuccessfull(self, returncode):
return not self.python_process_has_been_killed and returncode == 0
def pythonCommand(self, file):
puppetcommand = ['python', file]
return puppetcommand
def condenseOutput(self, stdout, stderr, retcode):
grep = self.grep
result = {
"exitcode": retcode,
"stdout" : grep.tail(stdout, grep.OUTPUT_LAST_LINES),
"stderr" : grep.tail(stderr, grep.OUTPUT_LAST_LINES)
}
return result
def python_watchdog_func(self, python):
self.event.wait(self.PYTHON_TIMEOUT_SECONDS)
if python.returncode is None:
logger.error("Subprocess timed out and will be killed")
self.runShellKillPgrp(python)
self.python_process_has_been_killed = True
pass
def runShellKillPgrp(self, python):
shell.killprocessgrp(python.pid)
class TestGrep(TestCase):
logger = logging.getLogger()
string_good = None
string_bad = None
grep = Grep()
def setUp(self):
self.string_good = open('agent' + os.sep + 'dummy_output_good.txt',
'r').read().replace("\n", os.linesep)
self.string_bad = open('agent' + os.sep + 'dummy_output_error.txt',
'r').read().replace("\n", os.linesep)
pass
def test_grep_many_lines(self):
fragment = self.grep.grep(self.string_bad, "err", 1000, 1000)
desired = self.string_bad.strip()
self.assertEquals(
fragment, desired,
"Grep grep function should return all lines if there are less lines than n"
)
def test_grep_few_lines(self):
fragment = self.grep.grep(self.string_bad, "Err", 3, 3)
desired = """
debug: /Schedule[never]: Skipping device resources because running on a host
debug: Exec[command_good](provider=posix): Executing 'wget e432423423xample.com/badurl444111'
debug: Executing 'wget e432423423xample.com/badurl444111'
err: /Stage[main]//Exec[command_good]/returns: change from notrun to 0 failed: wget e432423423xample.com/badurl444111 returned 4 instead of one of [0] at /root/puppet-learn/2-bad.pp:5
debug: /Schedule[weekly]: Skipping device resources because running on a host
debug: /Schedule[puppet]: Skipping device resources because running on a host
debug: Finishing transaction 70171639726240
""".strip()
self.assertEquals(
fragment, desired,
"Grep grep function should return only last 3 lines of file")
def test_grep_no_result(self):
fragment = self.grep.grep(self.string_good, "Err", 3, 3)
desired = None
self.assertEquals(
fragment, desired,
'Grep grep function should return None if result is not found')
def test_grep_empty_string(self):
fragment = self.grep.grep("", "Err", 1000, 1000)
desired = None
self.assertEquals(
fragment, desired,
'Grep grep function should return None for empty string')
def test_grep_all(self):
fragment = self.grep.grep(self.string_bad, "Err", 35, 9)
desired = self.string_bad.strip()
self.assertEquals(
fragment, desired,
'Grep grep function contains bug in index arithmetics')
def test_tail_many_lines(self):
fragment = self.grep.tail(self.string_good, 1000)
desired = self.string_good.strip()
self.assertEquals(
fragment, desired,
"Grep tail function should return all lines if there are less lines than n"
)
def test_tail_few_lines(self):
fragment = self.grep.tail(self.string_good, 3)
desired = """
debug: Finishing transaction 70060456663980
debug: Received report to process from ambari-dmi
debug: Processing report from ambari-dmi with processor Puppet::Reports::Store
""".strip()
self.assertEquals(
fragment, desired,
"Grep tail function should return only last 3 lines of file")
def test_tail_no_lines(self):
fragment = self.grep.tail("", 3)
desired = ''
self.assertEquals(
fragment, desired,
'Grep tail function should return "" for empty string')
def test_tail_all(self):
fragment = self.grep.tail("", 47)
desired = ''
self.assertEquals(
fragment, desired,
'Grep tail function contains bug in index arithmetics')
def test_filterMarkup(self):
string = """[0;36mnotice: /Stage[main]/Hdp-hadoop/Hdp-hadoop::Package[hadoop]/Hdp::Package[hadoop 64]/Hdp::Package::Process_pkg[hadoop 64]/Package[hadoop-libhdfs]/ensure: created[0m"""
desired = """notice: /Stage[main]/Hdp-hadoop/Hdp-hadoop::Package[hadoop]/Hdp::Package[hadoop 64]/Hdp::Package::Process_pkg[hadoop 64]/Package[hadoop-libhdfs]/ensure: created"""
filtered = self.grep.filterMarkup(string)
#sys.stderr.write(filtered)
self.assertEquals(filtered, desired)
def tearDown(self):
pass
def test_cleanByTemplate(self):
fragment = self.grep.cleanByTemplate(self.string_bad, "debug")
desired = """
info: Applying configuration version '1352127563'
err: /Stage[main]//Exec[command_good]/returns: change from notrun to 0 failed: wget e432423423xample.com/badurl444111 returned 4 instead of one of [0] at /root/puppet-learn/2-bad.pp:5
notice: Finished catalog run in 0.23 seconds
""".strip()
self.assertEquals(
fragment, desired,
'Grep cleanByTemplate function should return string without debug lines.'
)
class PuppetExecutor:
""" Class that executes the commands that come from the server using puppet.
This is the class that provides the pluggable point for executing the puppet"""
grep = Grep()
NO_ERROR = "none"
def __init__(self, puppetModule, puppetInstall, facterInstall, tmpDir,
config):
self.puppetModule = puppetModule
self.puppetInstall = puppetInstall
self.facterInstall = facterInstall
self.tmpDir = tmpDir
self.reposInstalled = False
self.config = config
self.modulesdir = self.puppetModule + "/modules"
self.event = threading.Event()
self.last_puppet_has_been_killed = False
self.sh = shellRunner()
self.puppet_timeout = config.get("puppet", "timeout_seconds")
def configureEnviron(self, environ):
if not self.config.has_option("puppet", "ruby_home"):
return environ
ruby_home = self.config.get("puppet", "ruby_home")
if os.path.exists(ruby_home):
"""Only update ruby home if the config is configured"""
path = os.environ["PATH"]
if not ruby_home in path:
environ[
"PATH"] = ruby_home + os.path.sep + "bin" + ":" + environ[
"PATH"]
environ["MY_RUBY_HOME"] = ruby_home
return environ
def getPuppetBinary(self):
puppetbin = os.path.join(self.puppetInstall, "bin", "puppet")
if os.path.exists(puppetbin):
return puppetbin
else:
logger.info("Using default puppet on the host : " + puppetbin +
" does not exist.")
return "puppet"
def discardInstalledRepos(self):
"""
Makes agent to forget about installed repos.
So the next call of generate_repo_manifests() will definitely
install repos again
"""
self.reposInstalled = False
def generate_repo_manifests(self, command, tmpDir, modulesdir, taskId):
# Hack to only create the repo files once
manifest_list = []
if not self.reposInstalled:
repoInstaller = RepoInstaller(command, tmpDir, modulesdir, taskId,
self.config)
manifest_list = repoInstaller.generate_repo_manifests()
return manifest_list
def puppetCommand(self, sitepp):
modules = self.puppetModule
puppetcommand = [
self.getPuppetBinary(), "apply", "--confdir=" + modules,
"--detailed-exitcodes", sitepp
]
return puppetcommand
def facterLib(self):
return self.facterInstall + "/lib/"
pass
def puppetLib(self):
return self.puppetInstall + "/lib"
pass
def condenseOutput(self, stdout, stderr, retcode):
grep = self.grep
if stderr == self.NO_ERROR:
result = grep.tail(stdout, grep.OUTPUT_LAST_LINES)
else:
result = grep.grep(stdout, "fail", grep.ERROR_LAST_LINES_BEFORE,
grep.ERROR_LAST_LINES_AFTER)
result = grep.cleanByTemplate(result, "warning")
if result is None: # Second try
result = grep.grep(stdout, "err", grep.ERROR_LAST_LINES_BEFORE,
grep.ERROR_LAST_LINES_AFTER)
result = grep.cleanByTemplate(result, "warning")
filteredresult = grep.filterMarkup(result)
return filteredresult
def isSuccessfull(self, returncode):
return not self.last_puppet_has_been_killed and (returncode == 0
or returncode == 2)
def run_manifest(self, command, file, tmpoutfile, tmperrfile):
result = {}
taskId = 0
timeout = command['commandParams']['command_timeout']
if command.has_key("taskId"):
taskId = command['taskId']
puppetEnv = os.environ
#Install repos
repo_manifest_list = self.generate_repo_manifests(
command, self.tmpDir, self.modulesdir, taskId)
puppetFiles = list(repo_manifest_list)
puppetFiles.append(file)
#Run all puppet commands, from manifest generator and for repos installation
#Appending outputs and errors, exitcode - maximal from all
for puppetFile in puppetFiles:
self.runPuppetFile(puppetFile, result, puppetEnv, tmpoutfile,
tmperrfile, timeout)
# Check if one of the puppet command fails and error out
if not self.isSuccessfull(result["exitcode"]):
break
if self.isSuccessfull(result["exitcode"]):
# Check if all the repos were installed or not and reset the flag
self.reposInstalled = True
logger.info("ExitCode : " + str(result["exitcode"]))
return result
def isJavaAvailable(self, command):
javaExecutablePath = "{0}/bin/java".format(command)
return not self.sh.run([javaExecutablePath, '-version'])['exitCode']
def runCommand(self, command, tmpoutfile, tmperrfile):
# After installing we must have jdk available for start/stop/smoke
if command['roleCommand'] != "INSTALL":
java64_home = None
if 'hostLevelParams' in command and 'java_home' in command[
'hostLevelParams']:
java64_home = str(
command['hostLevelParams']['java_home']).strip()
if java64_home is None or not self.isJavaAvailable(java64_home):
if java64_home is None:
errMsg = "Cannot access JDK! Make sure java_home is specified in hostLevelParams"
else:
errMsg = JAVANOTVALID_MSG.format(java64_home)
return {'stdout': '', 'stderr': errMsg, 'exitcode': 1}
pass
pass
taskId = 0
if command.has_key("taskId"):
taskId = command['taskId']
siteppFileName = os.path.join(self.tmpDir,
"site-" + str(taskId) + ".pp")
errMsg = manifestGenerator.generateManifest(command, siteppFileName,
self.modulesdir,
self.config)
if not errMsg:
result = self.run_manifest(command, siteppFileName, tmpoutfile,
tmperrfile)
else:
result = {'stdout': '', 'stderr': errMsg, 'exitcode': 1}
return result
def runPuppetFile(self, puppetFile, result, puppetEnv, tmpoutfile,
tmperrfile, timeout):
""" Run the command and make sure the output gets propagated"""
puppetcommand = self.puppetCommand(puppetFile)
rubyLib = ""
if os.environ.has_key("RUBYLIB"):
rubyLib = os.environ["RUBYLIB"]
logger.debug("RUBYLIB from Env " + rubyLib)
if not (self.facterLib() in rubyLib):
rubyLib = rubyLib + ":" + self.facterLib()
if not (self.puppetLib() in rubyLib):
rubyLib = rubyLib + ":" + self.puppetLib()
tmpout = open(tmpoutfile, 'w')
tmperr = open(tmperrfile, 'w')
puppetEnv["RUBYLIB"] = rubyLib
puppetEnv = self.configureEnviron(puppetEnv)
logger.debug("Setting RUBYLIB as: " + rubyLib)
logger.info("Running command " + pprint.pformat(puppetcommand))
puppet = self.lauch_puppet_subprocess(puppetcommand, tmpout, tmperr,
puppetEnv)
logger.info("Command started with PID: " + str(puppet.pid))
logger.debug("Launching watchdog thread")
self.event.clear()
self.last_puppet_has_been_killed = False
thread = Thread(target=self.puppet_watchdog_func,
args=(puppet, timeout))
thread.start()
# Waiting for process to finished or killed
puppet.communicate()
self.event.set()
thread.join()
# Building results
error = self.NO_ERROR
returncode = 0
if not self.isSuccessfull(puppet.returncode):
returncode = puppet.returncode
error = open(tmperrfile, 'r').read()
logging.error("Error running puppet: \n" + str(error))
pass
if self.last_puppet_has_been_killed:
error = str(error) + "\n Puppet has been killed due to timeout"
returncode = 999
if result.has_key("stderr"):
result["stderr"] = result["stderr"] + os.linesep + str(error)
else:
result["stderr"] = str(error)
puppetOutput = open(tmpoutfile, 'r').read()
logger.debug("Output from puppet :\n" + puppetOutput)
logger.info(
"Puppet execution process with pid %s exited with code %s." %
(str(puppet.pid), str(returncode)))
if result.has_key("exitcode"):
result["exitcode"] = max(returncode, result["exitcode"])
else:
result["exitcode"] = returncode
condensed = self.condenseOutput(puppetOutput, error, returncode)
if result.has_key("stdout"):
result["stdout"] = result["stdout"] + os.linesep + str(condensed)
else:
result["stdout"] = str(condensed)
return result
def lauch_puppet_subprocess(self, puppetcommand, tmpout, tmperr,
puppetEnv):
"""
Creates subprocess with given parameters. This functionality was moved to separate method
to make possible unit testing
"""
return subprocess.Popen(puppetcommand,
stdout=tmpout,
stderr=tmperr,
env=puppetEnv)
def puppet_watchdog_func(self, puppet, puppet_timeout):
self.event.wait(float(puppet_timeout))
if puppet.returncode is None:
logger.error("Task timed out, killing process with PID: " +
str(puppet.pid))
shell.kill_process_with_children(puppet.pid)
self.last_puppet_has_been_killed = True
pass
class PythonExecutor:
"""
Performs functionality for executing python scripts.
Warning: class maintains internal state. As a result, instances should not be
used as a singleton for a concurrent execution of python scripts
"""
NO_ERROR = "none"
grep = Grep()
event = threading.Event()
python_process_has_been_killed = False
def __init__(self, tmpDir, config, agentToggleLogger):
self.tmpDir = tmpDir
self.config = config
self.agentToggleLogger = agentToggleLogger
pass
def run_file(self,
script,
script_params,
tmpoutfile,
tmperrfile,
timeout,
tmpstructedoutfile,
logger_level,
override_output_files=True,
environment_vars=None):
"""
Executes the specified python file in a separate subprocess.
Method returns only when the subprocess is finished.
Params arg is a list of script parameters
Timeout meaning: how many seconds should pass before script execution
is forcibly terminated
override_output_files option defines whether stdout/stderr files will be
recreated or appended
"""
if override_output_files: # Recreate files
tmpout = open(tmpoutfile, 'w')
tmperr = open(tmperrfile, 'w')
else: # Append to files
tmpout = open(tmpoutfile, 'a')
tmperr = open(tmperrfile, 'a')
# need to remove this file for the following case:
# status call 1 does not write to file; call 2 writes to file;
# call 3 does not write to file, so contents are still call 2's result
try:
os.unlink(tmpstructedoutfile)
except OSError:
pass # no error
script_params += [
tmpstructedoutfile, logger_level,
self.config.getWorkRootPath()
]
pythonCommand = self.python_command(script, script_params)
self.agentToggleLogger.log("Running command " +
pprint.pformat(pythonCommand))
process = self.launch_python_subprocess(pythonCommand, tmpout, tmperr,
environment_vars)
logger.debug("Launching watchdog thread")
self.event.clear()
self.python_process_has_been_killed = False
thread = Thread(target=self.python_watchdog_func,
args=(process, timeout))
thread.start()
# Waiting for the process to be either finished or killed
process.communicate()
self.event.set()
thread.join()
# Building results
error = self.NO_ERROR
returncode = process.returncode
out = open(tmpoutfile, 'r').read()
error = open(tmperrfile, 'r').read()
structured_out = {}
try:
with open(tmpstructedoutfile, 'r') as fp:
structured_out = json.load(fp)
except Exception as e:
if os.path.exists(tmpstructedoutfile):
errMsg = 'Unable to read structured output from ' + tmpstructedoutfile + ' ' + str(
e)
structured_out = {'msg': errMsg}
logger.warn(structured_out)
if self.python_process_has_been_killed:
error = str(
error) + "\n Python script has been killed due to timeout"
returncode = 999
result = self.condenseOutput(out, error, returncode, structured_out)
self.agentToggleLogger.log("Result: %s" % result)
return result
def launch_python_subprocess(self,
command,
tmpout,
tmperr,
environment_vars=None):
"""
Creates subprocess with given parameters. This functionality was moved to separate method
to make possible unit testing
"""
close_fds = None if platform.system() == "Windows" else True
env = os.environ.copy()
if environment_vars:
for k, v in environment_vars:
self.agentToggleLogger.log("Setting env: %s to %s", k, v)
env[k] = v
return subprocess.Popen(command,
stdout=tmpout,
stderr=tmperr,
close_fds=close_fds,
env=env)
def isSuccessfull(self, returncode):
return not self.python_process_has_been_killed and returncode == 0
def python_command(self, script, script_params):
#we need manually pass python executable on windows because sys.executable will return service wrapper
python_binary = os.environ[
'PYTHON_EXE'] if 'PYTHON_EXE' in os.environ else sys.executable
python_command = [python_binary, "-S", script] + script_params
return python_command
def condenseOutput(self, stdout, stderr, retcode, structured_out):
log_lines_count = self.config.get('heartbeat', 'log_lines_count')
grep = self.grep
result = {
Constants.EXIT_CODE: retcode,
"stdout":
grep.tail(stdout, log_lines_count) if log_lines_count else stdout,
"stderr":
grep.tail(stderr, log_lines_count) if log_lines_count else stderr,
"structuredOut": structured_out
}
return result
def python_watchdog_func(self, python, timeout):
self.event.wait(timeout)
if python.returncode is None:
logger.error("Subprocess timed out and will be killed")
shell.kill_process_with_children(python.pid)
self.python_process_has_been_killed = True
pass
class CommandStatusDict():
"""
Holds results for all commands that are being executed or have finished
execution (but are not yet reported). Implementation is thread-safe.
Dict format:
task_id -> (command, cmd_report)
"""
def __init__(self, initializer_module):
"""
callback_action is called every time when status of some command is
updated
"""
self.current_state = {} # Contains all statuses
self.lock = threading.RLock()
self.initializer_module = initializer_module
self.command_update_output = initializer_module.config.command_update_output
self.reported_reports = set()
def put_command_status(self, command, report):
"""
Stores new version of report for command (replaces previous)
"""
from ActionQueue import ActionQueue
key = command['taskId']
# delete stale data about this command
with self.lock:
self.reported_reports.discard(key)
self.current_state.pop(key, None)
is_sent = self.force_update_to_server({command['clusterId']: [report]})
updatable = report[
'status'] == ActionQueue.IN_PROGRESS_STATUS and self.command_update_output
if not is_sent or updatable:
# if sending is not successful send later
with self.lock:
self.current_state[key] = (command, report)
self.reported_reports.discard(key)
def force_update_to_server(self, reports_dict):
if not self.initializer_module.is_registered:
return False
try:
self.initializer_module.connection.send(
message={'clusters': reports_dict},
destination=Constants.COMMANDS_STATUS_REPORTS_ENDPOINT)
return True
except ConnectionIsAlreadyClosed:
return False
def report(self):
report = self.generate_report()
if report and self.force_update_to_server(report):
self.clear_reported_reports()
def get_command_status(self, taskId):
with self.lock:
c = copy.copy(self.current_state[taskId][1])
return c
def generate_report(self):
"""
Generates status reports about commands that are IN_PROGRESS, COMPLETE or
FAILED. Statuses for COMPLETE or FAILED commands are forgotten after
generation
"""
self.generated_reports = []
from ActionQueue import ActionQueue
with self.lock: # Synchronized
resultReports = defaultdict(lambda: [])
for key, item in self.current_state.items():
command = item[0]
report = item[1]
cluster_id = report['clusterId']
if command['commandType'] in [
ActionQueue.EXECUTION_COMMAND,
ActionQueue.BACKGROUND_EXECUTION_COMMAND
]:
if (report['status']) != ActionQueue.IN_PROGRESS_STATUS:
resultReports[cluster_id].append(report)
self.reported_reports.add(key)
else:
in_progress_report = self.generate_in_progress_report(
command, report)
resultReports[cluster_id].append(in_progress_report)
elif command['commandType'] in [
ActionQueue.AUTO_EXECUTION_COMMAND
]:
logger.debug("AUTO_EXECUTION_COMMAND task deleted %s",
command['commandId'])
self.reported_reports.add(key)
pass
return resultReports
def clear_reported_reports(self):
with self.lock:
for key in self.reported_reports:
del self.current_state[key]
self.reported_reports = set()
def generate_in_progress_report(self, command, report):
"""
Reads stdout/stderr for IN_PROGRESS command from disk file
and populates other fields of report.
"""
from ActionQueue import ActionQueue
try:
tmpout = open(report['tmpout'], 'r').read()
tmperr = open(report['tmperr'], 'r').read()
except Exception, err:
logger.warn(err)
tmpout = '...'
tmperr = '...'
try:
tmpstructuredout = open(report['structuredOut'], 'r').read()
except Exception:
tmpstructuredout = '{}'
grep = Grep()
output = grep.tail(tmpout, Grep.OUTPUT_LAST_LINES)
inprogress = self.generate_report_template(command)
inprogress.update({
'stdout': output,
'stderr': tmperr,
'structuredOut': tmpstructuredout,
'exitCode': 777,
'status': ActionQueue.IN_PROGRESS_STATUS,
})
return inprogress
class PythonExecutor(object):
"""
Performs functionality for executing python scripts.
Warning: class maintains internal state. As a result, instances should not be
used as a singleton for a concurrent execution of python scripts
"""
NO_ERROR = "none"
def __init__(self, tmpDir, config):
self.grep = Grep()
self.event = threading.Event()
self.python_process_has_been_killed = False
self.tmpDir = tmpDir
self.config = config
self.log_max_symbols_size = self.config.log_max_symbols_size
pass
def open_subprocess32_files(self,
tmpoutfile,
tmperrfile,
override_output_files,
backup_log_files=True):
if override_output_files: # Recreate files, existing files are backed up if backup_log_files is True
if backup_log_files:
self.back_up_log_file_if_exists(tmpoutfile)
self.back_up_log_file_if_exists(tmperrfile)
tmpout = open(tmpoutfile, 'w')
tmperr = open(tmperrfile, 'w')
else: # Append to files
tmpout = open(tmpoutfile, 'a')
tmperr = open(tmperrfile, 'a')
return tmpout, tmperr
def back_up_log_file_if_exists(self, file_path):
if os.path.isfile(file_path):
counter = 0
while True:
# Find backup name that is not used yet (saves logs
# from multiple command retries)
backup_name = file_path + "." + str(counter)
if not os.path.isfile(backup_name):
break
counter += 1
os.rename(file_path, backup_name)
def run_file(self,
script,
script_params,
tmpoutfile,
tmperrfile,
timeout,
tmpstructedoutfile,
callback,
task_id,
override_output_files=True,
backup_log_files=True,
handle=None,
log_info_on_failure=True):
"""
Executes the specified python file in a separate subprocess32.
Method returns only when the subprocess32 is finished.
Params arg is a list of script parameters
Timeout meaning: how many seconds should pass before script execution
is forcibly terminated
override_output_files option defines whether stdout/stderr files will be
recreated or appended.
The structured out file, however, is preserved during multiple invocations that use the same file.
"""
pythonCommand = self.python_command(script, script_params)
if logger.isEnabledFor(logging.DEBUG):
logger.debug("Running command %s", pprint.pformat(pythonCommand))
if handle is None:
tmpout, tmperr = self.open_subprocess32_files(
tmpoutfile, tmperrfile, override_output_files,
backup_log_files)
process = self.launch_python_subprocess32(pythonCommand, tmpout,
tmperr)
# map task_id to pid
callback(task_id, process.pid)
logger.debug("Launching watchdog thread")
self.event.clear()
self.python_process_has_been_killed = False
thread = Thread(target=self.python_watchdog_func,
args=(process, timeout))
thread.start()
# Waiting for the process to be either finished or killed
process.communicate()
self.event.set()
thread.join()
result = self.prepare_process_result(process.returncode,
tmpoutfile,
tmperrfile,
tmpstructedoutfile,
timeout=timeout)
if log_info_on_failure and result['exitcode']:
self.on_failure(pythonCommand, result)
return result
else:
holder = Holder(pythonCommand, tmpoutfile, tmperrfile,
tmpstructedoutfile, handle)
background = BackgroundThread(holder, self)
background.start()
return {"exitcode": 777}
def on_failure(self, pythonCommand, result):
"""
Log some useful information after task failure.
"""
pass
#logger.info("Command %s failed with exitcode=%s", pprint.pformat(pythonCommand), result['exitcode'])
#log_process_information(logger)
def prepare_process_result(self,
returncode,
tmpoutfile,
tmperrfile,
tmpstructedoutfile,
timeout=None):
out, error, structured_out = self.read_result_from_files(
tmpoutfile, tmperrfile, tmpstructedoutfile)
if self.python_process_has_been_killed:
error = str(error) + "\n Python script has been killed due to timeout" + \
(" after waiting %s secs" % str(timeout) if timeout else "")
returncode = 999
result = self.condenseOutput(out, error, returncode, structured_out)
logger.debug("Result: %s", result)
return result
def read_result_from_files(self, out_path, err_path, structured_out_path):
out = open(out_path, 'r').read()
error = open(err_path, 'r').read()
try:
with open(structured_out_path, 'r') as fp:
structured_out = json.load(fp)
except Exception:
if os.path.exists(structured_out_path):
errMsg = 'Unable to read structured output from ' + structured_out_path
structured_out = {'msg': errMsg}
logger.warn(structured_out)
else:
structured_out = {}
return out, error, structured_out
def preexec_fn(self):
os.setpgid(0, 0)
def launch_python_subprocess32(self, command, tmpout, tmperr):
"""
Creates subprocess32 with given parameters. This functionality was moved to separate method
to make possible unit testing
"""
close_fds = None if OSCheck.get_os_family(
) == OSConst.WINSRV_FAMILY else True
command_env = dict(os.environ)
if OSCheck.get_os_family() == OSConst.WINSRV_FAMILY:
command_env["PYTHONPATH"] = os.pathsep.join(sys.path)
for k, v in command_env.iteritems():
command_env[k] = str(v)
return subprocess32.Popen(command,
stdout=tmpout,
stderr=tmperr,
close_fds=close_fds,
env=command_env,
preexec_fn=self.preexec_fn)
def isSuccessfull(self, returncode):
return not self.python_process_has_been_killed and returncode == 0
def python_command(self, script, script_params):
#we need manually pass python executable on windows because sys.executable will return service wrapper
python_binary = os.environ[
'PYTHON_EXE'] if 'PYTHON_EXE' in os.environ else sys.executable
python_command = [python_binary, script] + script_params
return python_command
def condenseOutput(self, stdout, stderr, retcode, structured_out):
result = {
"exitcode":
retcode,
"stdout":
self.grep.tail_by_symbols(stdout, self.log_max_symbols_size)
if self.log_max_symbols_size else stdout,
"stderr":
self.grep.tail_by_symbols(stderr, self.log_max_symbols_size)
if self.log_max_symbols_size else stderr,
"structuredOut":
structured_out
}
return result
def python_watchdog_func(self, python, timeout):
self.event.wait(timeout)
if python.returncode is None:
logger.error("subprocess32 timed out and will be killed")
shell.kill_process_with_children(python.pid)
self.python_process_has_been_killed = True
pass